sky2 panic in 2.6.32.1 under load
Berck E. Nash
(bittorrent usage).
[ 8673.345873] sky2 eth0: receiver hang detected
[ 8673.350368] sky2 eth0: disabling interface
[ 8673.354749] BUG: unable to handle kernel NULL pointer dereference at
0000000000000010
[ 8673.359748] IP: [<ffffffffa00373d3>] sky2_xmit_frame+0x321/0x5d8 [sky2]
[ 8673.364675] PGD a09a6067 PUD a09a5067 PMD 0
[ 8673.373838] Oops: 0002 [#1] SMP
[ 8673.373838] last sysfs file: /sys/devices/platform/coretemp.1/temp1_label
[ 8673.383900] CPU 0
[ 8673.383900] Modules linked in: nfsd exportfs nfs lockd nfs_acl
auth_rpcgss sunrpc nls_cp437 msdos fat kvm_intel kvm fuse snd_rtctimer
hwmon_vid nvidia(P) usbhid tuner_simple tuner_types wm8775 tda9887
snd_hda_codec_realtek tda8290 snd_hda_intel tuner snd_hda_codec
snd_pcm_oss snd_mixer_oss snd_pcm cx25840 snd_seq_dummy snd_seq_oss
snd_seq_midi_event ivtv snd_seq i2c_algo_bit cx2341x v4l2_common
snd_timer videodev uhci_hcd snd_seq_device v4l1_compat ehci_hcd snd
v4l2_compat_ioctl32 i2c_i801 soundcore snd_page_alloc floppy sky2
usbcore tveeprom
[ 8673.435268] Pid: 4, comm: ksoftirqd/0 Tainted: P 2.6.32.1
#3 P5W DH Deluxe
[ 8673.438943] RIP: 0010:[<ffffffffa00373d3>] [<ffffffffa00373d3>]
sky2_xmit_frame+0x321/0x5d8 [sky2]
[ 8673.448539] RSP: 0018:ffff880001603df8 EFLAGS: 00010246
[ 8673.458678] RAX: 0000000000000000 RBX: ffff8800bd201d40 RCX:
0000000000000000
[ 8673.465016] RDX: 0000000000000000 RSI: 000000000000008c RDI:
0000000000000000
[ 8673.472396] RBP: ffff880001603e48 R08: 0000000000000001 R09:
0000000000000000
[ 8673.474083] R10: 000000000000001e R11: 0000000000000ef8 R12:
ffff88009bf3ab48
[ 8673.484317] R13: ffff8800bef4d000 R14: 0000000000000000 R15:
00000000955fa87e
[ 8673.492381] FS: 0000000000000000(0000) GS:ffff880001600000(0000)
knlGS:0000000000000000
[ 8673.501448] CS: 0010 DS: 0018 ES: 0018 CR0: 000000008005003b
[ 8673.509707] CR2: 0000000000000010 CR3: 00000000a09bf000 CR4:
00000000000026f0
[ 8673.514146] DR0: 0000000000000000 DR1: 0000000000000000 DR2:
0000000000000000
[ 8673.520661] DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7:
0000000000000400
[ 8673.528842] Process ksoftirqd/0 (pid: 4, threadinfo ffff8800bf8b4000,
task ffff8800bf8a8650)
[ 8673.539212] Stack:
[ 8673.539212] ffff8800992f5980 ffff8800955fa87e ffff8800bd201800
000000428122a659
[ 8673.548658] <0> ffff880001603e48 ffff88009bf3ab48 ffff8800992f5980
ffffffff813eaf30
[ 8673.556929] <0> ffff8800bd201800 ffff8800bef03940 ffff880001603e98
ffffffff81231de8
[ 8673.565432] Call Trace:
[ 8673.565432] <IRQ>
[ 8673.565432] [<ffffffff81231de8>] dev_hard_start_xmit+0x21c/0x2b7
[ 8673.574516] [<ffffffff81041746>] ? run_timer_softirq+0x4f/0x1c9
[ 8673.579515] [<ffffffff81240252>] sch_direct_xmit+0x5e/0x154
[ 8673.584559] [<ffffffff81240404>] __qdisc_run+0xbc/0xd5
[ 8673.592673] [<ffffffff8122fb19>] net_tx_action+0xbb/0x10e
[ 8673.598719] [<ffffffff8103dc16>] __do_softirq+0x91/0x11b
[ 8673.601787] [<ffffffff8100be9c>] call_softirq+0x1c/0x28
[ 8673.609833] <EOI>
[ 8673.610994] [<ffffffff8100d907>] do_softirq+0x33/0x6b
[ 8673.614419] [<ffffffff8103d71e>] ksoftirqd+0x60/0xd7
[ 8673.620082] [<ffffffff8103d6be>] ? ksoftirqd+0x0/0xd7
[ 8673.620082] [<ffffffff8104aee7>] kthread+0x7a/0x82
[ 8673.629310] [<ffffffff8100bd9a>] child_rip+0xa/0x20
[ 8673.634137] [<ffffffff8104ae6d>] ? kthread+0x0/0x82
[ 8673.639492] [<ffffffff8100bd90>] ? child_rip+0x0/0x20
[ 8673.647639] Code: 06 00 00 00 00 89 08 66 c7 40 04 00 00 c6 40 06 01
c6 40 07 9f 41 0f b7 c6 48 89 c7 48 c1 e0 03 48 c1 e7 05 48 89 f9 48 03
4b 20 <4c> 89 79 10 48 c7 41 08 01 00 00 00 8b 75 cc 89 71 18 48 03 7b
[ 8673.667726] RIP [<ffffffffa00373d3>] sky2_xmit_frame+0x321/0x5d8 [sky2]
[ 8673.674902] RSP <ffff880001603df8>
[ 8673.674902] CR2: 0000000000000010
[ 8673.682956] hda-intel: IRQ timing workaround is activated for card
#0. Suggest a bigger bdl_pos_adj.
[ 8673.683015] ---[ end trace 2c387977cf1c7c9a ]---
[ 8673.683017] Kernel panic - not syncing: Fatal exception in interrupt
[ 8673.683020] Pid: 4, comm: ksoftirqd/0 Tainted: P D 2.6.32.1 #3
[ 8673.683021] Call Trace:
[ 8673.683023] <IRQ> [<ffffffff8129839d>] panic+0x75/0x11c
[ 8673.683030] [<ffffffff8100e9a7>] oops_end+0x81/0x8e
[ 8673.683033] [<ffffffff81026e5f>] no_context+0x1ee/0x1fd
[ 8673.683036] [<ffffffff81032a6d>] ? find_busiest_group+0x387/0x8d8
[ 8673.683039] [<ffffffff81026fe0>] __bad_area_nosemaphore+0x172/0x195
[ 8673.683041] [<ffffffff81027011>] bad_area_nosemaphore+0xe/0x10
[ 8673.683044] [<ffffffff8102724b>] do_page_fault+0x114/0x252
[ 8673.683047] [<ffffffff8129a97f>] page_fault+0x1f/0x30
[ 8673.683054] [<ffffffffa00373d3>] ? sky2_xmit_frame+0x321/0x5d8 [sky2]
[ 8673.683058] [<ffffffffa00371b8>] ? sky2_xmit_frame+0x106/0x5d8 [sky2]
[ 8673.683061] [<ffffffff81231de8>] dev_hard_start_xmit+0x21c/0x2b7
[ 8673.683065] [<ffffffff81041746>] ? run_timer_softirq+0x4f/0x1c9
[ 8673.683067] [<ffffffff81240252>] sch_direct_xmit+0x5e/0x154
[ 8673.683070] [<ffffffff81240404>] __qdisc_run+0xbc/0xd5
[ 8673.683072] [<ffffffff8122fb19>] net_tx_action+0xbb/0x10e
[ 8673.683075] [<ffffffff8103dc16>] __do_softirq+0x91/0x11b
[ 8673.683078] [<ffffffff8100be9c>] call_softirq+0x1c/0x28
[ 8673.683079] <EOI> [<ffffffff8100d907>] do_softirq+0x33/0x6b
[ 8673.683083] [<ffffffff8103d71e>] ksoftirqd+0x60/0xd7
[ 8673.683085] [<ffffffff8103d6be>] ? ksoftirqd+0x0/0xd7
[ 8673.683088] [<ffffffff8104aee7>] kthread+0x7a/0x82
[ 8673.683090] [<ffffffff8100bd9a>] child_rip+0xa/0x20
[ 8673.683093] [<ffffffff8104ae6d>] ? kthread+0x0/0x82
[ 8673.683095] [<ffffffff8100bd90>] ? child_rip+0x0/0x20
Note that sometimes I get the receiver hang and things continue without
the crash:
[ 1219.346571] sky2 eth0: receiver hang detected
[ 1219.351145] sky2 eth0: disabling interface
[ 1219.357389] sky2 eth0: enabling interface
[ 1222.572980] sky2 eth0: Link is up at 1000 Mbps, full duplex, flow
control both
Please CC as I'm not subscribed.
Thanks,
Berck Nash
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majo...@vger.kernel.org
More majordomo info at http://vger.kernel.org/majordomo-info.html
Please read the FAQ at http://www.tux.org/lkml/
Michael Breuer
before 2.6.33 rc1). I also had two similar events previously - one
2.6.31, and one 2.6.32 rc7.
I was doing some research today and came across a fair sampling of error
reports all suggesting that new firmware is a solution. Gigabyte (not my
MB) has firmware posted, but I haven't yet attempted to apply it (nor am
I sure how to test it after doing so).
For what it's worth, my three recent events were heavy smb usage -
windows system backing up. Today's event did not generate an oops as my
watchdog kicked in and rebooted the system after the kernel reported a
sky2 error.
The last messages before watchdog:
Dec 20 05:33:58 mail kernel: DRHD: handling fault status reg 2
Dec 20 05:33:58 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr ffe1a7ffe000
Dec 20 05:33:58 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Dec 20 05:33:58 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Dec 20 05:33:58 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
During the previous event I had vt-d disabled - it was enabled this time.
Daniel Hazelton
I can confirm a version of this happens - with a full Panic - as early as
2.6.25 (I have had the same machine collapse under a hack-attempt numerous
times because of this)
DRH
Michael Breuer
my kernel version unchanged for the next week or so and see if this recurs.
Michael Breuer
Nothing in dmesg.old - have oops in syslog. System became unresponsive
and watchdog kicked in after a minute.
Also note that I have a similar oops with VT-D disabled (posted here on
12/5). I'm attaching the oops from that below this oops for comparison.
That also happened under similar load.
On the assumption that I can recreate this (although it takes a while)
please let me know how I can help.
What's in my log (starting with an smbd error about 2 min before the
oops (note: the dchpd is not the system doing the backup).
Dec 23 17:31:05 mail smbd[20712]: [2009/12/23 17:31:05, 0]
smbd/nttrans.c:2076(call_nt_transact_ioctl)
Dec 23 17:31:05 mail smbd[20712]: call_nt_transact_ioctl(0x900eb):
Currently not implemented.
Dec 23 17:31:34 mail clamd[3449]: SelfCheck: Database status OK.
Dec 23 17:32:22 mail named[4284]: client 208.78.169.235#32797: view
External: query (cache) './NS/IN' denied
Dec 23 17:32:22 mail named[4284]: client 208.78.169.235#32797: view
External: query (cache) './NS/IN' denied
Dec 23 17:32:22 mail named[4284]: client 208.78.169.235#32797: view
External: query (cache) './NS/IN' denied
Dec 23 17:32:54 mail dhcpd: DHCPINFORM from 10.0.0.3 via eth0
Dec 23 17:32:54 mail dhcpd: DHCPACK to 10.0.0.3 (00:21:5d:cb:a1:74) via eth0
Dec 23 17:32:58 mail kernel: DRHD: handling fault status reg 2
Dec 23 17:32:58 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr fff8423fe000
Dec 23 17:32:58 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Dec 23 17:32:58 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Dec 23 17:32:58 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
Dec 23 17:33:06 mail kernel: ------------[ cut here ]------------
Dec 23 17:33:06 mail kernel: WARNING: at net/sched/sch_generic.c:255
dev_watchdog+0xf3/0x161()
Dec 23 17:33:06 mail kernel: Hardware name: System Product Name
Dec 23 17:33:06 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
queue 0 timed out
Dec 23 17:33:06 mail kernel: Modules linked in: ip6table_filter
ip6table_mangle ip6_tables iptable_raw iptable_mangle ipt_MASQUERADE
iptable_nat nf_nat bridge stp appletalk psnap llc nfsd lockd nfs_acl
auth_rpcgss exportfs sunrpc hwmon_vid coretemp acpi_cpufreq sit tunnel4
ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp xt_DSCP xt_dscp xt_MARK
nf_conntrack_ipv6 xt_multiport ipv6 dm_multipath kvm_intel kvm
snd_hda_codec_analog snd_ens1371 gameport snd_hda_intel snd_hda_codec
snd_rawmidi snd_ac97_codec ac97_bus snd_hwdep snd_seq snd_seq_device
snd_pcm snd_timer gspca_spca505 snd gspca_main soundcore snd_page_alloc
videodev firewire_ohci sky2 v4l1_compat v4l2_compat_ioctl32
firewire_core iTCO_wdt wmi asus_atk0110 iTCO_vendor_support i2c_i801
hwmon pcspkr crc_itu_t raid456 async_raid6_recov async_pq raid6_pq
async_xor xor async_memcpy async_tx raid1 ata_generic pata_acpi
pata_marvell nouveau ttm drm_kms_helper drm agpgart fb i2c_algo_bit
cfbcopyarea i2c_core cfbimgblt cfbfillrect [last unloaded: ip6_tables]
Dec 23 17:33:06 mail kernel: Pid: 0, comm: swapper Tainted: G W
2.6.32-09281-g1c42cda #6
Dec 23 17:33:06 mail kernel: Call Trace:
Dec 23 17:33:06 mail kernel: <IRQ> [<ffffffff8104afbd>]
warn_slowpath_common+0x7c/0x94
Dec 23 17:33:06 mail kernel: [<ffffffff8104b02c>]
warn_slowpath_fmt+0x41/0x43
Dec 23 17:33:06 mail kernel: [<ffffffff813d096f>] ? netif_tx_lock+0x44/0x6c
Dec 23 17:33:06 mail kernel: [<ffffffff813d0ad7>] dev_watchdog+0xf3/0x161
Dec 23 17:33:06 mail kernel: [<ffffffff8105610c>] ? cascade+0x6a/0x84
Dec 23 17:33:06 mail kernel: [<ffffffff81058558>]
run_timer_softirq+0x1c8/0x270
Dec 23 17:33:06 mail kernel: [<ffffffff81051595>] __do_softirq+0xf8/0x1cd
Dec 23 17:33:06 mail kernel: [<ffffffff810720af>] ?
tick_program_event+0x2a/0x2c
Dec 23 17:33:06 mail kernel: [<ffffffff8100ab1c>] call_softirq+0x1c/0x30
Dec 23 17:33:06 mail kernel: [<ffffffff8100c2b3>] do_softirq+0x4b/0xa3
Dec 23 17:33:06 mail kernel: [<ffffffff81051181>] irq_exit+0x4a/0x8c
Dec 23 17:33:06 mail kernel: [<ffffffff8145ed99>]
smp_apic_timer_interrupt+0x86/0x94
Dec 23 17:33:06 mail kernel: [<ffffffff8100a5d3>]
apic_timer_interrupt+0x13/0x20
Dec 23 17:33:06 mail kernel: <EOI> [<ffffffff812ae5fa>] ?
acpi_idle_enter_bm+0x256/0x28a
Dec 23 17:33:06 mail kernel: [<ffffffff812ae5f3>] ?
acpi_idle_enter_bm+0x24f/0x28a
Dec 23 17:33:06 mail kernel: [<ffffffff81393308>]
cpuidle_idle_call+0x9e/0xfa
Dec 23 17:33:06 mail kernel: [<ffffffff81008c05>] cpu_idle+0xb4/0xf6
Dec 23 17:33:06 mail kernel: [<ffffffff814532b2>]
start_secondary+0x201/0x242
Dec 23 17:33:06 mail kernel: ---[ end trace 57f7151f6a5def07 ]---
Dec 23 17:33:06 mail kernel: sky2 eth0: tx timeout
Dec 23 17:33:06 mail kernel: sky2 eth0: disabling interface
Dec 23 17:33:06 mail kernel: sky2 eth0: enabling interface
Dec 23 17:33:06 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Dec 23 17:33:11 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Dec 23 17:33:11 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Dec 23 17:33:26 mail kernel: sky2 eth0: tx timeout
Dec 23 17:33:26 mail kernel: sky2 eth0: disabling interface
Dec 23 17:33:26 mail kernel: sky2 eth0: enabling interface
Dec 23 17:33:26 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Dec 23 17:33:28 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:28 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:28 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:29 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:29 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:29 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Dec 23 17:33:29 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Dec 23 17:33:30 mail named[4284]: client 114.80.99.2#44695: view
External: query (cache) './NS/IN' denied
Dec 23 17:33:38 mail named[4284]: error (connection refused) resolving
'121.93.27.216.blackholes.mail-abuse.org/A/IN': 168.61.5.195#53
Dec 23 17:33:44 mail kernel: sky2 eth0: tx timeout
Dec 23 17:33:44 mail kernel: sky2 eth0: disabling interface
Dec 23 17:33:44 mail kernel: sky2 eth0: enabling interface
Dec 23 17:33:44 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Dec 23 17:33:49 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Dec 23 17:33:49 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Dec 23 17:33:52 mail dhcpd: DHCPINFORM from 10.0.0.11 via eth0
Dec 23 17:33:52 mail dhcpd: DHCPACK to 10.0.0.11 (00:1a:92:8d:30:81) via
eth0
Dec 23 17:34:01 mail smbd[24783]: [2009/12/23 17:34:01, 0]
lib/util_sock.c:539(read_fd_with_timeout)
Dec 23 17:34:01 mail smbd[24783]: [2009/12/23 17:34:01, 0]
lib/util_sock.c:1491(get_peer_addr_internal)
Dec 23 17:34:01 mail smbd[24783]: getpeername failed. Error was
Transport endpoint is not connected
Dec 23 17:34:01 mail smbd[24783]: read_fd_with_timeout: client 0.0.0.0
read error = Connection reset by peer.
Dec 23 17:34:04 mail abrt: Kerneloops: Reported 1 kernel oopses to Abrt
Dec 23 17:34:04 mail abrtd: Directory 'kerneloops-1261607644-1' creation
detected
Dec 23 17:34:04 mail abrtd: Getting local universal unique identification
Dec 23 17:34:04 mail abrtd: New crash, saving
Dec 23 17:34:04 mail abrtd: Activation of plugin 'RunApp' was not
successful: Plugin 'RunApp' is not registered
Dec 23 17:34:04 mail kernel: sky2 eth0: tx timeout
Dec 23 17:34:04 mail kernel: sky2 eth0: disabling interface
Dec 23 17:34:04 mail kernel: sky2 eth0: enabling interface
Dec 23 17:34:04 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Dec 23 17:34:09 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Dec 23 17:34:09 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Dec 23 17:34:11 mail logger: ping of potter failed
Dec 23 17:34:19 mail kernel: sky2 eth0: tx timeout
Dec 23 17:34:19 mail kernel: sky2 eth0: disabling interface
Dec 23 17:34:19 mail kernel: sky2 eth0: enabling interface
Dec 23 17:34:19 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Dec 23 17:34:22 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Dec 23 17:34:22 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Dec 23 17:37:40 mail kernel: imklog 4.4.2, log source = /proc/kmsg started.
Oops from 12/5 (no vt-d; no intel_iommu, firmware .12)
Dec 5 11:27:41 mail kernel: ------------[ cut here ]------------
Dec 5 11:27:41 mail kernel: WARNING: at lib/dma-debug.c:898
check_sync+0xbd/0x426()
Dec 5 11:27:41 mail kernel: Hardware name: System Product Name
Dec 5 11:27:41 mail kernel: sky2 0000:06:00.0: DMA-API: device driver
tries to sync DMA memory it has not allocated [device
address=0x000000031a57e022] [size=66 bytes]
Dec 5 11:27:41 mail kernel: Modules linked in: bridge stp appletalk
psnap llc nfsd lockd nfs_acl auth_rpcgss exportfs sunrpc hwmon_vid
coretemp acpi_cpufreq sit tunnel4 ipt_LOG ipt_MASQUERADE iptable_nat
nf_nat iptable_mangle iptable_raw nf_conntrack_netbios_ns
nf_conntrack_ftp nf_conntrack_ipv6 xt_multiport ip6table_filter xt_DSCP
xt_dscp xt_MARK ip6table_mangle ip6_tables ipv6 dm_multipath kvm_intel
kvm snd_hda_codec_analog snd_ens1371 gameport snd_rawmidi snd_ac97_codec
snd_hda_intel snd_hda_codec ac97_bus gspca_spca505 snd_hwdep snd_seq
snd_seq_device firewire_ohci gspca_main snd_pcm videodev firewire_core
sky2 snd_timer v4l1_compat wmi snd v4l2_compat_ioctl32 soundcore
crc_itu_t snd_page_alloc asus_atk0110 i2c_i801 iTCO_wdt
iTCO_vendor_support pcspkr hwmon raid456 async_raid6_recov async_pq
raid6_pq async_xor xor async_memcpy async_tx raid1 ata_generic pata_acpi
pata_marvell nouveau ttm drm_kms_helper drm agpgart fb i2c_algo_bit
cfbcopyarea i2c_core cfbimgblt cfbfillrect [last unloaded: scsi_wait_scan]
Dec 5 11:27:41 mail kernel: Pid: 0, comm: swapper Not tainted
2.6.32-00573-g6cf4d67 #2
Dec 5 11:27:41 mail kernel: Call Trace:
Dec 5 11:27:41 mail kernel: <IRQ> [<ffffffff8105365a>]
warn_slowpath_common+0x7c/0x94
Dec 5 11:27:41 mail kernel: [<ffffffff810536c9>]
warn_slowpath_fmt+0x41/0x43
Dec 5 11:27:41 mail kernel: [<ffffffff8127b1fd>] check_sync+0xbd/0x426
Dec 5 11:27:41 mail kernel: [<ffffffff813ca254>] ?
__netdev_alloc_skb+0x34/0x50
Dec 5 11:27:41 mail kernel: [<ffffffff8127b8b9>]
debug_dma_sync_single_for_cpu+0x42/0x44
Dec 5 11:27:41 mail kernel: [<ffffffff81278c5f>] ?
swiotlb_sync_single+0x2a/0xb6
Dec 5 11:27:41 mail kernel: [<ffffffff81278dbb>] ?
swiotlb_sync_single_for_cpu+0xc/0xe
Dec 5 11:27:41 mail kernel: [<ffffffffa01cee83>] sky2_poll+0x4c6/0xae1
[sky2]
Dec 5 11:27:41 mail kernel: [<ffffffff8146bb1a>] ?
_spin_unlock_irqrestore+0x29/0x41
Dec 5 11:27:41 mail kernel: [<ffffffff813d0ef2>] net_rx_action+0xb5/0x1f3
Dec 5 11:27:41 mail kernel: [<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
Dec 5 11:27:41 mail kernel: [<ffffffff810a2dea>] ?
handle_IRQ_event+0x119/0x12b
Dec 5 11:27:41 mail kernel: [<ffffffff81012e1c>] call_softirq+0x1c/0x30
Dec 5 11:27:41 mail kernel: [<ffffffff810143a3>] do_softirq+0x4b/0xa6
Dec 5 11:27:41 mail kernel: [<ffffffff8105aa1b>] irq_exit+0x4a/0x8c
Dec 5 11:27:41 mail kernel: [<ffffffff8146fb75>] do_IRQ+0xa5/0xbc
Dec 5 11:27:41 mail kernel: [<ffffffff81012613>] ret_from_intr+0x0/0x16
Dec 5 11:27:41 mail kernel: <EOI> [<ffffffff812c6b3e>] ?
acpi_idle_enter_bm+0x256/0x28a
Dec 5 11:27:41 mail kernel: [<ffffffff812c6b37>] ?
acpi_idle_enter_bm+0x24f/0x28a
Dec 5 11:27:41 mail kernel: [<ffffffff813a6280>] ?
cpuidle_idle_call+0x9e/0xfa
Dec 5 11:27:41 mail kernel: [<ffffffff81010c90>] ? cpu_idle+0xb4/0xf6
Dec 5 11:27:41 mail kernel: [<ffffffff814651f2>] ?
start_secondary+0x201/0x242
Dec 5 11:27:41 mail kernel: ---[ end trace ff8485ac82013a8d ]---
Andrew Morton
> Since 2.6.32, I've been getting kernel panics under heavy network load
> (bittorrent usage).
Let's cc the right list and developer.
This is a 2.6.31->2.6.32 regression?
> [ 8673.345873] sky2 eth0: receiver hang detected
> [ 8673.350368] sky2 eth0: disabling interface
> [ 8673.354749] BUG: unable to handle kernel NULL pointer dereference at
> 0000000000000010
Please fix the wordwrapping for next time.
--
Andrew Morton
On Wed, 23 Dec 2009 17:54:27 -0500 Michael Breuer <mbr...@majjas.com> wrote:
> Ok - not the firmware. Ran another Windows backup and sky2 went down.
>
> Nothing in dmesg.old - have oops in syslog. System became unresponsive
> and watchdog kicked in after a minute.
>
> Also note that I have a similar oops with VT-D disabled (posted here on
> 12/5). I'm attaching the oops from that below this oops for comparison.
> That also happened under similar load.
>
> On the assumption that I can recreate this (although it takes a while)
> please let me know how I can help.
>
> What's in my log (starting with an smbd error about 2 min before the
> oops (note: the dchpd is not the system doing the backup).
This (nastily wordwrapped) oops appers to be quite different from
Berck's one.
Berck Nash
> On Mon, 21 Dec 2009 16:52:10 -0700 "Berck E. Nash" <fly...@gmail.com> wrote:
>
>> Since 2.6.32, I've been getting kernel panics under heavy network load
>> (bittorrent usage).
>
> Let's cc the right list and developer.
>
> This is a 2.6.31->2.6.32 regression?
I believe so. Since it's intermittent and difficult to reproduce, it's
possible (but unlikely) that I simply never triggered it under 2.6.31.
>> [ 8673.345873] sky2 eth0: receiver hang detected
>> [ 8673.350368] sky2 eth0: disabling interface
>> [ 8673.354749] BUG: unable to handle kernel NULL pointer dereference at
>> 0000000000000010
>
> Please fix the wordwrapping for next time.
Sorry!
Michael Breuer
On 12/24/2009 1:58 AM, Andrew Morton wrote:
> On Mon, 21 Dec 2009 16:52:10 -0700 "Berck E. Nash"<fly...@gmail.com> wrote:
>
>
>> Since 2.6.32, I've been getting kernel panics under heavy network load
>> (bittorrent usage).
>>
> Let's cc the right list and developer.
>
> This is a 2.6.31->2.6.32 regression?
>
system. At the time, I was having issues with intel_iommu and thought
that the culprit.
The initial reply to this thread from Daniel Hazelton stated that this
has been happening since 2.6.25.
And apologies for the word wrap. I upgraded Thunderbird :(. Oddly, I
don't see the word wrap when reading my own message to the list. Must be
some new setting I missed.
Berck Nash
>>> Since 2.6.32, I've been getting kernel panics under heavy network load
>>> (bittorrent usage).
>>>
>> Let's cc the right list and developer.
>>
>> This is a 2.6.31->2.6.32 regression?
>>
> I don't think so. I saw this on 2.6.31 - first kernel I put on this
> system. At the time, I was having issues with intel_iommu and thought
> that the culprit.
> The initial reply to this thread from Daniel Hazelton stated that this
> has been happening since 2.6.25.
Your oops appears to be different than mine. Hazelton did not provide
any logs, and he said "a version of this" so I don't know if his is the
same or not.
Michael Breuer
> Michael Breuer wrote:
>
>>>> Since 2.6.32, I've been getting kernel panics under heavy network load
>>>> (bittorrent usage).
>>>>
>>>>
>>> Let's cc the right list and developer.
>>>
>>> This is a 2.6.31->2.6.32 regression?
>>>
>>>
>> I don't think so. I saw this on 2.6.31 - first kernel I put on this
>> system. At the time, I was having issues with intel_iommu and thought
>> that the culprit.
>> The initial reply to this thread from Daniel Hazelton stated that this
>> has been happening since 2.6.25.
>>
> Your oops appears to be different than mine. Hazelton did not provide
> any logs, and he said "a version of this" so I don't know if his is the
> same or not.
>
oops at all. All were produced under the same conditions, all pointing
at sky2. I'd guess at memory corruption under load with subsequent
divergent manifestations. The real question is whether the bug is in the
kernel or the NIC firmware. There were similar reports online of this
behavior affecting Vista, however those were resolved by moving to later
firmware. I've recreated the crash on the later firmware however.
Summary of conditions that appear to be required for the
lockup/oops/panic(s):
1. Running at 1Gb.
2. High traffic into the system (out seems ok).
3. For me, the crash only occurs when smbd is the application generating
the traffic.
Daniel Hazelton
> Andrew Morton wrote:
> > On Mon, 21 Dec 2009 16:52:10 -0700 "Berck E. Nash" <fly...@gmail.com>
wrote:
> >> Since 2.6.32, I've been getting kernel panics under heavy network load
> >> (bittorrent usage).
> >
> > Let's cc the right list and developer.
> >
> > This is a 2.6.31->2.6.32 regression?
>
> I believe so. Since it's intermittent and difficult to reproduce, it's
> possible (but unlikely) that I simply never triggered it under 2.6.31.
This is far from new. I have seen this under 2.6.27 when at least one botnet
has been pointed at a server of mine and told to gain access. It has happened
four times in the last six to eight months - and I have no easy way to capture
the logs. But the oops that was posted looks very, very similar to what I've
seen.
It's always an allocation error in the transmit path that leads to the panic.
Because this is a production machine that I do not have a way to take down and
do testing with I've not reported the problem before.
DRH
Michael Breuer
but I am wondering why __free_page(frag->page); is called in
skb_put_frags when the fragment length is zero. I don't see why that
page pointer wouldn't potentially be reused afterwords.
Stephen Hemminger
Daniel Hazelton <dhaz...@enter.net> wrote:
> On Thursday 24 December 2009 11:03:56 am Berck Nash wrote:
> > Andrew Morton wrote:
> > > On Mon, 21 Dec 2009 16:52:10 -0700 "Berck E. Nash" <fly...@gmail.com>
> wrote:
> > >> Since 2.6.32, I've been getting kernel panics under heavy network load
> > >> (bittorrent usage).
> > >
> > > Let's cc the right list and developer.
> > >
> > > This is a 2.6.31->2.6.32 regression?
> >
> > I believe so. Since it's intermittent and difficult to reproduce, it's
> > possible (but unlikely) that I simply never triggered it under 2.6.31.
>
> This is far from new. I have seen this under 2.6.27 when at least one botnet
> has been pointed at a server of mine and told to gain access. It has happened
> four times in the last six to eight months - and I have no easy way to capture
> the logs. But the oops that was posted looks very, very similar to what I've
> seen.
>
> It's always an allocation error in the transmit path that leads to the panic.
> Because this is a production machine that I do not have a way to take down and
> do testing with I've not reported the problem before.
>
Even though I wrote/maintain the sky driver, I don't work for SysKonnect, and
only have access to a limited set of information:
the technical manuals (under NDA), and the vendor sk98lin driver. The sky2 driver
imitates the receiver timeout of the sk98lin driver; other people have told me
that the FIFO hardware implementation is buggy and when it gets full, it gets
stuck. Probably the equivalent of a software FIFO where the developer forgets to
reserve a slot so that head == tail can mean both empty and full!
The workaround with a timer is prone to errors when traffic keeps going, also
the vendor doesn't really provide clear instructions on how to unlock it. I do
not have access to the hardware errata describing the problem. If I did a more
minimal solution would be possible.
The easiest advice is avoid sky2 chips with FIFO for any heavy traffic, the next
advice is make sure receive flow control is enabled so that receiver doesn't
get overrun. If tx timeouts are an issue use a rate limiter like TBF. Do not use
the chip with 10 or 100 mbit since the transmitter is more prone to get overrun.
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
> I'll be the first to admit I don't know much about network drivers...
> but I am wondering why __free_page(frag->page); is called in
> skb_put_frags when the fragment length is zero. I don't see why that
> page pointer wouldn't potentially be reused afterwords.
When using Jumbo frames, the sky2 driver allocates pages to hold
the larger part of the frame. With 9K MTU it will allocate 2 * 4K pages
and then 1K for start of frame. Then if frame is <= 1K it will drop
the extra pages. Not sure why this broke now, I am not a VM expert.
--
Michael Breuer
mbit. 100 appears stable.
Daniel Hazelton
Not here - it is crashing under 100. I do have a different NIC available for
that system and will likely switch to it when I have a chance to work on
upgrading the install there. The reason I am using the Sky NIC on that system
is because there are, apparently, two different NIC's on the board itself - an
nForce one and a Sky2 one...
DRH
Michael Breuer
While I thought it was coincidence, each and every time I hit this issue
there is a DHCP renew event immediately before the first error.
The crash occurs while under load - in my case seems that the traffic is
actually IPV6 (hadn't noticed that before).
I ran nethogs on a remote display - the reported rx rate on the IPV6 smb
connection at the time of the lockup was 33889.688 KB/sec on a 1gbit
nic. I've got two events like this - don't recall if the earlier one was
the exact same # - but it was in the ballpark.
On 12/24/2009 2:01 AM, Andrew Morton wrote:
Stephen Hemminger
Michael Breuer
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
It looks like the problem only shows up for packets generated by DHCP,
and these come through AF_PACKET. The problem maybe related to how this
packets are fragmented into header and page, in a different way than other
packets confusing the driver or DMA engine.
Does this help?
-----
--- a/drivers/net/sky2.c 2009-12-26 09:50:20.869565022 -0800
+++ b/drivers/net/sky2.c 2009-12-26 09:55:54.620645355 -0800
@@ -1616,6 +1616,13 @@ static netdev_tx_t sky2_xmit_frame(struc
if (unlikely(tx_avail(sky2) < tx_le_req(skb)))
return NETDEV_TX_BUSY;
+ if (!pskb_may_pull(skb, ETH_HLEN)) {
+ if (net_ratelimit())
+ pr_info(PFX "%s: packet missing ether header (%d)?",
+ dev->name, skb->len);
+ goto drop;
+ }
+
len = skb_headlen(skb);
mapping = pci_map_single(hw->pdev, skb->data, len, PCI_DMA_TODEVICE);
@@ -1761,6 +1768,7 @@ mapping_unwind:
mapping_error:
if (net_ratelimit())
dev_warn(&hw->pdev->dev, "%s: tx mapping error\n", dev->name);
+drop:
dev_kfree_skb(skb);
return NETDEV_TX_OK;
}
--
Michael Breuer
Still one odd message sequence, but no hangs or crashes.
The first time I forced a DHCP renew while running at high throughput, I
got the same SMB errors I saw in my original error log (pre-crash). This
only happened once:
Dec 26 15:24:18 mail dhcpd: DHCPACK on 10.0.0.56 to 00:1c:cc:f3:9f:f6
(BLACKBERRY-9542) via eth0
Dec 26 15:24:25 mail smbd[8937]: [2009/12/26 15:24:25, 0]
lib/util_sock.c:1564(matchname)
Dec 26 15:24:25 mail smbd[8937]: matchname: host name/address
mismatch: ::ffff:10.0.0.11 != potter.majjas.com
Dec 26 15:24:25 mail smbd[8937]: [2009/12/26 15:24:25, 0]
lib/util_sock.c:1685(get_peer_name)
Dec 26 15:24:25 mail smbd[8937]: Matchname failed on potter.majjas.com
::ffff:10.0.0.11
Dec 26 15:24:25 mail smbd[8937]: [2009/12/26 15:24:25, 0]
smbd/nttrans.c:2076(call_nt_transact_ioctl)
Dec 26 15:24:25 mail smbd[8937]: call_nt_transact_ioctl(0x900eb):
Currently not implemented.
I would discount this, but the same sequence was present in the logs
pre-crash as well. I do not see this at all absent the preceding DHCP
renew sequence. I also don't see this unless the adapter is under load.
Stephen Hemminger
to receive a transmit packet with the Ethernet header off in the
skb fragments. The hardware doesn't handle 0 size DMA's well,
so it gets confused.
Other drivers may have same problem, I really think this ought
to be done at higher level.
Signed-off-by: Stephen Hemminger <shemm...@vyatta.com>
---
Patch against net-2.6, but same patch applies to -stable as well
(with fuzz).
--- a/drivers/net/sky2.c 2009-12-26 13:39:34.289252942 -0800
+++ b/drivers/net/sky2.c 2009-12-26 13:59:44.548877690 -0800
@@ -1654,6 +1654,14 @@ static netdev_tx_t sky2_xmit_frame(struc
if (unlikely(tx_avail(sky2) < tx_le_req(skb)))
return NETDEV_TX_BUSY;
+ /* Make sure there is at least some data for first DMA */
+ if (!pskb_may_pull(skb, ETH_HLEN)) {
+ if (net_ratelimit())
+ pr_info(PFX "%s: packet missing ether header (%d)?",
+ dev->name, skb->len);
+ goto drop;
+ }
+
len = skb_headlen(skb);
mapping = pci_map_single(hw->pdev, skb->data, len, PCI_DMA_TODEVICE);
@@ -1799,6 +1807,7 @@ mapping_unwind:
mapping_error:
if (net_ratelimit())
dev_warn(&hw->pdev->dev, "%s: tx mapping error\n", dev->name);
+drop:
dev_kfree_skb(skb);
return NETDEV_TX_OK;
}
David Miller
Date: Sat, 26 Dec 2009 14:05:44 -0800
> Other drivers may have same problem, I really think this ought
> to be done at higher level.
I tend to agree with you, and I thought we had handled all
cases. Let's simply make AF_PACKET linearize the link
level header before sending things out to the transmit path.
I can work on this if you want.
David Miller
Date: Sat, 26 Dec 2009 19:44:18 -0800 (PST)
> From: Stephen Hemminger <shemm...@linux-foundation.org>
> Date: Sat, 26 Dec 2009 14:05:44 -0800
>
>> Other drivers may have same problem, I really think this ought
>> to be done at higher level.
>
> I tend to agree with you, and I thought we had handled all
> cases. Let's simply make AF_PACKET linearize the link
> level header before sending things out to the transmit path.
>
> I can work on this if you want.
Actually Stephen, I took a look and I can't see how AF_PACKET
can create this situation.
It always copies into the linear area of the SKB it allocates
for sendmsg() processing. Whether the data comes from sendmsg
data or the mmap() ring buffer.
Michael Breuer
AM... ans one from last night:
Dec 26 21:39:54 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:39 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:39 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:39 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:39 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:41 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 27 05:09:41 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:41 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:41 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:42 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 27 05:09:44 mail kernel: __ratelimit: 7 callbacks suppressed
... repeats for a couple of minutes. Never saw this before, but then
again, the system didn't stay up before.
I've also got this in dmesg (command, not /var/log/dmesg):
sky2 eth0: rx error, status 0x10660010 length 1518
sky2 eth0: rx error, status 0x10c60010 length 1518
sky2 eth0: rx error, status 0x14860010 length 1518
sky2 eth0: rx error, status 0x19e60010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x10660010 length 1518
sky2 eth0: rx error, status 0x10a60010 length 1518
sky2 eth0: rx error, status 0x10a60010 length 1518
sky2 eth0: rx error, status 0x11060010 length 1518
sky2 eth0: rx error, status 0x11060010 length 1518
DMA-API: debugging out of memory - disabling
... then later ...
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
sky2 eth0: rx error, status 0x23360010 length 1518
DRHD: handling fault status reg 2
DMAR:[DMA Write] Request device [06:00.0] fault addr fff82da28000
DMAR:[fault reason 05] PTE Write access is not set
DRHD: handling fault status reg 102
DMAR:[DMA Write] Request device [06:00.0] fault addr fff82da03000
DMAR:[fault reason 05] PTE Write access is not set
DRHD: handling fault status reg 202
DMAR:[DMA Write] Request device [06:00.0] fault addr fff82d9ec000
DMAR:[fault reason 05] PTE Write access is not set
DRHD: handling fault status reg 302
DMAR:[DMA Write] Request device [06:00.0] fault addr fff82d9a0000
DMAR:[fault reason 05] PTE Write access is not set
DRHD: handling fault status reg 402
DMAR:[DMA Write] Request device [06:00.0] fault addr fff82d968000
DMAR:[fault reason 05] PTE Write access is not set
------------[ cut here ]------------
WARNING: at net/sched/sch_generic.c:261 dev_watchdog+0xf3/0x164()
Hardware name: System Product Name
NETDEV WATCHDOG: eth0 (sky2): transmit queue 0 timed out
Modules linked in: ip6table_mangle ip6table_filter ip6_tables
iptable_raw iptable_mangle ipt_MASQUERADE iptable_nat nf_nat bridge stp
appletalk psnap llc fbcon tileblit font bitblit softcursor nfsd lockd
nfs_acl auth_rpcgss exportfs sunrpc hwmon_vid coretemp acpi_cpufreq sit
tunnel4 ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp
nf_conntrack_ipv6 xt_multiport xt_DSCP xt_dscp xt_MARK ipv6 dm_multipath
kvm_intel kvm snd_hda_codec_analog snd_ens1371 gameport snd_rawmidi
gspca_spca505 snd_hda_intel snd_ac97_codec gspca_main snd_hda_codec
videodev v4l1_compat snd_hwdep ac97_bus snd_seq v4l2_compat_ioctl32
snd_seq_device snd_pcm firewire_ohci pcspkr firewire_core snd_timer snd
soundcore snd_page_alloc wmi sky2 asus_atk0110 i2c_i801 crc_itu_t hwmon
iTCO_wdt iTCO_vendor_support raid456 async_raid6_recov async_pq raid6_pq
async_xor xor async_memcpy async_tx raid1 ata_generic pata_acpi
pata_marvell nouveau ttm drm_kms_helper drm agpgart fb i2c_algo_bit
cfbcopyarea i2c_core cfbimgblt cfbfillrect [last unloaded: ip6_tables]
Pid: 25, comm: ksoftirqd/7 Tainted: G W
2.6.32-00830-gca45ac4-dirty #3
Call Trace:
<IRQ> [<ffffffff8105365a>] warn_slowpath_common+0x7c/0x94
[<ffffffff810536c9>] warn_slowpath_fmt+0x41/0x43
[<ffffffff813e2dd7>] ? netif_tx_lock+0x44/0x6c
[<ffffffff813e2f3f>] dev_watchdog+0xf3/0x164
[<ffffffff8146b76a>] ? _spin_unlock_irqrestore+0x29/0x41
[<ffffffff8103c62e>] ? check_preempt_curr_idle+0x15/0x17
[<ffffffff8104357d>] ? task_rq_unlock+0x11/0x13
[<ffffffff8104e050>] ? try_to_wake_up+0x2a2/0x2b4
[<ffffffff8106316b>] run_timer_softirq+0x1c8/0x270
[<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
[<ffffffff81012e1c>] call_softirq+0x1c/0x30
<EOI> [<ffffffff810143a3>] do_softirq+0x4b/0xa6
[<ffffffff8105a730>] ksoftirqd+0x65/0xdc
[<ffffffff8105a6cb>] ? ksoftirqd+0x0/0xdc
[<ffffffff8107275c>] kthread+0x7f/0x87
[<ffffffff81012d1a>] child_rip+0xa/0x20
[<ffffffff8101267d>] ? restore_args+0x0/0x30
[<ffffffff810726dd>] ? kthread+0x0/0x87
[<ffffffff81012d10>] ? child_rip+0x0/0x20
---[ end trace 57f7151f6a5def07 ]---
sky2 eth0: tx timeout
sky2 eth0: transmit ring 27 .. 114 report=27 done=27
sky2 eth0: disabling interface
sky2 eth0: enabling interface
sky2 eth0: Link is up at 1000 Mbps, full duplex, flow control both
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
iint_free: readcount: 1
iint_free: opencount: 1
iint_free: readcount: 1
iint_free: opencount: 1
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
sky2 0000:06:00.0: error interrupt status=0x8
... this repeats for a while
I'm guessing that the dmesg and kernel messages correspond. System
stayed up and everything seems ok now. There were connections open at
the time of these events and they appear to have remained up.
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
> Just an FYI - I left stuff running overnight and saw lots of this this
> AM... ans one from last night:
> Dec 26 21:39:54 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 27 05:09:39 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
You have hardware/firmware problem, that is beyond the driver.
That status indicates:
Parity Error/MAC - "This interrupt is intended to indicate a panic event (hardware fault)"
What is your hardware configuration (lspci, kernel config, memory, cpu)?
Stephen Hemminger
upper address, or because of lack of wires from chip to memory controller;
there have been problems on motherboards where I/O devices couldn't access
all of memory.
Try this, it forces each transmit to have full 64 bit address. It drops an
optimization that was done to reduce the number of transmit descriptors
used.
--- a/drivers/net/sky2.c 2009-12-29 09:23:37.114074275 -0800
+++ b/drivers/net/sky2.c 2009-12-29 09:26:38.699912035 -0800
@@ -1038,10 +1038,11 @@ static void tx_init(struct sky2_port *sk
sky2->tx_tcpsum = 0;
sky2->tx_last_mss = 0;
- le = get_tx_le(sky2, &sky2->tx_prod);
- le->addr = 0;
- le->opcode = OP_ADDR64 | HW_OWNER;
- sky2->tx_last_upper = 0;
+ if (sizeof(dma_addr_t) == sizeof(u32)) {
+ le = get_tx_le(sky2, &sky2->tx_prod);
+ le->addr = 0;
+ le->opcode = OP_ADDR64 | HW_OWNER;
+ }
}
/* Update chip's next pointer */
@@ -1669,10 +1670,9 @@ static netdev_tx_t sky2_xmit_frame(struc
/* Send high bits if needed */
upper = upper_32_bits(mapping);
- if (upper != sky2->tx_last_upper) {
+ if (sizeof(mapping) > sizeof(u32)) {
le = get_tx_le(sky2, &slot);
le->addr = cpu_to_le32(upper);
- sky2->tx_last_upper = upper;
le->opcode = OP_ADDR64 | HW_OWNER;
}
@@ -1762,10 +1762,9 @@ static netdev_tx_t sky2_xmit_frame(struc
goto mapping_unwind;
upper = upper_32_bits(mapping);
- if (upper != sky2->tx_last_upper) {
+ if (sizeof(mapping) > sizeof(u32)) {
le = get_tx_le(sky2, &slot);
le->addr = cpu_to_le32(upper);
- sky2->tx_last_upper = upper;
le->opcode = OP_ADDR64 | HW_OWNER;
}
--- a/drivers/net/sky2.h 2009-12-29 09:23:37.164072886 -0800
+++ b/drivers/net/sky2.h 2009-12-29 09:25:15.302197993 -0800
@@ -2191,7 +2191,6 @@ struct sky2_port {
u16 tx_pending;
u16 tx_last_mss;
- u32 tx_last_upper;
u32 tx_tcpsum;
struct rx_ring_info *rx_ring ____cacheline_aligned_in_smp;
Michael Breuer
On 12/29/2009 12:30 PM, Stephen Hemminger wrote:
> There could be DMA problems, either because chip isn't remembering
> upper address, or because of lack of wires from chip to memory controller;
> there have been problems on motherboards where I/O devices couldn't access
> all of memory.
>
> Try this, it forces each transmit to have full 64 bit address. It drops an
> optimization that was done to reduce the number of transmit descriptors
> used.
>
> --- a/drivers/net/sky2.c 2009-12-29 09:23:37.114074275 -0800
> +++ b/drivers/net/sky2.c 2009-12-29 09:26:38.699912035 -0800
> @@ -1038,10 +1038,11 @@ static void tx_init(struct sky2_port *sk
> sky2->tx_tcpsum = 0;
> sky2->tx_last_mss = 0;
>
> - le->addr = 0;
> - le->opcode = OP_ADDR64 | HW_OWNER;
> - sky2->tx_last_upper = 0;
> + if (sizeof(dma_addr_t) == sizeof(u32)) {
Michael Breuer
number of DHCPINFORM/DHCPACK to/from the system from which I'm
generating load.
It appears that it's now taking a higher throughput to cause the
interrupt status errors than without this patch, but they're still
occurring. Just for fun, I'll try without this patch and with VT-D
disabled later today.
On 12/29/2009 12:30 PM, Stephen Hemminger wrote:
> There could be DMA problems, either because chip isn't remembering
> upper address, or because of lack of wires from chip to memory controller;
> there have been problems on motherboards where I/O devices couldn't access
> all of memory.
>
> Try this, it forces each transmit to have full 64 bit address. It drops an
> optimization that was done to reduce the number of transmit descriptors
> used.
>
> --- a/drivers/net/sky2.c 2009-12-29 09:23:37.114074275 -0800
> +++ b/drivers/net/sky2.c 2009-12-29 09:26:38.699912035 -0800
> @@ -1038,10 +1038,11 @@ static void tx_init(struct sky2_port *sk
> sky2->tx_tcpsum = 0;
> sky2->tx_last_mss = 0;
>
> - le = get_tx_le(sky2,&sky2->tx_prod);
> - le->addr = 0;
> - le->opcode = OP_ADDR64 | HW_OWNER;
> - sky2->tx_last_upper = 0;
> + if (sizeof(dma_addr_t) == sizeof(u32)) {
> + le = get_tx_le(sky2,&sky2->tx_prod);
Michael Breuer
interface is under load AND there is ipv6 dns activity. As this only
happens when under load I can't prove it, but it seems there is a
correlation.
> There could be DMA problems, either because chip isn't remembering
> upper address, or because of lack of wires from chip to memory controller;
> there have been problems on motherboards where I/O devices couldn't access
> all of memory.
>
> Try this, it forces each transmit to have full 64 bit address. It drops an
> optimization that was done to reduce the number of transmit descriptors
> used.
>
> --- a/drivers/net/sky2.c 2009-12-29 09:23:37.114074275 -0800
> +++ b/drivers/net/sky2.c 2009-12-29 09:26:38.699912035 -0800
> @@ -1038,10 +1038,11 @@ static void tx_init(struct sky2_port *sk
> sky2->tx_tcpsum = 0;
> sky2->tx_last_mss = 0;
>
> - le->addr = 0;
> - le->opcode = OP_ADDR64 | HW_OWNER;
> - sky2->tx_last_upper = 0;
> + if (sizeof(dma_addr_t) == sizeof(u32)) {
Jarek Poplawski
> More data points - I'm able to reliably recreate this now.
> While I thought it was coincidence, each and every time I hit this issue
> there is a DHCP renew event immediately before the first error.
Maybe it's totally unconnected and some different NetworkManager, but FYI,
there was reported a strange interaction of KNetworkManager vs 2.6.32:
http://bugzilla.kernel.org/show_bug.cgi?id=14794
Jarek P.
> The crash occurs while under load - in my case seems that the traffic is
> actually IPV6 (hadn't noticed that before).
> I ran nethogs on a remote display - the reported rx rate on the IPV6 smb
> connection at the time of the lockup was 33889.688 KB/sec on a 1gbit
> nic. I've got two events like this - don't recall if the earlier one was
> the exact same # - but it was in the ballpark.
>
...
--
Michael Breuer
> Michael Breuer wrote, On 12/25/2009 05:28 PM:
>
>
>> More data points - I'm able to reliably recreate this now.
>> While I thought it was coincidence, each and every time I hit this issue
>> there is a DHCP renew event immediately before the first error.
>>
>
> Maybe it's totally unconnected and some different NetworkManager, but FYI,
> there was reported a strange interaction of KNetworkManager vs 2.6.32:
> http://bugzilla.kernel.org/show_bug.cgi?id=14794
>
> Jarek P.
>
is not under the control of NetworkManager; I'm not using KDE, and the
connection isn't dropping - just getting DHCPINFORM from the attached
client that is generating load.
Stephen Hemminger
--- a/drivers/net/sky2.c 2009-12-29 11:30:06.441137685 -0800
+++ b/drivers/net/sky2.c 2009-12-29 11:46:37.389262922 -0800
@@ -2629,12 +2625,71 @@ static void sky2_hw_error(struct sky2_hw
}
}
+static void dump_txring(struct sky2_hw *hw, unsigned port)
+{
+ struct sky2_port *sky2 = netdev_priv(hw->dev[port]);
+ int sop = 1;
+ unsigned idx;
+
+ printk(KERN_INFO PFX "Tx ring pending=%u...%u report=%d done=%d\n",
+ sky2->tx_cons, sky2->tx_prod,
+ sky2_read16(hw, port == 0 ? STAT_TXA1_RIDX : STAT_TXA2_RIDX),
+ sky2_read16(hw, Q_ADDR(txqaddr[port], Q_DONE)));
+
+ /* Dump contents of tx ring */
+ for (idx = sky2->tx_next;
+ idx != sky2->tx_prod && idx < sky2->tx_ring_size;
+ idx = RING_NEXT(idx, sky2->tx_ring_size)) {
+ const struct sky2_tx_le *le = sky2->tx_le + idx;
+ u32 a = le32_to_cpu(le->addr);
+
+ if (sop)
+ printk(KERN_DEBUG "%u:", idx);
+ sop = 0;
+
+ switch(le->opcode & ~HW_OWNER) {
+ case OP_ADDR64:
+ printk(" %#x:", a);
+ break;
+ case OP_LRGLEN:
+ printk(" mtu=%d", a);
+ break;
+ case OP_VLAN:
+ printk(" vlan=%d", be16_to_cpu(le->length));
+ break;
+ case OP_TCPLISW:
+ printk(" csum=%#x", a);
+ break;
+ case OP_LARGESEND:
+ printk(" tso=%#x(%d)", a, le16_to_cpu(le->length));
+ break;
+ case OP_PACKET:
+ printk(" %#x(%d)", a, le16_to_cpu(le->length));
+ break;
+ case OP_BUFFER:
+ printk(" frag=%#x(%d)", a, le16_to_cpu(le->length));
+ break;
+ default:
+ printk(" op=%#x,%#x(%d)", le->opcode, a,
+ le16_to_cpu(le->length));
+ }
+
+ if (le->ctrl & EOP) {
+ printk("\n");
+ sop = 1;
+ }
+ }
+}
+
static void sky2_hw_intr(struct sky2_hw *hw)
{
struct pci_dev *pdev = hw->pdev;
u32 status = sky2_read32(hw, B0_HWE_ISRC);
u32 hwmsk = sky2_read32(hw, B0_HWE_IMSK);
+ printk(KERN_DEBUG PFX "hardware interrupt status %#x\n", status);
+ dump_txring(hw, 0);
+
status &= hwmsk;
if (status & Y2_IS_TIST_OV)
--
Michael Breuer
sky2 0000:06:00.0: error interrupt status=0x40000008
sky2 0000:06:00.0: error interrupt status=0x8
Also, fwiw, when running with vt-d disabled, I don't get the
dhcpinform/ack messages, but continue to get the interrupt status
messages. That said, I am not certain the the dhcpinform/ack is related
at to the sky2 issue.
On 12/29/2009 2:49 PM, Stephen Hemminger wrote:
> This patch will dump more info in case of hardware error.
>
> --- a/drivers/net/sky2.c 2009-12-29 11:30:06.441137685 -0800
> +++ b/drivers/net/sky2.c 2009-12-29 11:46:37.389262922 -0800
> @@ -2629,12 +2625,71 @@ static void sky2_hw_error(struct sky2_hw
> }
> }
>
> +static void dump_txring(struct sky2_hw *hw, unsigned port)
> +{
> + struct sky2_port *sky2 = netdev_priv(hw->dev[port]);
> + int sop = 1;
> + unsigned idx;
> +
> + printk(KERN_INFO PFX "Tx ring pending=%u...%u report=%d done=%d\n",
> + sky2->tx_cons, sky2->tx_prod,
> + sky2_read16(hw, port == 0 ? STAT_TXA1_RIDX : STAT_TXA2_RIDX),
> + sky2_read16(hw, Q_ADDR(txqaddr[port], Q_DONE)));
> +
> + /* Dump contents of tx ring */
> + for (idx = sky2->tx_next;
> + idx != sky2->tx_prod&& idx< sky2->tx_ring_size;
> + idx = RING_NEXT(idx, sky2->tx_ring_size)) {
> + const struct sky2_tx_le *le = sky2->tx_le + idx;
> + u32 a = le32_to_cpu(le->addr);
> +
> + if (sop)
> + printk(KERN_DEBUG "%u:", idx);
> + sop = 0;
> +
> + switch(le->opcode& ~HW_OWNER) {
> + if (le->ctrl& EOP) {
> + printk("\n");
> + sop = 1;
> + }
> + }
> +}
> +
> static void sky2_hw_intr(struct sky2_hw *hw)
> {
> struct pci_dev *pdev = hw->pdev;
> u32 status = sky2_read32(hw, B0_HWE_ISRC);
> u32 hwmsk = sky2_read32(hw, B0_HWE_IMSK);
>
> + printk(KERN_DEBUG PFX "hardware interrupt status %#x\n", status);
> + dump_txring(hw, 0);
> +
> status&= hwmsk;
>
> if (status& Y2_IS_TIST_OV)
>
>
--
Michael Breuer
--- a/drivers/net/sky2.c
+++ b/drivers/net/sky2.c
@@ -2725,8 +2791,10 @@ static void sky2_watchdog(unsigned long arg)
/* Hardware/software error handling */
static void sky2_err_intr(struct sky2_hw *hw, u32 status)
{
- if (net_ratelimit())
+ if (net_ratelimit()) {
dev_warn(&hw->pdev->dev, "error interrupt
status=%#x\n", status);
+ dump_txring(hw, 0);
+ }
if (status & Y2_IS_HW_ERR)
sky2_hw_intr(hw);
And got this:
Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
On 12/29/2009 02:49 PM, Stephen Hemminger wrote:
> This patch will dump more info in case of hardware error.
>
> --- a/drivers/net/sky2.c 2009-12-29 11:30:06.441137685 -0800
> +++ b/drivers/net/sky2.c 2009-12-29 11:46:37.389262922 -0800
> @@ -2629,12 +2625,71 @@ static void sky2_hw_error(struct sky2_hw
> }
> }
>
> +static void dump_txring(struct sky2_hw *hw, unsigned port)
> +{
> + struct sky2_port *sky2 = netdev_priv(hw->dev[port]);
> + int sop = 1;
> + unsigned idx;
> +
> + printk(KERN_INFO PFX "Tx ring pending=%u...%u report=%d done=%d\n",
> + sky2->tx_cons, sky2->tx_prod,
> + sky2_read16(hw, port == 0 ? STAT_TXA1_RIDX : STAT_TXA2_RIDX),
> + sky2_read16(hw, Q_ADDR(txqaddr[port], Q_DONE)));
> +
> + /* Dump contents of tx ring */
> + for (idx = sky2->tx_next;
> + idx != sky2->tx_prod&& idx< sky2->tx_ring_size;
> + idx = RING_NEXT(idx, sky2->tx_ring_size)) {
> + const struct sky2_tx_le *le = sky2->tx_le + idx;
> + u32 a = le32_to_cpu(le->addr);
> +
> + if (sop)
> + printk(KERN_DEBUG "%u:", idx);
> + sop = 0;
> +
> + switch(le->opcode& ~HW_OWNER) {
> + if (le->ctrl& EOP) {
> + printk("\n");
> + sop = 1;
> + }
> + }
> +}
> +
> static void sky2_hw_intr(struct sky2_hw *hw)
> {
> struct pci_dev *pdev = hw->pdev;
> u32 status = sky2_read32(hw, B0_HWE_ISRC);
> u32 hwmsk = sky2_read32(hw, B0_HWE_IMSK);
>
> + printk(KERN_DEBUG PFX "hardware interrupt status %#x\n", status);
> + dump_txring(hw, 0);
> +
> status&= hwmsk;
>
> if (status& Y2_IS_TIST_OV)
>
>
--
Stephen Hemminger
I notice that you have NOUVEAU Nvidia drivers loaded? The one difference in HW
between your board and mine is that I have ATI video card.
--
Stephen Hemminger
Andrew Morton <ak...@linux-foundation.org> wrote:
> > Dec 23 17:32:58 mail kernel: DRHD: handling fault status reg 2
> > Dec 23 17:32:58 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
> > fault addr fff8423fe000
> > Dec 23 17:32:58 mail kernel: DMAR:[fault reason 06] PTE Read access is
> > not set
> > Dec 23 17:32:58 mail kernel: sky2 0000:06:00.0: error interrupt
> > status=0x80000000
> > Dec 23 17:32:58 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
> > Dec 23 17:33:06 mail kernel: ------------[ cut here ]------------
> > Dec 23 17:33:06 mail kernel: WARNING: at net/sched/sch_generic.c:255
> > dev_watchdog+0xf3/0x161()
> > Dec 23 17:33:06 mail kernel: Hardware name: System Product Name
> > Dec 23 17:33:06 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
Just to reiterate, these are consistent with a DMA error on transmit.
Since is 4 seconds after the DHCPACK, they probably are not related, except
that when DHCP renew may have caused more traffic.
Are you using something like network console or kgdb, or anything that could
be using some unusual network I/O?
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
> And got this:
> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
The interesting bits are only output at DEBUG level. So either change kernel
log level or syslog.
--
Michael Breuer
issue) when I've seen the errors. As noted previously, there is a
correlation with dhcp, and maybe one with dns over ipv6.
Console is local (nouveau kms).
As per Stephen's other email, I'm rerunning with kernel debug enabled.
I'll also try nomodeset and could if need by (but a real PITA) can swap
video cards with an ATI card.
ipv6
appletalk
dhcpd
smb
dns (bind9)
X11 (accessing box via cygwin)
sendmail
imap
mediatomb
Michael Breuer
Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=31...40 report=35 done=35
Dec 30 10:37:14 mail kernel: 30: 0x0: 0xeb50c0ca(9014)
Dec 30 10:37:14 mail kernel: 32: 0x0: 0xeb5080ca(9014)
Dec 30 10:37:14 mail kernel: 34: 0x0: 0xeb5040ca(9014)
Dec 30 10:37:14 mail kernel: 36: 0x0: 0xeb5000ca(9014)
Dec 30 10:37:14 mail kernel: 38: 0x0: 0xeb4fc0ca(9014)
Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=87...92 report=89 done=91
Dec 30 10:37:14 mail kernel: 86: 0x0: 0xeafd80ca(9014)
Dec 30 10:37:14 mail kernel: 88: 0x0: 0xeafd40ca(9014)
Dec 30 10:37:14 mail kernel: 90: 0x0: 0xeafd00ca(9014)
Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=39...42 report=39 done=41
Dec 30 10:37:15 mail kernel: 38: 0x0: 0xe5fec0ca(9014)
Dec 30 10:37:15 mail kernel: 40: 0x0: 0xe5fe80ca(9014)
Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=117...124 report=119
done=119
Dec 30 10:37:15 mail kernel: 116: 0x0: 0xe5d6c0ca(9014)
Dec 30 10:37:15 mail kernel: 118: 0x0: 0xe5d680ca(9014)
Dec 30 10:37:15 mail kernel: 120: 0x0: 0xe5d660ca(5938)
Dec 30 10:37:15 mail kernel: 122: 0x0: 0xe5d640ca(4213)
continues on like this - but this is the start.
On 12/30/2009 02:59 AM, Stephen Hemminger wrote:
> On Wed, 30 Dec 2009 02:23:20 -0500
> Michael Breuer<mbr...@majjas.com> wrote:
>
>
>> And got this:
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
>>
> The interesting bits are only output at DEBUG level. So either change kernel
> log level or syslog.
>
>
--
Michael Breuer
> On Wed, 30 Dec 2009 02:23:20 -0500
> Michael Breuer<mbr...@majjas.com> wrote:
>
>
>> Ok - I called dump_txring from sky2_net_intr:
>> --- a/drivers/net/sky2.c
>> +++ b/drivers/net/sky2.c
>> @@ -2725,8 +2791,10 @@ static void sky2_watchdog(unsigned long arg)
>> /* Hardware/software error handling */
>> static void sky2_err_intr(struct sky2_hw *hw, u32 status)
>> {
>> - if (net_ratelimit())
>> + if (net_ratelimit()) {
>> dev_warn(&hw->pdev->dev, "error interrupt
>> status=%#x\n", status);
>> + dump_txring(hw, 0);
>> + }
>>
>> sky2_hw_intr(hw);
>>
>> And got this:
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=28...30 report=29 done=29
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
>> Dec 30 02:17:23 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
>> Dec 30 02:17:23 mail kernel: sky2 Tx ring pending=30...32 report=30 done=31
>>
>>
> I notice that you have NOUVEAU Nvidia drivers loaded? The one difference in HW
> between your board and mine is that I have ATI video card.
>
>
Today, I ran a bunch of scenarios. I first determined that the problem
only manifest in runlevel 5. Next, this occurred with or without KMS and
with or without nouveau. This happened whether or not I was logged in
(local or remote), and regardless of window manager (xdm, gdm, kdm). I
then checked to see what else was different between runlevel 3 and 5 -
only thing was auditd. I disabled auditd and reran - no errors.
Now for the odd stuff:
The errors only manifest if the high throughput data transfer is
initiated when the system is in runlevel 5 and auditd was started by
init when transitioning from runlevel 3 to 5. For example, the following
scenarios do not cause the errors to manifest:
runlevel3; start auditd runlevel 5; start transfer
runlevel3; chkconfig auditd off; runlevel5; start auditd; start transfer
runlevel3; start transfer (note: errors do not occur if I transition to
runlevel 5 after the high bandwidth transfer has started)
runlevel3; startx; start transfer
The only way I get the problem to manifest is transition to runlevel 5
with chkconfig auditd on (level 5 only) and then initate the windows
backup.
I'm guessing that there is some sort of race condition happening between
X (xdm/gdm/kdm/greeter?) and auditd that is somehow corrupting
something. I'd hazard a more or less obvious guess that whatever's being
corrupted differs when there is already a high throughput transfer under
way.
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
> Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=31...40 report=35 done=35
> Dec 30 10:37:14 mail kernel: 30: 0x0: 0xeb50c0ca(9014)
> Dec 30 10:37:14 mail kernel: 32: 0x0: 0xeb5080ca(9014)
> Dec 30 10:37:14 mail kernel: 34: 0x0: 0xeb5040ca(9014)
> Dec 30 10:37:14 mail kernel: 36: 0x0: 0xeb5000ca(9014)
> Dec 30 10:37:14 mail kernel: 38: 0x0: 0xeb4fc0ca(9014)
You must be using 9K MTU. Do you see the problem with smaller
MTU?
> Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=87...92 report=89 done=91
> Dec 30 10:37:14 mail kernel: 86: 0x0: 0xeafd80ca(9014)
> Dec 30 10:37:14 mail kernel: 88: 0x0: 0xeafd40ca(9014)
> Dec 30 10:37:14 mail kernel: 90: 0x0: 0xeafd00ca(9014)
> Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
> Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=39...42 report=39 done=41
> Dec 30 10:37:15 mail kernel: 38: 0x0: 0xe5fec0ca(9014)
> Dec 30 10:37:15 mail kernel: 40: 0x0: 0xe5fe80ca(9014)
> Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=117...124 report=119
> done=119
> Dec 30 10:37:15 mail kernel: 116: 0x0: 0xe5d6c0ca(9014)
> Dec 30 10:37:15 mail kernel: 118: 0x0: 0xe5d680ca(9014)
> Dec 30 10:37:15 mail kernel: 120: 0x0: 0xe5d660ca(5938)
> Dec 30 10:37:15 mail kernel: 122: 0x0: 0xe5d640ca(4213)
--
Michael Breuer
> On Wed, 30 Dec 2009 10:40:56 -0500
> Michael Breuer<mbr...@majjas.com> wrote:
>
>
>> Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=31...40 report=35 done=35
>> Dec 30 10:37:14 mail kernel: 30: 0x0: 0xeb50c0ca(9014)
>> Dec 30 10:37:14 mail kernel: 32: 0x0: 0xeb5080ca(9014)
>> Dec 30 10:37:14 mail kernel: 34: 0x0: 0xeb5040ca(9014)
>> Dec 30 10:37:14 mail kernel: 36: 0x0: 0xeb5000ca(9014)
>> Dec 30 10:37:14 mail kernel: 38: 0x0: 0xeb4fc0ca(9014)
>>
> You must be using 9K MTU. Do you see the problem with smaller
> MTU?
>
again & debug if it would be helpful.
>
>> Dec 30 10:37:14 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 10:37:14 mail kernel: sky2 Tx ring pending=87...92 report=89 done=91
>> Dec 30 10:37:14 mail kernel: 86: 0x0: 0xeafd80ca(9014)
>> Dec 30 10:37:14 mail kernel: 88: 0x0: 0xeafd40ca(9014)
>> Dec 30 10:37:14 mail kernel: 90: 0x0: 0xeafd00ca(9014)
>> Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
>> Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=39...42 report=39 done=41
>> Dec 30 10:37:15 mail kernel: 38: 0x0: 0xe5fec0ca(9014)
>> Dec 30 10:37:15 mail kernel: 40: 0x0: 0xe5fe80ca(9014)
>> Dec 30 10:37:15 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Dec 30 10:37:15 mail kernel: sky2 Tx ring pending=117...124 report=119
>> done=119
>> Dec 30 10:37:15 mail kernel: 116: 0x0: 0xe5d6c0ca(9014)
>> Dec 30 10:37:15 mail kernel: 118: 0x0: 0xe5d680ca(9014)
>> Dec 30 10:37:15 mail kernel: 120: 0x0: 0xe5d660ca(5938)
>> Dec 30 10:37:15 mail kernel: 122: 0x0: 0xe5d640ca(4213)
>>
>
--
Michael Breuer
condition when auditd is started at roughly the same time as X. I'm
guessing that the kaudit thread is fired up; the tty connected; and at
the same time X grabs the tty. Somewhere in there an skb gets hosed and
is then reused by whatever comes along - in my case sky2 as that's where
the subsequent demand is. If the demand happens first, the contaminated
skb (dk in what way yet) is probably waiting to manifest as some other
bug that's been frustrating people.
Michael Breuer
1) enabling auditd for runlevel 3 mitigates the issue
2) starting a remote x session (XDMCP) while under load and while auditd
is already running also triggers the sky2 interrupt status messages - so
maybe not tty1 - but some sort of X & auditd interaction. Even in this
case, the frequency of the error messages is much less than when auditd
is started in runlevel 5 for the first time.
Michael Breuer
> A couple more observations:
>
> 1) enabling auditd for runlevel 3 mitigates the issue
> 2) starting a remote x session (XDMCP) while under load and while
> auditd is already running also triggers the sky2 interrupt status
> messages - so maybe not tty1 - but some sort of X & auditd
> interaction. Even in this case, the frequency of the error messages is
> much less than when auditd is started in runlevel 5 for the first time.
manifest.
Michael Breuer
> On 12/30/2009 3:44 PM, Michael Breuer wrote:
>> A couple more observations:
>>
>> 1) enabling auditd for runlevel 3 mitigates the issue
>> 2) starting a remote x session (XDMCP) while under load and while
>> auditd is already running also triggers the sky2 interrupt status
>> messages - so maybe not tty1 - but some sort of X & auditd
>> interaction. Even in this case, the frequency of the error messages
>> is much less than when auditd is started in runlevel 5 for the first
>> time.
> And just for some certainty - running with audit=0, the errors do not
> manifest.
Dec 30 16:16:42 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:16:42 mail kernel: sky2 Tx ring pending=72...74 report=73 done=73
Dec 30 16:16:42 mail kernel: 72: 0x0: 0xb18a00be(8490)
Dec 30 16:16:42 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:16:42 mail kernel: sky2 Tx ring pending=86...88 report=87 done=88
Dec 30 16:16:42 mail kernel: 86: 0x0: 0xb1a140be(9014)
Dec 30 16:16:58 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:16:58 mail kernel: sky2 Tx ring pending=50...52 report=51 done=52
Dec 30 16:16:58 mail kernel: 50: 0x0: 0xac27c0be(8490)
Dec 30 16:17:15 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 16:17:15 mail kernel: sky2 Tx ring pending=16...18 report=16 done=17
Dec 30 16:17:15 mail kernel: 16: 0x0: 0xa67ec0be(8490)
Dec 30 16:17:15 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:17:15 mail kernel: sky2 Tx ring pending=122...124 report=123
done=124
Dec 30 16:17:15 mail kernel: 122: 0x0: 0xa68980be(8490)
Dec 30 16:17:16 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:17:16 mail kernel: sky2 Tx ring pending=66...68 report=67 done=67
Dec 30 16:17:16 mail kernel: 66: 0x0: 0xa67200be(8490)
Dec 30 16:17:16 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:17:16 mail kernel: sky2 Tx ring pending=74...76 report=75 done=76
Dec 30 16:17:16 mail kernel: 74: 0x0: 0xa659c0be(8490)
Dec 30 16:17:21 mail dhcpd: DHCPINFORM from 10.0.0.11 via eth0
Dec 30 16:17:21 mail dhcpd: DHCPACK to 10.0.0.11 (00:1a:92:8d:30:81) via
eth0
Dec 30 16:18:01 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:01 mail kernel: sky2 Tx ring pending=0...2 report=1 done=1
Dec 30 16:18:01 mail kernel: 0: 0x0: 0x926580be(8490)
Dec 30 16:18:04 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:04 mail kernel: sky2 Tx ring pending=116...118 report=117
done=117
Dec 30 16:18:04 mail kernel: 116: 0x0: 0x91f380be(8490)
Dec 30 16:18:04 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 16:18:04 mail kernel: sky2 Tx ring pending=102...104 report=102
done=103
Dec 30 16:18:04 mail kernel: 102: 0x0: 0x91ed80be(8490)
Dec 30 16:18:05 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:05 mail kernel: sky2 Tx ring pending=64...68 report=65 done=68
Dec 30 16:18:05 mail kernel: 64: 0x0: 0x91d340be(8490)
Dec 30 16:18:05 mail kernel: 66: 0x0: 0x920040ca(105)
Dec 30 16:18:06 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:06 mail kernel: sky2 Tx ring pending=82...86 report=83 done=83
Dec 30 16:18:06 mail kernel: 82: 0x0: 0x91bf80be(9014)
Dec 30 16:18:06 mail kernel: 84: 0x0: 0x91bec0be(7518)
Dec 30 16:18:06 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:06 mail kernel: sky2 Tx ring pending=83...86 report=85 done=86
Dec 30 16:18:06 mail kernel: 82: 0x0: 0x91bf80be(9014)
Dec 30 16:18:06 mail kernel: 84: 0x0: 0x91bec0be(7518)
Dec 30 16:18:06 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Dec 30 16:18:06 mail kernel: sky2 Tx ring pending=85...88 report=87 done=87
Dec 30 16:18:06 mail kernel: 84: 0x0: 0x91bec0be(7518)
Dec 30 16:18:06 mail kernel: 86: 0x0: 0x91b080be(8398)
Dec 30 16:18:08 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Dec 30 16:18:08 mail kernel: sky2 Tx ring pending=28...30 report=28 done=29
Dec 30 16:18:08 mail kernel: 28: 0x0: 0x919500be(8506)
... continues ...
Michael Breuer
going on with X and tty...
Among other things, when I telinit 3 && telinit 5 the tty keeps
switching between 7 and 8 (nothing else running on either tty). It would
appear that somehow the tty deallocation isn't complete when X restarts.
Also, X grabbing a tty seems to be a requisite step in recreating the
sky2 issue.
On 12/30/2009 1:10 PM, Stephen Hemminger wrote:
--
Stephen Hemminger
the tables, probably not related but see:
http://bugzilla.kernel.org/show_bug.cgi?id=14954
--
Michael Breuer
maybe console) driver. I had disabled mingetty on tty1 as a workaround
to a Fedora/KDE issue. When I reenabled it, I was then able to recreate
this problem (sky2) in runlevel 3.
Retesting, it seems that the following conditions must be met in order
for the interrupt errors to happen:
1) mingetty running on tty1 before the start of the test run
2) High sustained incoming load - 25MB/sec or more (as reported by nethogs)
3) I've only been able to recreate this using samba & a Windows 7 backup
- but there could be other triggers
As it happens, much of my other data all came down to mingetty starting
or not starting on tty1 at specific points of test preparation. At this
point I can recreate 100% of the time if I ensure that there is a
mingetty running on tty1, regardless of runlevel; and I can not recreate
100% of the time when there is no mingetty running on tty1 at the start
of the test. The results do not change if I start or stop mingetty on
tty1 during the test. It's possible that X running on tty1 may also
trigger the issue, but I haven't tested that. Note that running mingetty
on the other tty's does not affect the outcome of the test. The test is
also unaffected if I chvt to or away from tty1 before the test. I do not
have to be logged in at the console (on any vt) to trigger the issue.
In a nutshell, to recreate: make sure there is a mingetty running on
tty1, blast traffic into the system on eth0 (sky2).
On 12/31/2009 1:09 PM, Michael Breuer wrote:
Michael Breuer
On boot - lots of stuff opening and closing tty1. Once up and stable
(runlevel 3), I did initctl stop tty1, and then initctl start tty1. This
is what was logged:
Jan 1 14:03:21 mail root: close mingetty1
Jan 1 14:03:21 mail kernel: tty_release_dev of tty1 (tty count=6)...
Jan 1 14:03:21 mail kernel: tty_release_dev of tty1 (tty count=5)...
Jan 1 14:03:21 mail kernel: tty1 vhangup...
Jan 1 14:03:21 mail init: tty1 main process (6031) killed by TERM signal
Jan 1 14:03:36 mail root: start mingetty1
Jan 1 14:03:36 mail kernel: error attempted to write to tty [0x(null)]
= NULL
Jan 1 14:03:36 mail kernel: opening tty1...
Jan 1 14:03:36 mail kernel: tty1 vhangup...
Jan 1 14:03:36 mail kernel: tty_release_dev of tty1 (tty count=5)...
Start/stop of mingetty on other ttys does not get the NULL write error.
I am always getting the NULL error when starting mingetty on tty1.
For example:
Jan 1 14:04:11 mail root: restart mingetty2
Jan 1 14:04:11 mail init: tty2 main process (6029) killed by TERM signal
Jan 1 14:04:11 mail kernel: tty_release_dev of tty7 (tty count=2)...
Jan 1 14:04:11 mail kernel: tty_release_dev of tty2 (tty count=1)...
Jan 1 14:04:11 mail kernel: freeing tty structure...
Jan 1 14:04:11 mail kernel: opening tty2...
Jan 1 14:04:11 mail kernel: tty2 vhangup...
Jan 1 14:04:11 mail kernel: tty_release_dev of tty2 (tty count=1)...
Jan 1 14:04:11 mail kernel: freeing tty structure...
While starting/stopping tty2 and X was coming up, I also got this:
Jan 1 14:04:11 mail root: restart mingetty2
Jan 1 14:04:11 mail init: tty2 main process (6029) killed by TERM signal
Jan 1 14:04:11 mail kernel: tty_release_dev of tty7 (tty count=2)...
Jan 1 14:04:11 mail kernel: tty_release_dev of tty2 (tty count=1)...
Jan 1 14:04:11 mail kernel: freeing tty structure...
Jan 1 14:04:11 mail kernel: opening tty2...
Jan 1 14:04:11 mail kernel: tty2 vhangup...
Jan 1 14:04:11 mail kernel: tty_release_dev of tty2 (tty count=1)...
Jan 1 14:04:11 mail kernel: freeing tty structure...
Jan 1 14:04:17 mail gnome-session[6832]: WARNING: Could not parse
desktop file
/home/mbreuer/.config/autostart/xfce4-tips-autostart.desktop: Key file
does not have key 'Name'
Jan 1 14:04:17 mail gnome-session[6832]: WARNING: could not read
/home/mbreuer/.config/autostart/xfce4-tips-autostart.desktop
Jan 1 14:04:19 mail pulseaudio[7002]: pid.c: Stale PID file, overwriting.
Jan 1 14:04:20 mail kernel: opening tty2...
Jan 1 14:04:20 mail kernel: opening pts2...
Jan 1 14:04:20 mail kernel: opening pts2...
Jan 1 14:04:20 mail kernel: tty_release_dev of pts2 (tty count=3)...
Jan 1 14:04:20 mail kernel: opening pts2...
Jan 1 14:04:20 mail kernel: tty_release_dev of pts2 (tty count=3)...
Jan 1 14:04:20 mail kernel: opening pts3...
Jan 1 14:04:20 mail kernel: opening pts3...
Jan 1 14:04:20 mail kernel: tty_release_dev of pts3 (tty count=3)...
Jan 1 14:04:20 mail kernel: opening pts3...
Jan 1 14:04:20 mail kernel: tty_release_dev of pts3 (tty count=3)...
Jan 1 14:04:20 mail kernel: opening pts4...
Jan 1 14:04:20 mail kernel: opening pts4...
Jan 1 14:04:20 mail kernel: tty_release_dev of pts4 (tty count=3)...
Jan 1 14:04:20 mail kernel: opening pts4...
Jan 1 14:04:21 mail kernel: tty_release_dev of pts4 (tty count=3)...
Jan 1 14:04:21 mail kernel: DMA-API: debugging out of memory - disabling
Jan 1 14:04:23 mail pulseaudio[7417]: pid.c: Daemon already running.
Jan 1 14:04:24 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Jan 1 14:04:24 mail kernel: sky2 Tx ring pending=45...52 report=45 done=47
Jan 1 14:04:24 mail kernel: 44: 0x0: 0xf26a40be(9014)
Jan 1 14:04:24 mail kernel: 46: 0x0: 0xf26a00be(9014)
Jan 1 14:04:24 mail kernel: 48: 0x0: 0xf269c0be(9014)
Jan 1 14:04:24 mail kernel: 50: 0x0: 0xf26980be(9014)
Jan 1 14:04:24 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Jan 1 14:04:24 mail kernel: sky2 Tx ring pending=47...52 report=47 done=49
Jan 1 14:04:24 mail kernel: 46: 0x0: 0xf26a00be(9014)
Jan 1 14:04:24 mail kernel: 48: 0x0: 0xf269c0be(9014)
Jan 1 14:04:24 mail kernel: 50: 0x0: 0xf26980be(9014)
Note the sky2 errors (this time not under load).
It looks like there is something bad going on with the tty driver.
Michael Breuer
Looks like the first attempt to run mingetty on tty1 triggers a vhangup
of more than tty1. Also, the initial console (shell, etc) were open on
tty1 when I started mingetty on tty1. Looks like the subsequent vhangup
is what broke things. Also, the vhangup issued from mingetty seems to
have resulted in tty2 activity as well, although I don't see why it
should have.
Scenario:
Started in single user mode.
did initctl start tty2 and then switched to tty2 and logged in:
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty2 vhangup...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=1)...
Jan 1 15:11:42 mail kernel: freeing tty structure...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty2 vhangup...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=2)...
Then (and note that time should have advanced, but didn't): initctl
start tty1 (previously, the initial shell from single user mode was up):
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty1 vhangup...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=2)...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=3)...
Jan 1 15:11:42 mail kernel: tty1 vhangup...
Jan 1 15:11:42 mail kernel: error attempted to write to tty [0x(null)]
= NULL
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=3)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=4)...
While I was doing this, I was watching dmesg, not /var/log/message.
Didn't notice time was stuck...
Then, I did telinit 5:
Jan 1 15:11:42 mail kernel: sky2 eth1: enabling interface
Jan 1 15:11:42 mail kernel: ADDRCONF(NETDEV_UP): eth1: link is not ready
Jan 1 15:11:42 mail kernel: sky2 eth1: Link is up at 100 Mbps, full
duplex, flow control rx
Jan 1 15:11:42 mail kernel: ADDRCONF(NETDEV_CHANGE): eth1: link becomes
ready
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=4)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: IPv6 over IPv4 tunneling driver
Jan 1 15:11:42 mail kernel: sit0: Disabled Privacy Extensions
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: SELinux: initialized (dev cgroup, type
cgroup), uses genfs_contexts
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: audit rule for LSM 'dhclient_t' is invalid
Jan 1 15:11:42 mail kernel: audit rule for LSM 'mcstransd_t' is invalid
Jan 1 15:11:42 mail kernel: audit rule for LSM 'samba_t' is invalid
Jan 1 15:11:42 mail kernel: audit rule for LSM 'dhclient_t' is invalid
Jan 1 15:11:42 mail kernel: audit rule for LSM 'mcstransd_t' is invalid
Jan 1 15:11:42 mail kernel: audit rule for LSM 'samba_t' is invalid
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty2...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty2 (tty count=4)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail cpuspeed: Enabling ondemand cpu frequency scaling
governor
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:42 mail kdump: kexec: loaded kdump kernel
Jan 1 15:11:42 mail kdump: started up
Jan 1 15:11:42 mail kernel: tty_release_dev of tty1 (tty count=2)...
Jan 1 15:11:42 mail kernel: opening tty1...
Jan 1 15:11:43 mail kernel: tty_release_dev of tty1 (tty count=2)...
This is when time increments again ... time jumped ahead and was OK by
the time ntp started. Looks like system time was OK, but syslog was
backlogged.
Michael Breuer
direction....
Put extra debugging printk's into tty_io.c and learned that when init
starts the mingetty's, tty_release_dev is called for ptm0, and the tty
structure is freed (according to the debug log message) - but up to this
point, it had never been allocated. It looks like this is happening as
the result of vhangup for pts0 being invoked while in the middle of
closing (tty_release_dev) several tty1's. I'm guessing that's where
something is being stepped on, but haven't tracked it down quite yet.
Regardless, it's after this that I can generate sky2 network errors, and
not before. This does not seem to happen if I remove /etc/events.d/tty1
before boot.
David Miller
Date: Sat, 26 Dec 2009 20:11:07 -0800 (PST)
> From: David Miller <da...@davemloft.net>
> Date: Sat, 26 Dec 2009 19:44:18 -0800 (PST)
>
>> From: Stephen Hemminger <shemm...@linux-foundation.org>
>> Date: Sat, 26 Dec 2009 14:05:44 -0800
>>
>>> Other drivers may have same problem, I really think this ought
>>> to be done at higher level.
>>
>> I tend to agree with you, and I thought we had handled all
>> cases. Let's simply make AF_PACKET linearize the link
>> level header before sending things out to the transmit path.
>>
>> I can work on this if you want.
>
> Actually Stephen, I took a look and I can't see how AF_PACKET
> can create this situation.
>
> It always copies into the linear area of the SKB it allocates
> for sendmsg() processing. Whether the data comes from sendmsg
> data or the mmap() ring buffer.
Stephen can you get a backtrace of the code path which triggers
this? I want to fix it at a higher level too, but I can't
do that until I know where it actually happens.
Thanks!
Stephen Hemminger
David Miller <da...@davemloft.net> wrote:
> From: David Miller <da...@davemloft.net>
> Date: Sat, 26 Dec 2009 20:11:07 -0800 (PST)
>
> > From: David Miller <da...@davemloft.net>
> > Date: Sat, 26 Dec 2009 19:44:18 -0800 (PST)
> >
> >> From: Stephen Hemminger <shemm...@linux-foundation.org>
> >> Date: Sat, 26 Dec 2009 14:05:44 -0800
> >>
> >>> Other drivers may have same problem, I really think this ought
> >>> to be done at higher level.
> >>
> >> I tend to agree with you, and I thought we had handled all
> >> cases. Let's simply make AF_PACKET linearize the link
> >> level header before sending things out to the transmit path.
> >>
> >> I can work on this if you want.
> >
> > Actually Stephen, I took a look and I can't see how AF_PACKET
> > can create this situation.
> >
> > It always copies into the linear area of the SKB it allocates
> > for sendmsg() processing. Whether the data comes from sendmsg
> > data or the mmap() ring buffer.
>
> Stephen can you get a backtrace of the code path which triggers
> this? I want to fix it at a higher level too, but I can't
> do that until I know where it actually happens.
Ignore it, the problem is outside the sky2 driver in some other
place causing corrupt skb's. I never reproduced this (with added BUG_ON
and WARN_ON), only seen by Michael.
Michael Breuer
http://lkml.org/lkml/2009/12/5/60
http://lkml.org/lkml/2009/12/21/268
http://lkml.org/lkml/2009/12/23/316
In a nutshell, my system was hanging (sometimes with a viewable oops,
sometimes not (unrelated KMS issues). The hangs (with watchdog reboot)
happened when under load and when any attached device sent in a DHCP
request/offer.
The hang was 100% reproducible when running Microsoft Backup vrom a win7
box via SAMBA onto the affected server. Stephen's patch stopped the hang
and oops.
Please let me know what I can do to help.
Under the same load conditions (but no longer associated with DHCP) I'm
now seeing multiple soft interrupt errors coming from sky2. This seems
to be a race condition somewhere as it only occurs when a mingetty is
run on tty1 prior to generating load on the sky2 driver. It could be a
wild goose chase, but I think something is getting corrupted by either
devpts or console when mingetty issues a vhangup on pts0.
Jarek Poplawski
> From: David Miller <da...@davemloft.net>
> Date: Sat, 26 Dec 2009 19:44:18 -0800 (PST)
>
>> From: Stephen Hemminger <shemm...@linux-foundation.org>
>> Date: Sat, 26 Dec 2009 14:05:44 -0800
>>
>>> Other drivers may have same problem, I really think this ought
>>> to be done at higher level.
>> I tend to agree with you, and I thought we had handled all
>> cases. Let's simply make AF_PACKET linearize the link
>> level header before sending things out to the transmit path.
>>
>> I can work on this if you want.
>
> Actually Stephen, I took a look and I can't see how AF_PACKET
> can create this situation.
>
> It always copies into the linear area of the SKB it allocates
> for sendmsg() processing. Whether the data comes from sendmsg
> data or the mmap() ring buffer.
Actually, I think there is a bug in this place, but of course this
might be unconnected. Anyway, Michael, could you try this patch?
BTW, did you try with CONFIG_PACKET_MMAP disabled?
Thanks,
Jarek P.
----------------->
Changing an skb after dev_queue_xmit() is illegal. And since it's
inconsistent to treat specially net_xmit_errno() non-zero return,
while ignoring other dev_queue_xmit() errors, there is no reason
to break the loop in tpacket_snd() in this case.
With debugging by: Stephen Hemminger <shemm...@linux-foundation.org>
Reported-by: Michael Breuer <mbr...@majjas.com>
Signed-off-by: Jarek Poplawski <jar...@gmail.com>
---
net/packet/af_packet.c | 8 +++-----
1 files changed, 3 insertions(+), 5 deletions(-)
diff --git a/net/packet/af_packet.c b/net/packet/af_packet.c
index e0516a2..984a1fa 100644
--- a/net/packet/af_packet.c
+++ b/net/packet/af_packet.c
@@ -1021,8 +1021,9 @@ static int tpacket_snd(struct packet_sock *po, struct msghdr *msg)
status = TP_STATUS_SEND_REQUEST;
err = dev_queue_xmit(skb);
- if (unlikely(err > 0 && (err = net_xmit_errno(err)) != 0))
- goto out_xmit;
+ if (unlikely(err > 0))
+ err = net_xmit_errno(err);
+
packet_increment_head(&po->tx_ring);
len_sum += tp_len;
} while (likely((ph != NULL) ||
@@ -1033,9 +1034,6 @@ static int tpacket_snd(struct packet_sock *po, struct msghdr *msg)
err = len_sum;
goto out_put;
-out_xmit:
- skb->destructor = sock_wfree;
- atomic_dec(&po->tx_ring.pending);
out_status:
__packet_set_status(po, ph, status);
kfree_skb(skb);
Michael Breuer
> David Miller wrote, On 12/27/2009 05:11 AM:
>
>
>> From: David Miller<da...@davemloft.net>
>> Date: Sat, 26 Dec 2009 19:44:18 -0800 (PST)
>>
>>
>>> From: Stephen Hemminger<shemm...@linux-foundation.org>
>>> Date: Sat, 26 Dec 2009 14:05:44 -0800
>>>
>>>
>>>> Other drivers may have same problem, I really think this ought
>>>> to be done at higher level.
>>>>
>>> I tend to agree with you, and I thought we had handled all
>>> cases. Let's simply make AF_PACKET linearize the link
>>> level header before sending things out to the transmit path.
>>>
>>> I can work on this if you want.
>>>
>> Actually Stephen, I took a look and I can't see how AF_PACKET
>> can create this situation.
>>
>> It always copies into the linear area of the SKB it allocates
>> for sendmsg() processing. Whether the data comes from sendmsg
>> data or the mmap() ring buffer.
>>
> Actually, I think there is a bug in this place, but of course this
> might be unconnected. Anyway, Michael, could you try this patch?
> BTW, did you try with CONFIG_PACKET_MMAP disabled?
>
Please let me know which permutations of the following would be most
valuable to test:
Davids patch in/out
The attached patch in/out
CONFIG_PACKET_MMAP on/off
I'm thinking your patch in, david's out, with and without
CONFIG_PACKET_MMAP.
> Thanks,
> Jarek P.
> ----------------->
>
> Changing an skb after dev_queue_xmit() is illegal. And since it's
> inconsistent to treat specially net_xmit_errno() non-zero return,
> while ignoring other dev_queue_xmit() errors, there is no reason
> to break the loop in tpacket_snd() in this case.
>
> With debugging by: Stephen Hemminger<shemm...@linux-foundation.org>
>
> Reported-by: Michael Breuer<mbr...@majjas.com>
> Signed-off-by: Jarek Poplawski<jar...@gmail.com>
> ---
>
> net/packet/af_packet.c | 8 +++-----
> 1 files changed, 3 insertions(+), 5 deletions(-)
>
> diff --git a/net/packet/af_packet.c b/net/packet/af_packet.c
> index e0516a2..984a1fa 100644
> --- a/net/packet/af_packet.c
> +++ b/net/packet/af_packet.c
> @@ -1021,8 +1021,9 @@ static int tpacket_snd(struct packet_sock *po, struct msghdr *msg)
>
> status = TP_STATUS_SEND_REQUEST;
> err = dev_queue_xmit(skb);
> - if (unlikely(err> 0&& (err = net_xmit_errno(err)) != 0))
Jarek Poplawski
I'm not sure about David's (except do it first ;-), but try my patch
with CONFIG_PACKET_MMAP on; if there is no change, CONFIG_PACKET_MMAP
off, without any patches.
Thanks,
Jarek P.
Michael Breuer
> - goto out_xmit;
> + if (unlikely(err> 0))
> + err = net_xmit_errno(err);
> +
> packet_increment_head(&po->tx_ring);
> len_sum += tp_len;
> } while (likely((ph != NULL) ||
> @@ -1033,9 +1034,6 @@ static int tpacket_snd(struct packet_sock *po, struct msghdr *msg)
> err = len_sum;
> goto out_put;
>
> -out_xmit:
> - skb->destructor = sock_wfree;
> - atomic_dec(&po->tx_ring.pending);
> out_status:
> __packet_set_status(po, ph, status);
> kfree_skb(skb);
> --
> To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
> the body of a message to majo...@vger.kernel.org
> More majordomo info at http://vger.kernel.org/majordomo-info.html
> Please read the FAQ at http://www.tux.org/lkml/
>
12/26: [PATCH] sky2: make sure ethernet header is in transmit skb (I ran
without Steven's patch and with this patch).
Oddly, with this patch vs. Steven's - I'm getting software interrupt
errors sporadically while not under load - with Steven's I get the
frequently while under load (as per nethogs). For example:
Jan 5 21:29:00 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Jan 5 21:29:00 mail kernel: sky2 software interrupt status 0x40000008
Jan 5 21:29:00 mail kernel: sky2 Tx ring pending=124...125 report=125
done=125
Jan 5 21:29:00 mail kernel: 124: 0xb38de0be(5374)
Jan 5 21:29:00 mail kernel: sky2 0000:06:00.0: error interrupt status=0x8
Jan 5 21:29:00 mail kernel: sky2 software interrupt status 0x8
Jan 5 21:29:00 mail kernel: sky2 Tx ring pending=126...127 report=126
done=127
Jan 5 21:29:00 mail kernel: 126: 0xb38d80be(9014)
I also believe (can't prove yet) that my load test is slower with this
patch vs. the sky2 patch.
Is it possible that this patch is causing the transmission to
momentarily halt such that the overall utilization appears low at the
time I see the interrupt errors, vs. the other patch which perhaps
doesn't interrupt the traffic flow quite so much?
I haven't run yet with CONFIG_PACKET_MMAP disabled.
Jarek Poplawski
Yes, without this patch xmit could be stopped earlier on some kind of
errors, with retransmit of the last message possible. On the other
hand, other dev_queue_xmit() (negative) errors, are ignored. So this
place could be still improved by adding proper err handling (or
removing getting err return from dev_queue_xmit() at all).
Anyway, I think this patch should be a safe proposal for stable. If
so, David, please add Michael's "Tested-by".
>
> I haven't run yet with CONFIG_PACKET_MMAP disabled.
>
This should behave similarly as MMAP with this patch or maybe even
better in case of errors.
Thanks,
Jarek P.
Jarek Poplawski
> On Tue, Jan 05, 2010 at 09:36:28PM -0500, Michael Breuer wrote:
> > Is it possible that this patch is causing the transmission to
> > momentarily halt such that the overall utilization appears low at the
> > time I see the interrupt errors, vs. the other patch which perhaps
> > doesn't interrupt the traffic flow quite so much?
>
> Yes, without this patch xmit could be stopped earlier on some kind of
> errors, with retransmit of the last message possible. On the other
> hand, other dev_queue_xmit() (negative) errors, are ignored. So this
> place could be still improved by adding proper err handling (or
> removing getting err return from dev_queue_xmit() at all).
On the other hand, returning just this one net_xmit_errno() would be
consistent with non-MMAP sendmsg, so here is an alternative version
for testing.
Thanks,
Jarek P.
-----------------> (alternative #2)
tpacket_snd() can change and kfree an skb after dev_queue_xmit(),
which is illegal.
With debugging by: Stephen Hemminger <shemm...@linux-foundation.org>
Reported-by: Michael Breuer <mbr...@majjas.com>
Signed-off-by: Jarek Poplawski <jar...@gmail.com>
---
net/packet/af_packet.c | 8 +++-----
1 files changed, 3 insertions(+), 5 deletions(-)
diff --git a/net/packet/af_packet.c b/net/packet/af_packet.c
index e0516a2..aba2049 100644
--- a/net/packet/af_packet.c
+++ b/net/packet/af_packet.c
@@ -1021,9 +1021,10 @@ static int tpacket_snd(struct packet_sock *po, struct msghdr *msg)
status = TP_STATUS_SEND_REQUEST;
err = dev_queue_xmit(skb);
- if (unlikely(err > 0 && (err = net_xmit_errno(err)) != 0))
- goto out_xmit;
packet_increment_head(&po->tx_ring);
+ if (unlikely(err > 0 && (err = net_xmit_errno(err)) != 0))
+ goto out_put;
+
len_sum += tp_len;
} while (likely((ph != NULL) ||
((!(msg->msg_flags & MSG_DONTWAIT)) &&
Stephen Hemminger
Jarek Poplawski <jar...@gmail.com> wrote:
> tpacket_snd() can change and kfree an skb after dev_queue_xmit(),
> which is illegal.
>
> With debugging by: Stephen Hemminger <shemm...@linux-foundation.org>
>
> Reported-by: Michael Breuer <mbr...@majjas.com>
> Signed-off-by: Jarek Poplawski <jar...@gmail.com>
Good catch.
Acked-by: Stephen Hemminger <shemm...@vyatta.com>
--
Jarek Poplawski
> On Wed, 6 Jan 2010 09:15:32 +0000
> Jarek Poplawski <jar...@gmail.com> wrote:
>
> > tpacket_snd() can change and kfree an skb after dev_queue_xmit(),
> > which is illegal.
> >
> > With debugging by: Stephen Hemminger <shemm...@linux-foundation.org>
> >
> > Reported-by: Michael Breuer <mbr...@majjas.com>
> > Signed-off-by: Jarek Poplawski <jar...@gmail.com>
>
> Good catch.
> Acked-by: Stephen Hemminger <shemm...@vyatta.com>
First of all, we're incredibly lucky that such a helpful guy as
Michael had misfortune to hit so helpfully broken piece of hardware ;-)
Thanks,
Jarek P.
Michael Breuer
running a bit better... until the adapter went down :(
This is the syslog output at the time the network failed:
Jan 6 14:11:01 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Jan 6 14:11:01 mail kernel: sky2 software interrupt status 0x40000008
Jan 6 14:11:01 mail kernel: sky2 Tx ring pending=125...126 report=125
done=126
Jan 6 14:11:01 mail kernel: 125: 0xc9c340be(8310)
<network dropped as seen by clients here>
Jan 6 14:12:51 mail kernel: DRHD: handling fault status reg 2
Jan 6 14:12:51 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr fffa9ebfe000
Jan 6 14:12:51 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Jan 6 14:12:51 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Jan 6 14:12:51 mail kernel: sky2 software interrupt status 0x80000000
Jan 6 14:12:51 mail kernel: sky2 Tx ring pending=68...69 report=68 done=68
Jan 6 14:12:51 mail kernel: 68: 0x9ebfe4ca(105)
Jan 6 14:12:51 mail kernel: sky2 hardware interrupt status 0xd000000
Jan 6 14:12:51 mail kernel: sky2 Tx ring pending=68...69 report=68 done=68
Jan 6 14:12:51 mail kernel: 68: 0x9ebfe4ca(105)
Jan 6 14:12:51 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
Jan 6 14:12:51 mail smbd[6281]: [2010/01/06 14:12:51, 0]
lib/util_sock.c:539(read_fd_with_timeout)
Jan 6 14:12:51 mail smbd[6281]: [2010/01/06 14:12:51, 0]
lib/util_sock.c:1491(get_peer_addr_internal)
Jan 6 14:12:51 mail smbd[6281]: getpeername failed. Error was
Transport endpoint is not connected
Jan 6 14:12:51 mail smbd[6281]: read_fd_with_timeout: client 0.0.0.0
read error = Connection timed out.
Much of the same... followed by sky2's unsuccessful attempts to reset
the adapter - starting with NETDEV WATCHDOG oops:
Jan 6 14:13:41 mail kernel: ------------[ cut here ]------------
Jan 6 14:13:41 mail kernel: WARNING: at net/sched/sch_generic.c:261
dev_watchdog+0xf3/0x164()
Jan 6 14:13:41 mail kernel: Hardware name: System Product Name
Jan 6 14:13:41 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
queue 0 timed out
Jan 6 14:13:41 mail kernel: Modules linked in: ip6table_filter
ip6table_mangle ip6_tables ipt_MASQUERADE iptable_nat nf_nat
iptable_mangle iptable_raw bridge stp appletalk psnap llc nfsd lockd
nfs_acl auth_rpcgss exportfs hwmon_vid coretemp sunrpc acpi_cpufreq sit
tunnel4 ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp xt_DSCP xt_dscp
xt_MARK nf_conntrack_ipv6 xt_multiport ipv6 dm_multipath kvm_intel kvm
snd_hda_codec_analog gspca_spca505 snd_hda_intel snd_hda_codec
snd_ens1371 gspca_main gameport snd_rawmidi snd_ac97_codec ac97_bus
snd_hwdep snd_seq videodev snd_seq_device v4l1_compat
v4l2_compat_ioctl32 wmi snd_pcm pcspkr i2c_i801 asus_atk0110 hwmon
firewire_ohci snd_timer firewire_core snd iTCO_wdt crc_itu_t sky2
soundcore iTCO_vendor_support snd_page_alloc fbcon tileblit font bitblit
softcursor raid456 async_raid6_recov async_pq raid6_pq async_xor xor
async_memcpy async_tx raid1 ata_generic pata_acpi pata_marvell nouveau
ttm drm_kms_helper drm agpgart fb i2c_algo_bit cfbcopyarea i2c_core
cfbimgblt cfbfil
Jan 6 14:13:41 mail kernel: lrect [last unloaded: microcode]
Jan 6 14:13:41 mail kernel: Pid: 25, comm: ksoftirqd/7 Tainted:
G W 2.6.32-00839-g92238e5-dirty #40
Jan 6 14:13:41 mail kernel: Call Trace:
Jan 6 14:13:41 mail kernel: <IRQ> [<ffffffff8105365a>]
warn_slowpath_common+0x7c/0x94
Jan 6 14:13:41 mail kernel: [<ffffffff810536c9>]
warn_slowpath_fmt+0x41/0x43
Jan 6 14:13:41 mail kernel: [<ffffffff813e139f>] ? netif_tx_lock+0x44/0x6c
Jan 6 14:13:41 mail kernel: [<ffffffff813e1507>] dev_watchdog+0xf3/0x164
Jan 6 14:13:41 mail kernel: [<ffffffff8106e8a4>] ? __queue_work+0x3a/0x42
Jan 6 14:13:41 mail kernel: [<ffffffff8106316b>]
run_timer_softirq+0x1c8/0x270
Jan 6 14:13:41 mail kernel: [<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
Jan 6 14:13:41 mail kernel: [<ffffffff81012e1c>] call_softirq+0x1c/0x30
Jan 6 14:13:41 mail kernel: <EOI> [<ffffffff810143a3>]
do_softirq+0x4b/0xa6
Jan 6 14:13:41 mail kernel: [<ffffffff8105a730>] ksoftirqd+0x65/0xdc
Jan 6 14:13:41 mail kernel: [<ffffffff8105a6cb>] ? ksoftirqd+0x0/0xdc
Jan 6 14:13:41 mail kernel: [<ffffffff8107275c>] kthread+0x7f/0x87
Jan 6 14:13:41 mail kernel: [<ffffffff81012d1a>] child_rip+0xa/0x20
Jan 6 14:13:41 mail kernel: [<ffffffff8101267d>] ? restore_args+0x0/0x30
Jan 6 14:13:41 mail kernel: [<ffffffff810726dd>] ? kthread+0x0/0x87
Jan 6 14:13:41 mail kernel: [<ffffffff81012d10>] ? child_rip+0x0/0x20
Jan 6 14:13:41 mail kernel: ---[ end trace 57f7151f6a5def07 ]---
Jan 6 14:13:41 mail kernel: sky2 eth0: tx timeout
Jan 6 14:13:41 mail kernel: sky2 eth0: transmit ring 68 .. 27 report=68
done=68
Jan 6 14:13:41 mail kernel: sky2 eth0: disabling interface
Jan 6 14:13:41 mail kernel: sky2 eth0: enabling interface
<unrelated stuff>
Jan 6 14:14:29 mail kernel: sky2 eth0: tx timeout
Jan 6 14:14:29 mail kernel: sky2 eth0: transmit ring 2 .. 89 report=2
done=2
Jan 6 14:14:29 mail kernel: sky2 eth0: disabling interface
Jan 6 14:14:29 mail kernel: sky2 eth0: enabling interface
Jan 6 14:14:29 mail NetworkManager: <info> (eth0): carrier now OFF
(device state 1)
Jan 6 14:14:32 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
Jan 6 14:14:32 mail NetworkManager: <info> (eth0): carrier now ON
(device state 1)
Jan 6 14:14:34 mail dhcpd: DHCPINFORM from 10.0.0.11 via eth0
Jan 6 14:14:34 mail dhcpd: DHCPACK to 10.0.0.11 (00:1a:92:8d:30:81) via
eth0
<unrelated stuff>
Jan 6 14:15:17 mail kernel: sky2 eth0: tx timeout
Jan 6 14:15:17 mail kernel: sky2 eth0: transmit ring 2 .. 89 report=2
done=2
Jan 6 14:15:17 mail kernel: sky2 eth0: disabling interface
Jan 6 14:15:17 mail kernel: sky2 eth0: enabling interface
This sequence - without the NETDEV WATCHDOG oops, and with differening
DHCP client request/responses repeats until I rebooted the system. Note:
networkmanager is not managing the interface. Also note that my external
link (eth1) remained up and fully functional.
Observations leading up the the failure:
1) Peak Receive rates about 20% higher than with the prior patch (still
lower than with the earlier sky2 patch).
2) Peak rates sustained for longer than the prior patch.
3) Interrupt errors occurred mostly during periods of high receive rates
- not at all while quiesced as seen with the prior patch.
Jarek Poplawski
I'm not sure: do you mean this patch above vs previous one by Stephen,
or did you manage to try my "alernative #2" patch already?
BTW, I forgot to mention, and maybe it doesn't matter here, but it
would be better to (always) use my sky2 patch from Berck Nash's
thread.
Jarek P.
Michael Breuer
alternative #1. Your sky2 patch from Berck Nash's thread was included in
both cases; Stephen's was not.
Stephen Hemminger
Michael Breuer <mbr...@majjas.com> wrote:
> This patch at first behaved similarly to the previous one - seemed to be
> running a bit better... until the adapter went down :(
>
> This is the syslog output at the time the network failed:
> Jan 6 14:11:01 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Jan 6 14:11:01 mail kernel: sky2 software interrupt status 0x40000008
Could you go back to baseline sky2 driver. The display code might be buggy.
These bits indicate an error in the MAC. The interrupt source enabled
is Transmit FIFO underrun.
Looking at how vendor driver handles this.
It looks like the Yukon EC_U chip doesn't really do Jumbo frames correctly.
Maybe not enough internal buffering to ensure that the whole packet
is in the chip. Of course, none of this is in the chip manual.
Does this help
--------------
--- a/drivers/net/sky2.c 2010-01-06 12:48:43.012318966 -0800
+++ b/drivers/net/sky2.c 2010-01-06 13:05:31.273987255 -0800
@@ -792,33 +792,21 @@ static void sky2_set_tx_stfwd(struct sky
{
struct net_device *dev = hw->dev[port];
- if ( (hw->chip_id == CHIP_ID_YUKON_EX &&
- hw->chip_rev != CHIP_REV_YU_EX_A0) ||
- hw->chip_id >= CHIP_ID_YUKON_FE_P) {
- /* Yukon-Extreme B0 and further Extreme devices */
- /* enable Store & Forward mode for TX */
-
- if (dev->mtu <= ETH_DATA_LEN)
- sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
- TX_JUMBO_DIS | TX_STFW_ENA);
-
- else
- sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
- TX_JUMBO_ENA| TX_STFW_ENA);
- } else {
- if (dev->mtu <= ETH_DATA_LEN)
- sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
- else {
- /* set Tx GMAC FIFO Almost Empty Threshold */
- sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
- (ECU_JUMBO_WM << 16) | ECU_AE_THR);
-
- sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
-
- /* Can't do offload because of lack of store/forward */
- dev->features &= ~(NETIF_F_TSO | NETIF_F_SG | NETIF_F_ALL_CSUM);
- }
- }
+ if ( (hw->chip_id == CHIP_ID_YUKON_EX && hw->chip_rev != CHIP_REV_YU_EX_A0) ||
+ hw->chip_id >= CHIP_ID_YUKON_FE_P) {
+ /* Yukon-Extreme B0 and further Extreme devices */
+ /* enable Store & Forward mode for TX */
+ sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
+ } else if (dev->mtu > ETH_DATA_LEN) {
+ /* set Tx GMAC FIFO Almost Empty Threshold */
+ sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
+ (ECU_JUMBO_WM << 16) | ECU_AE_THR);
+ /* disable Store & Forward mode for TX */
+ sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
+ } else {
+ /* enable Store & Forward mode for TX */
+ sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
+ }
}
static void sky2_mac_init(struct sky2_hw *hw, unsigned port)
@@ -2185,11 +2173,16 @@ static int sky2_change_mtu(struct net_de
if (new_mtu < ETH_ZLEN || new_mtu > ETH_JUMBO_MTU)
return -EINVAL;
+ /* MTU > 1500 on yukon FE and FE+ not allowed */
if (new_mtu > ETH_DATA_LEN &&
(hw->chip_id == CHIP_ID_YUKON_FE ||
hw->chip_id == CHIP_ID_YUKON_FE_P))
return -EINVAL;
+ /* TSO on Yukon Ultra and MTU > 1500 not supported */
+ if (new_mtu > ETH_DATA_LEN && hw->chip_id == CHIP_ID_YUKON_EC_U)
+ dev->features &= ~NETIF_F_TSO;
+
if (!netif_running(dev)) {
dev->mtu = new_mtu;
return 0;
@@ -2233,6 +2226,15 @@ static int sky2_change_mtu(struct net_de
if (err)
dev_close(dev);
else {
+ /* WA for dev. #4.209 */
+ if (hw->chip_id == CHIP_ID_YUKON_EC_U &&
+ hw->chip_rev == CHIP_REV_YU_EC_U_A1) {
+ /* enable/disable Store & Forward mode for TX */
+ sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
+ sky2->speed != SPEED_1000
+ ? TX_STFW_ENA : TX_STFW_DIS);
+ }
+
gma_write16(hw, port, GM_GP_CTRL, ctl);
netif_wake_queue(dev);
--- a/drivers/net/sky2.h 2010-01-06 12:48:48.632247424 -0800
+++ b/drivers/net/sky2.h 2010-01-06 12:59:57.322078964 -0800
@@ -1901,8 +1901,8 @@ enum {
TX_VLAN_TAG_ON = 1<<25,/* enable VLAN tagging */
TX_VLAN_TAG_OFF = 1<<24,/* disable VLAN tagging */
- TX_JUMBO_ENA = 1<<23,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
- TX_JUMBO_DIS = 1<<22,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
+ TX_PCI_JUM_ENA = 1<<23,/* Enable PCI Jumbo Mode (Yukon-EC Ultra) */
+ TX_PCI_JUM_DIS = 1<<22,/* Disable PCI Jumbo Mode (Yukon-EC Ultra) */
GMF_WSP_TST_ON = 1<<18,/* Write Shadow Pointer Test On */
GMF_WSP_TST_OFF = 1<<17,/* Write Shadow Pointer Test Off */
Jarek Poplawski
> >>This patch at first behaved similarly to the previous one - seemed
> >>to be running a bit better... until the adapter went down :(
> >I'm not sure: do you mean this patch above vs previous one by Stephen,
> >or did you manage to try my "alernative #2" patch already?
> >
> >BTW, I forgot to mention, and maybe it doesn't matter here, but it
> >would be better to (always) use my sky2 patch from Berck Nash's
> >thread.
> >
> >Jarek P.
> This was using "alternative #2" patch. I didn't get the hang with
> alternative #1. Your sky2 patch from Berck Nash's thread was
> included in both cases; Stephen's was not.
OK, so I guess "alternative #1" (above) seems safer to recommend for
now (as I assumed earlier).
On the other hand, we really don't know if it's only because it's
because it's nicer for your hardware (or still some other bug around),
so as before: let David choose ;-)
BTW, I think you could still use Stephen's patch too (there might be
still something more like this). There was also mentioned this network
manager again. I might be wrong, but IMHO there could be some
interaction even if it doesn't use this device; so could/did you try
to disable it entirely?
Thanks for testing!
Jarek P.
Michael Breuer
> -
> - if (dev->mtu<= ETH_DATA_LEN)
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> - TX_JUMBO_DIS | TX_STFW_ENA);
> -
> - else
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> - TX_JUMBO_ENA| TX_STFW_ENA);
> - } else {
> - if (dev->mtu<= ETH_DATA_LEN)
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> - else {
> - /* set Tx GMAC FIFO Almost Empty Threshold */
> - sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
> - (ECU_JUMBO_WM<< 16) | ECU_AE_THR);
> -
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
> -
> - /* Can't do offload because of lack of store/forward */
> - }
> - }
> + if ( (hw->chip_id == CHIP_ID_YUKON_EX&& hw->chip_rev != CHIP_REV_YU_EX_A0) ||
> + hw->chip_id>= CHIP_ID_YUKON_FE_P) {
> + /* Yukon-Extreme B0 and further Extreme devices */
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> + } else if (dev->mtu> ETH_DATA_LEN) {
> + /* set Tx GMAC FIFO Almost Empty Threshold */
> + sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
> + (ECU_JUMBO_WM<< 16) | ECU_AE_THR);
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
> + } else {
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> + }
> }
>
> static void sky2_mac_init(struct sky2_hw *hw, unsigned port)
> @@ -2185,11 +2173,16 @@ static int sky2_change_mtu(struct net_de
> if (new_mtu< ETH_ZLEN || new_mtu> ETH_JUMBO_MTU)
> return -EINVAL;
>
> + /* MTU> 1500 on yukon FE and FE+ not allowed */
> if (new_mtu> ETH_DATA_LEN&&
> (hw->chip_id == CHIP_ID_YUKON_FE ||
> hw->chip_id == CHIP_ID_YUKON_FE_P))
> return -EINVAL;
>
> + /* TSO on Yukon Ultra and MTU> 1500 not supported */
> + dev->features&= ~NETIF_F_TSO;
> +
> if (!netif_running(dev)) {
> dev->mtu = new_mtu;
> return 0;
> @@ -2233,6 +2226,15 @@ static int sky2_change_mtu(struct net_de
> if (err)
> dev_close(dev);
> else {
> + /* WA for dev. #4.209 */
> + if (hw->chip_id == CHIP_ID_YUKON_EC_U&&
> + hw->chip_rev == CHIP_REV_YU_EC_U_A1) {
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> + sky2->speed != SPEED_1000
> + ? TX_STFW_ENA : TX_STFW_DIS);
> + }
> +
> gma_write16(hw, port, GM_GP_CTRL, ctl);
>
> netif_wake_queue(dev);
> --- a/drivers/net/sky2.h 2010-01-06 12:48:48.632247424 -0800
> +++ b/drivers/net/sky2.h 2010-01-06 12:59:57.322078964 -0800
> @@ -1901,8 +1901,8 @@ enum {
> TX_VLAN_TAG_ON = 1<<25,/* enable VLAN tagging */
> TX_VLAN_TAG_OFF = 1<<24,/* disable VLAN tagging */
>
> - TX_JUMBO_ENA = 1<<23,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
> - TX_JUMBO_DIS = 1<<22,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
> + TX_PCI_JUM_ENA = 1<<23,/* Enable PCI Jumbo Mode (Yukon-EC Ultra) */
> + TX_PCI_JUM_DIS = 1<<22,/* Disable PCI Jumbo Mode (Yukon-EC Ultra) */
>
> GMF_WSP_TST_ON = 1<<18,/* Write Shadow Pointer Test On */
> GMF_WSP_TST_OFF = 1<<17,/* Write Shadow Pointer Test Off */
>
issues with MTU=1500. Also, maybe I'm missing something, but I can only
recreate the issue with a high receive rate. Given the interaction with
DHCP, for example, I'm thinking that there is some precondition that is
as yet unknown. May be buggy hardware, or perhaps a race condition
resulting in a corrupt i/o buffer somewhere. I'm wondering whether
there's some useful place to insert some diagnostics on the RX side - at
least we can see if there are any consistent events on the RX side
preceding the TX error.
Michael Breuer
Stephen's new patch, alternative #1, and the patch from Berck Nash's thread.
Michael Breuer
> -
> - if (dev->mtu<= ETH_DATA_LEN)
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> - TX_JUMBO_DIS | TX_STFW_ENA);
> -
> - else
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> - TX_JUMBO_ENA| TX_STFW_ENA);
> - } else {
> - if (dev->mtu<= ETH_DATA_LEN)
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> - else {
> - /* set Tx GMAC FIFO Almost Empty Threshold */
> - sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
> - (ECU_JUMBO_WM<< 16) | ECU_AE_THR);
> -
> - sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
> -
> - /* Can't do offload because of lack of store/forward */
> - }
> - }
> + if ( (hw->chip_id == CHIP_ID_YUKON_EX&& hw->chip_rev != CHIP_REV_YU_EX_A0) ||
> + hw->chip_id>= CHIP_ID_YUKON_FE_P) {
> + /* Yukon-Extreme B0 and further Extreme devices */
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> + } else if (dev->mtu> ETH_DATA_LEN) {
> + /* set Tx GMAC FIFO Almost Empty Threshold */
> + sky2_write32(hw, SK_REG(port, TX_GMF_AE_THR),
> + (ECU_JUMBO_WM<< 16) | ECU_AE_THR);
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_DIS);
> + } else {
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T), TX_STFW_ENA);
> + }
> }
>
> static void sky2_mac_init(struct sky2_hw *hw, unsigned port)
> @@ -2185,11 +2173,16 @@ static int sky2_change_mtu(struct net_de
> if (new_mtu< ETH_ZLEN || new_mtu> ETH_JUMBO_MTU)
> return -EINVAL;
>
> + /* MTU> 1500 on yukon FE and FE+ not allowed */
> if (new_mtu> ETH_DATA_LEN&&
> (hw->chip_id == CHIP_ID_YUKON_FE ||
> hw->chip_id == CHIP_ID_YUKON_FE_P))
> return -EINVAL;
>
> + /* TSO on Yukon Ultra and MTU> 1500 not supported */
> + dev->features&= ~NETIF_F_TSO;
> +
> if (!netif_running(dev)) {
> dev->mtu = new_mtu;
> return 0;
> @@ -2233,6 +2226,15 @@ static int sky2_change_mtu(struct net_de
> if (err)
> dev_close(dev);
> else {
> + /* WA for dev. #4.209 */
> + if (hw->chip_id == CHIP_ID_YUKON_EC_U&&
> + hw->chip_rev == CHIP_REV_YU_EC_U_A1) {
> + sky2_write32(hw, SK_REG(port, TX_GMF_CTRL_T),
> + sky2->speed != SPEED_1000
> + ? TX_STFW_ENA : TX_STFW_DIS);
> + }
> +
> gma_write16(hw, port, GM_GP_CTRL, ctl);
>
> netif_wake_queue(dev);
> --- a/drivers/net/sky2.h 2010-01-06 12:48:48.632247424 -0800
> +++ b/drivers/net/sky2.h 2010-01-06 12:59:57.322078964 -0800
> @@ -1901,8 +1901,8 @@ enum {
> TX_VLAN_TAG_ON = 1<<25,/* enable VLAN tagging */
> TX_VLAN_TAG_OFF = 1<<24,/* disable VLAN tagging */
>
> - TX_JUMBO_ENA = 1<<23,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
> - TX_JUMBO_DIS = 1<<22,/* PCI Jumbo Mode enable (Yukon-EC Ultra) */
> + TX_PCI_JUM_ENA = 1<<23,/* Enable PCI Jumbo Mode (Yukon-EC Ultra) */
> + TX_PCI_JUM_DIS = 1<<22,/* Disable PCI Jumbo Mode (Yukon-EC Ultra) */
>
> GMF_WSP_TST_ON = 1<<18,/* Write Shadow Pointer Test On */
> GMF_WSP_TST_OFF = 1<<17,/* Write Shadow Pointer Test Off */
>
Running with this patch; Jarek's "alternative 1", and the patch from the
other thread. Not so good.
No reported errors (sky2, etc.) - however with mtu=9000, lots of stuff
broke: XDMCP; http via MASQ/netfilter, ssh connections intermittently
(when large frames involved perhaps), etc. Tried to change mtu to 1500
on the fly, got a bunch of errors - and network watchdog kicked in. Have
now rebooted with the same patches and mtu=1500.
... with mtu=1500, Everything is again working (i.e., XDMCP, netfilter,
etc.)
Load test with mtu=1500 went well for a while - high throughput
sustained for a few minutes - then similar crash as before... but no
interrup error messages this time until after the oops:
<nothing of note before this>
Jan 6 18:17:54 mail kernel: DRHD: handling fault status reg 2
Jan 6 18:17:54 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr 1bbfe000
Jan 6 18:17:54 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Jan 6 18:17:54 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Jan 6 18:17:54 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
Jan 6 18:18:04 mail kernel: ------------[ cut here ]------------
Jan 6 18:18:04 mail kernel: WARNING: at net/sched/sch_generic.c:261
dev_watchdog+0xf3/0x164()
Jan 6 18:18:04 mail kernel: Hardware name: System Product Name
Jan 6 18:18:04 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
queue 0 timed out
Jan 6 18:18:04 mail kernel: Modules linked in: ip6table_filter
ip6table_mangle ip6_tables ipt_MASQUERADE iptable_nat nf_nat
iptable_mangle iptable_raw bridge stp appletalk psnap llc nfsd lockd
nfs_acl auth_rpcgss exportfs hwmon_vid coretemp sunrpc acpi_cpufreq sit
tunnel4 ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp xt_DSCP xt_dscp
xt_MARK nf_conntrack_ipv6 xt_multiport ipv6 dm_multipath kvm_intel kvm
snd_hda_codec_analog snd_ens1371 gameport snd_rawmidi snd_ac97_codec
snd_hda_intel snd_hda_codec ac97_bus snd_hwdep snd_seq snd_seq_device
gspca_spca505 gspca_main videodev v4l1_compat snd_pcm
v4l2_compat_ioctl32 pcspkr asus_atk0110 hwmon i2c_i801 iTCO_wdt
firewire_ohci iTCO_vendor_support firewire_core crc_itu_t snd_timer snd
sky2 soundcore wmi snd_page_alloc fbcon tileblit font bitblit softcursor
raid456 async_raid6_recov async_pq raid6_pq async_xor xor async_memcpy
async_tx raid1 ata_generic pata_acpi pata_marvell nouveau ttm
drm_kms_helper drm agpgart fb i2c_algo_bit cfbcopyarea i2c_core
cfbimgblt cfbfil
Jan 6 18:18:04 mail kernel: lrect [last unloaded: microcode]
Jan 6 18:18:04 mail kernel: Pid: 0, comm: swapper Tainted: G W
2.6.32-00840-gec8257c-dirty #41
Jan 6 18:18:04 mail kernel: Call Trace:
Jan 6 18:18:04 mail kernel: <IRQ> [<ffffffff8105365a>]
warn_slowpath_common+0x7c/0x94
Jan 6 18:18:04 mail kernel: [<ffffffff810536c9>]
warn_slowpath_fmt+0x41/0x43
Jan 6 18:18:04 mail kernel: [<ffffffff813e12bf>] ? netif_tx_lock+0x44/0x6c
Jan 6 18:18:04 mail kernel: [<ffffffff813e1427>] dev_watchdog+0xf3/0x164
Jan 6 18:18:04 mail kernel: [<ffffffff81077696>] ?
sched_clock_cpu+0x47/0xd1
Jan 6 18:18:04 mail kernel: [<ffffffff8106316b>]
run_timer_softirq+0x1c8/0x270
Jan 6 18:18:04 mail kernel: [<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
Jan 6 18:18:04 mail kernel: [<ffffffff8107ef33>] ?
tick_program_event+0x2a/0x2c
Jan 6 18:18:04 mail kernel: [<ffffffff81012e1c>] call_softirq+0x1c/0x30
Jan 6 18:18:04 mail kernel: [<ffffffff810143a3>] do_softirq+0x4b/0xa6
Jan 6 18:18:04 mail kernel: [<ffffffff8105aa1b>] irq_exit+0x4a/0x8c
Jan 6 18:18:04 mail kernel: [<ffffffff8146dd32>]
smp_apic_timer_interrupt+0x86/0x94
Jan 6 18:18:04 mail kernel: [<ffffffff810127e3>]
apic_timer_interrupt+0x13/0x20
Jan 6 18:18:04 mail kernel: <EOI> [<ffffffff812c4a06>] ?
acpi_idle_enter_c1+0xb2/0xd0
Jan 6 18:18:04 mail kernel: [<ffffffff812c49ff>] ?
acpi_idle_enter_c1+0xab/0xd0
Jan 6 18:18:04 mail kernel: [<ffffffff813a43b8>] ?
cpuidle_idle_call+0x9e/0xfa
Jan 6 18:18:04 mail kernel: [<ffffffff81010c90>] ? cpu_idle+0xb4/0xf6
Jan 6 18:18:04 mail kernel: [<ffffffff81463312>] ?
start_secondary+0x201/0x242
Jan 6 18:18:04 mail kernel: ---[ end trace 57f7151f6a5def07 ]---
Jan 6 18:18:04 mail kernel: sky2 eth0: tx timeout
Jan 6 18:18:04 mail kernel: sky2 eth0: transmit ring 21 .. 108
report=21 done=21
Jan 6 18:18:04 mail kernel: sky2 eth0: disabling interface
Jan 6 18:18:04 mail kernel: sky2 eth0: enabling interface
<eth0 dead after this>
Michael Breuer
NET_CLS_ACT. At least in some cases (sch_cbq.c for example), the net
transmit error could be returned from here... after releasing the skb. A
quick scan of the various files in net/sched suggests that with
NET_CLS_ACT the skb may or may not have been freed in the event of an
error. If I have time later I'll see if I can bypass NET_CLS_ACT and see
whether this is even relevant.
Michael Breuer
doesn't re-free the skb after the net_dev_enqueue error) and all else as
above (your mtu patch on a clean 2.6.32.2 sky2.c, plus the devtpts inode
patch) with an MTU of 1500 I can run without errors (including the
interrupt errors previously reported).
Changing MTU to 9000, everything basically breaks - Can't use X11 (local
or remote - get X11 screen after gdm login locally, but then goes back
to greeter; remote gets no greeter); ssh sessions hang; etc. This time I
was able to reset the MTU back to 1500 without a reboot - but I did have
to ifconfig eth0 down and then up. Looking at the sk98lin code, it looks
to me like they do a bit more work with existing buffers before
completing the MTU switch. Note that even doing this, X11 did not work
(it did with the old mtu change code). Tried changing to mtu 4500 - same
effect as 9000... but when I switched back to 1500, ksoftirqd started
spinning using 100% of one core.
Running with these patches and 1500 MTU seems stable, but the network is
running rather slow. Latency is OK, but peak transfer rates seem to be
running about 20% of what I saw while receiving the interrupt errors
with earlier patches.
I'll leave this running overnight to confirm that at least the errors
and hangs are resolved with this patch set.
Stephen Hemminger
The problem is that patch was enabling scatter-gather and checksum offload
that won't work on EC_U hardware with 9K MTU. At least, it never worked
for me when I tested it. So because of that it really doesn't change anything
for the better on that chip version.
What version chip is on that motherboard? Mine is:
Yukon-2 EC Ultra chip revision 3
which corresponds to B0 step.
Another possibility is the PHY register which controls number of ticks
of buffering. The default is zero, which gives the most buffering (good),
but the firmware could be reprogramming it (bad). In general, the driver
doesn't fiddle with bits that are already set correctly, because sometimes
vendors need to tweak PCI timing in firmware/BIOS. It seems the firmware on this
chip is just a bunch of register setups done on power on.
Michael Breuer
at least an order of magnitude slower than with the other set of
patches. The other set also generated errors and was not stable :( But,
that set worked with mtu=9000, this set doesn't seem to work with
anything over 1500. The slowdown may also be (based on earlier testing)
attributable to Jarek's alternative #2 patch. As to the chip, I *think*
we have the same chip - I'm including lspci -vv - perhaps there is
something different.
06:00.0 Ethernet controller: Marvell Technology Group Ltd. 88E8056 PCI-E
Gigabit Ethernet Controller (rev 14)
Subsystem: Giga-byte Technology Device e000
Control: I/O+ Mem+ BusMaster+ SpecCycle- MemWINV- VGASnoop-
ParErr- Stepping- SERR+ FastB2B- DisINTx+
Status: Cap+ 66MHz- UDF- FastB2B- ParErr- DEVSEL=fast >TAbort-
<TAbort- <MAbort- >SERR- <PERR- INTx-
Latency: 0, Cache Line Size: 256 bytes
Interrupt: pin A routed to IRQ 58
Region 0: Memory at fbdfc000 (64-bit, non-prefetchable) [size=16K]
Region 2: I/O ports at d800 [size=256]
Expansion ROM at fbdc0000 [disabled] [size=128K]
Capabilities: [48] Power Management version 3
Flags: PMEClk- DSI- D1+ D2+ AuxCurrent=0mA
PME(D0+,D1+,D2+,D3hot+,D3cold+)
Status: D0 NoSoftRst- PME-Enable- DSel=0 DScale=1 PME-
Capabilities: [50] Vital Product Data
Product Name: Marvell Yukon 88E8056 Gigabit Ethernet
Controller
Read-only fields:
[PN] Part number: Yukon 88E8056
[EC] Engineering changes: Rev. 1.4
[MN] Manufacture ID: 4d 61 72 76 65 6c 6c
[SN] Serial number: AbCdEfG001C3B
[CP] Extended capability: 01 10 cc 03
[RV] Reserved: checksum good, 9 byte(s) reserved
Read/write fields:
[RW] Read-write area: 121 byte(s) free
End
Capabilities: [5c] MSI: Enable+ Count=1/1 Maskable- 64bit+
Address: 00000000fee00458 Data: 0000
Capabilities: [e0] Express (v1) Legacy Endpoint, MSI 00
DevCap: MaxPayload 128 bytes, PhantFunc 0, Latency L0s
unlimited, L1 unlimited
ExtTag- AttnBtn- AttnInd- PwrInd- RBE+ FLReset-
DevCtl: Report errors: Correctable- Non-Fatal- Fatal-
Unsupported-
RlxdOrd- ExtTag- PhantFunc- AuxPwr- NoSnoop-
MaxPayload 128 bytes, MaxReadReq 512 bytes
DevSta: CorrErr+ UncorrErr- FatalErr- UnsuppReq+
AuxPwr+ TransPend-
LnkCap: Port #0, Speed 2.5GT/s, Width x1, ASPM L0s L1,
Latency L0 <256ns, L1 unlimited
ClockPM+ Surprise- LLActRep- BwNot-
LnkCtl: ASPM Disabled; RCB 128 bytes Disabled- Retrain-
CommClk+
ExtSynch- ClockPM- AutWidDis- BWInt- AutBWInt-
LnkSta: Speed 2.5GT/s, Width x1, TrErr- Train- SlotClk+
DLActive- BWMgmt- ABWMgmt-
Capabilities: [100] Advanced Error Reporting
UESta: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt-
UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UEMsk: DLP- SDES- TLP- FCP- CmpltTO- CmpltAbrt-
UnxCmplt- RxOF- MalfTLP- ECRC- UnsupReq- ACSViol-
UESvrt: DLP+ SDES- TLP- FCP+ CmpltTO- CmpltAbrt-
UnxCmplt- RxOF+ MalfTLP+ ECRC- UnsupReq- ACSViol-
CESta: RxErr- BadTLP- BadDLLP- Rollover- Timeout-
NonFatalErr+
CEMsk: RxErr- BadTLP- BadDLLP- Rollover- Timeout-
NonFatalErr+
AERCap: First Error Pointer: 1f, GenCap- CGenEn-
ChkCap- ChkEn-
Kernel driver in use: sky2
Kernel modules: sky2
Michael Breuer
Probably why this is so slow.
Current ifconfig:
eth0 Link encap:Ethernet HWaddr 00:26:18:00:1C:3B
inet addr:10.0.0.1 Bcast:10.0.0.255 Mask:255.255.255.0
inet6 addr: fe80::226:18ff:fe00:1c3b/64 Scope:Link
UP BROADCAST RUNNING ALLMULTI MULTICAST MTU:1500 Metric:1
RX packets:26647536 errors:0 dropped:517884 overruns:0 frame:0
TX packets:12112780 errors:0 dropped:0 overruns:0 carrier:0
collisions:0 txqueuelen:1000
RX bytes:38960063319 (36.2 GiB) TX bytes:1889879762 (1.7 GiB)
Interrupt:18
Michael Breuer
Never mind... spoke too soon. Crashed again. Just took longer:
Jan 7 00:37:39 mail kernel: DRHD: handling fault status reg 2
Jan 7 00:37:39 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr fff1401fe000
Jan 7 00:37:39 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Jan 7 00:37:39 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Jan 7 00:37:39 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
Jan 7 00:37:40 mail smbd[4729]: [2010/01/07 00:37:40, 0]
lib/util_sock.c:539(read_fd_with_timeout)
Jan 7 00:37:40 mail smbd[4729]: [2010/01/07 00:37:40, 0]
lib/util_sock.c:1491(get_peer_addr_internal)
Jan 7 00:37:40 mail smbd[4729]: getpeername failed. Error was
Transport endpoint is not connected
Jan 7 00:37:40 mail smbd[4729]: read_fd_with_timeout: client 0.0.0.0
read error = Connection timed out.
Jan 7 00:37:40 mail dhcpd: DHCPREQUEST for 10.0.0.32 from
00:26:bb:aa:15:10 (mbitouch) via eth0
Jan 7 00:37:40 mail dhcpd: DHCPACK on 10.0.0.32 to 00:26:bb:aa:15:10
(mbitouch) via eth0
Jan 7 00:37:41 mail dhcpd: DHCPREQUEST for 10.0.0.32 from
00:26:bb:aa:15:10 (mbitouch) via eth0
Jan 7 00:37:41 mail dhcpd: DHCPACK on 10.0.0.32 to 00:26:bb:aa:15:10
(mbitouch) via eth0
Jan 7 00:37:44 mail dhcpd: DHCPREQUEST for 10.0.0.32 from
00:26:bb:aa:15:10 (mbitouch) via eth0
Jan 7 00:37:44 mail dhcpd: DHCPACK on 10.0.0.32 to 00:26:bb:aa:15:10
(mbitouch) via eth0
Jan 7 00:37:47 mail kernel: ------------[ cut here ]------------
Jan 7 00:37:47 mail kernel: WARNING: at net/sched/sch_generic.c:261
dev_watchdog+0xf3/0x164()
Jan 7 00:37:47 mail kernel: Hardware name: System Product Name
Jan 7 00:37:47 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
queue 0 timed out
Jan 7 00:37:47 mail kernel: Modules linked in: ip6table_filter
ip6table_mangle ip6_tables ipt_MASQUERADE iptable_nat nf_nat
iptable_mangle iptable_raw bridge stp appletalk psnap llc nfsd lockd
nfs_acl auth_rpcgss exportfs hwmon_vid coretemp sunrpc acpi_cpufreq sit
tunnel4 ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp xt_DSCP xt_dscp
xt_MARK nf_conntrack_ipv6 xt_multiport ipv6 dm_multipath kvm_intel kvm
snd_hda_codec_analog snd_hda_intel snd_hda_codec snd_ens1371 gameport
snd_rawmidi gspca_spca505 gspca_main pcspkr snd_ac97_codec snd_hwdep
i2c_i801 snd_seq firewire_ohci videodev v4l1_compat snd_seq_device
v4l2_compat_ioctl32 ac97_bus firewire_core crc_itu_t iTCO_wdt snd_pcm
iTCO_vendor_support wmi snd_timer snd sky2 asus_atk0110 hwmon soundcore
snd_page_alloc fbcon tileblit font bitblit softcursor raid456
async_raid6_recov async_pq raid6_pq async_xor xor async_memcpy async_tx
raid1 ata_generic pata_acpi pata_marvell nouveau ttm drm_kms_helper drm
agpgart fb i2c_algo_bit cfbcopyarea i2c_core cfbimgblt cfbfil
Jan 7 00:37:47 mail kernel: lrect [last unloaded: microcode]
Jan 7 00:37:47 mail kernel: Pid: 0, comm: swapper Tainted: G W
2.6.32-00840-gec8257c-dirty #44
Jan 7 00:37:47 mail kernel: Call Trace:
Jan 7 00:37:47 mail kernel: <IRQ> [<ffffffff8105365a>]
warn_slowpath_common+0x7c/0x94
Jan 7 00:37:47 mail kernel: [<ffffffff810536c9>]
warn_slowpath_fmt+0x41/0x43
Jan 7 00:37:47 mail kernel: [<ffffffff813e12bf>] ? netif_tx_lock+0x44/0x6c
Jan 7 00:37:47 mail kernel: [<ffffffff813e1427>] dev_watchdog+0xf3/0x164
Jan 7 00:37:47 mail kernel: [<ffffffff8105f320>] ? cascade+0x6a/0x84
Jan 7 00:37:47 mail kernel: [<ffffffff8106316b>]
run_timer_softirq+0x1c8/0x270
Jan 7 00:37:47 mail kernel: [<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
Jan 7 00:37:47 mail kernel: [<ffffffff8107ef33>] ?
tick_program_event+0x2a/0x2c
Jan 7 00:37:47 mail kernel: [<ffffffff81012e1c>] call_softirq+0x1c/0x30
Jan 7 00:37:47 mail kernel: [<ffffffff810143a3>] do_softirq+0x4b/0xa6
Jan 7 00:37:47 mail kernel: [<ffffffff8105aa1b>] irq_exit+0x4a/0x8c
Jan 7 00:37:47 mail kernel: [<ffffffff8146dd32>]
smp_apic_timer_interrupt+0x86/0x94
Jan 7 00:37:47 mail kernel: [<ffffffff810127e3>]
apic_timer_interrupt+0x13/0x20
Jan 7 00:37:47 mail kernel: <EOI> [<ffffffff812c4c7a>] ?
acpi_idle_enter_bm+0x256/0x28a
Jan 7 00:37:47 mail kernel: [<ffffffff812c4c73>] ?
acpi_idle_enter_bm+0x24f/0x28a
Jan 7 00:37:47 mail kernel: [<ffffffff813a43b8>] ?
cpuidle_idle_call+0x9e/0xfa
Jan 7 00:37:47 mail kernel: [<ffffffff81010c90>] ? cpu_idle+0xb4/0xf6
Jan 7 00:37:47 mail kernel: [<ffffffff81463312>] ?
start_secondary+0x201/0x242
Jan 7 00:37:47 mail kernel: ---[ end trace 57f7151f6a5def07 ]---
Jan 7 00:37:47 mail kernel: sky2 eth0: tx timeout
Jan 7 00:37:47 mail kernel: sky2 eth0: transmit ring 79 .. 39 report=79
done=79
Jan 7 00:37:47 mail kernel: sky2 eth0: disabling interface
Jan 7 00:37:47 mail kernel: sky2 eth0: enabling interface
Jan 7 00:37:51 mail kernel: sky2 eth0: Link is up at 1000 Mbps, full
duplex, flow control both
JJan 7 00:38:07 mail kernel: sky2 eth0: tx timeout
Jan 7 00:38:07 mail kernel: sky2 eth0: transmit ring 3 .. 90 report=3
done=3
Jan 7 00:38:07 mail kernel: sky2 eth0: disabling interface
Jan 7 00:38:07 mail kernel: sky2 eth0: enabling interface
and so on.
Michael Breuer
Reapplied a couple of earlier patches - still can't do jumbo frames, but
the rx errors are gone and speed has improved. Too early to assure that
it's stable.
Patches that seem to fix the rx drops (all from Stephen):
1) Patch change to tx_init
2) Patch to lock netif_device_detach
3) Patch to sky2_tx_complete to add netif_device_present test
Also in the mix: Jarek's alternative 2
With this set and mtu=1500 all seems good - decent if not stellar
throughput; no logged errors; no reported packet loss. As before, will
leave running and see if anything falls apart.
Jarek Poplawski
> ...
> Reapplied a couple of earlier patches - still can't do jumbo frames, but
> the rx errors are gone and speed has improved. Too early to assure that
> it's stable.
>
> Patches that seem to fix the rx drops (all from Stephen):
> 1) Patch change to tx_init
> 2) Patch to lock netif_device_detach
> 3) Patch to sky2_tx_complete to add netif_device_present test
> Also in the mix: Jarek's alternative 2
BTW, the main difference between alt. 1 and 2 is error notification:
alternative 2 doesn't hide some (most) of drops, so, dependending on
app, there might be more and faster retransmits. (I don't know what
apps used by you (other than dhcp) can depend so much on this.)
>
> With this set and mtu=1500 all seems good - decent if not stellar
> throughput; no logged errors; no reported packet loss. As before, will
> leave running and see if anything falls apart.
Good news!
Jarek P.
Michael Breuer
> On Thu, Jan 07, 2010 at 02:20:22AM -0500, Michael Breuer wrote:
>
>> ...
>> Reapplied a couple of earlier patches - still can't do jumbo frames, but
>> the rx errors are gone and speed has improved. Too early to assure that
>> it's stable.
>>
>> Patches that seem to fix the rx drops (all from Stephen):
>> 1) Patch change to tx_init
>> 2) Patch to lock netif_device_detach
>> 3) Patch to sky2_tx_complete to add netif_device_present test
>> Also in the mix: Jarek's alternative 2
>>
> BTW, the main difference between alt. 1 and 2 is error notification:
> alternative 2 doesn't hide some (most) of drops, so, dependending on
> app, there might be more and faster retransmits. (I don't know what
> apps used by you (other than dhcp) can depend so much on this.)
>
>
freed if the cfq (among others perhaps) scheduler returns an error on
enqueue (flow control perhaps). Thus with alternative 1, it is possible
that the skb is acted upon after being freed - this would be consistent
with the DMAR errors I saw.
Jarek Poplawski
> On 1/7/2010 2:47 AM, Jarek Poplawski wrote:
>> On Thu, Jan 07, 2010 at 02:20:22AM -0500, Michael Breuer wrote:
>>
>>> ...
>>> Reapplied a couple of earlier patches - still can't do jumbo frames, but
>>> the rx errors are gone and speed has improved. Too early to assure that
>>> it's stable.
>>>
>>> Patches that seem to fix the rx drops (all from Stephen):
>>> 1) Patch change to tx_init
>>> 2) Patch to lock netif_device_detach
>>> 3) Patch to sky2_tx_complete to add netif_device_present test
>>> Also in the mix: Jarek's alternative 2
>>>
>> BTW, the main difference between alt. 1 and 2 is error notification:
>> alternative 2 doesn't hide some (most) of drops, so, dependending on
>> app, there might be more and faster retransmits. (I don't know what
>> apps used by you (other than dhcp) can depend so much on this.)
>>
>>
> Unless I misread the code, I think that in some cases e skb is actually
> freed if the cfq (among others perhaps) scheduler returns an error on
> enqueue (flow control perhaps). Thus with alternative 1, it is possible
> that the skb is acted upon after being freed - this would be consistent
> with the DMAR errors I saw.
I can't see your point: could you give some scenario?
Michael Breuer
same crash as before. Network watchdog... lots of attempts to reset the
adapter... then hw watchdog rebooted the system.
Michael Breuer
> On Thu, Jan 07, 2010 at 02:55:20AM -0500, Michael Breuer wrote:
>
>> On 1/7/2010 2:47 AM, Jarek Poplawski wrote:
>>
>>> On Thu, Jan 07, 2010 at 02:20:22AM -0500, Michael Breuer wrote:
>>>
>>>
>>>> ...
>>>> Reapplied a couple of earlier patches - still can't do jumbo frames, but
>>>> the rx errors are gone and speed has improved. Too early to assure that
>>>> it's stable.
>>>>
>>>> Patches that seem to fix the rx drops (all from Stephen):
>>>> 1) Patch change to tx_init
>>>> 2) Patch to lock netif_device_detach
>>>> 3) Patch to sky2_tx_complete to add netif_device_present test
>>>> Also in the mix: Jarek's alternative 2
>>>>
>>>>
>>> BTW, the main difference between alt. 1 and 2 is error notification:
>>> alternative 2 doesn't hide some (most) of drops, so, dependending on
>>> app, there might be more and faster retransmits. (I don't know what
>>> apps used by you (other than dhcp) can depend so much on this.)
>>>
>>>
>>>
>> Unless I misread the code, I think that in some cases e skb is actually
>> freed if the cfq (among others perhaps) scheduler returns an error on
>> enqueue (flow control perhaps). Thus with alternative 1, it is possible
>> that the skb is acted upon after being freed - this would be consistent
>> with the DMAR errors I saw.
>>
> I can't see your point: could you give some scenario?
>
> Jarek P.
>
the skb. Alternative 1 disregards the error and assumes the skb is still
valid. The original code and alternative 2 exit the loop assuming the
skb has been freed.
Jarek Poplawski
> On 1/7/2010 3:21 AM, Jarek Poplawski wrote:
> >On Thu, Jan 07, 2010 at 02:55:20AM -0500, Michael Breuer wrote:
> >>Unless I misread the code, I think that in some cases e skb is actually
> >>freed if the cfq (among others perhaps) scheduler returns an error on
> >>enqueue (flow control perhaps). Thus with alternative 1, it is possible
> >>that the skb is acted upon after being freed - this would be consistent
> >>with the DMAR errors I saw.
> >I can't see your point: could you give some scenario?
> >
> >Jarek P.
> With NET_CLS_ACT set, net_dev_enqueue can return an error after
> freeing the skb. Alternative 1 disregards the error and assumes the
> skb is still valid. The original code and alternative 2 exit the
> loop assuming the skb has been freed.
Not exactly: alternative 1 disregards the error, and tries to send
next skbs if the message was longer. After consuming all the message
it returns without err code (at least wrt. dev_queue_xmit). This is
quite often practice to skip dev_queue_xmit() return (try to grep in
net\). It should never touch any part of an earlier sent skb.
Jarek P.
Jarek Poplawski
> Bad news - crashed about an hour after I wrote this email - under
> load - same crash as before. Network watchdog... lots of attempts to
> reset the adapter... then hw watchdog rebooted the system.
It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
if you find time.
Jarek Poplawski
> [...] (try to grep in net\). [...]
Did I say "net\"?!
Extremely sorry! ;-)
Michael Breuer
> On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
>
>> Bad news - crashed about an hour after I wrote this email - under
>> load - same crash as before. Network watchdog... lots of attempts to
>> reset the adapter... then hw watchdog rebooted the system.
>>
> It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
> if you find time.
>
> Jarek P.
>
clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but can't
get a usable console... will look at that later.)
Jarek Poplawski
> On 1/7/2010 1:01 PM, Jarek Poplawski wrote:
> >On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
> >>Bad news - crashed about an hour after I wrote this email - under
> >>load - same crash as before. Network watchdog... lots of attempts to
> >>reset the adapter... then hw watchdog rebooted the system.
> >It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
> >if you find time.
> >
> >Jarek P.
> Ok - any particular patch set to try with? I'm going to start with a
> clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but
> can't get a usable console... will look at that later.)
My "Berck E. Nash" and Stephen's "pskb_may_pull" sky2 patches. (BTW,
could you remind if it worked any better with 2.6.31 or earlier?)
Jarek P.
Michael Breuer
> On Thu, Jan 07, 2010 at 01:19:41PM -0500, Michael Breuer wrote:
>
>> On 1/7/2010 1:01 PM, Jarek Poplawski wrote:
>>
>>> On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
>>>
>>>> Bad news - crashed about an hour after I wrote this email - under
>>>> load - same crash as before. Network watchdog... lots of attempts to
>>>> reset the adapter... then hw watchdog rebooted the system.
>>>>
>>> It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
>>> if you find time.
>>>
>>> Jarek P.
>>>
>> Ok - any particular patch set to try with? I'm going to start with a
>> clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but
>> can't get a usable console... will look at that later.)
>>
> My "Berck E. Nash" and Stephen's "pskb_may_pull" sky2 patches. (BTW,
> could you remind if it worked any better with 2.6.31 or earlier?)
>
> Jarek P.
>
issues on 2.6.31, including sky2 DMAR errors... so probably not a 2.6.32
regression.
Michael Breuer
> On Thu, Jan 07, 2010 at 01:19:41PM -0500, Michael Breuer wrote:
>
>> On 1/7/2010 1:01 PM, Jarek Poplawski wrote:
>>
>>> On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
>>>
>>>> Bad news - crashed about an hour after I wrote this email - under
>>>> load - same crash as before. Network watchdog... lots of attempts to
>>>> reset the adapter... then hw watchdog rebooted the system.
>>>>
>>> It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
>>> if you find time.
>>>
>>> Jarek P.
>>>
>> Ok - any particular patch set to try with? I'm going to start with a
>> clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but
>> can't get a usable console... will look at that later.)
>>
> My "Berck E. Nash" and Stephen's "pskb_may_pull" sky2 patches. (BTW,
> could you remind if it worked any better with 2.6.31 or earlier?)
>
> Jarek P.
>
patch :(
Going to rerun with these patches and with and without MMAP. Will also
retry both with jumbo frames if possible.
Jarek Poplawski
> On 1/7/2010 1:35 PM, Jarek Poplawski wrote:
> >On Thu, Jan 07, 2010 at 01:19:41PM -0500, Michael Breuer wrote:
> >>On 1/7/2010 1:01 PM, Jarek Poplawski wrote:
> >>>On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
> >>>>Bad news - crashed about an hour after I wrote this email - under
> >>>>load - same crash as before. Network watchdog... lots of attempts to
> >>>>reset the adapter... then hw watchdog rebooted the system.
> >>>It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
> >>>if you find time.
> >>>
> >>>Jarek P.
> >>Ok - any particular patch set to try with? I'm going to start with a
> >>clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but
> >>can't get a usable console... will look at that later.)
> >My "Berck E. Nash" and Stephen's "pskb_may_pull" sky2 patches. (BTW,
> >could you remind if it worked any better with 2.6.31 or earlier?)
> >
> >Jarek P.
> I'm not sure my crash-and-burn runs yesterday included the
> pskb_may_pull patch :(
>
> Going to rerun with these patches and with and without MMAP. Will
> also retry both with jumbo frames if possible.
If MMAP then some "alternative" too. But first no MMAP.
Jarek P.
Jarek Poplawski
> > Going to rerun with these patches and with and without MMAP. Will
> > also retry both with jumbo frames if possible.
>
> If MMAP then some "alternative" too. But first no MMAP.
Another things IMHO worth to try: a sky2 module parameter
"disable_msi=1", and CONFIG_DMAR off.
Michael Breuer
> On Thu, Jan 07, 2010 at 07:50:40PM +0100, Jarek Poplawski wrote:
>
>>> Going to rerun with these patches and with and without MMAP. Will
>>> also retry both with jumbo frames if possible.
>>>
>> If MMAP then some "alternative" too. But first no MMAP.
>>
> Another things IMHO worth to try: a sky2 module parameter
> "disable_msi=1", and CONFIG_DMAR off.
>
> Jarek P.
>
MMAP I'm not seeing any errors - throughput is running about half what I
was seeing with MMAP enabled (before crashing that is). CPU is also way
busier (also to be expected). One other observation - I had been seeing
lots of DNS errors - IPV6 related format errors I really didn't think
much of it as they were mostly .ru and seemed spam-related, but now I
don't see any. Haven't updated bind; doubt the world has changed - so
perhaps this is related to the network issue.
Jarek Poplawski
> On 1/7/2010 2:36 PM, Jarek Poplawski wrote:
> >On Thu, Jan 07, 2010 at 07:50:40PM +0100, Jarek Poplawski wrote:
> >>>Going to rerun with these patches and with and without MMAP. Will
> >>>also retry both with jumbo frames if possible.
> >>If MMAP then some "alternative" too. But first no MMAP.
> >Another things IMHO worth to try: a sky2 module parameter
> >"disable_msi=1", and CONFIG_DMAR off.
> >
> >Jarek P.
> Ok - that'd be with or without MMAP enabled? (note that so-far,
> without MMAP I'm not seeing any errors - throughput is running about
> half what I was seeing with MMAP enabled (before crashing that is).
> CPU is also way busier (also to be expected). One other observation
> - I had been seeing lots of DNS errors - IPV6 related format errors
> I really didn't think much of it as they were mostly .ru and seemed
> spam-related, but now I don't see any. Haven't updated bind; doubt
> the world has changed - so perhaps this is related to the network
> issue.
MMAP enabled (with some "alternative" patch - to avoid known bugs)
should give as earlier the answer if these changes matter. But first
let's try longer (if possible) if this "no MMAP" could really heal
your hardware.
Jarek P.
Michael Breuer
> On Thu, Jan 07, 2010 at 01:43:08PM -0500, Michael Breuer wrote:
>
>> On 1/7/2010 1:35 PM, Jarek Poplawski wrote:
>>
>>> On Thu, Jan 07, 2010 at 01:19:41PM -0500, Michael Breuer wrote:
>>>
>>>> On 1/7/2010 1:01 PM, Jarek Poplawski wrote:
>>>>
>>>>> On Thu, Jan 07, 2010 at 10:05:37AM -0500, Michael Breuer wrote:
>>>>>
>>>>>> Bad news - crashed about an hour after I wrote this email - under
>>>>>> load - same crash as before. Network watchdog... lots of attempts to
>>>>>> reset the adapter... then hw watchdog rebooted the system.
>>>>>>
>>>>> It's a pity. Anyway, I'd be still interested in CONFIG_PACKET_MMAP off
>>>>> if you find time.
>>>>>
>>>>> Jarek P.
>>>>>
>>>> Ok - any particular patch set to try with? I'm going to start with a
>>>> clean tree using the latest 2.6.32 from git (tried 2.6.33-rc3, but
>>>> can't get a usable console... will look at that later.)
>>>>
>>> My "Berck E. Nash" and Stephen's "pskb_may_pull" sky2 patches. (BTW,
>>> could you remind if it worked any better with 2.6.31 or earlier?)
>>>
>>> Jarek P.
>>>
>> I'm not sure my crash-and-burn runs yesterday included the
>> pskb_may_pull patch :(
>>
>> Going to rerun with these patches and with and without MMAP. Will
>> also retry both with jumbo frames if possible.
>>
> If MMAP then some "alternative" too. But first no MMAP.
>
> Jarek P.
>
* no MMAP, mtu=1500, neither alternative patch loaded: adapter crashed:
Jan 7 15:44:23 mail kernel: DRHD: handling fault status reg 2
Jan 7 15:44:23 mail kernel: DMAR:[DMA Read] Request device [06:00.0]
fault addr fffb7bffe000
Jan 7 15:44:23 mail kernel: DMAR:[fault reason 06] PTE Read access is
not set
Jan 7 15:44:23 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x80000000
Jan 7 15:44:23 mail kernel: sky2 0000:06:00.0: PCI hardware error (0x2010)
Jan 7 15:44:24 mail smbd[6572]: [2010/01/07 15:44:24, 0]
lib/util_sock.c:539(read_fd_with_timeout)
Jan 7 15:44:24 mail smbd[6572]: [2010/01/07 15:44:24, 0]
lib/util_sock.c:1491(get_peer_addr_internal)
Jan 7 15:44:24 mail smbd[6572]: getpeername failed. Error was
Jan 7 15:44:44 mail kernel: WARNING: at net/sched/sch_generic.c:261
dev_watchdog+0xf3/0x164()
Jan 7 15:44:44 mail kernel: Hardware name: System Product Name
Jan 7 15:44:44 mail kernel: NETDEV WATCHDOG: eth0 (sky2): transmit
queue 0 timed out
Jan 7 15:44:44 mail kernel: Modules linked in: ip6table_filter
iptable_mangle iptable_raw bridge stp appletalk psnap llc nfsd lockd
nfs_acl auth_rpcgss exportfs hwmon_vid coretemp sunrpc acpi_cpufreq sit
tunnel4 ipt_LOG nf_conntrack_netbios_ns nf_conntrack_ftp xt_DSCP xt_dscp
xt_MARK nf_conntrack_ipv6 xt_multiport ipv6 dm_multipath kvm_intel kvm
snd_hda_intel snd_hda_codec ac97_bus snd_hwdep snd_seq snd_seq_device
firewire_core pcspkr v4l2_compat_ioctl32 snd_timer iTCO_wdt i2c_i801
crc_itu_t iTCO_vendor_support snd soundcore snd_page_alloc sky2 wmi
asus_atk0110 hwmon fbcon tileblit font bitblit softcursor raid456
raid1 ata_generic pata_acpi pata_marvell nouveau ttm drm_kms_helper drm
agpgart fb i2c_algo_bit cfbcopyarea i2c_core cfbimgblt cfbfil
Jan 7 15:44:44 mail kernel: Pid: 0, comm: swapper Tainted: G W
2.6.32NOMMAP-00847-g50ebb93-dirty #4
Jan 7 15:44:44 mail kernel: Call Trace:
Jan 7 15:44:44 mail kernel: <IRQ> [<ffffffff8105365a>]
warn_slowpath_common+0x7c/0x94
Jan 7 15:44:44 mail kernel: [<ffffffff810536c9>]
warn_slowpath_fmt+0x41/0x43
Jan 7 15:44:44 mail kernel: [<ffffffff813e2dcf>] ? netif_tx_lock+0x44/0x6c
Jan 7 15:44:44 mail kernel: [<ffffffff813e2f37>] dev_watchdog+0xf3/0x164
Jan 7 15:44:44 mail kernel: [<ffffffff8106e8a4>] ? __queue_work+0x3a/0x42
Jan 7 15:44:44 mail kernel: [<ffffffff8106316b>]
run_timer_softirq+0x1c8/0x270
Jan 7 15:44:44 mail kernel: [<ffffffff8105ae3b>] __do_softirq+0xf8/0x1cd
Jan 7 15:44:44 mail kernel: [<ffffffff8107ef33>] ?
tick_program_event+0x2a/0x2c
Jan 7 15:44:44 mail kernel: [<ffffffff81012e1c>] call_softirq+0x1c/0x30
Jan 7 15:44:44 mail kernel: [<ffffffff810143a3>] do_softirq+0x4b/0xa6
Jan 7 15:44:44 mail kernel: [<ffffffff8105aa1b>] irq_exit+0x4a/0x8c
Jan 7 15:44:44 mail kernel: [<ffffffff8146e3e2>]
smp_apic_timer_interrupt+0x86/0x94
Jan 7 15:44:44 mail kernel: [<ffffffff810127e3>]
apic_timer_interrupt+0x13/0x20
Jan 7 15:44:44 mail kernel: <EOI> [<ffffffff812c678a>] ?
acpi_idle_enter_bm+0x256/0x28a
Jan 7 15:44:44 mail kernel: [<ffffffff812c6783>] ?
acpi_idle_enter_bm+0x24f/0x28a
Jan 7 15:44:44 mail kernel: [<ffffffff813a5ec8>] ?
cpuidle_idle_call+0x9e/0xfa
Jan 7 15:44:44 mail kernel: [<ffffffff81010c90>] ? cpu_idle+0xb4/0xf6
Jan 7 15:44:44 mail kernel: [<ffffffff814639c2>] ?
start_secondary+0x201/0x242
Jan 7 15:44:44 mail kernel: ---[ end trace 57f7151f6a5def07 ]---
Jan 7 15:44:44 mail kernel: sky2 eth0: tx timeout
Jan 7 15:44:44 mail kernel: sky2 eth0: transmit ring 77 .. 36 report=77
done=77
Jan 7 15:44:44 mail kernel: sky2 eth0: disabling interface
Jan 7 15:44:44 mail kernel: sky2 eth0: enabling interface
--- adapter dead after this --- rebooted.
* no MMAP; alternative 1 patch, mtu=1500; no errors; sustained transfer
rates about 25% lower than what I saw with mmap enabled...(before MMAP
enabled crashed).
* no MMAP mtu=9000; ran ok at low transfer rates - when high rates
kicked in, got the sky2 interrupt error & things went south:
Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
status=0x40000008
After this, remote connections broke and I rebooted... decided to rerun
w/o MMAP again before going back to MMAP and trying those other sky2
options...
* Retest of no MMAP + Alternative 1 - just to confirm consistency.
Worked - no errors. Only version so far that allows the win7 backup to
complete.
* MMAP + NO DMAR + disable_msi=1... also works w/o errors... leaving
this one running for a while - also completed a backup successfully.
Fastest of the lot... about 3x faster than any other version, working or
not.
I'm leaving this one running for now. Not retesting jumbo for now. Be
happy to help dig further.
Tentative recommendations:
1) The af alternative patch seems rather necessary. First alternative
seems to be working, I'd suggest that be submitted and backported to 2.6.32.
2) Steven's pskb_may_pull patch also ought to be included and backported.
3) Jumbo frame support for yukon2 should probably be disabled until/if
fixed.
4) When possible I'll test dmar and disable_msi, and no dmar and no
disable_msi. When I first hit issues, I was running without DMAR, but
also without the above patches. I suppose the non-working permutations
need to be either fixed or invalidated (or well documented).
5) It would be nice if someone with comparable hardware could reproduce
these issues. FWIW, I can only recreate the crash running windows backup
to a cifs share. Copying large files doesn't seem to do it. Could also
be some other interaction going on here that perhaps others aren't
running - would be happy to compare notes.
Notes:
This *could* be coincidental, but maybe not...
With MMAP+NO DMAR + disable_msi there are far fewer ... actually almost
no... bind error reports... and no bind format error messages. With
NOMMAP and alternative one there are a few more bind error messages and
one format error message during the several hours that version was up.
All other configurations going back perhaps for two weeks have
significantly more bind error reports - and all versions show increasing
frequency of bind format errors (IPV6 only) in the roughly 10-15 minutes
preceding the lockup/crash/interrupt error messages. There are none
immediately preceding any crash, but perhaps there is some correlation
between the network errors and bind ipv6 packets.
Jarek Poplawski
BTW, was there any other oops saved before this one?
...
> --- adapter dead after this --- rebooted.
> * no MMAP; alternative 1 patch, mtu=1500; no errors; sustained transfer
> rates about 25% lower than what I saw with mmap enabled...(before MMAP
> enabled crashed).
?? Read below...
> * no MMAP mtu=9000; ran ok at low transfer rates - when high rates
> kicked in, got the sky2 interrupt error & things went south:
> Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
> status=0x40000008
> After this, remote connections broke and I rebooted... decided to rerun
> w/o MMAP again before going back to MMAP and trying those other sky2
> options...
> * Retest of no MMAP + Alternative 1 - just to confirm consistency.
> Worked - no errors. Only version so far that allows the win7 backup to
> complete.
??? Hmm... Alternative 1 or 2 doesn't even compile into when no MMAP,
so it definitely needs re-retesting ;-)
> * MMAP + NO DMAR + disable_msi=1... also works w/o errors... leaving
> this one running for a while - also completed a backup successfully.
> Fastest of the lot... about 3x faster than any other version, working or
> not.
Very interesting. It would be nice to give it a really long try, and
if still true, try MMAP + NO DMAR only.
OK, for now let's make sure this MMAP + NO DMAR + disable_msi is
really really working.
Thanks,
Jarek P.
Michael Breuer
> On Thu, Jan 07, 2010 at 06:11:34PM -0500, Michael Breuer wrote:
>
>> Results:
>> Jan 7 15:44:44 mail kernel: Pid: 0, comm: swapper Tainted: G W
>>
> BTW, was there any other oops saved before this one?
>
> ...
>
>> --- adapter dead after this --- rebooted.
>> * no MMAP; alternative 1 patch, mtu=1500; no errors; sustained transfer
>> rates about 25% lower than what I saw with mmap enabled...(before MMAP
>> enabled crashed).
>>
> ?? Read below...
>
>
>> * no MMAP mtu=9000; ran ok at low transfer rates - when high rates
>> Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> Jan 7 15:09:28 mail kernel: sky2 0000:06:00.0: error interrupt
>> status=0x40000008
>> After this, remote connections broke and I rebooted... decided to rerun
>> w/o MMAP again before going back to MMAP and trying those other sky2
>> options...
>> * Retest of no MMAP + Alternative 1 - just to confirm consistency.
>> Worked - no errors. Only version so far that allows the win7 backup to
>> complete.
>>
> ??? Hmm... Alternative 1 or 2 doesn't even compile into when no MMAP,
> so it definitely needs re-retesting ;-)
>
something else is going on - some sort if intermittent thing that just
got caught there... have one thought - see below.
>
>> * MMAP + NO DMAR + disable_msi=1... also works w/o errors... leaving
>> this one running for a while - also completed a backup successfully.
>> Fastest of the lot... about 3x faster than any other version, working or
>> not.
>>
> Very interesting. It would be nice to give it a really long try, and
> if still true, try MMAP + NO DMAR only.
>
rate (RX) which seems to actually correlate with DNS format error
messages (ipv6 only). I spent some time tracking those down.
Interestingly, most pointed back to one netblock & one ISP (0qf.ru). I
blocked that domain and the errors expectedly dropped - as did the RX
dropped packet rate. Since booting this version yesterday eth0 shows
1752944 dropped packets. 1752939 of those happened before I blocked the
domain about 8 hours ago. I have run load tests since as well.
I think this dns activity is sendmail attempting to validate spam - but
not 100% sure yet as I can't correlate the .ru domain with anything
sendmail has reported. I'm running a sniffer now hoping to catch the
next one. I *think* but can't prove, that these are coming in via
sendmail - i.e., bad email, not even spam really - just enough to get a
system configured to do dns lookups as part of spam filtering to connect
to the server in question. What comes back would seem to be corrupt ipv6
packets.
This gets us back somewhat to Berck Nash's reported problem. His report
of sky2 failure was due to external attack. Could this be related? Is it
possible that absent some set of the patches & config settings in this
version that ipv6 bind activity involving corrupt (perhaps
intentionally) packets is breaking something?
Will try rerunning without disable_msi later (after I catch the dns
thing in the sniffer).
Still running :)
Jarek Poplawski
> On 1/8/2010 2:45 AM, Jarek Poplawski wrote:
> >On Thu, Jan 07, 2010 at 06:11:34PM -0500, Michael Breuer wrote:
> >??? Hmm... Alternative 1 or 2 doesn't even compile into when no MMAP,
> >so it definitely needs re-retesting ;-)
> I see your point. I'm pretty sure that run failed miserably. Perhaps
> something else is going on - some sort if intermittent thing that
> just got caught there... have one thought - see below.
It looks like very timing dependent and without MMAP it can work just
below limit, which could trigger those dmar or msi bugs. Anyway, it
seems to show there is no another serious bug in the MMAP part (i.e.
except the one fixed be alternative 1 or 2 patches).
Berck Nash reported oopses during sky2 TX timeout recovery, which are
generally hardware/driver problems, and shouldn't be triggered by ip
level bugs, so it should be queried as a separate bug report.
>
> Will try rerunning without disable_msi later (after I catch the dns
> thing in the sniffer).
> >>I'm leaving this one running for now. Not retesting jumbo for now. Be
> >>happy to help dig further.
> >>
> >>Tentative recommendations:
> >>
> >>1) The af alternative patch seems rather necessary. First alternative
> >>seems to be working, I'd suggest that be submitted and backported to
> >>2.6.32.
BTW, don't hurry with that yet, but in the next test, please try
alternative 2 again (i.e. with MMAP + no DMAR + disable_msi).
> >>2) Steven's pskb_may_pull patch also ought to be included and backported.
This patch is very helpful for debugging, but I doubt appropriate
for the mainline if it isn't triggered any more after 1) fix. But,
please keep it yourself for some time in all these tests (and of
course Berck Nash's patch).
> >OK, for now let's make sure this MMAP + NO DMAR + disable_msi is
> >really really working.
> Still running :)
Very nice :)