Thanks for the input Bjoern. No, neither the CPE's or our LNS's have had any recent software updates / configuration changes at all. Our provider on the other hand has been rolling out some major software upgrades across their network. We suspect that something in one of those updates no longer agrees with the way that the SonicWALLs negotiate their PPPoE sessions.
It's like the SonicWALL is stuck waiting for something that it no longer receives and so it sends a termination request and things start all over again. I've scanned through some other LNS logs and it does look like IPCP packets are being sent once every second from the LNS yes. 29 Jan 2017 00:06:35 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:36 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:37 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:38 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:39 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:40 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:41 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:42 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:43 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:44 l2tp-poll T13111-30001-62.24.203.99 S19863-17367 PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 [email protected] 29 Jan 2017 00:06:44 l2tp-rx T13111-30001-62.24.203.99 S19863-17367 PPP Rx FF03 C021:LCP 05 04 0004 TermReq [email protected] -----Original Message----- From: Bjoern A. Zeeb [mailto:[email protected]] Sent: 28 January 2017 23:41 To: Gareth Phillips <[email protected]> Cc: [email protected] Subject: Re: [uknof] SonicWALL PPPoE Issues over Talk-Talk WFTTC Circuits On 28 Jan 2017, at 19:48, Gareth Phillips wrote: > Thanks Neil. Fortunately I still have access to this most recent > SonicWALL box remotely via the backup ADSL interface. I've attached a > .pcap trace file from the PPPoE WAN interface that connects to the OR > modem and I've also attached some PPPoE debug logs from the SonicWALL. > Please let me know if you have any trouble receiving them. > > This happens with a whole range of different SonicWALL models, from > TZ100 / 200's to TZ105's and even the newest SOHO devices. Our LNS > that these sessions are hosted on is a Firebrick FB6202 Running FB6202 > Nestor+ (V1.35.019 2015-02-11T17:21:55) firmware. The logs off of > that for this particular FTTC PPPoE session from this SonicWALL are as > follows. We have checked and double-checked our RADIUS servers and > the username / password combos are definitely correct, so there's no > issue there. > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > request lts001.hex NMCIHW eth 0/1/17:101@FTTC1264195 > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > incoming NMCIHW eth 0/1/17:101@FTTC1264195 > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Init Rx C021:LCP 01 01 000E ConfReq 01:MRU 04 1492 05:MAGIC 06 > 29:97:fe:3b [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Last Rx C021:LCP 01 01 000E ConfReq 01:MRU 04 1492 05:MAGIC 06 > 29:97:fe:3b [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Last Tx C021:LCP 01 01 000F ConfReq 03:AUTH 05 c2:23:05 05:MAGIC > 06 0a:d4:9c:d4 [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Auth name > 6d:63:6d:66:6d:74:32:40:63:6f:6e:6e:65:63:74:2e:63:6c:65:61:72:73:74:7 > 2:65:61:6d:67:72:6f:75:70:2e:63:6f:2e:75:6b > [[email protected]] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Auth chal 15 57:7d:f2:7f:ea:06:6c:ff:f8:a8:3c:7d:f9:6f:59:a6 > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Auth response 8c:8c:b0:d3:76:4e:b4:5c:de:60:76:80:83:9c:78:cf > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > connect [email protected] 39956000/9999000bps mtu1492 > 28 Jan 2017 19:24:22 radius-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx C223:CHAP 03 15 0004 [email protected] PPP Auth done. The CPE log (unfortunately timestamps are not in synch) is a bit weird with regards to the CHAP Success message. > 28 Jan 2017 19:24:22 radius-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx C021:LCP 01 01 000E ConfReq 05:MAGIC 06 0a:d4:9c:d4 01:MRU 04 > 1472 [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Rx FF03 8021:IPCP 01 01 0016 ConfReq 03:IP 06 0.0.0.0 81:DNS1 06 > 0.0.0.0 83:DNS2 06 0.0.0.0 [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx 8021:IPCP 03 01 0016 ConfNak 03:IP 06 46.17.214.185 81:DNS1 06 > 185.23.52.131 83:DNS2 06 185.23.52.132 [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Rx FF03 8057:IPV6CP 01 01 000E ConfReq 01:I/F 0A > c2:ea:e4:ff:fe:7a:16:e6 [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx C021:LCP 08 01 0014 ProtoRej 8057 01 01 000E ConfReq 01:I/F 0A > c2:ea:e4:ff:fe:7a:16:e6 [email protected] You reject IPV6CP. That’s fine. CPE stops on IPV6CP. > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Rx FF03 C021:LCP 01 02 000E ConfReq 01:MRU 04 1492 05:MAGIC 06 > 29:97:fe:3b [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx C021:LCP 02 02 000E ConfAck 01:MRU 04 1492 05:MAGIC 06 > 29:97:fe:3b [email protected] > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Rx FF03 C021:LCP 02 01 000E ConfAck 05:MAGIC 06 0a:d4:9c:d4 01:MRU > 04 1472 [email protected] LCP seems done. Not seen any missing packets. CPE ACKs the last bit from your early request, so CPE should be happy as well with LCP UP. > 28 Jan 2017 19:24:22 l2tp-rx T13092-51756-62.24.203.227 S17150-9461 > PPP Tx 8021:IPCP 01 00 000A ConfReq 03:IP 06 62.24.191.98 > [email protected] You tell CPE your IP address. The pcap on the other end shows this being received way too often, re-send once a second; this end doesn’t show this. But the CPE never ACKs. And the CPE also doesn’t send you a request for its local IP address end. Seems the state machine on the CPE side is stuck? Also can you confirm that your LNS is actually re-sending the IPCP packet <n> times every second? > 28 Jan 2017 19:24:22 l2tp-rx T10838-3606-62.24.203.91 S24816-43992 PPP > Rx FF03 C021:LCP 08 B1 0040 ProtoRej AAAA 03 00 00 00 08 06 00 13 08 > 00 00 00 00 08 04 00 00 00 71 q 72 r 73 s 74 t FD 12 A5 AD BA 38 8 8E > BD FB 55 U 50 P 18 10 00 F8 E0 00 00 17 03 03 00 50 P D6 07 80 20 81 > D2 6F o 57 W B8 CC 9C 2E . 0F > 28 Jan 2017 19:24:22 l2tp-rx T10838-3606-62.24.203.91 S43511-28544 PPP > Rx FF03 C021:LCP 08 E9 001C ProtoRej AAAA 03 00 00 00 08 06 00 13 08 > 00 00 00 00 08 04 00 00 00 71 q 72 r 73 s 74 t Whatever those are I am confused about; Someone cleverly prints the ASCII parts along with the hex values it seems. If T/Sxxxx-xxxxx is the tunnel/session ID from L2TP this is a different session anyway? The CPE on the remote end at best logs Auth done (even though it is seems grumpy about it), LCP up, but never logs anything about IPCP (whatever they’d call it). Not sure if we see the same “conversation” there though. Did the CPEs get a software update lately?
