Re: Bug#549606: [linux-image-2.6.30-1-amd64] VIA-Rhine II network interface lost connectivity
On Monday, 5. October 2009 01:29:39 Ben Hutchings wrote:
> On Mon, 2009-10-05 at 00:15 +0100, Antonio Marcos López Alonso wrote:
> > > Is this a new problem or did it occur with earlier kernel versions?
> >
> > No, it happened also in previous versions. But at least irqpoll/irqfixup
> > worked pretty well. Now this behavior seems to get worsened even using
> > these kernel options.
> >
> > > Can you try to reproduce this without the nvidia or virtualbox modules
> > > loaded?
> >
> > I can but just to make things faster:
> >
> > Jens-Michael,
> >
> > Have you got any nvidia/virtualbox modules running in your host? Just to
> > discard...
>
> The warning message shows all loaded modules, and those aren't included,
> so this question is answered.
>
> I had a look at the code and the values in the 'transmit timed out'
> message, and it seems that the NIC has reported a transmit completion
> but this hasn't been handled. Perhaps another device sharing its IRQ is
> misbehaving and causing the IRQ to be disabled. Please can you send
> more of the kernel log from before the TX watchdog warning? Also, if
> this happens again, please send the contents of /proc/interrupts.
/proc/interrupts:
CPU0 CPU1
0: 42 0 IO-APIC-edge timer
1: 0 82 IO-APIC-edge i8042
8: 0 0 IO-APIC-edge rtc0
9: 0 0 IO-APIC-fasteoi acpi
14: 0 109 IO-APIC-edge ide0
17: 5 581 IO-APIC-fasteoi firewire_ohci
18: 350432 19112694 IO-APIC-fasteoi eth1
20: 6365 143067 IO-APIC-fasteoi sata_via
21: 0 0 IO-APIC-fasteoi uhci_hcd:usb1, ehci_hcd:usb2, uhci_hcd:usb3, uhci_hcd:usb4, uhci_hcd:usb5
23: 150373 6348653 IO-APIC-fasteoi eth2
NMI: 0 0 Non-maskable interrupts
LOC: 1346329 1327512 Local timer interrupts
SPU: 0 0 Spurious interrupts
RES: 835039 35715 Rescheduling interrupts
CAL: 89 110 Function call interrupts
TLB: 782 741 TLB shootdowns
TRM: 0 0 Thermal event interrupts
THR: 0 0 Threshold APIC interrupts
ERR: 2
MIS: 0
kern.log:
Oct 5 04:07:43 histor2 kernel: [ 1244.566658] martian source 87.193.192.142 from 117.192.224.4, on dev eth2
Oct 5 04:07:43 histor2 kernel: [ 1244.566731] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 04:07:44 histor2 kernel: [ 1245.341532] martian source 87.193.192.142 from 125.161.193.46, on dev eth2
Oct 5 04:07:44 histor2 kernel: [ 1245.341605] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 04:07:45 histor2 kernel: [ 1246.937539] martian source 87.193.192.142 from 130.15.19.206, on dev eth2
Oct 5 04:07:45 histor2 kernel: [ 1246.937609] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 04:08:04 histor2 kernel: [ 1265.481435] martian source 87.193.192.142 from 93.88.4.171, on dev eth2
Oct 5 04:08:04 histor2 kernel: [ 1265.481508] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 04:08:07 histor2 kernel: [ 1268.517808] martian source 87.193.192.142 from 93.88.4.171, on dev eth2
Oct 5 04:08:07 histor2 kernel: [ 1268.517882] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 04:08:09 histor2 kernel: [ 1270.940643] martian source 87.193.192.142 from 130.15.19.206, on dev eth2
Oct 5 04:08:09 histor2 kernel: [ 1270.940716] ll header: 00:30:1b:41:e1:89:00:14:a9:9e:b4:28:08:00
Oct 5 06:59:42 histor2 kernel: [11563.805018] ------------[ cut here ]------------
Oct 5 06:59:42 histor2 kernel: [11563.805058] WARNING: at /tmp/buildd/linux-2.6-2.6.30/debian/build/source_amd64_none/net/sched/sch_generic.c:226 dev_watchdog+0xc7/0x164()
Oct 5 06:59:42 histor2 kernel: [11563.805105] Hardware name: SK22V10
Oct 5 06:59:42 histor2 kernel: [11563.805125] NETDEV WATCHDOG: eth2 (via-rhine): transmit timed out
Oct 5 06:59:42 histor2 kernel: [11563.805148] Modules linked in: iptable_filter iptable_nat nf_nat nf_conntrack_ipv4 nf_conntrack nf_defrag_ipv4 ip_tables x_tables ppdev parport_pc lp
parport cpufreq_stats cpufreq_userspace cpufreq_conservative cpufreq_powersave nfsd exportfs nfs lockd fscache nfs_acl auth_rpcgss sunrpc powernow_k8 loop snd_pcm snd_timer snd
soundcore evdev snd_page_alloc k8temp i2c_viapro i2c_core pcspkr button processor shpchp pci_hotplug ext3 jbd mbcache sha256_generic aes_x86_64 aes_generic cbc dm_crypt
dm_mirror dm_region_hash dm_log dm_snapshot dm_mod raid10 raid456 raid6_pq async_xor async_memcpy async_tx xor raid1 raid0 multipath linear md_mod sd_mod crc_t10dif
ide_cd_mod cdrom ide_pci_generic sata_via via82cxxx ide_core ata_generic libata ehci_hcd scsi_mod via_rhine uhci_hcd 8139too firewire_ohci firewire_core crc_itu_t 8139cp mii thermal fan
thermal_sys [last unloaded: scsi_wait_scan]
Oct 5 06:59:42 histor2 kernel: [11563.809598] Pid: 0, comm: swapper Not tainted 2.6.30-bpo.1-amd64 #1
Oct 5 06:59:42 histor2 kernel: [11563.809623] Call Trace:
Oct 5 06:59:42 histor2 kernel: [11563.809642] <IRQ> [<ffffffff8042353e>] ? dev_watchdog+0xc7/0x164
Oct 5 06:59:42 histor2 kernel: [11563.809678] [<ffffffff8042353e>] ? dev_watchdog+0xc7/0x164
Oct 5 06:59:42 histor2 kernel: [11563.809708] [<ffffffff80242387>] ? warn_slowpath_common+0x77/0xa3
Oct 5 06:59:42 histor2 kernel: [11563.809736] [<ffffffff80423477>] ? dev_watchdog+0x0/0x164
Oct 5 06:59:42 histor2 kernel: [11563.809763] [<ffffffff8024240f>] ? warn_slowpath_fmt+0x51/0x59
Oct 5 06:59:42 histor2 kernel: [11563.809792] [<ffffffff802342fe>] ? enqueue_task+0x5c/0x65
Oct 5 06:59:42 histor2 kernel: [11563.809820] [<ffffffff8025474b>] ? autoremove_wake_function+0x9/0x2e
Oct 5 06:59:42 histor2 kernel: [11563.809848] [<ffffffff8042344b>] ? netif_tx_lock+0x3d/0x69
Oct 5 06:59:42 histor2 kernel: [11563.809877] [<ffffffff8040fef0>] ? netdev_drivername+0x3b/0x40
Oct 5 06:59:42 histor2 kernel: [11563.809904] [<ffffffff8042353e>] ? dev_watchdog+0xc7/0x164
Oct 5 06:59:42 histor2 kernel: [11563.809931] [<ffffffff80230065>] ? gup_huge_pmd+0x36/0x94
Oct 5 06:59:42 histor2 kernel: [11563.809957] [<ffffffff80423477>] ? dev_watchdog+0x0/0x164
Oct 5 06:59:42 histor2 kernel: [11563.809985] [<ffffffff8024aa6f>] ? run_timer_softirq+0x193/0x210
Oct 5 06:59:42 histor2 kernel: [11563.810015] [<ffffffff8025b4d1>] ? getnstimeofday+0x55/0xaf
Oct 5 06:59:42 histor2 kernel: [11563.810042] [<ffffffff80246f91>] ? __do_softirq+0xac/0x173
Oct 5 06:59:42 histor2 kernel: [11563.810070] [<ffffffff80210bcc>] ? call_softirq+0x1c/0x30
Oct 5 06:59:42 histor2 kernel: [11563.810097] [<ffffffff802125fa>] ? do_softirq+0x3a/0x7e
Oct 5 06:59:42 histor2 kernel: [11563.810123] [<ffffffff80246d0e>] ? irq_exit+0x3f/0x80
Oct 5 06:59:42 histor2 kernel: [11563.810150] [<ffffffff80220e63>] ? smp_apic_timer_interrupt+0x87/0x94
Oct 5 06:59:42 histor2 kernel: [11563.810178] [<ffffffff802105d3>] ? apic_timer_interrupt+0x13/0x20
Oct 5 06:59:42 histor2 kernel: [11563.810202] <EOI> [<ffffffff80256fa9>] ? hrtimer_cancel+0xc/0x16
Oct 5 06:59:42 histor2 kernel: [11563.810235] [<ffffffff80227520>] ? native_safe_halt+0x2/0x3
Oct 5 06:59:42 histor2 kernel: [11563.810263] [<ffffffff80216995>] ? default_idle+0x40/0x68
Oct 5 06:59:42 histor2 kernel: [11563.810290] [<ffffffff80257d0d>] ? notifier_call_chain+0x29/0x4c
Oct 5 06:59:42 histor2 kernel: [11563.810318] [<ffffffff80216d6a>] ? c1e_idle+0x107/0x10d
Oct 5 06:59:42 histor2 kernel: [11563.810346] [<ffffffff8020edda>] ? cpu_idle+0x50/0x91
Oct 5 06:59:42 histor2 kernel: [11563.810371] ---[ end trace d486a35a41d2f448 ]---
Oct 5 06:59:42 histor2 kernel: [11563.810538] eth2: Transmit timed out, status 1003, PHY status 786d, resetting...
Oct 5 06:59:42 histor2 kernel: [11563.811381] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Oct 5 06:59:46 histor2 kernel: [11567.804166] eth2: Transmit timed out, status 0003, PHY status 786d, resetting...
Oct 5 06:59:46 histor2 kernel: [11567.805004] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Oct 5 06:59:50 histor2 kernel: [11571.804168] eth2: Transmit timed out, status 0003, PHY status 786d, resetting...
Oct 5 06:59:50 histor2 kernel: [11571.805007] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Oct 5 06:59:54 histor2 kernel: [11575.804166] eth2: Transmit timed out, status 0003, PHY status 786d, resetting...
Oct 5 06:59:54 histor2 kernel: [11575.804997] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Oct 5 06:59:58 histor2 kernel: [11579.804166] eth2: Transmit timed out, status 0003, PHY status 786d, resetting...
Oct 5 06:59:58 histor2 kernel: [11579.805011] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Oct 5 07:00:02 histor2 kernel: [11583.804169] eth2: Transmit timed out, status 0003, PHY status 786d, resetting...
Oct 5 07:00:02 histor2 kernel: [11583.805009] eth2: link up, 100Mbps, full-duplex, lpa 0x45E1
Best regards,
Jens-Michael
Reply to: