Bellsouth/AT&T PPPoE broken

kingfisher

Here is my log -

Last 50 system log entries
Dec 27 16:39:06 mpd: IPADDR xxx.xxx.xxx.xxx
Dec 27 16:39:06 mpd: xxx.xxx.xxx.xxx is OK
Dec 27 16:39:06 mpd: [pppoe] IPCP: SendConfigReq #126
Dec 27 16:39:06 mpd: PRIDNS 205.152.37.23
Dec 27 16:39:06 mpd: [pppoe] IPCP: rec'd Configure Nak #126 link 0 (Ack-Sent)
Dec 27 16:39:06 mpd: IPADDR xxx.xxx.xxx.xxx
Dec 27 16:39:06 mpd: xxx.xxx.xxx.xxx is OK
Dec 27 16:39:06 mpd: [pppoe] IPCP: not converging
Dec 27 16:39:06 mpd: [pppoe] IPCP: parameter negotiation failed
Dec 27 16:39:06 mpd: [pppoe] IPCP: state change Ack-Sent –> Stopped
Dec 27 16:39:06 mpd: [pppoe] IPCP: LayerFinish
Dec 27 16:39:06 mpd: [pppoe] bundle: CLOSE event in state OPENED
Dec 27 16:39:06 mpd: [pppoe] closing link "pppoe"…
Dec 27 16:39:06 mpd: [pppoe] link: CLOSE event
Dec 27 16:39:06 mpd: [pppoe] LCP: Close event
Dec 27 16:39:06 mpd: [pppoe] LCP: state change Opened –> Closing
Dec 27 16:39:06 mpd: [pppoe] LCP: phase shift NETWORK –> TERMINATE
Dec 27 16:39:06 mpd: [pppoe] setting interface ng0 MTU to 1500 bytes
Dec 27 16:39:06 mpd: [pppoe] up: 0 links, total bandwidth 9600 bps
Dec 27 16:39:06 mpd: [pppoe] IPCP: Down event
Dec 27 16:39:06 mpd: [pppoe] IPCP: state change Stopped –> Starting
Dec 27 16:39:06 mpd: [pppoe] IPCP: LayerStart
Dec 27 16:39:06 mpd: [pppoe] closing link "pppoe"…
Dec 27 16:39:06 mpd: [pppoe] LCP: SendTerminateReq #230
Dec 27 16:39:06 mpd: [pppoe] LCP: LayerDown
Dec 27 16:39:06 mpd: [pppoe] bundle: OPEN event in state CLOSED
Dec 27 16:39:06 mpd: [pppoe] opening link "pppoe"…
Dec 27 16:39:06 mpd: [pppoe] link: CLOSE event
Dec 27 16:39:06 mpd: [pppoe] LCP: Close event
Dec 27 16:39:06 mpd: [pppoe] link: OPEN event
Dec 27 16:39:06 mpd: [pppoe] LCP: Open event
Dec 27 16:39:06 mpd: [pppoe] LCP: state change Closing –> Stopping
Dec 27 16:39:06 mpd: [pppoe] LCP: rec'd Terminate Ack #230 link 0 (Stopping)
Dec 27 16:39:06 mpd: [pppoe] LCP: state change Stopping –> Stopped
Dec 27 16:39:06 mpd: [pppoe] LCP: phase shift TERMINATE –> ESTABLISH
Dec 27 16:39:06 mpd: [pppoe] LCP: LayerFinish
Dec 27 16:39:06 mpd: [pppoe] device: CLOSE event in state UP
Dec 27 16:39:06 mpd: [pppoe] device is now in state CLOSING
Dec 27 16:39:06 mpd: [pppoe] device: DOWN event in state CLOSING
Dec 27 16:39:06 mpd: [pppoe] device is now in state DOWN
Dec 27 16:39:06 mpd: [pppoe] link: DOWN event
Dec 27 16:39:06 mpd: [pppoe] LCP: Down event
Dec 27 16:39:06 mpd: [pppoe] LCP: state change Stopped –> Starting
Dec 27 16:39:06 mpd: [pppoe] LCP: phase shift ESTABLISH –> DEAD
Dec 27 16:39:06 mpd: [pppoe] LCP: LayerStart
Dec 27 16:39:06 mpd: [pppoe] device: OPEN event in state DOWN
Dec 27 16:39:06 mpd: [pppoe] pausing 6 seconds before open
Dec 27 16:39:06 mpd: [pppoe] device is now in state DOWN
Dec 27 16:39:06 mpd: [pppoe] device: OPEN event in state DOWN
Dec 27 16:39:06 mpd: [pppoe] device is now in state DOWN

