Bug 14483 - Interrupts enabled after irqrouter_resume - iMac9,1
Interrupts enabled after irqrouter_resume - iMac9,1
Status: CLOSED PATCH_ALREADY_AVAILABLE
Product: ACPI
Classification: Unclassified
Component: Power-Sleep-Wake
All Linux
: P1 normal
Assigned To: Alexey Starikovskiy
:
Depends on:
Blocks: 7216 14230
  Show dependency treegraph
 
Reported: 2009-10-26 18:00 UTC by Rafael J. Wysocki
Modified: 2010-01-23 19:25 UTC (History)
5 users (show)

See Also:
Kernel Version: 2.6.32-rc3
Tree: Mainline
Regression: Yes


Attachments
print log right when the machine sleeps, and waking up. (13.50 KB, application/octet-stream)
2009-10-28 06:07 UTC, Justin P. Mattock
Details
bisect log 2.6.31-rc8 - current (2.41 KB, text/plain)
2009-10-28 21:28 UTC, Justin P. Mattock
Details
acpidump dsdt of imac9,1 (207.58 KB, application/octet-stream)
2009-10-28 21:31 UTC, Justin P. Mattock
Details
imac91_dmesg (62.61 KB, application/octet-stream)
2009-10-28 21:41 UTC, Justin P. Mattock
Details
bisectlog#2 and bisectlog#3 (5.57 KB, application/octet-stream)
2009-10-29 07:42 UTC, Justin P. Mattock
Details
dmesg after resume on T30 with 2.6.32-rc8 from yesterday (119.22 KB, text/plain)
2009-11-22 00:28 UTC, Christian Hartmann
Details
the acpidump of this machine before anybody ask for it (200.64 KB, text/plain)
2009-11-22 00:33 UTC, Christian Hartmann
Details

Description Rafael J. Wysocki 2009-10-26 18:00:53 UTC
Subject    : WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x54/0xca()
Submitter  : Justin Mattock <justinmattock@gmail.com>
Date       : 2009-10-25 19:58
References : http://marc.info/?l=linux-kernel&m=125650070420168&w=4

This entry is being used for tracking a regression from 2.6.31.  Please don't
close it until the problem is fixed in the mainline.
Comment 1 Rafael J. Wysocki 2009-10-26 20:59:28 UTC
On Monday 26 October 2009, Justin P. Mattock wrote:
> Rafael J. Wysocki wrote:
> > This message has been generated automatically as a part of a report
> > of recent regressions.
> >
> > The following bug entry is on the current list of known regressions
> > from 2.6.31.  Please verify if it still should be listed and let me know
> > (either way).
> >
> >
> > Bug-Entry	: http://bugzilla.kernel.org/show_bug.cgi?id=14483
> > Subject		: WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x54/0xca()
> > Submitter	: Justin Mattock<justinmattock@gmail.com>
> > Date		: 2009-10-25 19:58 (2 days old)
> > References	: http://marc.info/?l=linux-kernel&m=125650070420168&w=4
> >
> >
> >
> >    
> yeah this happens on the first go of
> echo mem > /sys/power/state
> for both of my imac's I have here.
> (on the second  try, this message does not appear)
Comment 2 Len Brown 2009-10-27 01:53:31 UTC
my only guess right now is that this may be SMM related --
perhaps SMM is being provoked during the AML evaluation
related to resuming the links?

Probably we could find out by adding some more
statements analogous to this:

WARN_ONCE(!irqs_disabled(),
                "Interrupts enabled after %pF\n", cls->resume);

say, in the loop of acpi_pci_link_resume()

Justin,
Please attach the output from acpidump for the failing machine.
also, the complete output from dmesg -s64000
Comment 3 Rafael J. Wysocki 2009-10-27 07:41:33 UTC
For the record, one machine in bug #14334 also has this problem.
Comment 4 Justin P. Mattock 2009-10-28 06:05:48 UTC
apologize for the late response(did not see amongst the e-mails).

