Re: [possible regression] 2.6.22 reiserfs/libata sporadically hangs on resume from hibernation

[Andrey Borzenkov <arvidjaar@mail.ru>]

On Sunday 01 July 2007, Rafael J. Wysocki wrote:
> On Saturday, 30 June 2007 06:59, Andrey Borzenkov wrote:
> > Since 2.6.18 I do not have suspend to RAM; now I am starting to lose
> > suspend to disk :)
> >
> > Environment - vanilla kernel (2.6.22-rc6 currently + squashfs + single
> > pata_ali patch to switch off DMA on CD-ROM), single root on reiserfs,
> > libata with pata_ali driver.
> >
> > Until 2.6.22-rc I never had problems with hibernation. With 2.6.22-rc
> > system hung at least once in every rcX. Up to rc6 those lockups were
> > absolutely silent (black screen without reaction to any key). In rc6 I
> > just got something different. After resume I got on screem:
> >
> > swsusp: Marking nosave pages: 000000000009f000-0000000000100000
> > swsusp: Basic memory bitmaps created
> > swsusp: Basic memory bitmaps freed
> >
> > After that it just sits there doing nothing. Ther was brief sound of HDD
> > but I suspect it was related more to power-on. System was responding to
> > power-on button press:
> >
> > ACPI Error (event-0305): No installed handler for fixed event [00000002
> > 20070125]
> >
> > And SysRq was functioning.
>
> That probably means that there's a deadlock somewhere in there.
>
> > Unfortunately I do not have serial console so I
> > copy manually stacks from several last screens of output; I have tried to
> > make a photo but right now my kbluetooth is refusing to work at all so I
> > cannot transfer them :( (but I suspect quality would be too bad anyway)
> >
> > laptop_mode D
> > 	io_schedule+0xe/0x20
>
> Looks suspicious to me.  Can you identify what line of code this points to?
>

If you could explain how to ... (I never understood what those two numbers 
mean :) ) Here is disassembled function

 4168                   .section .sched.text
 4169                   .p2align 4,,15
 4170                   .globl io_schedule
 4171                   .type io_schedule,@function
 4172                   io_schedule:
 4173 0cd0 55           pushl %ebp
 4174 0cd1 89E5         movl %esp,%ebp
 4175
 4176 0cd3 FF05140A     incl per_cpu__runqueues+2388
 4176      0000
 4177
 4178 0cd9 E8FCFFFF     call schedule
 4178      FF
 4179
 4180 0cde FF0D140A     decl per_cpu__runqueues+2388
 4180      0000
 4181
 4182 0ce4 5D           popl %ebp
 4183 0ce5 C3           ret
 4184                   .size io_schedule,.-io_schedule


> > 	sync_buffer+0x35/0x40
> > 	__wait_on_bit+0x45/0x70
> > 	out_of_line_wait_on_bit+0x6c/0x80
> > 	__wait_on_buffer+0x27/0x30
> > 	search_by_key+0x15e/0x1250 [reiserfs]
> > 	reiserfs_read_locked_inode+0x64/0x570 [reiserfs]
> > 	reiserfs_iget+0x7e/0xa0 [reiserfs]
> > 	reiserfs_lookup+0xc7/0x120 [reiserfs]
> > 	do_lookup+0x138/0x180
> > 	__link_path_walk+0x787/0xce0
> > 	link_path_walk+0x44/0xc0
> > 	path_walk+0x18/0x20
> > 	do_path_lookup_0x88/0x210
> > 	__path_lookupintent_open+0x4d/0x90
> > 	path_lookup_open+0x1f/0x30
> > 	open_exec+0x28/0xb0
> > 	do_execve+0x36/0x1d0
> > 	sys_execve+0x2e/0x80
> > 	sysenter_past_esp+0x5f/0x99
> >
> > 90clock D
> > 	__mutex_lock_slow_path+0xa1/0x290
> > 	mutex_lock+0x21/0x30
> > 	do_lookup+0xa1/0x180
> > 	__link_path_walk+0x44/0xc0
> > 	path_walk+0x18/0x20
> > 	do_path_lookup+0x78/0x210
> > 	__user_walk_fd+0x38/0x50
> > 	vfs_stat_fd+0x21/0x50
> > 	vfs_stat+0x11/0x20
> > 	sys_stat64+0x14/0x30
> > 	sysenter_past_esp+0x5f/0x99
> >
> > alsactl D
> > 	io_schedule+0xe/0x20
>
> Same here.  Hmm.
>
> > 	sync_page+0x35/0x40
> > 	__wait_on_bit_lock+0x3f/0x70
> > 	__lock_page+0x68/0x70
> > 	filemap_nopage+0x16c/0x300
> > 	__handle_mm_faul+0x1d7/0x610
> > 	do_page_fault+0x1d7/0x610
> > 	error_code+0x6a/0x70
> > 	padzero+0x1f/0x30
> > 	load_elf_binary+0x743/0x1ab0
> > 	search_binary_handler+0x7b/0x1f0
> > 	do_execve+0x137/0x1d0
> > 	sys_execve+0x2e/0x80
> > 	sysenter_past_esp+0x5f/0x90
> >
> > After that I could remount, sync and reboot using SysRq (well, after
> > reboot it still insisted on replaying insane number of transactions so
> > may be it did *not* remount / ro after all). Before reboot there was
> > brief output that resembled lockdep warnings, but it went too fast to be
> > readable.
> >
> > usual stuff follows
>
> I see you're using CFQ as the default IO scheduler.  Can you please switch
> to AS and see if that changes anything?
>

Sure, but given that I have no idea how to reproduce the lockup, we may never 
know whether it actually helped.

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