From owner-freebsd-current Fri Jun 8 9:13:22 2001 Delivered-To: freebsd-current@freebsd.org Received: from kalaid.f2f.com.ua (kalaid.f2f.com.ua [62.149.0.33]) by hub.freebsd.org (Postfix) with ESMTP id E46FC37B406; Fri, 8 Jun 2001 09:13:07 -0700 (PDT) (envelope-from sobomax@mail-in.net) Received: from Mail-In.Net (borey.f2f.com.ua [62.149.0.24]) by kalaid.f2f.com.ua (8.11.3/8.11.1) with ESMTP id f58GE7D55844; Fri, 8 Jun 2001 19:14:13 +0300 (EEST) (envelope-from sobomax@mail-in.net) Received: from vega.vega.com (das0-l98.uic-in.net [212.35.189.225]) by Mail-In.Net (8.11.3/8.H.Z) with ESMTP id f58GDJV66040; Fri, 8 Jun 2001 19:13:23 +0300 (EEST) Received: from FreeBSD.org (big_brother.vega.com [192.168.1.1]) by vega.vega.com (8.11.3/8.11.3) with ESMTP id f58FfaH20368; Fri, 8 Jun 2001 18:41:36 +0300 (EEST) (envelope-from sobomax@FreeBSD.org) Message-ID: <3B20F22E.8004BE28@FreeBSD.org> Date: Fri, 08 Jun 2001 18:41:35 +0300 From: Maxim Sobolev Organization: Vega International Capital X-Mailer: Mozilla 4.77 [en] (WinNT; U) X-Accept-Language: en,uk,ru MIME-Version: 1.0 To: Brian Somers Cc: brian@FreeBSD.ORG, current@FreeBSD.ORG Subject: Re: Unrecognised CBCP packet [strange problems with ppp(8)] References: <200105290823.f4T8NYM34180@hak.lan.Awfulhak.org> Content-Type: multipart/mixed; boundary="------------BADE080333E00C87344B89B1" Sender: owner-freebsd-current@FreeBSD.ORG Precedence: bulk List-ID: List-Archive: (Web Archive) List-Help: (List Instructions) List-Subscribe: List-Unsubscribe: X-Loop: FreeBSD.ORG This is a multi-part message in MIME format. --------------BADE080333E00C87344B89B1 Content-Type: text/plain; charset=koi8-r Content-Transfer-Encoding: 7bit Brian Somers wrote: > I've had reports of this in the past. The other end is sending a > ``code 5'' packet - something that doesn't appear in the spec :( > > ppp(8) just ignores these (emitting a warning), they shouldn't be > causing any problems themselves (even if CBCP is actually being used). > > Try enabling IPCP logging. You may be having a problem at that > level, or alternatively, perhaps the peer thinks you've already got a > connection and is (rudely) dropping the connection because of that. Attached please find relevant log. I could add that now the problem became even more frequent, so I would appreciate any help. Thank you! -Maxim > > Hi, > > > > I'm having strange problems with one of local dial-up providers: without > > any visible reasons from time to time I can't establish PPP connection > > during 20-30 minutes. Shortly after going into `Network' mode ppp(8) > > complains about `Unrecognised CBCP packet' and drops down line. > > Restarting ppp/machine/modem etc. doesn't help and provider's technical > > people have no idea what could be wrong. Attached please find piece of > > log, please let me know if any additional information would be necessary. > > > > -Maxim > > > > Phase: bundle: Authenticate > > Phase: deflink: his = PAP, mine = none > > Phase: Pap Output: sobomax1 ******** > > Ppp ON vega> Phase: Pap Input: SUCCESS () > > Phase: deflink: lcp -> open > > Phase: bundle: Network > > PPp ON vega> Warning: Unrecognised CBCP packet (code 5, length 4) > > PPp ON vega> Phase: deflink: open -> lcp > > Phase: bundle: Terminate > > ppp ON vega> Phase: deflink: Carrier lost > > Phase: deflink: Disconnected! > > Phase: deflink: lcp -> logout > > Phase: deflink: Disconnected! > > Phase: deflink: logout -> hangup > > Phase: deflink: Connect time: 32 secs: 248 octets in, 235 octets out > > -- > Brian > > Don't _EVER_ lose your sense of humour ! --------------BADE080333E00C87344B89B1 Content-Type: text/plain; charset=koi8-r; name="PPPLOG" Content-Transfer-Encoding: 7bit Content-Disposition: inline; filename="PPPLOG" ppp ON vega> set log local +ipcp +phase +debug ppp ON vega> dia Phase: bundle: Establish Phase: deflink: closed -> opening Debug: deflink: Opened /dev/cuaa0 Debug: deflink: tty_Create: physical (get): fd = 1, iflag = 0, oflag = 0, cflag = 34b00 Debug: deflink: physical (put): iflag = 201, oflag = 0, cflag = 3cb00 Phase: deflink: Connected! Phase: deflink: opening -> dial ppp ON vega> Phase: deflink: dial -> carrier Debug: deflink: Using tty_Timeout [0x8071f50] Debug: Waiting for carrier Debug: Waiting for carrier Phase: deflink: /dev/cuaa0: CD detected Phase: deflink: carrier -> login Debug: deflink: Entering tty_Raw Phase: deflink: login -> lcp Debug: deflink: Still online Debug: fsm_Output Debug: 01 28 00 18 08 02 07 02 02 06 00 00 00 00 01 04 .(.............. Debug: 05 dc 05 06 e3 2d 98 14 .....-.. Debug: proto_LayerPush: Using 0xc021 Debug: link_PushPacket: Transmit proto 0xc021 Debug: m_enqueue: len = 1 Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 53(53) to 1 Debug: deflink: DescriptorRead: read 34/2048 from 1 Debug: deflink: DescriptorRead: read 77/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0xc021 Debug: link_PullPacket: Despatch proto 0xc021 Debug: fsm_Output Debug: 02 01 00 1f 01 04 05 f4 02 06 00 00 00 00 03 04 ................ Debug: c0 23 07 02 08 02 13 09 03 00 c0 7b 8f 05 53 .#.........{..S Debug: proto_LayerPush: Using 0xc021 Debug: link_PushPacket: Transmit proto 0xc021 Debug: m_enqueue: len = 1 Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 65(65) to 1 Debug: deflink: DescriptorRead: read 5/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0xc021 Debug: link_PullPacket: Despatch proto 0xc021 Phase: bundle: Authenticate Phase: deflink: his = PAP, mine = none Debug: pap_Req: namelen = 8, keylen = 6 Phase: Pap Output: sobomax1 ******** Debug: proto_LayerPush: Using 0xc023 Debug: link_PushPacket: Transmit proto 0xc023 Debug: m_enqueue: len = 1 Ppp ON vega> Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 26(26) to 1 Debug: deflink: DescriptorRead: read 33/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0xc023 Debug: link_PullPacket: Despatch proto 0xc023 Phase: Pap Input: SUCCESS () IPCP: Using trigger address 0.0.0.0 Phase: deflink: lcp -> open Phase: bundle: Network IPCP: FSM: Using "deflink" as a transport IPCP: deflink: State change Initial --> Closed IPCP: deflink: LayerStart. IPCP: deflink: SendConfigReq(69) state = Closed IPCP: IPADDR[6] 0.0.0.0 Debug: fsm_Output Debug: 01 45 00 0a 03 06 00 00 00 00 .E........ Debug: proto_LayerPush: Using 0x8021 Debug: link_PushPacket: Transmit proto 0x8021 Debug: m_enqueue: len = 1 IPCP: deflink: State change Closed --> Req-Sent Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0x8021 Debug: link_PullPacket: Despatch proto 0x8021 IPCP: deflink: RecvConfigReq(1) state = Req-Sent IPCP: COMPPROTO[6] 16 VJ slots with slot compression IPCP: IPADDR[6] 212.35.189.18 IPCP: deflink: SendConfigRej(1) state = Req-Sent IPCP: COMPPROTO[6] 16 VJ slots with slot compression Debug: fsm_Output Debug: 04 01 00 0a 02 06 00 2d 0f 01 .......-.. Debug: proto_LayerPush: Using 0x8021 Debug: link_PushPacket: Transmit proto 0x8021 Debug: m_enqueue: len = 2 PPp ON vega> Debug: m_dequeue: queue len = 2 Debug: link_Dequeue: Dequeued from queue 1, containing 1 more packets Debug: deflink: DescriptorWrite: wrote 16(16) to 1 Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 16(16) to 1 Debug: deflink: DescriptorRead: read 32/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0x8021 Debug: link_PullPacket: Despatch proto 0x8021 IPCP: deflink: RecvConfigNak(69) state = Req-Sent IPCP: IPADDR[6] 212.35.189.239 IPCP: IPADDR[6] changing address: 0.0.0.0 --> 212.35.189.239 IPCP: deflink: SendConfigReq(70) state = Req-Sent IPCP: IPADDR[6] 212.35.189.239 Debug: fsm_Output Debug: 01 46 00 0a 03 06 d4 23 bd ef .F.....#.. Debug: proto_LayerPush: Using 0x8021 Debug: link_PushPacket: Transmit proto 0x8021 Debug: m_enqueue: len = 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0x8021 Debug: link_PullPacket: Despatch proto 0x8021 IPCP: deflink: RecvConfigReq(2) state = Req-Sent IPCP: IPADDR[6] 212.35.189.18 IPCP: deflink: SendConfigAck(2) state = Req-Sent IPCP: IPADDR[6] 212.35.189.18 Debug: fsm_Output Debug: 02 02 00 0a 03 06 d4 23 bd 12 .......#.. Debug: proto_LayerPush: Using 0x8021 Debug: link_PushPacket: Transmit proto 0x8021 Debug: m_enqueue: len = 2 IPCP: deflink: State change Req-Sent --> Ack-Sent Debug: m_dequeue: queue len = 2 Debug: link_Dequeue: Dequeued from queue 1, containing 1 more packets Debug: deflink: DescriptorWrite: wrote 16(16) to 1 Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 16(16) to 1 Debug: deflink: DescriptorRead: read 36/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0x8021 Debug: link_PullPacket: Despatch proto 0x8021 IPCP: deflink: RecvConfigAck(70) state = Ack-Sent IPCP: deflink: State change Ack-Sent --> Opened IPCP: deflink: LayerUp. IPCP: myaddr 212.35.189.239 hisaddr = 212.35.189.18 Debug: Delete 212.35.189.239 Debug: Add 212.35.189.239 -> 212.35.189.18 Debug: ReadSystem: Checking 212.35.189.239 (/etc/ppp/ppp.linkup). Debug: ReadSystem: Checking mycard (/etc/ppp/ppp.linkup). Debug: wrote 124: cmd = Delete!, dst = 0, gateway = 0 Debug: wrote 140: cmd = Add!, dst = 0, gateway = 12bd23d4 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0x8021 Debug: link_PullPacket: Despatch proto 0x8021 IPCP: deflink: RecvTerminateReq(3) state = Opened IPCP: deflink: LayerDown: 212.35.189.239 Debug: ReadSystem: Checking 212.35.189.239 (/etc/ppp/ppp.linkdown). Debug: ReadSystem: Checking mycard (/etc/ppp/ppp.linkdown). IPCP: Using trigger address 0.0.0.0 IPCP: deflink: SendTerminateAck(3) state = Opened Debug: fsm_Output Debug: 06 03 00 04 .... Debug: proto_LayerPush: Using 0x8021 Debug: link_PushPacket: Transmit proto 0x8021 Debug: m_enqueue: len = 1 IPCP: deflink: State change Opened --> Stopping Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0xc029 Debug: link_PullPacket: Despatch proto 0xc029 Warning: Unrecognised CBCP packet (code 5, length 4) PPp ON vega> Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 10(10) to 1 Debug: deflink: Still online Debug: deflink: DescriptorRead: read 17/2048 from 1 Debug: deflink: hdlc_LayerPull: fcs = f0b8 (good) Debug: proto_LayerPull: unknown -> 0xc021 Debug: link_PullPacket: Despatch proto 0xc021 Debug: fsm_Output Debug: 06 02 00 04 .... Debug: proto_LayerPush: Using 0xc021 Debug: link_PushPacket: Transmit proto 0xc021 Debug: m_enqueue: len = 1 Phase: deflink: open -> lcp IPCP: deflink: State change Stopping --> Starting IPCP: deflink: LayerFinish. IPCP: Connect time: 0 secs: 0 octets in, 0 octets out IPCP: : 16773 packets in, 18801 packets out IPCP: total 0 bytes/sec, peak 0 bytes/sec on Fri Jun 8 18:29:14 2001 IPCP: deflink: State change Starting --> Initial Phase: bundle: Terminate ppp ON vega> Debug: m_dequeue: queue len = 1 Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Debug: deflink: DescriptorWrite: wrote 18(18) to 1 Debug: deflink: Still online Debug: deflink: DescriptorRead: read 14/2048 from 1 Debug: deflink: online -> offline Phase: deflink: Carrier lost Phase: deflink: Disconnected! Phase: deflink: lcp -> logout Phase: deflink: Disconnected! Phase: deflink: logout -> hangup Debug: deflink: Close Phase: deflink: Connect time: 40 secs: 248 octets in, 236 octets out Phase: deflink: : 211231 packets in, 19051 packets out Phase: total 12 bytes/sec, peak 96 bytes/sec on Fri Jun 8 18:29:16 2001 Phase: deflink: hangup -> closed Phase: bundle: Dead ppp ON vega> q Connection closed root@big_brother# exit Script done on Fri Jun 8 18:29:27 2001 --------------BADE080333E00C87344B89B1-- To Unsubscribe: send mail to majordomo@FreeBSD.org with "unsubscribe freebsd-current" in the body of the message