pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after pppoe

pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after pppoe

[Thomas Glanzmann]

Hello,
I have a openvpn connection using port 5000 udp. One openvpn endpoint
uses pppoe, the otherone is connected using ethernet. After a reboot the
openvpn works. However if the pppoe session is manually or due to 24
hour disconnect terminated, the openvpn connection stops working.
Strange is that I can see the inbound udp packets on the ethernet device
inside the pppoe session, but I can no longer see them on ppp0. When I
reboot the system, it continues working till the next hangup.

        I tried so far the following:

                - I'm running debian stable, upgraded the kernel to:
                  '4.9.0-0.bpo.2-amd64', no change
                - I upgraded pppd to 'ppp_2.4.7-1+4_amd64.deb', no
                  change
                - I tried to flush the conntrack table, no change
                - I tried to change the udp port, no change.
                - I tried to enable debug and kdebug 4 in ppp without any
                  additional logging.
                - Sniffed the pppoe traffic and verified the ipv4 and udp header
                  checksums using wireshark, they're correct.
                - net.ipv4.conf.ppp0.log_martians = 1 and looked in dmesg, nothing.

Sniffing on 217.92.232.50 eth1 (connection to the dsl modem) I can see packets
orginating from 217.92.232.50 as well as from 88.198.215.20. [1]

infra) [~/.www/tmp/ppp] tcpdump -r eth1.pcap -s 0 -n | grep UDP | grep 5000
reading from file eth1.pcap, link-type EN10MB (Ethernet)
20:30:53.439370 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 68
20:30:53.439391 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:53.439406 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:54.438912 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:55.438919 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:56.438919 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:57.438945 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:58.438914 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:59.438910 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:00.438912 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:01.438911 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:02.438945 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:03.438935 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:03.438954 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 68
--
20:31:03.680762 PPPoE  [ses 0xb5e0] IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
--
20:31:04.438845 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:05.438913 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:06.438917 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:07.438922 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:08.438914 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:09.438925 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:10.438914 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:11.438909 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:12.438911 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:13.438938 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:13.438955 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 68
--
20:31:13.456015 PPPoE  [ses 0xb5e0] IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:13.456521 PPPoE  [ses 0xb5e0] IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
--
20:31:14.438915 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:15.438916 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:16.438934 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:17.438946 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:18.438913 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:19.438913 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:20.438883 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:21.438913 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:22.438912 PPPoE  [ses 0xb7b3] IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
--
20:31:23.145767 PPPoE  [ses 0xb5e0] IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:23.146251 PPPoE  [ses 0xb5e0] IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68

Sniffing on 217.92.232.50 at the same time on ppp0, I can only see packets
originating 217.92.232.50, but not from 88.198.215.20: [2]

(infra) [~/.www/tmp/ppp] tcpdump -r ppp0.pcap -s 0 -n
reading from file ppp0.pcap, link-type LINUX_SLL (Linux cooked)
20:30:54.438907 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:55.438914 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:56.438914 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:57.438939 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:58.438908 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:30:59.438905 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:00.438907 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:01.438906 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:02.438938 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:03.438930 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:03.438952 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 68
20:31:04.438841 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:05.438908 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:06.438912 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:07.438917 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:08.438909 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:09.438920 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:10.438909 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:11.438904 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:12.438906 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:13.438933 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:13.438953 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 68
20:31:14.438910 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:15.438911 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:16.438929 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:17.438941 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:18.438908 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:19.438909 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:20.438878 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148
20:31:21.438908 IP 217.92.232.50.5000 > 88.198.215.20.5000: UDP, length 148

Sniffing at the same time on 88.198.215.20, I can see the packets going out,
but no packets going in. All other traffic (tcp; icmp) works like a charm: [3]

(infra) [~/.www/tmp/ppp] tcpdump -r bond0.997.pcap -s 0 -n
reading from file bond0.997.pcap, link-type EN10MB (Ethernet)
20:30:51.432023 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:30:51.432053 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:03.653245 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:13.428410 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:13.428443 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:23.118177 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68
20:31:23.118204 IP 88.198.215.20.5000 > 217.92.232.50.5000: UDP, length 68

I'm grateful for any pointers how to debug this problem further or for ideas
which can be used to resolve the issue. Currently I switched to tcp, which is
working perfectly fine. All other traffic appears to work fine over the link
(http, https, dns, ssh, pop3s, imaps, ...).

