mjhjmtu

I have the issue while establishing pppoe connection on De(b)vuan based distribution.
My ISP allows me to establish link via tagged vlan 300. Previosly the connection worked just fine, before i slightly recompiled kernel (made it more generic), but I don't believe it should be a problem.

All modules are (should) be properly loaded already.

Here is the log:

Nov 11 01:08:02 pppd[2863]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Nov 11 01:08:02 pppd[2863]: dst ff:ff:ff:ff:ff:ff src b8:27:eb:62:e6:80
Nov 11 01:08:02 pppd[2863]: [service-name] [host-uniq 2f 0b 00 00]
Nov 11 01:08:02 pppd[2863]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 53
Nov 11 01:08:02 pppd[2863]: dst b8:27:eb:62:e6:80 src e4:81:84:26:2e:6c
Nov 11 01:08:02 pppd[2863]: [service-name] [AC-name BNG_NS_SATELIT1_2] [host-uniq 2f 0b 00 00] [AC-cookie 06 40 99 9b 50 e9 b3 90 be 93 bb 10 9f e6 16 db]
Nov 11 01:08:02 pppd[2863]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32
Nov 11 01:08:02 pppd[2863]: dst e4:81:84:26:2e:6c src b8:27:eb:62:e6:80
Nov 11 01:08:02 pppd[2863]: [service-name] [host-uniq 2f 0b 00 00] [AC-cookie 06 40 99 9b 50 e9 b3 90 be 93 bb 10 9f e6 16 db]
Nov 11 01:08:02 pppd[2863]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 57
Nov 11 01:08:02 pppd[2863]: dst b8:27:eb:62:e6:80 src e4:81:84:25:df:d6
Nov 11 01:08:02 pppd[2863]: [service-name] [AC-name BNG_XXXX] [host-uniq 2f 0b 00 00] [AC-cookie 5e 0c 8b 60 fb 75 10 fd 83 4f 68 ce fa 5a f3 d9]
Nov 11 01:08:02 pppd[2863]: Recv PPPOE Discovery V1T1 PADS session 0x642 length 12
Nov 11 01:08:02 pppd[2863]: dst b8:27:eb:62:e6:80 src e4:81:84:26:2e:6c
Nov 11 01:08:02 pppd[2863]: [service-name] [host-uniq 2f 0b 00 00]
Nov 11 01:08:02 pppd[2863]: PADS: Service-Name: ''
Nov 11 01:08:02 pppd[2863]: PPP session is 1602
Nov 11 01:08:02 pppd[2863]: Connected to e4:81:xx:xx:xx via interface eth0.300
Nov 11 01:08:02 pppd[2863]: using channel 71
Nov 11 01:08:02 pppd[2863]: Using interface ppp0
Nov 11 01:08:02 pppd[2863]: Connect: ppp0 <--> eth0.300
Nov 11 01:08:02 pppd[2863]: sent [LCP ConfReq id=0xa <mru 1492> <magic 0x6bd07e40>]
Nov 11 01:08:02 pppd[2863]: rcvd [LCP ConfAck id=0xa <mru 1492> <magic 0x6bd07e40>]
Nov 11 01:08:05 pppd[2863]: rcvd [LCP ConfReq id=0x28 <mru 1492> <auth pap> <magic 0x6e7eeffa>]
Nov 11 01:08:05 pppd[2863]: sent [LCP ConfAck id=0x28 <mru 1492> <auth pap> <magic 0x6e7eeffa>]
Nov 11 01:08:05 pppd[2863]: sent [LCP EchoReq id=0x0 magic=0x6bd07e40]
Nov 11 01:08:05 pppd[2863]: sent [PAP AuthReq id=0x9 user="username@isp.com" password=<hidden>]
Nov 11 01:08:05 pppd[2863]: rcvd [LCP EchoRep id=0x0 magic=0x6e7eeffa]
Nov 11 01:08:06 pppd[2863]: rcvd [PAP AuthAck id=0x9 "Login ok"]
Nov 11 01:08:06 pppd[2863]: Remote message: Login ok
Nov 11 01:08:06 pppd[2863]: PAP authentication succeeded
Nov 11 01:08:06 pppd[2863]: peer from calling number E4:81:xx:xx:xx:xx authorized
Nov 11 01:08:06 pppd[2863]: sent [IPCP ConfReq id=0x19 <addr 0.0.0.0>]
Nov 11 01:08:06 pppd[2863]: rcvd [IPCP ConfReq id=0xe <addr xxx.xxx.xxx.xxx>]
Nov 11 01:08:06 pppd[2863]: sent [IPCP ConfAck id=0xe <addr xxx.xxx.xxx.xxx>] # <- GW
Nov 11 01:08:06 pppd[2863]: rcvd [IPCP ConfNak id=0x19 <addr xxx.xxx.xxx.xxx>]
Nov 11 01:08:06 pppd[2863]: sent [IPCP ConfReq id=0x1a <addr xxx.xxx.xxx.xxx>]
Nov 11 01:08:06 pppd[2863]: rcvd [IPCP ConfAck id=0x1a <addr xxx.xxx.xxx.xxx>]
Nov 11 01:08:06 pppd[2863]: ioctl(SIOCADDRT) device route: Network is down (line 2501)
Nov 11 01:08:06 pppd[2863]: Interface configuration failed
Nov 11 01:08:06 pppd[2863]: Connect time 0.1 minutes.
Nov 11 01:08:06 pppd[2863]: Sent 30 bytes, received 30 bytes.
Nov 11 01:08:06 pppd[2863]: sent [IPCP TermReq id=0x1b "Interface configuration failed"]
Nov 11 01:08:06 pppd[2863]: rcvd [LCP TermReq id=0x29]
Nov 11 01:08:06 pppd[2863]: LCP terminated by peer
Nov 11 01:08:06 pppd[2863]: sent [LCP TermAck id=0x29]
Nov 11 01:08:06 pppd[2863]: rcvd [IPCP TermAck id=0x1b]
Nov 11 01:08:06 pppd[2863]: Discarded non-LCP packet when LCP not open
Nov 11 01:08:06 pppd[2863]: Modem hangup
Nov 11 01:08:06 pppd[2863]: Connection terminated.
Nov 11 01:08:06 pppd[2863]: Failed to disconnect PPPoE socket: 114 Operation already in progress


 # cat /etc/ppp/peers/dsl-provider 
