Re: [2.6.29-rc2] Inconsistent lock state on resume in hres_timers_resume

["Rafael J. Wysocki" <rjw@sisk.pl>]

On Monday 19 January 2009, Andrey Borzenkov wrote:
> On 19 января 2009 03:17:49 Rafael J. Wysocki wrote:
> > 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.
> > >
> 
> With sligtly modified patch:
> 
> [  133.000279] PM: Syncing filesystems ... done.                                
> [  133.062027] orinoco_cs 0.0: firmware: requesting agere_sta_fw.bin            
> [  133.102942] Freezing user space processes ... (elapsed 0.02 seconds) 
> done.   
> [  133.123635] Freezing remaining freezable tasks ... (elapsed 0.00 seconds) 
> done.                                                                              
> [  133.124813] Suspending console(s) (use no_console_suspend to debug)          
> [  133.136151] sd 0:0:0:0: [sda] Synchronizing SCSI cache                       
> [  133.648916] sd 0:0:0:0: [sda] Stopping disk                                  
> [  134.339703] pci 0000:01:00.0: power state changed by ACPI to D3              
> [  134.354447] e100 0000:00:0a.0: PME# enabled                                  
> [  134.354679] e100 0000:00:0a.0: wake-up capability enabled by ACPI            
> [  134.354845] e100 0000:00:0a.0: PCI INT A disabled                            
> [  134.420836] ALI 5451 0000:00:06.0: PCI INT A disabled                        
> [  134.433823] ALI 5451 0000:00:06.0: power state changed by ACPI to D3         
> [  135.192366] pata_ali 0000:00:04.0: can't derive routing for PCI INT A        
> [  135.203635] ohci_hcd 0000:00:02.0: PME# enabled                              
> [  135.203854] ohci_hcd 0000:00:02.0: wake-up capability enabled by ACPI        
> [  135.203886] ohci_hcd 0000:00:02.0: PCI INT A disabled                        
> [  135.220184] ACPI: Preparing to enter system sleep state S3                   
> [  135.233610] ------------[ cut here ]------------                             
> [  135.233624] WARNING: at /home/bor/src/linux-
> git/kernel/time/timekeeping.c:357 timekeeping_suspend+0xe9/0x230()                                               
> [  135.233633] Hardware name: PORTEGE 4000                                      
> [  135.233638] [0] Interrupts enabled in timekeeping_suspend                    
> [  135.233772] Pid: 4232, comm: pm-suspend Not tainted 2.6.29-rc2-1avb #7       
> [  135.233779] Call Trace:                                                      
> [  135.233809]  [<c011f8b3>] warn_slowpath+0x73/0xd0                            
> [  135.233825]  [<c0143419>] ? trace_hardirqs_on_caller+0x139/0x190             
> [  135.233835]  [<c014347b>] ? trace_hardirqs_on+0xb/0x10                       
> [  135.233844]  [<c013831a>] ? up+0x2a/0x40                                     
> [  135.233870]  [<c02346ba>] ? acpi_os_signal_semaphore+0x25/0x29               
> [  135.233902]  [<c024aea0>] ? acpi_ut_release_mutex+0x54/0x58                  
> [  135.233935]  [<c02423f9>] ? acpi_get_data+0x51/0x60                          
> [  135.233952]  [<c024c5c7>] ? acpi_bus_data_handler+0x0/0x5                    
> [  135.233962]  [<c024be26>] ? acpi_bus_get_device+0x20/0x32                    
> [  135.233973]  [<c024bec6>] ? acpi_bus_power_manageable+0xe/0x25               
> [  135.234002]  [<c02226a4>] ? acpi_pci_power_manageable+0x14/0x20              
> [  135.234012]  [<c021c972>] ? pci_set_power_state+0x92/0x2c0                   
> [  135.234049]  [<c021ab5a>] ? pci_find_capability+0x5a/0x80                    
> [  135.234059]  [<c013ac19>] timekeeping_suspend+0xe9/0x230                     
> [  135.234090]  [<c0273825>] sysdev_suspend+0xb5/0x270                          
> [  135.234119]  [<c0278adf>] ? device_pm_lock+0xf/0x20                          
> [  135.234128]  [<c027944f>] device_power_down+0xef/0x110                       
> [  135.234156]  [<c0150612>] suspend_devices_and_enter+0xb2/0x150               
> [  135.234167]  [<c0150e1f>] ? freeze_processes+0x3f/0x90                       
> [  135.234176]  [<c0150804>] enter_state+0xf4/0x140                             
> [  135.234185]  [<c01508cd>] state_store+0x7d/0xc0                              
> [  135.234193]  [<c0150850>] ? state_store+0x0/0xc0                             
> [  135.234219]  [<c0202f94>] kobj_attr_store+0x24/0x30                          
> [  135.234229]  [<c01dd72c>] sysfs_write_file+0x9c/0x100                        
> [  135.234262]  [<c019935c>] vfs_write+0x9c/0x160                               
> [  135.234277]  [<c0103494>] ? restore_nocheck_notrace+0x0/0xe                  
> [  135.234285]  [<c01dd690>] ? sysfs_write_file+0x0/0x100                       
> [  135.234294]  [<c01994dd>] sys_write+0x3d/0x70                                
> [  135.234303]  [<c0103371>] sysenter_do_call+0x12/0x31                         
> [  135.234310] ---[ end trace 0160afff8645b4ac ]---                             
> 
> I am absolutely confused. According to Documentation/power/devices.txt, 
> timekeeping_suspend and timekeeping_resume are class interfaces and allowed 
> to sleep. "Allowed to sleep" means to me - irqa enabled? But 
> device_power_down obviously runs under irqs disabled?

That's correct, device_power_down() runs with interrupts off, so
timekeeping_resume() is not allowed to sleep.

However, I suspect the problem is somewhere else.

Can you apply the patch I sent earlier in this thread
(http://lkml.org/lkml/2009/1/18/183) and retest?

Thanks,
Rafael