LCP Failure with noauth

[c***@gmail.com]

Can you help me understand the reason the LCP is failing...there are 2
logs below to help you understand what is happening. This is for a
pppoe-server session but the failure is happening in the pppd setup (or
so I think).

Here's my current pppoe-server-options (which are used as if they were
in ppp/options):
noauth
debug
ms-dns 192.168.1.1
logfile /var/log/pppd.log

Here's the /var/log/pppd.log with windows client:
using channel 153
Using interface ppp0
Connect: ppp0 <--> /dev/pts/22
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 21 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 23 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 25 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 27 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
LCP: timeout sending Config-Requests
Connection terminated.
using channel 154
Using interface ppp0
Connect: ppp0 <--> /dev/pts/23
Waiting for 2 child processes...
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60
-s', pid 8839
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60
-s', pid 8831

And if I remove the -s option:

using channel 156
Using interface ppp0
Connect: ppp0 <--> /dev/pts/25
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x1 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x1 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sending SIGTERM to process 8863
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x3 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x3 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x5 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x5 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x7 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x7 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
LCP: timeout sending Config-Requests
Connection terminated.
using channel 157
Using interface ppp0
Connect: ppp0 <--> /dev/pts/26
Waiting for 2 child processes...
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60',
pid 8903 script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S '
-T 60', pid 8895sent [LCP ConfReq id=0x2 <magic 0x8838f39c>]

[James Carlson]

Post by c***@gmail.com
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 21 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...

Either the peer is attempting to encode the PPPoE packets using AHDLC
(which would be weird) or your local PPPoE implementation has a bug.

Post by c***@gmail.com
Connect: ppp0 <--> /dev/pts/23

I think that has a lot to do with it.

Post by c***@gmail.com
using channel 156
Using interface ppp0
Connect: ppp0 <--> /dev/pts/25
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x1 <mru 1480> <magic 0x20e927fe> <callback CBCP>]

This looks slightly more normal.

Post by c***@gmail.com
sent [LCP ConfRej id=0x1 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sending SIGTERM to process 8863

What is that about SIGTERM? That doesn't look like a pppd message to
me.

Post by c***@gmail.com
rcvd [LCP ConfReq id=0x3 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x3 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]

It looks like the peer cannot see the packets you're sending. Again,
that points to problems with in the PPPoE implementation, not pppd.

[k***@gmail.com]

Hi,

The problem I find from the first log is that the client
sends LCP packet with an invalid code or protocol (0x7eff as per your
log).
When the PPP is in opened state it will send a Protocol-Rej packet. But
in
your case the opened state is not reached. That is why you get the
message
"Discarded non-LCP packet when LCP not open" in the log. PPP reaches
opened state only when Config-Ack has been both sent and receive
(Refer RFC 1661).

Now with the second log the client sends some callback options in its
LCP
Config-Req. But the server doesn't support that option. So, it sends a
Config-Rej
packet to the client. In that case the client should again send a
Config-Req
without that option. But in your case, from the log I note that it is
sending
the Config-Req with the same option. So the pppd fails.

Note: I am not sure whether pppd in linux has implemented RFC 1570.
Callback is defined in that RFC (RFC for LCP extensions).

You probably might be running a windows client or simulating the
process (for the
second case). If so stop sending the callback option with the
Config-Req.

Its not the problem with the pppoe-server.

Regards,
Sriram K

Post by c***@gmail.com
Can you help me understand the reason the LCP is failing...there are 2
logs below to help you understand what is happening. This is for a
pppoe-server session but the failure is happening in the pppd setup (or
so I think).
Here's my current pppoe-server-options (which are used as if they were
noauth
debug
ms-dns 192.168.1.1
logfile /var/log/pppd.log
using channel 153
Using interface ppp0
Connect: ppp0 <--> /dev/pts/22
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 21 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 23 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 25 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
rcvd [proto=0x7eff] 7d 23 c0 21 7d 21 7d 27 7d 20 7d 31 7d 21 7d 24 7d
25 c8 7d 25 7d 26 7d 3f 83 7d 20 66 7d 2d 7d ...
Discarded non-LCP packet when LCP not open
sent [LCP ConfReq id=0x1 <magic 0xe188cc35>]
LCP: timeout sending Config-Requests
Connection terminated.
using channel 154
Using interface ppp0
Connect: ppp0 <--> /dev/pts/23
Waiting for 2 child processes...
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60
-s', pid 8839
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60
-s', pid 8831
using channel 156
Using interface ppp0
Connect: ppp0 <--> /dev/pts/25
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x1 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x1 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sending SIGTERM to process 8863
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x3 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x3 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x5 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x5 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
rcvd [LCP ConfReq id=0x7 <mru 1480> <magic 0x20e927fe> <callback CBCP>]
sent [LCP ConfRej id=0x7 <callback CBCP>]
sent [LCP ConfReq id=0x1 <magic 0x65589cc4>]
LCP: timeout sending Config-Requests
Connection terminated.
using channel 157
Using interface ppp0
Connect: ppp0 <--> /dev/pts/26
Waiting for 2 child processes...
script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S ' -T 60',
pid 8903 script /usr/sbin/pppoe -n -I eth1 -e 1:00:0a:e4:de:2e:bf -S '
-T 60', pid 8895sent [LCP ConfReq id=0x2 <magic 0x8838f39c>]