Date: Wed, 24 Oct 2007 15:11:39 -0600 From: freebsd@dreamchaser.org To: Nikos Vassiliadis <nvass@teledomenet.gr> Cc: freebsd-questions@freebsd.org Subject: Re: user ppp and PPPoE bridging Message-ID: <471FB50B.1020909@dreamchaser.org> In-Reply-To: <200710241051.58064.nvass@teledomenet.gr> References: <471D5D11.3090201@dreamchaser.org> <200710231205.09703.nvass@teledomenet.gr> <471E37C0.5040702@dreamchaser.org> <200710241051.58064.nvass@teledomenet.gr>
next in thread | previous in thread | raw e-mail | index | archive | help
Nikos Vassiliadis wrote: > You said you had wrong encapsulation type. Did you make any progress? Yes. Changing the encapsulation type brought the line up, and things hobbled along... However, the line is dropped after a few minutes, apparently a result of not being able to determine line quality: Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: ** Too many LQR packets lost ** Oct 24 12:39:06 nightmare ppp[859]: tun0: LQM: deflink: Too many LQR packets lost Oct 24 12:39:06 nightmare ppp[859]: tun0: CCP: deflink: State change Stopped --> Closed Oct 24 12:39:06 nightmare ppp[859]: tun0: CCP: deflink: State change Closed --> Initial Oct 24 12:39:06 nightmare ppp[859]: tun0: LCP: deflink: LayerDown Oct 24 12:39:06 nightmare ppp[859]: tun0: LCP: deflink: State change Opened --> Starting Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: open -> lcp Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_UpdateMTU (5) Oct 24 12:39:06 nightmare ppp[859]: tun0: TCP/IP: route_UpdateMTU: Netif: 5 (tun0), dst 0.0.0.0/0, mtu 1500 Oct 24 12:39:06 nightmare ppp[859]: tun0: TCP/IP: route_UpdateMTU: Netif: 5 (tun0), dst 216.47.48.1, mtu 1500 Oct 24 12:39:06 nightmare ppp[859]: tun0: TCP/IP: route_UpdateMTU: Netif: 5 (tun0), dst ff01:5::/32, mtu 1500 Oct 24 12:39:06 nightmare ppp[859]: tun0: TCP/IP: route_UpdateMTU: Netif: 5 (tun0), dst ff02:5::/32, mtu 1500 Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: deflink: LayerDown: 12.32.44.142 Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: ReadSystem: Can't open /etc/ppp/ppp.linkdown. Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: deflink: State change Opened --> Starting Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: deflink: LayerFinish. Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: Connect time: 331 secs: 2253 octets in, 1584 octets out Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: 24 packets in, 25 packets out Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: total 11 bytes/sec, peak 275 bytes/sec on Wed Oct 24 12:34:43 2007 Oct 24 12:39:06 nightmare ppp[859]: tun0: IPCP: deflink: State change Starting --> Initial Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: bundle: Terminate Oct 24 12:39:06 nightmare ppp[859]: tun0: LCP: deflink: LayerFinish Oct 24 12:39:06 nightmare ppp[859]: tun0: LCP: deflink: State change Starting --> Initial Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: Disconnected! Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: lcp -> logout Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: Disconnected! Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: logout -> hangup Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: deflink: Close Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: Connect time: 332 secs: 3044 octets in, 2789 octets out Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: 70 packets in, 77 packets out Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: total 17 bytes/sec, peak 315 bytes/sec on Wed Oct 24 12:34:46 2007 Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: deflink: hangup -> closed Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_IfDelete (5) Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found 0.0.0.0/0 216.47.48.1 Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_IfDelete: Skip it (pass 0) Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found 216.47.48.1 12.32.44.142 Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_IfDelete: Skip it (pass 0) Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found ff01:5::/32 <AF_UNSPEC> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_IfDelete: Skip it (pass 0) Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found ff02:5::/32 <AF_UNSPEC> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: route_IfDelete: Skip it (pass 0) Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found 0.0.0.0/0 216.47.48.1 Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: wrote 124: cmd = Delete, dst = 0.0.0.0/0, gateway = <none> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found 216.47.48.1 12.32.44.142 Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: wrote 108: cmd = Delete, dst = 216.47.48.1, gateway = <none> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found ff01:5::/32 <AF_UNSPEC> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: wrote 148: cmd = Delete, dst = ff01:5::/32, gateway = <none> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: Found ff02:5::/32 <AF_UNSPEC> Oct 24 12:39:06 nightmare ppp[859]: tun0: Debug: wrote 148: cmd = Delete, dst = ff02:5::/32, gateway = <none> Oct 24 12:39:06 nightmare ppp[859]: tun0: Phase: bundle: Dead During initial protocol negotiation, it looks like come sort of compression is disallowed, but it doesn't seem like that should cause the line to be dropped later: Oct 24 12:33:35 nightmare ppp[859]: tun0: LCP: deflink: RecvProtocolRej(2) state = Opened Oct 24 12:33:35 nightmare ppp[859]: tun0: LCP: deflink: -- Protocol 0x80fd (Compression Control Protocol) was rejected! Oct 24 12:33:35 nightmare ppp[859]: tun0: CCP: deflink: State change Req-Sent --> Stopped Oct 24 12:33:35 nightmare ppp[859]: tun0: IPCP: deflink: RecvConfigRej(1) state = Ack-Sent Oct 24 12:33:35 nightmare ppp[859]: tun0: IPCP: COMPPROTO[6] 16 VJ slots with slot compression Oct 24 12:33:35 nightmare ppp[859]: tun0: IPCP: deflink: SendConfigReq(2) state = Ack-Sent And after the line is up, I see this: Oct 24 12:33:35 nightmare ppp[859]: tun0: Debug: deflink: PPPoE:ed1: Cannot determine bandwidth I presume this is a result of the lost LQR packets. Prior to closing the line, there are a number of what look like sync attempts; they look to me like they succeed: Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: deflink: DescriptorRead: read 14/2048 from 3 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: proto_LayerPull: unknown -> 0xc021 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: link_PullPacket: Despatch proto 0xc021 Oct 24 12:38:36 nightmare ppp[859]: tun0: LCP: deflink: RecvEchoRequest(30) state = Opened Oct 24 12:38:36 nightmare ppp[859]: tun0: LCP: deflink: SendEchoReply(30) state = Opened Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: fsm_Output Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: 0a 1e 00 0c 0b 58 fc 84 0b 58 fc 84 .....X...X.. Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: proto_LayerPush: Using 0xc021 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: link_PushPacket: Transmit proto 0xc021 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: m_enqueue: len = 1 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: m_dequeue: queue len = 1 Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: link_Dequeue: Dequeued from queue 1, containing 0 more packets Oct 24 12:38:36 nightmare ppp[859]: tun0: Debug: deflink: DescriptorWrite: wrote 14(14) to 3 Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: deflink: Output: Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: Magic: 0b58fc84 LastOutLQRs: 00000005 Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: LastOutPackets: 20464846 LastOutOctets: 46454d44 Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: PeerInLQRs: 00000005 PeerInPackets: 0000002f Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: PeerInDiscards: 00000000 PeerInErrors: 00000000 Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: PeerInOctets: 00000a6c PeerOutLQRs: 0000000b Oct 24 12:38:36 nightmare ppp[859]: tun0: LQM: PeerOutPackets: 00000049 PeerOutOctets: 00000ac2 The above summary appears to indicate that line quality requests are being transferred; so what's with the too many LQR packets lost message? Finally, Where does the initial IP address used in the negotiation come from? I did not specify specific IP address assignment, yet the request appears to have asked for 12.32.36.65 This is the IP of the other interface on the machine, and my ppp.conf has no mention of it. Can you also check the number of cells going out/coming in from the ATM > interface? I'm not sure what you mean by this... Thanks for any help; I'm going to be out for a day or so, so may be slow to reply Gary
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?471FB50B.1020909>