Ryan

My DSL is doing the same. I get back from Christmas and I got a gift from AT$T. The gift of aggrivation. Gee thanks. If someone knows how to fix this, Please help!!!

sullrich

Can someone get a tcpdump and dump all packets and then send it to us?

It appears to be failing around:

Dec 27 16:39:06 mpd: [pppoe] IPCP: not converging
Dec 27 16:39:06 mpd: [pppoe] IPCP: parameter negotiation failed

kingfisher

I am not going to be able to, we have switched out the eight routers that affected with temporary replacements. These are all at live locations.

Interestingly enough, this seems to be a widespread but not total. I have a pfsense @ home on a BellSouth account and it is still up and running. 10 miles away I have 2 clients that both have a Monowall and both were affected.

To sum up, we have a total of 8 locations all over Atlanta that were affected. It all started last Friday with some on Monday and one on Wednesday. It seems like they are upgrading something a little at a time.

Ryan

I am happy to give a tcpdump if someone will explain how to do it. I have 2 dsl accounts. 1 in bridge mode (now not working) and 1 in router mode. I am happy to help however i can, but i am rather ignorant as to how

sullrich

Has anyone called them to inquire about these changes?

Ryan

I am sure someone there has a clue, but i don't think they let those people talk to customers on the phone. In other words, yes I have called and they say there is nothing wrong. the problem must be with our router. ???

sullrich

@Ryan:

I am sure someone there has a clue, but i don't think they let those people talk to customers on the phone. In other words, yes I have called and they say there is nothing wrong. the problem must be with our router. ???

Yes, but what do they say when you tell them it worked FINE until their changes a week ago?

I would put some heat on them. Lord knows that if my ISP did this to me, I would become their worst nightmare in no time.

megalodon

@sullrich:

Yes, but what do they say when you tell them it worked FINE until their changes a week ago?

I would put some heat on them. Lord knows that if my ISP did this to me, I would become their worst nightmare in no time.

Basically what happened in my case: I told them that everything was working fine until a couple of days ago. Asked if they changed something on their end. "My records don't show any changes…" They had me bypass the router completely and connect directly from XP. When this worked, they told me "it must be a problem with your router. What brand is it? Linksys? Netgear?" flips page in script I couldn't get them to pass me along to anyone more clueful.

I can probably get a trace of the pppoe connection. However, I'm not sure how to go about it, since I don't have a non-switch hub that I can use to snoop the traffic. Any suggestions?

sullrich

Yeah, typical huge companies. That's really bad to hear.

lksimps

This is also happening to our at&t/bellsouth dsl, north of atlanta.

megalodon

I've spent some time doing some investigation on this issue. I set up freebsd on an old machine I had lying around to debug the problem. The first thing I tried was to try to establish a pppoe link using the more recent mpd4 instead of the mpd 3.18 that m0n0wall uses. Unfortunately, that didn't work; it failed with a similar error.

Next I tried capturing the network traffic to see what was going on. Here are the results. The first link is MPD 3.18 on freebsd, which is showing the problem. The second is a capture from the pppoe client on XP, which works.
http://attenuated.org/~greg/mpd/mpd_notworking.txt
http://attenuated.org/~greg/mpd/xp_working.txt

After comparing the traffic, it seems that after getting the NAK from the server, MPD is not filling out the ip address from the NAK in the subsequent request. I am determined to get this working, so I am going to try to debug the problem and hopefully come up with a patch that fixes the problem.