Finally got my firewire debugging working. And to my amazement it actually works
just grabbed dmesg from the imac that's hitting this.
(this time there's no nvidia loaded, nor wl)
Attached is the log from waking up, unfortunately I get a black screen,
fortunately firewire came through with a log.

What I'll do is do a bisect on this, to get an idea of where/what might be causing this, then can add a printk.(seems straight forward since this is reproducible every first s2ram, just need to find a good commit version).
Comment 5 Justin P. Mattock 2009-10-28 06:07:05 UTC
Created attachment 23555 [details]
print log right when the machine sleeps, and waking up.

here is dmesg of the wake up.
Comment 6 Justin P. Mattock 2009-10-28 21:28:04 UTC
Created attachment 23565 [details]
bisect log 2.6.31-rc8 - current

here is my bisect log.. seems git bisect goes astray when adding your own commits to the kernel.(going to redu the bisect).
Comment 7 Justin P. Mattock 2009-10-28 21:31:18 UTC
Created attachment 23566 [details]
acpidump dsdt of imac9,1

len - I did an acpidump on the machine, but wasn't sure which area so I just randomly figured dsdt.(if you need another let me know.
As for adding printk I can try and see, just need to figure out where acpi_pci_link_resume is located.(I'll have a look right now before I go and do another bisect).
Comment 8 Justin P. Mattock 2009-10-28 21:41:26 UTC
Created attachment 23567 [details]
imac91_dmesg

Almost forgot, here's full dmesg of the machine with the warning.
happens on another imac(2.6 mhz processor) but does not happen on
the macbook pro ati chipset.
Comment 9 Jose Marino 2009-10-28 23:38:17 UTC
I have the same problem with a laptop Dell Inspiron 600m (the machine mentioned in comment #3).
I noticed that if I unload module acpi_cpufreq the backtrace does not happen:
- Fresh boot into v2.6.32-rc2
- rmmod acpi_cpufreq
- suspend/resume
> dmesg doesn't show the backtrace

I'm not sure if this is trivial and should be expected, but just in case I thought I should mention it.
Comment 10 Justin P. Mattock 2009-10-29 07:42:10 UTC
Created attachment 23574 [details]
bisectlog#2 and bisectlog#3

whew.. I think I need a beer after doing this(so If you don't here from me, well you get the idea).

Anyways I did a second bisect, and the results, were close, but not what I was shooting for. Then after that I decided to do another(3rd) between these two bad/good commits:

bad=2.6.31-08247-g2b5bbe3 good=2.6.31-07777-gbe90a49

the result was pointing me at this commit:
7ef0143e2f898f9bf675c81bdf0e045c8dd53c57 is the first bad commit
(which I think the first bisect resulted in)

After finishing up the bisection I went and reverted the bad commit,
but after all of that the warning still showed itself.

During the bisection I kept a note of the commit/kernel numbers which look like this:


2.6.31-08020-gc11f6c8 @bad
2.6.31-06578-gcbeee13 @bad
2.6.31-06517-g3bb29ec @good
2.6.31-06548-g7a92d80 @good
2.6.31-06562-g762caf0 @good
2.6.31-06571-g89ae400 @good
2.6.31-06575-g7ef0143 @bad 
2.6.31-06573-g44396a2 @good

somewhere between 06571-06575 (hopefully)might be where the warning is showing up. much too tired now to go any further until tomorrow!!
(and I was thinking nah this should be easy...man was I wrong)..
Comment 11 Justin P. Mattock 2009-10-31 20:10:25 UTC
After spending some time yesterday, and today I'm still unable to find the commit that is causing this. the bisect pointed me in this direction
7ef0143e2f898f9bf675c81bdf0e045c8dd53c57 is the first bad commit
but reverting that does nothing. Then manually looking I'm seeing the other commits for acpi, and am trying to use git revert xxx
but looking I'm seeing some of these have a diff1 and diff2
(I don't know how to tell git revert to do the first diff1 revert then the second).
So at this point I've managed to add this:
http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=3b87bb640e77023c97cf209e3dd85887a1113ad0

with using 2.6.30.5 because the latest git head has too many changes to this area,
but could not create the problem(so this commit is not it).

At the moment I'll try adding acpica(http://git.kernel.org/?p=linux/kernel/git/torvalds/linux-2.6.git;a=commit;h=985f38781d19101aba121df423f92c87b208c6df) to see if this causes the waning message.
(but this merge also has diff1 diff2 so this might take a while).
Comment 12 Jose Marino 2009-11-03 02:13:22 UTC
I tried a bisect and this is the result:

89133f93508137231251543d1732da638e6022e1 is the first bad commit
commit 89133f93508137231251543d1732da638e6022e1
Author: Martin Schwidefsky <schwidefsky@de.ibm.com>
Date:   Thu Sep 24 17:29:52 2009 +0200

    clocksource: Resume clocksource without taking the clocksource mutex
    
    git commit 75c5158f70c065b9 converted the clocksource spinlock to a
    mutex. This causes the following BUG:
    
    BUG: sleeping function called from invalid context at
    kernel/mutex.c:280 in_atomic(): 0, irqs_disabled(): 1, pid: 2473,
    name: pm-suspend 2 locks held by pm-suspend/2473:
     #0:  (&buffer->mutex){......}, at: [<ffffffff8115ab13>]
    sysfs_write_file+0x3c/0x137
     #1:  (pm_mutex){......}, at: [<ffffffff810865b5>]
    enter_state+0x39/0x130 Pid: 2473, comm: pm-suspend Not tainted 2.6.31
    #1 Call Trace:
     [<ffffffff810792f0>] ? __debug_show_held_locks+0x22/0x24
     [<ffffffff8104a2ef>] __might_sleep+0x107/0x10b
     [<ffffffff8141fca9>] mutex_lock_nested+0x25/0x43
     [<ffffffff81073537>] clocksource_resume+0x1c/0x60
     [<ffffffff81072902>] timekeeping_resume+0x1e/0x1c8
     [<ffffffff812aee62>] __sysdev_resume+0x25/0xcf
     [<ffffffff812aef79>] sysdev_resume+0x6d/0xae
     [<ffffffff810864f8>] suspend_devices_and_enter+0x12b/0x1af
     [<ffffffff8108665b>] enter_state+0xdf/0x130
     [<ffffffff81085dc3>] state_store+0xb6/0xd3
     [<ffffffff81204c73>] kobj_attr_store+0x17/0x19
     [<ffffffff8115abd2>] sysfs_write_file+0xfb/0x137
     [<ffffffff811057d2>] vfs_write+0xae/0x10b
     [<ffffffff81208392>] ? __up_read+0x1a/0x7f
     [<ffffffff811058ef>] sys_write+0x4a/0x6e
     [<ffffffff81011b82>] system_call_fastpath+0x16/0x1b
    
    clocksource_resume is called early in the resume process, there is
    only one cpu, no processes are running and the interrupts are
    disabled. It is therefore possible to resume the clocksources
    without taking the clocksource mutex.
    
    Reported-by: Xiaotian Feng <xtfeng@gmail.com>
    Signed-off-by: Martin Schwidefsky <schwidefsky@de.ibm.com>
    Tested-by: Michal Schmidt <mschmidt@redhat.com>
    Cc: Xiaotian Feng <xtfeng@gmail.com>
    Cc: John Stultz <johnstul@us.ibm.com>
    LKML-Reference: <20090924172952.49697825@mschwide.boeblingen.de.ibm.com>
    Signed-off-by: Ingo Molnar <mingo@elte.hu>

:040000 040000 b1a01ffad4b391de609a1a439f72c7dbfd51c8bd 3dffb0b3f8336a5ae6ed4d549fb3b47bec3f4ed6 M	kernel
Comment 13 Len Brown 2009-11-03 02:49:23 UTC
Jose, Justin, please confirm that reverting 89133f93508137231251543d1732da638e6022e1
from the latest kernel makes the problem go away.
Comment 14 Jose Marino 2009-11-03 04:46:38 UTC
I reverted commit 89133f93508137231251543d1732da638e6022e1 on top of v2.6.32-rc5 and it made the backtrace go away. However, it reintroduced these 2 backtraces that the commit seemed to fix:

------------[ cut here ]------------
WARNING: at kernel/hrtimer.c:654 hres_timers_resume+0x3b/0x50()
Hardware name: Inspiron 600m                   
hres_timers_resume() called with IRQs enabled!
Modules linked in: reiserfs fan button thermal battery sr_mod cdrom dcdbas ac acpi_cpufreq processor rtc_cmos rtc_core rtc_lib
Pid: 1933, comm: pm-suspend Not tainted 2.6.32-rc5-bisect #88
Call Trace:
 [<c10226cd>] warn_slowpath_common+0x6d/0xa0
 [<c1037dcb>] ? hres_timers_resume+0x3b/0x50
 [<c1037dcb>] ? hres_timers_resume+0x3b/0x50
 [<c1022746>] warn_slowpath_fmt+0x26/0x30
 [<c1037dcb>] hres_timers_resume+0x3b/0x50
 [<c103ad99>] timekeeping_resume+0x179/0x1a0
 [<c1184057>] __sysdev_resume+0x17/0xd0
 [<c1184167>] sysdev_resume+0x57/0xd0
 [<c113ffc6>] ? acpi_suspend_enter+0xb5/0xc6
 [<c1048583>] suspend_devices_and_enter+0x173/0x1b0
 [<c1239af0>] ? printk+0x18/0x20
 [<c10486c8>] enter_state+0x108/0x130
 [<c1047e1b>] state_store+0x6b/0xb0
 [<c1047db0>] ? state_store+0x0/0xb0
 [<c1115240>] kobj_attr_store+0x20/0x30
 [<c10b8384>] sysfs_write_file+0x94/0xf0
 [<c107703a>] vfs_write+0x9a/0x180
 [<c10b82f0>] ? sysfs_write_file+0x0/0xf0
 [<c10771dd>] sys_write+0x3d/0x70
 [<c1002d08>] sysenter_do_call+0x12/0x26
---[ end trace 12433f916540704e ]---
------------[ cut here ]------------
WARNING: at drivers/base/sys.c:353 __sysdev_resume+0xba/0xd0()
Hardware name: Inspiron 600m                   
Interrupts enabled after timekeeping_resume+0x0/0x1a0
Modules linked in: reiserfs fan button thermal battery sr_mod cdrom dcdbas ac acpi_cpufreq processor rtc_cmos rtc_core rtc_lib
Pid: 1933, comm: pm-suspend Tainted: G        W  2.6.32-rc5-bisect #88
Call Trace:
 [<c10226cd>] warn_slowpath_common+0x6d/0xa0
 [<c11840fa>] ? __sysdev_resume+0xba/0xd0
 [<c11840fa>] ? __sysdev_resume+0xba/0xd0
 [<c1022746>] warn_slowpath_fmt+0x26/0x30
 [<c11840fa>] __sysdev_resume+0xba/0xd0
 [<c103ac20>] ? timekeeping_resume+0x0/0x1a0
 [<c1184167>] sysdev_resume+0x57/0xd0
 [<c113ffc6>] ? acpi_suspend_enter+0xb5/0xc6
 [<c1048583>] suspend_devices_and_enter+0x173/0x1b0
 [<c1239af0>] ? printk+0x18/0x20
 [<c10486c8>] enter_state+0x108/0x130
 [<c1047e1b>] state_store+0x6b/0xb0
 [<c1047db0>] ? state_store+0x0/0xb0
 [<c1115240>] kobj_attr_store+0x20/0x30
 [<c10b8384>] sysfs_write_file+0x94/0xf0
 [<c107703a>] vfs_write+0x9a/0x180
 [<c10b82f0>] ? sysfs_write_file+0x0/0xf0
 [<c10771dd>] sys_write+0x3d/0x70
 [<c1002d08>] sysenter_do_call+0x12/0x26
---[ end trace 12433f916540704f ]---
Comment 15 Justin P. Mattock 2009-11-03 07:33:18 UTC
o.k.I reverted that commit, but still same warning.
no extra messages like jose.
Comment 16 Jose Marino 2009-11-03 14:21:26 UTC
Oops. Could we be having different issues? I just noticed that the backtraces are a bit different:
Justin's: WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x54/0xca()
Mine:     WARNING: at drivers/base/sys.c:353 __sysdev_resume+0xba/0xd0()

The whole backtrace I get can be found here: http://bugzilla.kernel.org/show_bug.cgi?id=14334#c12
Comment 17 Justin P. Mattock 2009-11-03 16:00:16 UTC
Interesting thing here is your bisect put you into something completely different than the bisect did for me..problem here is during the acpi merges looking at the git web interface is I see diff1 diff2 in a lot of these commits. I think this is causing git to get confused at where the issue really is.

Any ideas on how to revert a merge that has a commit with multiple diff's(or commits)i.g. git revert -m1 xxx works but as soon as -m1 has more than one commit inside git errors out for me.
Comment 18 Jose Marino 2009-11-13 20:50:44 UTC
I'm still seeing "my" backtrace with 2.6.32-rc7. 
I suspect Justin and I are seeing different issues. Can somebody confirm this? Maybe I should file a new bug.
Just to be clear this is the backtrace I get after a succesful suspend/resume:
------------[ cut here ]------------
WARNING: at drivers/base/sys.c:353 __sysdev_resume+0xba/0xd0()
Hardware name: Inspiron 600m                   
Interrupts enabled after irqrouter_resume+0x0/0x3e
Modules linked in: ipv6 xt_recent xt_state reiserfs fan snd_seq_oss snd_seq_midi_event snd_seq snd_seq_device snd_intel8x0 snd_intel8x0m snd_ac97_codec ac97_bus snd_pcm_oss snd_mixer_oss usbhid parport_pc snd_pcm b44 snd_timer battery ac button sr_mod ssb snd snd_page_alloc cdrom thermal ipw2200 libipw iTCO_wdt iTCO_vendor_support intel_agp agpgart lp parport psmouse uhci_hcd dcdbas ehci_hcd cfg80211 rfkill lib80211 acpi_cpufreq processor rtc_cmos rtc_core rtc_lib
Pid: 3565, comm: pm-suspend Tainted: G        W  2.6.32-rc7-jos #93
Call Trace:
 [<c102839d>] warn_slowpath_common+0x6d/0xa0
 [<c119684a>] ? __sysdev_resume+0xba/0xd0
 [<c119684a>] ? __sysdev_resume+0xba/0xd0
 [<c1028416>] warn_slowpath_fmt+0x26/0x30
 [<c119684a>] __sysdev_resume+0xba/0xd0
 [<c11524a6>] ? irqrouter_resume+0x0/0x3e
 [<c11968b7>] sysdev_resume+0x57/0xd0
 [<c114dc76>] ? acpi_suspend_enter+0xb5/0xc6
 [<c104ed33>] suspend_devices_and_enter+0x173/0x1b0
 [<c1279aa1>] ? printk+0x18/0x1f
 [<c104ee78>] enter_state+0x108/0x130
 [<c104e5cb>] state_store+0x6b/0xb0
 [<c104e560>] ? state_store+0x0/0xb0
 [<c1121f50>] kobj_attr_store+0x20/0x30
 [<c10c4fa4>] sysfs_write_file+0x94/0xf0
 [<c10835ea>] vfs_write+0x9a/0x180
 [<c10c4f10>] ? sysfs_write_file+0x0/0xf0
 [<c101aef0>] ? do_page_fault+0x140/0x2f0
 [<c108378d>] sys_write+0x3d/0x70
 [<c1002d08>] sysenter_do_call+0x12/0x26
---[ end trace 4eaa2a86a8e2da24 ]---
Comment 19 Justin P. Mattock 2009-11-13 21:17:49 UTC
might be some time for me i.g. just had surgery on my mouth
(molar) in a bit of pain right now.
maybe tomorrow
Comment 20 Justin P. Mattock 2009-11-16 01:54:09 UTC
o.k.(whew what a pain to have teeth extracted) Anyways pulled the latest kernel, and yes this still shows up:
WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x54/0xca()
I can try and look through the commits that I came up with and try to revert some to see.(main problem is how intricate all of these merges where).
Comment 21 Justin P. Mattock 2009-11-20 03:29:02 UTC
well, out of curiosity I've decided to revert everything from acpi up to today,
down to about where the bisect was reporting where this might be hitting.
So far I've had no results with finding anything. Keep in mind I just reverted commits,so the problem(from what it seems) is among the merges that took place.
(in the process of trying to revert acpica,but given the length not sure if I have the energy).
Comment 22 Christian Hartmann 2009-11-22 00:24:24 UTC
Linux 2.6.32-rc8.git (a8a8a669ea13d792296737505adc43ccacf3a648) on a Thinkpad T30

Today I got also after a resume from s2disk this message:
[11105.043008]  clocksource0
[11105.043008] Resuming type 'irqrouter':
[11105.043008]  irqrouter0
11105.046759] ------------[ cut here ]------------
[11105.046777] WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x44/0xb0()
[11105.046783] Hardware name: 2366DG3
[11105.046792] Interrupts enabled after irqrouter_resume+0x0/0x43
[11105.046796] Modules linked in: sco bridge stp llc bnep rfcomm l2cap bluetooth speedstep_lib cpufreq_s
deon ttm drm_kms_helper drm i2c_algo_bit cfbcopyarea cfbimgblt cfbfillrect snd_mixer_oss uvcvideo acpi_c
deo cfg80211 snd_intel8x0m rng_core nsc_ircc pcmcia output battery irda processor ac button uhci_hcd ehc
ded: scsi_wait_scan]
[11105.046876] Pid: 5288, comm: s2disk Not tainted 2.6.32-rc8 #1
[11105.046881] Call Trace:
[11105.046898]  [<c012b300>] warn_slowpath_common+0x65/0x95
[11105.046907]  [<c012b36e>] warn_slowpath_fmt+0x29/0x2c
[11105.046917]  [<c02d42e6>] __sysdev_resume+0x44/0xb0
[11105.046926]  [<c0288e7e>] ? irqrouter_resume+0x0/0x43
[11105.046937]  [<c02d43d5>] sysdev_resume+0x83/0xbb
[11105.046950]  [<c0153646>] create_image+0xaf/0xec
[11105.046960]  [<c01536cf>] hibernation_snapshot+0x4c/0xb3
[11105.046970]  [<c0155d40>] snapshot_ioctl+0x219/0x4ca
[11105.046981]  [<c01a4bcc>] ? fsnotify_modify+0x62/0x6d
[11105.046990]  [<c0155b27>] ? snapshot_ioctl+0x0/0x4ca
[11105.046970]  [<c0155d40>] snapshot_ioctl+0x219/0x4ca
[11105.046981]  [<c01a4bcc>] ? fsnotify_modify+0x62/0x6d
[11105.046990]  [<c0155b27>] ? snapshot_ioctl+0x0/0x4ca
[11105.047001]  [<c01af2d6>] vfs_ioctl+0x1e/0x56
[11105.047047]  [<c01af8ef>] do_vfs_ioctl+0x2e7/0x310
[11105.047057]  [<c01af95d>] sys_ioctl+0x45/0x5f
[11105.047067]  [<c01033db>] sysenter_do_call+0x12/0x28
[11105.047074] ---[ end trace 0cb378311d759fd0 ]---
[11105.047135] ACPI: Waking up from system sleep state S4
[11105.125195] platform dock.0: EARLY restore

I have read this bug entry just now and waiting to pull the mentioned reverts here  from linus-2.6 (still nothing reverted till 2009-11-22@00:57)

This warning I had not yet seen before  Linux version 2.6.32-rc7 (chris@oddysseus) (gcc version 4.3.4 (Debian 4.3.4-6) ) #1 Mon Nov 16 16:24:25 CET 2009

I am testing since a few weeks 2.6.32 the suspend/resume w and w/o kms/agp and I have not seen it before 16.11.2009.

If additional info/debug is needed, please ask me.
Comment 23 Christian Hartmann 2009-11-22 00:28:12 UTC
Created attachment 23864 [details]
dmesg after resume on T30 with 2.6.32-rc8 from yesterday
Comment 24 Christian Hartmann 2009-11-22 00:33:05 UTC
Created attachment 23865 [details]
the acpidump of this machine before anybody ask for it
Comment 25 Justin P. Mattock 2009-11-22 16:47:46 UTC
I will be away from the machine that gives me this warning for a few days.
I can try a bisect again to see if I can get anything on this as soon as I return.
Comment 26 Justin P. Mattock 2009-11-26 07:06:44 UTC
here's the results from the fourth bisect on this. Seems to have taken this in another direction:


a03fdb7612874834d6847107198712d18b5242c7 is the first bad commit



git bisect start
# bad: [a9366e61b03f55a6e009e687ad10e706714c9907] Merge git://git.infradead.org/users/dwmw2/iommu-2.6.32
git bisect bad a9366e61b03f55a6e009e687ad10e706714c9907
# good: [74fca6a42863ffacaf7ba6f1936a9f228950f657] Linux 2.6.31
git bisect good 74fca6a42863ffacaf7ba6f1936a9f228950f657
# good: [ca9a702e50287cf429f1c12832319a26a715e70b] Merge branch 'upstream-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/jgarzik/libata-dev
git bisect good ca9a702e50287cf429f1c12832319a26a715e70b
# bad: [9f6ac7850a9c6363f4117fd2248e232a2d534627] Merge branch 'for_linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mchehab/linux-2.6
git bisect bad 9f6ac7850a9c6363f4117fd2248e232a2d534627
# bad: [b8c7f1dc5ca4e0d10709182233cdab932cef593d] Merge branch 'core-fixes-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect bad b8c7f1dc5ca4e0d10709182233cdab932cef593d
# bad: [48d0764998ad4ab7570afab8bb3bee0fbfa55b2a] nfs: initialize the backing_dev_info when creating the server
git bisect bad 48d0764998ad4ab7570afab8bb3bee0fbfa55b2a
# bad: [9eead2a8115d2a6aecf267c292f751f7761fa5f8] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/mszeredi/fuse
git bisect bad 9eead2a8115d2a6aecf267c292f751f7761fa5f8
# bad: [5ce00289875a853280985aee671258795b77e089] Merge branch 'for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/teigland/dlm
git bisect bad 5ce00289875a853280985aee671258795b77e089
# good: [dcbf77b9e86e1726f5fbd01bb98820dac06d456e] Merge branch 'sched-core-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect good dcbf77b9e86e1726f5fbd01bb98820dac06d456e
# good: [12e09337fe238981cb0c87543306e23775d1a143] time: Prevent 32 bit overflow with set_normalized_timespec()
git bisect good 12e09337fe238981cb0c87543306e23775d1a143
# bad: [a03fdb7612874834d6847107198712d18b5242c7] Merge branch 'timers-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
git bisect bad a03fdb7612874834d6847107198712d18b5242c7
# good: [e3346fc48204d780f92527d06df8bf6f28d603ec] x86, mce: fix "mce" boot option handling for CONFIG_X86_NEW_MCE
git bisect good e3346fc48204d780f92527d06df8bf6f28d603ec
# good: [5be9ed251f58881dfc3dd6742a81ff9ad1a7bb04] x86, mce: Move debugfs mce dir creating to mce.c
git bisect good 5be9ed251f58881dfc3dd6742a81ff9ad1a7bb04
# good: [e34e77ce348feac3c8c607774efb1f8a9262127d] x86, mce: Fix compilation with !CONFIG_DEBUG_FS in mce-severity.c
git bisect good e34e77ce348feac3c8c607774efb1f8a9262127d
# good: [202c4675c55ddf6b443c7e057d2dff6b42ef71aa] pty_write: don't do a tty_wakeup() when the buffers are full
git bisect good 202c4675c55ddf6b443c7e057d2dff6b42ef71aa


I'll try reverting the timers-for-linus merge(hopefully I don't run into issues)to see if this is the cause.
Comment 27 Justin P. Mattock 2009-12-01 00:00:51 UTC
O.k. here is the git bisect log of the merge timers-for-linus
(I owe a Thanks to a Jeff King for helping me on this one);

Anyways still no luck finding the bad commit that's causing this:
(reverting below does not cause the bug).


361bdce2f7963457ce3d329f8dc61897366f8f08 is the first bad commit
commit 361bdce2f7963457ce3d329f8dc61897366f8f08
Author: Thomas Gleixner <tglx@linutronix.de>
Date:   Mon Sep 14 23:37:40 2009 +0200

    time: Prevent 32 bit overflow with set_normalized_timespec()
    
    set_normalized_timespec() nsec argument is of type long. The recent
    timekeeping changes of ktime_get_ts() feed
    
        ts->tv_nsec + tomono.tv_nsec + nsecs
    
    to set_normalized_timespec(). On 32 bit machines that sum can be
    larger than (1 << 31) and therefor result in a negative value which
    screws up the result completely.
    
    Make the nsec argument of set_normalized_timespec() s64 to fix the
    problem at hand. This also prevents similar problems for future users
    of set_normalized_timespec().
    
    Signed-off-by: Thomas Gleixner <tglx@linutronix.de>
    Tested-by: Carsten Emde <carsten.emde@osadl.org>
    LKML-Reference: <new-submission>
    Cc: Martin Schwidefsky <schwidefsky@de.ibm.com>
    Cc: John Stultz <johnstul@us.ibm.com>

:040000 040000 950a478ac4a8592907de368971fc4f2dadd60b4b 82b18fc16755f70e700f7bdd089a6da1c56c9d61 M      include
:040000 040000 a10e4156c6a85043886fa78f81b8380d21523a5c f7ee51064e0c5811fce0dea422d399247ea68365 M      kernel



# bad: [361bdce2f7963457ce3d329f8dc61897366f8f08] time: Prevent 32 bit overflow with set_normalized_timespec()
git bisect bad 361bdce2f7963457ce3d329f8dc61897366f8f08
# good: [202c4675c55ddf6b443c7e057d2dff6b42ef71aa] pty_write: don't do a tty_wakeup() when the buffers are full
git bisect good 202c4675c55ddf6b443c7e057d2dff6b42ef71aa
# good: [e24a62d7f55d749c04d9339d3201f7d248faca16] timekeeping: Update clocksource with stop_machine
git bisect good e24a62d7f55d749c04d9339d3201f7d248faca16
# good: [6d01a5a341f510311ad43b346afdefa13bc548af] timekeeping: Increase granularity of read_persistent_clock(), build fix
git bisect good 6d01a5a341f510311ad43b346afdefa13bc548af
# good: [23b15067b16729f775d0cf3b6afe731cd5dc011b] clocksource: Resolve cpu hotplug dead lock with TSC unstable
git bisect good 23b15067b16729f775d0cf3b6afe731cd5dc011b
# good: [b10662863722ea0be67eaeb75a4964b2d48b47eb] clocksource: Resolve cpu hotplug dead lock with TSC unstable, fix crash
git bisect good b10662863722ea0be67eaeb75a4964b2d48b47eb
# good: [e15867b0c038c125d3267d9cbc4d2a1e310002a7] clocksource: Delay clocksource down rating to late boot
git bisect good e15867b0c038c125d3267d9cbc4d2a1e310002a7
Comment 28 Justin P. Mattock 2009-12-01 09:07:32 UTC
NOTE:Can somebody revert this to see if this fixes this for them
(make sure you do a make clean before compiling);

Well, I really don't understand how git bisect is going from one
area to another(really simple it seems i.g. bisect start,compile,reboot,install video module,suspend, either good/bad)

Anyways I did another bisect, and it led me to the acpi merges, then getting ready to try my attempt at doing a rebase I somehow came to this:


ACPICA: Don't switch task then not allowed
author	Alexey Starikovskiy <astarikovskiy@suse.de>	
	Fri, 28 Aug 2009 19:29:38 +0000 (23:29 +0400)
committer	Len Brown <len.brown@intel.com>	
	Sat, 29 Aug 2009 18:41:27 +0000 (14:41 -0400)
commit	138d15692bf76841f252d4b836a535cf5f9154e9
tree	df5d81076d4e4c74d51f3ed16146f245f34e8f8e	tree | snapshot
parent	326ba5010a5429a5a528b268b36a5900d4ab0eba	commit | diff
ACPICA: Don't switch task then not allowed

Signed-off-by: Alexey Starikovskiy <astarikovskiy@suse.de>
Signed-off-by: Len Brown <len.brown@intel.com>
include/acpi/platform/aclinux.h 		diff | blob | history

with the first bisect that I did, I reverted this, but had no results,
then looking at it this time I asked the question, did I make clean
before compiling so the *.h file gets compiled correctly. So long story short
after reverting this, and making sure the source tree was clean I'm not
seeing this warning message(hopefully this is correct);

Anyways apologize for the spam of bisect logs. And hope this atleast gets a handle on this.
Comment 29 Justin P. Mattock 2009-12-02 08:34:48 UTC
o.k. luckily somebody on lkml had reported something in the same area.
here's the thread:
http://lkml.org/lkml/2009/12/1/371
seems we(hopefully)have some handle on this.
At this point I'm going to wait and see what
you guys have to say about this, then go from there.
Comment 30 Zhang Rui 2009-12-04 03:52:52 UTC
re-assign to Alexey.
Comment 31 Zhang Rui 2009-12-04 05:37:36 UTC
patch already available at http://patchwork.kernel.org/patch/64771/

Justin, please verify if the patch above fixes the problem for you.
Comment 32 Christian Hartmann 2009-12-07 15:15:53 UTC
I applied this patch from comment #31 ,  compiled again the 2.6.32-rc8(a) and rebooted. s2ram with a additional resume does not bring these warning
"WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x44/0xb0()"
anymore. So this patch helps or solves this error for me.



commit d98bdaabceb2c815697a2de48a9458255b53175d
Author: christian hartmann <cornogle@googlemail.com>
Date:   Mon Dec 7 12:56:31 2009 +0100

    ACPICA: don't cond_resched() when irq_disabled or in_atomic

    * include/acpi/platform/aclinux.h
    * http://patchwork.kernel.org/patch/64771/

    Signed-off-by: christian hartmann <cornogle@googlemail.com>

 include/acpi/platform/aclinux.h |    2 +-
 1 files changed, 1 insertions(+), 1 deletions(-)

commit fe029d1ed0d3d52b618606733b54ea493b3d1a5a
Merge: a0cb2f4 6ec22f9
Author: christian hartmann <cornogle@googlemail.com>
Date:   Sun Dec 6 09:41:30 2009 +0100

    Merge branch 'master' into rc8_drm_readback

commit 6ec22f9b037fc0c2e00ddb7023fad279c365324d
Merge: 83be7d7 9b3660a
Author: Linus Torvalds <torvalds@linux-foundation.org>
Date:   Sat Dec 5 15:33:27 2009 -0800

    Merge branch 'x86-debug-for-linus' of git://git.kernel.org/pub/scm/linux/kernel/git/tip/linux-2.6-tip
Comment 33 Justin P. Mattock 2009-12-07 16:27:47 UTC
good.. glad it's fixed for you. I guess well leave this open until
this patch makes it into the main tree.
Comment 34 Zhang Rui 2009-12-08 01:11:31 UTC
Mark this bug as resolved to ping len to push the patch in this bug entry.
And it will be closed after it has been shipped in upstream kernel.
Comment 35 Len Brown 2009-12-16 06:01:50 UTC
patch is in acpi-test, pending consensus on the list
Comment 36 Rafael J. Wysocki 2009-12-27 21:58:32 UTC
What's the current status here?  We're still getting reports about that.

Handled-By : Xiaotian Feng <dfeng@redhat.com>
Patch : http://patchwork.kernel.org/patch/64771/
Comment 37 Justin P. Mattock 2009-12-27 22:25:40 UTC
I'm at:
2.6.33-rc1-00154-gf7b84a6
and am seeing this after waking up, telling me that the fix hasn't made it in yet.
(but will pull to the latest to see)
Comment 38 Justin P. Mattock 2009-12-28 06:51:30 UTC
o.k. pulled the latest, and this error
is still there.  looking at the git web interface I see there has been no changes to aclinux.h so .
so leave this open, Also if you or anybody else needs me to test any other kind of patch let me know.
Comment 39 Christian Hartmann 2010-01-11 11:22:39 UTC
with the git of 2.6.33-rc3 from 2010-01-06  I have this warning also yet:

Linux oddysseus 2.6.33-rc3 #24 Wed Jan 6 13:18:08 CET 2010 i686 GNU/Linux



[70696.197213]  irqrouter0
[70696.199965] ------------[ cut here ]------------
[70696.199979] WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x40/0xa2()
[70696.199984] Hardware name: 2366DG3
[70696.199991] Interrupts enabled after irqrouter_resume+0x0/0x43
[70696.199995] Modules linked in: sco bridge stp llc bnep rfcomm l2cap bluetooth speedstep_lib cpufreq_stats cpufreq_powersave b
infmt_misc usbserial radeon ttm drm_kms_helper drm i2c_algo_bit cfbcopyarea cfbimgblt cfbfillrect snd_mixer_oss uvcvideo acpi_cp
ufreq arc4 ecb ath5k mac80211 ath cfg80211 irda video rng_core snd_intel8x0m output ac pcmcia battery thinkpad_acpi processor bu
tton uhci_hcd ehci_hcd usbcore thermal fan [last unloaded: scsi_wait_scan]
[70696.200082] Pid: 9215, comm: s2ram Not tainted 2.6.33-rc3 #24
[70696.200085] Call Trace:
[70696.200098]  [<c0126702>] warn_slowpath_common+0x65/0x95
[70696.200104]  [<c0126770>] warn_slowpath_fmt+0x29/0x2c
[70696.200109]  [<c02c088a>] __sysdev_resume+0x40/0xa2
[70696.200115]  [<c027664e>] ? irqrouter_resume+0x0/0x43
[70696.200120]  [<c02c0968>] sysdev_resume+0x7c/0xb4
[70696.200127]  [<c014c7f2>] suspend_enter+0x87/0xc6
[70696.200132]  [<c014c891>] suspend_devices_and_enter+0x60/0x8c
[70696.200138]  [<c014c917>] enter_state+0x5a/0x88
[70696.200143]  [<c014c259>] state_store+0x99/0xad
[70696.200147]  [<c014c1c0>] ? state_store+0x0/0xad
[70696.200155]  [<c02467dd>] kobj_attr_store+0x1a/0x22
[70696.200163]  [<c01d1300>] sysfs_write_file+0xb9/0xe4
[70696.200168]  [<c01d1247>] ? sysfs_write_file+0x0/0xe4
[70696.200176]  [<c0197b55>] vfs_write+0x81/0xb2
[70696.200181]  [<c0197c29>] sys_write+0x40/0x65
[70696.200187]  [<c0102913>] sysenter_do_call+0x12/0x22
[70696.200192] ---[ end trace 36266317b026187b ]---
[70696.200197] ACPI: Waking up from system sleep state S3
[70696.282143] platform dock.0: EARLY resume
[70696.282149] platform dock.1: EARLY resume
Comment 40 Justin P. Mattock 2010-01-11 13:54:01 UTC
On 01/11/10 03:22, bugzilla-daemon@bugzilla.kernel.org wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=14483
>
>
>
>
>
> --- Comment #39 from Christian Hartmann<cornogle@googlemail.com>   2010-01-11 11:22:39 ---
> with the git of 2.6.33-rc3 from 2010-01-06  I have this warning also yet:
>
> Linux oddysseus 2.6.33-rc3 #24 Wed Jan 6 13:18:08 CET 2010 i686 GNU/Linux
>
>
>
> [70696.197213]  irqrouter0
> [70696.199965] ------------[ cut here ]------------
> [70696.199979] WARNING: at drivers/base/sys.c:353 __sysdev_resume+0x40/0xa2()
> [70696.199984] Hardware name: 2366DG3
> [70696.199991] Interrupts enabled after irqrouter_resume+0x0/0x43
> [70696.199995] Modules linked in: sco bridge stp llc bnep rfcomm l2cap
> bluetooth speedstep_lib cpufreq_stats cpufreq_powersave b
> infmt_misc usbserial radeon ttm drm_kms_helper drm i2c_algo_bit cfbcopyarea
> cfbimgblt cfbfillrect snd_mixer_oss uvcvideo acpi_cp
> ufreq arc4 ecb ath5k mac80211 ath cfg80211 irda video rng_core snd_intel8x0m
> output ac pcmcia battery thinkpad_acpi processor bu
> tton uhci_hcd ehci_hcd usbcore thermal fan [last unloaded: scsi_wait_scan]
> [70696.200082] Pid: 9215, comm: s2ram Not tainted 2.6.33-rc3 #24
> [70696.200085] Call Trace:
> [70696.200098]  [<c0126702>] warn_slowpath_common+0x65/0x95
> [70696.200104]  [<c0126770>] warn_slowpath_fmt+0x29/0x2c
> [70696.200109]  [<c02c088a>] __sysdev_resume+0x40/0xa2
> [70696.200115]  [<c027664e>] ? irqrouter_resume+0x0/0x43
> [70696.200120]  [<c02c0968>] sysdev_resume+0x7c/0xb4
> [70696.200127]  [<c014c7f2>] suspend_enter+0x87/0xc6
> [70696.200132]  [<c014c891>] suspend_devices_and_enter+0x60/0x8c
> [70696.200138]  [<c014c917>] enter_state+0x5a/0x88
> [70696.200143]  [<c014c259>] state_store+0x99/0xad
> [70696.200147]  [<c014c1c0>] ? state_store+0x0/0xad
> [70696.200155]  [<c02467dd>] kobj_attr_store+0x1a/0x22
> [70696.200163]  [<c01d1300>] sysfs_write_file+0xb9/0xe4
> [70696.200168]  [<c01d1247>] ? sysfs_write_file+0x0/0xe4
> [70696.200176]  [<c0197b55>] vfs_write+0x81/0xb2
> [70696.200181]  [<c0197c29>] sys_write+0x40/0x65
> [70696.200187]  [<c0102913>] sysenter_do_call+0x12/0x22
> [70696.200192] ---[ end trace 36266317b026187b ]---
> [70696.200197] ACPI: Waking up from system sleep state S3
> [70696.282143] platform dock.0: EARLY resume
> [70696.282149] platform dock.1: EARLY resume
>


yep still see this is the latest HEAD
please keep this open.

Justin P. Mattock
Comment 41 Len Brown 2010-01-23 19:10:45 UTC
commit c084ca704a3661bf77690a05bc6bd2c305d87c34
Author: Xiaotian Feng <dfeng@redhat.com>
Date:   Thu Dec 10 19:56:45 2009 +0800

    ACPI: don't cond_resched if irq is disabled


shipped in Linux-2.6.33-rc5
closed
Comment 42 Justin P. Mattock 2010-01-23 19:25:19 UTC
On 01/23/10 11:10, bugzilla-daemon@bugzilla.kernel.org wrote:
> http://bugzilla.kernel.org/show_bug.cgi?id=14483
>
>
> Len Brown<lenb@kernel.org>  changed:
>
>             What    |Removed                     |Added
> ----------------------------------------------------------------------------
>               Status|RESOLVED                    |CLOSED
>
>
>
>
> --- Comment #41 from Len Brown<lenb@kernel.org>   2010-01-23 19:10:45 ---
> commit c084ca704a3661bf77690a05bc6bd2c305d87c34
> Author: Xiaotian Feng<dfeng@redhat.com>
> Date:   Thu Dec 10 19:56:45 2009 +0800
>
>      ACPI: don't cond_resched if irq is disabled
>
>
> shipped in Linux-2.6.33-rc5
> closed
>

alright!!

Justin P. Mattock

Note You need to log in before you can comment on or make changes to this bug.