# Minimalistic default options file for DSL/PPPoE connections

noipdefault
defaultroute
replacedefaultroute
hide-password
#lcp-echo-interval 0 
#lcp-echo-failure 0
noauth
persist
mtu 1412
persist
#maxfail 0
holdoff 20
plugin rp-pppoe.so
eth0.300
user "username@isp.com"

EDIT: As it is on my modified router, here is the link status :

# ip a
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN group default qlen 1
 link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
 inet 127.0.0.1/8 scope host lo
 valid_lft forever preferred_lft forever
 inet6 ::1/128 scope host 
 valid_lft forever preferred_lft forever
2: eth0: <BROADCAST,MULTICAST,PROMISC,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
 link/ether b8:27:eb:62:e6:80 brd ff:ff:ff:ff:ff:ff
 inet6 fe80::ba27:ebff:fe62:e680/64 scope link 
 valid_lft forever preferred_lft forever
3: eth1: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast state UP group default qlen 1000
 link/ether 00:0e:c6:c7:3e:1c brd ff:ff:ff:ff:ff:ff
 inet 192.168.1.1/24 brd 192.168.1.255 scope global eth1
 valid_lft forever preferred_lft forever
 inet6 fe80::20e:c6ff:fec7:3e1c/64 scope link 
 valid_lft forever preferred_lft forever
4: eth3: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc pfifo_fast master br0 state UP group default qlen 1000
 link/ether 00:e0:4c:36:02:76 brd ff:ff:ff:ff:ff:ff
 inet6 fe80::2e0:4cff:fe36:276/64 scope link 
 valid_lft forever preferred_lft forever