[1] https://thomas.glanzmann.de/tmp/ppp/eth1.pcap (6 MB)
[2] https://thomas.glanzmann.de/tmp/ppp/ppp0.pcap
[3] https://thomas.glanzmann.de/tmp/ppp/bond0.997.pcap

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello Michael,

* Michael Richardson <mcr@sandelman.ca> [2017-04-10 22:02]:

> Are you using openvpn with a 0.0.0.0/0 route?

no, I don't.

> Can you post your routing table when it is working, and when it is
> not?

The routing table is the same:

(generate-03) [~] ip r s
default dev ppp0  scope link
172.17.0.0/24 via 172.17.0.254 dev falkenstein
172.17.0.254 dev falkenstein  proto kernel  scope link  src 192.168.168.1
172.19.0.0/24 via 172.19.0.254 dev eclogicnew
172.19.0.254 dev eclogicnew  proto kernel  scope link  src 192.168.168.1
172.20.0.0/24 via 172.19.0.254 dev eclogicnew
192.168.168.0/24 dev eth0  proto kernel  scope link  src 192.168.168.1
217.5.98.12 dev ppp0  proto kernel  scope link  src 217.92.232.50

The real interesting question is, why do perfectly healthy ip/udp packets from
within the pppoe session drop before reaching ppp0? Why does it only happen
after one hangup?

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Michael Richardson]

Thomas Glanzmann <thomas@glanzmann.de> wrote:
    > The real interesting question is, why do perfectly healthy ip/udp
    > packets from within the pppoe session drop before reaching ppp0? Why
    > does it only happen after one hangup?

It sounds like they aren't part of the correct PPPoE session to me.
As if the other end is not killing it's PPP session when the new one forms.

--
]               Never tell me the odds!                 | ipv6 mesh networks [
]   Michael Richardson, Sandelman Software Works        | network architect  [
]     mcr@sandelman.ca  http://www.sandelman.ca/        |   ruby on rails    [

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello Michael,

> It sounds like they aren't part of the correct PPPoE session to me.
> As if the other end is not killing it's PPP session when the new one forms.

wow. You nailed it. Thank you for identifying the root cause. I'll open a call
with German Telekom to fix there ppp endpoint.

(x1) [~/pcaps] tshark -nr eth1.pcap -T fields -e 'pppoe.session_id' | sort -u

0x0000b53b
0x0000b5e0
0x0000b7b3

These are exactly the packages I was missing:

(x1) [~/pcaps] tshark -nr eth1.pcap -Y 'pppoe.session_id = 0x0000b5e0'
 2938  12.176318 88.198.215.20 → 217.92.232.50 UDP 118 5000 → 5000 Lenh
 5247  21.951571 88.198.215.20 → 217.92.232.50 UDP 118 5000 → 5000 Lenh
 5248  21.952077 88.198.215.20 → 217.92.232.50 UDP 118 5000 → 5000 Lenh
 5802  31.641323 88.198.215.20 → 217.92.232.50 UDP 118 5000 → 5000 Lenh
 5803  31.641807 88.198.215.20 → 217.92.232.50 UDP 118 5000 → 5000 Lenh

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello Michael,
small follow up. Taking the link down on my site seems to reset the
pppoe session on the remote site. This symptom was probably triggered by
the reboot of the server.

--
(generate-03) [~] ping -c 5 172.17.0.254
PING 172.17.0.254 (172.17.0.254) 56(84) bytes of data.

--- 172.17.0.254 ping statistics ---
5 packets transmitted, 0 received, 100% packet loss, time 4092ms

(generate-03) [~] poff; ifconfig eth1 down; sleep 10; ifconfig eth1 up; pon dsl-provider
Plugin rp-pppoe.so loaded.
(generate-03) [~] ping -c 5 172.17.0.254
PING 172.17.0.254 (172.17.0.254) 56(84) bytes of data.
64 bytes from 172.17.0.254: icmp_seq=1 ttld timeA.5 ms
64 bytes from 172.17.0.254: icmp_seq=2 ttld timeA.1 ms
64 bytes from 172.17.0.254: icmp_seq=3 ttld timeA.4 ms
64 bytes from 172.17.0.254: icmp_seq=4 ttld timeA.2 ms
64 bytes from 172.17.0.254: icmp_seq=5 ttld timeA.4 ms

--- 172.17.0.254 ping statistics ---
5 packets transmitted, 5 received, 0% packet loss, time 4005ms
rtt min/avg/max/mdev = 41.194/41.377/41.579/0.148 ms
--

Also my ssh session survives, which it previously did not. Thank you again.

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello Michael,
another small follow-up in pppd 2.4.7 is [1]. When I manually hangup
with this patch, all pending pppoe sessions are terminated as well.

[1] https://github.com/paulusmack/ppp/commit/cd2c14f998c57bbe6a01dc5854f2763c0d7f31fb

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello everyone,

* Thomas Glanzmann <thomas@glanzmann.de> [2017-04-11 18:01]:
> another small follow-up in pppd 2.4.7 is [1]. When I manually hangup
> with this patch, all pending pppoe sessions are terminated as well.

> [1] https://github.com/paulusmack/ppp/commit/cd2c14f998c57bbe6a01dc5854f2763c0d7f31fb

another small follow up. This does not work always. Tonight at 03:00 I
hangup and the VPN did not come backup up. But this works reliable;

ifconfig eth1 down; sleep 10; ifconfig eth1 up; pon dsl-provider

Cheers,
        Thomas

Re: pppoe encapsulated udp packets which appear on ethernet disappear between pppoe and ppp0 after p

[Thomas Glanzmann]

Hello Michael,

> I'll be curious to know what product is at the other end.

After a few months we found the problem. The culprit for the wrong
session ID is not the Providers DSLAM or PPP, but the Zyxel ZyXEL
VMG1312-B30A or more specific:

> * https://support.aa.net.uk/VMG1312-B10A:_Bugs

> PPPoE Session-ID caching bug (In Bridge mode)
> ======================
> Issue Description
> -----------------

> Last year we had an problem with Huawei FTTC modems, the standard ones that
> Openreach supply The bug appears to be that the modem manages to "blacklist"
> some UDP packets after a PPP restart. Typically this affects VPN tunnels. The
> short term fix is to unplugged and plugged back in!  We now have what looks to
> be the same fault on the ZyXELs - both on ADSL and VDSL.  When a PPPoE session
> finishes and a new one starts, ethernet frames containing IP packets with the
> same source and destination IP and port combination that were used in the
> previous session are received with the PPPoE Session-ID from the earlier
> session.  This affects long running sessions using protocols which use the same
> source port for all communications. This includes IPsec and (in some
> circumstances) SIP.  Our understanding of this, having talked to Huawei last
> year to get a very similar bug fixed is that the problem is with the packet
> accelerator feature in the Broadcom chipset. It is caching frame headers
> including the PPPoE Session-ID, but not checking if the Session-ID is the same
> when searching for the entry in the cache for subsequent packets. Unplugging
> the ethernet cable from the VMG1312 momentarily resolves the problem - that
> action must trigger a cache flush in the Broadcom chipset.  Possible fixes
> would be to either not store the Session-ID in the packet accelerator cache at
> all, or to check the Session-ID in addition to the IP and ports when searching
> the cache. A workaround would be to disable the packet accelerator.  (Side note
> for other ISPs looking at this: This does not affect lines that have dynamic
> WAN addresses, which none of our service do.)

> Date Reported
> -------------
> 2015-05-06

> Updates
> -------
> 2015-05-06 - Escalated with ZyXEL/Broadcom
> 2015-05-15 - ZyXEL staff came to AAISP offices and we demonstrated and discussed the problem
> 2015-06-02 - Still in hand with ZyXEL HQ reproducing this in their lab
> 2016-10-01 - ZyXEL still unable to reproduce this, even though we have had customers recently seeing the issue with their VPN sessions

> Resolution

> None yet.

We identified the ZyXEL VMG1312-B30A as culprit by doing:

Telekom DSLAM <-DSL-> Older Zyxel without Vectoring support <-Ethernet Bridge Sniffer-> Allnet DSLAN <-DSL-> Zyxel VMG1312-B30A <-> Ethernet

We sniffed on the Ethernet Bridge and found out that the PPPOE Session ID from
German Telekom are correct, but the PPPOE Session ID from the Zyxel was corrupt.

Thank you again for helping me identifying the issue.

Cheers,
        Thomas