sullrich

@megalodon:

I've spent some time doing some investigation on this issue. I set up freebsd on an old machine I had lying around to debug the problem. The first thing I tried was to try to establish a pppoe link using the more recent mpd4 instead of the mpd 3.18 that m0n0wall uses. Unfortunately, that didn't work; it failed with a similar error.

Next I tried capturing the network traffic to see what was going on. Here are the results. The first link is MPD 3.18 on freebsd, which is showing the problem. The second is a capture from the pppoe client on XP, which works.
http://attenuated.org/~greg/mpd/mpd_notworking.txt
http://attenuated.org/~greg/mpd/xp_working.txt

After comparing the traffic, it seems that after getting the NAK from the server, MPD is not filling out the ip address from the NAK in the subsequent request. I am determined to get this working, so I am going to try to debug the problem and hopefully come up with a patch that fixes the problem.

Great, thanks! We surely will include it if you can get it working.

jcuervo

You're the man, megalodon. I'm eagerly watching this thread for a fix. I'd try to work on it myself, but I honestly don't know where to begin!

ptaylor

When I started this thread I suspected an ISP change, and it appears that it was..

One other piece of info here is that I have a static IP Address. Not sure if this is only affecting people with statics or what…

From looking at the TCP dump info, posted above (Sorry if this is redundant - I just posted it because it helped me "think it through", and I thought others might also be interested):

Both sides get through CHAP and move into configuration negotiations. Eventually, they both get to the same basic point: Frame 16 in the MPD file looks essentially the same as frame 22 in the XP file. In both cases, the next frame AT&T sends is a Nak containing the IP Address and Primary DNS server IP. MPD replies with a frame containing the Primary DNS server IP. XP replies with a frame containing the IP Address and Primary DNS server IP.

In looking at the way this negotiation has been going up to this point, it appears that options have been rejected by the ISP until it gets down to these two - The IP Address and primary DNS server.

To sum up: AT&T is expecting to send the IP Address and Primary DNS server to the client, and that they expect the client to echo that information back to them (a confirmation, I suppose) before they will give an Ack.

Next, I downloaded the source of MPD 3.18. I'm having a bit of a time following it, as I haven't done much C programming in many years, but this is what I've gathered from it:

ipcp.c appears to be the most closely related file that I could track down.
Two constants, TY_PRIMARYDNS and TY_IPADDR, look to be deeply involved. A function on line 339 is called IpcpBuildConfigReq. Inside that function, a comment on line 364 states that it will "Add option if we desire it and it hasn't been rejected". That leads me to believe that MPD mistakenly believes the TY_IPADDR option has been rejected by the ISP, so it isn't offering that anymore.

Further looking at the code makes me think we might be able to jury-rig it to work by just commenting out line 344, which is an "if" statement. This would cause line 345 to always be executed, which I think would cause the IP Address to always be in the request.

Unfortunately, I don't have a pfSense test system to try it out on. Is anyone with an appropriate system game on trying out this mod to ipcp.c? That, of course, assumes that pfSense is using this version of MPD.

ptaylor

On second thought, this might be a safer "Hack":

Insert this code in ipcp.c, within the IpcpBuildConfigReq function, just about line 346:

/* Hack for BellSouth/AT&T PPPoE behavior */
if (fp->reqid == (FSM_MAXNAK - 1))
cp = FsmConfValue(cp, TY_IPADDR, 4, &ipcp->want_addr.s_addr);

If I've read the code correctly, that should wait until the last attempt before it would normally fail, at which time it would insert the IP Address field in the Configuration Request, regardless of if it has been previously rejected. This would be less likely to break MPD, if this code is used for other purposes. (I believe FSM_MAXNAK is a valid variable here, but as I indicated above, my C is rusty.)

sullrich

