Flaky PPPoE connection with TO 2GB + Vigor166

DjogaRo · January 3, 2023, 1:08pm

Hello,

one year ago, I installed a Vigor166 in bridge mode and a new TO as router at my mother’s - ISP is Deutsche Telekom with VDSL 200Mb line. (By now running TOS 6.1.0)

The whole thing seems to know 3 modes

being seemingly stable
losing the PPPoE connection every now and then and needing some time to reestablish
not being able to hold the PPPoE connection for more than a minute and needing a lot of time for every succesfull reconnect

Last it’s been in mode 3) for around 12 hours. After that, I let the Vigor restart, immediately cut the connection between TO and Vigor, restarted the TO too, waited for Vigor to sync, reconnected the two, waited for the PPPoE connect, and now it seems to be in mode 1). That seems to be a sure fire way to have it working. Impractical though, when I’m not around.

I don’t know what to make of it. Yesterday, I was playing around with it all evening and half the night. The Vigor rebooted a lot - it seems asking in its web interface for DSL status does have a crit chance/can make it cycle.

In mode 3) though, going by the Vigor’s LEDs it doesn’s lose sync. So one might think it’s something between the TO and the provider. ?

A message excerpt from last night

Jan 3 10:38:33 ghc pppd[31457]: Plugin rp-pppoe.so loaded. Jan 3 10:38:33 ghc pppd[31457]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 3 10:38:33 ghc pppd[31457]: pppd 2.4.8 started by root, uid 0 Jan 3 10:38:48 ghc pppd[31457]: Timeout waiting for PADO packets Jan 3 10:38:48 ghc pppd[31457]: Unable to complete PPPoE Discovery Jan 3 10:38:48 ghc pppd[31457]: Exit. Jan 3 10:38:48 ghc netifd: Interface 'wan' is now down Jan 3 10:38:48 ghc netifd: Interface 'wan' is disabled Jan 3 10:38:48 ghc netifd: Interface 'wan' is enabled Jan 3 10:38:48 ghc netifd: Interface 'wan' is setting up now Jan 3 10:38:48 ghc insmod: module is already loaded - slhc Jan 3 10:38:48 ghc insmod: module is already loaded - ppp_generic Jan 3 10:38:48 ghc insmod: module is already loaded - pppox Jan 3 10:38:48 ghc insmod: module is already loaded - pppoe Jan 3 10:38:48 ghc netifd: wan (31508): ppp: warning: Sleeping for '10' seconds Jan 3 10:38:50 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:38:58 ghc pppd[31741]: Plugin rp-pppoe.so loaded. Jan 3 10:38:58 ghc pppd[31741]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 3 10:38:58 ghc pppd[31741]: pppd 2.4.8 started by root, uid 0 Jan 3 10:38:58 ghc pppd[31741]: PPP session is 97 Jan 3 10:38:58 ghc pppd[31741]: Connected to 12:23:34:45:56 via interface eth2.7 Jan 3 11:38:58 ghc kernel: [36332.378216] pppoe-wan: renamed from ppp0 Jan 3 10:38:58 ghc pppd[31741]: Renamed interface ppp0 to pppoe-wan Jan 3 10:38:58 ghc pppd[31741]: Using interface pppoe-wan Jan 3 10:38:58 ghc pppd[31741]: Connect: pppoe-wan <--> eth2.7 Jan 3 10:38:59 ghc pppd[31741]: Remote message: SRU=43976#SRD=192412# Jan 3 10:38:59 ghc pppd[31741]: PAP authentication succeeded Jan 3 10:38:59 ghc pppd[31741]: peer from calling number 12:23:34:45:56 authorized Jan 3 10:38:59 ghc pppd[31741]: local IP address 79.216.205.219 Jan 3 10:38:59 ghc pppd[31741]: remote IP address 62.155.240.107 Jan 3 10:38:59 ghc pppd[31741]: primary DNS address 217.237.151.51 Jan 3 10:38:59 ghc pppd[31741]: secondary DNS address 217.237.149.205 Jan 3 10:38:59 ghc pppd[31741]: local LL address fe80::bd48:8d3e:ab57:db7f Jan 3 10:38:59 ghc pppd[31741]: remote LL address fe80::224e:71ff:fe67:214e Jan 3 10:38:59 ghc netifd: Network device 'pppoe-wan' link is up Jan 3 10:38:59 ghc netifd: Interface 'wan6' is enabled Jan 3 10:38:59 ghc netifd: Network alias 'pppoe-wan' link is up Jan 3 10:38:59 ghc netifd: Interface 'wan6' has link connectivity Jan 3 10:38:59 ghc netifd: Interface 'wan6' is setting up now Jan 3 10:38:59 ghc netifd: Interface 'wan' is now up Jan 3 10:38:59 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 3 10:38:59 ghc netifd: Interface 'wan6' is now up Jan 3 10:39:02 ghc netifd: Interface 'wan6' has lost the connection Jan 3 10:39:02 ghc netifd: Interface 'wan6' is now up Jan 3 11:39:02 ghc dnsmasq-dhcp[5387]: read /etc/ethers - 0 addresses Jan 3 10:39:03 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:03 ghc dhcp_host_domain_ng.py: DHCP update hostname [Unknown,192.168.78.208] Jan 3 10:39:03 ghc dhcp_host_domain_ng.py: DHCP update hostname [rose,192.168.78.120] Jan 3 10:39:03 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:03 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:06 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 3 10:39:10 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:13 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 3 10:39:17 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:48 ghc hostapd: wlan0: STA ab:bc:cd:de:ef IEEE 802.11: authenticated Jan 3 10:39:48 ghc hostapd: wlan0: STA ab:bc:cd:de:ef IEEE 802.11: associated (aid 1) Jan 3 10:39:48 ghc hostapd: wlan0: AP-STA-CONNECTED ab:bc:cd:de:ef Jan 3 10:39:48 ghc hostapd: wlan0: STA ab:bc:cd:de:ef RADIUS: starting accounting session D1031603137761E1 Jan 3 10:39:48 ghc hostapd: wlan0: STA ab:bc:cd:de:ef WPA: pairwise key handshake completed (RSN) Jan 3 11:39:48 ghc dnsmasq-dhcp[5387]: DHCPDISCOVER(br-lan) ab:bc:cd:de:ef Jan 3 11:39:48 ghc dnsmasq-dhcp[5387]: DHCPOFFER(br-lan) 192.168.78.208 ab:bc:cd:de:ef Jan 3 11:39:48 ghc dnsmasq-dhcp[5387]: DHCPREQUEST(br-lan) 192.168.78.208 ab:bc:cd:de:ef Jan 3 11:39:48 ghc dnsmasq-dhcp[5387]: DHCPACK(br-lan) 192.168.78.208 ab:bc:cd:de:ef Jan 3 10:39:49 ghc dhcp_host_domain_ng.py: DHCP update hostname [Unknown,192.168.78.208] Jan 3 10:39:49 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:51 ghc pppd[31741]: No response to 5 echo-requests Jan 3 10:39:51 ghc pppd[31741]: Serial link appears to be disconnected. Jan 3 10:39:51 ghc pppd[31741]: Connect time 0.9 minutes. Jan 3 10:39:51 ghc pppd[31741]: Sent 2096 bytes, received 6506 bytes. Jan 3 10:39:51 ghc odhcp6c[31797]: Failed to send RELEASE message to ff02::1:2 (Permission denied) Jan 3 10:39:51 ghc netifd: Network device 'pppoe-wan' link is down Jan 3 10:39:51 ghc netifd: Network alias 'pppoe-wan' link is down Jan 3 10:39:51 ghc netifd: Interface 'wan6' has link connectivity loss Jan 3 10:39:52 ghc netifd: Interface 'wan' has lost the connection Jan 3 10:39:52 ghc netifd: wan6 (31797): Command failed: Permission denied Jan 3 10:39:52 ghc odhcp6c[31797]: Failed to send SOLICIT message to ff02::1:2 (Permission denied) Jan 3 10:39:52 ghc netifd: Interface 'wan6' is now down Jan 3 10:39:52 ghc netifd: Interface 'wan6' is disabled Jan 3 11:39:53 ghc dnsmasq-dhcp[5387]: read /etc/ethers - 0 addresses Jan 3 10:39:53 ghc dhcp_host_domain_ng.py: DHCP update hostname [Unknown,192.168.78.208] Jan 3 10:39:53 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:53 ghc dhcp_host_domain_ng.py: DHCP update hostname [rose,192.168.78.120] Jan 3 10:39:53 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:53 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:39:53 ghc hostapd: wlan0: AP-STA-DISCONNECTED ab:bc:cd:de:ef Jan 3 10:39:58 ghc pppd[31741]: Connection terminated. Jan 3 10:39:58 ghc pppd[31741]: Sent PADT Jan 3 10:39:58 ghc pppd[31741]: Modem hangup Jan 3 10:39:58 ghc pppd[31741]: Exit. Jan 3 10:39:58 ghc netifd: Interface 'wan' is now down Jan 3 10:39:58 ghc netifd: Interface 'wan' is disabled Jan 3 10:39:58 ghc netifd: Interface 'wan' is enabled Jan 3 10:39:58 ghc netifd: Interface 'wan' is setting up now Jan 3 10:39:58 ghc insmod: module is already loaded - slhc Jan 3 10:39:58 ghc insmod: module is already loaded - ppp_generic Jan 3 10:39:58 ghc insmod: module is already loaded - pppox Jan 3 10:39:58 ghc insmod: module is already loaded - pppoe Jan 3 10:39:58 ghc netifd: wan (1227): ppp: warning: Sleeping for '10' seconds Jan 3 10:39:58 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:40:01 ghc crond[1399]: (root) CMD (/usr/bin/notifier) Jan 3 10:40:01 ghc crond[1398]: (root) CMDOUT (There is no message to send.) Jan 3 10:40:01 ghc crond[1398]: (root) CMDEND (/usr/bin/notifier) Jan 3 10:40:03 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:40:08 ghc pppd[1609]: Plugin rp-pppoe.so loaded. Jan 3 10:40:08 ghc pppd[1609]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 3 10:40:08 ghc pppd[1609]: pppd 2.4.8 started by root, uid 0 Jan 3 10:40:23 ghc pppd[1609]: Timeout waiting for PADO packets Jan 3 10:40:23 ghc pppd[1609]: Unable to complete PPPoE Discovery Jan 3 10:40:23 ghc pppd[1609]: Exit. Jan 3 10:40:23 ghc netifd: Interface 'wan' is now down Jan 3 10:40:23 ghc netifd: Interface 'wan' is disabled Jan 3 10:40:23 ghc netifd: Interface 'wan' is enabled Jan 3 10:40:23 ghc netifd: Interface 'wan' is setting up now Jan 3 10:40:23 ghc insmod: module is already loaded - slhc Jan 3 10:40:23 ghc insmod: module is already loaded - ppp_generic Jan 3 10:40:23 ghc insmod: module is already loaded - pppox Jan 3 10:40:23 ghc insmod: module is already loaded - pppoe Jan 3 10:40:23 ghc netifd: wan (1673): ppp: warning: Sleeping for '10' seconds Jan 3 10:40:25 ghc dhcp_host_domain_ng.py: Refresh kresd leases Jan 3 10:40:33 ghc pppd[1896]: Plugin rp-pppoe.so loaded. Jan 3 10:40:33 ghc pppd[1896]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 3 10:40:33 ghc pppd[1896]: pppd 2.4.8 started by root, uid 0 Jan 3 10:40:48 ghc pppd[1896]: Timeout waiting for PADO packets Jan 3 10:40:48 ghc pppd[1896]: Unable to complete PPPoE Discovery Jan 3 10:40:48 ghc pppd[1896]: Exit. Jan 3 10:40:48 ghc netifd: Interface 'wan' is now down Jan 3 10:40:48 ghc netifd: Interface 'wan' is disabled

I’ll have to work now. But if you could give me some advice, so I may take a more educated look at it tonight or tomorrow, that be very much appreciated.
I’ve seen, there are other topics regarding PPPoE here, but I’m not sure, if or how they relate. According to the message excerpt a retry delay seems to be already in place.

Thanks for reading so far.

Regards,
Djoga’Ro

moeller0 · January 3, 2023, 1:28pm

Maybe also look at the output of dmesg and try adding the following line to the config interface 'wan' section in /etc/config/network

        option force_link '1'

this might or might not help…

DjogaRo · January 4, 2023, 1:30am

Hello moeller0,

thanks for your answer. force_link doesn’t fix it.
I don’t really know, what to look for in dmesg output. (I’m using Linux, but I’m not much of an expert let alone when it comes to embedded systems.) The only thing I noticed is

