WAN doesn't connect on boot and interrupts intermittently

ShwangShwing · November 29, 2021, 1:02am

Hello,

I installed OpenWrt 21.02.1 r16325-88151b8303 on my D-Link DIR-2660 A1 router.
I connect to my internet service provider directly through an ethernet cat 5 twisted pair cable. Connection settings to my ISP are set by DHCP and my ISP filters by MAC address.
I have set the wan MAC address to be the same as the one on my previous (working) router via the web interface.

The result is that when the router boots the wan network doesn't come up and devices in my router network (wired and wireless) don't get internet access.

If I connect via SSH and write

root@Hidroizolatsia:~# ifconfig wan down
root@Hidroizolatsia:~# ifconfig wan up

The network does come up and internet connection is working somewhat. However every ten or so minutes, the interface goes down for around 20 seconds and goes up again (which causes a short lapse in internet connection for the connected devices).

Config:

root@Hidroizolatsia:~# cat /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 packet_steering '1'
        option ula_prefix 'fdb1:377c:01ee::/48'

config device
        option name 'br-lan'
        option type 'bridge'
        list ports 'lan1'
        list ports 'lan2'
        list ports 'lan3'
        list ports 'lan4'

config interface 'lan'
        option device 'br-lan'
        option proto 'static'
        option netmask '255.255.255.0'
        option ip6assign '60'
        option ipaddr '192.168.0.1'

config interface 'wan'
        option proto 'dhcp'
        option device 'wan'

config interface 'wan6'
        option proto 'dhcpv6'
        option reqaddress 'try'
        option reqprefix 'auto'
        option device 'wan'

config device
        option name 'wan'
        option macaddr '68:7F:74:B0:E8:F7'

ALSO:
If I connect my old router WANport to my ISP and connect my new openwrt router WAN port to one of the LAN ports of my old router, there is absolutely no connection problem. The packets flow freely through both routers and devices have internet without any interruptions, and also the new router gets its connection correctly on startup.

If you can help me I will be grateful. I tried searching the documentation and the whole internet but I couldn't find anything.

ShwangShwing · November 29, 2021, 1:09am

Logs (I can't post the whole log because this forum doesn't let me):

root@Hidroizolatsia:~# logread
Mon Nov 29 02:23:25 2021 kern.notice kernel: [    0.000000] Linux version 5.4.154 (builder@buildhost) (gcc version 8.4.0 (OpenWrt GCC 8.4.0 r16325-88151b8303)) #0 SMP Sun Oct 24 09:01:35 2021
.............................................................................
Mon Nov 29 02:23:45 2021 kern.info kernel: [   34.426040] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 02:23:45 2021 kern.info kernel: [   34.441179] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
Mon Nov 29 02:23:45 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 02:23:45 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 02:23:45 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 02:23:45 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 02:23:45 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 02:23:45 2021 daemon.notice netifd: wan (3370): udhcpc: started, v1.33.1
Mon Nov 29 02:23:45 2021 daemon.err odhcp6c[3371]: Failed to send RS (Address not available)
Mon Nov 29 02:23:45 2021 daemon.notice netifd: wan (3370): udhcpc: sending discover
Mon Nov 29 02:23:46 2021 daemon.err odhcp6c[3371]: Failed to send SOLICIT message to ff02::1:2 (Address not available)
Mon Nov 29 02:23:46 2021 daemon.err odhcp6c[3371]: Failed to send RS (Address not available)
Mon Nov 29 02:23:46 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 02:23:46 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 02:23:46 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 02:23:46 2021 kern.info kernel: [   35.449801] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 02:23:46 2021 daemon.notice netifd: wan (3370): udhcpc: received SIGTERM
Mon Nov 29 02:23:46 2021 daemon.notice netifd: wan (3370): udhcpc: entering released state
Mon Nov 29 02:23:46 2021 daemon.notice netifd: wan (3370): Command failed: Permission denied
Mon Nov 29 02:23:46 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 02:23:46 2021 daemon.err odhcp6c[3371]: Failed to send SOLICIT message to ff02::1:2 (Address not available)
Mon Nov 29 02:23:46 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 02:23:47 2021 kern.info kernel: [   36.314099] mt7530 mdio-bus:1f lan3: Link is Up - 100Mbps/Full - flow control off
Mon Nov 29 02:23:47 2021 kern.info kernel: [   36.329111] br-lan: port 3(lan3) entered blocking state
Mon Nov 29 02:23:47 2021 kern.info kernel: [   36.339577] br-lan: port 3(lan3) entered forwarding state
Mon Nov 29 02:23:47 2021 daemon.notice netifd: Network device 'lan3' link is up
Mon Nov 29 02:23:52 2021 daemon.info hostapd: wlan0: STA 84:cf:bf:92:68:ac IEEE 802.11: authenticated
Mon Nov 29 02:23:52 2021 daemon.info hostapd: wlan0: STA 84:cf:bf:92:68:ac IEEE 802.11: associated (aid 1)
Mon Nov 29 02:23:52 2021 daemon.notice hostapd: wlan0: AP-STA-CONNECTED 84:cf:bf:92:68:ac
Mon Nov 29 02:23:52 2021 daemon.info hostapd: wlan0: STA 84:cf:bf:92:68:ac WPA: pairwise key handshake completed (RSN)
Mon Nov 29 02:23:56 2021 daemon.info dnsmasq-dhcp[3042]: DHCPDISCOVER(br-lan) 84:cf:bf:92:68:ac
Mon Nov 29 02:23:56 2021 daemon.info dnsmasq-dhcp[3042]: DHCPOFFER(br-lan) 192.168.0.176 84:cf:bf:92:68:ac
Mon Nov 29 02:23:56 2021 daemon.info dnsmasq-dhcp[3042]: DHCPREQUEST(br-lan) 192.168.0.176 84:cf:bf:92:68:ac
Mon Nov 29 02:23:56 2021 daemon.info dnsmasq-dhcp[3042]: DHCPACK(br-lan) 192.168.0.176 84:cf:bf:92:68:ac
Mon Nov 29 02:23:59 2021 kern.info kernel: [   48.761954] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 02:23:59 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 02:23:59 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 02:23:59 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 02:23:59 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 02:23:59 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 02:23:59 2021 daemon.notice netifd: wan (3475): udhcpc: started, v1.33.1
Mon Nov 29 02:24:00 2021 daemon.notice netifd: wan (3475): udhcpc: sending discover
Mon Nov 29 02:24:00 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 02:24:00 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 02:24:00 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 02:24:00 2021 kern.info kernel: [   49.785805] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 02:24:00 2021 daemon.notice netifd: wan (3475): udhcpc: received SIGTERM
Mon Nov 29 02:24:00 2021 daemon.notice netifd: wan (3475): udhcpc: entering released state
Mon Nov 29 02:24:01 2021 daemon.notice netifd: wan (3475): Command failed: Permission denied
Mon Nov 29 02:24:01 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 02:24:01 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 02:24:22 2021 authpriv.info dropbear[3571]: Child connection from 192.168.0.102:56660
Mon Nov 29 02:24:24 2021 daemon.info hostapd: wlan1: STA 9c:b6:d0:bf:eb:91 IEEE 802.11: authenticated
Mon Nov 29 02:24:24 2021 daemon.info hostapd: wlan1: STA 9c:b6:d0:bf:eb:91 IEEE 802.11: associated (aid 1)
Mon Nov 29 02:24:24 2021 daemon.notice hostapd: wlan1: AP-STA-CONNECTED 9c:b6:d0:bf:eb:91
Mon Nov 29 02:24:24 2021 daemon.info hostapd: wlan1: STA 9c:b6:d0:bf:eb:91 WPA: pairwise key handshake completed (RSN)
Mon Nov 29 02:24:24 2021 daemon.info dnsmasq-dhcp[3042]: DHCPREQUEST(br-lan) 192.168.0.100 9c:b6:d0:bf:eb:91
Mon Nov 29 02:24:24 2021 daemon.info dnsmasq-dhcp[3042]: DHCPACK(br-lan) 192.168.0.100 9c:b6:d0:bf:eb:91 Silvera
Mon Nov 29 02:24:29 2021 kern.info kernel: [   78.457963] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 02:24:29 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 02:24:29 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 02:24:29 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 02:24:29 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 02:24:29 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 02:24:29 2021 daemon.notice netifd: wan (3609): udhcpc: started, v1.33.1
Mon Nov 29 02:24:29 2021 daemon.notice netifd: wan (3609): udhcpc: sending discover
Mon Nov 29 02:24:30 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 02:24:30 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 02:24:30 2021 kern.info kernel: [   79.481822] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 02:24:30 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 02:24:30 2021 daemon.notice netifd: wan (3609): udhcpc: received SIGTERM
Mon Nov 29 02:24:30 2021 daemon.notice netifd: wan (3609): udhcpc: entering released state
Mon Nov 29 02:24:30 2021 daemon.notice netifd: wan (3609): Command failed: Permission denied
Mon Nov 29 02:24:30 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 02:24:31 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 02:24:35 2021 daemon.info dnsmasq[3042]: read /etc/hosts - 4 addresses
Mon Nov 29 02:24:35 2021 daemon.info dnsmasq[3042]: read /tmp/hosts/odhcpd - 2 addresses
Mon Nov 29 02:24:35 2021 daemon.info dnsmasq[3042]: read /tmp/hosts/dhcp.cfg01411c - 1 addresses
Mon Nov 29 02:24:35 2021 daemon.info dnsmasq-dhcp[3042]: read /etc/ethers - 0 addresses
Mon Nov 29 02:24:43 2021 kern.info kernel: [   92.793963] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 02:24:43 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 02:24:43 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 02:24:43 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 02:24:43 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 02:24:43 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 02:24:44 2021 daemon.notice netifd: wan (3722): udhcpc: started, v1.33.1
Mon Nov 29 02:24:44 2021 daemon.notice netifd: wan (3722): udhcpc: sending discover
Mon Nov 29 02:24:44 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 02:24:44 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 02:24:44 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 02:24:44 2021 kern.info kernel: [   93.817830] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 02:24:45 2021 daemon.notice netifd: wan (3722): udhcpc: received SIGTERM
Mon Nov 29 02:24:45 2021 daemon.notice netifd: wan (3722): udhcpc: entering released state
Mon Nov 29 02:24:45 2021 daemon.notice netifd: wan (3722): Command failed: Permission denied
Mon Nov 29 02:24:45 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 02:24:45 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 02:25:18 2021 authpriv.notice dropbear[3571]: Password auth succeeded for 'root' from 192.168.0.102:56660