Warning: Object directory not changed from original /usr/ports/net/mpd/work/mpd-3.18/src
cc -O2 -fno-strict-aliasing -pipe -DPATH_CONF_DIR="/usr/local/etc/mpd" -DSYSLOG_FACILITY=LOG_DAEMON -DMPD_VERSION='"3.18 (root@freebsd6.geekgod.com 01:13 31-Dec-2007)"' -g -Wall -Wcast-align -Wchar-subscripts -Wformat -Winline -Wmissing-declarations -Wmissing-prototypes -Wnested-externs -Wpointer-arith -Wwrite-strings -DPHYSTYPE_MODEM -DPHYSTYPE_UDP -DPHYSTYPE_NG_SOCKET -DPHYSTYPE_PPTP '-DPPTP_VENDOR_NAME="FreeBSD mpd-3.18"' -DPHYSTYPE_PPPOE -DENCRYPTION_DES -DENCRYPTION_MPPE -DCOMPRESSION_MPPC -c ipcp.c
ipcp.c: In function IpcpBuildConfigReq': ipcp.c:352: error: FSM_MAXNAK' undeclared (first use in this function)
ipcp.c:352: error: (Each undeclared identifier is reported only once
ipcp.c:352: error: for each function it appears in.)
*** Error code 1

Stop in /usr/ports/net/mpd/work/mpd-3.18/src.

ptaylor

I must have been tired last night. In ipcp.c, it includes fsm.h, but that constant is defined on line 23 of fsm.c.

We could move the Definition of that constant from fsm.c to fsm.h. If (for some odd reason) that didn't work, we could always hard-wire the if statement that I suggested to 9 instead of (FSM_MAXNAK - 1).. (Yea, ugly, I know)

Or just comment out the first "if" in that function (line 344 on my copy):
if (!IPCP_REJECTED(ipcp, TY_IPADDR) || ipcp->want_addr.s_addr == 0)

so that the next line is always executed:
cp = FsmConfValue(cp, TY_IPADDR, 4, &ipcp->want_addr.s_addr);

megalodon

I spent some time looking at the code last night, and I think I know why it's failing. The problem section is definitely this part in ipcp.c:


  /* Put in my desired IP address */
  if (!IPCP_REJECTED(ipcp, TY_IPADDR) || ipcp->want_addr.s_addr == 0)
    cp = FsmConfValue(cp, TY_IPADDR, 4, &ipcp->want_addr.s_addr);

You can hack it to make it work by removing the if statement so that the FsmConfValue line is always executed. The if statement is essentially checking to see if the IPADDR option has been rejected by the server. If not, it should add its desired ipaddr to the request.

The reason this is failing is because Bellsouth is rejecting the SECONDARYDNS option, which has a value of 131. MPD stores the rejected options in a bit mask. Look at the IPCP_REJECTED and IPCP_PEER_REJ macros towards the top of ipcp.c.

The problem is that when you left shift 131 places (the value of TY_SECONDARYDNS), it's going to wrap the peer_reject variable a bunch of times, with the end result the same as if you had shifted to the left by 3, which just so happens to be the value of TY_IPADDR.

So, to make a long story short, if the server rejects the SECONDARYDNS option, the MPD code thinks the IPADDR option has been rejected. The way it keeps track of rejected options is fundamentally broken. I could probably come up with a patch to redo the IPCP_REJECTED/IPCP_PEER_REJ macros within a couple of days (unless there is an MPD dev reading this, who could probably do it a lot faster, and integrate it into the main MPD codebase)

The question I have is: is it really so bad to take out that if statement so that the desired ipaddr is always added to the request? I can't think of a reason why the server would ever reject the IPADDR option. I don't really know the ins and outs of IPCP though.

megalodon

@ptaylor:

If I've read the code correctly, that should wait until the last attempt before it would normally fail, at which time it would insert the IP Address field in the Configuration Request, regardless of if it has been previously rejected. This would be less likely to break MPD, if this code is used for other purposes. (I believe FSM_MAXNAK is a valid variable here, but as I indicated above, my C is rusty.)

I'm not sure this is the right approach… it should actually be putting the IP in the first request after the first NAK. This is what XP's PPPoE client does:

http://attenuated.org/~greg/mpd/xp_working.txt