[    3.731293] squashfs: Unknown parameter 'commit'
[    3.736967] F2FS-fs (mmcblk0p1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[    3.744210] F2FS-fs (mmcblk0p1): Can't find valid F2FS filesystem in 1th superblock
[    3.752890] F2FS-fs (mmcblk0p1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[    3.760140] F2FS-fs (mmcblk0p1): Can't find valid F2FS filesystem in 2th superblock

but since the device isn’t bricked, I don’t know what to make of it.
Maybe it’s related to this?

############## firmware
== U-Boot version ==
U-Boot SPL 2015.10-rc2 (Oct 06 2020 - 03:14:44)
U-Boot 2019.07 for turris_omnia 
U-Boot 2019.07 (Oct 05 2020 - 23:50:39 +0000)
== U-Boot environment ==
Warning: Bad CRC, using default environment
bootcmd=bootp; setenv bootargs root=/dev/nfs nfsroot=${serverip}:${rootpath} ip=${ipaddr}:${serverip}:${gatewayip}:${netmask}:${hostname}::off; bootm
bootdelay=5
baudrate=115200
== Rescue image version (this can be missing for even pretty new rescue versions) ==
lzcat: /dev/mtd1: Compressed data is corrupt
************** firmware

What confuses me though, is that when the TO is PPPoE-looping, it ends established sessions, because it didn’t get echo-requests answered, while “LCP echo failure threshold” (with description “Presume peer to be dead after given amount of LCP echo failures, use 0 to ignore failures” and seemingly default ‘0’) is not set.

I don’t know if, there’s something useful in it:

dmesg (from that overnight PPPoE looping uptime mentioned above)

[ 0.000000] Booting Linux on physical CPU 0x0
[ 0.000000] Linux version 5.15.84 (packaging@turris.cz) (arm-openwrt-linux-muslgnueabi-gcc (OpenWrt GCC 8.4.0 r16805+123-b119562a07) 8.4.0, GNU ld (GNU Binutils) 2.34) #0 SMP Wed Dec 21 02:03:42 2022
[ 0.000000] CPU: ARMv7 Processor [414fc091] revision 1 (ARMv7), cr=10c5387d
[ 0.000000] CPU: PIPT / VIPT nonaliasing data cache, VIPT aliasing instruction cache
[ 0.000000] OF: fdt: Machine model: Turris Omnia
[ 0.000000] Memory policy: Data cache writealloc
[ 0.000000] Zone ranges:
[ 0.000000] Normal [mem 0x0000000000000000-0x000000002fffffff]
[ 0.000000] HighMem [mem 0x0000000030000000-0x000000007fffffff]
[ 0.000000] Movable zone start for each node
[ 0.000000] Early memory node ranges
[ 0.000000] node 0: [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x000000007fffffff]
[ 0.000000] percpu: Embedded 11 pages/cpu s14988 r8192 d21876 u45056
[ 0.000000] pcpu-alloc: s14988 r8192 d21876 u45056 alloc=114096
[ 0.000000] pcpu-alloc: [0] 0 [0] 1
[ 0.000000] Built 1 zonelists, mobility grouping on. Total pages: 522560
[ 0.000000] Kernel command line: earlyprintk rootwait console=ttyS0,115200 rootfstype=btrfs root=PARTUUID=00000000-01 rootflags=commit=5,subvol=@ rw cfg80211.freg=**
[ 0.000000] Bootloader command line not present
[ 0.000000] Unknown kernel command line parameters “earlyprintk mangled_fs=btrfs”, will be passed to user space.
[ 0.000000] Dentry cache hash table entries: 131072 (order: 7, 524288 bytes, linear)
[ 0.000000] Inode-cache hash table entries: 65536 (order: 6, 262144 bytes, linear)
[ 0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[ 0.000000] Memory: 2063496K/2097152K available (9216K kernel code, 671K rwdata, 2208K rodata, 1024K init, 255K bss, 33656K reserved, 0K cma-reserved, 1310720K highmem)
[ 0.000000] SLUB: HWalign=64, Order=0-3, MinObjects=0, CPUs=2, Nodes=1
[ 0.000000] rcu: Hierarchical RCU implementation.
[ 0.000000] rcu: RCU restricting CPUs from NR_CPUS=4 to nr_cpu_ids=2.
[ 0.000000] Tracing variant of Tasks RCU enabled.
[ 0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 10 jiffies.
[ 0.000000] rcu: Adjusting geometry for rcu_fanout_leaf=16, nr_cpu_ids=2
[ 0.000000] NR_IRQS: 16, nr_irqs: 16, preallocated irqs: 16
[ 0.000000] Registering MPIC SoC Error Interrupt Controller
[ 0.000000] L2C: DT/platform modifies aux control register: 0x06070000 → 0x16070000
[ 0.000000] L2C-310 enabling early BRESP for Cortex-A9
[ 0.000000] L2C-310 full line of zeros enabled for Cortex-A9
[ 0.000000] L2C-310 D prefetch enabled, offset 1 lines
[ 0.000000] L2C-310 dynamic clock gating enabled, standby mode enabled
[ 0.000000] L2C-310 Coherent cache controller enabled, 16 ways, 1024 kB
[ 0.000000] L2C-310 Coherent: CACHE_ID 0x410054c9, AUX_CTRL 0x56070001
[ 0.000001] sched_clock: 64 bits at 800MHz, resolution 1ns, wraps every 4398046511103ns
[ 0.000018] clocksource: arm_global_timer: mask: 0xffffffffffffffff max_cycles: 0xb881274fa3, max_idle_ns: 440795210636 ns
[ 0.000035] Switching to timer-based delay loop, resolution 1ns
[ 0.000178] Ignoring duplicate/late registration of read_current_timer delay
[ 0.000185] clocksource: armada_370_xp_clocksource: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 76450417870 ns
[ 0.000371] Console: colour dummy device 80x30
[ 0.000399] Calibrating delay loop (skipped), value calculated using timer frequency… 1600.00 BogoMIPS (lpj=8000000)
[ 0.000408] pid_max: default: 32768 minimum: 301
[ 0.000501] Mount-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.000510] Mountpoint-cache hash table entries: 2048 (order: 1, 8192 bytes, linear)
[ 0.000898] CPU: Testing write buffer coherency: ok
[ 0.000920] CPU0: Spectre v2: using BPIALL workaround
[ 0.001018] CPU0: thread -1, cpu 0, socket 0, mpidr 80000000
[ 0.001312] Setting up static identity map for 0x100000 - 0x100060
[ 0.001396] mvebu-soc-id: MVEBU SoC ID=0x6820, Rev=0x4
[ 0.001485] mvebu-pmsu: Initializing Power Management Service Unit
[ 0.001546] rcu: Hierarchical SRCU implementation.
[ 0.001620] dyndbg: Ignore empty _ddebug table in a CONFIG_DYNAMIC_DEBUG_CORE build
[ 0.001681] smp: Bringing up secondary CPUs …
[ 0.001844] Booting CPU 1
[ 0.001979] CPU1: thread -1, cpu 1, socket 0, mpidr 80000001
[ 0.001986] CPU1: Spectre v2: using BPIALL workaround
[ 0.002043] smp: Brought up 1 node, 2 CPUs
[ 0.002050] SMP: Total of 2 processors activated (3200.00 BogoMIPS).
[ 0.002056] CPU: All CPU(s) started in SVC mode.
[ 0.002397] devtmpfs: initialized
[ 0.004245] VFP support v0.3: implementor 41 architecture 3 part 30 variant 9 rev 4
[ 0.004298] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 19112604462750000 ns
[ 0.004309] futex hash table entries: 512 (order: 3, 32768 bytes, linear)
[ 0.004384] pinctrl core: initialized pinctrl subsystem
[ 0.004931] NET: Registered PF_NETLINK/PF_ROUTE protocol family
[ 0.005461] DMA: preallocated 256 KiB pool for atomic coherent allocations
[ 0.005919] thermal_sys: Registered thermal governor ‘step_wise’
[ 0.006058] cpuidle: using governor ladder
[ 0.006149] hw-breakpoint: found 5 (+1 reserved) breakpoint and 1 watchpoint registers.
[ 0.006157] hw-breakpoint: maximum watchpoint size is 4 bytes.
[ 0.006284] mvebu-pmsu: CPU hotplug support is currently broken on Armada 38x: disabling
[ 0.006291] mvebu-pmsu: CPU idle is currently broken on Armada 38x: disabling
[ 0.014707] cryptd: max_cpu_qlen set to 1000
[ 0.015505] raid6: skip pq benchmark and using algorithm neonx8
[ 0.015514] raid6: using neon recovery algorithm
[ 0.015780] SCSI subsystem initialized
[ 0.015861] libata version 3.00 loaded.
[ 0.015949] usbcore: registered new interface driver usbfs
[ 0.015970] usbcore: registered new interface driver hub
[ 0.015987] usbcore: registered new device driver usb
[ 0.016604] clocksource: Switched to clocksource arm_global_timer
[ 0.018825] NET: Registered PF_INET protocol family
[ 0.018939] IP idents hash table entries: 16384 (order: 5, 131072 bytes, linear)
[ 0.019472] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[ 0.019492] Table-perturb hash table entries: 65536 (order: 6, 262144 bytes, linear)
[ 0.019502] TCP established hash table entries: 8192 (order: 3, 32768 bytes, linear)
[ 0.019541] TCP bind hash table entries: 8192 (order: 4, 65536 bytes, linear)
[ 0.019605] TCP: Hash tables configured (established 8192 bind 8192)
[ 0.019656] UDP hash table entries: 512 (order: 2, 16384 bytes, linear)
[ 0.019687] UDP-Lite hash table entries: 512 (order: 2, 16384 bytes, linear)
[ 0.019799] NET: Registered PF_UNIX/PF_LOCAL protocol family
[ 0.019818] PCI: CLS 0 bytes, default 64
[ 0.020332] hw perfevents: enabled with armv7_cortex_a9 PMU driver, 7 counters available
[ 0.022230] workingset: timestamp_bits=14 max_order=19 bucket_order=5
[ 0.024235] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[ 0.024242] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[ 0.024688] xor: measuring software checksum speed
[ 0.028504] arm4regs : 2610 MB/sec
[ 0.033414] 8regs : 2005 MB/sec
[ 0.038142] 32regs : 2083 MB/sec
[ 0.043341] neon : 1892 MB/sec
[ 0.043345] xor: using function: arm4regs (2610 MB/sec)
[ 0.043389] bounce: pool size: 64 pages
[ 0.043423] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 250)
[ 0.044550] armada-38x-pinctrl f1018000.pinctrl: registered pinctrl driver
[ 0.045084] debugfs: Directory ‘f1018100.gpio’ with parent ‘regmap’ already present!
[ 0.045382] debugfs: Directory ‘f1018140.gpio’ with parent ‘regmap’ already present!
[ 0.045698] mvebu-pcie soc:pcie: host bridge /soc/pcie ranges:
[ 0.045726] mvebu-pcie soc:pcie: MEM 0x00f1080000…0x00f1081fff → 0x0000080000
[ 0.045742] mvebu-pcie soc:pcie: MEM 0x00f1040000…0x00f1041fff → 0x0000040000
[ 0.045755] mvebu-pcie soc:pcie: MEM 0x00f1044000…0x00f1045fff → 0x0000044000
[ 0.045768] mvebu-pcie soc:pcie: MEM 0x00f1048000…0x00f1049fff → 0x0000048000
[ 0.045781] mvebu-pcie soc:pcie: MEM 0xffffffffffffffff…0x00fffffffe → 0x0100000000
[ 0.045793] mvebu-pcie soc:pcie: IO 0xffffffffffffffff…0x00fffffffe → 0x0100000000
[ 0.045805] mvebu-pcie soc:pcie: MEM 0xffffffffffffffff…0x00fffffffe → 0x0200000000
[ 0.045818] mvebu-pcie soc:pcie: IO 0xffffffffffffffff…0x00fffffffe → 0x0200000000
[ 0.045829] mvebu-pcie soc:pcie: MEM 0xffffffffffffffff…0x00fffffffe → 0x0300000000
[ 0.045841] mvebu-pcie soc:pcie: IO 0xffffffffffffffff…0x00fffffffe → 0x0300000000
[ 0.045853] mvebu-pcie soc:pcie: MEM 0xffffffffffffffff…0x00fffffffe → 0x0400000000
[ 0.045862] mvebu-pcie soc:pcie: IO 0xffffffffffffffff…0x00fffffffe → 0x0400000000
[ 0.045971] mvebu-pcie soc:pcie: pcie0.0: Slot power limit 10.0W
[ 0.046027] mvebu-pcie soc:pcie: pcie1.0: Slot power limit 10.0W
[ 0.046078] mvebu-pcie soc:pcie: pcie2.0: Slot power limit 10.0W
[ 0.046662] mvebu-pcie soc:pcie: PCI host bridge to bus 0000:00
[ 0.046673] pci_bus 0000:00: root bus resource [bus 00-ff]
[ 0.046682] pci_bus 0000:00: root bus resource [mem 0xf1080000-0xf1081fff] (bus address [0x00080000-0x00081fff])
[ 0.046690] pci_bus 0000:00: root bus resource [mem 0xf1040000-0xf1041fff] (bus address [0x00040000-0x00041fff])
[ 0.046697] pci_bus 0000:00: root bus resource [mem 0xf1044000-0xf1045fff] (bus address [0x00044000-0x00045fff])
[ 0.046703] pci_bus 0000:00: root bus resource [mem 0xf1048000-0xf1049fff] (bus address [0x00048000-0x00049fff])
[ 0.046709] pci_bus 0000:00: root bus resource [mem 0xe0000000-0xe7ffffff]
[ 0.046715] pci_bus 0000:00: root bus resource [io 0x1000-0xeffff]
[ 0.046787] pci 0000:00:01.0: [11ab:6820] type 01 class 0x060400
[ 0.046968] pci 0000:00:02.0: [11ab:6820] type 01 class 0x060400
[ 0.047108] pci 0000:00:03.0: [11ab:6820] type 01 class 0x060400
[ 0.047945] PCI: bus0: Fast back to back transfers disabled
[ 0.047954] pci 0000:00:01.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.047965] pci 0000:00:02.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.047974] pci 0000:00:03.0: bridge configuration invalid ([bus 00-00]), reconfiguring
[ 0.048050] pci 0000:01:00.0: [168c:002e] type 00 class 0x028000
[ 0.048073] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x0000ffff 64bit]
[ 0.048168] pci 0000:01:00.0: supports D1
[ 0.048174] pci 0000:01:00.0: PME# supported from D0 D1 D3hot
[ 0.049062] PCI: bus1: Fast back to back transfers disabled
[ 0.049069] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[ 0.049143] pci 0000:02:00.0: [168c:003c] type 00 class 0x028000
[ 0.049165] pci 0000:02:00.0: reg 0x10: [mem 0x00000000-0x001fffff 64bit]
[ 0.049193] pci 0000:02:00.0: reg 0x30: [mem 0x00000000-0x0000ffff pref]
[ 0.049262] pci 0000:02:00.0: supports D1 D2
[ 0.050144] PCI: bus2: Fast back to back transfers disabled
[ 0.050151] pci_bus 0000:02: busn_res: [bus 02-ff] end is updated to 02
[ 0.050986] PCI: bus3: Fast back to back transfers enabled
[ 0.050993] pci_bus 0000:03: busn_res: [bus 03-ff] end is updated to 03
[ 0.051016] pci 0000:00:01.0: BAR 8: assigned [mem 0xe0000000-0xe03fffff]
[ 0.051026] pci 0000:00:02.0: BAR 8: assigned [mem 0xe0400000-0xe07fffff]
[ 0.051034] pci 0000:00:03.0: BAR 8: assigned [mem 0xe0800000-0xe0bfffff]
[ 0.051041] pci 0000:00:01.0: BAR 7: assigned [io 0x10000-0x10fff]
[ 0.051048] pci 0000:00:02.0: BAR 7: assigned [io 0x20000-0x20fff]
[ 0.051054] pci 0000:00:03.0: BAR 7: assigned [io 0x30000-0x30fff]
[ 0.051062] pci 0000:01:00.0: BAR 0: assigned [mem 0xe0000000-0xe000ffff 64bit]
[ 0.051074] pci 0000:00:01.0: PCI bridge to [bus 01]
[ 0.051081] pci 0000:00:01.0: bridge window [io 0x10000-0x10fff]
[ 0.051092] pci 0000:00:01.0: bridge window [mem 0xe0000000-0xe03fffff]
[ 0.051105] pci 0000:02:00.0: BAR 0: assigned [mem 0xe0400000-0xe05fffff 64bit]
[ 0.051117] pci 0000:02:00.0: BAR 6: assigned [mem 0xe0600000-0xe060ffff pref]
[ 0.051124] pci 0000:00:02.0: PCI bridge to [bus 02]
[ 0.051129] pci 0000:00:02.0: bridge window [io 0x20000-0x20fff]
[ 0.051138] pci 0000:00:02.0: bridge window [mem 0xe0400000-0xe07fffff]
[ 0.051149] pci 0000:00:03.0: PCI bridge to [bus 03]
[ 0.051155] pci 0000:00:03.0: bridge window [io 0x30000-0x30fff]
[ 0.051163] pci 0000:00:03.0: bridge window [mem 0xe0800000-0xe0bfffff]
[ 0.051229] pcieport 0000:00:01.0: enabling device (0140 → 0143)
[ 0.051297] pcieport 0000:00:01.0: pciehp: Slot #1 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise- Interlock- NoCompl+ IbPresDis- LLActRep+
[ 0.051600] pcieport 0000:00:02.0: enabling device (0140 → 0143)
[ 0.051656] pcieport 0000:00:02.0: pciehp: Slot #2 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise- Interlock- NoCompl+ IbPresDis- LLActRep+
[ 0.052036] pcieport 0000:00:03.0: enabling device (0140 → 0143)
[ 0.052093] pcieport 0000:00:03.0: pciehp: Slot #3 AttnBtn- PwrCtrl- MRL- AttnInd- PwrInd- HotPlug+ Surprise- Interlock- NoCompl+ IbPresDis- LLActRep+
[ 0.052414] pcieport 0000:00:03.0: pciehp: Slot(3): Card present
[ 0.052668] mv_xor f1060800.xor: Marvell shared XOR driver
[ 0.066608] mvebu-pcie soc:pcie: pcie1.0: link up
[ 0.066628] mvebu-pcie soc:pcie: pcie0.0: link up
[ 0.107018] mv_xor f1060800.xor: Marvell XOR (Descriptor Mode): ( xor cpy intr )
[ 0.107154] mv_xor f1060900.xor: Marvell shared XOR driver
[ 0.166997] mv_xor f1060900.xor: Marvell XOR (Descriptor Mode): ( xor cpy intr )
[ 0.167286] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[ 0.168739] printk: console [ttyS0] disabled
[ 0.188833] f1012000.serial: ttyS0 at MMIO 0xf1012000 (irq = 30, base_baud = 15625000) is a 16550A
[ 1.440718] printk: console [ttyS0] enabled
[ 1.465342] f1012100.serial: ttyS1 at MMIO 0xf1012100 (irq = 31, base_baud = 15625000) is a 16550A
[ 1.476861] loop: module loaded
[ 1.480021] Loading iSCSI transport class v2.0-870.
[ 1.486094] ahci-mvebu f10a8000.sata: supply ahci not found, using dummy regulator
[ 1.493781] ahci-mvebu f10a8000.sata: supply phy not found, using dummy regulator
[ 1.501312] ahci-mvebu f10a8000.sata: supply target not found, using dummy regulator
[ 1.509149] ahci-mvebu f10a8000.sata: AHCI 0001.0000 32 slots 2 ports 6 Gbps 0x3 impl platform mode
[ 1.518229] ahci-mvebu f10a8000.sata: flags: 64bit ncq sntf led only pmp fbs pio slum part sxs
[ 1.527550] scsi host0: ahci-mvebu
[ 1.531241] scsi host1: ahci-mvebu
[ 1.534733] ata1: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x100 irq 53
[ 1.542691] ata2: SATA max UDMA/133 mmio [mem 0xf10a8000-0xf10a9fff] port 0x180 irq 53
[ 1.551688] spi-nor spi0.0: s25fl164k (8192 Kbytes)
[ 1.556740] 2 fixed-partitions partitions found on MTD device spi0.0
[ 1.563114] Creating 2 MTD partitions on “spi0.0”:
[ 1.567963] 0x000000000000-0x000000100000 : “U-Boot”
[ 1.573227] 0x000000100000-0x000000800000 : “Rescue system”
[ 1.580838] hwmon hwmon0: temp1_input not attached to any thermal zone
[ 1.587883] mv88e6085 f1072004.mdio-mii:10: switch 0x1760 detected: Marvell 88E6176, revision 1
[ 1.772381] mvneta_bm f10c8000.bm: Buffer Manager for network controller enabled
[ 1.781416] mvneta f1070000.ethernet eth0: Using hardware mac address d8:58:d7:01:41:63
[ 1.790719] mvneta f1030000.ethernet eth1: Using hardware mac address d8:58:d7:01:41:61
[ 1.800001] mvneta f1034000.ethernet eth2: Using hardware mac address d8:58:d7:01:41:62
[ 1.808173] ehci_hcd: USB 2.0 ‘Enhanced’ Host Controller (EHCI) Driver
[ 1.814718] ehci-pci: EHCI PCI platform driver
[ 1.819210] ehci-platform: EHCI generic platform driver
[ 1.824528] ehci-orion: EHCI orion driver
[ 1.828653] orion-ehci f1058000.usb: EHCI Host Controller
[ 1.834080] orion-ehci f1058000.usb: new USB bus registered, assigned bus number 1
[ 1.841721] orion-ehci f1058000.usb: irq 49, io mem 0xf1058000
[ 1.876607] orion-ehci f1058000.usb: USB 2.0 started, EHCI 1.00
[ 1.877830] ata1: SATA link down (SStatus 0 SControl 300)
[ 1.887999] ata2: SATA link down (SStatus 0 SControl 300)
[ 1.893560] hub 1-0:1.0: USB hub found
[ 1.897347] hub 1-0:1.0: 1 port detected
[ 1.901674] xhci-hcd f10f0000.usb3: xHCI Host Controller
[ 1.907025] xhci-hcd f10f0000.usb3: new USB bus registered, assigned bus number 2
[ 1.914583] xhci-hcd f10f0000.usb3: hcc params 0x0a000990 hci version 0x100 quirks 0x0000000000010010
[ 1.923857] xhci-hcd f10f0000.usb3: irq 55, io mem 0xf10f0000
[ 1.929700] xhci-hcd f10f0000.usb3: xHCI Host Controller
[ 1.935030] xhci-hcd f10f0000.usb3: new USB bus registered, assigned bus number 3
[ 1.942572] xhci-hcd f10f0000.usb3: Host supports USB 3.0 SuperSpeed
[ 1.949205] hub 2-0:1.0: USB hub found
[ 1.952979] hub 2-0:1.0: 1 port detected
[ 1.957064] usb usb3: We don’t know the algorithms for LPM for this host, disabling LPM.
[ 1.965380] hub 3-0:1.0: USB hub found
[ 1.969164] hub 3-0:1.0: 1 port detected
[ 1.973287] xhci-hcd f10f8000.usb3: xHCI Host Controller
[ 1.978629] xhci-hcd f10f8000.usb3: new USB bus registered, assigned bus number 4
[ 1.986180] xhci-hcd f10f8000.usb3: hcc params 0x0a000990 hci version 0x100 quirks 0x0000000000010010
[ 1.995453] xhci-hcd f10f8000.usb3: irq 56, io mem 0xf10f8000
[ 2.001285] xhci-hcd f10f8000.usb3: xHCI Host Controller
[ 2.006623] xhci-hcd f10f8000.usb3: new USB bus registered, assigned bus number 5
[ 2.014161] xhci-hcd f10f8000.usb3: Host supports USB 3.0 SuperSpeed
[ 2.020769] hub 4-0:1.0: USB hub found
[ 2.024542] hub 4-0:1.0: 1 port detected
[ 2.028619] usb usb5: We don’t know the algorithms for LPM for this host, disabling LPM.
[ 2.036935] hub 5-0:1.0: USB hub found
[ 2.040706] hub 5-0:1.0: 1 port detected
[ 2.044856] usbcore: registered new interface driver usb-storage
[ 2.051392] armada38x-rtc f10a3800.rtc: registered as rtc0
[ 2.056978] armada38x-rtc f10a3800.rtc: setting system clock to 2023-01-03T00:33:25 UTC (1672706005)
[ 2.066279] i2c_dev: i2c /dev entries driver
[ 2.072799] orion_wdt: Initial timeout 171 sec
[ 2.077521] sdhci: Secure Digital Host Controller Interface driver
[ 2.083718] sdhci: Copyright(c) Pierre Ossman
[ 2.088206] sdhci-pltfm: SDHCI platform and OF driver helper
[ 2.094851] marvell-cesa f1090000.crypto: CESA device successfully registered
[ 2.102515] NET: Registered PF_INET6 protocol family
[ 2.108147] Segment Routing with IPv6
[ 2.111840] In-situ OAM (IOAM) with IPv6
[ 2.115806] NET: Registered PF_PACKET protocol family
[ 2.119961] mmc0: SDHCI controller on f10d8000.sdhci [f10d8000.sdhci] using ADMA
[ 2.120916] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[ 2.141371] 8021q: 802.1Q VLAN Support v1.8
[ 2.145654] Registering SWP/SWPB emulation handler
[ 2.152577] Btrfs loaded, crc32c=crc32c-generic, zoned=no, fsverity=no
[ 2.160527] mv88e6085 f1072004.mdio-mii:10: switch 0x1760 detected: Marvell 88E6176, revision 1
[ 2.254357] mmc0: new high speed MMC card at address 0001
[ 2.260172] mmcblk0: mmc0:0001 008G30 7.28 GiB
[ 2.266078] mmcblk0: p1
[ 2.269005] mmcblk0boot0: mmc0:0001 008G30 4.00 MiB
[ 2.274424] mmcblk0boot1: mmc0:0001 008G30 4.00 MiB
[ 2.279727] mmcblk0rpmb: mmc0:0001 008G30 4.00 MiB, chardev (247:0)
[ 3.106649] mv88e6085 f1072004.mdio-mii:10: configuring for fixed/rgmii-id link mode
[ 3.116543] mv88e6085 f1072004.mdio-mii:10: configuring for fixed/rgmii-id link mode
[ 3.125948] mv88e6085 f1072004.mdio-mii:10: Link is Up - 1Gbps/Full - flow control off
[ 3.135111] mv88e6085 f1072004.mdio-mii:10: Link is Up - 1Gbps/Full - flow control off
[ 3.231122] mv88e6085 f1072004.mdio-mii:10 lan0 (uninitialized): PHY [mv88e6xxx-1:00] driver [Marvell 88E1540] (irq=79)
[ 3.353357] mv88e6085 f1072004.mdio-mii:10 lan1 (uninitialized): PHY [mv88e6xxx-1:01] driver [Marvell 88E1540] (irq=80)
[ 3.356602] pcieport 0000:00:03.0: pciehp: Slot(3): No link
[ 3.473356] mv88e6085 f1072004.mdio-mii:10 lan2 (uninitialized): PHY [mv88e6xxx-1:02] driver [Marvell 88E1540] (irq=81)
[ 3.588886] mv88e6085 f1072004.mdio-mii:10 lan3 (uninitialized): PHY [mv88e6xxx-1:03] driver [Marvell 88E1540] (irq=82)
[ 3.707997] mv88e6085 f1072004.mdio-mii:10 lan4 (uninitialized): PHY [mv88e6xxx-1:04] driver [Marvell 88E1540] (irq=83)
[ 3.726178] DSA: tree 0 setup
[ 3.731293] squashfs: Unknown parameter ‘commit’
[ 3.736967] F2FS-fs (mmcblk0p1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[ 3.744210] F2FS-fs (mmcblk0p1): Can’t find valid F2FS filesystem in 1th superblock
[ 3.752890] F2FS-fs (mmcblk0p1): Magic Mismatch, valid(0xf2f52010) - read(0x0)
[ 3.760140] F2FS-fs (mmcblk0p1): Can’t find valid F2FS filesystem in 2th superblock
[ 3.768826] BTRFS: device fsid 22502254-fb0e-4175-93a3-4c09b80be438 devid 1 transid 7810 /dev/root scanned by swapper/0 (1)
[ 3.781341] BTRFS info (device mmcblk0p1): disk space caching is enabled
[ 3.788077] BTRFS info (device mmcblk0p1): has skinny extents
[ 3.807054] BTRFS info (device mmcblk0p1): enabling ssd optimizations
[ 3.819713] VFS: Mounted root (btrfs filesystem) on device 0:14.
[ 3.827457] devtmpfs: mounted
[ 3.830853] Freeing unused kernel image (initmem) memory: 1024K
[ 3.856759] Run /sbin/init as init process
[ 3.860866] with arguments:
[ 3.860868] /sbin/init
[ 3.860870] earlyprintk
[ 3.860872] with environment:
[ 3.860874] HOME=/
[ 3.860876] TERM=linux
[ 3.860878] mangled_fs=btrfs
[ 3.895747] init: Console is alive
[ 3.899265] init: - watchdog -
[ 4.115590] kmodloader: loading kernel modules from /etc/modules-boot.d/
[ 4.128535] ehci-fsl: Freescale EHCI Host controller driver
[ 4.136085] usbcore: registered new interface driver uas
[ 4.141653] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[ 4.159084] init: - preinit -
[ 6.275000] mount_root: mounting /dev/root
[ 6.372560] random: procd: uninitialized urandom read (4 bytes read)
[ 6.375876] insmod: module is already loaded - fat
[ 6.385291] insmod: module is already loaded - vfat
[ 6.441943] BTRFS info: devid 1 device path /dev/root changed to /dev/mmcblk0p1 scanned by mount (699)
[ 6.462663] urandom-seed: Seeding with /etc/urandom.seed
[ 6.783125] procd: - early -
[ 6.786045] procd: - watchdog -
[ 6.868831] random: jshn: uninitialized urandom read (4 bytes read)
[ 6.927409] random: jshn: uninitialized urandom read (4 bytes read)
[ 7.315308] procd: - watchdog -
[ 7.320133] procd: - ubus -
[ 7.373442] procd: - init -
[ 7.621388] random: jshn: uninitialized urandom read (4 bytes read)
[ 7.630179] random: ubusd: uninitialized urandom read (4 bytes read)
[ 7.636676] random: ubus: uninitialized urandom read (4 bytes read)
[ 7.730024] kmodloader: loading kernel modules from /etc/modules.d/*
[ 7.794242] tun: Universal TUN/TAP device driver, 1.6
[ 7.807352] sit: IPv6, IPv4 and MPLS over IPv4 tunneling driver
[ 7.861926] i2c i2c-0: Added multiplexed i2c bus 1
[ 7.867365] i2c i2c-0: Added multiplexed i2c bus 2
[ 7.876249] i2c i2c-0: Added multiplexed i2c bus 3
[ 7.882848] i2c i2c-0: Added multiplexed i2c bus 4
[ 7.889641] i2c i2c-0: Added multiplexed i2c bus 5
[ 7.894717] i2c i2c-0: Added multiplexed i2c bus 6
[ 7.900508] i2c i2c-0: Added multiplexed i2c bus 7
[ 7.905806] pca953x 8-0071: supply vcc not found, using dummy regulator
[ 7.912611] pca953x 8-0071: using no AI
[ 7.927169] i2c i2c-0: Added multiplexed i2c bus 8
[ 7.932006] pca954x 0-0070: registered 8 multiplexed busses for I2C mux pca9547
[ 7.942228] GACT probability on
[ 7.945912] Mirror/redirect action on
[ 7.957396] u32 classifier
[ 7.960119] input device check on
[ 7.963787] Actions configured
[ 7.975103] at24 1-0054: supply vcc not found, using dummy regulator
[ 7.987451] at24 1-0054: 8192 byte 24c64 EEPROM, writable, 1 bytes/write
[ 7.997005] Bridge firewalling registered
[ 8.002580] Loading modules backported from Linux version v5.15.81-0-ge4a7232c917c
[ 8.010216] Backport generated by backports.git v5.15.81-1-0-ge1867d55
[ 8.027578] usbcore: registered new interface driver ums-alauda
[ 8.033985] usbcore: registered new interface driver ums-cypress
[ 8.044495] usbcore: registered new interface driver ums-datafab
[ 8.049973] random: crng init done
[ 8.051107] usbcore: registered new interface driver ums-freecom
[ 8.053943] random: 26 urandom warning(s) missed due to ratelimiting
[ 8.060297] usbcore: registered new interface driver ums-isd200
[ 8.072745] usbcore: registered new interface driver ums-jumpshot
[ 8.083056] usbcore: registered new interface driver ums-karma
[ 8.089327] usbcore: registered new interface driver ums-sddr09
[ 8.095602] usbcore: registered new interface driver ums-sddr55
[ 8.101899] usbcore: registered new interface driver ums-usbat
[ 8.111938] usbcore: registered new interface driver usblp
[ 8.118407] usbcore: registered new interface driver usbserial_generic
[ 8.124986] usbserial: USB Serial support registered for generic
[ 8.136863] xt_time: kernel timezone is -0000
[ 8.175762] PPP generic driver version 2.4.2
[ 8.180679] NET: Registered PF_PPPOX protocol family
[ 8.187510] wireguard: WireGuard 1.0.0 loaded. See www.wireguard.com for information.
[ 8.195364] wireguard: Copyright (C) 2015-2019 Jason A. Donenfeld Jason@zx2c4.com. All Rights Reserved.
[ 8.223877] ath10k_pci 0000:02:00.0: enabling device (0140 → 0142)
[ 8.230403] ath10k_pci 0000:02:00.0: pci irq msi oper_irq_mode 2 irq_mode 0 reset_mode 0
[ 8.496891] ath10k_pci 0000:02:00.0: qca988x hw2.0 target 0x4100016c chip_id 0x043202ff sub 0000:0000
[ 8.506149] ath10k_pci 0000:02:00.0: kconfig debug 0 debugfs 1 tracing 0 dfs 1 testmode 0
[ 8.515790] ath10k_pci 0000:02:00.0: firmware ver 10.2.4-1.0-00047 api 5 features no-p2p,raw-mode,mfp,allows-mesh-bcast crc32 35bd9258
[ 8.572191] ath10k_pci 0000:02:00.0: board_file api 1 bmi_id N/A crc32 bebc7c08
[ 9.710733] ath10k_pci 0000:02:00.0: htt-ver 2.1 wmi-op 5 htt-op 2 cal otp max-sta 128 raw 0 hwcrypto 1
[ 9.828038] ath: EEPROM regdomain: 0x0
[ 9.828046] ath: EEPROM indicates default country code should be used
[ 9.828049] ath: doing EEPROM country->regdmn map search
[ 9.828053] ath: country maps to regdmn code: 0x3a
[ 9.828056] ath: Country alpha2 being used: US
[ 9.828059] ath: Regpair used: 0x3a
[ 9.838022] usbcore: registered new interface driver qcserial
[ 9.843818] usbserial: USB Serial support registered for Qualcomm USB modem
[ 9.855628] ath9k 0000:01:00.0: enabling device (0140 → 0142)
[ 9.948598] ath: EEPROM regdomain: 0x0
[ 9.948610] ath: EEPROM indicates default country code should be used
[ 9.948613] ath: doing EEPROM country->regdmn map search
[ 9.948617] ath: country maps to regdmn code: 0x3a
[ 9.948620] ath: Country alpha2 being used: US
[ 9.948622] ath: Regpair used: 0x3a
[ 9.960285] ieee80211 phy1: Selected rate control algorithm ‘minstrel_ht’
[ 9.961426] ieee80211 phy1: Atheros AR9287 Rev:2 mem=0xf0f10000, irq=98
[ 9.968484] kmodloader: done loading kernel modules from /etc/modules.d/*
[ 12.583367] mvneta f1030000.ethernet eth1: configuring for fixed/rgmii link mode
[ 12.591693] mvneta f1030000.ethernet eth1: Link is Up - 1Gbps/Full - flow control off
[ 12.603168] IPv6: ADDRCONF(NETDEV_CHANGE): eth1: link becomes ready
[ 12.617133] mv88e6085 f1072004.mdio-mii:10 lan0: configuring for phy/gmii link mode
[ 12.633895] br-lan: port 1(lan0) entered blocking state
[ 12.639197] br-lan: port 1(lan0) entered disabled state
[ 12.693766] device lan0 entered promiscuous mode
[ 12.698454] device eth1 entered promiscuous mode
[ 12.892535] mv88e6085 f1072004.mdio-mii:10 lan1: configuring for phy/gmii link mode
[ 12.904619] mv88e6085 f1072004.mdio-mii:10 lan0: Link is Up - 1Gbps/Full - flow control rx/tx
[ 12.960157] br-lan: port 2(lan1) entered blocking state
[ 12.965400] br-lan: port 2(lan1) entered disabled state
[ 13.014331] device lan1 entered promiscuous mode
[ 13.036374] br-lan: port 1(lan0) entered blocking state
[ 13.041652] br-lan: port 1(lan0) entered forwarding state
[ 13.050117] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[ 13.137663] mvneta f1034000.ethernet eth2: PHY [f1072004.mdio-mii:01] driver [Marvell 88E1510] (irq=POLL)
[ 13.147469] mvneta f1034000.ethernet eth2: configuring for phy/sgmii link mode
[ 13.157960] mv88e6085 f1072004.mdio-mii:10 lan3: configuring for phy/gmii link mode
[ 13.453702] ath: EEPROM regdomain: 0x8114
[ 13.457813] ath: EEPROM indicates we should expect a country code
[ 13.463932] ath: doing EEPROM country->regdmn map search
[ 13.469266] ath: country maps to regdmn code: 0x37
[ 13.474076] ath: Country alpha2 being used: DE
[ 13.478537] ath: Regpair used: 0x37
[ 13.482032] ath: regdomain 0x8114 dynamically updated by user
[ 13.487847] ath: EEPROM regdomain: 0x8114
[ 13.491866] ath: EEPROM indicates we should expect a country code
[ 13.497975] ath: doing EEPROM country->regdmn map search
[ 13.503297] ath: country maps to regdmn code: 0x37
[ 13.508100] ath: Country alpha2 being used: DE
[ 13.512552] ath: Regpair used: 0x37
[ 13.516046] ath: regdomain 0x8114 dynamically updated by user
[ 13.752202] br-lan: port 3(wlan1) entered blocking state
[ 13.757581] br-lan: port 3(wlan1) entered disabled state
[ 13.763051] device wlan1 entered promiscuous mode
[ 13.767917] br-lan: port 3(wlan1) entered blocking state
[ 13.773252] br-lan: port 3(wlan1) entered forwarding state
[ 13.838738] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[ 16.056110] ath10k_pci 0000:02:00.0: pdev param 0 not supported by firmware
[ 16.078045] br-lan: port 4(wlan0) entered blocking state
[ 16.083385] br-lan: port 4(wlan0) entered disabled state
[ 16.088921] device wlan0 entered promiscuous mode
[ 16.093748] br-lan: port 4(wlan0) entered blocking state
[ 16.099091] br-lan: port 4(wlan0) entered forwarding state
[ 16.104810] br-lan: port 4(wlan0) entered disabled state
[ 18.337106] mvneta f1034000.ethernet eth2: Link is Up - 1Gbps/Full - flow control rx/tx
[ 18.345207] IPv6: ADDRCONF(NETDEV_CHANGE): eth2: link becomes ready
[ 18.359854] IPv6: ADDRCONF(NETDEV_CHANGE): eth2.7: link becomes ready
[ 36.939080] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[ 36.945605] br-lan: port 4(wlan0) entered blocking state
[ 36.950969] br-lan: port 4(wlan0) entered forwarding state
[ 53.984824] pppoe-wan: renamed from ppp0
[ 163.155385] pppoe-wan: renamed from ppp0
[ 278.999579] br-lan: port 1(lan0) entered disabled state
[ 279.006009] mv88e6085 f1072004.mdio-mii:10 lan0: Link is Down
[ 282.345392] pppoe-wan: renamed from ppp0
[ 382.493605] pppoe-wan: renamed from ppp0
[ 502.746078] pppoe-wan: renamed from ppp0
[ 623.882610] pppoe-wan: renamed from ppp0
[ 744.090695] pppoe-wan: renamed from ppp0
[ 868.321189] pppoe-wan: renamed from ppp0
[ 984.480765] pppoe-wan: renamed from ppp0
[ 1104.689154] pppoe-wan: renamed from ppp0
[ 1224.807565] pppoe-wan: renamed from ppp0
[ 1345.022513] pppoe-wan: renamed from ppp0
[ 1468.167301] pppoe-wan: renamed from ppp0
[ 1585.321643] pppoe-wan: renamed from ppp0
[ 1705.557085] pppoe-wan: renamed from ppp0
[ 1826.751000] pppoe-wan: renamed from ppp0
[ 1945.950505] pppoe-wan: renamed from ppp0
[ 1955.487569] nf_conntrack: default automatic helper assignment has been turned off for security reasons and CT-based firewall rule not found. Use the iptables CT target to attach helpers instead.

[<every 120s or 180s>] pppoe-wan: renamed from ppp0

[38844.842759] mv88e6085 f1072004.mdio-mii:10 lan0: Link is Up - 1Gbps/Full - flow control rx/tx
[38844.851350] br-lan: port 1(lan0) entered blocking state
[38844.856610] br-lan: port 1(lan0) entered forwarding state
[38856.241672] pppoe-wan: renamed from ppp0
[38976.379417] pppoe-wan: renamed from ppp0
[39053.541992] pppoe-wan: renamed from ppp0
[39155.028898] pppoe-wan: renamed from ppp0
[39240.257630] pppoe-wan: renamed from ppp0
[39272.748931] mvneta f1034000.ethernet eth2: Link is Down

DjogaRo · January 5, 2023, 12:33am

I made additions to /etc/ppp/options according to https://forum.openwrt.org/t/forced-separation-of-internet-connection-solution-for-reconnection/65010/25, then logread -f.

So according to the log, not only that it does mind LCP echo failures despite the default setting to ignore them, it does only sent one echo request in the beginning, gets that one answered, doesn’t sent any more echo requests, and then abandons ship stating 5 echo requests had not been answered.

What’s going wrong there?

log of some looping - grep'ed for ppp

Jan 4 23:52:22 ghc pppd[24443]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:52:22 ghc pppd[24443]: pppd 2.4.8 started by root, uid 0 Jan 4 23:52:37 ghc pppd[24443]: Timeout waiting for PADO packets Jan 4 23:52:37 ghc pppd[24443]: Unable to complete PPPoE Discovery Jan 4 23:52:37 ghc pppd[24443]: Exit. Jan 4 23:52:37 ghc insmod: module is already loaded - ppp_generic Jan 4 23:52:37 ghc insmod: module is already loaded - pppox Jan 4 23:52:37 ghc insmod: module is already loaded - pppoe Jan 4 23:52:37 ghc netifd: wan (24507): ppp: warning: Sleeping for '10' seconds Jan 4 23:52:47 ghc pppd[24727]: Plugin rp-pppoe.so loaded. Jan 4 23:52:47 ghc pppd[24727]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:52:47 ghc pppd[24727]: pppd 2.4.8 started by root, uid 0 Jan 4 23:52:47 ghc pppd[24727]: PPP session is 97 Jan 4 23:52:47 ghc pppd[24727]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 5 00:52:47 ghc kernel: [ 838.014439] pppoe-wan: renamed from ppp0 Jan 4 23:52:48 ghc pppd[24727]: Renamed interface ppp0 to pppoe-wan Jan 4 23:52:48 ghc pppd[24727]: Using interface pppoe-wan Jan 4 23:52:48 ghc pppd[24727]: Connect: pppoe-wan <--> eth2.7 Jan 4 23:52:48 ghc pppd[24727]: Remote message: SRU=43976#SRD=192412# Jan 4 23:52:48 ghc pppd[24727]: PAP authentication succeeded Jan 4 23:52:48 ghc pppd[24727]: peer from calling number 20:4E:71:67:21:4E authorized Jan 4 23:52:48 ghc pppd[24727]: local IP address 84.139.125.250 Jan 4 23:52:48 ghc pppd[24727]: remote IP address 62.155.240.107 Jan 4 23:52:48 ghc pppd[24727]: primary DNS address 217.237.151.51 Jan 4 23:52:48 ghc pppd[24727]: secondary DNS address 217.237.149.205 Jan 4 23:52:48 ghc pppd[24727]: local LL address fe80::2cdb:a9b6:ee6a:e98f Jan 4 23:52:48 ghc pppd[24727]: remote LL address fe80::224e:71ff:fe67:214e Jan 4 23:52:48 ghc netifd: Network device 'pppoe-wan' link is up Jan 4 23:52:48 ghc netifd: Network alias 'pppoe-wan' link is up Jan 4 23:52:48 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 4 23:52:54 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 4 23:53:01 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 4 23:53:41 ghc pppd[24727]: No response to 5 echo-requests Jan 4 23:53:41 ghc pppd[24727]: Serial link appears to be disconnected. Jan 4 23:53:41 ghc pppd[24727]: Connect time 0.9 minutes. Jan 4 23:53:41 ghc pppd[24727]: Sent 42652 bytes, received 519980 bytes. Jan 4 23:53:41 ghc netifd: Network device 'pppoe-wan' link is down Jan 4 23:53:41 ghc netifd: Network alias 'pppoe-wan' link is down Jan 4 23:53:47 ghc pppd[24727]: Connection terminated. Jan 4 23:53:47 ghc pppd[24727]: Sent PADT Jan 4 23:53:47 ghc pppd[24727]: Modem hangup Jan 4 23:53:47 ghc pppd[24727]: Exit. Jan 4 23:53:47 ghc insmod: module is already loaded - ppp_generic Jan 4 23:53:47 ghc insmod: module is already loaded - pppox Jan 4 23:53:47 ghc insmod: module is already loaded - pppoe Jan 4 23:53:47 ghc netifd: wan (26608): ppp: warning: Sleeping for '10' seconds Jan 4 23:53:57 ghc pppd[26915]: Plugin rp-pppoe.so loaded. Jan 4 23:53:57 ghc pppd[26915]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:53:57 ghc pppd[26915]: pppd 2.4.8 started by root, uid 0 Jan 4 23:54:12 ghc pppd[26915]: Timeout waiting for PADO packets Jan 4 23:54:12 ghc pppd[26915]: Unable to complete PPPoE Discovery Jan 4 23:54:12 ghc pppd[26915]: Exit. Jan 4 23:54:12 ghc insmod: module is already loaded - ppp_generic Jan 4 23:54:12 ghc insmod: module is already loaded - pppox Jan 4 23:54:12 ghc insmod: module is already loaded - pppoe Jan 4 23:54:12 ghc netifd: wan (27059): ppp: warning: Sleeping for '10' seconds root@ghc:~# vim /etc/ppp/options Jan 4 23:57:11 ghc insmod: module is already loaded - ppp_generic Jan 4 23:57:11 ghc insmod: module is already loaded - pppox Jan 4 23:57:11 ghc insmod: module is already loaded - pppoe Jan 4 23:57:11 ghc netifd: wan (706): ppp: warning: Sleeping for '10' seconds Jan 4 23:57:21 ghc pppd[1579]: Plugin rp-pppoe.so loaded. Jan 4 23:57:21 ghc pppd[1579]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:57:21 ghc pppd[1579]: pppd 2.4.8 started by root, uid 0 Jan 4 23:57:21 ghc pppd[1579]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:21 ghc pppd[1579]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:21 ghc pppd[1579]: [service-name] [host-uniq 2b 06 00 00] Jan 4 23:57:26 ghc pppd[1579]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:26 ghc pppd[1579]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:26 ghc pppd[1579]: [service-name] [host-uniq 2b 06 00 00] Jan 4 23:57:31 ghc pppd[1579]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:31 ghc pppd[1579]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:31 ghc pppd[1579]: [service-name] [host-uniq 2b 06 00 00] Jan 4 23:57:36 ghc pppd[1579]: Timeout waiting for PADO packets Jan 4 23:57:36 ghc pppd[1579]: Unable to complete PPPoE Discovery Jan 4 23:57:36 ghc pppd[1579]: Exit. Jan 4 23:57:36 ghc insmod: module is already loaded - ppp_generic Jan 4 23:57:36 ghc insmod: module is already loaded - pppox Jan 4 23:57:36 ghc insmod: module is already loaded - pppoe Jan 4 23:57:36 ghc netifd: wan (1959): ppp: warning: Sleeping for '10' seconds Jan 4 23:57:46 ghc pppd[2042]: Plugin rp-pppoe.so loaded. Jan 4 23:57:46 ghc pppd[2042]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:57:47 ghc pppd[2042]: pppd 2.4.8 started by root, uid 0 Jan 4 23:57:47 ghc pppd[2042]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:47 ghc pppd[2042]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:47 ghc pppd[2042]: [service-name] [host-uniq fa 07 00 00] Jan 4 23:57:52 ghc pppd[2042]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:52 ghc pppd[2042]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:52 ghc pppd[2042]: [service-name] [host-uniq fa 07 00 00] Jan 4 23:57:57 ghc pppd[2042]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:57:57 ghc pppd[2042]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:57:57 ghc pppd[2042]: [service-name] [host-uniq fa 07 00 00] Jan 4 23:58:02 ghc pppd[2042]: Timeout waiting for PADO packets Jan 4 23:58:02 ghc pppd[2042]: Unable to complete PPPoE Discovery Jan 4 23:58:02 ghc pppd[2042]: Exit. Jan 4 23:58:02 ghc insmod: module is already loaded - ppp_generic Jan 4 23:58:02 ghc insmod: module is already loaded - pppox Jan 4 23:58:02 ghc insmod: module is already loaded - pppoe Jan 4 23:58:02 ghc netifd: wan (2191): ppp: warning: Sleeping for '10' seconds Jan 4 23:58:12 ghc pppd[2287]: Plugin rp-pppoe.so loaded. Jan 4 23:58:12 ghc pppd[2287]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:58:12 ghc pppd[2287]: pppd 2.4.8 started by root, uid 0 Jan 4 23:58:12 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:58:12 ghc pppd[2287]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:58:12 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] Jan 4 23:58:12 ghc pppd[2287]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42 Jan 4 23:58:12 ghc pppd[2287]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 4 23:58:12 ghc pppd[2287]: [AC-name BERJ32] [host-uniq ef 08 00 00] [service-name] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:58:12 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32 Jan 4 23:58:12 ghc pppd[2287]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 4 23:58:12 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:58:12 ghc pppd[2287]: Recv PPPOE Discovery V1T1 PADS session 0x61 length 42 Jan 4 23:58:12 ghc pppd[2287]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 4 23:58:12 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] [AC-name BERJ32] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:58:12 ghc pppd[2287]: PADS: Service-Name: '' Jan 4 23:58:12 ghc pppd[2287]: PPP session is 97 Jan 4 23:58:12 ghc pppd[2287]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 4 23:58:12 ghc pppd[2287]: using channel 11 Jan 5 00:58:12 ghc kernel: [ 1162.474886] pppoe-wan: renamed from ppp0 Jan 4 23:58:12 ghc pppd[2287]: Renamed interface ppp0 to pppoe-wan Jan 4 23:58:12 ghc pppd[2287]: Using interface pppoe-wan Jan 4 23:58:12 ghc pppd[2287]: Connect: pppoe-wan <--> eth2.7 Jan 4 23:58:12 ghc pppd[2287]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xe99cfad0>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [LCP ConfReq id=0xde <mru 1492> <auth pap> <magic 0x154a9ec2>] Jan 4 23:58:12 ghc pppd[2287]: sent [LCP ConfAck id=0xde <mru 1492> <auth pap> <magic 0x154a9ec2>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xe99cfad0>] Jan 4 23:58:12 ghc pppd[2287]: sent [LCP EchoReq id=0x0 magic=0xe99cfad0] Jan 4 23:58:12 ghc pppd[2287]: sent [PAP AuthReq id=0x1 user="<hidden>" password=<hidden>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [LCP EchoRep id=0x0 magic=0x154a9ec2] Jan 4 23:58:12 ghc pppd[2287]: rcvd [PAP AuthAck id=0x1 "SRU=43976#SRD=192412#"] Jan 4 23:58:12 ghc pppd[2287]: Remote message: SRU=43976#SRD=192412# Jan 4 23:58:12 ghc pppd[2287]: PAP authentication succeeded Jan 4 23:58:12 ghc pppd[2287]: peer from calling number 20:4E:71:67:21:4E authorized Jan 4 23:58:12 ghc pppd[2287]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] Jan 4 23:58:12 ghc pppd[2287]: sent [IPV6CP ConfReq id=0x1 <addr fe80::b516:d15d:43da:66ab>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [IPCP ConfReq id=0xe7 <addr 62.155.240.107>] Jan 4 23:58:12 ghc pppd[2287]: sent [IPCP ConfAck id=0xe7 <addr 62.155.240.107>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [IPCP ConfNak id=0x1 <addr 79.216.192.251> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:58:12 ghc pppd[2287]: sent [IPCP ConfReq id=0x2 <addr 79.216.192.251> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [IPV6CP ConfReq id=0x51 <addr fe80::224e:71ff:fe67:214e>] Jan 4 23:58:12 ghc pppd[2287]: sent [IPV6CP ConfAck id=0x51 <addr fe80::224e:71ff:fe67:214e>] Jan 4 23:58:12 ghc pppd[2287]: rcvd [IPCP ConfAck id=0x2 <addr 79.216.192.251> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:58:12 ghc pppd[2287]: local IP address 79.216.192.251 Jan 4 23:58:12 ghc pppd[2287]: remote IP address 62.155.240.107 Jan 4 23:58:12 ghc pppd[2287]: primary DNS address 217.237.151.51 Jan 4 23:58:12 ghc pppd[2287]: secondary DNS address 217.237.149.205 Jan 4 23:58:12 ghc pppd[2287]: Script /lib/netifd/ppp-up started (pid 2316) Jan 4 23:58:12 ghc pppd[2287]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::b516:d15d:43da:66ab>] Jan 4 23:58:12 ghc pppd[2287]: local LL address fe80::b516:d15d:43da:66ab Jan 4 23:58:12 ghc pppd[2287]: remote LL address fe80::224e:71ff:fe67:214e Jan 4 23:58:12 ghc pppd[2287]: Script /lib/netifd/ppp6-up started (pid 2317) Jan 4 23:58:12 ghc netifd: Network device 'pppoe-wan' link is up Jan 4 23:58:12 ghc netifd: Network alias 'pppoe-wan' link is up Jan 4 23:58:12 ghc pppd[2287]: Script /lib/netifd/ppp6-up finished (pid 2317), status = 0x0 Jan 4 23:58:12 ghc pppd[2287]: Script /lib/netifd/ppp-up finished (pid 2316), status = 0x1 Jan 4 23:58:12 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 4 23:58:18 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 4 23:58:26 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 4 23:58:41 ghc pppd[2287]: No response to 5 echo-requests Jan 4 23:58:41 ghc pppd[2287]: Serial link appears to be disconnected. Jan 4 23:58:41 ghc pppd[2287]: Connect time 0.5 minutes. Jan 4 23:58:41 ghc pppd[2287]: Sent 56976 bytes, received 547853 bytes. Jan 4 23:58:41 ghc pppd[2287]: Script /lib/netifd/ppp-down started (pid 3635) Jan 4 23:58:41 ghc netifd: Network device 'pppoe-wan' link is down Jan 4 23:58:41 ghc netifd: Network alias 'pppoe-wan' link is down Jan 4 23:58:41 ghc pppd[2287]: Script /lib/netifd/ppp-down started (pid 3639) Jan 4 23:58:41 ghc pppd[2287]: sent [LCP TermReq id=0x2 "Peer not responding"] Jan 4 23:58:41 ghc pppd[2287]: Script /lib/netifd/ppp-down finished (pid 3635), status = 0x1 Jan 4 23:58:41 ghc pppd[2287]: Script /lib/netifd/ppp-down finished (pid 3639), status = 0x1 Jan 4 23:58:44 ghc pppd[2287]: sent [LCP TermReq id=0x3 "Peer not responding"] Jan 4 23:58:47 ghc pppd[2287]: Connection terminated. Jan 4 23:58:47 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADT session 0x61 length 28 Jan 4 23:58:47 ghc pppd[2287]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 4 23:58:47 ghc pppd[2287]: [host-uniq ef 08 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:58:47 ghc pppd[2287]: Sent PADT Jan 4 23:58:47 ghc pppd[2287]: Modem hangup Jan 4 23:59:17 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:59:17 ghc pppd[2287]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:59:17 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] Jan 4 23:59:22 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:59:22 ghc pppd[2287]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:59:22 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] Jan 4 23:59:27 ghc pppd[2287]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:59:27 ghc pppd[2287]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:59:27 ghc pppd[2287]: [service-name] [host-uniq ef 08 00 00] Jan 4 23:59:32 ghc pppd[2287]: Timeout waiting for PADO packets Jan 4 23:59:32 ghc pppd[2287]: Unable to complete PPPoE Discovery Jan 4 23:59:32 ghc pppd[2287]: Exit. Jan 4 23:59:32 ghc insmod: module is already loaded - ppp_generic Jan 4 23:59:32 ghc insmod: module is already loaded - pppox Jan 4 23:59:32 ghc insmod: module is already loaded - pppoe Jan 4 23:59:32 ghc netifd: wan (4306): ppp: warning: Sleeping for '10' seconds Jan 4 23:59:42 ghc pppd[4524]: Plugin rp-pppoe.so loaded. Jan 4 23:59:42 ghc pppd[4524]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 4 23:59:42 ghc pppd[4524]: pppd 2.4.8 started by root, uid 0 Jan 4 23:59:43 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 4 23:59:43 ghc pppd[4524]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 4 23:59:43 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] Jan 4 23:59:43 ghc pppd[4524]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42 Jan 4 23:59:43 ghc pppd[4524]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 4 23:59:43 ghc pppd[4524]: [AC-name BERJ32] [host-uniq ac 11 00 00] [service-name] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:59:43 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32 Jan 4 23:59:43 ghc pppd[4524]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 4 23:59:43 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:59:43 ghc pppd[4524]: Recv PPPOE Discovery V1T1 PADS session 0x61 length 42 Jan 4 23:59:43 ghc pppd[4524]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 4 23:59:43 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] [AC-name BERJ32] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 4 23:59:43 ghc pppd[4524]: PADS: Service-Name: '' Jan 4 23:59:43 ghc pppd[4524]: PPP session is 97 Jan 4 23:59:43 ghc pppd[4524]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 4 23:59:43 ghc pppd[4524]: using channel 12 Jan 5 00:59:43 ghc kernel: [ 1253.096263] pppoe-wan: renamed from ppp0 Jan 4 23:59:43 ghc pppd[4524]: Renamed interface ppp0 to pppoe-wan Jan 4 23:59:43 ghc pppd[4524]: Using interface pppoe-wan Jan 4 23:59:43 ghc pppd[4524]: Connect: pppoe-wan <--> eth2.7 Jan 4 23:59:43 ghc pppd[4524]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xa1b3288a>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [LCP ConfReq id=0x66 <mru 1492> <auth pap> <magic 0x299666aa>] Jan 4 23:59:43 ghc pppd[4524]: sent [LCP ConfAck id=0x66 <mru 1492> <auth pap> <magic 0x299666aa>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xa1b3288a>] Jan 4 23:59:43 ghc pppd[4524]: sent [LCP EchoReq id=0x0 magic=0xa1b3288a] Jan 4 23:59:43 ghc pppd[4524]: sent [PAP AuthReq id=0x1 user="<hidden>" password=<hidden>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [LCP EchoRep id=0x0 magic=0x299666aa] Jan 4 23:59:43 ghc pppd[4524]: rcvd [PAP AuthAck id=0x1 "SRU=43976#SRD=192412#"] Jan 4 23:59:43 ghc pppd[4524]: Remote message: SRU=43976#SRD=192412# Jan 4 23:59:43 ghc pppd[4524]: PAP authentication succeeded Jan 4 23:59:43 ghc pppd[4524]: peer from calling number 20:4E:71:67:21:4E authorized Jan 4 23:59:43 ghc pppd[4524]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] Jan 4 23:59:43 ghc pppd[4524]: sent [IPV6CP ConfReq id=0x1 <addr fe80::e9aa:cf1f:8ddf:08f8>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [IPCP ConfReq id=0x51 <addr 62.155.240.107>] Jan 4 23:59:43 ghc pppd[4524]: sent [IPCP ConfAck id=0x51 <addr 62.155.240.107>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [IPCP ConfNak id=0x1 <addr 84.139.124.55> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:59:43 ghc pppd[4524]: sent [IPCP ConfReq id=0x2 <addr 84.139.124.55> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [IPV6CP ConfReq id=0xef <addr fe80::224e:71ff:fe67:214e>] Jan 4 23:59:43 ghc pppd[4524]: sent [IPV6CP ConfAck id=0xef <addr fe80::224e:71ff:fe67:214e>] Jan 4 23:59:43 ghc pppd[4524]: rcvd [IPCP ConfAck id=0x2 <addr 84.139.124.55> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 4 23:59:43 ghc pppd[4524]: local IP address 84.139.124.55 Jan 4 23:59:43 ghc pppd[4524]: remote IP address 62.155.240.107 Jan 4 23:59:43 ghc pppd[4524]: primary DNS address 217.237.151.51 Jan 4 23:59:43 ghc pppd[4524]: secondary DNS address 217.237.149.205 Jan 4 23:59:43 ghc pppd[4524]: Script /lib/netifd/ppp-up started (pid 4553) Jan 4 23:59:43 ghc pppd[4524]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::e9aa:cf1f:8ddf:08f8>] Jan 4 23:59:43 ghc pppd[4524]: local LL address fe80::e9aa:cf1f:8ddf:08f8 Jan 4 23:59:43 ghc pppd[4524]: remote LL address fe80::224e:71ff:fe67:214e Jan 4 23:59:43 ghc pppd[4524]: Script /lib/netifd/ppp6-up started (pid 4554) Jan 4 23:59:43 ghc netifd: Network device 'pppoe-wan' link is up Jan 4 23:59:43 ghc netifd: Network alias 'pppoe-wan' link is up Jan 4 23:59:43 ghc pppd[4524]: Script /lib/netifd/ppp6-up finished (pid 4554), status = 0x0 Jan 4 23:59:43 ghc pppd[4524]: Script /lib/netifd/ppp-up finished (pid 4553), status = 0x1 Jan 4 23:59:43 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 4 23:59:49 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 4 23:59:56 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 5 00:00:42 ghc pppd[4524]: No response to 5 echo-requests Jan 5 00:00:42 ghc pppd[4524]: Serial link appears to be disconnected. Jan 5 00:00:42 ghc pppd[4524]: Connect time 1.0 minutes. Jan 5 00:00:42 ghc pppd[4524]: Sent 81755 bytes, received 588148 bytes. Jan 5 00:00:42 ghc pppd[4524]: Script /lib/netifd/ppp-down started (pid 6006) Jan 5 00:00:42 ghc netifd: Network device 'pppoe-wan' link is down Jan 5 00:00:42 ghc netifd: Network alias 'pppoe-wan' link is down Jan 5 00:00:42 ghc pppd[4524]: Script /lib/netifd/ppp-down started (pid 6010) Jan 5 00:00:42 ghc pppd[4524]: sent [LCP TermReq id=0x2 "Peer not responding"] Jan 5 00:00:42 ghc pppd[4524]: Script /lib/netifd/ppp-down finished (pid 6006), status = 0x1 Jan 5 00:00:42 ghc pppd[4524]: Script /lib/netifd/ppp-down finished (pid 6010), status = 0x1 Jan 5 00:00:45 ghc pppd[4524]: sent [LCP TermReq id=0x3 "Peer not responding"] Jan 5 00:00:48 ghc pppd[4524]: Connection terminated. Jan 5 00:00:48 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADT session 0x61 length 28 Jan 5 00:00:48 ghc pppd[4524]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:00:48 ghc pppd[4524]: [host-uniq ac 11 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:00:48 ghc pppd[4524]: Sent PADT Jan 5 00:00:48 ghc pppd[4524]: Modem hangup Jan 5 00:01:18 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:01:18 ghc pppd[4524]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:01:18 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] Jan 5 00:01:23 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:01:23 ghc pppd[4524]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:01:23 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] Jan 5 00:01:28 ghc pppd[4524]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:01:28 ghc pppd[4524]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:01:28 ghc pppd[4524]: [service-name] [host-uniq ac 11 00 00] Jan 5 00:01:33 ghc pppd[4524]: Timeout waiting for PADO packets Jan 5 00:01:33 ghc pppd[4524]: Unable to complete PPPoE Discovery Jan 5 00:01:33 ghc pppd[4524]: Exit. Jan 5 00:01:33 ghc insmod: module is already loaded - ppp_generic Jan 5 00:01:33 ghc insmod: module is already loaded - pppox Jan 5 00:01:33 ghc insmod: module is already loaded - pppoe Jan 5 00:01:33 ghc netifd: wan (6670): ppp: warning: Sleeping for '10' seconds Jan 5 00:01:43 ghc pppd[6887]: Plugin rp-pppoe.so loaded. Jan 5 00:01:43 ghc pppd[6887]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 5 00:01:43 ghc pppd[6887]: pppd 2.4.8 started by root, uid 0 Jan 5 00:01:43 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:01:43 ghc pppd[6887]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:01:43 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] Jan 5 00:01:43 ghc pppd[6887]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42 Jan 5 00:01:43 ghc pppd[6887]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:01:43 ghc pppd[6887]: [AC-name BERJ32] [host-uniq e7 1a 00 00] [service-name] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:01:43 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32 Jan 5 00:01:43 ghc pppd[6887]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:01:43 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:01:43 ghc pppd[6887]: Recv PPPOE Discovery V1T1 PADS session 0x61 length 42 Jan 5 00:01:43 ghc pppd[6887]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:01:43 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] [AC-name BERJ32] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:01:43 ghc pppd[6887]: PADS: Service-Name: '' Jan 5 00:01:43 ghc pppd[6887]: PPP session is 97 Jan 5 00:01:43 ghc pppd[6887]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 5 00:01:43 ghc pppd[6887]: using channel 13 Jan 5 01:01:43 ghc kernel: [ 1373.730764] pppoe-wan: renamed from ppp0 Jan 5 00:01:43 ghc pppd[6887]: Renamed interface ppp0 to pppoe-wan Jan 5 00:01:43 ghc pppd[6887]: Using interface pppoe-wan Jan 5 00:01:43 ghc pppd[6887]: Connect: pppoe-wan <--> eth2.7 Jan 5 00:01:43 ghc pppd[6887]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x42ef50b2>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [LCP ConfReq id=0xfc <mru 1492> <auth pap> <magic 0x58c46abd>] Jan 5 00:01:43 ghc pppd[6887]: sent [LCP ConfAck id=0xfc <mru 1492> <auth pap> <magic 0x58c46abd>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x42ef50b2>] Jan 5 00:01:43 ghc pppd[6887]: sent [LCP EchoReq id=0x0 magic=0x42ef50b2] Jan 5 00:01:43 ghc pppd[6887]: sent [PAP AuthReq id=0x1 user="<hidden>" password=<hidden>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [LCP EchoRep id=0x0 magic=0x58c46abd] Jan 5 00:01:43 ghc pppd[6887]: rcvd [PAP AuthAck id=0x1 "SRU=43976#SRD=192412#"] Jan 5 00:01:43 ghc pppd[6887]: Remote message: SRU=43976#SRD=192412# Jan 5 00:01:43 ghc pppd[6887]: PAP authentication succeeded Jan 5 00:01:43 ghc pppd[6887]: peer from calling number 20:4E:71:67:21:4E authorized Jan 5 00:01:43 ghc pppd[6887]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] Jan 5 00:01:43 ghc pppd[6887]: sent [IPV6CP ConfReq id=0x1 <addr fe80::f1b3:6087:f5e7:46a2>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [IPCP ConfReq id=0xfb <addr 62.155.240.107>] Jan 5 00:01:43 ghc pppd[6887]: sent [IPCP ConfAck id=0xfb <addr 62.155.240.107>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [IPCP ConfNak id=0x1 <addr 84.139.124.75> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:01:43 ghc pppd[6887]: sent [IPCP ConfReq id=0x2 <addr 84.139.124.75> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [IPV6CP ConfReq id=0xb <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:01:43 ghc pppd[6887]: sent [IPV6CP ConfAck id=0xb <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:01:43 ghc pppd[6887]: rcvd [IPCP ConfAck id=0x2 <addr 84.139.124.75> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:01:43 ghc pppd[6887]: local IP address 84.139.124.75 Jan 5 00:01:43 ghc pppd[6887]: remote IP address 62.155.240.107 Jan 5 00:01:43 ghc pppd[6887]: primary DNS address 217.237.151.51 Jan 5 00:01:43 ghc pppd[6887]: secondary DNS address 217.237.149.205 Jan 5 00:01:44 ghc pppd[6887]: Script /lib/netifd/ppp-up started (pid 6916) Jan 5 00:01:44 ghc pppd[6887]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::f1b3:6087:f5e7:46a2>] Jan 5 00:01:44 ghc pppd[6887]: local LL address fe80::f1b3:6087:f5e7:46a2 Jan 5 00:01:44 ghc pppd[6887]: remote LL address fe80::224e:71ff:fe67:214e Jan 5 00:01:44 ghc pppd[6887]: Script /lib/netifd/ppp6-up started (pid 6917) Jan 5 00:01:44 ghc netifd: Network device 'pppoe-wan' link is up Jan 5 00:01:44 ghc netifd: Network alias 'pppoe-wan' link is up Jan 5 00:01:44 ghc pppd[6887]: Script /lib/netifd/ppp6-up finished (pid 6917), status = 0x0 Jan 5 00:01:44 ghc pppd[6887]: Script /lib/netifd/ppp-up finished (pid 6916), status = 0x1 Jan 5 00:01:44 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 5 00:01:50 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 5 00:01:57 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 5 00:02:42 ghc pppd[6887]: No response to 5 echo-requests Jan 5 00:02:42 ghc pppd[6887]: Serial link appears to be disconnected. Jan 5 00:02:42 ghc pppd[6887]: Connect time 1.0 minutes. Jan 5 00:02:42 ghc pppd[6887]: Sent 92737 bytes, received 1029722 bytes. Jan 5 00:02:42 ghc pppd[6887]: Script /lib/netifd/ppp-down started (pid 8294) Jan 5 00:02:42 ghc netifd: Network device 'pppoe-wan' link is down Jan 5 00:02:42 ghc netifd: Network alias 'pppoe-wan' link is down Jan 5 00:02:42 ghc pppd[6887]: Script /lib/netifd/ppp-down started (pid 8299) Jan 5 00:02:42 ghc pppd[6887]: sent [LCP TermReq id=0x2 "Peer not responding"] Jan 5 00:02:42 ghc pppd[6887]: Script /lib/netifd/ppp-down finished (pid 8294), status = 0x1 Jan 5 00:02:42 ghc pppd[6887]: Script /lib/netifd/ppp-down finished (pid 8299), status = 0x1 Jan 5 00:02:45 ghc pppd[6887]: sent [LCP TermReq id=0x3 "Peer not responding"] Jan 5 00:02:48 ghc pppd[6887]: Connection terminated. Jan 5 00:02:48 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADT session 0x61 length 28 Jan 5 00:02:48 ghc pppd[6887]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:02:48 ghc pppd[6887]: [host-uniq e7 1a 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:02:48 ghc pppd[6887]: Sent PADT Jan 5 00:02:48 ghc pppd[6887]: Modem hangup Jan 5 00:03:18 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:03:18 ghc pppd[6887]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:03:18 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] Jan 5 00:03:23 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:03:23 ghc pppd[6887]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:03:23 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] Jan 5 00:03:28 ghc pppd[6887]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:03:28 ghc pppd[6887]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:03:28 ghc pppd[6887]: [service-name] [host-uniq e7 1a 00 00] Jan 5 00:03:33 ghc pppd[6887]: Timeout waiting for PADO packets Jan 5 00:03:34 ghc pppd[6887]: Unable to complete PPPoE Discovery Jan 5 00:03:34 ghc pppd[6887]: Exit. Jan 5 00:03:34 ghc insmod: module is already loaded - ppp_generic Jan 5 00:03:34 ghc insmod: module is already loaded - pppox Jan 5 00:03:34 ghc insmod: module is already loaded - pppoe Jan 5 00:03:34 ghc netifd: wan (8945): ppp: warning: Sleeping for '10' seconds Jan 5 00:03:44 ghc pppd[9171]: Plugin rp-pppoe.so loaded. Jan 5 00:03:44 ghc pppd[9171]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 5 00:03:44 ghc pppd[9171]: pppd 2.4.8 started by root, uid 0 Jan 5 00:03:44 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:03:44 ghc pppd[9171]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:03:44 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] Jan 5 00:03:44 ghc pppd[9171]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42 Jan 5 00:03:44 ghc pppd[9171]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:03:44 ghc pppd[9171]: [AC-name BERJ32] [host-uniq d3 23 00 00] [service-name] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:03:44 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32 Jan 5 00:03:44 ghc pppd[9171]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:03:44 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:03:44 ghc pppd[9171]: Recv PPPOE Discovery V1T1 PADS session 0x61 length 42 Jan 5 00:03:44 ghc pppd[9171]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:03:44 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] [AC-name BERJ32] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:03:44 ghc pppd[9171]: PADS: Service-Name: '' Jan 5 00:03:44 ghc pppd[9171]: PPP session is 97 Jan 5 00:03:44 ghc pppd[9171]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 5 00:03:44 ghc pppd[9171]: using channel 14 Jan 5 01:03:44 ghc kernel: [ 1494.346143] pppoe-wan: renamed from ppp0 Jan 5 00:03:44 ghc pppd[9171]: Renamed interface ppp0 to pppoe-wan Jan 5 00:03:44 ghc pppd[9171]: Using interface pppoe-wan Jan 5 00:03:44 ghc pppd[9171]: Connect: pppoe-wan <--> eth2.7 Jan 5 00:03:44 ghc pppd[9171]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x8cc96d72>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [LCP ConfReq id=0x26 <mru 1492> <auth pap> <magic 0x43a47d93>] Jan 5 00:03:44 ghc pppd[9171]: sent [LCP ConfAck id=0x26 <mru 1492> <auth pap> <magic 0x43a47d93>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x8cc96d72>] Jan 5 00:03:44 ghc pppd[9171]: sent [LCP EchoReq id=0x0 magic=0x8cc96d72] Jan 5 00:03:44 ghc pppd[9171]: sent [PAP AuthReq id=0x1 user="<hidden>" password=<hidden>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [LCP EchoRep id=0x0 magic=0x43a47d93] Jan 5 00:03:44 ghc pppd[9171]: rcvd [PAP AuthAck id=0x1 "SRU=43976#SRD=192412#"] Jan 5 00:03:44 ghc pppd[9171]: Remote message: SRU=43976#SRD=192412# Jan 5 00:03:44 ghc pppd[9171]: PAP authentication succeeded Jan 5 00:03:44 ghc pppd[9171]: peer from calling number 20:4E:71:67:21:4E authorized Jan 5 00:03:44 ghc pppd[9171]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] Jan 5 00:03:44 ghc pppd[9171]: sent [IPV6CP ConfReq id=0x1 <addr fe80::b171:13f0:b532:dc39>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [IPCP ConfReq id=0xb9 <addr 62.155.240.107>] Jan 5 00:03:44 ghc pppd[9171]: sent [IPCP ConfAck id=0xb9 <addr 62.155.240.107>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [IPCP ConfNak id=0x1 <addr 84.139.125.166> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:03:44 ghc pppd[9171]: sent [IPCP ConfReq id=0x2 <addr 84.139.125.166> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [IPV6CP ConfReq id=0xbe <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:03:44 ghc pppd[9171]: sent [IPV6CP ConfAck id=0xbe <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:03:44 ghc pppd[9171]: rcvd [IPCP ConfAck id=0x2 <addr 84.139.125.166> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:03:44 ghc pppd[9171]: local IP address 84.139.125.166 Jan 5 00:03:44 ghc pppd[9171]: remote IP address 62.155.240.107 Jan 5 00:03:44 ghc pppd[9171]: primary DNS address 217.237.151.51 Jan 5 00:03:44 ghc pppd[9171]: secondary DNS address 217.237.149.205 Jan 5 00:03:44 ghc pppd[9171]: Script /lib/netifd/ppp-up started (pid 9200) Jan 5 00:03:44 ghc pppd[9171]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::b171:13f0:b532:dc39>] Jan 5 00:03:44 ghc pppd[9171]: local LL address fe80::b171:13f0:b532:dc39 Jan 5 00:03:44 ghc pppd[9171]: remote LL address fe80::224e:71ff:fe67:214e Jan 5 00:03:44 ghc pppd[9171]: Script /lib/netifd/ppp6-up started (pid 9201) Jan 5 00:03:44 ghc netifd: Network device 'pppoe-wan' link is up Jan 5 00:03:44 ghc netifd: Network alias 'pppoe-wan' link is up Jan 5 00:03:44 ghc pppd[9171]: Script /lib/netifd/ppp6-up finished (pid 9201), status = 0x0 Jan 5 00:03:44 ghc pppd[9171]: Script /lib/netifd/ppp-up finished (pid 9200), status = 0x1 Jan 5 00:03:44 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 5 00:03:50 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 5 00:03:58 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan) Jan 5 00:04:42 ghc pppd[9171]: No response to 5 echo-requests Jan 5 00:04:42 ghc pppd[9171]: Serial link appears to be disconnected. Jan 5 00:04:42 ghc pppd[9171]: Connect time 1.0 minutes. Jan 5 00:04:42 ghc pppd[9171]: Sent 78122 bytes, received 1018577 bytes. Jan 5 00:04:42 ghc pppd[9171]: Script /lib/netifd/ppp-down started (pid 10568) Jan 5 00:04:42 ghc netifd: Network device 'pppoe-wan' link is down Jan 5 00:04:42 ghc netifd: Network alias 'pppoe-wan' link is down Jan 5 00:04:42 ghc pppd[9171]: Script /lib/netifd/ppp-down started (pid 10573) Jan 5 00:04:42 ghc pppd[9171]: sent [LCP TermReq id=0x2 "Peer not responding"] Jan 5 00:04:42 ghc pppd[9171]: Script /lib/netifd/ppp-down finished (pid 10573), status = 0x1 Jan 5 00:04:42 ghc pppd[9171]: Script /lib/netifd/ppp-down finished (pid 10568), status = 0x1 Jan 5 00:04:45 ghc pppd[9171]: sent [LCP TermReq id=0x3 "Peer not responding"] Jan 5 00:04:48 ghc pppd[9171]: Connection terminated. Jan 5 00:04:48 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADT session 0x61 length 28 Jan 5 00:04:48 ghc pppd[9171]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:04:48 ghc pppd[9171]: [host-uniq d3 23 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:04:48 ghc pppd[9171]: Sent PADT Jan 5 00:04:48 ghc pppd[9171]: Modem hangup Jan 5 00:05:18 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:05:18 ghc pppd[9171]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:05:18 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] Jan 5 00:05:23 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:05:23 ghc pppd[9171]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:05:23 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] Jan 5 00:05:28 ghc pppd[9171]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:05:28 ghc pppd[9171]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:05:28 ghc pppd[9171]: [service-name] [host-uniq d3 23 00 00] Jan 5 00:05:33 ghc pppd[9171]: Timeout waiting for PADO packets Jan 5 00:05:33 ghc pppd[9171]: Unable to complete PPPoE Discovery Jan 5 00:05:33 ghc pppd[9171]: Exit. Jan 5 00:05:33 ghc insmod: module is already loaded - ppp_generic Jan 5 00:05:33 ghc insmod: module is already loaded - pppox Jan 5 00:05:33 ghc insmod: module is already loaded - pppoe Jan 5 00:05:33 ghc netifd: wan (11214): ppp: warning: Sleeping for '10' seconds Jan 5 00:05:43 ghc pppd[11445]: Plugin rp-pppoe.so loaded. Jan 5 00:05:43 ghc pppd[11445]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8 Jan 5 00:05:43 ghc pppd[11445]: pppd 2.4.8 started by root, uid 0 Jan 5 00:05:43 ghc pppd[11445]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12 Jan 5 00:05:43 ghc pppd[11445]: dst ff:ff:ff:ff:ff:ff src d8:58:d7:01:41:62 Jan 5 00:05:43 ghc pppd[11445]: [service-name] [host-uniq b5 2c 00 00] Jan 5 00:05:43 ghc pppd[11445]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 42 Jan 5 00:05:43 ghc pppd[11445]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:05:43 ghc pppd[11445]: [AC-name BERJ32] [host-uniq b5 2c 00 00] [service-name] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:05:43 ghc pppd[11445]: Send PPPOE Discovery V1T1 PADR session 0x0 length 32 Jan 5 00:05:43 ghc pppd[11445]: dst 20:4e:71:67:21:4e src d8:58:d7:01:41:62 Jan 5 00:05:43 ghc pppd[11445]: [service-name] [host-uniq b5 2c 00 00] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:05:43 ghc pppd[11445]: Recv PPPOE Discovery V1T1 PADS session 0x61 length 42 Jan 5 00:05:43 ghc pppd[11445]: dst d8:58:d7:01:41:62 src 20:4e:71:67:21:4e Jan 5 00:05:43 ghc pppd[11445]: [service-name] [host-uniq b5 2c 00 00] [AC-name BERJ32] [AC-cookie f2 22 f3 bc 0d c3 a7 dc 54 da 6c 4b da af 52 da] Jan 5 00:05:43 ghc pppd[11445]: PADS: Service-Name: '' Jan 5 00:05:43 ghc pppd[11445]: PPP session is 97 Jan 5 00:05:43 ghc pppd[11445]: Connected to 20:4e:71:67:21:4e via interface eth2.7 Jan 5 00:05:43 ghc pppd[11445]: using channel 15 Jan 5 01:05:43 ghc kernel: [ 1613.973445] pppoe-wan: renamed from ppp0 Jan 5 00:05:44 ghc pppd[11445]: Renamed interface ppp0 to pppoe-wan Jan 5 00:05:44 ghc pppd[11445]: Using interface pppoe-wan Jan 5 00:05:44 ghc pppd[11445]: Connect: pppoe-wan <--> eth2.7 Jan 5 00:05:44 ghc pppd[11445]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x7652ba2a>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [LCP ConfReq id=0x98 <mru 1492> <auth pap> <magic 0x17f8fb21>] Jan 5 00:05:44 ghc pppd[11445]: sent [LCP ConfAck id=0x98 <mru 1492> <auth pap> <magic 0x17f8fb21>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x7652ba2a>] Jan 5 00:05:44 ghc pppd[11445]: sent [LCP EchoReq id=0x0 magic=0x7652ba2a] Jan 5 00:05:44 ghc pppd[11445]: sent [PAP AuthReq id=0x1 user="<hidden>" password=<hidden>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [LCP EchoRep id=0x0 magic=0x17f8fb21] Jan 5 00:05:44 ghc pppd[11445]: rcvd [PAP AuthAck id=0x1 "SRU=43976#SRD=192412#"] Jan 5 00:05:44 ghc pppd[11445]: Remote message: SRU=43976#SRD=192412# Jan 5 00:05:44 ghc pppd[11445]: PAP authentication succeeded Jan 5 00:05:44 ghc pppd[11445]: peer from calling number 20:4E:71:67:21:4E authorized Jan 5 00:05:44 ghc pppd[11445]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>] Jan 5 00:05:44 ghc pppd[11445]: sent [IPV6CP ConfReq id=0x1 <addr fe80::096c:1604:2dda:2b85>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [IPCP ConfReq id=0x91 <addr 62.155.240.107>] Jan 5 00:05:44 ghc pppd[11445]: sent [IPCP ConfAck id=0x91 <addr 62.155.240.107>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [IPCP ConfNak id=0x1 <addr 84.139.124.34> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:05:44 ghc pppd[11445]: sent [IPCP ConfReq id=0x2 <addr 84.139.124.34> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [IPV6CP ConfReq id=0x47 <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:05:44 ghc pppd[11445]: sent [IPV6CP ConfAck id=0x47 <addr fe80::224e:71ff:fe67:214e>] Jan 5 00:05:44 ghc pppd[11445]: rcvd [IPCP ConfAck id=0x2 <addr 84.139.124.34> <ms-dns1 217.237.151.51> <ms-dns2 217.237.149.205>] Jan 5 00:05:44 ghc pppd[11445]: local IP address 84.139.124.34 Jan 5 00:05:44 ghc pppd[11445]: remote IP address 62.155.240.107 Jan 5 00:05:44 ghc pppd[11445]: primary DNS address 217.237.151.51 Jan 5 00:05:44 ghc pppd[11445]: secondary DNS address 217.237.149.205 Jan 5 00:05:44 ghc pppd[11445]: Script /lib/netifd/ppp-up started (pid 11474) Jan 5 00:05:44 ghc pppd[11445]: rcvd [IPV6CP ConfAck id=0x1 <addr fe80::096c:1604:2dda:2b85>] Jan 5 00:05:44 ghc pppd[11445]: local LL address fe80::096c:1604:2dda:2b85 Jan 5 00:05:44 ghc pppd[11445]: remote LL address fe80::224e:71ff:fe67:214e Jan 5 00:05:44 ghc pppd[11445]: Script /lib/netifd/ppp6-up started (pid 11475) Jan 5 00:05:44 ghc netifd: Network device 'pppoe-wan' link is up Jan 5 00:05:44 ghc netifd: Network alias 'pppoe-wan' link is up Jan 5 00:05:44 ghc pppd[11445]: Script /lib/netifd/ppp6-up finished (pid 11475), status = 0x0 Jan 5 00:05:44 ghc pppd[11445]: Script /lib/netifd/ppp-up finished (pid 11474), status = 0x1 Jan 5 00:05:44 ghc firewall: Reloading firewall due to ifup of wan (pppoe-wan) Jan 5 00:05:50 ghc firewall: Reloading firewall due to ifupdate of wan (pppoe-wan) Jan 5 00:05:57 ghc firewall: Reloading firewall due to ifup of wan6 (pppoe-wan)

EDIT running TOS 6.2.0 now btw

DjogaRo · January 5, 2023, 11:48am

By now it seems to remedy ppp looping, I just need to reboot the Router. I want to say the last few days it wasn’t always enough, but I’m not 100% sure/didn’t test explicitly for that.
I remember though, that back in Oct/Nov, when I had to steer my mother via phone to rollback to the pre-6.0.1 snapshot and disable automatic updates (which we did twice, since the second part didn’t hold the first time), she needed to restart both the router and the modem to get it working again. It “felt” as if the Router had put the modem in a bad state, though I didn’t see its LEDs and my mother couldn’t read their labels.

Now I can predictably sent the router ppp looping, by just reaching the modem on port 80 or 22 from the PC. I only recognized this this morning - can’t say, if it was like that before.
On the Turris I setup an interface MODEM on eth2 and WAN with PPPoE on eth2.7. On the modem I disabled the VLAN-tagging.

Again, I want to say there weren’t such clear patterns until yesterday.

And still, why is the TO going on about missing LCP echo responses, when its setup to not care and doesn’t sent any echo requests that would go unanswered? @Pepe Or am I interpreting this wrong?

DjogaRo · January 9, 2023, 12:43pm

I fell ill - haven’t looked at it, since my last post.

Any educated opinions on the findings in my last three posts?