Re: PPP connection terminated every 5 minutes

2020-04-24 Thread Jan Stary
> Note the time seqence:
> * when ifconfig says time 00:05:00, pings die
> * after 20 seconds, a LCP Echo Request comes
> * after another 10 seconds, another LCP Echo Request comes
> * after another 10 seconds, another LCP Echo Request comes
> * after another 10 seconds, a LCP Terminate Request comes
>   and the connection is established anew.
> 
> This pattern has been repeating since the last midnight.
> It looks to me like my ISP is cutting me off every 5 minutes,
> and than it takes 50 seconds to realize the connection is down,
> which is when it sends the Terminate,
> and then the connection is re-established.
> 
> Has anyone seen the same?
> Is this a known issue with pppoe connections?
> 
> Searching the archives, I found this:
> https://marc.info/?l=openbsd-misc&m=155053560723855&w=2
> (but see the entire thread for other details).
> 
> Adam's issue 2 rings a bell, because the drop
> happens when I get a new IP6 configuraion request.
> I do have the "inet6 eui64" in my setup though.

Eh, _now_ I do, and the problem disappeared. It seems that
for this ISP at least, I have to accept their IP6 setting:
if I don't, my connection gets terminated as described;
if I do, everything works as expected.

# cat /etc/hostname.pppoe0  
# 185.63.96.79 -> 10.11.5.146
# The inet6 settings are necessary,
# otherwise we get dropped every 5 minutes
inet 0.0.0.0 255.255.255.255 NONE pppoedev vlan0 \
authproto 'pap' authname 'X' authkey 'PASS' up
dest 0.0.0.1
inet6 eui64
!/sbin/route add default 0.0.0.1
!/sbin/route add -inet6 default -ifp pppoe0 fe80::%pppoe0

# ifconfig pppoe0
pppoe0: flags=8851 mtu 1492
index 6 priority 0 llprio 3
dev: vlan0 state: session
sid: 0x1 PADI retries: 2 PADR retries: 0 time: 01:28:19
sppp: phase network authproto pap authname "X" 
groups: pppoe egress
status: active
inet6 fe80::20d:b9ff:fe56:5efc%pppoe0 ->  prefixlen 64 scopeid 0x6
inet 185.63.96.79 --> 10.11.5.146 netmask 0x

Sorry for the noise.

Jan



PPP connection terminated every 5 minutes

2020-04-24 Thread Jan Stary
This is current/amd64 on an APU2.E2.
It is connected via pppoe over vlan over em as follows:

$ cat /etc/hostname.em0
up

$ cat /etc/hostname.vlan848
descr UVTNET vlan 848 vlandev em0 up

$ cat /etc/hostname.pppoe0
inet 0.0.0.0 255.255.255.255 NONE pppoedev vlan848 \
authproto 'pap' authname 'X' authkey 'PASS' up
dest 0.0.0.1
!/sbin/route add default 0.0.0.1

(The 'X' and 'PASS' are actual bogus values,
the ISP filters by the link I am connected to.)

$ ifconfig em0
em0: flags=8843 mtu 1500
lladdr 00:0d:b9:56:5e:fc
index 1 priority 0 llprio 3
media: Ethernet autoselect (1000baseT full-duplex)
status: active

$ ifconfig vlan848
vlan848: flags=8843 mtu 1500
lladdr 00:0d:b9:56:5e:fc
description: UVTNET
index 8 priority 0 llprio 3
encap: vnetid 848 parent em0 txprio packet rxprio outer
groups: vlan
media: Ethernet autoselect (1000baseT full-duplex)
status: active

$ ifconfig pppoe0
pppoe0: flags=8851 mtu 1492
index 7 priority 0 llprio 3
dev: vlan848 state: session
sid: 0x1 PADI retries: 5 PADR retries: 0 time: 00:03:17
sppp: phase network authproto pap authname "X" 
groups: pppoe egress
status: active
inet6 fe80::20d:b9ff:fe56:5efc%pppoe0 ->  prefixlen 64 scopeid 0x7
inet 185.63.96.79 --> 10.11.5.146 netmask 0x

