LCP Failure with noauth

[cfou...@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]

cfou...@gmail.com writes:
> 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.

> Connect: ppp0 <--> /dev/pts/23

I think that has a lot to do with it.

> 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>]

This looks slightly more normal.

> 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.

> 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.

--
James Carlson, KISS Network <james.d...@sun.com>
Sun Microsystems / 1 Network Drive 71.232W Vox +1 781 442 2084
MS UBUR02-212 / Burlington MA 01803-2757 42.496N Fax +1 781 442 1677

[ksri...@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