On Mon, Mar 28, 2011 at 6:38 PM, Sedat Dilek <sedat.dilek@xxxxxxxxxxxxxx> wrote: > On Mon, Mar 28, 2011 at 5:11 PM, Paul E. McKenney > <paulmck@xxxxxxxxxxxxxxxxxx> wrote: >> On Mon, Mar 28, 2011 at 06:24:36AM -0700, Paul E. McKenney wrote: >>> On Mon, Mar 28, 2011 at 02:33:36PM +0200, Sedat Dilek wrote: >>> > On Mon, Mar 28, 2011 at 6:08 AM, Paul E. McKenney >>> > <paulmck@xxxxxxxxxxxxxxxxxx> wrote: >>> > > On Sun, Mar 27, 2011 at 11:48:30PM +0200, Sedat Dilek wrote: >>> > >> On Sun, Mar 27, 2011 at 11:32 PM, Paul E. McKenney >>> > >> <paulmck@xxxxxxxxxxxxxxxxxx> wrote: >>> > >> > On Sun, Mar 27, 2011 at 02:26:15PM +0200, Sedat Dilek wrote: >>> > >> >> On Sun, Mar 27, 2011 at 7:07 AM, Paul E. McKenney >>> > >> >> <paulmck@xxxxxxxxxxxxxxxxxx> wrote: >>> > >> >> > On Sat, Mar 26, 2011 at 08:25:29PM -0700, Paul E. McKenney wrote: >>> > >> >> >> On Sun, Mar 27, 2011 at 03:30:34AM +0200, Sedat Dilek wrote: >>> > >> >> >> > On Sun, Mar 27, 2011 at 1:09 AM, Paul E. McKenney >>> > >> >> >> > <paulmck@xxxxxxxxxxxxxxxxxx> wrote: >>> > >> >> >> > > On Sat, Mar 26, 2011 at 11:15:22PM +0100, Sedat Dilek wrote: >>> > >> >> > >>> > >> >> > [ . . . ] >>> > >> >> > >>> > >> >> >> > >> But then came RCU :-(. >>> > >> >> >> > > >>> > >> >> >> > > Well, if it turns out to be a problem in RCU I will certainly apologize. >>> > >> >> >> > > >>> > >> >> >> > >>> > >> >> >> > No, that's not so dramatic. >>> > >> >> >> > Dealing with this RCU issue has nice side-effects: I remembered (and >>> > >> >> >> > finally did) to use a reduced kernel-config set. >>> > >> >> >> > The base for it I created with 'make localmodconfig' and did some >>> > >> >> >> > manual fine-tuning afterwards (throw out media, rc, dvd, unneeded FSs, >>> > >> >> >> > etc.). >>> > >> >> >> > Also, I can use fresh gcc-4.6 (4.6.0-1) from the official Debian repos. >>> > >> >> >> > >>> > >> >> >> > So, I started building with >>> > >> >> >> > "revert-rcu-patches/0001-Revert-rcu-introduce-kfree_rcu.patch". >>> > >> >> >> > I will let you know. >>> > >> >> >> >>> > >> >> >> And please also check for tasks consuming all available CPU. >>> > >> >> > >>> > >> >> > And I still cannot reproduce with the full RCU stack (but based off of >>> > >> >> > 2.6.38 rather than -next). ÂNevertheless, if you would like to try a >>> > >> >> > speculative patch, here you go. >>> > >> >> >>> > >> >> You are right and my strategy on handling the (possible RCU?) issue is wrong. >>> > >> >> Surely, you tested your RCU stuff in your own repo and everything >>> > >> >> might be OK on top of stable 2.6.38. >>> > >> >> Linux-next gets daily updates from a lot of different trees, so there >>> > >> >> might be interferences with other stuff. >>> > >> >> Please, understand I am interested in finding out what is the cause >>> > >> >> for my issues, my aim is not to blame you. >>> > >> > >>> > >> > I am not worried about blame, but rather getting the bug fixed. ÂThe >>> > >> > bug might be in RCU, it might be elsewhere, or it might be a combination >>> > >> > of problems in RCU and elsewhere. >>> > >> > >>> > >> > So the first priority is locating the bug. >>> > >> > >>> > >> > And that is why I have been asking you over and over to PLEASE take >>> > >> > a look at what tasks are consuming CPU while the problem is occuring. >>> > >> > The reason that I have been asking over and over is that the symptoms >>> > >> > you describe are likely caused by a loop in some kernel code. ÂYes, >>> > >> > there might be other causes, but this is the most likely. ÂGiven that >>> > >> > TREE_PREEMPT_RCU behaves better than TREE_RCU, it is likely that this >>> > >> > loop is in preemptible code with irqs enabled. ÂTherefore, the process >>> > >> > accounting code is likely to be able to see the CPU consumption, and >>> > >> > you should be able to see it via the "top" or "ps" commands -- or via >>> > >> > any number of other tools. >>> > >> > >>> > >> > For example, if the problem is confined to RCU, you would likely see >>> > >> > the "rcuc0" or "rcun0" tasks consuming lots of CPU. ÂThis would narrow >>> > >> > the problem down to a few tens of lines of code. ÂIf the problem was >>> > >> > in some other kthread, then identifying the kthread would very likely >>> > >> > narrow things down as well. >>> > >> > >>> > >> > So, please do take a look to see what taks consuming CPU. >>> > >> > >>> > >> >> As I was wrong and want to be 99.9% sure it is RCU stuff, I reverted >>> > >> >> all (18) RCU patches from linux-next (next-20110325) by keeping the >>> > >> >> RCU|PREEMPT|HZ settings from last working next-20110323. >>> > >> > >>> > >> > Makes sense. >>> > >> > >>> > >> >> $ egrep 'RCU|PREEMPT|_HZ' /boot/config-2.6.38-next20110325-7-686-iniza >>> > >> >> # RCU Subsystem >>> > >> >> CONFIG_TREE_RCU=y >>> > >> >> # CONFIG_PREEMPT_RCU is not set >>> > >> >> # CONFIG_RCU_TRACE is not set >>> > >> >> CONFIG_RCU_FANOUT=32 >>> > >> >> # CONFIG_RCU_FANOUT_EXACT is not set >>> > >> >> CONFIG_RCU_FAST_NO_HZ=y >>> > >> >> # CONFIG_TREE_RCU_TRACE is not set >>> > >> >> CONFIG_PREEMPT_NOTIFIERS=y >>> > >> >> CONFIG_NO_HZ=y >>> > >> >> # CONFIG_PREEMPT_NONE is not set >>> > >> >> CONFIG_PREEMPT_VOLUNTARY=y >>> > >> >> # CONFIG_PREEMPT is not set >>> > >> >> # CONFIG_HZ_100 is not set >>> > >> >> CONFIG_HZ_250=y >>> > >> >> # CONFIG_HZ_300 is not set >>> > >> >> # CONFIG_HZ_1000 is not set >>> > >> >> CONFIG_HZ=250 >>> > >> >> # CONFIG_SPARSE_RCU_POINTER is not set >>> > >> >> # CONFIG_RCU_TORTURE_TEST is not set >>> > >> >> # CONFIG_RCU_CPU_STALL_DETECTOR is not set >>> > >> >> >>> > >> >> I will work and stress this kernel before doing any step-by-step >>> > >> >> revert of RCU stuff. >>> > >> >> >>> > >> >> Thanks for your patch, I applied it on top of "naked" next-20110325, >>> > >> >> but I still see call-traces. >>> > >> > >>> > >> > Thank you very much for testing it! >>> > >> > >>> > >> > I intend to keep that patch, as it should increase robustness in other >>> > >> > situations. >>> > >> > >>> > >> > Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â ÂThanx, Paul >>> > >> > >>> > >> >> - Sedat - >>> > >> >> >>> > >> >> >>> > >> >> >>> > >> >> > Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â ÂThanx, Paul >>> > >> >> > >>> > >> >> > ------------------------------------------------------------------------ >>> > >> >> > >>> > >> >> > rcu: further lower priority in rcu_yield() >>> > >> >> > >>> > >> >> > Although rcu_yield() dropped from real-time to normal priority, there >>> > >> >> > is always the possibility that the competing tasks have been niced. >>> > >> >> > So nice to 19 in rcu_yield() to help ensure that other tasks have a >>> > >> >> > better chance of running. >>> > >> >> > >>> > >> >> > Â ÂSigned-off-by: Paul E. McKenney <paulmck@xxxxxxxxxxxxxxxxxx> >>> > >> >> > >>> > >> >> > diff --git a/kernel/rcutree.c b/kernel/rcutree.c >>> > >> >> > index 759f54b..5477764 100644 >>> > >> >> > --- a/kernel/rcutree.c >>> > >> >> > +++ b/kernel/rcutree.c >>> > >> >> > @@ -1492,6 +1492,7 @@ static void rcu_yield(void (*f)(unsigned long), unsigned long arg) >>> > >> >> > Â Â Â Âmod_timer(&yield_timer, jiffies + 2); >>> > >> >> > Â Â Â Âsp.sched_priority = 0; >>> > >> >> > Â Â Â Âsched_setscheduler_nocheck(current, SCHED_NORMAL, &sp); >>> > >> >> > + Â Â Â set_user_nice(current, 19); >>> > >> >> > Â Â Â Âschedule(); >>> > >> >> > Â Â Â Âsp.sched_priority = RCU_KTHREAD_PRIO; >>> > >> >> > Â Â Â Âsched_setscheduler_nocheck(current, SCHED_FIFO, &sp); >>> > >> >>> > >> Sorry, my attempt was to identify and isolate the culprit commit. >>> > >> >>> > >> Reverting all RCU patches resulted in a stable system, the following 8 >>> > >> kernels with reduced k-config setup where all built using this kernel. >>> > >> >>> > >> All kernels used TREE_RCU (see above), I did not change it (no >>> > >> mixing/switching to PREEMPT and TREE_PREEMPT_RCU). >>> > >> ( I doubt that TREE_PREEMPT_RCU was some kind of more stable here. ) >>> > >> >>> > >> The culprit commit is bc56163ebd4580199ac7e63f5e160bf139ba0dd6 (from >>> > >> rcu/next GIT tree): >>> > >> "rcu: move TREE_RCU from softirq to kthread" >>> > > >>> > >>> > Hi Paul, >>> > >>> > > OK, please accept my apologies for your lost weekend. ÂAnd thank you for >>> > > testing this. >>> > > >>> > >>> > No worries, it was mostly a rainy day. >>> > The only thing I did @ 16:30 was to go to regional election (the new >>> > (regional) prime minister will be the 1st from The German Green >>> > party). >>> >>> ;-) >>> >>> > But back to RCU :-): >>> > The reduced kernel-config setup decreased the build-time from approx. >>> > 2hrs (full, generic build) down to approx. 35mins. >>> >>> Very good! >>> >>> > >> I can do parallelly a tar job, open 20 tabs in firefox and run a flash >>> > >> video in one of them (I did this several times). >>> > > >>> > > How many files in the tar job? ÂIs this creating a tar archive, expanding >>> > > it, or both? >>> > >>> > I am doing a simple tar (filesize: 1.6G for full and 1.0G for reduced build): >>> > >>> > $ tar -cf $archivedir-on-external-usbhdd/$tarfile $kernel-build-dir >>> >>> OK, I was extracting a tarball and then removing the resulting source >>> tree. ÂI will try this. ÂThough it does seem strange -- I can understand >>> how removing a file tree would stress RCU, but not creating a tarball. >>> Ah, well, if I fully understood it, there would not be a bug. >>> >>> > ...plus parallelly opening 20 tabs in firefox. >>> > That's normally enough to get my system freaky and see RCU related >>> > messages in the logs. >>> >>> Hmmm... ÂMy normal test systems don't have X -- I will need to set >>> this up. >>> >>> > > Do you have a script for this? ÂAre all of these running at normal >>> > > priority, or are some of them running at real-time priority? >>> > > >>> > >>> > Nothing special. >>> >>> OK. >>> >>> > >> [ setup.log ] >>> > >> ... >>> > >> Â (+) OK Â revert-rcu-patches/0001-Revert-rcu-introduce-kfree_rcu.patch >>> > >> Â (+) OK Â revert-rcu-patches/0002-Revert-rcu-fix-spelling.patch >>> > >> Â (+) OK Â revert-rcu-patches/0003-Revert-rcu-fix-rcu_cpu_kthread_task-synchronization.patch >>> > >> Â (+) OK Â revert-rcu-patches/0004-Revert-rcu-call-__rcu_read_unlock-in-exit_rcu-for-tr.patch >>> > >> Â (+) OK Â revert-rcu-patches/0005-Revert-rcu-Converge-TINY_RCU-expedited-and-normal-bo.patch >>> > >> Â (+) OK Â revert-rcu-patches/0006-Revert-rcu-remove-useless-boosted_this_gp-field.patch >>> > >> Â (+) OK Â revert-rcu-patches/0007-Revert-rcu-code-cleanups-in-TINY_RCU-priority-boosti.patch >>> > >> Â (+) OK Â revert-rcu-patches/0008-Revert-rcu-Switch-to-this_cpu-primitives.patch >>> > >> Â (+) OK Â revert-rcu-patches/0009-Revert-rcu-Use-WARN_ON_ONCE-for-DEBUG_OBJECTS_RCU_HE.patch >>> > >> Â (+) OK Â revert-rcu-patches/0010-Revert-rcu-Enable-DEBUG_OBJECTS_RCU_HEAD-from-PREEMP.patch >>> > >> Â (+) OK Â revert-rcu-patches/0011-Revert-rcu-Add-boosting-to-TREE_PREEMPT_RCU-tracing.patch >>> > >> Â (+) OK Â revert-rcu-patches/0012-Revert-rcu-eliminate-unused-boosting-statistics.patch >>> > >> Â (+) OK Â revert-rcu-patches/0013-Revert-rcu-priority-boosting-for-TREE_PREEMPT_RCU.patch >>> > >> Â (+) OK Â revert-rcu-patches/0014-Revert-rcu-move-TREE_RCU-from-softirq-to-kthread.patch >>> > >> ... >>> > >> >>> > >> Hope this helps to narrow down the problem. >>> > >> >>> > >> As I kept all kernels I can have a look at the tasks consuming high >>> > >> CPU usage tomorrow. >>> > > >>> > > Could you please? >>> > >>> > I recalled (as you say I requested over and over again from you :-)) I >>> > looked with top, htop and 'ps axu', but there was nothing special. >>> > Sometimes the system got frozen - at this point (or short before) I >>> > did not see anything suspicious with top. >>> >>> OK, thank you for the info. >>> >>> > > Also, could you please mount debugfs and list out the files in the >>> > > "rcu" directory? ÂThe "ql=" value from the "rcu/rcudata" file is of >>> > > particular interest. >>> > > >>> > >>> > Ah, before I forget... >>> > >>> > I used TREE_RCU (was the default before noticing RCU issue) for >>> > finding the culprit commit. >>> > If it is from your POV more helpful to switch to PREEMPT + PREEMPT_RCU >>> > + RCU_BOOST, please let me *now* know. >>> > ( Both RCU setups freaks up the system. ) >>> >>> If TREE_RCU hits problems faster, it is probably best to stay with >>> TREE_RCU. >> >> And of course, one exception to this advice is if TREE_RCU hangs so hard >> and fast that you don't have time to get any diagnostics. ÂIf this is the >> case, then TREE_PREEMPT_RCU might be more productive. >> > > OK, that would somehow explain why I could not really get some debug > infos when doing "my stress-test" and checking via: > > $ LC_ALL=C tail -f /sys/kernel/debug/rcu/rcudata > > Then I remembered I saw a snippet for a RCU torture script mentionned > in the kernel-docs (see Documentation/RCU/torture.txt). > > 189 The following script may be used to torture RCU: > 190 > 191 Â Â Â Â #!/bin/sh > 192 > 193 Â Â Â Â modprobe rcutorture > 194 Â Â Â Â sleep 100 > 195 Â Â Â Â rmmod rcutorture > 196 Â Â Â Â dmesg | grep torture: > > So, I recompiled a new TREE_RC-based kernel and build with > CONFIG_RCU_TORTURE_TEST=m. > > Unfortunately, the rmmod (I prefer modprobe -r -v) hangs... the > messages in the logs look promising. > > - Sedat - > Wrong attachment, correct attached. - Sedat - > > >> Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â ÂThanx, Paul >> >>> > I think top & Co. are not enough to track the problem down. >>> > I have seen tracing and debugging facililities for RCU. >>> > >>> > Some questions to debug and trace setup: >>> > >>> > Case #1: TREE_RCU >>> > >>> > CONFIG_RCU_TRACE=y >>> > CONFIG_TREE_RCU_TRACE=y >>> >>> Yep. >>> >>> > Case #2: PREEMPT + PREEMPT_RCU + RCU_BOOST >>> > >>> > CONFIG_RCU_TRACE=y >>> > CONFIG_TREE_RCU_TRACE=y >>> > CONFIG_DEBUG_PREEMPT=y <--- Helpful? >>> > CONFIG_PREEMPT_TRACER=y <--- Helpful? >>> > >>> > Any other recommends for useful/helpful trace and/or debug options? >>> > >>> > Any other intructions for debugging/tracing? >>> >>> Not at the moment. ÂI will be looking at diagnostics will going >>> through the code, so might have something later. >>> >>> > BTW, today's linux-next (next-20110328) is still freaky, I applied the >>> > revert-rcu-patches patchset and all is fine. >>> >>> I reverted back to the commit preceding the one you pointed out last night >>> my time, so the upcoming -next should be less freaky. >>> >>> > - Sedat - >>> > >>> > P.S.: Note to myself >>> > >>> > # mount -t debugfs none /sys/kernel/debug/ >>> > # ln -s /sys/kernel/debug /debug >>> > >>> > # find /debug -name rcu >>> >>> Or: >>> >>> # cd /debug/rcu >>> >>> then dump out everything except for the .csv file (which is the same >>> as the non-.csv equivalent, but in spreadsheet format -- intended >>> for systems with 100s or 1000s of CPUs). >>> >>> Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Â Thanx, Paul >> >
Mar 28 18:09:03 tbox kernel: [ 145.596004] INFO: rcu_sched_state detected stall on CPU 0 (t=15000 jiffies) Mar 28 18:09:03 tbox kernel: [ 145.596004] sending NMI to all CPUs: Mar 28 18:09:03 tbox kernel: [ 145.596004] NMI backtrace for cpu 0 Mar 28 18:09:03 tbox kernel: [ 145.596004] Modules linked in: rcutorture acpi_cpufreq mperf cpufreq_powersave cpufreq_userspace cpufreq_stats cpufreq_conservative ppdev lp aes_i586 aes_generic rfcomm bnep bluetooth binfmt_misc fuse snd_intel8x0m snd_intel8x0 snd_ac97_codec radeon ac97_bus snd_pcm_oss arc4 snd_mixer_oss ecb ath5k joydev snd_pcm thinkpad_acpi pcmcia snd_seq_midi ath ttm mac80211 snd_rawmidi drm_kms_helper drm cfg80211 yenta_socket snd_seq_midi_event pcmcia_rsrc snd_seq pcmcia_core snd_timer i2c_algo_bit rfkill snd_seq_device psmouse snd nsc_ircc tpm_tis parport_pc battery ac pcspkr tpm irda i2c_i801 shpchp serio_raw tpm_bios soundcore processor i2c_core evdev pci_hotplug snd_page_alloc crc_ccitt parport nvram power_supply video button ext4 mbcache jbd2 crc16 dm_mod usbhid hid usb_storage uas sg sr_mod sd_mod cdrom crc_t10dif ata_generic ata_piix uhci_hcd libata ehci_hcd scsi_mod usbcore e1000 thermal thermal_sys floppy [last unloaded: scsi_wait_scan] Mar 28 18:09:03 tbox kernel: [ 145.596004] Mar 28 18:09:03 tbox kernel: [ 145.596004] Pid: 1659, comm: rcu_torture_rea Not tainted 2.6.38-next20110328-3-686-iniza #1 IBM 2374SG6/2374SG6 Mar 28 18:09:03 tbox kernel: [ 145.596004] EIP: 0060:[<c114b8d6>] EFLAGS: 00000046 CPU: 0 Mar 28 18:09:03 tbox kernel: [ 145.596004] EIP is at paravirt_read_tsc+0x6/0xd Mar 28 18:09:03 tbox kernel: [ 145.596004] EAX: 99652d8e EBX: 99652d00 ECX: 00000000 EDX: 0000002c Mar 28 18:09:03 tbox kernel: [ 145.596004] ESI: 00000000 EDI: 0019a58a EBP: f5075ddc ESP: f5075dd8 Mar 28 18:09:03 tbox kernel: [ 145.596004] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 Mar 28 18:09:03 tbox kernel: [ 145.596004] Process rcu_torture_rea (pid: 1659, ti=f5074000 task=f637d400 task.ti=f5074000) Mar 28 18:09:03 tbox kernel: [ 145.596004] Stack: Mar 28 18:09:03 tbox kernel: [ 145.596004] 0019a58a f5075df4 c114b972 0019a589 00002710 c13d7500 c13d7580 f5075dfc Mar 28 18:09:03 tbox kernel: [ 145.596004] c114b90f f5075e04 c114b92b f5075e10 c10164ca c13d7500 f5075e2c c1074e8d Mar 28 18:09:03 tbox kernel: [ 145.596004] c133c4ef c133c5be 00000000 00003a98 f6403488 f5075e40 c1074f02 00000000 Mar 28 18:09:03 tbox kernel: [ 145.596004] Call Trace: Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b972>] delay_tsc+0x28/0x5e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b90f>] __delay+0x9/0xb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1015892>] smp_apic_timer_interrupt+0x5b/0x6e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1297789>] apic_timer_interrupt+0x31/0x38 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10300e0>] ? resume_console+0x3/0x27 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b8d6>] ? paravirt_read_tsc+0x6/0xd Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b972>] delay_tsc+0x28/0x5e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b90f>] __delay+0x9/0xb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e23fa>] rcu_read_delay+0x2f/0x59 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e2c77>] rcu_torture_reader+0xf5/0x1c4 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e250a>] ? rcu_torture_shuffle_tasks+0xe6/0xe6 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e2b82>] ? rcu_torture_writer+0x171/0x171 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10444f6>] kthread+0x62/0x67 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1044494>] ? kthread_worker_fn+0x111/0x111 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c129ca7e>] kernel_thread_helper+0x6/0xd Mar 28 18:09:03 tbox kernel: [ 145.596004] Code: 02 72 11 66 8b 16 8d 76 02 66 89 17 8d 7f 02 74 07 c1 e2 10 8a 16 88 17 01 d0 83 d0 00 5e 5f 5b c3 90 90 90 90 55 89 e5 57 0f 31 <8d> 74 26 00 5f 5d c3 55 89 e5 85 c0 74 1f eb 0a 8d 76 00 8d bc Mar 28 18:09:03 tbox kernel: [ 145.596004] Call Trace: Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b972>] delay_tsc+0x28/0x5e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b90f>] __delay+0x9/0xb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1015892>] smp_apic_timer_interrupt+0x5b/0x6e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1297789>] apic_timer_interrupt+0x31/0x38 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10300e0>] ? resume_console+0x3/0x27 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b8d6>] ? paravirt_read_tsc+0x6/0xd Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b972>] delay_tsc+0x28/0x5e Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b90f>] __delay+0x9/0xb Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e23fa>] rcu_read_delay+0x2f/0x59 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e2c77>] rcu_torture_reader+0xf5/0x1c4 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e250a>] ? rcu_torture_shuffle_tasks+0xe6/0xe6 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<f82e2b82>] ? rcu_torture_writer+0x171/0x171 [rcutorture] Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c10444f6>] kthread+0x62/0x67 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c1044494>] ? kthread_worker_fn+0x111/0x111 Mar 28 18:09:03 tbox kernel: [ 145.596004] [<c129ca7e>] kernel_thread_helper+0x6/0xd Mar 28 18:12:03 tbox kernel: [ 325.716030] INFO: rcu_sched_state detected stall on CPU 0 (t=60030 jiffies) Mar 28 18:12:03 tbox kernel: [ 325.720011] sending NMI to all CPUs: Mar 28 18:12:03 tbox kernel: [ 325.720011] NMI backtrace for cpu 0 Mar 28 18:12:03 tbox kernel: [ 325.720011] Modules linked in: rcutorture(-) acpi_cpufreq mperf cpufreq_powersave cpufreq_userspace cpufreq_stats cpufreq_conservative ppdev lp aes_i586 aes_generic rfcomm bnep bluetooth binfmt_misc fuse snd_intel8x0m snd_intel8x0 snd_ac97_codec radeon ac97_bus snd_pcm_oss arc4 snd_mixer_oss ecb ath5k joydev snd_pcm thinkpad_acpi pcmcia snd_seq_midi ath ttm mac80211 snd_rawmidi drm_kms_helper drm cfg80211 yenta_socket snd_seq_midi_event pcmcia_rsrc snd_seq pcmcia_core snd_timer i2c_algo_bit rfkill snd_seq_device psmouse snd nsc_ircc tpm_tis parport_pc battery ac pcspkr tpm irda i2c_i801 shpchp serio_raw tpm_bios soundcore processor i2c_core evdev pci_hotplug snd_page_alloc crc_ccitt parport nvram power_supply video button ext4 mbcache jbd2 crc16 dm_mod usbhid hid usb_storage uas sg sr_mod sd_mod cdrom crc_t10dif ata_generic ata_piix uhci_hcd libata ehci_hcd scsi_mod usbcore e1000 thermal thermal_sys floppy [last unloaded: scsi_wait_scan] Mar 28 18:12:03 tbox kernel: [ 325.720011] Mar 28 18:12:03 tbox kernel: [ 325.720011] Pid: 0, comm: swapper Not tainted 2.6.38-next20110328-3-686-iniza #1 IBM 2374SG6/2374SG6 Mar 28 18:12:03 tbox kernel: [ 325.720011] EIP: 0060:[<c114b94a>] EFLAGS: 00000807 CPU: 0 Mar 28 18:12:03 tbox kernel: [ 325.720011] EIP is at delay_tsc+0x0/0x5e Mar 28 18:12:03 tbox kernel: [ 325.720011] EAX: 00090d40 EBX: 00002710 ECX: c132e541 EDX: 00090d3f Mar 28 18:12:03 tbox kernel: [ 325.720011] ESI: c13d7500 EDI: c13d7580 EBP: f6019ea4 ESP: f6019ea0 Mar 28 18:12:03 tbox kernel: [ 325.720011] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 Mar 28 18:12:03 tbox kernel: [ 325.720011] Process swapper (pid: 0, ti=f6018000 task=c13ccfa0 task.ti=c13a0000) Mar 28 18:12:03 tbox kernel: [ 325.720011] Stack: Mar 28 18:12:03 tbox kernel: [ 325.720011] c114b90f f6019eac c114b92b f6019eb8 c10164ca c13d7500 f6019ed4 c1074e8d Mar 28 18:12:03 tbox kernel: [ 325.720011] c133c4ef c133c5be 00000000 0000ea7e f6403488 f6019ee8 c1074f02 00000000 Mar 28 18:12:03 tbox kernel: [ 325.720011] 00000000 c13ccfa0 f6019ef4 c10752ab 00000000 f6019f08 c1039c2c c13a1ef8 Mar 28 18:12:03 tbox kernel: [ 325.720011] Call Trace: Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c114b90f>] ? __delay+0x9/0xb Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:12:03 tbox kernel: [ 325.720011] <IRQ> Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:12:03 tbox kernel: [ 325.720011] Code: d2 3e f7 e2 8d 42 01 e8 db ff ff ff 5d c3 69 c0 c7 10 00 00 55 89 e5 e8 d6 ff ff ff 5d c3 55 89 e5 8d 04 80 e8 c9 ff ff ff 5d c3 Mar 28 18:12:03 tbox kernel: [ 325.720011] Call Trace: Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c114b90f>] ? __delay+0x9/0xb Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c114b92b>] __const_udelay+0x1a/0x1c Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:12:03 tbox kernel: [ 325.720011] <IRQ> [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:12:03 tbox kernel: [ 325.720011] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:12:37 tbox kernel: [ 360.304066] INFO: task modprobe:1662 blocked for more than 120 seconds. Mar 28 18:12:37 tbox kernel: [ 360.314213] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 28 18:12:37 tbox kernel: [ 360.324527] modprobe D f5127ea4 0 1662 1651 0x00000000 Mar 28 18:12:37 tbox kernel: [ 360.335003] f5127e98 00000082 f594ac00 f5127ea4 c145d380 ed715c1f 0000002a c145d380 Mar 28 18:12:37 tbox kernel: [ 360.345745] 00000000 00000000 f594ac00 f637dc00 0000002a f594ac00 ffffffff ffffffff Mar 28 18:12:37 tbox kernel: [ 360.356521] f5127ed8 ed715020 f64063c4 ed715c1f 00000000 3d090000 00000000 f594ac2c Mar 28 18:12:37 tbox kernel: [ 360.367389] Call Trace: Mar 28 18:12:37 tbox kernel: [ 360.378083] [<c10215b4>] ? wakeup_preempt_entity+0x36/0x53 Mar 28 18:12:37 tbox kernel: [ 360.388915] [<c1295ed0>] schedule_timeout+0x21/0xaa Mar 28 18:12:37 tbox kernel: [ 360.399708] [<c1295ed0>] ? schedule_timeout+0x21/0xaa Mar 28 18:12:37 tbox kernel: [ 360.410473] [<c114507f>] ? cpumask_next_and+0x23/0x2f Mar 28 18:12:37 tbox kernel: [ 360.421240] [<c1295d41>] wait_for_common+0x77/0xcd Mar 28 18:12:37 tbox kernel: [ 360.432032] [<c102a570>] ? try_to_wake_up+0x142/0x142 Mar 28 18:12:37 tbox kernel: [ 360.442808] [<c107499c>] ? call_rcu_bh+0xf/0xf Mar 28 18:12:37 tbox kernel: [ 360.453598] [<c1295e18>] wait_for_completion+0x12/0x14 Mar 28 18:12:37 tbox kernel: [ 360.464436] [<c1074df6>] _rcu_barrier.isra.41+0x78/0x85 Mar 28 18:12:37 tbox kernel: [ 360.475315] [<c1074e10>] rcu_barrier_sched+0xd/0xf Mar 28 18:12:37 tbox kernel: [ 360.485900] [<c1074e1a>] rcu_barrier+0x8/0xa Mar 28 18:12:37 tbox kernel: [ 360.496150] [<f82e35df>] rcu_torture_cleanup+0x2cd/0x317 [rcutorture] Mar 28 18:12:37 tbox kernel: [ 360.506544] [<c1057d05>] sys_delete_module+0x198/0x1f5 Mar 28 18:12:37 tbox kernel: [ 360.516992] [<c1075093>] ? rcu_enter_nohz+0x28/0x9c Mar 28 18:12:37 tbox kernel: [ 360.527410] [<c1075219>] ? rcu_irq_exit+0x8/0xa Mar 28 18:12:37 tbox kernel: [ 360.537813] [<c129c4df>] sysenter_do_call+0x12/0x28 Mar 28 18:14:37 tbox kernel: [ 480.548068] INFO: task modprobe:1662 blocked for more than 120 seconds. Mar 28 18:14:37 tbox kernel: [ 480.558653] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 28 18:14:37 tbox kernel: [ 480.569378] modprobe D f5127ea4 0 1662 1651 0x00000000 Mar 28 18:14:37 tbox kernel: [ 480.580205] f5127e98 00000082 f594ac00 f5127ea4 c145d380 ed715c1f 0000002a c145d380 Mar 28 18:14:37 tbox kernel: [ 480.591303] 00000000 00000000 f594ac00 f637dc00 0000002a f594ac00 ffffffff ffffffff Mar 28 18:14:37 tbox kernel: [ 480.602479] f5127ed8 ed715020 f64063c4 ed715c1f 00000000 3d090000 00000000 f594ac2c Mar 28 18:14:37 tbox kernel: [ 480.613746] Call Trace: Mar 28 18:14:37 tbox kernel: [ 480.624810] [<c10215b4>] ? wakeup_preempt_entity+0x36/0x53 Mar 28 18:14:37 tbox kernel: [ 480.636044] [<c1295ed0>] schedule_timeout+0x21/0xaa Mar 28 18:14:37 tbox kernel: [ 480.647248] [<c1295ed0>] ? schedule_timeout+0x21/0xaa Mar 28 18:14:37 tbox kernel: [ 480.658528] [<c114507f>] ? cpumask_next_and+0x23/0x2f Mar 28 18:14:37 tbox kernel: [ 480.669762] [<c1295d41>] wait_for_common+0x77/0xcd Mar 28 18:14:37 tbox kernel: [ 480.680957] [<c102a570>] ? try_to_wake_up+0x142/0x142 Mar 28 18:14:37 tbox kernel: [ 480.692187] [<c107499c>] ? call_rcu_bh+0xf/0xf Mar 28 18:14:37 tbox kernel: [ 480.703404] [<c1295e18>] wait_for_completion+0x12/0x14 Mar 28 18:14:37 tbox kernel: [ 480.714691] [<c1074df6>] _rcu_barrier.isra.41+0x78/0x85 Mar 28 18:14:37 tbox kernel: [ 480.725994] [<c1074e10>] rcu_barrier_sched+0xd/0xf Mar 28 18:14:37 tbox kernel: [ 480.737266] [<c1074e1a>] rcu_barrier+0x8/0xa Mar 28 18:14:37 tbox kernel: [ 480.748460] [<f82e35df>] rcu_torture_cleanup+0x2cd/0x317 [rcutorture] Mar 28 18:14:37 tbox kernel: [ 480.759798] [<c1057d05>] sys_delete_module+0x198/0x1f5 Mar 28 18:14:37 tbox kernel: [ 480.771072] [<c1075093>] ? rcu_enter_nohz+0x28/0x9c Mar 28 18:14:37 tbox kernel: [ 480.782354] [<c1075219>] ? rcu_irq_exit+0x8/0xa Mar 28 18:14:37 tbox kernel: [ 480.793576] [<c129c4df>] sysenter_do_call+0x12/0x28 Mar 28 18:15:03 tbox kernel: [ 505.836029] INFO: rcu_sched_state detected stall on CPU 0 (t=105060 jiffies) Mar 28 18:15:03 tbox kernel: [ 505.840011] sending NMI to all CPUs: Mar 28 18:15:03 tbox kernel: [ 505.840011] NMI backtrace for cpu 0 Mar 28 18:15:03 tbox kernel: [ 505.840011] Modules linked in: rcutorture(-) acpi_cpufreq mperf cpufreq_powersave cpufreq_userspace cpufreq_stats cpufreq_conservative ppdev lp aes_i586 aes_generic rfcomm bnep bluetooth binfmt_misc fuse snd_intel8x0m snd_intel8x0 snd_ac97_codec radeon ac97_bus snd_pcm_oss arc4 snd_mixer_oss ecb ath5k joydev snd_pcm thinkpad_acpi pcmcia snd_seq_midi ath ttm mac80211 snd_rawmidi drm_kms_helper drm cfg80211 yenta_socket snd_seq_midi_event pcmcia_rsrc snd_seq pcmcia_core snd_timer i2c_algo_bit rfkill snd_seq_device psmouse snd nsc_ircc tpm_tis parport_pc battery ac pcspkr tpm irda i2c_i801 shpchp serio_raw tpm_bios soundcore processor i2c_core evdev pci_hotplug snd_page_alloc crc_ccitt parport nvram power_supply video button ext4 mbcache jbd2 crc16 dm_mod usbhid hid usb_storage uas sg sr_mod sd_mod cdrom crc_t10dif ata_generic ata_piix uhci_hcd libata ehci_hcd scsi_mod usbcore e1000 thermal thermal_sys floppy [last unloaded: scsi_wait_scan] Mar 28 18:15:03 tbox kernel: [ 505.840011] Mar 28 18:15:03 tbox kernel: [ 505.840011] Pid: 0, comm: swapper Not tainted 2.6.38-next20110328-3-686-iniza #1 IBM 2374SG6/2374SG6 Mar 28 18:15:03 tbox kernel: [ 505.840011] EIP: 0060:[<c114b91b>] EFLAGS: 00000002 CPU: 0 Mar 28 18:15:03 tbox kernel: [ 505.840011] EIP is at __const_udelay+0xa/0x1c Mar 28 18:15:03 tbox kernel: [ 505.840011] EAX: 00418958 EBX: 00002710 ECX: c132e541 EDX: 00247fab Mar 28 18:15:03 tbox kernel: [ 505.840011] ESI: c13d7500 EDI: c13d7580 EBP: f6019eac ESP: f6019eac Mar 28 18:15:03 tbox kernel: [ 505.840011] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 Mar 28 18:15:03 tbox kernel: [ 505.840011] Process swapper (pid: 0, ti=f6018000 task=c13ccfa0 task.ti=c13a0000) Mar 28 18:15:03 tbox kernel: [ 505.840011] Stack: Mar 28 18:15:03 tbox kernel: [ 505.840011] f6019eb8 c10164ca c13d7500 f6019ed4 c1074e8d c133c4ef c133c5be 00000000 Mar 28 18:15:03 tbox kernel: [ 505.840011] 00019a64 f6403488 f6019ee8 c1074f02 00000000 00000000 c13ccfa0 f6019ef4 Mar 28 18:15:03 tbox kernel: [ 505.840011] c10752ab 00000000 f6019f08 c1039c2c c13a1ef8 c62d1b06 00000075 f6019f20 Mar 28 18:15:03 tbox kernel: [ 505.840011] Call Trace: Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:15:03 tbox kernel: [ 505.840011] <IRQ> Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:15:03 tbox kernel: [ 505.840011] Code: eb 0e 8d b4 26 00 00 00 00 8d bc 27 00 00 00 00 48 75 fd 48 5d c3 55 89 e5 ff 15 a8 81 3e c1 5d c3 55 89 e5 64 8b 15 dc d2 45 c1 <c1> e0 02 6b d2 3e f7 e2 8d 42 01 e8 db ff ff ff 5d c3 69 c0 c7 Mar 28 18:15:03 tbox kernel: [ 505.840011] Call Trace: Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:15:03 tbox kernel: [ 505.840011] <IRQ> [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:15:03 tbox kernel: [ 505.840011] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:16:38 tbox kernel: [ 600.804066] INFO: task modprobe:1662 blocked for more than 120 seconds. Mar 28 18:16:38 tbox kernel: [ 600.814684] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 28 18:16:38 tbox kernel: [ 600.825484] modprobe D f5127ea4 0 1662 1651 0x00000000 Mar 28 18:16:38 tbox kernel: [ 600.836381] f5127e98 00000082 f594ac00 f5127ea4 c145d380 ed715c1f 0000002a c145d380 Mar 28 18:16:38 tbox kernel: [ 600.847562] 00000000 00000000 f594ac00 f637dc00 0000002a f594ac00 ffffffff ffffffff Mar 28 18:16:38 tbox kernel: [ 600.858807] f5127ed8 ed715020 f64063c4 ed715c1f 00000000 3d090000 00000000 f594ac2c Mar 28 18:16:38 tbox kernel: [ 600.870196] Call Trace: Mar 28 18:16:38 tbox kernel: [ 600.881367] [<c10215b4>] ? wakeup_preempt_entity+0x36/0x53 Mar 28 18:16:38 tbox kernel: [ 600.892671] [<c1295ed0>] schedule_timeout+0x21/0xaa Mar 28 18:16:38 tbox kernel: [ 600.903940] [<c1295ed0>] ? schedule_timeout+0x21/0xaa Mar 28 18:16:38 tbox kernel: [ 600.915184] [<c114507f>] ? cpumask_next_and+0x23/0x2f Mar 28 18:16:38 tbox kernel: [ 600.926423] [<c1295d41>] wait_for_common+0x77/0xcd Mar 28 18:16:38 tbox kernel: [ 600.937628] [<c102a570>] ? try_to_wake_up+0x142/0x142 Mar 28 18:16:38 tbox kernel: [ 600.948873] [<c107499c>] ? call_rcu_bh+0xf/0xf Mar 28 18:16:38 tbox kernel: [ 600.960134] [<c1295e18>] wait_for_completion+0x12/0x14 Mar 28 18:16:38 tbox kernel: [ 600.971503] [<c1074df6>] _rcu_barrier.isra.41+0x78/0x85 Mar 28 18:16:38 tbox kernel: [ 600.982899] [<c1074e10>] rcu_barrier_sched+0xd/0xf Mar 28 18:16:38 tbox kernel: [ 600.993893] [<c1074e1a>] rcu_barrier+0x8/0xa Mar 28 18:16:38 tbox kernel: [ 601.004417] [<f82e35df>] rcu_torture_cleanup+0x2cd/0x317 [rcutorture] Mar 28 18:16:38 tbox kernel: [ 601.015076] [<c1057d05>] sys_delete_module+0x198/0x1f5 Mar 28 18:16:38 tbox kernel: [ 601.025690] [<c1075093>] ? rcu_enter_nohz+0x28/0x9c Mar 28 18:16:38 tbox kernel: [ 601.036275] [<c1075219>] ? rcu_irq_exit+0x8/0xa Mar 28 18:16:38 tbox kernel: [ 601.046855] [<c129c4df>] sysenter_do_call+0x12/0x28 Mar 28 18:17:01 tbox /USR/SBIN/CRON[1665]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly) Mar 28 18:18:04 tbox kernel: [ 685.956029] INFO: rcu_sched_state detected stall on CPU 0 (t=150090 jiffies) Mar 28 18:18:04 tbox kernel: [ 685.960012] sending NMI to all CPUs: Mar 28 18:18:04 tbox kernel: [ 685.960012] NMI backtrace for cpu 0 Mar 28 18:18:04 tbox kernel: [ 685.960012] Modules linked in: rcutorture(-) acpi_cpufreq mperf cpufreq_powersave cpufreq_userspace cpufreq_stats cpufreq_conservative ppdev lp aes_i586 aes_generic rfcomm bnep bluetooth binfmt_misc fuse snd_intel8x0m snd_intel8x0 snd_ac97_codec radeon ac97_bus snd_pcm_oss arc4 snd_mixer_oss ecb ath5k joydev snd_pcm thinkpad_acpi pcmcia snd_seq_midi ath ttm mac80211 snd_rawmidi drm_kms_helper drm cfg80211 yenta_socket snd_seq_midi_event pcmcia_rsrc snd_seq pcmcia_core snd_timer i2c_algo_bit rfkill snd_seq_device psmouse snd nsc_ircc tpm_tis parport_pc battery ac pcspkr tpm irda i2c_i801 shpchp serio_raw tpm_bios soundcore processor i2c_core evdev pci_hotplug snd_page_alloc crc_ccitt parport nvram power_supply video button ext4 mbcache jbd2 crc16 dm_mod usbhid hid usb_storage uas sg sr_mod sd_mod cdrom crc_t10dif ata_generic ata_piix uhci_hcd libata ehci_hcd scsi_mod usbcore e1000 thermal thermal_sys floppy [last unloaded: scsi_wait_scan] Mar 28 18:18:04 tbox kernel: [ 685.960012] Mar 28 18:18:04 tbox kernel: [ 685.960012] Pid: 0, comm: swapper Not tainted 2.6.38-next20110328-3-686-iniza #1 IBM 2374SG6/2374SG6 Mar 28 18:18:04 tbox kernel: [ 685.960012] EIP: 0060:[<c114b923>] EFLAGS: 00000807 CPU: 0 Mar 28 18:18:04 tbox kernel: [ 685.960012] EIP is at __const_udelay+0x12/0x1c Mar 28 18:18:04 tbox kernel: [ 685.960012] EAX: 4f1a99c0 EBX: 00002710 ECX: c132e541 EDX: 00090d3f Mar 28 18:18:04 tbox kernel: [ 685.960012] ESI: c13d7500 EDI: c13d7580 EBP: f6019eac ESP: f6019eac Mar 28 18:18:04 tbox kernel: [ 685.960012] DS: 007b ES: 007b FS: 00d8 GS: 00e0 SS: 0068 Mar 28 18:18:04 tbox kernel: [ 685.960012] Process swapper (pid: 0, ti=f6018000 task=c13ccfa0 task.ti=c13a0000) Mar 28 18:18:04 tbox kernel: [ 685.960012] Stack: Mar 28 18:18:04 tbox kernel: [ 685.960012] f6019eb8 c10164ca c13d7500 f6019ed4 c1074e8d c133c4ef c133c5be 00000000 Mar 28 18:18:04 tbox kernel: [ 685.960012] 00024a4a f6403488 f6019ee8 c1074f02 00000000 00000000 c13ccfa0 f6019ef4 Mar 28 18:18:04 tbox kernel: [ 685.960012] c10752ab 00000000 f6019f08 c1039c2c c13a1ef8 b62a34e0 0000009f f6019f20 Mar 28 18:18:04 tbox kernel: [ 685.960012] Call Trace: Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:18:04 tbox kernel: [ 685.960012] <IRQ> Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:18:04 tbox kernel: [ 685.960012] Code: 00 8d bc 27 00 00 00 00 48 75 fd 48 5d c3 55 89 e5 ff 15 a8 81 3e c1 5d c3 55 89 e5 64 8b 15 dc d2 45 c1 c1 e0 02 6b d2 3e f7 e2 <8d> 42 01 e8 db ff ff ff 5d c3 69 c0 c7 10 00 00 55 89 e5 e8 d6 Mar 28 18:18:04 tbox kernel: [ 685.960012] Call Trace: Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10164ca>] arch_trigger_all_cpu_backtrace+0x50/0x62 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1074e8d>] check_cpu_stall+0x58/0xb8 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1074f02>] __rcu_pending+0x15/0xc4 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10752ab>] rcu_check_callbacks+0x6d/0x93 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1039c2c>] update_process_times+0x2d/0x58 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1050991>] tick_sched_timer+0x6b/0x9a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104713e>] __run_hrtimer+0x9c/0x111 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1050926>] ? tick_nohz_handler+0xdf/0xdf Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1047ae0>] hrtimer_interrupt+0xd6/0x1bb Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104fc49>] tick_do_broadcast.constprop.4+0x38/0x6a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c104fd28>] tick_handle_oneshot_broadcast+0xad/0xe1 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1004209>] timer_interrupt+0x15/0x1c Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c107140d>] handle_irq_event_percpu+0x4e/0x164 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1071559>] handle_irq_event+0x36/0x51 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072d62>] ? unmask_irq+0x25/0x25 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1072daf>] handle_level_irq+0x4d/0x63 Mar 28 18:18:04 tbox kernel: [ 685.960012] <IRQ> [<c1003b81>] ? do_IRQ+0x35/0x80 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c129ca70>] ? common_interrupt+0x30/0x38 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c10400d8>] ? worker_maybe_bind_and_lock+0x3e/0x83 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868e30f>] ? arch_local_irq_enable+0x5/0xb [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868eef5>] ? acpi_idle_enter_simple+0x100/0x138 [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<f868ec6a>] ? acpi_idle_enter_bm+0xd0/0x25b [processor] Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c11e1ea2>] ? cpuidle_idle_call+0xc2/0x137 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1001da3>] ? cpu_idle+0x89/0xa3 Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c127d300>] ? rest_init+0x58/0x5a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c1401722>] ? start_kernel+0x315/0x31a Mar 28 18:18:04 tbox kernel: [ 685.960012] [<c14010a2>] ? i386_start_kernel+0xa2/0xaa Mar 28 18:18:38 tbox kernel: [ 721.056065] INFO: task modprobe:1662 blocked for more than 120 seconds. Mar 28 18:18:38 tbox kernel: [ 721.066683] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message. Mar 28 18:18:38 tbox kernel: [ 721.077467] modprobe D f5127ea4 0 1662 1651 0x00000000 Mar 28 18:18:38 tbox kernel: [ 721.088422] f5127e98 00000082 f594ac00 f5127ea4 c145d380 ed715c1f 0000002a c145d380 Mar 28 18:18:38 tbox kernel: [ 721.099608] 00000000 00000000 f594ac00 f637dc00 0000002a f594ac00 ffffffff ffffffff Mar 28 18:18:38 tbox kernel: [ 721.110877] f5127ed8 ed715020 f64063c4 ed715c1f 00000000 3d090000 00000000 f594ac2c Mar 28 18:18:38 tbox kernel: [ 721.122224] Call Trace: Mar 28 18:18:38 tbox kernel: [ 721.133395] [<c10215b4>] ? wakeup_preempt_entity+0x36/0x53 Mar 28 18:18:38 tbox kernel: [ 721.144707] [<c1295ed0>] schedule_timeout+0x21/0xaa Mar 28 18:18:38 tbox kernel: [ 721.155977] [<c1295ed0>] ? schedule_timeout+0x21/0xaa Mar 28 18:18:38 tbox kernel: [ 721.167211] [<c114507f>] ? cpumask_next_and+0x23/0x2f Mar 28 18:18:38 tbox kernel: [ 721.178445] [<c1295d41>] wait_for_common+0x77/0xcd Mar 28 18:18:38 tbox kernel: [ 721.189693] [<c102a570>] ? try_to_wake_up+0x142/0x142 Mar 28 18:18:38 tbox kernel: [ 721.200939] [<c107499c>] ? call_rcu_bh+0xf/0xf Mar 28 18:18:38 tbox kernel: [ 721.212205] [<c1295e18>] wait_for_completion+0x12/0x14 Mar 28 18:18:38 tbox kernel: [ 721.223518] [<c1074df6>] _rcu_barrier.isra.41+0x78/0x85 Mar 28 18:18:38 tbox kernel: [ 721.234876] [<c1074e10>] rcu_barrier_sched+0xd/0xf Mar 28 18:18:38 tbox kernel: [ 721.245861] [<c1074e1a>] rcu_barrier+0x8/0xa Mar 28 18:18:38 tbox kernel: [ 721.256390] [<f82e35df>] rcu_torture_cleanup+0x2cd/0x317 [rcutorture] Mar 28 18:18:38 tbox kernel: [ 721.267042] [<c1057d05>] sys_delete_module+0x198/0x1f5 Mar 28 18:18:38 tbox kernel: [ 721.277652] [<c1075093>] ? rcu_enter_nohz+0x28/0x9c Mar 28 18:18:38 tbox kernel: [ 721.288273] [<c1075219>] ? rcu_irq_exit+0x8/0xa Mar 28 18:18:38 tbox kernel: [ 721.298872] [<c129c4df>] sysenter_do_call+0x12/0x28
