Bug#636797: linux-image-2.6.32-5-amd64: avoid divide-by-zero (divide error: 0000) in scheduler

2011-08-07 Thread Ben Hutchings
On Fri, 2011-08-05 at 18:36 -0400, Daniel Kahn Gillmor wrote:
 Package: linux-2.6
 Version: 2.6.32-35
 Tags: patch
 
 We've now seen multiple crashes during periods of heavy IO on amd64
 architecture machines running 2.6.32-5-amd64 from stock squeeze
 installs.
[...]
 This seems to be related to the kernel's upstream bug report:
 
   https://bugzilla.kernel.org/show_bug.cgi?id=16991
 
 It looks like ubuntu has done something to try to address the same bug
 in their linux-ec2 package in march:
 
  https://bugs.launchpad.net/linux/+bug/614853

Right.

 We've applied the attached patch (a simple workaround to ensure no
 division-by-zero) to the debian packages for several weeks in production
 (over a month on some machines) and haven't seen a recurrence of the
 problem.
 
 I recommend this patch for inclusion in debian's next bugfix release.  I
 welcome feedback on it, of course.
[...]

This doesn't really fix the bug - division by zero is just a symptom of
a more fundamental problem which has yet to be identified.  As a result,
it hasn't been accepted upstream and won't be accepted in Debian.

That said, I would consider applying a variant that WARNs before 'fixing
up' the zero divisor, as a *temporary* measure to aid in understanding
the bug (more like
https://bugzilla.kernel.org/show_bug.cgi?id=16991#c13).

I notice your 'oops' messages show 'Tainted: G W' which indicates there
was an earlier kernel warning.  What was the previous warning?

Ben.



signature.asc
Description: This is a digitally signed message part


Bug#636797: linux-image-2.6.32-5-amd64: avoid divide-by-zero (divide error: 0000) in scheduler

2011-08-07 Thread Daniel Kahn Gillmor
Hi Ben--

Thanks for the quick followup!

On 08/07/2011 12:36 PM, Ben Hutchings wrote:
 On Fri, 2011-08-05 at 18:36 -0400, Daniel Kahn Gillmor wrote:
 We've applied the attached patch (a simple workaround to ensure no
 division-by-zero) to the debian packages for several weeks in production
 (over a month on some machines) and haven't seen a recurrence of the
 problem.

 This doesn't really fix the bug - division by zero is just a symptom of
 a more fundamental problem which has yet to be identified.

yep, that's why i called it a workaround :)

 As a result,
 it hasn't been accepted upstream and won't be accepted in Debian.
 
 That said, I would consider applying a variant that WARNs before 'fixing
 up' the zero divisor, as a *temporary* measure to aid in understanding
 the bug (more like
 https://bugzilla.kernel.org/show_bug.cgi?id=16991#c13).

That sounds reasonable to me.  Are you up for preparing such a patch or
do you need me to do it?

 I notice your 'oops' messages show 'Tainted: G W' which indicates there
 was an earlier kernel warning.  What was the previous warning?

hmm, we've seen this on multiple machines, and they didn't all have a
prior warning.  in the referenced machine, though, it was 5 months
previously, a netdev watchdog timeout.  It doesn't seem related to me,
but i'm happy to include the dump here in case anyone else can extract
meaning from it:

 2011-01-04_10:28:18.85061 [3129874.324489] [ cut here 
 ]
 2011-01-04_10:28:18.89235 [3129874.329286] WARNING: at 
 /build/buildd-linux-2.6_2.6.32-28-amd64-EUJiNq/linux-2.6-2.6.32/debian/build/source_amd64_none/net/sched/sch_generic.c:261
  dev_watchdog+0xe2/0x194()
 2011-01-04_10:28:18.89236 [3129874.344808] Hardware name: PowerEdge R410
 2011-01-04_10:28:18.89237 [3129874.348981] NETDEV WATCHDOG: eth0 (bnx2): 
 transmit queue 1 timed out
 2011-01-04_10:28:18.89238 [3129874.355561] Modules linked in: btrfs 
 zlib_deflate crc32c libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat 
 jfs xfs exportfs reiserfs ext4 jbd2 crc16 ext2 bridge stp kvm_intel kvm tun 
 loop snd_pcm snd_timer snd soundcore snd_page_alloc dcdbas pcspkr psmouse 
 serio_raw evdev button power_meter processor ext3 jbd mbcache sha256_generic 
 aes_x86_64 aes_generic cbc dm_crypt dm_mod raid1 md_mod sd_mod crc_t10dif sg 
 sr_mod cdrom ata_generic uhci_hcd mpt2sas ehci_hcd thermal ata_piix 
 thermal_sys usbcore nls_base scsi_transport_sas libata scsi_mod bnx2 [last 
 unloaded: scsi_wait_scan]
 2011-01-04_10:28:18.89240 [3129874.408913] Pid: 0, comm: swapper Not tainted 
 2.6.32-5-amd64 #1
 2011-01-04_10:28:18.89240 [3129874.415063] Call Trace:
 2011-01-04_10:28:18.89242 [3129874.417740]  IRQ  [81261c12] ? 
 dev_watchdog+0xe2/0x194
 2011-01-04_10:28:18.89243 [3129874.424219]  [81261c12] ? 
 dev_watchdog+0xe2/0x194
 2011-01-04_10:28:18.89244 [3129874.430018]  [8104dd6c] ? 
 warn_slowpath_common+0x77/0xa3
 2011-01-04_10:28:18.89245 [3129874.436423]  [81261b30] ? 
 dev_watchdog+0x0/0x194
 2011-01-04_10:28:18.89246 [3129874.442131]  [8104ddf4] ? 
 warn_slowpath_fmt+0x51/0x59
 2011-01-04_10:28:18.89247 [3129874.448276]  [81041b41] ? 
 enqueue_task_fair+0x3e/0x82
 2011-01-04_10:28:18.89248 [3129874.454420]  [8103fbfa] ? 
 task_rq_lock+0x46/0x79
 2011-01-04_10:28:18.89249 [3129874.460132]  [8104a252] ? 
 try_to_wake_up+0x2a7/0x2b9
 2011-01-04_10:28:18.89250 [3129874.466191]  [81261b04] ? 
 netif_tx_lock+0x3d/0x69
 2011-01-04_10:28:18.89250 [3129874.471989]  [8124c97c] ? 
 netdev_drivername+0x3b/0x40
 2011-01-04_10:28:18.89251 [3129874.478132]  [81261c12] ? 
 dev_watchdog+0xe2/0x194
 2011-01-04_10:28:18.89252 [3129874.483930]  [8103a9cd] ? 
 __wake_up_common+0x44/0x72
 2011-01-04_10:28:18.89253 [3129874.489992]  [81057560] ? 
 cascade+0x5f/0x77
 2011-01-04_10:28:18.89253 [3129874.495278]  [8105a337] ? 
 run_timer_softirq+0x1c9/0x268
 2011-01-04_10:28:18.89254 [3129874.501594]  [81053aaf] ? 
 __do_softirq+0xdd/0x1a2
 2011-01-04_10:28:18.89256 [3129874.507398]  [8102419a] ? 
 lapic_next_event+0x18/0x1d
 2011-01-04_10:28:18.89256 [3129874.513458]  [81011cac] ? 
 call_softirq+0x1c/0x30
 2011-01-04_10:28:18.89257 [3129874.519166]  [8101322b] ? 
 do_softirq+0x3f/0x7c
 2011-01-04_10:28:18.89261 [3129874.524774]  [8105391e] ? 
 irq_exit+0x36/0x76
 2011-01-04_10:28:19.85162 [3129874.530164]  [81024c68] ? 
 smp_apic_timer_interrupt+0x87/0x95
 2011-01-04_10:28:19.85163 [3129874.536911]  [81011673] ? 
 apic_timer_interrupt+0x13/0x20
 2011-01-04_10:29:45.93714 x9d/0xb8 [processor]
 2011-01-04_10:29:45.93717 [3129874.551277]  [a01c024c] ? 
 acpi_idle_enter_c1+0x78/0xb8 [processor]
 2011-01-04_10:29:45.93718 [3129874.558550]  [81238f62] ? 
 cpuidle_idle_call+0x94/0xee
 2011-01-04_10:29:45.93719 [3129874.564695]  [8100feb1] ? 
 cpu_idle+0xa2/0xda

hth,

--dkg




Bug#636797: linux-image-2.6.32-5-amd64: avoid divide-by-zero (divide error: 0000) in scheduler

2011-08-07 Thread Ben Hutchings
On Sun, 2011-08-07 at 17:28 -0400, Daniel Kahn Gillmor wrote:
 Hi Ben--
 
 Thanks for the quick followup!
 
 On 08/07/2011 12:36 PM, Ben Hutchings wrote:
  On Fri, 2011-08-05 at 18:36 -0400, Daniel Kahn Gillmor wrote:
  We've applied the attached patch (a simple workaround to ensure no
  division-by-zero) to the debian packages for several weeks in production
  (over a month on some machines) and haven't seen a recurrence of the
  problem.
 
  This doesn't really fix the bug - division by zero is just a symptom of
  a more fundamental problem which has yet to be identified.
 
 yep, that's why i called it a workaround :)
 
  As a result,
  it hasn't been accepted upstream and won't be accepted in Debian.
  
  That said, I would consider applying a variant that WARNs before 'fixing
  up' the zero divisor, as a *temporary* measure to aid in understanding
  the bug (more like
  https://bugzilla.kernel.org/show_bug.cgi?id=16991#c13).
 
 That sounds reasonable to me.  Are you up for preparing such a patch or
 do you need me to do it?

I'm quite busy so if you could try to do it that would be helpful.

  I notice your 'oops' messages show 'Tainted: G W' which indicates there
  was an earlier kernel warning.  What was the previous warning?
 
 hmm, we've seen this on multiple machines, and they didn't all have a
 prior warning.  in the referenced machine, though, it was 5 months
 previously, a netdev watchdog timeout.  It doesn't seem related to me,
 but i'm happy to include the dump here in case anyone else can extract
 meaning from it:
[...]

Agreed.

Ben.



signature.asc
Description: This is a digitally signed message part


Bug#636797: linux-image-2.6.32-5-amd64: avoid divide-by-zero (divide error: 0000) in scheduler

2011-08-05 Thread Daniel Kahn Gillmor
Package: linux-2.6
Version: 2.6.32-35
Tags: patch

We've now seen multiple crashes during periods of heavy IO on amd64
architecture machines running 2.6.32-5-amd64 from stock squeeze
installs.

An example crash [0] yields a backtrace like this:

2011-06-26_12:46:14.63097 [62478.818625] divide error:  [#1] SMP 
2011-06-26_12:46:14.68003 [62478.822564] last sysfs file: 
/sys/devices/pci:00/:00:1e.0/:04:03.0/class
2011-06-26_12:46:14.68004 [62478.830287] CPU 0 
2011-06-26_12:46:14.68005 [62478.832304] Modules linked in: rng_core btrfs 
zlib_deflate crc32c libcrc32c ufs qnx4 hfsplus hfs minix ntfs vfat msdos fat 
jfs xfs exportfs reiserfs ext4 
jbd2 crc16 ext2 bridge stp kvm_intel kvm tun loop snd_pcm snd_timer snd 
soundcore snd_page_alloc dcdbas pcspkr psmouse serio_raw evdev button 
power_meter processor ext3 jbd mbcache sh
a256_generic aes_x86_64 aes_generic cbc dm_crypt dm_mod raid1 md_mod sd_mod 
crc_t10dif sg sr_mod cdrom ata_generic uhci_hcd mpt2sas ehci_hcd thermal 
ata_piix thermal_sys usbcore nls_b
ase scsi_transport_sas libata scsi_mod bnx2 [last unloaded: scsi_wait_scan]
2011-06-26_12:46:14.68007 [62478.885126] Pid: 32653, comm: kvm Tainted: G   
 W  2.6.32-5-amd64 #1 PowerEdge R410
2011-06-26_12:46:14.68008 [62478.893108] RIP: 0010:[81044d3a]  
[81044d3a] find_busiest_group+0x3d0/0x876
2011-06-26_12:46:14.68009 [62478.901803] RSP: 0018:8804c5a8ba68  EFLAGS: 
00010046
2011-06-26_12:46:14.68010 [62478.907101] RAX:  RBX: 
 RCX: 8103a601
2011-06-26_12:46:14.68012 [62478.914219] RDX:  RSI: 
 RDI: 0200
2011-06-26_12:46:14.68013 [62478.921334] RBP: 88044e40fd50 R08: 
 R09: 88083e4400b0
2011-06-26_12:46:14.68014 [62478.928449] R10: 880298c3a8b8 R11: 
a0253fb7 R12: 00015780
2011-06-26_12:46:14.68014 [62478.935565] R13:  R14: 
0001 R15: 88083e440060
2011-06-26_12:46:14.68015 [62478.942683] FS:  7f995a599700() 
GS:88044e40() knlGS:
2011-06-26_12:46:14.68016 [62478.950753] CS:  0010 DS: 002b ES: 002b CR0: 
80050033
2011-06-26_12:46:14.68017 [62478.956483] CR2: 7f80157a6000 CR3: 
000393285000 CR4: 26e0
2011-06-26_12:46:14.68018 [62478.963601] DR0:  DR1: 
 DR2: 
2011-06-26_12:46:14.68019 [62478.970716] DR3:  DR6: 
0ff0 DR7: 0400
2011-06-26_12:46:14.68020 [62478.977833] Process kvm (pid: 32653, threadinfo 
8804c5a8a000, task 88083e67a350)
2011-06-26_12:46:14.68021 [62478.985901] Stack:
2011-06-26_12:46:14.68021 [62478.987907]  00015788 00015780 
0008 00015780
2011-06-26_12:46:14.68022 [62478.995142] 0 00015780 00015780 
813cd8a8 8106fde3
2011-06-26_12:46:14.68027 [62479.002834] 0  88001d1e8e10 
88044e410108 88044e40f9e0
2011-06-26_12:46:14.68027 [62479.010711] Call Trace:
2011-06-26_12:46:14.68028 [62479.013157]  [8106fde3] ? 
tick_dev_program_event+0x2d/0x95
2011-06-26_12:46:14.68029 [62479.019496]  [81067b20] ? 
__hrtimer_start_range_ns+0x22f/0x242
2011-06-26_12:46:14.68030 [62479.026183]  [812f9b40] ? 
schedule+0x2bd/0x7cb
2011-06-26_12:46:14.68030 [62479.031491]  [a02856ec] ? 
x86_emulate_insn+0x1f08/0x2fc4 [kvm]
2011-06-26_12:46:14.68031 [62479.038184]  [a026d858] ? 
kvm_vcpu_block+0x94/0xb4 [kvm]
2011-06-26_12:46:14.68032 [62479.044349]  [81064bee] ? 
autoremove_wake_function+0x0/0x2e
2011-06-26_12:46:14.68033 [62479.050781]  [a0278127] ? 
kvm_arch_vcpu_ioctl_run+0x80b/0xa44 [kvm]
2011-06-26_12:46:14.68033 [62479.057901]  [8104a252] ? 
try_to_wake_up+0x2a7/0x2b9
2011-06-26_12:46:14.68034 [62479.063719]  [8107188f] ? 
wake_futex+0x31/0x4e
2011-06-26_12:46:14.68035 [62479.069024]  [a026a9d1] ? 
kvm_vcpu_ioctl+0xf1/0x4e6 [kvm]
2011-06-26_12:46:14.68035 [62479.075275]  [81067b20] ? 
__hrtimer_start_range_ns+0x22f/0x242
2011-06-26_12:46:14.68036 [62479.081964]  [810fa492] ? 
vfs_ioctl+0x21/0x6c
2011-06-26_12:46:14.68038 [62479.087176]  [810fa9e0] ? 
do_vfs_ioctl+0x48d/0x4cb
2011-06-26_12:46:14.68039 [62479.092822]  [81073c0a] ? 
sys_futex+0x113/0x131
2011-06-26_12:46:14.68039 [62479.098210]  [8451] ? 
block_llseek+0x75/0x81
2011-06-26_12:46:14.68040 [62479.103681]  [810faa6f] ? 
sys_ioctl+0x51/0x70
2011-06-26_12:46:14.68041 [62479.108894]  [81010b42] ? 
system_call_fastpath+0x16/0x1b
2011-06-26_12:46:14.68042 [62479.115056] Code: bc 24 a0 01 00 00 00 74 10 48 8b 
94 24 a0 01 00 00 c7 02 00 00 00 00 eb 65 41 8b 77 08 48 8b 84 24 38 01 00 00 
31 d2 48 c1 e0 0a 48 f7 f6 48 8b b4 24 40 01 00 00 48 89 84 24 30 01 00 00 31 
c0 
2011-06-26_12:46:14.68042 [62479.134577] RIP  [81044d3a] 
find_busiest_group+0x3d0/0x876