root@Hidroizolatsia:~# dmesg
.................................
[    0.000000] Built 1 zonelists, mobility grouping on.  Total pages: 64960
[    0.000000] Kernel command line: console=ttyS0,57600 rootfstype=squashfs,jffs2
[    0.000000] Dentry cache hash table entries: 32768 (order: 5, 131072 bytes, linear)
[    0.000000] Inode-cache hash table entries: 16384 (order: 4, 65536 bytes, linear)
[    0.000000] Writing ErrCtl register=00010c30
[    0.000000] Readback ErrCtl register=00010c30
[    0.000000] mem auto-init: stack:off, heap alloc:off, heap free:off
[    0.000000] Memory: 250788K/262144K available (6089K kernel code, 210K rwdata, 748K rodata, 1260K init, 238K bss, 11356K reserved, 0K cma-reserved, 0K highmem)
[    0.000000] SLUB: HWalign=32, Order=0-3, MinObjects=0, CPUs=4, Nodes=1
[    0.000000] rcu: Hierarchical RCU implementation.
[    0.000000] rcu: RCU calculated value of scheduler-enlistment delay is 25 jiffies.
[    0.000000] NR_IRQS: 256
[    0.000000] random: get_random_bytes called from 0x806e5a3c with crng_init=0
[    0.000000] CPU Clock: 880MHz
[    0.000000] clocksource: GIC: mask: 0xffffffffffffffff max_cycles: 0xcaf478abb4, max_idle_ns: 440795247997 ns
[    0.000000] clocksource: MIPS: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 4343773742 ns
[    0.000008] sched_clock: 32 bits at 440MHz, resolution 2ns, wraps every 4880645118ns
[    0.015502] Calibrating delay loop... 583.68 BogoMIPS (lpj=1167360)
[    0.055846] pid_max: default: 32768 minimum: 301
[    0.065203] Mount-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.079609] Mountpoint-cache hash table entries: 1024 (order: 0, 4096 bytes, linear)
[    0.097740] rcu: Hierarchical SRCU implementation.
[    0.107849] smp: Bringing up secondary CPUs ...
[    0.117701] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.117714] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.117726] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.117827] CPU1 revision is: 0001992f (MIPS 1004Kc)
[    0.145022] Synchronize counters for CPU 1: done.
[    0.208784] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.208794] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.208802] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.208859] CPU2 revision is: 0001992f (MIPS 1004Kc)
[    0.239509] Synchronize counters for CPU 2: done.
[    0.299941] Primary instruction cache 32kB, VIPT, 4-way, linesize 32 bytes.
[    0.299951] Primary data cache 32kB, 4-way, PIPT, no aliases, linesize 32 bytes
[    0.299959] MIPS secondary cache 256kB, 8-way, linesize 32 bytes.
[    0.300021] CPU3 revision is: 0001992f (MIPS 1004Kc)
[    0.327109] Synchronize counters for CPU 3: done.
[    0.386723] smp: Brought up 1 node, 4 CPUs
[    0.399304] clocksource: jiffies: mask: 0xffffffff max_cycles: 0xffffffff, max_idle_ns: 7645041785100000 ns
[    0.418602] futex hash table entries: 1024 (order: 3, 32768 bytes, linear)
[    0.432427] pinctrl core: initialized pinctrl subsystem
[    0.444328] NET: Registered protocol family 16
[    0.460486] FPU Affinity set after 4688 emulations
[    0.476512] workqueue: max_active 576 requested for napi_workq is out of range, clamping between 1 and 512
[    0.497605] clocksource: Switched to clocksource GIC
[    0.508907] thermal_sys: Registered thermal governor 'step_wise'
[    0.509376] NET: Registered protocol family 2
[    0.530017] IP idents hash table entries: 4096 (order: 3, 32768 bytes, linear)
[    0.545182] tcp_listen_portaddr_hash hash table entries: 512 (order: 0, 6144 bytes, linear)
[    0.561742] TCP established hash table entries: 2048 (order: 1, 8192 bytes, linear)
[    0.576903] TCP bind hash table entries: 2048 (order: 2, 16384 bytes, linear)
[    0.591076] TCP: Hash tables configured (established 2048 bind 2048)
[    0.603810] UDP hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.616695] UDP-Lite hash table entries: 256 (order: 1, 8192 bytes, linear)
[    0.630797] NET: Registered protocol family 1
[    0.639358] PCI: CLS 0 bytes, default 32
[    0.737507] 4 CPUs re-calibrate udelay(lpj = 1163264)
[    0.749061] workingset: timestamp_bits=14 max_order=16 bucket_order=2
[    0.769829] random: fast init done
[    0.780105] squashfs: version 4.0 (2009/01/31) Phillip Lougher
[    0.791611] jffs2: version 2.2 (NAND) (SUMMARY) (LZMA) (RTIME) (CMODE_PRIORITY) (c) 2001-2006 Red Hat, Inc.
[    0.812541] Block layer SCSI generic (bsg) driver version 0.4 loaded (major 251)
[    0.828902] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.840204] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.851469] mt7621_gpio 1e000600.gpio: registering 32 gpios
[    0.863200] Serial: 8250/16550 driver, 16 ports, IRQ sharing enabled
[    0.879083] printk: console [ttyS0] disabled
[    0.887552] 1e000c00.uartlite: ttyS0 at MMIO 0x1e000c00 (irq = 19, base_baud = 3125000) is a 16550A
[    0.905478] printk: console [ttyS0] enabled
[    0.922016] printk: bootconsole [early0] disabled
[    0.943124] mt7621-nand 1e003000.nand: Using programmed access timing: 31c07388
[    0.957969] nand: device found, Manufacturer ID: 0xef, Chip ID: 0xf1
[    0.970634] nand: Winbond W29N01HV
[    0.977409] nand: 128 MiB, SLC, erase size: 128 KiB, page size: 2048, OOB size: 64
[    0.992494] mt7621-nand 1e003000.nand: ECC strength adjusted to 4 bits
[    1.005545] mt7621-nand 1e003000.nand: Using programmed access timing: 21005134
[    1.020108] mt7621-nand 1e003000.nand: Using programmed access timing: 21005134
[    1.034670] Scanning device for bad blocks
[    1.691797] 9 fixed-partitions partitions found on MTD device mt7621-nand
[    1.705322] Creating 9 MTD partitions on "mt7621-nand":
[    1.715743] 0x000000000000-0x000000080000 : "Bootloader"
[    1.727801] 0x000000080000-0x000000100000 : "config"
[    1.739023] 0x000000100000-0x000000140000 : "factory"
[    1.750589] 0x000000140000-0x000000180000 : "config2"
[    1.762074] 0x000000180000-0x000002980000 : "firmware"
[    1.784666] 2 uimage-fw partitions found on MTD device firmware
[    1.796593] Creating 2 MTD partitions on "firmware":
[    1.806497] 0x000000000000-0x000000400000 : "kernel"
[    1.817939] 0x000000400000-0x000002800000 : "ubi"
[    1.828886] 0x000002980000-0x000004980000 : "private"
[    1.840429] 0x000004980000-0x000007180000 : "firmware2"
[    2.236392] 0x000007180000-0x000007780000 : "mydlink"
[    2.247911] 0x000007780000-0x000008000000 : "reserved"
[    2.261211] libphy: Fixed MDIO Bus: probed
[    2.295864] libphy: mdio: probed
[    2.302523] mt7530 mdio-bus:1f: MT7530 adapts as multi-chip module
[    2.318718] mtk_soc_eth 1e100000.ethernet eth0: mediatek frame engine at 0xbe100000, irq 21
[    2.337649] mt7621-pci 1e140000.pcie: Parsing DT failed
[    2.350893] NET: Registered protocol family 10
[    2.361231] Segment Routing with IPv6
[    2.368650] NET: Registered protocol family 17
[    2.377600] bridge: filtering via arp/ip/ip6tables is no longer available by default. Update your scripts to load br_netfilter if you need this.
[    2.403647] 8021q: 802.1Q VLAN Support v1.8
[    2.414030] mt7530 mdio-bus:1f: MT7530 adapts as multi-chip module
[    2.437583] libphy: dsa slave smi: probed
[    2.445969] mt7530 mdio-bus:1f lan4 (uninitialized): PHY [dsa-0.0:00] driver [Generic PHY]
[    2.463902] mt7530 mdio-bus:1f lan3 (uninitialized): PHY [dsa-0.0:01] driver [Generic PHY]
[    2.481929] mt7530 mdio-bus:1f lan2 (uninitialized): PHY [dsa-0.0:02] driver [Generic PHY]
[    2.499809] mt7530 mdio-bus:1f lan1 (uninitialized): PHY [dsa-0.0:03] driver [Generic PHY]
[    2.517814] mt7530 mdio-bus:1f wan (uninitialized): PHY [dsa-0.0:04] driver [Generic PHY]
[    2.535659] mt7530 mdio-bus:1f: configuring for fixed/rgmii link mode
[    2.553280] DSA: tree 0 setup
[    2.559503] rt2880-pinmux pinctrl: pcie is already enabled
[    2.570591] mt7621-pci-phy 1e149000.pcie-phy: PHY for 0xbe149000 (dual port = 1)
[    2.585561] mt7621-pci-phy 1e14a000.pcie-phy: PHY for 0xbe14a000 (dual port = 0)
[    2.700016] mt7621-pci-phy 1e149000.pcie-phy: Xtal is 40MHz
[    2.711130] mt7621-pci-phy 1e14a000.pcie-phy: Xtal is 40MHz
[    2.821875] mt7621-pci 1e140000.pcie: pcie2 no card, disable it (RST & CLK)
[    2.835741] mt7621-pci 1e140000.pcie: PCIE0 enabled
[    2.845450] mt7621-pci 1e140000.pcie: PCIE1 enabled
[    2.855171] mt7621-pci 1e140000.pcie: PCI coherence region base: 0x60000000, mask/settings: 0xf0000002
[    2.873881] mt7621-pci 1e140000.pcie: PCI host bridge to bus 0000:00
[    2.886548] pci_bus 0000:00: root bus resource [io  0x1e160000-0x1e16ffff]
[    2.900241] pci_bus 0000:00: root bus resource [mem 0x60000000-0x6fffffff]
[    2.913938] pci_bus 0000:00: root bus resource [bus 00-ff]
[    2.924898] pci 0000:00:00.0: [0e8d:0801] type 01 class 0x060400
[    2.936892] pci 0000:00:00.0: reg 0x10: [mem 0x00000000-0x7fffffff]
[    2.949380] pci 0000:00:00.0: reg 0x14: [mem 0x60400000-0x6040ffff]
[    2.961932] pci 0000:00:00.0: supports D1
[    2.969917] pci 0000:00:00.0: PME# supported from D0 D1 D3hot
[    2.981742] pci 0000:00:01.0: [0e8d:0801] type 01 class 0x060400
[    2.993740] pci 0000:00:01.0: reg 0x10: [mem 0x00000000-0x7fffffff]
[    3.006236] pci 0000:00:01.0: reg 0x14: [mem 0x60410000-0x6041ffff]
[    3.018775] pci 0000:00:01.0: supports D1
[    3.026758] pci 0000:00:01.0: PME# supported from D0 D1 D3hot
[    3.039812] pci 0000:01:00.0: [14c3:7615] type 00 class 0x000280
[    3.051840] pci 0000:01:00.0: reg 0x10: [mem 0x00000000-0x000fffff 64bit]
[    3.065551] pci 0000:01:00.0: 2.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s x1 link at 0000:00:00.0 (capable of 4.000 Gb/s with 5 GT/s x1 link)
[    3.094559] pci 0000:00:00.0: PCI bridge to [bus 01-ff]
[    3.104977] pci 0000:00:00.0:   bridge window [io  0x0000-0x0fff]
[    3.117116] pci 0000:00:00.0:   bridge window [mem 0x60000000-0x600fffff]
[    3.130640] pci 0000:00:00.0:   bridge window [mem 0x60100000-0x601fffff pref]
[    3.145033] pci_bus 0000:01: busn_res: [bus 01-ff] end is updated to 01
[    3.158409] pci 0000:02:00.0: [14c3:7615] type 00 class 0x000280
[    3.170425] pci 0000:02:00.0: reg 0x10: [mem 0x00000000-0x000fffff 64bit]
[    3.184107] pci 0000:02:00.0: 2.000 Gb/s available PCIe bandwidth, limited by 2.5 GT/s x1 link at 0000:00:01.0 (capable of 4.000 Gb/s with 5 GT/s x1 link)
[    3.213066] pci 0000:00:01.0: PCI bridge to [bus 02-ff]
[    3.223489] pci 0000:00:01.0:   bridge window [io  0x0000-0x0fff]
[    3.235628] pci 0000:00:01.0:   bridge window [mem 0x60200000-0x602fffff]
[    3.249148] pci 0000:00:01.0:   bridge window [mem 0x60300000-0x603fffff pref]
[    3.263539] pci_bus 0000:02: busn_res: [bus 02-ff] end is updated to 02
[    3.276766] pci 0000:00:00.0: BAR 0: no space for [mem size 0x80000000]
[    3.289942] pci 0000:00:00.0: BAR 0: failed to assign [mem size 0x80000000]
[    3.303808] pci 0000:00:01.0: BAR 0: no space for [mem size 0x80000000]
[    3.316983] pci 0000:00:01.0: BAR 0: failed to assign [mem size 0x80000000]
[    3.330853] pci 0000:00:00.0: BAR 8: assigned [mem 0x60000000-0x600fffff]
[    3.344376] pci 0000:00:00.0: BAR 9: assigned [mem 0x60100000-0x601fffff pref]
[    3.358765] pci 0000:00:01.0: BAR 8: assigned [mem 0x60200000-0x602fffff]
[    3.372287] pci 0000:00:01.0: BAR 9: assigned [mem 0x60300000-0x603fffff pref]
[    3.386676] pci 0000:00:00.0: BAR 1: assigned [mem 0x60400000-0x6040ffff]
[    3.400203] pci 0000:00:01.0: BAR 1: assigned [mem 0x60410000-0x6041ffff]
[    3.413736] pci 0000:00:00.0: BAR 7: assigned [io  0x1e160000-0x1e160fff]
[    3.427258] pci 0000:00:01.0: BAR 7: assigned [io  0x1e161000-0x1e161fff]
[    3.440786] pci 0000:01:00.0: BAR 0: assigned [mem 0x60000000-0x600fffff 64bit]
[    3.455357] pci 0000:00:00.0: PCI bridge to [bus 01]
[    3.465244] pci 0000:00:00.0:   bridge window [io  0x1e160000-0x1e160fff]
[    3.478767] pci 0000:00:00.0:   bridge window [mem 0x60000000-0x600fffff]
[    3.492286] pci 0000:00:00.0:   bridge window [mem 0x60100000-0x601fffff pref]
[    3.506681] pci 0000:02:00.0: BAR 0: assigned [mem 0x60200000-0x602fffff 64bit]
[    3.521247] pci 0000:00:01.0: PCI bridge to [bus 02]
[    3.531136] pci 0000:00:01.0:   bridge window [io  0x1e161000-0x1e161fff]
[    3.544661] pci 0000:00:01.0:   bridge window [mem 0x60200000-0x602fffff]
[    3.558183] pci 0000:00:01.0:   bridge window [mem 0x60300000-0x603fffff pref]
[    3.573106] mt7530 mdio-bus:1f: Link is Up - 1Gbps/Full - flow control off
[    3.574301] UBI: auto-attach mtd6
[    3.593451] ubi0: attaching mtd6
[    3.965699] ubi0: scanning is finished
[    3.989581] ubi0: attached mtd6 (name "ubi", size 36 MiB)
[    4.000351] ubi0: PEB size: 131072 bytes (128 KiB), LEB size: 126976 bytes
[    4.014042] ubi0: min./max. I/O unit sizes: 2048/2048, sub-page size 2048
[    4.027556] ubi0: VID header offset: 2048 (aligned 2048), data offset: 4096
[    4.041414] ubi0: good PEBs: 288, bad PEBs: 0, corrupted PEBs: 0
[    4.053372] ubi0: user volume: 2, internal volumes: 1, max. volumes count: 128
[    4.067755] ubi0: max/mean erase counter: 2/1, WL threshold: 4096, image sequence number: 1635066095
[    4.085942] ubi0: available PEBs: 0, total reserved PEBs: 288, PEBs reserved for bad PEB handling: 20
[    4.104327] ubi0: background thread "ubi_bgt0d" started, PID 503
[    4.106662] block ubiblock0_0: created from ubi0:0(rootfs)
[    4.127277] ubiblock: device ubiblock0_0 (rootfs) set to be root filesystem
[    4.141147] hctosys: unable to open rtc device (rtc0)
[    4.159169] VFS: Mounted root (squashfs filesystem) readonly on device 254:0.
[    4.177825] Freeing unused kernel memory: 1260K
[    4.186861] This architecture does not have kernel memory protection.
[    4.199683] Run /sbin/init as init process
[    4.752426] init: Console is alive
[    4.759492] init: - watchdog -
[    5.556508] kmodloader: loading kernel modules from /etc/modules-boot.d/*
[    5.658108] usbcore: registered new interface driver usbfs
[    5.669197] usbcore: registered new interface driver hub
[    5.679920] usbcore: registered new device driver usb
[    5.699380] xhci-mtk 1e1c0000.xhci: 1e1c0000.xhci supply vbus not found, using dummy regulator
[    5.716704] xhci-mtk 1e1c0000.xhci: 1e1c0000.xhci supply vusb33 not found, using dummy regulator
[    5.734429] xhci-mtk 1e1c0000.xhci: xHCI Host Controller
[    5.745046] xhci-mtk 1e1c0000.xhci: new USB bus registered, assigned bus number 1
[    5.765718] xhci-mtk 1e1c0000.xhci: hcc params 0x01401198 hci version 0x96 quirks 0x0000000000290010
[    5.784003] xhci-mtk 1e1c0000.xhci: irq 20, io mem 0x1e1c0000
[    5.795679] xhci-mtk 1e1c0000.xhci: xHCI Host Controller
[    5.806279] xhci-mtk 1e1c0000.xhci: new USB bus registered, assigned bus number 2
[    5.821191] xhci-mtk 1e1c0000.xhci: Host supports USB 3.0 SuperSpeed
[    5.834945] hub 1-0:1.0: USB hub found
[    5.842547] hub 1-0:1.0: 2 ports detected
[    5.851453] usb usb2: We don't know the algorithms for LPM for this host, disabling LPM.
[    5.868509] hub 2-0:1.0: USB hub found
[    5.876122] hub 2-0:1.0: 1 port detected
[    5.889854] kmodloader: done loading kernel modules from /etc/modules-boot.d/*
[    5.905879] init: - preinit -
[    6.506728] mtk_soc_eth 1e100000.ethernet eth0: configuring for fixed/rgmii link mode
[    6.522835] mtk_soc_eth 1e100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[    6.539723] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[    6.694891] random: jshn: uninitialized urandom read (4 bytes read)
[    6.766052] random: jshn: uninitialized urandom read (4 bytes read)
[    6.815872] random: jshn: uninitialized urandom read (4 bytes read)
[    7.062205] mt7530 mdio-bus:1f lan1: configuring for phy/gmii link mode
[    7.075814] 8021q: adding VLAN 0 to HW filter on device lan1
[   11.269078] UBIFS (ubi0:1): Mounting in unauthenticated mode
[   11.280656] UBIFS (ubi0:1): background thread "ubifs_bgt0_1" started, PID 640
[   11.364267] UBIFS (ubi0:1): recovery needed
[   11.535973] UBIFS (ubi0:1): recovery completed
[   11.545013] UBIFS (ubi0:1): UBIFS: mounted UBI device 0, volume 1, name "rootfs_data"
[   11.560620] UBIFS (ubi0:1): LEB size: 126976 bytes (124 KiB), min./max. I/O unit sizes: 2048 bytes/2048 bytes
[   11.580375] UBIFS (ubi0:1): FS size: 28315648 bytes (27 MiB, 223 LEBs), journal size 1396736 bytes (1 MiB, 11 LEBs)
[   11.601163] UBIFS (ubi0:1): reserved for root: 1337417 bytes (1306 KiB)
[   11.614347] UBIFS (ubi0:1): media format: w5/r0 (latest is w5/r0), UUID 23E96789-AFF0-446A-A4FB-36297BDD5320, small LPT model
[   11.643487] mount_root: switching to ubifs overlay
[   11.669468] urandom-seed: Seeding with /etc/urandom.seed
[   11.778018] procd: - early -
[   11.783937] procd: - watchdog -
[   12.385719] procd: - watchdog -
[   12.395320] procd: - ubus -
[   12.561663] procd: - init -
[   13.184136] kmodloader: loading kernel modules from /etc/modules.d/*
[   13.210563] Loading modules backported from Linux version v5.10.68-0-g4d8524048a35
[   13.225773] Backport generated by backports.git v5.10.68-1-0-ga4f9ba32
[   13.255868] xt_time: kernel timezone is -0000
[   13.315749] mt7621-pci 1e140000.pcie: bus=1 slot=0 irq=23
[   13.326562] pci 0000:00:00.0: enabling device (0006 -> 0007)
[   13.337847] mt7615e 0000:01:00.0: enabling device (0000 -> 0002)
[   13.363682] ieee80211 phy0: Selected rate control algorithm 'minstrel_ht'
[   13.368666] mt7621-pci 1e140000.pcie: bus=2 slot=1 irq=24
[   13.375954] urngd: v1.0.2 started.
[   13.379542] pci 0000:00:01.0: enabling device (0006 -> 0007)
[   13.386737] mt7615e 0000:01:00.0: HW/SW Version: 0x8a108a10, Build Time: 20180518100604a
[   13.386737]
[   13.397609] mt7615e 0000:02:00.0: enabling device (0000 -> 0002)
[   13.537420] ieee80211 phy1: Selected rate control algorithm 'minstrel_ht'
[   13.563084] mt7615e 0000:02:00.0: HW/SW Version: 0x8a108a10, Build Time: 20180518100604a
[   13.563084]
[   13.590541] PPP generic driver version 2.4.2
[   13.605323] NET: Registered protocol family 24
[   13.645252] random: crng init done
[   13.652190] random: 7 urandom warning(s) missed due to ratelimiting
[   13.653456] kmodloader: done loading kernel modules from /etc/modules.d/*
[   13.726726] mt7615e 0000:01:00.0: N9 Firmware Version: _reserved_, Build Time: 20200814163649
[   13.744007] mt7615e 0000:02:00.0: N9 Firmware Version: _reserved_, Build Time: 20200814163649
[   13.813187] mt7615e 0000:02:00.0: CR4 Firmware Version: _reserved_, Build Time: 20190121161307
[   13.830796] mt7615e 0000:01:00.0: CR4 Firmware Version: _reserved_, Build Time: 20190121161307
[   19.670300] mtk_soc_eth 1e100000.ethernet eth0: Link is Down
[   19.695206] mtk_soc_eth 1e100000.ethernet eth0: configuring for fixed/rgmii link mode
[   19.711398] mtk_soc_eth 1e100000.ethernet eth0: Link is Up - 1Gbps/Full - flow control rx/tx
[   19.718282] mt7530 mdio-bus:1f lan1: configuring for phy/gmii link mode
[   19.742157] 8021q: adding VLAN 0 to HW filter on device lan1
[   19.756579] IPv6: ADDRCONF(NETDEV_CHANGE): eth0: link becomes ready
[   19.770474] br-lan: port 1(lan1) entered blocking state
[   19.781058] br-lan: port 1(lan1) entered disabled state
[   19.793075] device lan1 entered promiscuous mode
[   19.802363] device eth0 entered promiscuous mode
[   19.841407] mt7530 mdio-bus:1f lan2: configuring for phy/gmii link mode
[   19.855322] 8021q: adding VLAN 0 to HW filter on device lan2
[   19.870418] br-lan: port 2(lan2) entered blocking state
[   19.881013] br-lan: port 2(lan2) entered disabled state
[   19.893028] device lan2 entered promiscuous mode
[   19.914754] mt7530 mdio-bus:1f lan3: configuring for phy/gmii link mode
[   19.929864] 8021q: adding VLAN 0 to HW filter on device lan3
[   19.945414] br-lan: port 3(lan3) entered blocking state
[   19.956001] br-lan: port 3(lan3) entered disabled state
[   19.968351] device lan3 entered promiscuous mode
[   19.989987] mt7530 mdio-bus:1f lan4: configuring for phy/gmii link mode
[   20.006961] 8021q: adding VLAN 0 to HW filter on device lan4
[   20.022420] br-lan: port 4(lan4) entered blocking state
[   20.032954] br-lan: port 4(lan4) entered disabled state
[   20.045776] device lan4 entered promiscuous mode
[   20.077281] mt7530 mdio-bus:1f wan: configuring for phy/gmii link mode
[   20.090975] 8021q: adding VLAN 0 to HW filter on device wan
[   22.811693] br-lan: port 5(wlan0) entered blocking state
[   22.822320] br-lan: port 5(wlan0) entered disabled state
[   22.833417] device wlan0 entered promiscuous mode
[   22.843131] br-lan: port 5(wlan0) entered blocking state
[   22.853791] br-lan: port 5(wlan0) entered forwarding state
[   22.865300] br-lan: port 5(wlan0) entered disabled state
[   24.122043] mt7530 mdio-bus:1f lan4: Link is Up - 1Gbps/Full - flow control rx/tx
[   24.172279] br-lan: port 4(lan4) entered blocking state
[   24.182723] br-lan: port 4(lan4) entered forwarding state
[   24.194639] br-lan: port 6(wlan1) entered blocking state
[   24.205260] br-lan: port 6(wlan1) entered disabled state
[   24.216346] device wlan1 entered promiscuous mode
[   24.226139] IPv6: ADDRCONF(NETDEV_CHANGE): br-lan: link becomes ready
[   32.623029] IPv6: ADDRCONF(NETDEV_CHANGE): wlan1: link becomes ready
[   32.636054] br-lan: port 6(wlan1) entered blocking state
[   32.646689] br-lan: port 6(wlan1) entered forwarding state
[   34.171784] IPv6: ADDRCONF(NETDEV_CHANGE): wlan0: link becomes ready
[   34.184826] br-lan: port 5(wlan0) entered blocking state
[   34.195450] br-lan: port 5(wlan0) entered forwarding state
[   34.426040] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   34.441179] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
[   35.449801] mt7530 mdio-bus:1f wan: Link is Down
[   36.314099] mt7530 mdio-bus:1f lan3: Link is Up - 100Mbps/Full - flow control off
[   36.329111] br-lan: port 3(lan3) entered blocking state
[   36.339577] br-lan: port 3(lan3) entered forwarding state
[   48.761954] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   49.785805] mt7530 mdio-bus:1f wan: Link is Down
[   78.457963] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   79.481822] mt7530 mdio-bus:1f wan: Link is Down
[   92.793963] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   93.817830] mt7530 mdio-bus:1f wan: Link is Down

psherman · November 29, 2021, 1:12am

A lot of link-up/down messages. Seems like a port flapping issue. Try replacing the cable and see if that helps.

ShwangShwing · November 29, 2021, 1:25am

I will try that tomorrow if I have time. But don't you think bad cable will cause problem in my old router also? Also why would connection be established after I disable and then enable the wan interface through the cli?

psherman · November 29, 2021, 1:29am

bad cables can be problematic with some devices and not with others -- depends on the specific failure modes of the cable and the electrical tolerances of the hardware on each end. I'm not saying that it is absolutely the issue, but best to rule it out before banging your head on other potential causes.

ShwangShwing · November 29, 2021, 1:57am

OK, but it is very difficult for me to completely rule it out, due to the place I live in. I live in an apartent in a 10 story building. My appartment is at floor 8. I have a cable from my router to the wall. This is the only thing I can change easily. From the wall there is a cable to a box near the elevator outside the appartments. In this box there is a switch in which my cable from the wall goes (along with cables from other apartments on the same floor who are subscribed to the same ISP. From the switch goes a cable to the first floor (through some pipes) and there I think is some switch or some other device that accepts ethernet cables and has an optic cable that exits the building.

So as you can see the only thing I can easily test is the cable from the router to the wall . That's why if some of the other cables have a problem I will need the cooperation of the technitians to find the problem.

Is there any way to see if bad cables can couse the problem? Can I at least somehow test the connection to the ISP switch on my floor?

ShwangShwing · November 29, 2021, 2:28pm

So I changed the cable and the result is the same.
Here are logs before dong ifconfig wan down and ifconfig wan up

Mon Nov 29 12:10:13 2021 kern.info kernel: [  264.745275] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 12:10:13 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 12:10:13 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 12:10:13 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 12:10:13 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 12:10:13 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 12:10:13 2021 daemon.notice netifd: wan (4821): udhcpc: started, v1.33.1
Mon Nov 29 12:10:13 2021 daemon.notice netifd: wan (4821): udhcpc: sending discover
Mon Nov 29 12:10:14 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 12:10:14 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 12:10:14 2021 kern.info kernel: [  265.769156] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 12:10:14 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 12:10:14 2021 daemon.notice netifd: wan (4821): udhcpc: received SIGTERM
Mon Nov 29 12:10:14 2021 daemon.notice netifd: wan (4821): udhcpc: entering released state
Mon Nov 29 12:10:14 2021 daemon.notice netifd: wan (4821): Command failed: Permission denied
Mon Nov 29 12:10:14 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 12:10:14 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 12:10:28 2021 kern.info kernel: [  279.081295] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 12:10:28 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 12:10:28 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 12:10:28 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 12:10:28 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 12:10:28 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 12:10:28 2021 daemon.notice netifd: wan (4927): udhcpc: started, v1.33.1
Mon Nov 29 12:10:28 2021 daemon.notice netifd: wan (4927): udhcpc: sending discover
Mon Nov 29 12:10:29 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 12:10:29 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 12:10:29 2021 kern.info kernel: [  280.105110] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 12:10:29 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 12:10:29 2021 daemon.notice netifd: wan (4927): udhcpc: received SIGTERM
Mon Nov 29 12:10:29 2021 daemon.notice netifd: wan (4927): udhcpc: entering released state
Mon Nov 29 12:10:29 2021 daemon.notice netifd: wan (4927): Command failed: Permission denied
Mon Nov 29 12:10:29 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 12:10:30 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 12:10:42 2021 kern.info kernel: [  293.417271] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 12:10:42 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 12:10:42 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 12:10:42 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 12:10:42 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 12:10:42 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 12:10:42 2021 daemon.notice netifd: wan (5033): udhcpc: started, v1.33.1
Mon Nov 29 12:10:42 2021 daemon.notice netifd: wan (5033): udhcpc: sending discover
Mon Nov 29 12:10:43 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 12:10:43 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 12:10:43 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 12:10:43 2021 kern.info kernel: [  294.441119] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 12:10:43 2021 daemon.notice netifd: wan (5033): udhcpc: received SIGTERM
Mon Nov 29 12:10:43 2021 daemon.notice netifd: wan (5033): udhcpc: entering released state
Mon Nov 29 12:10:43 2021 daemon.notice netifd: wan (5033): Command failed: Permission denied
Mon Nov 29 12:10:43 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 12:10:44 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 12:10:56 2021 kern.info kernel: [  307.753270] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 12:10:56 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 12:10:56 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 12:10:56 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 12:10:56 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 12:10:56 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 12:10:56 2021 daemon.notice netifd: wan (5148): udhcpc: started, v1.33.1
Mon Nov 29 12:10:56 2021 daemon.notice netifd: wan (5148): udhcpc: sending discover
Mon Nov 29 12:10:57 2021 daemon.notice netifd: Network device 'wan' link is down
Mon Nov 29 12:10:57 2021 daemon.notice netifd: Interface 'wan' has link connectivity loss
Mon Nov 29 12:10:57 2021 daemon.notice netifd: Interface 'wan6' has link connectivity loss
Mon Nov 29 12:10:57 2021 kern.info kernel: [  308.777114] mt7530 mdio-bus:1f wan: Link is Down
Mon Nov 29 12:10:57 2021 daemon.notice netifd: wan (5148): udhcpc: received SIGTERM
Mon Nov 29 12:10:57 2021 daemon.notice netifd: wan (5148): udhcpc: entering released state
Mon Nov 29 12:10:57 2021 daemon.notice netifd: wan (5148): Command failed: Permission denied
Mon Nov 29 12:10:57 2021 daemon.notice netifd: Interface 'wan' is now down
Mon Nov 29 12:10:58 2021 daemon.notice netifd: Interface 'wan6' is now down

[   48.681249] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   49.705120] mt7530 mdio-bus:1f wan: Link is Down
[   63.017246] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   64.041100] mt7530 mdio-bus:1f wan: Link is Down
[   77.353268] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   78.377098] mt7530 mdio-bus:1f wan: Link is Down
[   91.689255] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[   92.713096] mt7530 mdio-bus:1f wan: Link is Down
[  106.025251] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  107.049121] mt7530 mdio-bus:1f wan: Link is Down
[  150.057325] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  151.081158] mt7530 mdio-bus:1f wan: Link is Down
[  164.393256] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  165.417108] mt7530 mdio-bus:1f wan: Link is Down
[  193.065291] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  194.089129] mt7530 mdio-bus:1f wan: Link is Down
[  207.401265] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  208.425109] mt7530 mdio-bus:1f wan: Link is Down
[  221.737287] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  222.761106] mt7530 mdio-bus:1f wan: Link is Down
[  236.073293] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  237.097123] mt7530 mdio-bus:1f wan: Link is Down
[  250.409279] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  251.433119] mt7530 mdio-bus:1f wan: Link is Down
[  264.745275] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  265.769156] mt7530 mdio-bus:1f wan: Link is Down
[  279.081295] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  280.105110] mt7530 mdio-bus:1f wan: Link is Down
[  293.417271] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  294.441119] mt7530 mdio-bus:1f wan: Link is Down
[  307.753270] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  308.777114] mt7530 mdio-bus:1f wan: Link is Down
[  337.449288] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  338.473118] mt7530 mdio-bus:1f wan: Link is Down
[  351.785295] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  352.809121] mt7530 mdio-bus:1f wan: Link is Down
[  381.481279] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  382.505132] mt7530 mdio-bus:1f wan: Link is Down
[  395.817280] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  396.841122] mt7530 mdio-bus:1f wan: Link is Down

And then I do
ifconfig wan down
ifconfig wan up
And the network comes online. Here are the logs:

[  442.007156] mt7530 mdio-bus:1f wan: configuring for phy/gmii link mode
[  442.020760] 8021q: adding VLAN 0 to HW filter on device wan
[  456.361374] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
[  456.376523] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready

Mon Nov 29 12:12:55 2021 daemon.notice netifd: Interface 'wan6' is now down
Mon Nov 29 12:13:11 2021 kern.info kernel: [  442.007156] mt7530 mdio-bus:1f wan: configuring for phy/gmii link mode
Mon Nov 29 12:13:11 2021 kern.info kernel: [  442.020760] 8021q: adding VLAN 0 to HW filter on device wan
Mon Nov 29 12:13:25 2021 kern.info kernel: [  456.361374] mt7530 mdio-bus:1f wan: Link is Up - 100Mbps/Full - flow control rx/tx
Mon Nov 29 12:13:25 2021 kern.info kernel: [  456.376523] IPv6: ADDRCONF(NETDEV_CHANGE): wan: link becomes ready
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Network device 'wan' link is up
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Interface 'wan' has link connectivity
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Interface 'wan' is setting up now
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Interface 'wan6' has link connectivity
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Interface 'wan6' is setting up now
Mon Nov 29 12:13:25 2021 daemon.notice netifd: wan (5820): udhcpc: started, v1.33.1
Mon Nov 29 12:13:25 2021 daemon.err odhcp6c[5821]: Failed to send RS (Address not available)
Mon Nov 29 12:13:25 2021 daemon.notice netifd: wan (5820): udhcpc: sending discover
Mon Nov 29 12:13:25 2021 daemon.notice netifd: wan (5820): udhcpc: sending select for 92.118.152.209
Mon Nov 29 12:13:25 2021 daemon.notice netifd: wan (5820): udhcpc: lease of 92.118.152.209 obtained, lease time 600
Mon Nov 29 12:13:25 2021 daemon.err odhcp6c[5821]: Failed to send SOLICIT message to ff02::1:2 (Address not available)
Mon Nov 29 12:13:25 2021 daemon.notice netifd: Interface 'wan' is now up
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: reading /tmp/resolv.conf.d/resolv.conf.auto
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain test
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain onion
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain localhost
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain local
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain invalid
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain bind
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 198.101.242.72#53
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 8.8.4.4#53
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 8.8.8.8#53
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 208.67.220.220#53
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 208.67.222.222#53
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using only locally-known addresses for domain lan
Mon Nov 29 12:13:25 2021 daemon.info dnsmasq[3034]: using nameserver 92.118.152.1#53
Mon Nov 29 12:13:25 2021 user.notice firewall: Reloading firewall due to ifup of wan (wan)
Mon Nov 29 12:13:26 2021 daemon.err odhcp6c[5821]: Failed to send SOLICIT message to ff02::1:2 (Address not available)

What causes this? How can I debug it?

trendy · November 30, 2021, 2:54pm

You can try to troubleshoot by capturing the packets.

Maybe we'll be able to see something more enlightening there.

ShwangShwing · December 1, 2021, 1:18am

Here is the tcpdump log after restarting the router:

root@Hidroizolatsia:~# tcpdump -i wan -e
tcpdump: verbose output suppressed, use -v or -vv for full protocol decode
listening on wan, link-type EN10MB (Ethernet), capture size 262144 bytes
02:55:18.847632 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
02:55:18.931712 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 70: fe80::6a7f:74ff:feb0:e8f7 > ip6-allrouters: ICMP6, router solicitation, length 16
02:55:18.955596 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
02:55:19.035517 68:7f:74:b0:e8:f7 (oui Unknown) > Broadcast, ethertype IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 68:7f:74:b0:e8:f7 (oui Unknown), length 300
02:55:19.803787 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:01:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 171: fe80::6a7f:74ff:feb0:e8f7.546 > ff02::1:2.547: dhcp6 solicit
02:56:30.531633 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
02:56:30.619340 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 70: fe80::6a7f:74ff:feb0:e8f7 > ip6-allrouters: ICMP6, router solicitation, length 16
02:56:30.711572 68:7f:74:b0:e8:f7 (oui Unknown) > Broadcast, ethertype IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 68:7f:74:b0:e8:f7 (oui Unknown), length 300
02:56:30.919546 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
02:56:31.203816 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:01:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 171: fe80::6a7f:74ff:feb0:e8f7.546 > ff02::1:2.547: dhcp6 solicit
02:57:41.183639 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
02:57:41.267020 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 70: fe80::6a7f:74ff:feb0:e8f7 > ip6-allrouters: ICMP6, router solicitation, length 16
02:57:41.343525 68:7f:74:b0:e8:f7 (oui Unknown) > Broadcast, ethertype IPv4 (0x0800), length 342: 0.0.0.0.68 > 255.255.255.255.67: BOOTP/DHCP, Request from 68:7f:74:b0:e8:f7 (oui Unknown), length 300
02:57:41.611770 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:01:00:02 (oui Unknown), ethertype IPv6 (0x86dd), length 171: fe80::6a7f:74ff:feb0:e8f7.546 > ff02::1:2.547: dhcp6 solicit
02:57:42.151539 68:7f:74:b0:e8:f7 (oui Unknown) > 33:33:00:00:00:16 (oui Unknown), ethertype IPv6 (0x86dd), length 150: fe80::6a7f:74ff:feb0:e8f7 > ff02::16: HBH ICMP6, multicast listener report v2, 4 group record(s), length 88
^C
15 packets captured
15 packets received by filter
0 packets dropped by kernel

As you can see every minute the same messages repeat.
Here is some more random info:

root@Hidroizolatsia:~# ip link
1: lo: <LOOPBACK,UP,LOWER_UP> mtu 65536 qdisc noqueue state UNKNOWN qlen 1000
    link/loopback 00:00:00:00:00:00 brd 00:00:00:00:00:00
2: eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1504 qdisc fq_codel state UP qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
3: lan4@eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br-lan state UP qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
4: lan3@eth0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br-lan state UP qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
5: lan2@eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue master br-lan state LOWERLAYERDOWN qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
6: lan1@eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue master br-lan state LOWERLAYERDOWN qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
7: wan@eth0: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue state LOWERLAYERDOWN qlen 1000
    link/ether 68:7f:74:b0:e8:f7 brd ff:ff:ff:ff:ff:ff
10: br-lan: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue state UP qlen 1000
    link/ether bc:0f:9a:53:47:30 brd ff:ff:ff:ff:ff:ff
11: wlan0: <BROADCAST,MULTICAST,UP,LOWER_UP> mtu 1500 qdisc noqueue master br-lan state UP qlen 1000
    link/ether bc:0f:9a:53:47:31 brd ff:ff:ff:ff:ff:ff
12: wlan1: <NO-CARRIER,BROADCAST,MULTICAST,UP> mtu 1500 qdisc noqueue master br-lan state DOWN qlen 1000
    link/ether bc:0f:9a:53:47:32 brd ff:ff:ff:ff:ff:ff

Also
The wan led on the router is off most of the time, flashes a little every minute and once again turns back off. The same is happening on the switch of my ISP (yes, I can access it). The port I am connected to lights up briefly every minute and turns back off.

What the hell is going on?

psherman · December 1, 2021, 1:39am

Your router has a gigabit ethernet port on it, but is only connecting at 100Mbps. What is the device on the other side? Is it also a gigabit device (switch, modem, ONT)? If so, there may be an issue with the cabling.

Do you happen to have a basic gigabit switch you can connect between the wall and the router? (nothing else should be connected to this switch). This will help you verify that the router isn't responsible for the port flapping issue. You may even be able to see the port on the switch that is connected upstream flapping if the cable is the problem. Or, in some situations, the intermediate switch can help stabilize a marginal connection.

ShwangShwing · December 1, 2021, 2:20am

So... I did some investigation (which included a little tinkering with my ISP's device that I happen to have access to). I opened the cable box on my floor in front of my appartment, where my ISP's switch (which I am connected to through the wall) happen to be.
And yes, it is a Gigabit switch.

But here it gets interesting. Only two of the four twisted pairs of the cable corresponding to my appartment were crimped (the other two were dangling). This apperently didn't bother my previous 100Mbps router as 100Mbps uses only two pairs.

I decided to do a little more testing. I brought my router and connected it directly to my ISP's switch with a properly crimped cable. I brought my laptop with me to test. WAN connected correctly. I stayed there like an idiot for 20-30 minutes and the random disconnects were gone.

So tomorrow I will probably try to crimp the cable to my ISP's switch correctly and see if the problem will disappear.

BUT.
I am wandering why 100Mbps fallback doesn't work. I don't really need gigabit WAN as I 1. don't need such a speed and 2. I haven't paid for such a speed so the ISP won't provide it to me anyway.

Nevertheless I will try recrimping tomorrow and hope this will solve/work around the problem.

psherman · December 1, 2021, 2:51am

Like I said at the beginning, bad cables can cause all sorts of unpredictable issues.

ShwangShwing · December 1, 2021, 10:44pm

OK, I recrimped everything and now I have 1Gbit connection on my WAN port, which doesn't interrupt every 10 minutes.

I am still wandoering why the 100Mbit fallback didn't work well though, but I am glad I fixed this issue.

psherman · December 1, 2021, 10:58pm

It is possible that the auto-negotiation was looping, thus the port flapping. I have never experience this specific issue, but basically the auto-negotiation starts by the two endpoints advertising their 'technology abilities' -- IIRC, this happens over the 2 pairs used for 10/100 connectivity. If both sides can do gigabit, they will try to connect as such, but then fail back to 100Mbps when link cannot be established due to the missing pairs. AFAIK, some devices may try again and may even end up in a perpetual negotiation loop, while others will fall back to 100Mbps and maintain that unless/until the link is dropped and re-established. In the case of your 100Mbps router, the negotiation would always be happy at 100Mbps using the 2 working pairs, so it wouldn't ever need to worry about the fact that 2 pairs were not connected.

system · December 11, 2021, 10:58pm

This topic was automatically closed 10 days after the last reply. New replies are no longer allowed.