Return-Path: Received: (majordomo@vger.kernel.org) by vger.kernel.org via listexpand id S1756497AbZASASr (ORCPT ); Sun, 18 Jan 2009 19:18:47 -0500 Received: (majordomo@vger.kernel.org) by vger.kernel.org id S1753773AbZASASj (ORCPT ); Sun, 18 Jan 2009 19:18:39 -0500 Received: from ogre.sisk.pl ([217.79.144.158]:59659 "EHLO ogre.sisk.pl" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1753830AbZASASi convert rfc822-to-8bit (ORCPT ); Sun, 18 Jan 2009 19:18:38 -0500 From: "Rafael J. Wysocki" To: Andrey Borzenkov Subject: Re: [2.6.29-rc2] Inconsistent lock state on resume in hres_timers_resume Date: Mon, 19 Jan 2009 01:17:49 +0100 User-Agent: KMail/1.10.3 (Linux/2.6.29-rc2-tst; KDE/4.1.3; x86_64; ; ) Cc: Ingo Molnar , Peter Zijlstra , linux-kernel@vger.kernel.org, Thomas Gleixner References: <200901181642.00886.arvidjaar@mail.ru> <200901182121.24863.rjw@sisk.pl> <200901182347.26083.arvidjaar@mail.ru> In-Reply-To: <200901182347.26083.arvidjaar@mail.ru> MIME-Version: 1.0 Content-Type: text/plain; charset="utf-8" Content-Transfer-Encoding: 8BIT Content-Disposition: inline Message-Id: <200901190117.49748.rjw@sisk.pl> Sender: linux-kernel-owner@vger.kernel.org List-ID: X-Mailing-List: linux-kernel@vger.kernel.org Content-Length: 6458 Lines: 166 On Sunday 18 January 2009, Andrey Borzenkov wrote: > On 18 января 2009 23:21:24 Rafael J. Wysocki wrote: > > > > > As far as I can tell, timekeeping_resume is called via class > > > > ->resume method; and according to comments in sysdev_resume() and > > > > device_power_up(), they are called with interrupts disabled. > > > > > > > > Looking at suspend_enter, irqs *are* disabled at this point. > > > > > > > > So it actually looks like something (may be some driver) > > > > unconditionally enabled irqs in resume path. > > > > > > > > I believe the patch should be hold back until this is clarified. > > > > > > That's a nice theory! > > > > That would be a bad bug. > > > > If the below is correct, I wonder, why I am the only one to see it? > > [ 134.727381] PM: Syncing filesystems ... done. > [ 134.767483] orinoco_cs 0.0: firmware: requesting agere_sta_fw.bin > [ 134.809435] Freezing user space processes ... (elapsed 0.02 seconds) > done. > [ 134.831823] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) > done. > [ 134.832520] Suspending console(s) (use no_console_suspend to debug) > [ 134.844050] sd 0:0:0:0: [sda] Synchronizing SCSI cache > [ 135.335944] sd 0:0:0:0: [sda] Stopping disk > [ 136.019819] pci 0000:01:00.0: power state changed by ACPI to D3 > [ 136.034461] e100 0000:00:0a.0: PME# enabled > [ 136.034699] e100 0000:00:0a.0: wake-up capability enabled by ACPI > [ 136.034868] e100 0000:00:0a.0: PCI INT A disabled > [ 136.097607] ALI 5451 0000:00:06.0: PCI INT A disabled > [ 136.110484] ALI 5451 0000:00:06.0: power state changed by ACPI to D3 > [ 136.894487] pata_ali 0000:00:04.0: can't derive routing for PCI INT A > [ 136.906958] ohci_hcd 0000:00:02.0: PME# enabled > [ 136.907177] ohci_hcd 0000:00:02.0: wake-up capability enabled by ACPI > [ 136.907208] ohci_hcd 0000:00:02.0: PCI INT A disabled > [ 136.923328] ACPI: Preparing to enter system sleep state S3 > [ 136.937129] ------------[ cut here ]------------ > [ 136.937142] WARNING: at /home/bor/src/linux-git/drivers/base/sys.c:400 > sysdev_suspend+0x268/0x270() > [ 136.937151] Hardware name: PORTEGE 4000 > [ 136.937184] timekeeping_suspend+0x0/0x80 enabled IRQs > ... > [ 136.937323] Pid: 4305, comm: pm-suspend Not tainted 2.6.29-rc2-1avb #5 > [ 136.937330] Call Trace: > [ 136.937358] [] warn_slowpath+0x73/0xd0 > [ 136.937373] [] ? mark_held_locks+0x48/0x90 > [ 136.937395] [] ? _spin_unlock_irqrestore+0x35/0x60 > [ 136.937406] [] ? trace_hardirqs_on_caller+0x139/0x190 > [ 136.937433] [] ? init_pit_timer+0x67/0xf0 > [ 136.937442] [] ? trace_hardirqs_on+0xb/0x10 > [ 136.937451] [] ? lock_release_holdtime+0x35/0x210 > [ 136.937466] [] ? clockevents_notify+0x30/0x80 > [ 136.937475] [] ? _spin_unlock+0x1d/0x20 > [ 136.937484] [] ? clockevents_notify+0x30/0x80 > [ 136.937495] [] sysdev_suspend+0x268/0x270 > [ 136.937504] [] ? timekeeping_suspend+0x0/0x80 > [ 136.937535] [] device_power_down+0xef/0x110 > [ 136.937564] [] suspend_devices_and_enter+0xb2/0x150 > [ 136.937575] [] ? freeze_processes+0x3f/0x90 > [ 136.937584] [] enter_state+0xf4/0x140 > [ 136.937594] [] state_store+0x7d/0xc0 > [ 136.937602] [] ? state_store+0x0/0xc0 > [ 136.937629] [] kobj_attr_store+0x24/0x30 > [ 136.937640] [] sysfs_write_file+0x9c/0x100 > [ 136.937673] [] vfs_write+0x9c/0x160 > [ 136.937683] [] ? restore_nocheck_notrace+0x0/0xe > [ 136.937692] [] ? sysfs_write_file+0x0/0x100 > [ 136.937701] [] sys_write+0x3d/0x70 > [ 136.937711] [] sysenter_do_call+0x12/0x31 > [ 136.937718] ---[ end trace a8e2ee01b2b45f69 ]--- > [ 136.937727] ------------[ cut here ]------------ > > This is with this patch: > > > diff --git a/drivers/base/sys.c b/drivers/base/sys.c > index c98c31e..7245496 100644 > --- a/drivers/base/sys.c > +++ b/drivers/base/sys.c > @@ -341,13 +341,17 @@ static void __sysdev_resume(struct sys_device *dev) > struct sysdev_driver *drv; > > /* First, call the class-specific one */ > - if (cls->resume) > + if (cls->resume) { > cls->resume(dev); > + WARN(!irqs_disabled(), "%pF enabled IRQs\n", cls->resume); > + } > > /* Call auxillary drivers next. */ > list_for_each_entry(drv, &cls->drivers, entry) { > - if (drv->resume) > + if (drv->resume) { > drv->resume(dev); > + WARN(!irqs_disabled(), "%pF enabled IRQs\n", drv->resume); > + } > } > } > > @@ -384,6 +388,7 @@ int sysdev_suspend(pm_message_t state) > list_for_each_entry(drv, &cls->drivers, entry) { > if (drv->suspend) { > ret = drv->suspend(sysdev, state); > + WARN(!irqs_disabled(), "%pF enabled IRQs\n", drv- > >suspend); > if (ret) > goto aux_driver; > } > @@ -392,6 +397,7 @@ int sysdev_suspend(pm_message_t state) > /* Now call the generic one */ > if (cls->suspend) { > ret = cls->suspend(sysdev, state); > + WARN(!irqs_disabled(), "%pF enabled IRQs\n", cls->suspend); > if (ret) > goto cls_driver; > } > > Can you apply the appended patch in addition to the above one and see what happens? Rafael --- kernel/time/timekeeping.c | 9 +++++++++ 1 file changed, 9 insertions(+) Index: linux-2.6/kernel/time/timekeeping.c =================================================================== --- linux-2.6.orig/kernel/time/timekeeping.c +++ linux-2.6/kernel/time/timekeeping.c @@ -355,13 +355,22 @@ static int timekeeping_suspend(struct sy timekeeping_suspend_time = read_persistent_clock(); + WARN_ONCE(!irqs_disabled(), + "[1] Interrupts enabled in timekeeping_suspend\n"); + write_seqlock_irqsave(&xtime_lock, flags); clocksource_forward_now(); timekeeping_suspended = 1; write_sequnlock_irqrestore(&xtime_lock, flags); + WARN_ONCE(!irqs_disabled(), + "[2] Interrupts enabled in timekeeping_suspend\n"); + clockevents_notify(CLOCK_EVT_NOTIFY_SUSPEND, NULL); + WARN_ONCE(!irqs_disabled(), + "[3] Interrupts enabled in timekeeping_suspend\n"); + return 0; } -- To unsubscribe from this list: send the line "unsubscribe linux-kernel" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html Please read the FAQ at http://www.tux.org/lkml/