The connection works just fine, except it drops every five minutes
- I mean after exactly five minutes, for the last ten hours.

This is the test I did:

(1) in one script, keep pinging out
(2) in another script, watch the pppoe up time in a loop:
while true ; do date ; ifconfig pppoe0 ; sleep 1; done
(3) run a tcpdump during that

This is what the pinging looks like:

$ ping stary.fit.cvut.cz
PING stary.fit.cvut.cz (147.32.232.84): 56 data bytes
64 bytes from 147.32.232.84: icmp_seq=0 ttl=246 time=6.632 ms
64 bytes from 147.32.232.84: icmp_seq=1 ttl=246 time=7.339 ms
64 bytes from 147.32.232.84: icmp_seq=2 ttl=246 time=6.762 ms
64 bytes from 147.32.232.84: icmp_seq=3 ttl=246 time=6.438 ms
64 bytes from 147.32.232.84: icmp_seq=4 ttl=246 time=6.626 ms
64 bytes from 147.32.232.84: icmp_seq=5 ttl=246 time=6.989 ms
64 bytes from 147.32.232.84: icmp_seq=6 ttl=246 time=6.951 ms
64 bytes from 147.32.232.84: icmp_seq=7 ttl=246 time=7.136 ms
64 bytes from 147.32.232.84: icmp_seq=8 ttl=246 time=7.620 ms
64 bytes from 147.32.232.84: icmp_seq=9 ttl=246 time=7.404 ms
 ^^^
[no reply for about 50 seconds]
64 bytes from 147.32.232.84: icmp_seq=60 ttl=246 time=6.786 ms
^
64 bytes from 147.32.232.84: icmp_seq=61 ttl=246 time=7.316 ms
64 bytes from 147.32.232.84: icmp_seq=62 ttl=246 time=7.570 ms
64 bytes from 147.32.232.84: icmp_seq=63 ttl=246 time=7.296 ms
[getting replies for precisely 300 pings, then repeats]

The drop happens exactly when ifconfig pppoe0 says
the interface has been up for 5 minues:

Fri Apr 24 13:13:28 CEST 2020
pppoe0: flags=8951 mtu 1492
index 7 priority 0 llprio 3
dev: vlan848 state: session
sid: 0x1 PADI retries: 5 PADR retries: 0 time: 00:05:00
 ^^^
sppp: phase network authproto pap authname "X"
groups: pppoe egress
status: active
inet 185.63.96.79 --> 10.11.5.146 netmask 0x

For almost exactly 50 seconds then, the pings are not getting replies.
This is what tcpdump says:

[pinging away]
13:13:26.840342 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:26.847192 147.32.232.84 > 185.63.96.79: icmp: echo reply
13:13:27.840399 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:27.847448 147.32.232.84 > 185.63.96.79: icmp: echo reply
13:13:28.840398 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:28.847934 147.32.232.84 > 185.63.96.79: icmp: echo reply

[ifconfig pppoe0 shows time 00:05:00]
[The pings are no longer getting replies]

13:13:29.450416 IPV6CP Configure-Request Id=0xff: 
IPv6-Interface-Id=427c:7dff:feea:db03
13:13:29.450438 IPV6CP Configure-Ack Id=0xff: 
IPv6-Interface-Id=427c:7dff:feea:db03
13:13:29.840366 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:29.847671 147.32.232.84 > 185.63.96.79: icmp: echo reply
13:13:30.840381 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:31.840472 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:32.840499 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:33.840449 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:34.840401 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:35.840431 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:36.840437 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:37.840422 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:38.840517 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:39.840458 185.63.96.79 > 147.32.232.84: icmp: echo request
13:13:40.840