Control: tags -1 + moreinfo Hi,
On Sun, Mar 28, 2021 at 01:55:27PM -0400, jorges wrote: > Package: src:linux > Version: 5.10.13-1~bpo10+1 > Severity: normal > > Dear Maintainer, > > > * What led up to the situation? > plugged in unplugged network cable after system had booted > > > -- Package-specific info: > ** Version: > Linux version 5.10.0-0.bpo.3-amd64 ([email protected]) (gcc-8 > (Debian 8.3.0-6) 8.3.0, GNU ld (GNU Binutils for Debian) 2.31.1) #1 SMP > Debian 5.10.13-1~bpo10+1 (2021-02-11) > > ** Command line: > BOOT_IMAGE=/boot/vmlinuz-5.10.0-0.bpo.3-amd64 > root=UUID=f44239b2-ab75-4ed4-b80c-66a3e3bfdb7c ro quiet > > ** Tainted: W (512) > * kernel issued warning > > ** Kernel log: > [ 10.145673] bond0: active interface up! > [ 10.145721] IPv6: ADDRCONF(NETDEV_CHANGE): bond0: link becomes ready > [ 98.468938] bridge: filtering via arp/ip/ip6tables is no longer available > by default. Update your scripts to load br_netfilter if you need this. > [ 98.472209] Bridge firewalling registered > [ 98.810797] Initializing XFRM netlink socket > [ 99.885351] docker0: port 1(vethd1123f1) entered blocking state > [ 99.885358] docker0: port 1(vethd1123f1) entered disabled state > [ 99.886403] device vethd1123f1 entered promiscuous mode > [ 100.235346] cgroup: cgroup: disabling cgroup2 socket matching due to > net_prio or net_cls activation > [ 100.549859] eth0: renamed from vethbfc64a3 > [ 100.565530] IPv6: ADDRCONF(NETDEV_CHANGE): vethd1123f1: link becomes ready > [ 100.565579] docker0: port 1(vethd1123f1) entered blocking state > [ 100.565582] docker0: port 1(vethd1123f1) entered forwarding state > [ 100.565642] IPv6: ADDRCONF(NETDEV_CHANGE): docker0: link becomes ready > [ 105.367582] softdog: initialized. soft_noboot=0 soft_margin=60 sec > soft_panic=0 (nowayout=0) > [ 105.367585] softdog: soft_reboot_cmd=<not set> > soft_active_on_boot=0 > [ 128.344188] md/raid:md0: device sde operational as raid disk 3 > [ 128.344195] md/raid:md0: device sdd operational as raid disk 2 > [ 128.344197] md/raid:md0: device sdc operational as raid disk 1 > [ 128.344200] md/raid:md0: device sdb operational as raid disk 0 > [ 128.346881] md/raid:md0: raid level 5 active with 4 out of 5 devices, > algorithm 2 > [ 128.439807] md0: detected capacity change from 0 to 32005710413824 > [ 128.650465] md: recovery of RAID array md0 > [ 454.103857] md: md0: recovery interrupted. > [ 454.357959] md0: detected capacity change from 32005710413824 to 0 > [ 454.357980] md: md0 stopped. > [ 476.791911] md/raid:md0: not clean -- starting background reconstruction > [ 476.792000] md/raid:md0: device sdf operational as raid disk 4 > [ 476.792003] md/raid:md0: device sde operational as raid disk 3 > [ 476.792006] md/raid:md0: device sdd operational as raid disk 2 > [ 476.792009] md/raid:md0: device sdc operational as raid disk 1 > [ 476.792011] md/raid:md0: device sdb operational as raid disk 0 > [ 476.795225] md/raid:md0: raid level 5 active with 5 out of 5 devices, > algorithm 2 > [ 476.884048] md0: detected capacity change from 0 to 32005710413824 > [ 476.894859] md: resync of RAID array md0 > [ 2184.661660] perf: interrupt took too long (2510 > 2500), lowering > kernel.perf_event_max_sample_rate to 79500 > [ 2730.638069] RTL8226B_RTL8221B 2.5Gbps PHY r8169-200:00: Downshift occurred > from negotiated speed 1Gbps to actual speed 100Mbps, check cabling! > [ 2730.638081] r8169 0000:02:00.0 enp2s0: Link is Up - 100Mbps/Full > (downshifted) - flow control off > [ 2730.673598] bond0: (slave enp2s0): link status up, enabling it in 200 ms > [ 2730.673603] bond0: (slave enp2s0): invalid new link 3 on slave > [ 2730.881666] bond0: (slave enp2s0): link status definitely up, 100 Mbps > full duplex > [ 2741.212653] ------------[ cut here ]------------ > [ 2741.212657] NETDEV WATCHDOG: enp2s0 (r8169): transmit queue 0 timed out > [ 2741.212678] WARNING: CPU: 1 PID: 0 at net/sched/sch_generic.c:443 > dev_watchdog+0x246/0x250 > [ 2741.212680] Modules linked in: softdog xt_nat xt_tcpudp veth xt_conntrack > xt_MASQUERADE nf_conntrack_netlink nfnetlink xfrm_user xfrm_algo xt_addrtype > iptable_filter iptable_nat nf_nat nf_conntrack nf_defrag_ipv6 nf_defrag_ipv4 > br_netfilter bridge stp llc cpufreq_conservative cpufreq_userspace > cpufreq_powersave cpufreq_ondemand overlay snd_hda_codec_hdmi intel_rapl_msr > intel_rapl_common snd_hda_codec_realtek snd_hda_codec_generic > x86_pkg_temp_thermal intel_powerclamp coretemp nls_ascii nls_cp437 kvm_intel > vfat fat kvm irqbypass crc32_pclmul ghash_clmulni_intel i915 snd_sof_pci > snd_sof_intel_byt snd_sof_intel_ipc snd_sof_intel_hda_common > snd_sof_xtensa_dsp snd_sof snd_sof_intel_hda ledtrig_audio snd_soc_skl > snd_soc_hdac_hda snd_hda_ext_core snd_soc_sst_ipc snd_soc_sst_dsp > snd_soc_acpi_intel_match snd_soc_acpi snd_hda_intel snd_intel_dspcfg > soundwire_intel soundwire_generic_allocation snd_soc_core snd_compress > soundwire_cadence drm_kms_helper snd_hda_codec aesni_intel libaes crypto_simd > [ 2741.212740] snd_hda_core cryptd glue_helper cec snd_hwdep rapl > soundwire_bus snd_pcm intel_cstate efi_pstore pcspkr ucsi_acpi wdat_wdt drm > watchdog evdev mei_me snd_timer typec_ucsi i2c_algo_bit snd mei sg soundcore > typec intel_pmc_core button bonding sunrpc emc2103 i2c_dev efivarfs ip_tables > x_tables autofs4 ext4 crc16 mbcache jbd2 btrfs blake2b_generic raid10 raid456 > async_raid6_recov async_memcpy async_pq async_xor async_tx xor raid6_pq > libcrc32c crc32c_generic raid1 raid0 multipath linear md_mod dm_mirror > dm_region_hash dm_log dm_mod sd_mod t10_pi crc_t10dif crct10dif_generic > mmc_block xhci_pci sdhci_pci xhci_hcd cqhci sdhci mmc_core crct10dif_pclmul > crct10dif_common i2c_i801 usbcore crc32c_intel i2c_smbus ahci libahci libata > intel_lpss_pci intel_lpss idma64 usb_common r8169 realtek mdio_devres libphy > scsi_mod fan video > [ 2741.212817] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 5.10.0-0.bpo.3-amd64 > #1 Debian 5.10.13-1~bpo10+1 > [ 2741.212819] Hardware name: HARDKERNEL ODROID-H2/ODROID-H2, BIOS 5.13 > 08/11/2020 > [ 2741.212822] RIP: 0010:dev_watchdog+0x246/0x250 > [ 2741.212825] Code: e8 1f d1 fd ff eb ad 4c 89 e7 c6 05 bc b5 13 01 01 e8 de > b4 fa ff 89 d9 4c 89 e6 48 c7 c7 00 f0 d6 b7 48 89 c2 e8 bb e1 13 00 <0f> 0b > eb 8f 66 0f 1f 44 00 00 0f 1f 44 00 00 41 57 41 56 49 89 d6 > [ 2741.212826] RSP: 0018:ffffa75c800e4ec8 EFLAGS: 00010282 > [ 2741.212828] RAX: 0000000000000000 RBX: 0000000000000000 RCX: > 0000000000000027 > [ 2741.212829] RDX: 0000000000000027 RSI: ffff9c102fc98a00 RDI: > ffff9c102fc98a08 > [ 2741.212830] RBP: ffff9c0f5a65c3dc R08: 0000000000000000 R09: > c0000000ffffefff > [ 2741.212831] R10: 0000000000000001 R11: ffffa75c800e4cd0 R12: > ffff9c0f5a65c000 > [ 2741.212833] R13: 0000000000000001 R14: ffff9c0f5a65c480 R15: > 0000000000000001 > [ 2741.212834] FS: 0000000000000000(0000) GS:ffff9c102fc80000(0000) > knlGS:0000000000000000 > [ 2741.212835] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 > [ 2741.212837] CR2: 00007f6d743a9718 CR3: 0000000105396000 CR4: > 0000000000350ee0 > [ 2741.212838] Call Trace: > [ 2741.212841] <IRQ> > [ 2741.212846] ? pfifo_fast_enqueue+0x140/0x140 > [ 2741.212850] call_timer_fn+0x29/0xf0 > [ 2741.212853] run_timer_softirq+0x1c7/0x3e0 > [ 2741.212856] ? ktime_get+0x3e/0xa0 > [ 2741.212859] ? lapic_next_deadline+0x22/0x30 > [ 2741.212862] ? clockevents_program_event+0x94/0xf0 > [ 2741.212866] __do_softirq+0xd5/0x29c > [ 2741.212869] asm_call_irq_on_stack+0xf/0x20 > [ 2741.212871] </IRQ> > [ 2741.212874] do_softirq_own_stack+0x37/0x40 > [ 2741.212878] irq_exit_rcu+0x9d/0xa0 > [ 2741.212881] sysvec_apic_timer_interrupt+0x34/0x80 > [ 2741.212883] asm_sysvec_apic_timer_interrupt+0x12/0x20 > [ 2741.212887] RIP: 0010:cpuidle_enter_state+0xde/0x360 > [ 2741.212889] Code: 31 ff e8 65 dc a4 ff 45 84 ff 74 17 9c 58 0f 1f 44 00 00 > f6 c4 02 0f 85 38 02 00 00 31 ff e8 89 2f ab ff fb 66 0f 1f 44 00 00 <45> 85 > f6 0f 88 e0 00 00 00 49 63 d6 4c 2b 24 24 48 8d 04 52 48 8d > [ 2741.212890] RSP: 0018:ffffa75c8009fe80 EFLAGS: 00000246 > [ 2741.212892] RAX: ffff9c102fcabc00 RBX: 0000000000000002 RCX: > 000000000000001f > [ 2741.212893] RDX: 0000027e3d0182c7 RSI: 0000000047af4125 RDI: > 0000000000000000 > [ 2741.212894] RBP: ffff9c102fcb5c00 R08: 0000000000000000 R09: > 000000000002b480 > [ 2741.212895] R10: 0000047970650ec0 R11: ffff9c102fcaab84 R12: > 0000027e3d0182c7 > [ 2741.212896] R13: ffffffffb83ae500 R14: 0000000000000002 R15: > 0000000000000000 > [ 2741.212901] cpuidle_enter+0x29/0x40 > [ 2741.212905] do_idle+0x25c/0x2b0 > [ 2741.212908] cpu_startup_entry+0x19/0x20 > [ 2741.212911] start_secondary+0x113/0x150 > [ 2741.212914] secondary_startup_64_no_verify+0xb0/0xbb > [ 2741.212917] ---[ end trace 8176557f023b292c ]--- > [ 2888.955393] perf: interrupt took too long (3153 > 3137), lowering > kernel.perf_event_max_sample_rate to 63250 > [ 2929.835422] r8169 0000:02:00.0 enp2s0: Link is Down > [ 2929.852222] bond0: (slave enp2s0): link status down for interface, > disabling it in 200 ms > [ 2929.852227] bond0: (slave enp2s0): invalid new link 1 on slave > [ 2930.060358] bond0: (slave enp2s0): link status definitely down, disabling > slave > [ 2932.429693] r8169 0000:02:00.0 enp2s0: Link is Up - 1Gbps/Full - flow > control off > [ 2932.455981] bond0: (slave enp2s0): link status up, enabling it in 200 ms > [ 2932.455986] bond0: (slave enp2s0): invalid new link 3 on slave > [ 2932.668085] bond0: (slave enp2s0): link status definitely up, 1000 Mbps > full duplex > [ 3669.017422] r8169 0000:02:00.0: invalid large VPD tag 7f at offset 0 > [ 3669.018292] r8169 0000:03:00.0: invalid large VPD tag 7f at offset 0 > [ 4193.250031] perf: interrupt took too long (3946 > 3941), lowering > kernel.perf_event_max_sample_rate to 50500 The error looks like the one addressed in 186edbb510bd ("net: amd-xgbe: Fix NETDEV WATCHDOG transmit queue timeout warning") in 5.12-rc1 which for the 5.10.y stable series was backported to 5.10.20. Can you check the kernel from unstable if you can reproduce the issue there? I believe with above information it should be already fixed in 5.10.24 based upload. Regards, Salvatore
