Skip site navigation (1)Skip section navigation (2)
Date:      Fri, 08 Jun 2001 18:41:35 +0300
From:      Maxim Sobolev <sobomax@FreeBSD.ORG>
To:        Brian Somers <brian@Awfulhak.org>
Cc:        brian@FreeBSD.ORG, current@FreeBSD.ORG
Subject:   Re: Unrecognised CBCP packet [strange problems with ppp(8)]
Message-ID:  <3B20F22E.8004BE28@FreeBSD.org>
References:  <200105290823.f4T8NYM34180@hak.lan.Awfulhak.org>

next in thread | previous in thread | raw e-mail | index | archive | help
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 <brian@Awfulhak.org>                        <brian@[uk.]FreeBSD.org>
>       <http://www.Awfulhak.org>;                   <brian@[uk.]OpenBSD.org>
> 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




Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?3B20F22E.8004BE28>