PPPoE internet disconnects

Mars4 · February 11, 2022, 2:01pm

Hi,

I am very new to Openwrt and don't know so much about working with Linux. I installed Openwrt on my router (Asus RT AC51U) and I am connected to internet via PPPoe from my ISP. ISP only provides IPv4, no IPv6.

Ever since I started using Openwrt I am getting daily notifications from my ISP that there is a break in my internet connection. And even tough I don't visually see it or experience it(no breaks in downloads or live streams), I keep getting this annoying notifications. Sometimes my internet will run almost a day without receiving that notification, other days its a few times a day.

Now today I started all over with flashing my router with V21.02.1 and already 3 hours later I get that notification again. Since I don't know much about which values I must put in under WAN, I wanted to see if maybe one of you can point me in the right direction what can be the issue. Cause I think it must be an issue under my WAN settings, since thats the PPPoe protocol, but I might be wrong.

I will paste below my system log and my network configuration. Maybe you see something which isn't right that hopefully can fix this issue:). Systemlog is just the timeframe when I must have received the new notification of break in internet.

Thanks in advance

systemlog

Fri Feb 11 13:30:16 2022 daemon.info hostapd: wlan1: STA 6c:c4:d5:55:2f:fb WPA: pairwise key handshake completed (RSN)
Fri Feb 11 13:30:17 2022 daemon.info dnsmasq-dhcp[2524]: DHCPDISCOVER(br-lan) 6c:c4:d5:55:2f:fb
Fri Feb 11 13:30:17 2022 daemon.info dnsmasq-dhcp[2524]: DHCPOFFER(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Fri Feb 11 13:30:17 2022 daemon.info dnsmasq-dhcp[2524]: DHCPREQUEST(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Fri Feb 11 13:30:17 2022 daemon.info dnsmasq-dhcp[2524]: DHCPACK(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb android-e7e7bbb06323587d
Fri Feb 11 14:27:05 2022 daemon.info hostapd: wlan1: STA 00:22:fa:88:eb:de IEEE 802.11: authenticated
Fri Feb 11 14:27:05 2022 daemon.info hostapd: wlan1: STA 00:22:fa:88:eb:de IEEE 802.11: associated (aid 3)
Fri Feb 11 14:27:05 2022 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 00:22:fa:88:eb:de
Fri Feb 11 14:27:05 2022 daemon.info hostapd: wlan1: STA 00:22:fa:88:eb:de WPA: pairwise key handshake completed (RSN)
Fri Feb 11 14:27:05 2022 daemon.info dnsmasq-dhcp[2524]: DHCPREQUEST(br-lan) 192.168.1.209 00:22:fa:88:eb:de
Fri Feb 11 14:27:05 2022 daemon.info dnsmasq-dhcp[2524]: DHCPACK(br-lan) 192.168.1.209 00:22:fa:88:eb:de WIN-4SGHEROGVUU
Fri Feb 11 14:30:52 2022 daemon.err uhttpd[1515]: luci: accepted login on / for root from 192.168.1.209

/etc/config/network

config interface 'loopback'
	option device 'lo'
	option proto 'static'
	option ipaddr '127.0.0.1'
	option netmask '255.0.0.0'

config globals 'globals'
	option ula_prefix 'fdcf:1291:6296::/48'

config device
	option name 'br-lan'
	option type 'bridge'
	list ports 'eth0.1'

config device
	option name 'eth0.1'
	option macaddr '70:8b:cd:e9:ee:7c'

config interface 'lan'
	option device 'br-lan'
	option proto 'static'
	option ipaddr '192.168.1.1'
	option netmask '255.255.255.0'
	option ip6assign '60'
	list dns '154.127.57.224'
	list dns '129.232.164.26'

config interface 'wan'
	option device 'eth0.2'
	option proto 'pppoe'
	option force_link '1'
	option username 'xxx'
	option password 'xxx'
	option ipv6 'auto'
	option keepalive '10 6'
	option peerdns '0'
	list dns '208.67.222.222'
	list dns '208.67.220.220'
	list dns '1.1.1.1'
	list dns '1.0.0.1'
	option demand '0'
	option mtu '1500'

config interface 'wan6'
	option device 'eth0.2'
	option proto 'dhcpv6'
	option reqaddress 'none'
	option reqprefix 'auto'

config switch
	option name 'switch0'
	option reset '1'
	option enable_vlan '1'

config switch_vlan
	option device 'switch0'
	option vlan '1'
	option ports '1 2 3 4 6t'

config switch_vlan
	option device 'switch0'
	option vlan '2'
	option ports '0 6t'

config interface 'OPVN'
	option proto 'none'
	option device 'tun0'

frollic · February 11, 2022, 4:19pm

Beside the massages from your ISP, do you actually experience outages?

Would be interesting to know what criteria have to be fulfilled, for them to send one out.

Mars4 · February 11, 2022, 4:35pm

Hi, no I don't experience any outages. That's why I cant understand why I get this messages on a daily basis from them.

When I asked ISP why I get this notification, they replied"The messages you get via SMS are generated by the system in case it detects a disconnection on the line".

So that's all I know. And with previous router I never got these notifications. So I really have no clue. But since I am not that familliar with Openwrt I thaught maybe there is some setting wrong...

Did you see any issues in configuration or logs I posted?

Mars4 · February 11, 2022, 4:48pm

Mars4 · February 11, 2022, 4:49pm

Mars4 · February 11, 2022, 4:50pm

So these are the print screens from my settings in Luci. My apologies for not posting them in one post, but since I am new to the forum I as only allowed one picture per post:).

frollic · February 11, 2022, 7:04pm

Post your dmesg.

Suggest you also get an infinite ping running, towards 8.8.8.8, from a LAN client or the openwrt device, and wait for disconnection alerts.

If you do, check if there were and ping timeouts.
If you don't, keep it runnig, to see it acts as a keep alive for your connection.

Mars4 · February 11, 2022, 8:01pm

dmesg

[    0.000000] Linux version 5.4.154 (builder@buildhost) (gcc version 8.4.0 (OpenWrt GCC 8.4.0 r16325-88151b8303)) #0 Sun Oct 24 09:01:35 2021
[    0.000000] Board has DDR2
[    0.000000] Analog PMU set to hw control
[    0.000000] Digital PMU set to hw control
[    0.000000] SoC Type: MediaTek MT7620A ver:2 eco:6
[    0.000000] printk: bootconsole [early0] enabled
[    0.000000] CPU0 revision is: 00019650 (MIPS 24KEc)
[    0.000000] MIPS: machine is Asus RT-AC51U
[    0.000000] Initrd not found or empty - disabling initrd
[    0.000000] Primary instruction cache 64kB, VIPT, 4-way, linesize 32 bytes.
[    0.000000] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.000000] Zone ranges:
[    0.000000]   Normal   [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] Movable zone start for each node
[    0.000000] Early memory node ranges
[    0.000000]   node   0: [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] Initmem setup node 0 [mem 0x0000000000000000-0x0000000003ffffff]
[    0.000000] On node 0 totalpages: 16384
[    0.000000]   Normal zone: 144 pages used for memmap
[    0.000000]   Normal zone: 0 pages reserved
[    0.000000]   Normal zone: 16384 pages, LIFO batch:3
[    0.000000] pcpu-alloc: s0 r0 d32768 u32768 alloc=1*32768
[    0.000000] pcpu-alloc: [0] 0
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 16240
[    0.000000] Kernel command line: console=ttyS0,57600 rootfstype=squashfs,jffs2
[    0.000000] Dentry cache hash table entries: 8192 (order: 3, 32768 bytes, linear)
[    0.000000] Inode-cache hash table entries: 4096 (order: 2, 16384 bytes, linear)
[    0.000000] Writing ErrCtl register=0007cee0
[    0.000000] Readback ErrCtl register=0007cee0
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 57496K/65536K available (5065K kernel code, 211K rwdata, 632K rodata, 1188K init, 213K bss, 8040K reserved, 0K cma-reserved)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=1, Nodes=1
[    0.000000] NR_IRQS: 256
[    0.000000] random: get_random_bytes called from 0x805c7a28 with crng_init=0
[    0.000000] CPU Clock: 580MHz
[    0.000000] clocksource: systick: mask: 0xffff max_cycles: 0xffff, max_idle_ns: 583261500 ns
[    0.000000] systick: enable autosleep mode
[    0.000000] systick: running - mult: 214748, shift: 32
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 6590553264 ns
[    0.000011] sched_clock: 32 bits at 290MHz, resolution 3ns, wraps every 7405115902ns
[    0.007604] Calibrating delay loop... 385.02 BogoMIPS (lpj=770048)
[    0.041399] pid_max: default: 32768 minimum: 301
[    0.046086] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.053136] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.067626] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.077081] futex hash table entries: 256 (order: -1, 3072 bytes, linear)
[    0.083756] pinctrl core: initialized pinctrl subsystem
[    0.090365] NET: Registered protocol family 16
[    0.353169] PCI host bridge /pcie@10140000 ranges:
[    0.357777]  MEM 0x0000000020000000..0x000000002fffffff
[    0.362819]   IO 0x0000000010160000..0x000000001016ffff
[    0.390556] rt2880_gpio 10000600.gpio: registering 24 gpios
[    0.396022] rt2880_gpio 10000600.gpio: registering 24 irq handlers
[    0.402026] GPIO line 10 (enable-leds) hogged as output/low
[    0.407742] rt2880_gpio 10000688.gpio: registering 1 gpios
[    0.413072] rt2880_gpio 10000688.gpio: registering 1 irq handlers
[    0.419921] PCI host bridge to bus 0000:00
[    0.423893] pci_bus 0000:00: root bus resource [mem 0x20000000-0x2fffffff]
[    0.430503] pci_bus 0000:00: root bus resource [io  0x10160000-0x1016ffff]
[    0.437163] pci_bus 0000:00: root bus resource [??? 0x00000000 flags 0x0]
[    0.443736] pci_bus 0000:00: No busn resource found for root bus, will use [bus 00-ff]
[    0.451454] pci 0000:00:00.0: [1814:0801] type 01 class 0x060400
[    0.457263] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x7fffffff]
[    0.463309] pci 0000:00:00.0: reg 0x14: [mem 0x20200000-0x2020ffff]
[    0.469450] pci 0000:00:00.0: supports D1
[    0.473265] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[    0.481271] pci 0000:01:00.0: [14c3:7650] type 00 class 0x028000
[    0.487118] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x000fffff]
[    0.493289] pci 0000:01:00.0: PME# supported from D0 D3hot D3cold
[    0.499429] pci 0000:01:00.1: [14c3:8650] type 00 class 0x0d1100
[    0.505256] pci 0000:01:00.1: reg 0x10: [mem 0x00000000-0x000fffff]
[    0.511427] pci 0000:01:00.1: supports D1
[    0.515242] pci 0000:01:00.1: PME# supported from D0 D1 D3hot D3cold
[    0.523492] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    0.529888] pci_bus 0000:00: busn_res: [bus 00-ff] end is updated to 01
[    0.536296] pci 0000:00:00.0: BAR 0: no space for [mem size 0x80000000]
[    0.542668] pci 0000:00:00.0: BAR 0: failed to assign [mem size 0x80000000]
[    0.549416] pci 0000:00:00.0: BAR 8: assigned [mem 0x20000000-0x201fffff]
[    0.555993] pci 0000:00:00.0: BAR 1: assigned [mem 0x20200000-0x2020ffff]
[    0.562578] pci 0000:01:00.0: BAR 0: assigned [mem 0x20000000-0x200fffff]
[    0.569150] pci 0000:01:00.1: BAR 0: assigned [mem 0x20100000-0x201fffff]
[    0.575721] pci 0000:00:00.0: PCI bridge to [bus 01]
[    0.580523] pci 0000:00:00.0:   bridge window [mem 0x20000000-0x201fffff]
[    0.587213] workqueue: max_active 576 requested for napi_workq is out of range, clamping between 1 and 512
[    0.602374] clocksource: Switched to clocksource systick
[    0.608657] thermal_sys: Registered thermal governor 'step_wise'
[    0.609088] NET: Registered protocol family 2
[    0.619271] IP idents hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.627158] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 4096 bytes, linear)
[    0.635300] TCP established hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.642695] TCP bind hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.649513] TCP: Hash tables configured (established 1024 bind 1024)
[    0.655816] UDP hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.662161] UDP-Lite hash table entries: 256 (order: 0, 4096 bytes, linear)
[    0.669204] NET: Registered protocol family 1
[    0.673491] PCI: CLS 0 bytes, default 32
[    0.680483] rt-timer 10000100.timer: maximum frequency is 1220Hz
[    0.688615] workingset: timestamp_bits=14 max_order=14 bucket_order=0
[    0.703566] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.709217] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.734284] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 252)
[    0.744508] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    0.753657] printk: console [ttyS0] disabled
[    0.757869] 10000c00.uartlite: ttyS0 at MMIO 0x10000c00 (irq = 20, base_baud = 2500000) is a Palmchip BK-3103
[    0.767467] printk: console [ttyS0] enabled
[    0.783953] printk: bootconsole [early0] disabled
[    0.811954] spi spi0.0: force spi mode3
[    0.820640] spi-nor spi0.0: mx25l12805d (16384 Kbytes)
[    0.830986] 4 fixed-partitions partitions found on MTD device spi0.0
[    0.843626] Creating 4 MTD partitions on "spi0.0":
[    0.853164] 0x000000000000-0x000000030000 : "u-boot"
[    0.864185] 0x000000030000-0x000000040000 : "u-boot-env"
[    0.875920] 0x000000040000-0x000000050000 : "factory"
[    0.887123] 0x000000050000-0x000001000000 : "firmware"
[    0.902428] 2 uimage-fw partitions found on MTD device firmware
[    0.914267] Creating 2 MTD partitions on "firmware":
[    0.924156] 0x000000000000-0x0000001e641f : "kernel"
[    0.935194] 0x0000001e641f-0x000000fb0000 : "rootfs"
[    0.946227] mtd: device 5 (rootfs) set to be root filesystem
[    0.959613] 1 squashfs-split partitions found on MTD device rootfs
[    0.971996] 0x000000510000-0x000000fb0000 : "rootfs_data"
[    0.984785] libphy: Fixed MDIO Bus: probed
[    1.002763] gsw: setting port4 to ephy mode
[    1.011165] mtk_soc_eth 10100000.ethernet eth0 (uninitialized): port 0 link up (100Mbps/Full duplex)
[    1.029832] mtk_soc_eth 10100000.ethernet: loaded mt7620 driver
[    1.042395] mtk_soc_eth 10100000.ethernet eth0: mediatek frame engine at 0xb0100000, irq 5
[    1.059405] rt2880_wdt 10000120.watchdog: Initialized
[    1.071180] NET: Registered protocol family 10
[    1.084598] Segment Routing with IPv6
[    1.092118] NET: Registered protocol family 17
[    1.101058] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    1.126822] 8021q: 802.1Q VLAN Support v1.8
[    1.144768] VFS: Mounted root (squashfs filesystem) readonly on device 31:5.
[    1.165549] Freeing unused kernel memory: 1188K
[    1.174578] This architecture does not have kernel memory protection.
[    1.187386] Run /sbin/init as init process
[    1.369635] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[    1.424204] random: fast init done
[    2.196812] init: Console is alive
[    2.203946] init: - watchdog -
[    3.577221] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    3.789693] usbcore: registered new interface driver usbfs
[    3.800766] usbcore: registered new interface driver hub
[    3.811465] usbcore: registered new device driver usb
[    3.828624] ehci_hcd: USB 2.0 'Enhanced' Host Controller (EHCI) Driver
[    3.843495] ehci-fsl: Freescale EHCI Host controller driver
[    3.856213] ehci-platform: EHCI generic platform driver
[    3.877022] phy phy-usbphy.0: remote usb device wakeup disabled
[    3.888805] phy phy-usbphy.0: UTMI 16bit 30MHz
[    3.897646] ehci-platform 101c0000.ehci: EHCI Host Controller
[    3.909115] ehci-platform 101c0000.ehci: new USB bus registered, assigned bus number 1
[    3.925002] ehci-platform 101c0000.ehci: irq 26, io mem 0x101c0000
[    3.941804] ehci-platform 101c0000.ehci: USB 2.0 started, EHCI 1.00
[    3.955356] hub 1-0:1.0: USB hub found
[    3.963340] hub 1-0:1.0: 1 port detected
[    3.976547] ohci_hcd: USB 1.1 'Open' Host Controller (OHCI) Driver
[    3.990713] ohci-platform: OHCI generic platform driver
[    4.001484] ohci-platform 101c1000.ohci: Generic Platform OHCI controller
[    4.015047] ohci-platform 101c1000.ohci: new USB bus registered, assigned bus number 2
[    4.030915] ohci-platform 101c1000.ohci: irq 26, io mem 0x101c1000
[    4.068020] hub 2-0:1.0: USB hub found
[    4.076000] hub 2-0:1.0: 1 port detected
[    4.088779] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    4.107646] init: - preinit -
[    5.318300] random: jshn: uninitialized urandom read (4 bytes read)
[    5.421100] random: jshn: uninitialized urandom read (4 bytes read)
[    5.655471] random: jshn: uninitialized urandom read (4 bytes read)
[    6.311085] 8021q: adding VLAN 0 to HW filter on device eth0
[    6.383316] urandom_read: 4 callbacks suppressed
[    6.383325] random: procd: uninitialized urandom read (4 bytes read)
[    8.113749] jffs2: notice: (499) jffs2_build_xattr_subsystem: complete building xattr subsystem, 62 of xdatum (44 unchecked, 18 orphan) and 89 of xref (9 dead, 10 orphan) found.
[    8.148296] mount_root: switching to jffs2 overlay
[    8.164006] overlayfs: upper fs does not support tmpfile.
[    8.184841] urandom-seed: Seeding with /etc/urandom.seed
[    8.347105] procd: - early -
[    8.353057] procd: - watchdog -
[    8.810694] procd: - watchdog -
[    8.818675] procd: - ubus -
[    8.899820] random: ubusd: uninitialized urandom read (4 bytes read)
[    8.915309] random: ubusd: uninitialized urandom read (4 bytes read)
[    8.939682] procd: - init -
[   10.273802] kmodloader: loading kernel modules from /etc/modules.d/*
[   10.346399] tun: Universal TUN/TAP device driver, 1.6
[   10.584230] urngd: jent-rng init failed, err: 2
[   10.616742] Loading modules backported from Linux version v5.10.68-0-g4d8524048a35
[   10.631862] Backport generated by backports.git v5.10.68-1-0-ga4f9ba32
[   10.675962] xt_time: kernel timezone is -0000
[   10.867529] PPP generic driver version 2.4.2
[   10.879020] NET: Registered protocol family 24
[   10.919283] mt76x0e 0000:01:00.0: card - bus=0x1, slot = 0x0 irq=4
[   10.931911] mt76x0e 0000:01:00.0: ASIC revision: 76100002
[   10.945348] mt76x0e 0000:01:00.0: Firmware Version: 0.1.00
[   11.057249] mt76x0e 0000:01:00.0: EEPROM ver:01 fae:00
[   11.070239] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   11.202265] rt2800_wmac 10180000.wmac: loaded eeprom from mtd device "factory"
[   11.216696] ieee80211 phy1: rt2x00_set_rt: Info - RT chipset 6352, rev 0500 detected
[   11.232136] ieee80211 phy1: rt2x00_set_rf: Info - RF chipset 7620 detected
[   11.246094] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[   11.255628] kmodloader: done loading kernel modules from /etc/modules.d/*
[   18.394697] random: crng init done
[   29.158321] 8021q: adding VLAN 0 to HW filter on device eth0
[   29.219251] device eth0 entered promiscuous mode
[   29.252941] br-lan: port 1(eth0.1) entered blocking state
[   29.263900] br-lan: port 1(eth0.1) entered disabled state
[   29.275093] device eth0.1 entered promiscuous mode
[   29.381458] br-lan: port 1(eth0.1) entered blocking state
[   29.392266] br-lan: port 1(eth0.1) entered forwarding state
[   30.165010] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   33.340453] pppoe-wan: renamed from ppp0
[   35.437408] ieee80211 phy1: rt2800_rf_self_txdc_cal: Info - RF Tx self calibration start
[   35.454045] ieee80211 phy1: rt2800_rf_self_txdc_cal: Info - RF Tx self calibration end
[   37.588481] ieee80211 phy1: rt2800_loft_iq_calibration: Info - LOFT Calibration Done!
[   37.608163] ieee80211 phy1: rt2800_iq_search: Info - IQCalibration Start!
[   37.635612] ieee80211 phy1: rt2800_iq_search: Info - IQCalibration Done! CH = 0, (gain= 0, phase=3b)
[   37.654682] ieee80211 phy1: rt2800_iq_search: Info - IQCalibration Start!
[   37.682568] ieee80211 phy1: rt2800_iq_search: Info - IQCalibration Done! CH = 1, (gain= 1, phase=3d)
[   37.700777] ieee80211 phy1: rt2800_loft_iq_calibration: Info - TX IQ Calibration Done!
[   37.853775] ieee80211 phy1: rt2800_rxiq_calibration: Info - RXIQ G_imb=-2, Ph_rx=-5
[   37.881687] ieee80211 phy1: rt2800_rxiq_calibration: Info - RXIQ G_imb=0, Ph_rx=2
[   38.107456] br-lan: port 2(wlan1) entered blocking state
[   38.118096] br-lan: port 2(wlan1) entered disabled state
[   38.129210] device wlan1 entered promiscuous mode
[   38.589495] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   38.602443] br-lan: port 2(wlan1) entered blocking state
[   38.613055] br-lan: port 2(wlan1) entered forwarding state
[   38.732059] br-lan: port 3(wlan0) entered blocking state
[   38.742870] br-lan: port 3(wlan0) entered disabled state
[   38.754018] device wlan0 entered promiscuous mode
[   38.763593] br-lan: port 3(wlan0) entered blocking state
[   38.774194] br-lan: port 3(wlan0) entered forwarding state
[   39.060435] br-lan: port 3(wlan0) entered disabled state
[   39.654969] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   39.668029] br-lan: port 3(wlan0) entered blocking state
[   39.678661] br-lan: port 3(wlan0) entered forwarding state
[  767.677659] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[  768.231989] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[  813.597577] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[  814.166004] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[  859.782198] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[  860.347310] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[  865.712186] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[  866.277066] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[  963.070669] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[ 2343.853126] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[ 2357.309113] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[ 2373.255710] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[ 4368.088428] pppoe-wan: renamed from ppp0
[ 4407.475688] pppoe-wan: renamed from ppp0
[ 5883.580619] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[ 6832.299616] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
[ 7113.104699] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
[ 7113.667639] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)

Ping results

Pinging 8.8.8.8 with 32 bytes of data:
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=27ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=27ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=44ms TTL=59
Reply from 8.8.8.8: bytes=32 time=52ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=19ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=95ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=98ms TTL=59
Reply from 8.8.8.8: bytes=32 time=113ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=26ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Request timed out.
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=181ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=256ms TTL=59
Request timed out.
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=19ms TTL=59
Reply from 8.8.8.8: bytes=32 time=74ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=27ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=20ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=28ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=24ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=29ms TTL=59
Reply from 8.8.8.8: bytes=32 time=25ms TTL=59
Reply from 8.8.8.8: bytes=32 time=21ms TTL=59
Reply from 8.8.8.8: bytes=32 time=22ms TTL=59
Reply from 8.8.8.8: bytes=32 time=23ms TTL=59

I hope this is what you were asking for? For the ping test, you can see there do were a few requested time outs. Maybe it is relevant to mention that I am using custom rules in my firewall which preroute dns 8.8.8.8 to my smart dns to get around chromecast issue of blocking my smart dns.

Or doesn't that matter? I actually tried also a ping to 1.1.1.1 and also that one had kinda same results as a ping to 8.8.8.8 with some requested time outs.

frollic · February 11, 2022, 8:04pm

Does the ping timeouts match the interface down errors?

Mars4 · February 11, 2022, 8:37pm

Do you mean internet disconnecting and getting an isp notification? No internet didn't disconnect and no notification. As I said in the beginning I only get that notification once a day or so, sometimes twice.

Times may differ. It is just something weird and I want to find out if the issue is on my side or on isp his side. Do you think all my wan pppoe settings are right? Or can the issue still be on my side why I get disconnected?(according to isp)

I have never seen my internet disconnecting or live streams disconnecting. But something must trigger their system which sends smses telling me there is a break in my connection.

Mars4 · February 15, 2022, 8:16am

I had almost given up on this issue since I never see any router log which might indicate an issue on my side. But now this Morning I got again an notification from ISP about break in my connection and now I went again to check my router log. This time it appears to have a log about issues with pppoe and wan, even two times during last night.

But I don't know much about all this info, can maybe someone have a look and see if the issue do was on my side this time and what the solution might be to get this issue sorted out. Thanks

Router log:

Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: No response to 10 echo-requests
Mon Feb 14 23:45:07 2022 daemon.notice pppd[2016]: Serial link appears to be disconnected.
Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: Connect time 782.0 minutes.
Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: Sent 162512225 bytes, received 2092666129 bytes.
Mon Feb 14 23:45:07 2022 daemon.notice netifd: Network device 'pppoe-wan' link is down
Mon Feb 14 23:45:07 2022 daemon.notice netifd: Interface 'wan' has lost the connection
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Mon Feb 14 23:45:13 2022 daemon.notice pppd[2016]: Connection terminated.
Mon Feb 14 23:45:13 2022 daemon.info pppd[2016]: Sent PADT
Mon Feb 14 23:45:13 2022 daemon.notice pppd[2016]: Modem hangup
Mon Feb 14 23:45:13 2022 daemon.info pppd[2016]: Exit.
Mon Feb 14 23:45:14 2022 daemon.notice netifd: Interface 'wan' is now down
Mon Feb 14 23:45:14 2022 daemon.notice netifd: Interface 'wan' is setting up now
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - slhc
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - ppp_generic
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - pppox
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - pppoe
Mon Feb 14 23:45:14 2022 daemon.info pppd[4334]: Plugin rp-pppoe.so loaded.
Mon Feb 14 23:45:14 2022 daemon.info pppd[4334]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Mon Feb 14 23:45:14 2022 daemon.notice pppd[4334]: pppd 2.4.8 started by root, uid 0
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Mon Feb 14 23:45:29 2022 daemon.warn pppd[4334]: Timeout waiting for PADO packets
Mon Feb 14 23:45:29 2022 daemon.err pppd[4334]: Unable to complete PPPoE Discovery
Mon Feb 14 23:45:29 2022 daemon.info pppd[4334]: Exit.
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is now down
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is setting up now
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - slhc
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - ppp_generic
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - pppox
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - pppoe
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Plugin rp-pppoe.so loaded.
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: pppd 2.4.8 started by root, uid 0
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: PPP session is 41149
Mon Feb 14 23:45:29 2022 daemon.warn pppd[4574]: Connected to 08:55:31:2c:ca:d7 via interface eth0.2
Mon Feb 14 23:45:29 2022 kern.info kernel: [16547.536501] pppoe-wan: renamed from ppp0
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Renamed interface ppp0 to pppoe-wan
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Using interface pppoe-wan
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: Connect: pppoe-wan <--> eth0.2
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: CHAP authentication succeeded
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: peer from calling number 08:55:31:2C:CA:D7 authorized
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: local  IP address 100.68.9.80
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: remote IP address 41.87.202.66
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: primary   DNS address 1.1.1.1
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: secondary DNS address 8.8.4.4
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Network device 'pppoe-wan' link is up
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is now up
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.222.222#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.220.220#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 1.1.1.1#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 1.0.0.1#53
Mon Feb 14 23:45:30 2022 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: No response to 10 echo-requests
Tue Feb 15 01:01:50 2022 daemon.notice pppd[4574]: Serial link appears to be disconnected.
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: Connect time 76.4 minutes.
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: Sent 3539611 bytes, received 36938384 bytes.
Tue Feb 15 01:01:50 2022 daemon.notice netifd: Network device 'pppoe-wan' link is down
Tue Feb 15 01:01:50 2022 daemon.notice netifd: Interface 'wan' has lost the connection
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 01:01:56 2022 daemon.notice pppd[4574]: Connection terminated.
Tue Feb 15 01:01:56 2022 daemon.info pppd[4574]: Sent PADT
Tue Feb 15 01:01:56 2022 daemon.notice pppd[4574]: Modem hangup
Tue Feb 15 01:01:56 2022 daemon.info pppd[4574]: Exit.
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is now down
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is setting up now
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - slhc
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - ppp_generic
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - pppox
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - pppoe
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Plugin rp-pppoe.so loaded.
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: pppd 2.4.8 started by root, uid 0
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: PPP session is 34945
Tue Feb 15 01:01:57 2022 daemon.warn pppd[5172]: Connected to 08:55:31:2c:c5:19 via interface eth0.2
Tue Feb 15 01:01:57 2022 kern.info kernel: [18127.138877] pppoe-wan: renamed from ppp0
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Renamed interface ppp0 to pppoe-wan
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Using interface pppoe-wan
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: Connect: pppoe-wan <--> eth0.2
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: CHAP authentication succeeded
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: peer from calling number 08:55:31:2C:C5:19 authorized
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: local  IP address 100.68.29.208
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: remote IP address 41.87.202.67
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: primary   DNS address 1.1.1.1
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: secondary DNS address 8.8.4.4
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Network device 'pppoe-wan' link is up
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is now up
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.222.222#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.220.220#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 1.1.1.1#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 1.0.0.1#53
Tue Feb 15 01:01:57 2022 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 02:42:34 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Tue Feb 15 02:42:34 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb android-e7e7bbb06323587d
Tue Feb 15 03:29:38 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Tue Feb 15 03:29:38 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf Chromecast
Tue Feb 15 03:45:53 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Tue Feb 15 03:45:53 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d M2006C3MG-Redmi9C

moeller0 · February 15, 2022, 8:42am

But there you have it, there are issues with reaching the PPPoE servers on the ISP side...
according to your dmesg above these doe not seem to be correlated with eth0 going down, so this might be truly PPPoE related. What kind of link do you have, dsl? If yes, what do the error counters show around PPPoE disconnects?

Also, have a look at /etc/ppp/options:

root@turris:~# cat /etc/ppp/options
debug
logfile /srv/pppd_logs/ppp.log
noipdefault
noaccomp
nopcomp
nocrtscts
lock
maxfail 0

if you uncomment #debug to debug pppoe will be more verbose in the log and logfile /srv/pppd_logs/ppp.log instructs ppp to save the log at the configured location (just be carefull that logfile will grow slowly but infinitely, so make sure there is sufficient space and/or stop logging after you are done debugging the issue)

Mars4 · February 15, 2022, 9:03am

Hi, I have a fibre cable connection. I did copied my whole log file in my previous post. So the error encounter should be in there?

And I did now have a look at that /etc/ppp/options file and it shows following:

#debug
logfile /dev/null
noipdefault
noaccomp
nopcomp
nocrtscts
lock
maxfail 0

So now I must just replace all that text with with your text from above? And then wait on next disconnect and go check then that /srv/pppd_logs/ppp.log file and post all here again? Thanks already for assisting me, cause I am really clueless about this all:).

moeller0 · February 15, 2022, 9:31am

No idea what exactly "fibre cable" is, but it appears not to be DSL so no DSL error counters....

No if you want debug output replace #debug with debug (just remove the #), if you want a persistent log written to file in addition to the debug output appearing in the logread output replace the /dev/null in logfile /dev/null with a full path to a writable file like /tmp/ppp_logfile.txt but keep in mind that this will grow so you need to make sure there is enough space and/or stop the logging before the file gets too large.

One option, but if you catch the disconnect quickly enough the debug output will still be visible in logread output, which is IMHO a bit more helpful as it also shows what else might have happened around the time of the PPPoE issues. But make sure that any logread output you post does not contain sensitive information like passwords or usernames (if it does just replace the true username with the string USERNAME and the real password with the string PASSWORD).

frollic · February 15, 2022, 9:48am

i think logread -f using putty will provide continuous output, just scroll back ...

Mars4 · February 15, 2022, 10:03am

Here is a large part of my readlog from yesterday until now(I couldn't post all due limit on letters). The two disconnects were at 23.45:07h yesterday and at 01.01:50h this early Morning. And my internet connection is what you call in US "Cable broadband".Can you have a look at this when you have time and if you don't find the issue/solution, then I will create a new log file for next disconnect.

Mostly this happens only one or two times a day that I get a notification. I also forwarded my logs to my ISP, maybe they can do something on issue as well, since I never had this issue until two weeks ago which more or less started when I started using OpenWrt, that's why I first thought issue is with me, but after reverting back to original stock firmware I got same notifications.

Readlog:

Mon Feb 14 19:33:01 2022 daemon.err uhttpd[1516]: luci: accepted login on / for root from 192.168.1.208
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.222.222#53
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.220.220#53
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 1.1.1.1#53
Mon Feb 14 19:34:19 2022 daemon.info dnsmasq[2534]: using nameserver 1.0.0.1#53
Mon Feb 14 20:42:32 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Mon Feb 14 20:42:32 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb android-e7e7bbb06323587d
Mon Feb 14 21:45:50 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d IEEE 802.11: authenticated
Mon Feb 14 21:45:50 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d IEEE 802.11: associated (aid 3)
Mon Feb 14 21:45:50 2022 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 9a:49:ab:1d:10:0d
Mon Feb 14 21:45:50 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d WPA: pairwise key handshake completed (RSN)
Mon Feb 14 21:45:54 2022 daemon.info dnsmasq-dhcp[2534]: DHCPDISCOVER(br-lan) 9a:49:ab:1d:10:0d
Mon Feb 14 21:45:54 2022 daemon.info dnsmasq-dhcp[2534]: DHCPOFFER(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Mon Feb 14 21:45:54 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Mon Feb 14 21:45:54 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d M2006C3MG-Redmi9C
Mon Feb 14 21:47:59 2022 kern.info kernel: [14022.273881] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
Mon Feb 14 22:00:22 2022 daemon.info dnsmasq-dhcp[2534]: DHCPDISCOVER(br-lan) cc:b1:1a:2a:15:e8
Mon Feb 14 22:00:22 2022 daemon.info dnsmasq-dhcp[2534]: DHCPOFFER(br-lan) 192.168.1.248 cc:b1:1a:2a:15:e8
Mon Feb 14 22:00:22 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.248 cc:b1:1a:2a:15:e8
Mon Feb 14 22:00:22 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.248 cc:b1:1a:2a:15:e8
Mon Feb 14 22:00:30 2022 kern.info kernel: [14289.597763] mtk_soc_eth 10100000.ethernet eth0: port 1 link up (100Mbps/Full duplex)
Mon Feb 14 22:07:32 2022 daemon.err uhttpd[1516]: luci: accepted login on / for root from 192.168.1.208
Mon Feb 14 22:12:24 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Mon Feb 14 22:12:24 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf Chromecast
Mon Feb 14 22:21:55 2022 kern.info kernel: [14798.981818] mtk_soc_eth 10100000.ethernet eth0: port 1 link down
Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: No response to 10 echo-requests
Mon Feb 14 23:45:07 2022 daemon.notice pppd[2016]: Serial link appears to be disconnected.
Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: Connect time 782.0 minutes.
Mon Feb 14 23:45:07 2022 daemon.info pppd[2016]: Sent 162512225 bytes, received 2092666129 bytes.
Mon Feb 14 23:45:07 2022 daemon.notice netifd: Network device 'pppoe-wan' link is down
Mon Feb 14 23:45:07 2022 daemon.notice netifd: Interface 'wan' has lost the connection
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Mon Feb 14 23:45:07 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:10 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Mon Feb 14 23:45:13 2022 daemon.notice pppd[2016]: Connection terminated.
Mon Feb 14 23:45:13 2022 daemon.info pppd[2016]: Sent PADT
Mon Feb 14 23:45:13 2022 daemon.notice pppd[2016]: Modem hangup
Mon Feb 14 23:45:13 2022 daemon.info pppd[2016]: Exit.
Mon Feb 14 23:45:14 2022 daemon.notice netifd: Interface 'wan' is now down
Mon Feb 14 23:45:14 2022 daemon.notice netifd: Interface 'wan' is setting up now
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - slhc
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - ppp_generic
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - pppox
Mon Feb 14 23:45:14 2022 daemon.err insmod: module is already loaded - pppoe
Mon Feb 14 23:45:14 2022 daemon.info pppd[4334]: Plugin rp-pppoe.so loaded.
Mon Feb 14 23:45:14 2022 daemon.info pppd[4334]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Mon Feb 14 23:45:14 2022 daemon.notice pppd[4334]: pppd 2.4.8 started by root, uid 0
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:16 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Mon Feb 14 23:45:29 2022 daemon.warn pppd[4334]: Timeout waiting for PADO packets
Mon Feb 14 23:45:29 2022 daemon.err pppd[4334]: Unable to complete PPPoE Discovery
Mon Feb 14 23:45:29 2022 daemon.info pppd[4334]: Exit.
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is now down
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is setting up now
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - slhc
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - ppp_generic
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - pppox
Mon Feb 14 23:45:29 2022 daemon.err insmod: module is already loaded - pppoe
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Plugin rp-pppoe.so loaded.
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: pppd 2.4.8 started by root, uid 0
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: PPP session is 41149
Mon Feb 14 23:45:29 2022 daemon.warn pppd[4574]: Connected to 08:55:31:2c:ca:d7 via interface eth0.2
Mon Feb 14 23:45:29 2022 kern.info kernel: [16547.536501] pppoe-wan: renamed from ppp0
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Renamed interface ppp0 to pppoe-wan
Mon Feb 14 23:45:29 2022 daemon.info pppd[4574]: Using interface pppoe-wan
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: Connect: pppoe-wan <--> eth0.2
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: CHAP authentication succeeded
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: peer from calling number 08:55:31:2C:CA:D7 authorized
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: local  IP address 100.68.9.80
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: remote IP address 41.87.202.66
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: primary   DNS address 1.1.1.1
Mon Feb 14 23:45:29 2022 daemon.notice pppd[4574]: secondary DNS address 8.8.4.4
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Network device 'pppoe-wan' link is up
Mon Feb 14 23:45:29 2022 daemon.notice netifd: Interface 'wan' is now up
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Mon Feb 14 23:45:29 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.222.222#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.220.220#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 1.1.1.1#53
Mon Feb 14 23:45:30 2022 daemon.info dnsmasq[2534]: using nameserver 1.0.0.1#53
Mon Feb 14 23:45:30 2022 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Mon Feb 14 23:45:32 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: No response to 10 echo-requests
Tue Feb 15 01:01:50 2022 daemon.notice pppd[4574]: Serial link appears to be disconnected.
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: Connect time 76.4 minutes.
Tue Feb 15 01:01:50 2022 daemon.info pppd[4574]: Sent 3539611 bytes, received 36938384 bytes.
Tue Feb 15 01:01:50 2022 daemon.notice netifd: Network device 'pppoe-wan' link is down
Tue Feb 15 01:01:50 2022 daemon.notice netifd: Interface 'wan' has lost the connection
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Tue Feb 15 01:01:50 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 01:01:53 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 01:01:56 2022 daemon.notice pppd[4574]: Connection terminated.
Tue Feb 15 01:01:56 2022 daemon.info pppd[4574]: Sent PADT
Tue Feb 15 01:01:56 2022 daemon.notice pppd[4574]: Modem hangup
Tue Feb 15 01:01:56 2022 daemon.info pppd[4574]: Exit.
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is now down
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is setting up now
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - slhc
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - ppp_generic
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - pppox
Tue Feb 15 01:01:57 2022 daemon.err insmod: module is already loaded - pppoe
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Plugin rp-pppoe.so loaded.
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: pppd 2.4.8 started by root, uid 0
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: PPP session is 34945
Tue Feb 15 01:01:57 2022 daemon.warn pppd[5172]: Connected to 08:55:31:2c:c5:19 via interface eth0.2
Tue Feb 15 01:01:57 2022 kern.info kernel: [18127.138877] pppoe-wan: renamed from ppp0
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Renamed interface ppp0 to pppoe-wan
Tue Feb 15 01:01:57 2022 daemon.info pppd[5172]: Using interface pppoe-wan
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: Connect: pppoe-wan <--> eth0.2
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: CHAP authentication succeeded
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: peer from calling number 08:55:31:2C:C5:19 authorized
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: local  IP address 100.68.29.208
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: remote IP address 41.87.202.67
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: primary   DNS address 1.1.1.1
Tue Feb 15 01:01:57 2022 daemon.notice pppd[5172]: secondary DNS address 8.8.4.4
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Network device 'pppoe-wan' link is up
Tue Feb 15 01:01:57 2022 daemon.notice netifd: Interface 'wan' is now up
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain test
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain onion
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain localhost
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain local
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain invalid
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain bind
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using only locally-known addresses for domain lan
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 154.127.57.224#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 129.232.164.26#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.222.222#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 208.67.220.220#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 1.1.1.1#53
Tue Feb 15 01:01:57 2022 daemon.info dnsmasq[2534]: using nameserver 1.0.0.1#53
Tue Feb 15 01:01:57 2022 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 0 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 01:01:59 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 02:42:34 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Tue Feb 15 02:42:34 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb android-e7e7bbb06323587d
Tue Feb 15 03:29:38 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Tue Feb 15 03:29:38 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf Chromecast
Tue Feb 15 03:45:53 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Tue Feb 15 03:45:53 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d M2006C3MG-Redmi9C
Tue Feb 15 04:02:47 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED d8:eb:46:7b:9e:cf
Tue Feb 15 04:03:10 2022 daemon.info hostapd: wlan0: STA d8:eb:46:7b:9e:cf IEEE 802.11: authenticated
Tue Feb 15 04:03:10 2022 daemon.info hostapd: wlan0: STA d8:eb:46:7b:9e:cf IEEE 802.11: associated (aid 1)
Tue Feb 15 04:03:10 2022 daemon.notice hostapd: wlan0: AP-STA-CONNECTED d8:eb:46:7b:9e:cf
Tue Feb 15 04:03:10 2022 daemon.info hostapd: wlan0: STA d8:eb:46:7b:9e:cf WPA: pairwise key handshake completed (RSN)
Tue Feb 15 04:03:11 2022 daemon.info dnsmasq-dhcp[2534]: DHCPDISCOVER(br-lan) d8:eb:46:7b:9e:cf
Tue Feb 15 04:03:11 2022 daemon.info dnsmasq-dhcp[2534]: DHCPOFFER(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Tue Feb 15 04:03:11 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Tue Feb 15 04:03:11 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf Chromecast
Tue Feb 15 04:11:57 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: authenticated
Tue Feb 15 04:11:57 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: associated (aid 2)
Tue Feb 15 04:11:57 2022 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 04:11:57 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e WPA: pairwise key handshake completed (RSN)
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPDISCOVER(br-lan) 60:a5:e2:27:01:1e
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPOFFER(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq[2534]: read /etc/hosts - 4 addresses
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/odhcpd - 1 addresses
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq[2534]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: read /etc/ethers - 0 addresses
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPDISCOVER(br-lan) 60:a5:e2:27:01:1e
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPOFFER(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPREQUEST(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 04:12:01 2022 daemon.warn dnsmasq-dhcp[2534]: Ignoring domain stb.sun.ac.za for DHCP host name WINWYN523333
Tue Feb 15 04:12:01 2022 daemon.info dnsmasq-dhcp[2534]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 05:13:03 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 60:a5:e2:27:01:1e

moeller0 · February 15, 2022, 11:08am

This is the only thing I see and that simply means that your router sent 10 probes to the PPPoE server to make sure it is still reachable and got no response...

BTW, this is the first time I see PPPoE used over "Cable broadband", even though looking at Cyberwave's website, I would guess they use true fiber of some sort (no idea whether active (AON) or passive (PON) though).

As a quick test you could change the following values in the GUI page shown in https://forum.openwrt.org/t/pppoe-internet-disconnects/119977/4?u=moeller0

LCP echo failure threshold
LCP echo interval

currently this seems to be set for ~1 minute, for testing maybe set LCP echo failure threshold to 100 for 10 minutes? Again I repeat "for testing" it might be sufficient, it might be not, please test this and then see what next to try (maybe getting a packet capture while the network is idle otherwise and see whether LCP packets are sent in both directions).

Mars4 · February 15, 2022, 1:05pm

Thanks for the help. I changed LCP echo failure threshold to 100 and I also created that ppp logfile. So let us wait and see now.

I used same LCP echo failure threshold(10) on previous router as well for already two years, never problems. So if this increase would work, then its definetly a change or issue on ISP side.

And indeed they did used fiber cable. I think it's gpon? Don't know if thats same as the "pon" you mentioned, but I have seen people talking about this in fibre operator threads on my operator in my country.

moeller0 · February 15, 2022, 1:23pm

This is really just a test, the PPPoE server should not be unresponsive for even a minute, but let's see whether that helps. The problem is that IIRC the error message only ends up in the log if LCP echo failure threshold is exceeded, so in case this helps we have no idea how long it takes the server to respond again...

I think here is my misunderstanding, "cable" for me is short hand for coaxial cable as was initially used as an alternative to terrestrial broadcasting for TV signals; so DOCSIS. But that is clearly not the only way to read fiber cable (as the physical "carrier" delivering 1 or more optic fibers is also a "cable"). Sorry and thanks for patiently letting me understand

GPON is one of the "passive" optical network technologies, and one that currently is quite popular with ISPs, so a likely candidate. GPON end devices, often called ONU or ONT as far as I can tell offer only very limited diagnostic information (to the customer side, your ISP probably can read out a rich set of performance and error counters).

Mars4 · February 16, 2022, 6:39am

Last night it seems again I had same issue after increasing the LCP echo failure threshold to 100. So I still have no idea what causes it. I will post again a large part of readlog below. The issue occurred at 23:22:31h,

No response to 100 echo-requests

Readlog:

Tue Feb 15 23:14:08 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:14:08 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: authenticated
Tue Feb 15 23:14:08 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: associated (aid 2)
Tue Feb 15 23:14:08 2022 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:14:08 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e WPA: pairwise key handshake completed (RSN)
Tue Feb 15 23:14:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 23:14:08 2022 daemon.warn dnsmasq-dhcp[2529]: Ignoring domain stb.sun.ac.za for DHCP host name WINWYN523333
Tue Feb 15 23:14:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 23:14:24 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:14:27 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: authenticated
Tue Feb 15 23:14:27 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: associated (aid 2)
Tue Feb 15 23:14:27 2022 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:14:27 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e WPA: pairwise key handshake completed (RSN)
Tue Feb 15 23:14:27 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 23:14:27 2022 daemon.warn dnsmasq-dhcp[2529]: Ignoring domain stb.sun.ac.za for DHCP host name WINWYN523333
Tue Feb 15 23:14:27 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 23:15:32 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:16:32 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: authenticated
Tue Feb 15 23:16:32 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e IEEE 802.11: associated (aid 2)
Tue Feb 15 23:16:32 2022 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 60:a5:e2:27:01:1e
Tue Feb 15 23:16:32 2022 daemon.info hostapd: wlan0: STA 60:a5:e2:27:01:1e WPA: pairwise key handshake completed (RSN)
Tue Feb 15 23:16:32 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 23:16:32 2022 daemon.warn dnsmasq-dhcp[2529]: Ignoring domain stb.sun.ac.za for DHCP host name WINWYN523333
Tue Feb 15 23:16:32 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 23:18:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPINFORM(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 23:18:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 23:18:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPINFORM(br-lan) 192.168.1.132 60:a5:e2:27:01:1e
Tue Feb 15 23:18:08 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.132 60:a5:e2:27:01:1e WINWYN523333
Tue Feb 15 23:18:56 2022 daemon.notice hostapd: wlan1: AP-STA-DISCONNECTED 9a:49:ab:1d:10:0d
Tue Feb 15 23:19:07 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d IEEE 802.11: authenticated
Tue Feb 15 23:19:07 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d IEEE 802.11: associated (aid 2)
Tue Feb 15 23:19:07 2022 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 9a:49:ab:1d:10:0d
Tue Feb 15 23:19:07 2022 daemon.info hostapd: wlan1: STA 9a:49:ab:1d:10:0d WPA: pairwise key handshake completed (RSN)
Tue Feb 15 23:19:07 2022 daemon.info dnsmasq-dhcp[2529]: DHCPDISCOVER(br-lan) 9a:49:ab:1d:10:0d
Tue Feb 15 23:19:07 2022 daemon.info dnsmasq-dhcp[2529]: DHCPOFFER(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Tue Feb 15 23:19:07 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d
Tue Feb 15 23:19:07 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.244 9a:49:ab:1d:10:0d M2006C3MG-Redmi9C
Tue Feb 15 23:20:43 2022 daemon.warn dnsmasq[2529]: Maximum number of concurrent DNS queries reached (max: 150)
Tue Feb 15 23:22:31 2022 daemon.info pppd[3295]: No response to 100 echo-requests
Tue Feb 15 23:22:31 2022 daemon.notice pppd[3295]: Serial link appears to be disconnected.
Tue Feb 15 23:22:31 2022 daemon.info pppd[3295]: Connect time 608.8 minutes.
Tue Feb 15 23:22:31 2022 daemon.info pppd[3295]: Sent 140953411 bytes, received 2885060632 bytes.
Tue Feb 15 23:22:31 2022 daemon.notice netifd: Network device 'pppoe-wan' link is down
Tue Feb 15 23:22:31 2022 daemon.debug pppd[3295]: Script /lib/netifd/ppp-down started (pid 5274)
Tue Feb 15 23:22:31 2022 daemon.debug pppd[3295]: sent [LCP TermReq id=0x2 "Peer not responding"]
Tue Feb 15 23:22:31 2022 daemon.notice netifd: Interface 'wan' has lost the connection
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain test
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain onion
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain localhost
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain local
Tue Feb 15 23:22:31 2022 daemon.debug pppd[3295]: Script /lib/netifd/ppp-down finished (pid 5274), status = 0x1
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain invalid
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain bind
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain lan
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using nameserver 154.127.57.224#53
Tue Feb 15 23:22:31 2022 daemon.info dnsmasq[2529]: using nameserver 129.232.164.26#53
Tue Feb 15 23:22:34 2022 daemon.info dnsmasq[2529]: read /etc/hosts - 4 addresses
Tue Feb 15 23:22:34 2022 daemon.info dnsmasq[2529]: read /tmp/hosts/odhcpd - 2 addresses
Tue Feb 15 23:22:34 2022 daemon.info dnsmasq[2529]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 23:22:34 2022 daemon.info dnsmasq-dhcp[2529]: read /etc/ethers - 0 addresses
Tue Feb 15 23:22:34 2022 daemon.debug pppd[3295]: sent [LCP TermReq id=0x3 "Peer not responding"]
Tue Feb 15 23:22:37 2022 daemon.notice pppd[3295]: Connection terminated.
Tue Feb 15 23:22:37 2022 daemon.debug pppd[3295]: Send PPPOE Discovery V1T1 PADT session 0xff44 length 8
Tue Feb 15 23:22:37 2022 daemon.debug pppd[3295]:  dst 08:55:31:2c:c5:19  src 70:8b:cd:e9:ee:78
Tue Feb 15 23:22:37 2022 daemon.debug pppd[3295]:  [host-uniq  df 0c 00 00]
Tue Feb 15 23:22:37 2022 daemon.info pppd[3295]: Sent PADT
Tue Feb 15 23:22:37 2022 daemon.notice pppd[3295]: Modem hangup
Tue Feb 15 23:22:37 2022 daemon.info pppd[3295]: Exit.
Tue Feb 15 23:22:37 2022 daemon.notice netifd: Interface 'wan' is now down
Tue Feb 15 23:22:37 2022 daemon.notice netifd: Interface 'wan' is setting up now
Tue Feb 15 23:22:38 2022 daemon.err insmod: module is already loaded - slhc
Tue Feb 15 23:22:38 2022 daemon.err insmod: module is already loaded - ppp_generic
Tue Feb 15 23:22:38 2022 daemon.err insmod: module is already loaded - pppox
Tue Feb 15 23:22:38 2022 daemon.err insmod: module is already loaded - pppoe
Tue Feb 15 23:22:38 2022 daemon.info pppd[5527]: Plugin rp-pppoe.so loaded.
Tue Feb 15 23:22:38 2022 daemon.info pppd[5527]: RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: pppd 2.4.8 started by root, uid 0
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Send PPPOE Discovery V1T1 PADI session 0x0 length 12
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  dst ff:ff:ff:ff:ff:ff  src 70:8b:cd:e9:ee:78
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  [service-name] [host-uniq  97 15 00 00]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  [host-uniq  97 15 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt1] [service-name cpt-acc-hc-1]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Send PPPOE Discovery V1T1 PADR session 0x0 length 12
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  dst 08:55:31:2c:ca:d7  src 70:8b:cd:e9:ee:78
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  [service-name] [host-uniq  97 15 00 00]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:c5:19
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  [host-uniq  97 15 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt2] [service-name cpt-acc-hc-2]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Recv PPPOE Discovery V1T1 PADS session 0x9a8a length 12
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]:  [host-uniq  97 15 00 00] [service-name]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: PADS: Service-Name: ''
Tue Feb 15 23:22:38 2022 daemon.info pppd[5527]: PPP session is 39562
Tue Feb 15 23:22:38 2022 daemon.warn pppd[5527]: Connected to 08:55:31:2c:ca:d7 via interface eth0.2
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: using channel 3
Tue Feb 15 23:22:38 2022 kern.info kernel: [13448.946495] pppoe-wan: renamed from ppp0
Tue Feb 15 23:22:38 2022 daemon.info pppd[5527]: Renamed interface ppp0 to pppoe-wan
Tue Feb 15 23:22:38 2022 daemon.info pppd[5527]: Using interface pppoe-wan
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: Connect: pppoe-wan <--> eth0.2
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x85f7ee63>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <mru 1480> <magic 0xe8451730>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [LCP ConfAck id=0x1 <auth chap MS-v2> <mru 1480> <magic 0xe8451730>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x85f7ee63>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [LCP EchoReq id=0x0 magic=0x85f7ee63]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [CHAP Challenge id=0x1 <8653b0071d9e6863133a5032889bddc5>, name = "cip-gwf-access_ftth-rt1"]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: added response cache entry 0
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [CHAP Response id=0x1 <ac0d6c58ebc9f85b1e0d9ebbb64fed50000000000000000007d16581c5e725358e10d8b4b3021a94396d60c26c9c0cfa00>, name = "USERNAME"]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [LCP EchoRep id=0x0 magic=0xe8451730]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [CHAP Success id=0x1 "S=9CD5C37DC880587E800BC128727B1C0503AB47FB"]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: response found in cache (entry 0)
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: CHAP authentication succeeded
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: peer from calling number 08:55:31:2C:CA:D7 authorized
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [IPV6CP ConfReq id=0x1 <addr fe80::912e:46c8:5c11:36b1>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [IPCP ConfReq id=0x1 <addr 41.87.202.66>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [IPCP ConfAck id=0x1 <addr 41.87.202.66>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [IPCP ConfNak id=0x1 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: sent [IPCP ConfReq id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [LCP ProtRej id=0x2 80 57 01 01 00 0e 01 0a 91 2e 46 c8 5c 11 36 b1]
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: rcvd [IPCP ConfAck id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: local  IP address 100.68.9.80
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: remote IP address 41.87.202.66
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: primary   DNS address 1.1.1.1
Tue Feb 15 23:22:38 2022 daemon.notice pppd[5527]: secondary DNS address 8.8.4.4
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Script /lib/netifd/ppp-up started (pid 5551)
Tue Feb 15 23:22:38 2022 daemon.notice netifd: Network device 'pppoe-wan' link is up
Tue Feb 15 23:22:38 2022 daemon.notice netifd: Interface 'wan' is now up
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: reading /tmp/resolv.conf.d/resolv.conf.auto
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain test
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain onion
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain localhost
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain local
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain invalid
Tue Feb 15 23:22:38 2022 daemon.debug pppd[5527]: Script /lib/netifd/ppp-up finished (pid 5551), status = 0x1
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain bind
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using only locally-known addresses for domain lan
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 154.127.57.224#53
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 129.232.164.26#53
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 208.67.222.222#53
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 208.67.220.220#53
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 1.1.1.1#53
Tue Feb 15 23:22:38 2022 daemon.info dnsmasq[2529]: using nameserver 1.0.0.1#53
Tue Feb 15 23:22:38 2022 user.notice firewall: Reloading firewall due to ifup of wan (pppoe-wan)
Tue Feb 15 23:22:40 2022 daemon.info dnsmasq[2529]: read /etc/hosts - 4 addresses
Tue Feb 15 23:22:40 2022 daemon.info dnsmasq[2529]: read /tmp/hosts/odhcpd - 2 addresses
Tue Feb 15 23:22:40 2022 daemon.info dnsmasq[2529]: read /tmp/hosts/dhcp.cfg01411c - 2 addresses
Tue Feb 15 23:22:40 2022 daemon.info dnsmasq-dhcp[2529]: read /etc/ethers - 0 addresses
Tue Feb 15 23:23:18 2022 daemon.notice hostapd: wlan0: AP-STA-DISCONNECTED 60:a5:e2:27:01:1e
Wed Feb 16 00:31:51 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf
Wed Feb 16 00:31:51 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.131 d8:eb:46:7b:9e:cf Chromecast
Wed Feb 16 02:42:20 2022 daemon.info dnsmasq-dhcp[2529]: DHCPREQUEST(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb
Wed Feb 16 02:42:20 2022 daemon.info dnsmasq-dhcp[2529]: DHCPACK(br-lan) 192.168.1.208 6c:c4:d5:55:2f:fb android-e7e7bbb06323587d

ppp.logfile:

Plugin rp-pppoe.so loaded.
RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
 dst ff:ff:ff:ff:ff:ff  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  df 07 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
 [host-uniq  df 07 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt1] [service-name cpt-acc-hc-1]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
 dst 08:55:31:2c:ca:d7  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  df 07 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:c5:19
 [host-uniq  df 07 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt2] [service-name cpt-acc-hc-2]
Recv PPPOE Discovery V1T1 PADS session 0x503f length 12
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
 [host-uniq  df 07 00 00] [service-name]
PADS: Service-Name: ''
PPP session is 20543
Connected to 08:55:31:2c:ca:d7 via interface eth0.2
using channel 1
Renamed interface ppp0 to pppoe-wan
Using interface pppoe-wan
Connect: pppoe-wan <--> eth0.2
sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xb307d613>]
rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <mru 1480> <magic 0x86993f0b>]
sent [LCP ConfAck id=0x1 <auth chap MS-v2> <mru 1480> <magic 0x86993f0b>]
rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xb307d613>]
sent [LCP EchoReq id=0x0 magic=0xb307d613]
rcvd [CHAP Challenge id=0x1 <4668a8e35b47fcfb25a9ce95077a7281>, name = "cip-gwf-access_ftth-rt1"]
added response cache entry 0
sent [CHAP Response id=0x1 <5cc973de30de33d7ecd338766cd552dc0000000000000000024edd399116fa895c645743bf2ce50f0931579566e5fa1b00>, name = "765e-2151@home-connect.co.za"]
rcvd [LCP EchoRep id=0x0 magic=0x86993f0b]
rcvd [CHAP Success id=0x1 "S=6B9CB18103975743FF5B16F669F08E8DA1211067"]
response found in cache (entry 0)
CHAP authentication succeeded
peer from calling number 08:55:31:2C:CA:D7 authorized
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::8150:3190:8c24:117a>]
rcvd [IPCP ConfReq id=0x1 <addr 41.87.202.66>]
sent [IPCP ConfAck id=0x1 <addr 41.87.202.66>]
rcvd [IPCP ConfNak id=0x1 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
sent [IPCP ConfReq id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
rcvd [LCP ProtRej id=0x2 80 57 01 01 00 0e 01 0a 81 50 31 90 8c 24 11 7a]
Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received
rcvd [IPCP ConfAck id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
local  IP address 100.68.9.80
remote IP address 41.87.202.66
primary   DNS address 1.1.1.1
secondary DNS address 8.8.4.4
Script /lib/netifd/ppp-up started (pid 2211)
Script /lib/netifd/ppp-up finished (pid 2211), status = 0x1
Terminating on signal 15
Connect time 13.1 minutes.
Sent 1014522 bytes, received 7056555 bytes.
Script /lib/netifd/ppp-down started (pid 3243)
sent [LCP TermReq id=0x2 "User request"]
rcvd [LCP TermAck id=0x2]
Connection terminated.
Send PPPOE Discovery V1T1 PADT session 0x503f length 8
 dst 08:55:31:2c:ca:d7  src 70:8b:cd:e9:ee:78
 [host-uniq  df 07 00 00]
Sent PADT
Waiting for 1 child processes...
  script /lib/netifd/ppp-down, pid 3243
Script /lib/netifd/ppp-down finished (pid 3243), status = 0x1
Plugin rp-pppoe.so loaded.
RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
 dst ff:ff:ff:ff:ff:ff  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  df 0c 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:c5:19
 [host-uniq  df 0c 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt2] [service-name cpt-acc-hc-2]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
 dst 08:55:31:2c:c5:19  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  df 0c 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
 [host-uniq  df 0c 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt1] [service-name cpt-acc-hc-1]
Recv PPPOE Discovery V1T1 PADS session 0xff44 length 12
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:c5:19
 [host-uniq  df 0c 00 00] [service-name]
PADS: Service-Name: ''
PPP session is 65348
Connected to 08:55:31:2c:c5:19 via interface eth0.2
using channel 2
Renamed interface ppp0 to pppoe-wan
Using interface pppoe-wan
Connect: pppoe-wan <--> eth0.2
sent [LCP ConfReq id=0x1 <mru 1492> <magic 0xca321c5e>]
rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <mru 1480> <magic 0x9446fc44>]
sent [LCP ConfAck id=0x1 <auth chap MS-v2> <mru 1480> <magic 0x9446fc44>]
rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0xca321c5e>]
sent [LCP EchoReq id=0x0 magic=0xca321c5e]
rcvd [CHAP Challenge id=0x1 <68f295338aca47b68857cec900a6936e>, name = "cip-gwf-access_ftth-rt2"]
added response cache entry 0
sent [CHAP Response id=0x1 <0c094f0b9d23f8d34ba0ce07eedf680d00000000000000000cc50630af23b448db41fafb02feb0dc8cec38b8074b304a00>, name = "765e-2151@home-connect.co.za"]
rcvd [LCP EchoRep id=0x0 magic=0x9446fc44]
rcvd [CHAP Success id=0x1 "S=1B9ACDC9A539B23DA2CD8F0BE80379F1D0D514D0"]
response found in cache (entry 0)
CHAP authentication succeeded
peer from calling number 08:55:31:2C:C5:19 authorized
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::307a:3c81:0f1e:9952>]
rcvd [IPCP ConfReq id=0x1 <addr 41.87.202.67>]
sent [IPCP ConfAck id=0x1 <addr 41.87.202.67>]
rcvd [LCP ProtRej id=0x2 80 57 01 01 00 0e 01 0a 30 7a 3c 81 0f 1e 99 52]
Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received
rcvd [IPCP ConfNak id=0x1 <addr 100.68.29.208> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
sent [IPCP ConfReq id=0x2 <addr 100.68.29.208> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
rcvd [IPCP ConfAck id=0x2 <addr 100.68.29.208> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
local  IP address 100.68.29.208
remote IP address 41.87.202.67
primary   DNS address 1.1.1.1
secondary DNS address 8.8.4.4
Script /lib/netifd/ppp-up started (pid 3330)
Script /lib/netifd/ppp-up finished (pid 3330), status = 0x1
No response to 100 echo-requests
Serial link appears to be disconnected.
Connect time 608.8 minutes.
Sent 140953411 bytes, received 2885060632 bytes.
Script /lib/netifd/ppp-down started (pid 5274)
sent [LCP TermReq id=0x2 "Peer not responding"]
Script /lib/netifd/ppp-down finished (pid 5274), status = 0x1
sent [LCP TermReq id=0x3 "Peer not responding"]
Connection terminated.
Send PPPOE Discovery V1T1 PADT session 0xff44 length 8
 dst 08:55:31:2c:c5:19  src 70:8b:cd:e9:ee:78
 [host-uniq  df 0c 00 00]
Sent PADT
Modem hangup
Plugin rp-pppoe.so loaded.
RP-PPPoE plugin version 3.8p compiled against pppd 2.4.8
Send PPPOE Discovery V1T1 PADI session 0x0 length 12
 dst ff:ff:ff:ff:ff:ff  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  97 15 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
 [host-uniq  97 15 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt1] [service-name cpt-acc-hc-1]
Send PPPOE Discovery V1T1 PADR session 0x0 length 12
 dst 08:55:31:2c:ca:d7  src 70:8b:cd:e9:ee:78
 [service-name] [host-uniq  97 15 00 00]
Recv PPPOE Discovery V1T1 PADO session 0x0 length 55
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:c5:19
 [host-uniq  97 15 00 00] [service-name] [AC-name cip-gwf-access_ftth-rt2] [service-name cpt-acc-hc-2]
Recv PPPOE Discovery V1T1 PADS session 0x9a8a length 12
 dst 70:8b:cd:e9:ee:78  src 08:55:31:2c:ca:d7
 [host-uniq  97 15 00 00] [service-name]
PADS: Service-Name: ''
PPP session is 39562
Connected to 08:55:31:2c:ca:d7 via interface eth0.2
using channel 3
Renamed interface ppp0 to pppoe-wan
Using interface pppoe-wan
Connect: pppoe-wan <--> eth0.2
sent [LCP ConfReq id=0x1 <mru 1492> <magic 0x85f7ee63>]
rcvd [LCP ConfReq id=0x1 <auth chap MS-v2> <mru 1480> <magic 0xe8451730>]
sent [LCP ConfAck id=0x1 <auth chap MS-v2> <mru 1480> <magic 0xe8451730>]
rcvd [LCP ConfAck id=0x1 <mru 1492> <magic 0x85f7ee63>]
sent [LCP EchoReq id=0x0 magic=0x85f7ee63]
rcvd [CHAP Challenge id=0x1 <8653b0071d9e6863133a5032889bddc5>, name = "cip-gwf-access_ftth-rt1"]
added response cache entry 0
sent [CHAP Response id=0x1 <ac0d6c58ebc9f85b1e0d9ebbb64fed50000000000000000007d16581c5e725358e10d8b4b3021a94396d60c26c9c0cfa00>, name = "765e-2151@home-connect.co.za"]
rcvd [LCP EchoRep id=0x0 magic=0xe8451730]
rcvd [CHAP Success id=0x1 "S=9CD5C37DC880587E800BC128727B1C0503AB47FB"]
response found in cache (entry 0)
CHAP authentication succeeded
peer from calling number 08:55:31:2C:CA:D7 authorized
sent [IPCP ConfReq id=0x1 <addr 0.0.0.0> <ms-dns1 0.0.0.0> <ms-dns2 0.0.0.0>]
sent [IPV6CP ConfReq id=0x1 <addr fe80::912e:46c8:5c11:36b1>]
rcvd [IPCP ConfReq id=0x1 <addr 41.87.202.66>]
sent [IPCP ConfAck id=0x1 <addr 41.87.202.66>]
rcvd [IPCP ConfNak id=0x1 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
sent [IPCP ConfReq id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
rcvd [LCP ProtRej id=0x2 80 57 01 01 00 0e 01 0a 91 2e 46 c8 5c 11 36 b1]
Protocol-Reject for 'IPv6 Control Protocol' (0x8057) received
rcvd [IPCP ConfAck id=0x2 <addr 100.68.9.80> <ms-dns1 1.1.1.1> <ms-dns2 8.8.4.4>]
local  IP address 100.68.9.80
remote IP address 41.87.202.66
primary   DNS address 1.1.1.1
secondary DNS address 8.8.4.4
Script /lib/netifd/ppp-up started (pid 5551)
Script /lib/netifd/ppp-up finished (pid 5551), status = 0x1