Message-Id: <201201250110.44360.rjw@sisk.pl>
Date:	Wed, 25 Jan 2012 01:10:44 +0100
From:	"Rafael J. Wysocki" <rjw@...k.pl>
To:	Jiri Slaby <jirislaby@...il.com>
Cc:	Jiri Slaby <jslaby@...e.cz>,
	"Srivatsa S. Bhat" <srivatsa.bhat@...ux.vnet.ibm.com>,
	"Linux-pm mailing list" <linux-pm@...ts.linux-foundation.org>,
	LKML <linux-kernel@...r.kernel.org>
Subject: Re: [linux-pm] PM: cannot hibernate -- BUG at kernel/workqueue.c:3659

On Wednesday, January 25, 2012, Jiri Slaby wrote:
> On 01/25/2012 12:02 AM, Rafael J. Wysocki wrote:
> > On Tuesday, January 24, 2012, Jiri Slaby wrote:
> >> On 01/24/2012 11:36 PM, Rafael J. Wysocki wrote:
> >>> On Tuesday, January 24, 2012, Jiri Slaby wrote:
> >>>> On 01/24/2012 05:18 PM, Srivatsa S. Bhat wrote:
> >>>>> Hi Jiri,
> >>>>>
> >>>>> On 01/24/2012 08:35 PM, Jiri Slaby wrote:
> >>>>>
> >>>>>> Hi,
> >>>>>>
> >>>>>> this is a freshly booted system. When I do s2dsk, I see:
> >>>>>> ...
> >>>>>> Freezing remaining freezable tasks ... BUG: 'workqueue_freezing' is true!
> >>>>>> ------------[ cut here ]------------
> >>>>>> kernel BUG at /l/latest/linux/kernel/workqueue.c:3659!
> >>>>>> invalid opcode: 0000 [#1] SMP
> >>>>>> CPU 0
> >>>>>> Modules linked in:
> >>>>>>
> >>>>>> Pid: 2669, comm: s2disk Not tainted 3.3.0-rc1-next-20120124_64+ #1627
> >>>>>> Bochs Bochs
> >>>>>> RIP: 0010:[<ffffffff8107e365>]  [<ffffffff8107e365>]
> >>>>>> freeze_workqueues_begin+0x195/0x1a0
> >>>>>> RSP: 0018:ffff880046f01d68  EFLAGS: 00010292
> >>>>>> RAX: 0000000000000023 RBX: 0000000000000001 RCX: 00000000000000c9
> >>>>>> RDX: 0000000000000077 RSI: 0000000000000046 RDI: ffffffff81b51f7c
> >>>>>> RBP: ffff880046f01d98 R08: ffffffff81a9d760 R09: 0000000000000000
> >>>>>> R10: 0000000000000000 R11: 0000000000000000 R12: 0000000000000000
> >>>>>> R13: 00007fff579464dc R14: ffffffffffffffff R15: 0000000000000004
> >>>>>> FS:  00007f3c65d54700(0000) GS:ffff880049600000(0000) knlGS:0000000000000000
> >>>>>> CS:  0010 DS: 0000 ES: 0000 CR0: 000000008005003b
> >>>>>> CR2: 00007f3c64f58c20 CR3: 0000000045b64000 CR4: 00000000000006f0
> >>>>>> DR0: 0000000000000000 DR1: 0000000000000000 DR2: 0000000000000000
> >>>>>> DR3: 0000000000000000 DR6: 00000000ffff0ff0 DR7: 0000000000000400
> >>>>>> Process s2disk (pid: 2669, threadinfo ffff880046f00000, task
> >>>>>> ffff880047251980)
> >>>>>> Stack:
> >>>>>>  ffff880046f01d98 0000000000000001 0000000000000000 00007fff579464dc
> >>>>>>  ffffffffffffffff 0000000000000004 ffff880046f01e18 ffffffff81096cb9
> >>>>>>  00000000ffff0124 0000000000000004 ffff880046f01e18 000000004f1ec7d1
> >>>>>> Call Trace:
> >>>>>>  [<ffffffff81096cb9>] try_to_freeze_tasks+0x1b9/0x2d0
> >>>>>>  [<ffffffff81096ed5>] freeze_kernel_threads+0x25/0x90
> >>>>>>  [<ffffffff81097b55>] hibernation_snapshot+0x75/0x2e0
> >>>>>>  [<ffffffff8109d724>] snapshot_ioctl+0x314/0x4e0
> >>>>>>  [<ffffffff81130856>] do_vfs_ioctl+0x96/0x550
> >>>>>>  [<ffffffff8111ff7b>] ? vfs_write+0x10b/0x180
> >>>>>>  [<ffffffff81130d5a>] sys_ioctl+0x4a/0x80
> >>>>>>  [<ffffffff81630e22>] system_call_fastpath+0x16/0x1b
> >>>>>> Code: c7 c6 0a a4 92 81 48 c7 c7 16 65 92 81 31 c0 e8 19 94 5a 00 0f 0b
> >>>>>> 48 c7 c6 27 a4 92 81 48 c7 c7 16 65 92 81 31 c0 e8 02 94 5a 00 <0f> 0b
> >>>>>> 66 0f 1f 84 00 00 00 00 00 55 48 c7 c7 82 4b b9 81 48 89
> >>>>>> RIP  [<ffffffff8107e365>] freeze_workqueues_begin+0x195/0x1a0
> >>>>>>  RSP <ffff880046f01d68>
> >>>>>> ---[ end trace 632574abdc098963 ]---
> >>>>>>
> >>>>>
> >>>>>
> >>>>> I couldn't find any obvious root-cause from a quick check. Is this completely
> >>>>> reproducible upon a fresh boot?
> >>>>
> >>>> True.
> >>>>
> >>>> The cause is that the function is called twice:
> >>>
> >>> Which function?
> >>
> >> The one where the BUG is. Maybe the functions which should clear the
> >> flag is not called in between? See:
> >>
> >>>>  [<ffffffff8107e206>] freeze_workqueues_begin+0x36/0x1b0
> >>                          ^^^^^^^^^^^^^^^^^^^^^^^
> >>>>  [<ffffffff81096cc9>] try_to_freeze_tasks+0x1b9/0x2d0
> >>>>  [<ffffffff81096ee5>] freeze_kernel_threads+0x25/0x90
> >>>>  [<ffffffff81097b65>] hibernation_snapshot+0x75/0x2e0
> >>>>  [<ffffffff8109d734>] snapshot_ioctl+0x314/0x4e0
> >>>>  [<ffffffff81130866>] do_vfs_ioctl+0x96/0x550
> >>>>  [<ffffffff8111ff8b>] ? vfs_write+0x10b/0x180
> >>>>  [<ffffffff81130d6a>] sys_ioctl+0x4a/0x80
> >>>>  [<ffffffff81630e22>] system_call_fastpath+0x16/0x1b
> >>>> (elapsed 0.03 seconds) done.
> >> ...
> >>>> Freezing remaining freezable tasks ... BUG: 'workqueue_freezing' is true!
> >>>> ------------[ cut here ]------------
> >>>> kernel BUG at /l/latest/linux/kernel/workqueue.c:3659!
> >> ...
> >>>> RIP: 0010:[<ffffffff8107e371>]  [<ffffffff8107e371>
> >>>> freeze_workqueues_begin+0x1a1/0x1b0
> >>    ^^^^^^^^^^^^^^^^^^^^^^^
> >>>> Call Trace:
> >>>>  [<ffffffff81096cc9>] try_to_freeze_tasks+0x1b9/0x2d0
> >>>>  [<ffffffff81096ee5>] freeze_kernel_threads+0x25/0x90
> >>>>  [<ffffffff81097b65>] hibernation_snapshot+0x75/0x2e0
> >>>>  [<ffffffff8109d734>] snapshot_ioctl+0x314/0x4e0
> >>>>  [<ffffffff81130866>] do_vfs_ioctl+0x96/0x550
> >>>>  [<ffffffff8111ff8b>] ? vfs_write+0x10b/0x180
> >>>>  [<ffffffff81130d6a>] sys_ioctl+0x4a/0x80
> >>>>  [<ffffffff81630e22>] system_call_fastpath+0x16/0x1b
> > 
> > Ah.  So this is linux-next, right?
> 
> Right.
> 
> > Can you please test the linux-next branch of the linux-pm tree and see if
> > the problem is reproducible in there?
> 
> Yeah, 100%. Just try it with a small enough swap.

Ah, thanks, so that's an error code path problem and most likely in the Linus'
tree.

Srivatsa, any ideas?

Rafael
--
To unsubscribe from this list: send the line "unsubscribe linux-kernel" in
the body of a message to majordomo@...r.kernel.org
More majordomo info at  http://vger.kernel.org/majordomo-info.html
Please read the FAQ at  http://www.tux.org/lkml/

Powered by blists - more mailing lists