32: eth0.200@eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br0 state UP group default qlen 1000
 link/ether b8:27:eb:62:e6:80 brd ff:ff:ff:ff:ff:ff
 inet6 fe80::ba27:ebff:fe62:e680/64 scope link 
 valid_lft forever preferred_lft forever
33: br0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
 link/ether 00:e0:4c:36:02:76 brd ff:ff:ff:ff:ff:ff
 inet6 fe80::2e0:4cff:fe36:276/64 scope link 
 valid_lft forever preferred_lft forever
63: eth0.300@eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP group default qlen 1000
 link/ether b8:27:eb:62:e6:80 brd ff:ff:ff:ff:ff:ff
 inet6 fe80::ba27:ebff:fe62:e680/64 scope link 
 valid_lft forever preferred_lft forever

Modules:

# lsmod | grep 'ppp|802|garp':

ppp_mppe 6951 0 
pppoe 11779 0 
pppox 2913 1 pppoe
ppp_generic 29613 3 pppox,pppoe,ppp_mppe
slhc 5959 1 ppp_generic
8021q 22998 0 
garp 7049 1 8021q
mrp 8903 1 8021q
stp 2430 2 garp,bridge
llc 5903 3 garp,bridge,stp

Can anyone point me what is causing:

Nov 11 01:08:29 pppd[2863]: ioctl(SIOCADDRT) device route: Network is down (line 2501)
Nov 11 01:08:29 pppd[2863]: Interface configuration failed
Nov 11 01:08:29 pppd[2863]: Connect time 0.1 minutes.
Nov 11 01:08:29 pppd[2863]: Sent 30 bytes, received 30 bytes.
Nov 11 01:08:29 pppd[2863]: sent [IPCP TermReq id=0x1e "Interface configuration failed"]
Nov 11 01:08:29 pppd[2863]: rcvd [LCP TermReq id=0x34]
Nov 11 01:08:29 pppd[2863]: LCP terminated by peer

Edit interfaces file:

 # cat /etc/network/interfaces

# This file describes the network interfaces available on your system
# and how to activate them. For more information, see interfaces(5).

source /etc/network/interfaces.d/*

# The loopback network interface
auto lo
iface lo inet loopback

# The primary network interface

auto eth0
auto eth1
auto eth3

#LAN
iface eth1 inet static
 address 192.168.1.1
 netmask 255.255.255.0

#IPTV
auto eth0.200
iface eth0.200 inet manual


#WAN
auto eth0.300
iface eth0.300 inet manual

auto dsl-provider
iface dsl-provider inet ppp
 pre-up /bin/ip link set eth0.300 up # line maintained by pppoeconf
 provider dsl-provider

iface br0 inet manual
 bridge_ports eth3 eth0.200

IP route:

 # ip r
192.168.1.0/24 dev eth1 proto kernel scope link src 192.168.1.1 

Generated by pppoeconf:

:/~ # grep -v '^$|^#' /etc/ppp/peers/dsl-provider 
noipdefault
defaultroute
hide-password
lcp-echo-interval 20
lcp-echo-failure 3
connect /bin/true
noauth
persist
mtu 1492
noaccomp
default-asyncmap
logfile /var/log/ppp.log
plugin rp-pppoe.so eth0.300
user "myusername@isp.com"

Edit 2:

Attached strace output:

strace pppd file /etc/ppp/peers/dsl-provider debug

http://paste.debian.net/995356/

strace -p PID

http://paste.debian.net/995357/

Appreciated!

The line

ioctl(SIOCADDRT) device route: Network is down

means that pppd tried to set a route for an address range on a device which is down. The same happens if you set the route manually with ip route.

Debug by doing ip addr, looking at the addresses on the network interfaces and which ones are up or down, and looking at the addresses pppd received. This may involve some guessing what pppd was doing during the execution, as the state after it shuts down may not be the same state as during the execution. If you can't guess anything, use strace and be prepared for a large output.

You didn't show the other network interfaces or the addresses, so I can't do that for you.