| Message ID | 1367884221-20462-14-git-send-email-ccross@android.com (mailing list archive) |
|---|---|
| State | Accepted, archived |
| Headers | show |
On Mon, 6 May 2013 16:50:18 -0700
Colin Cross <ccross@android.com> wrote:
> Avoid waking up every thread sleeping in a futex_wait call during
[...]
With 3.11-rc s2disk from suspend-utils stopped working: Frozen at
displaying 0% of saving image to disk.
echo "1" >/sys/power/state still works.
Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, reverting
that from 3.11-rc2 makes s2disk working again.
On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun <lkml20130126@newton.leun.net> wrote: > On Mon, 6 May 2013 16:50:18 -0700 > Colin Cross <ccross@android.com> wrote: > >> Avoid waking up every thread sleeping in a futex_wait call during > [...] > > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > displaying 0% of saving image to disk. > > echo "1" >/sys/power/state still works. > > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, reverting > that from 3.11-rc2 makes s2disk working again. > I think the expanded use of the freezable_* helpers is exposing an existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls freeze_processes(), which sets the global system_freezing_cnt and pm_freezing. try_to_freeze_tasks then sends every process except current a signal which causes them all to end up in the refrigerator. The current task then returns back to userspace and continues its work to suspend to disk. If that task ever hits a call to try_to_freeze() in the kernel, it will see system_freezing_cnt and pm_freezing=true and freeze, and suspend to disk will hang forever. It could hit try_to_freeze() because of a signal delivered to the task, or from calling any syscall that uses a freezable_* helper like the one I added to sys_futex. I think the right solution is to add a flag to the freezing task that marks it unfreezable. I think PF_NOFREEZE would work, although it is normally used on kernel threads, can you see if the attached patch helps?
On Tue 2013-07-23 01:02:50, Michael Leun wrote: > On Mon, 6 May 2013 16:50:18 -0700 > Colin Cross <ccross@android.com> wrote: > > > Avoid waking up every thread sleeping in a futex_wait call during > [...] > > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > displaying 0% of saving image to disk. > > echo "1" >/sys/power/state still works. > > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, reverting > that from 3.11-rc2 makes s2disk working again. Would id be possible to get all the backtraces using magic sysrq? ...actually... I see what could happen. Before, system hibernated in state where all the futexes were unlocked. Now, it can happen that we attempt s2disk with futex held. s2disk should not depend on other parts of userspace, and should not take futexes, but maybe it does...? Pavel
On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross <ccross@android.com> wrote: > > I think the right solution is to add a flag to the freezing task that > marks it unfreezable. I think PF_NOFREEZE would work, although it is > normally used on kernel threads, can you see if the attached patch > helps? Hmm. That does seem to be the right thing to do, but I wonder about the *other* callers of freeze_processes() IOW, kexec and friends. So maybe we should do this in {freeze|thaw}_processes() itself, and just make the rule be that the caller of freeze_processes() itself is obviously not frozen, and has to be the same one that then thaws things? Colin? Rafael? Comments? Linus -- To unsubscribe from this list: send the line "unsubscribe linux-pm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, Jul 22, 2013 at 5:32 PM, Linus Torvalds <torvalds@linux-foundation.org> wrote: > On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross <ccross@android.com> wrote: >> >> I think the right solution is to add a flag to the freezing task that >> marks it unfreezable. I think PF_NOFREEZE would work, although it is >> normally used on kernel threads, can you see if the attached patch >> helps? > > Hmm. That does seem to be the right thing to do, but I wonder about > the *other* callers of freeze_processes() IOW, kexec and friends. > > So maybe we should do this in {freeze|thaw}_processes() itself, and > just make the rule be that the caller of freeze_processes() itself is > obviously not frozen, and has to be the same one that then thaws > things? > > Colin? Rafael? Comments? > > Linus I was worried about clearing the flag in thaw_processes(). If a kernel thread with PF_NOFREEZE set ever called thaw_processes(), which autosleep might do, it would clear the flag. Or if a different thread called freeze_processes() and thaw_processes(). All the other callers besides the SNAPSHOT_FREEZE ioctl stay in the kernel between freeze_processes() and thaw_processes(), which makes the fanout of places that could call try_to_freeze() much more controllable. Using a new flag that operates like PF_NOFREEZE but doesn't conflict with it, or a nofreeze_depth counter, would also work. -- To unsubscribe from this list: send the line "unsubscribe linux-pm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Monday, July 22, 2013 05:42:49 PM Colin Cross wrote: > On Mon, Jul 22, 2013 at 5:32 PM, Linus Torvalds > <torvalds@linux-foundation.org> wrote: > > On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross <ccross@android.com> wrote: > >> > >> I think the right solution is to add a flag to the freezing task that > >> marks it unfreezable. I think PF_NOFREEZE would work, although it is > >> normally used on kernel threads, can you see if the attached patch > >> helps? > > > > Hmm. That does seem to be the right thing to do, but I wonder about > > the *other* callers of freeze_processes() IOW, kexec and friends. > > > > So maybe we should do this in {freeze|thaw}_processes() itself, and > > just make the rule be that the caller of freeze_processes() itself is > > obviously not frozen, and has to be the same one that then thaws > > things? > > > > Colin? Rafael? Comments? > > > > Linus > > I was worried about clearing the flag in thaw_processes(). If a > kernel thread with PF_NOFREEZE set ever called thaw_processes(), which > autosleep might do, it would clear the flag. Or if a different thread > called freeze_processes() and thaw_processes(). Is that legitimate? > All the other callers besides the SNAPSHOT_FREEZE ioctl stay in the kernel > between freeze_processes() and thaw_processes(), which makes the fanout of > places that could call try_to_freeze() much more controllable. > > Using a new flag that operates like PF_NOFREEZE but doesn't conflict > with it, or a nofreeze_depth counter, would also work. Well, that would be robust enough. At least if the purpose of that new flag is clearly specified, people hopefully won't be tempted to optimize it away in the future. Thanks, Rafael
On Mon, Jul 22, 2013 at 6:41 PM, Rafael J. Wysocki <rjw@sisk.pl> wrote: > On Monday, July 22, 2013 05:42:49 PM Colin Cross wrote: >> On Mon, Jul 22, 2013 at 5:32 PM, Linus Torvalds >> <torvalds@linux-foundation.org> wrote: >> > On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross <ccross@android.com> wrote: >> >> >> >> I think the right solution is to add a flag to the freezing task that >> >> marks it unfreezable. I think PF_NOFREEZE would work, although it is >> >> normally used on kernel threads, can you see if the attached patch >> >> helps? >> > >> > Hmm. That does seem to be the right thing to do, but I wonder about >> > the *other* callers of freeze_processes() IOW, kexec and friends. >> > >> > So maybe we should do this in {freeze|thaw}_processes() itself, and >> > just make the rule be that the caller of freeze_processes() itself is >> > obviously not frozen, and has to be the same one that then thaws >> > things? >> > >> > Colin? Rafael? Comments? >> > >> > Linus >> >> I was worried about clearing the flag in thaw_processes(). If a >> kernel thread with PF_NOFREEZE set ever called thaw_processes(), which >> autosleep might do, it would clear the flag. Or if a different thread >> called freeze_processes() and thaw_processes(). > > Is that legitimate? Nothing precludes it today, but I don't see any need for it. I'll add a comment when I add the flag. >> All the other callers besides the SNAPSHOT_FREEZE ioctl stay in the kernel >> between freeze_processes() and thaw_processes(), which makes the fanout of >> places that could call try_to_freeze() much more controllable. >> >> Using a new flag that operates like PF_NOFREEZE but doesn't conflict >> with it, or a nofreeze_depth counter, would also work. > > Well, that would be robust enough. At least if the purpose of that new flag > is clearly specified, people hopefully won't be tempted to optimize it away in > the future. > > Thanks, > Rafael OK, I'll add a new flag. -- To unsubscribe from this list: send the line "unsubscribe linux-pm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Mon, 22 Jul 2013 16:55:58 -0700 Colin Cross <ccross@android.com> wrote: > On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun > <lkml20130126@newton.leun.net> wrote: > > On Mon, 6 May 2013 16:50:18 -0700 > > Colin Cross <ccross@android.com> wrote: > > > >> Avoid waking up every thread sleeping in a futex_wait call during > > [...] > > > > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > > displaying 0% of saving image to disk. > > > > echo "1" >/sys/power/state still works. > > > > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, > > reverting that from 3.11-rc2 makes s2disk working again. > > > > I think the expanded use of the freezable_* helpers is exposing an > existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls > freeze_processes(), which sets the global system_freezing_cnt and > pm_freezing. try_to_freeze_tasks then sends every process except > current a signal which causes them all to end up in the refrigerator. > The current task then returns back to userspace and continues its work > to suspend to disk. If that task ever hits a call to try_to_freeze() > in the kernel, it will see system_freezing_cnt and pm_freezing=true > and freeze, and suspend to disk will hang forever. It could hit > try_to_freeze() because of a signal delivered to the task, or from > calling any syscall that uses a freezable_* helper like the one I > added to sys_futex. > > I think the right solution is to add a flag to the freezing task that > marks it unfreezable. I think PF_NOFREEZE would work, although it is > normally used on kernel threads, can you see if the attached patch > helps? That patch helps. BTW, the only machine I can reproduce this bug with is an i7-3630QM notebook. Cannot reproduce on an Core Duo U1400 and cannot reproduce on an i7 M 620. Are the sysreq backtraces still wanted? If so, any tip, how I could get them saved?
On Tue, 2013-07-23 at 20:08 +0200, Michael Leun wrote: > On Mon, 22 Jul 2013 16:55:58 -0700 > Colin Cross <ccross@android.com> wrote: > > > On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun > > <lkml20130126@newton.leun.net> wrote: > > > On Mon, 6 May 2013 16:50:18 -0700 > > > Colin Cross <ccross@android.com> wrote: > > > > > >> Avoid waking up every thread sleeping in a futex_wait call during > > > [...] > > > > > > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > > > displaying 0% of saving image to disk. > > > > > > echo "1" >/sys/power/state still works. > > > > > > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, > > > reverting that from 3.11-rc2 makes s2disk working again. > > > > > > > I think the expanded use of the freezable_* helpers is exposing an > > existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls > > freeze_processes(), which sets the global system_freezing_cnt and > > pm_freezing. try_to_freeze_tasks then sends every process except > > current a signal which causes them all to end up in the refrigerator. > > The current task then returns back to userspace and continues its work > > to suspend to disk. If that task ever hits a call to try_to_freeze() > > in the kernel, it will see system_freezing_cnt and pm_freezing=true > > and freeze, and suspend to disk will hang forever. It could hit > > try_to_freeze() because of a signal delivered to the task, or from > > calling any syscall that uses a freezable_* helper like the one I > > added to sys_futex. > > > > I think the right solution is to add a flag to the freezing task that > > marks it unfreezable. I think PF_NOFREEZE would work, although it is > > normally used on kernel threads, can you see if the attached patch > > helps? > > That patch helps. > > BTW, the only machine I can reproduce this bug with is an i7-3630QM > notebook. Cannot reproduce on an Core Duo U1400 and cannot reproduce on > an i7 M 620. > > Are the sysreq backtraces still wanted? If so, any tip, how I could get > them saved? Typically by setting up a serial console or a netconsole and saving the log from the attached terminal emulator (such as screen or minicom). Is this what you are asking?
On Tue, Jul 23, 2013 at 11:08 AM, Michael Leun <lkml20130126@newton.leun.net> wrote: > On Mon, 22 Jul 2013 16:55:58 -0700 > Colin Cross <ccross@android.com> wrote: > >> On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun >> <lkml20130126@newton.leun.net> wrote: >> > On Mon, 6 May 2013 16:50:18 -0700 >> > Colin Cross <ccross@android.com> wrote: >> > >> >> Avoid waking up every thread sleeping in a futex_wait call during >> > [...] >> > >> > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at >> > displaying 0% of saving image to disk. >> > >> > echo "1" >/sys/power/state still works. >> > >> > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, >> > reverting that from 3.11-rc2 makes s2disk working again. >> > >> >> I think the expanded use of the freezable_* helpers is exposing an >> existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls >> freeze_processes(), which sets the global system_freezing_cnt and >> pm_freezing. try_to_freeze_tasks then sends every process except >> current a signal which causes them all to end up in the refrigerator. >> The current task then returns back to userspace and continues its work >> to suspend to disk. If that task ever hits a call to try_to_freeze() >> in the kernel, it will see system_freezing_cnt and pm_freezing=true >> and freeze, and suspend to disk will hang forever. It could hit >> try_to_freeze() because of a signal delivered to the task, or from >> calling any syscall that uses a freezable_* helper like the one I >> added to sys_futex. >> >> I think the right solution is to add a flag to the freezing task that >> marks it unfreezable. I think PF_NOFREEZE would work, although it is >> normally used on kernel threads, can you see if the attached patch >> helps? > > That patch helps. > > BTW, the only machine I can reproduce this bug with is an i7-3630QM > notebook. Cannot reproduce on an Core Duo U1400 and cannot reproduce on > an i7 M 620. > > Are the sysreq backtraces still wanted? If so, any tip, how I could get > them saved? > > > -- > MfG, > > Michael Leun > Any chance that the failing machine has threads=y in the suspend.conf file? Rafael, it appears that swsusp's suspend.c spawns new threads after calling the SNAPSHOT_FREEZE ioctl. The PF_NOFREEZE (or the new flag) will get copied to those new threads, but nothing will clear the flag. Should I just assume that the userspace suspend code will kill those threads before continuing with suspend? Or maybe add a WARN_ON in the kernel if any threads besides current have the new flag set when the suspend ops that assume all of userspace is frozen are called? -- To unsubscribe from this list: send the line "unsubscribe linux-pm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Tue, 23 Jul 2013 11:29:57 -0700 Colin Cross <ccross@android.com> wrote: > On Tue, Jul 23, 2013 at 11:08 AM, Michael Leun > <lkml20130126@newton.leun.net> wrote: > > On Mon, 22 Jul 2013 16:55:58 -0700 > > Colin Cross <ccross@android.com> wrote: > > > >> On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun > >> <lkml20130126@newton.leun.net> wrote: > >> > On Mon, 6 May 2013 16:50:18 -0700 > >> > Colin Cross <ccross@android.com> wrote: > >> > > >> >> Avoid waking up every thread sleeping in a futex_wait call > >> >> during > >> > [...] > >> > > >> > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > >> > displaying 0% of saving image to disk. > >> > > >> > echo "1" >/sys/power/state still works. > >> > > >> > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, > >> > reverting that from 3.11-rc2 makes s2disk working again. > >> > > >> > >> I think the expanded use of the freezable_* helpers is exposing an > >> existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls > >> freeze_processes(), which sets the global system_freezing_cnt and > >> pm_freezing. try_to_freeze_tasks then sends every process except > >> current a signal which causes them all to end up in the > >> refrigerator. The current task then returns back to userspace and > >> continues its work to suspend to disk. If that task ever hits a > >> call to try_to_freeze() in the kernel, it will see > >> system_freezing_cnt and pm_freezing=true and freeze, and suspend > >> to disk will hang forever. It could hit try_to_freeze() because > >> of a signal delivered to the task, or from calling any syscall > >> that uses a freezable_* helper like the one I added to sys_futex. > >> > >> I think the right solution is to add a flag to the freezing task > >> that marks it unfreezable. I think PF_NOFREEZE would work, > >> although it is normally used on kernel threads, can you see if the > >> attached patch helps? > > > > That patch helps. > > > > BTW, the only machine I can reproduce this bug with is an i7-3630QM > > notebook. Cannot reproduce on an Core Duo U1400 and cannot > > reproduce on an i7 M 620. > > > > Are the sysreq backtraces still wanted? If so, any tip, how I could > > get them saved? Darren Hart <dvhart@linux.intel.com> wrote: > Typically by setting up a serial console or a netconsole and saving [...] > Is this what you are asking? Yes, and it indeed works - I halfway expected the net / netconsole stuff being already frozen in that situation... Thanks, Darren - see below for the backtraces. > > Any chance that the failing machine has threads=y in the suspend.conf > file? Yes, that indeed is the trigger / difference, enabling that on the U4100 (its not a U1400) machine makes that fail also and disabling makes it work on the i7-3630QM. [ 1405.527138] SysRq : Changing Loglevel [ 1405.527220] Loglevel set to 9 [ 1407.845730] SysRq : Show backtrace of all active CPUs [ 1407.845818] sending NMI to all CPUs: [ 1407.845835] NMI backtrace for cpu 4 [ 1407.845870] CPU: 4 PID: 0 Comm: swapper/4 Not tainted 3.11.0-rc2 #1 [ 1407.845911] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1407.845967] task: ffff880803540000 ti: ffff88080353a000 task.ti: ffff88080353a000 [ 1407.846002] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1407.846046] RSP: 0000:ffff88080353bde8 EFLAGS: 00000046 [ 1407.846072] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1407.846104] RDX: 0000000000000000 RSI: ffff88080353bfd8 RDI: 0000000000000004 [ 1407.846137] RBP: ffff88080353be18 R08: 0000000000000057 R09: 000000000fde67ee [ 1407.846169] R10: 0000000000000000 R11: 00000000003567bb R12: 0000000000000005 [ 1407.846201] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1407.846246] FS: 0000000000000000(0000) GS:ffff88082f300000(0000) knlGS:0000000000000000 [ 1407.846283] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1407.846310] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1407.846342] Stack: [ 1407.846355] ffff88080353be18 0000000481098d4d ffff88082f319e00 ffffffff81a56c00 [ 1407.846401] 000001473bc66eed 0000000000000005 ffff88080353be78 ffffffff81371eea [ 1407.846452] 000000000000010a 000000000df017f3 000000000000010a 000000000df017f3 [ 1407.846498] Call Trace: [ 1407.846520] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1407.846550] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1407.846580] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1407.846607] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1407.846637] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1407.846672] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1407.846709] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1407.847137] NMI backtrace for cpu 0 [ 1407.847140] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 1.301 msecs [ 1407.847198] CPU: 0 PID: 0 Comm: swapper/0 Not tainted 3.11.0-rc2 #1 [ 1407.847220] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1407.847254] task: ffffffff81a10440 ti: ffffffff81a00000 task.ti: ffffffff81a00000 [ 1407.847283] RIP: 0010:[<ffffffff8126667f>] [ 1407.847387] RBP: ffff88082f203b98 R08: 0000000000000001 R09: 000000000000066c [ 1407.847414] R10: ffffffff81a1ec40 R11: 0000000000000000 R12: 000000000000006c [ 1407.847441] R13: 0000000000000086 R14: 0000000000000001 R15: 0000000000000009 [ 1407.847467] FS: 0000000000000000(0000) GS:ffff88082f200000(0000) knlGS:0000000000000000 [ 1407.847495] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1407.847516] CR2: 00007fffb526ebdc CR3: 0000000001a0b000 CR4: 00000000001407f0 [ 1407.847540] Stack: [ 1407.847550] ffff88082f203bb8 ffffffff81030500 0000000000000000 ffffffff81a5bd40 [ 1407.847589] ffff88082f203bc8 ffffffff812ec099 ffff88082f203c08 ffffffff812ec547 [ 1407.847624] ffff88082f203c88 ffff88080e80b400 0000000000000026 0000000000000001 [ 1407.848858] Call Trace: [ 1407.850070] <IRQ> [ 1407.850079] [<ffffffff81030500>] arch_trigger_all_cpu_backtrace+0x80/0xa0 [ 1407.852518] [<ffffffff812ec099>] sysrq_handle_showallcpus+0x9/0x10 [ 1407.853731] [<ffffffff812ec547>] __handle_sysrq+0x127/0x190 [ 1407.854922] [<ffffffff812ec92e>] sysrq_filter+0x33e/0x380 [ 1407.856114] [<ffffffff81335522>] input_to_handler+0x52/0xf0 [ 1407.857308] [<ffffffff813375a9>] input_pass_values.part.9+0x169/0x170 [ 1407.858508] [<ffffffff813388c7>] input_handle_event+0x117/0x530 [ 1407.859706] [<ffffffff81338de2>] input_event+0x52/0x70 [ 1407.860910] [<ffffffff81340457>] atkbd_interrupt+0x5e7/0x6b0 [ 1407.862117] [<ffffffff813329ed>] serio_interrupt+0x4d/0xa0 [ 1407.863317] [<ffffffff81333e4a>] i8042_interrupt+0x1ba/0x3a0 [ 1407.864513] [<ffffffff810708a1>] ? raw_notifier_call_chain+0x11/0x20 [ 1407.865716] [<ffffffff810984f8>] ? timekeeping_update.constprop.8+0x38/0x80 [ 1407.866926] [<ffffffff812a1bb0>] ? fbcon_add_cursor_timer+0x100/0x100 [ 1407.868139] [<ffffffff810cc78d>] handle_irq_event_percpu+0x6d/0x240 [ 1407.869357] [<ffffffff810cc9a3>] handle_irq_event+0x43/0x70 [ 1407.870572] [<ffffffff810cf07f>] handle_edge_irq+0x6f/0x110 [ 1407.871788] [<ffffffff81004aed>] handle_irq+0x1d/0x30 [ 1407.872996] [<ffffffff810045c5>] do_IRQ+0x55/0xd0 [ 1407.874202] [<ffffffff814989ea>] common_interrupt+0x6a/0x6a [ 1407.875410] <EOI> [ 1407.875419] [<ffffffff810a0b7f>] ? tick_program_event+0x1f/0x30 [ 1407.877811] [<ffffffff81371ef6>] ? cpuidle_enter_state+0x56/0xd0 [ 1407.879001] [<ffffffff81371ef2>] ? cpuidle_enter_state+0x52/0xd0 [ 1407.880171] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1407.881330] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1407.882484] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1407.883642] [<ffffffff81485380>] rest_init+0x80/0x90 [ 1407.884795] [<ffffffff81ab2e49>] start_kernel+0x3aa/0x3b7 [ 1407.885944] [<ffffffff81ab289e>] ? repair_env_string+0x5e/0x5e [ 1407.887093] [<ffffffff81ab25a3>] x86_64_start_reservations+0x2a/0x2c [ 1407.888236] [<ffffffff81ab269d>] x86_64_start_kernel+0xf8/0xfc [ 1407.889366] Code: 4c 89 4d f8 c7 45 b8 10 00 00 00 48 89 45 c8 e8 38 ff ff ff c9 c3 66 0f 1f 44 00 00 8d 4e 3f 85 f6 55 0f 49 ce 48 89 e5 c1 f9 06 <85> c9 7e 61 48 83 3f 00 75 57 48 8d 57 08 31 c0 eb 12 0f 1f 80 [ 1407.890771] NMI backtrace for cpu 1 [ 1407.890773] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 44.935 msecs [ 1407.894228] CPU: 1 PID: 0 Comm: swapper/1 Not tainted 3.11.0-rc2 #1 [ 1407.895746] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1407.897286] task: ffff88080350aea0 ti: ffff880803534000 task.ti: ffff880803534000 [ 1407.899298] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1407.901326] RSP: 0018:ffff880803535de8 EFLAGS: 00000046 [ 1407.902884] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1407.904456] RDX: 0000000000000000 RSI: ffff880803535fd8 RDI: 0000000000000001 [ 1407.906026] RBP: ffff880803535e18 R08: 0000000000000057 R09: 000000000ff56e74 [ 1407.907597] R10: 0000000000000000 R11: 00000000003567c1 R12: 0000000000000005 [ 1407.909164] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1407.910669] FS: 0000000000000000(0000) GS:ffff88082f240000(0000) knlGS:0000000000000000 [ 1407.912575] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1407.914455] CR2: 00007ff17fd28000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1407.915879] Stack: [ 1407.917716] ffff880803535e18 0000000181098d4d ffff88082f259e00 ffffffff81a56c00 [ 1407.919152] 00000146e25e4673 0000000000000005 ffff880803535e78 ffffffff81371eea [ 1407.920573] 000000000000010b 000000002c46c98c 000000000000010b 000000002c46c98c [ 1407.921986] Call Trace: [ 1407.923370] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1407.924769] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1407.926166] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1407.927561] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1407.928963] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1407.930368] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1407.932200] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1407.933922] NMI backtrace for cpu 5 [ 1407.933924] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 88.055 msecs [ 1407.936433] CPU: 5 PID: 0 Comm: swapper/5 Not tainted 3.11.0-rc2 #1 [ 1407.937700] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1407.938987] task: ffff880803541750 ti: ffff88080353c000 task.ti: ffff88080353c000 [ 1407.940270] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1407.941576] RSP: 0000:ffff88080353dde8 EFLAGS: 00000046 [ 1407.942873] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1407.944181] RDX: 0000000000000000 RSI: ffff88080353dfd8 RDI: 0000000000000005 [ 1407.945488] RBP: ffff88080353de18 R08: 0000000000000057 R09: 000000000fd6bb17 [ 1407.946798] R10: 0000000000000000 R11: 00000000003567d7 R12: 0000000000000005 [ 1407.948105] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1407.949415] FS: 0000000000000000(0000) GS:ffff88082f340000(0000) knlGS:0000000000000000 [ 1407.950735] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1407.952055] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1407.953389] Stack: [ 1407.954719] ffff88080353de18 0000000581098d4d ffff88082f359e00 ffffffff81a56c00 [ 1407.956084] 000001475993cee2 0000000000000005 ffff88080353de78 ffffffff81371eea [ 1407.957448] 0000000000000109 000000002b8fbaa2 0000000000000109 000000002b8fbaa2 [ 1407.958812] Call Trace: [ 1407.960160] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1407.961519] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1407.962879] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1407.964240] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1407.965602] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1407.966978] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1407.968352] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1407.970046] NMI backtrace for cpu 6 [ 1407.970048] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 124.179 msecs [ 1407.974761] CPU: 6 PID: 0 Comm: swapper/6 Not tainted 3.11.0-rc2 #1 [ 1407.976613] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1407.978491] task: ffff880803542ea0 ti: ffff88080353e000 task.ti: ffff88080353e000 [ 1407.980381] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1407.982855] RSP: 0018:ffff88080353fde8 EFLAGS: 00000046 [ 1407.984756] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1407.986674] RDX: 0000000000000000 RSI: ffff88080353ffd8 RDI: 0000000000000006 [ 1407.988590] RBP: ffff88080353fe18 R08: 0000000000000057 R09: 000000000fcf0e3f [ 1407.991088] R10: 0000000000000000 R11: 00000000003567da R12: 0000000000000005 [ 1407.993018] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1407.994875] FS: 0000000000000000(0000) GS:ffff88082f380000(0000) knlGS:0000000000000000 [ 1407.996698] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1407.998485] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1408.000272] Stack: [ 1408.002572] ffff88080353fe18 0000000681098d4d ffff88082f399e00 ffffffff81a56c00 [ 1408.004361] 0000014777613532 0000000000000005 ffff88080353fe78 ffffffff81371eea [ 1408.006674] 0000000000000109 000000000d948c6f 0000000000000109 000000000d948c6f [ 1408.008443] Call Trace: [ 1408.010189] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1408.011951] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1408.014250] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1408.016546] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1408.018843] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1408.021144] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1408.022885] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1408.024957] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 179.088 msecs [ 1408.024958] NMI backtrace for cpu 2 [ 1408.024960] CPU: 2 PID: 0 Comm: swapper/2 Not tainted 3.11.0-rc2 #1 [ 1408.024961] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1408.024962] task: ffff88080350c5f0 ti: ffff880803536000 task.ti: ffff880803536000 [ 1408.024964] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1408.024965] RSP: 0000:ffff880803537de8 EFLAGS: 00000046 [ 1408.024966] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1408.024967] RDX: 0000000000000000 RSI: ffff880803537fd8 RDI: 0000000000000002 [ 1408.024967] RBP: ffff880803537e18 R08: 0000000000000057 R09: 000000000fedc1a1 [ 1408.024968] R10: 0000000000000000 R11: 00000000003567d7 R12: 0000000000000005 [ 1408.024969] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1408.024970] FS: 0000000000000000(0000) GS:ffff88082f280000(0000) knlGS:0000000000000000 [ 1408.024971] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1408.024971] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1408.024972] Stack: [ 1408.024974] ffff880803537e18 0000000281098d4d ffff88082f299e00 ffffffff81a56c00 [ 1408.024975] 00000147002b9b55 0000000000000005 ffff880803537e78 ffffffff81371eea [ 1408.024976] 000000000000010b 000000000e4baf99 000000000000010b 000000000e4baf99 [ 1408.024977] Call Trace: [ 1408.024979] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1408.024982] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1408.024984] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1408.024985] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1408.024987] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1408.024989] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1408.025006] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1408.025008] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 179.139 msecs [ 1408.025009] NMI backtrace for cpu 7 [ 1408.025011] CPU: 7 PID: 0 Comm: swapper/7 Not tainted 3.11.0-rc2 #1 [ 1408.025011] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1408.025013] task: ffff8808035445f0 ti: ffff880803550000 task.ti: ffff880803550000 [ 1408.025016] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1408.025016] RSP: 0000:ffff880803551de8 EFLAGS: 00000046 [ 1408.025017] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1408.025018] RDX: 0000000000000000 RSI: ffff880803551fd8 RDI: 0000000000000007 [ 1408.025018] RBP: ffff880803551e18 R08: 0000000000000057 R09: 000000000007a079 [ 1408.025019] R10: 0000000000000000 R11: 000000000020e8dc R12: 0000000000000005 [ 1408.025020] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1408.025021] FS: 0000000000000000(0000) GS:ffff88082f3c0000(0000) knlGS:0000000000000000 [ 1408.025022] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1408.025022] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1408.025023] Stack: [ 1408.025025] ffff880803551e18 0000000781098d4d ffff88082f3d9e00 ffffffff81a56c00 [ 1408.025026] 0000014777614583 0000000000000005 ffff880803551e78 ffffffff81371eea [ 1408.025027] 0000000000000000 000000001dcad99a 0000000000000000 000000001dcad99a [ 1408.025028] Call Trace: [ 1408.025030] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1408.025032] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1408.025035] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1408.025036] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1408.025038] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1408.025040] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1408.025057] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1408.025057] NMI backtrace for cpu 3 [ 1408.025059] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 179.189 msecs [ 1408.025061] CPU: 3 PID: 0 Comm: swapper/3 Not tainted 3.11.0-rc2 #1 [ 1408.025061] Hardware name: CLEVO P15xEMx/P15xEMx, BIOS 4.6.5 01/24/2013 [ 1408.025062] task: ffff88080350dd40 ti: ffff880803538000 task.ti: ffff880803538000 [ 1408.025064] RIP: 0010:[<ffffffff812ac403>] [<ffffffff812ac403>] intel_idle+0xa3/0xf0 [ 1408.025065] RSP: 0000:ffff880803539de8 EFLAGS: 00000046 [ 1408.025065] RAX: 0000000000000030 RBX: 0000000000000010 RCX: 0000000000000001 [ 1408.025066] RDX: 0000000000000000 RSI: ffff880803539fd8 RDI: 0000000000000003 [ 1408.025066] RBP: ffff880803539e18 R08: 0000000000000057 R09: 00000000001e939c [ 1408.025067] R10: 0000000000000000 R11: 00000000001c6983 R12: 0000000000000005 [ 1408.025067] R13: 0000000000000030 R14: 0000000000000004 R15: ffffffff81a56dd0 [ 1408.025068] FS: 0000000000000000(0000) GS:ffff88082f2c0000(0000) knlGS:0000000000000000 [ 1408.025068] CS: 0010 DS: 0000 ES: 0000 CR0: 0000000080050033 [ 1408.025069] CR2: 0000000000000000 CR3: 0000000001a0b000 CR4: 00000000001407e0 [ 1408.025069] Stack: [ 1408.025070] ffff880803539e18 0000000381098d4d ffff88082f2d9e00 ffffffff81a56c00 [ 1408.025071] 0000014780148c27 0000000000000005 ffff880803539e78 ffffffff81371eea [ 1408.025071] 0000000000000002 00000000003b0659 0000000000000002 00000000003b0659 [ 1408.025072] Call Trace: [ 1408.025073] [<ffffffff81371eea>] cpuidle_enter_state+0x4a/0xd0 [ 1408.025075] [<ffffffff81372026>] cpuidle_idle_call+0xb6/0x260 [ 1408.025076] [<ffffffff8100c699>] arch_cpu_idle+0x9/0x20 [ 1408.025078] [<ffffffff81097800>] cpu_startup_entry+0x80/0x280 [ 1408.025079] [<ffffffff8109f301>] ? clockevents_config_and_register+0x21/0x30 [ 1408.025080] [<ffffffff8102cc2c>] start_secondary+0x1cc/0x270 [ 1408.025090] Code: 28 e0 ff ff 83 e2 08 75 22 31 d2 48 83 c0 10 48 89 d1 0f 01 c8 0f ae f0 48 8b 86 38 e0 ff ff a8 08 75 08 b1 01 4c 89 e8 0f 01 c9 <85> 1d 8f ab 7a 00 75 0e 48 8d 75 dc bf 05 00 00 00 e8 37 2a df [ 1408.025091] INFO: NMI handler (arch_trigger_all_cpu_backtrace_handler) took too long to run: 179.222 msecs
On Tue, Jul 23, 2013 at 12:16 PM, Michael Leun <lkml20130126@newton.leun.net> wrote: > On Tue, 23 Jul 2013 11:29:57 -0700 > Colin Cross <ccross@android.com> wrote: > >> On Tue, Jul 23, 2013 at 11:08 AM, Michael Leun >> <lkml20130126@newton.leun.net> wrote: >> > On Mon, 22 Jul 2013 16:55:58 -0700 >> > Colin Cross <ccross@android.com> wrote: >> > >> >> On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun >> >> <lkml20130126@newton.leun.net> wrote: >> >> > On Mon, 6 May 2013 16:50:18 -0700 >> >> > Colin Cross <ccross@android.com> wrote: >> >> > >> >> >> Avoid waking up every thread sleeping in a futex_wait call >> >> >> during >> >> > [...] >> >> > >> >> > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at >> >> > displaying 0% of saving image to disk. >> >> > >> >> > echo "1" >/sys/power/state still works. >> >> > >> >> > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, >> >> > reverting that from 3.11-rc2 makes s2disk working again. >> >> > >> >> >> >> I think the expanded use of the freezable_* helpers is exposing an >> >> existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls >> >> freeze_processes(), which sets the global system_freezing_cnt and >> >> pm_freezing. try_to_freeze_tasks then sends every process except >> >> current a signal which causes them all to end up in the >> >> refrigerator. The current task then returns back to userspace and >> >> continues its work to suspend to disk. If that task ever hits a >> >> call to try_to_freeze() in the kernel, it will see >> >> system_freezing_cnt and pm_freezing=true and freeze, and suspend >> >> to disk will hang forever. It could hit try_to_freeze() because >> >> of a signal delivered to the task, or from calling any syscall >> >> that uses a freezable_* helper like the one I added to sys_futex. >> >> >> >> I think the right solution is to add a flag to the freezing task >> >> that marks it unfreezable. I think PF_NOFREEZE would work, >> >> although it is normally used on kernel threads, can you see if the >> >> attached patch helps? >> > >> > That patch helps. >> > >> > BTW, the only machine I can reproduce this bug with is an i7-3630QM >> > notebook. Cannot reproduce on an Core Duo U1400 and cannot >> > reproduce on an i7 M 620. >> > >> > Are the sysreq backtraces still wanted? If so, any tip, how I could >> > get them saved? > > Darren Hart <dvhart@linux.intel.com> wrote: > >> Typically by setting up a serial console or a netconsole and saving > [...] >> Is this what you are asking? > > Yes, and it indeed works - I halfway expected the net / netconsole > stuff being already frozen in that situation... > > Thanks, Darren - see below for the backtraces. > >> >> Any chance that the failing machine has threads=y in the suspend.conf >> file? > > Yes, that indeed is the trigger / difference, enabling that on the > U4100 (its not a U1400) machine makes that fail also and disabling > makes it work on the i7-3630QM. Thanks, if you get a chance sysrq w might be interesting but I think we have enough info to solve the problem. -- To unsubscribe from this list: send the line "unsubscribe linux-pm" in the body of a message to majordomo@vger.kernel.org More majordomo info at http://vger.kernel.org/majordomo-info.html
On Tue, 23 Jul 2013 12:29:57 -0700 Colin Cross <ccross@android.com> wrote: > On Tue, Jul 23, 2013 at 12:16 PM, Michael Leun > <lkml20130126@newton.leun.net> wrote: > > On Tue, 23 Jul 2013 11:29:57 -0700 > > Colin Cross <ccross@android.com> wrote: > > > >> On Tue, Jul 23, 2013 at 11:08 AM, Michael Leun > >> <lkml20130126@newton.leun.net> wrote: > >> > On Mon, 22 Jul 2013 16:55:58 -0700 > >> > Colin Cross <ccross@android.com> wrote: > >> > > >> >> On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun > >> >> <lkml20130126@newton.leun.net> wrote: > >> >> > On Mon, 6 May 2013 16:50:18 -0700 > >> >> > Colin Cross <ccross@android.com> wrote: > >> >> > > >> >> >> Avoid waking up every thread sleeping in a futex_wait call > >> >> >> during > >> >> > [...] > >> >> > > >> >> > With 3.11-rc s2disk from suspend-utils stopped working: > >> >> > Frozen at displaying 0% of saving image to disk. > >> >> > > >> >> > echo "1" >/sys/power/state still works. > >> >> > > >> >> > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, > >> >> > reverting that from 3.11-rc2 makes s2disk working again. > >> >> > > >> >> > >> >> I think the expanded use of the freezable_* helpers is exposing > >> >> an existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls > >> >> freeze_processes(), which sets the global system_freezing_cnt > >> >> and pm_freezing. try_to_freeze_tasks then sends every process > >> >> except current a signal which causes them all to end up in the > >> >> refrigerator. The current task then returns back to userspace > >> >> and continues its work to suspend to disk. If that task ever > >> >> hits a call to try_to_freeze() in the kernel, it will see > >> >> system_freezing_cnt and pm_freezing=true and freeze, and suspend > >> >> to disk will hang forever. It could hit try_to_freeze() because > >> >> of a signal delivered to the task, or from calling any syscall > >> >> that uses a freezable_* helper like the one I added to > >> >> sys_futex. > >> >> > >> >> I think the right solution is to add a flag to the freezing task > >> >> that marks it unfreezable. I think PF_NOFREEZE would work, > >> >> although it is normally used on kernel threads, can you see if > >> >> the attached patch helps? > >> > > >> > That patch helps. > >> > > >> > BTW, the only machine I can reproduce this bug with is an > >> > i7-3630QM notebook. Cannot reproduce on an Core Duo U1400 and > >> > cannot reproduce on an i7 M 620. > >> > > >> > Are the sysreq backtraces still wanted? If so, any tip, how I > >> > could get them saved? > > > > Darren Hart <dvhart@linux.intel.com> wrote: > > > >> Typically by setting up a serial console or a netconsole and saving > > [...] > >> Is this what you are asking? > > > > Yes, and it indeed works - I halfway expected the net / netconsole > > stuff being already frozen in that situation... > > > > Thanks, Darren - see below for the backtraces. > > > >> > >> Any chance that the failing machine has threads=y in the > >> suspend.conf file? > > > > Yes, that indeed is the trigger / difference, enabling that on the > > U4100 (its not a U1400) machine makes that fail also and disabling > > makes it work on the i7-3630QM. > > Thanks, if you get a chance sysrq w might be interesting but I think > we have enough info to solve the problem. > Now that I've set up everything this is no big effort... [ 343.801889] Loglevel set to 9 [ 347.336205] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.337184] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.338170] [<ffffffff8107601e>] ? __wake_up+0x4e/0x70 [ 347.339163] [<ffffffffa0198866>] kjournald2+0x236/0x240 [jbd2] [ 347.340156] [<ffffffff8106ba70>] ? finish_wait+0x80/0x80 [ 347.341162] [<ffffffffa0198630>] ? journal_init_common+0x160/0x160 [jbd2] [ 347.342162] [<ffffffff8106b27b>] kthread+0xbb/0xc0 [ 347.343143] [<ffffffff8106b1c0>] ? kthread_create_on_node+0x130/0x130 [ 347.344116] [<ffffffff814990ac>] ret_from_fork+0x7c/0xb0 [ 347.345059] [<ffffffff8106b1c0>] ? kthread_create_on_node+0x130/0x130 [ 347.345983] systemd-journal D ffff88082f252d40 0 526 1 0x00000000 [ 347.346919] ffff8807f63e7dd8 0000000000000082 ffff8807f72e1750 ffff8807f63e7fd8 [ 347.347871] ffff8807f63e7fd8 ffff8807f63e7fd8 ffff88080350aea0 ffff8807f72e1750 [ 347.348827] ffff8807f63e7dc8 ffff8807f72e1750 ffff8807f72e1750 ffff8807f72e1750 [ 347.349784] Call Trace: [ 347.350733] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.351688] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.352641] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 347.353592] [<ffffffff811b3a30>] ep_poll+0x320/0x340 [ 347.354533] [<ffffffff81392361>] ? sock_ioctl+0x71/0x2a0 [ 347.355473] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.356414] [<ffffffff811b4aa5>] SyS_epoll_wait+0xd5/0x100 [ 347.357350] [<ffffffff81499152>] system_call_fastpath+0x16/0x1b [ 347.358286] kauditd D ffff88082f312d40 0 527 2 0x00000000 [ 347.359236] ffff8807f618bde8 0000000000000046 ffff8807f7361750 ffff8807f618bfd8 [ 347.360198] ffff8807f618bfd8 ffff8807f618bfd8 ffff880803540000 ffff8807f7361750 [ 347.361165] ffff8807f7259380 ffff8807f7361750 ffff8807f7361750 ffff8807f7361750 [ 347.362132] Call Trace: [ 347.363084] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.364043] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.365001] [<ffffffff8107601e>] ? __wake_up+0x4e/0x70 [ 347.365959] [<ffffffff810c0c5a>] kauditd_thread+0x1aa/0x1b0 [ 347.366913] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.367860] [<ffffffff810c0ab0>] ? audit_printk_skb+0x70/0x70 [ 347.368805] [<ffffffff8106b27b>] kthread+0xbb/0xc0 [ 347.369746] [<ffffffff8106b1c0>] ? kthread_create_on_node+0x130/0x130 [ 347.370685] [<ffffffff814990ac>] ret_from_fork+0x7c/0xb0 [ 347.371621] [<ffffffff8106b1c0>] ? kthread_create_on_node+0x130/0x130 [ 347.372565] systemd-udevd D ffff88082f252d40 0 553 1 0x00000000 [ 347.373524] ffff8807f5fdbdd8 0000000000000086 ffff8807f72b5d40 ffff8807f5fdbfd8 [ 347.374496] ffff8807f5fdbfd8 ffff8807f5fdbfd8 ffff88080350aea0 ffff8807f72b5d40 [ 347.375471] 0000000000000000 ffff8807f72b5d40 ffff8807f72b5d40 ffff8807f72b5d40 [ 347.376444] Call Trace: [ 347.377402] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.378369] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.379333] [<ffffffff811b3a30>] ep_poll+0x320/0x340 [ 347.380296] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.381254] [<ffffffff811b4aa5>] SyS_epoll_wait+0xd5/0x100 [ 347.382206] [<ffffffff81499152>] system_call_fastpath+0x16/0x1b [ 347.383158] haveged D ffff88082f352d40 0 858 1 0x00000000 [ 347.384129] ffff8807f641b908 0000000000000082 ffff8807f45add40 ffff8807f641bfd8[ 347.385106] ffff8807f641bfd8 ffff8807f641bfd8 ffff880803541750 ffff8807f45add40 [ 347.386083] ffff8807f641b8f8 ffff8807f45add40 ffff8807f45add40 ffff8807f45add40[ 347.389000] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.389976] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 347.390949] [<ffffffff81180699>] poll_schedule_timeout+0xa9/0xb0 [ 347.391915] [<ffffffff81180fd5>] do_select+0x6f5/0x840 [ 347.393845] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 347.396686] [<ffffffff81105834>] ? filemap_fault+0x84/0x460 [ 347.397623] [<ffffffff81103512>] ? unlock_page+0x22/0x30 [ 347.401351] [<ffffffff81181303>] core_sys_select+0x1e3/0x310 [ 347.402278] [<ffffffff81306c7b>] ? credit_entropy_bits.part.7+0x18b/0x1f0 [ 347.403209] [<ffffffff8130710a>] ? random_ioctl+0x16a/0x190 [ 347.404140] [<ffffffff8130710a>] ? random_ioctl+0x16a/0x190 [ 347.540893] ffff8807f7378d00 ffff8808029f8000 ffff8808029f8000[ 347.543682] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.544609] [<ffffffff8107601e>] ? __wake_up+0x4e/0x70 [ 347.546466] [<ffffffff8106ba70>] ? finish_wait+0x80/0x80 [ 347.549269] [<ffffffff8106b1c0>] ? kthread_create_on_node+0x130/0x130 [ 347.553048] ffff8807f4de7d18 0000000000000086 ffff8807f6e02ea0 ffff8807f4de7fd8[ 347.554022] ffff8807f4de7fd8 ffff8807f6e02ea0 ffff8807f6e02ea0 [ 347.556887] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.557837] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.559725] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 ffff88082f212d40 [ 347.577740] [<ffffffff81180fd5>] do_select+0x6f5/0x840 [ 347.584244] [<ffffffff81128d6e>] ? __do_fault+0x1ee/0x520 [ 347.590613] [<ffffffff81499152>] system_call_fastpath+0x16/0x1b [ 347.592425] ffff8807f5ce9908 ffff8807f4a82ea0 ffff8807f5ce9fd8[ 347.594265] 0000000000007530 ffff8807f4a82ea0 [ 347.597922] [<ffffffff8106ed7f>] ? hrtimer_start_range_ns+0xf/0x20 ffff88082f212d40 [ 347.813797] ffff8807fc6d5a68 0000000000000086 ffff8807fc6d5fd8 [ 347.814556] ffff8807fc6d5fd8 ffffffff81a10440[ 347.956796] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.957668] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 347.958543] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 347.959418] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 347.960290] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.961160] [<ffffffff812e7857>] ? tty_ldisc_deref+0x37/0xa0 [ 347.962029] [<ffffffff812dfd61>] ? tty_read+0xa1/0x100 [ 347.962894] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 347.963762] [<ffffffff8116e21d>] ? SyS_read+0x4d/0xa0 [ 347.964627] [<ffffffff814993da>] int_signal+0x12/0x17 [ 347.965489] bash D ffff88082f212d40 0 2780 2707 0x00000004 [ 347.966369] ffff8807f99b7d18 0000000000000086 ffff8807f9cfc5f0 ffff8807f99b7fd8 [ 347.967258] ffff8807f99b7fd8 ffff8807f99b7fd8 ffffffff81a10440 ffff8807f9cfc5f0 [ 347.968140] ffff8807f99b7d08 ffff8807f9cfc5f0 ffff8807f9cfc5f0 ffff8807f9cfc5f0 [ 347.969014] Call Trace: [ 347.969873] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.970743] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.971606] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 347.972469] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 347.973333] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 347.974193] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.975056] [<ffffffff812e7857>] ? tty_ldisc_deref+0x37/0xa0 [ 347.975917] [<ffffffff812dfd61>] ? tty_read+0xa1/0x100 [ 347.976774] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 347.977634] [<ffffffff8116e21d>] ? SyS_read+0x4d/0xa0 [ 347.978492] [<ffffffff814993da>] int_signal+0x12/0x17 [ 347.979348] bash D ffff88082f252d40 0 2786 2700 0x00000004 [ 347.980221] ffff8807f98d3d18 0000000000000086 ffff8807f9f92ea0 ffff8807f98d3fd8 [ 347.981113] ffff8807f98d3fd8 ffff8807f98d3fd8 ffff8807f9de0000 ffff8807f9f92ea0 [ 347.981996] ffff8807f98d3d08 ffff8807f9f92ea0 ffff8807f9f92ea0 ffff8807f9f92ea0 [ 347.982868] Call Trace: [ 347.983722] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.984587] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.985448] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 347.986306] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 347.987168] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 347.988027] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 347.988890] [<ffffffff812e7857>] ? tty_ldisc_deref+0x37/0xa0 [ 347.989748] [<ffffffff812dfd61>] ? tty_read+0xa1/0x100 [ 347.990603] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 347.991460] [<ffffffff8116e21d>] ? SyS_read+0x4d/0xa0 [ 347.992316] [<ffffffff814993da>] int_signal+0x12/0x17 [ 347.993170] bash D ffff88082f352d40 0 2792 2707 0x00000004 [ 347.994042] ffff8807f9f25d18 0000000000000086 ffff8807f9cf8000 ffff8807f9f25fd8 [ 347.994930] ffff8807f9f25fd8 ffff8807f9f25fd8 ffff8807fa300000 ffff8807f9cf8000 [ 347.995810] ffff8807f9f25d08 ffff8807f9cf8000 ffff8807f9cf8000 ffff8807f9cf8000 [ 347.996680] Call Trace: [ 347.997533] [<ffffffff81496df4>] schedule+0x24/0x70 [ 347.998397] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 347.999254] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 348.000111] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 348.000971] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 348.001831] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 348.002687] [<ffffffff812e7857>] ? tty_ldisc_deref+0x37/0xa0 [ 348.003540] [<ffffffff812dfd61>] ? tty_read+0xa1/0x100 [ 348.004395] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 348.005248] [<ffffffff8116e21d>] ? SyS_read+0x4d/0xa0 [ 348.006102] [<ffffffff814993da>] int_signal+0x12/0x17 [ 348.006955] bash D ffff88082f252d40 0 2798 2700 0x00000004 [ 348.007823] ffff8807f9e41d18 0000000000000082 ffff8807f9de0000 ffff8807f9e41fd8 [ 348.008709] ffff8807f9e41fd8 ffff8807f9e41fd8 ffff88080350aea0 ffff8807f9de0000 [ 348.009588] ffff8807f9e41d08 ffff8807f9de0000 ffff8807f9de0000 ffff8807f9de0000 [ 348.010460] Call Trace: [ 348.011313] [<ffffffff81496df4>] schedule+0x24/0x70 [ 348.012179] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 348.013036] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 348.013893] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 348.014755] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 348.015611] [<ffffffff8107b120>] ? try_to_wake_up+0x2b0/0x2b0 [ 348.016469] [<ffffffff812e7857>] ? tty_ldisc_deref+0x37/0xa0 [ 348.017325] [<ffffffff812dfd61>] ? tty_read+0xa1/0x100 [ 348.018179] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 348.158814] ffff8807fc441fd8 ffff8807fc441fd8 ffff880803540000 ffff8807f9c4dd40 [ 348.159718] ffff8807fc441a58 ffff8807f9c4dd40 ffff8807f9c4dd40 ffff8807f9c4dd40 [ 348.160622] Call Trace: [ 348.161503] [<ffffffff81496df4>] schedule+0x24/0x70 [ 348.162386] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 348.163269] [<ffffffff8106ed7f>] ? hrtimer_start_range_ns+0xf/0x20 [ 348.164158] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 348.165039] [<ffffffff81180699>] poll_schedule_timeout+0xa9/0xb0 [ 348.165921] [<ffffffff81181b3d>] do_sys_poll+0x3ed/0x5b0 [ 348.166798] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 348.167676] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 348.168544] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 348.169405] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 348.170255] [<ffffffff81180580>] ? __pollwait+0xf0/0xf0 [ 348.171096] [<ffffffff81394c28>] ? SYSC_recvfrom+0x118/0x140 [ 348.171938] [<ffffffff81098e17>] ? ktime_get_ts+0x47/0xe0 [ 348.172781] [<ffffffff811808c2>] ? poll_select_set_timeout+0x72/0x90 [ 348.173624] [<ffffffff81181dcd>] SyS_poll+0x6d/0x100 [ 348.174468] [<ffffffff81499152>] system_call_fastpath+0x16/0x1b [ 348.175314] systemd-sleep D ffff88082f292d40 0 3262 1 0x00000004 [ 348.176167] ffff8807fc7e1d18 0000000000000086 ffff8807f6fa8000 ffff8807fc7e1fd8 [ 348.177024] ffff8807fc7e1fd8 ffff8807fc7e1fd8 ffff88080350c5f0 ffff8807f6fa8000 [ 348.177881] ffff8807fc7e1d08 ffff8807f6fa8000 ffff8807f6fa8000 ffff8807f6fa8000 [ 348.178740] Call Trace: [ 348.179575] [<ffffffff81496df4>] schedule+0x24/0x70 [ 348.180418] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 348.181264] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 348.182109] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 348.182956] [<ffffffff81075ba4>] ? finish_task_switch+0x44/0xd0 [ 348.183803] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 348.184647] [<ffffffff8106bda1>] ? remove_wait_queue+0x51/0x60 [ 348.185494] [<ffffffff8104acd3>] ? do_wait+0x123/0x280 [ 348.186335] [<ffffffff8107b27b>] ? wake_up_new_task+0xfb/0x1a0 [ 348.187181] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 348.188028] [<ffffffff81049a70>] ? task_stopped_code+0x50/0x50 [ 348.188880] [<ffffffff814993da>] int_signal+0x12/0x17 [ 348.189725] pm-hibernate D ffff88082f3d2d40 0 3264 3262 0x00000004 [ 348.190576] ffff8807fc16bd18 0000000000000086 ffff8807fa2eaea0 ffff8807fc16bfd8 [ 348.191439] ffff8807fc16bfd8 ffff8807fc16bfd8 ffff8808035445f0 ffff8807fa2eaea0 [ 348.192307] ffff8807fc16bd08 ffff8807fa2eaea0 ffff8807fa2eaea0 ffff8807fa2eaea0 [ 348.193163] Call Trace: [ 348.194004] [<ffffffff81496df4>] schedule+0x24/0x70 [ 348.194852] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 348.195704] [<ffffffff810bab88>] ? cgroup_freezing+0x28/0x40 [ 348.196554] [<ffffffff8105b14c>] get_signal_to_deliver+0x5fc/0x650 [ 348.197406] [<ffffffff810801e3>] ? pick_next_task_fair+0x63/0x180 [ 348.198258] [<ffffffff81075ba4>] ? finish_task_switch+0x44/0xd0 [ 348.199114] [<ffffffff81002392>] do_signal+0x52/0x5a0 [ 348.199968] [<ffffffff8106bda1>] ? remove_wait_queue+0x51/0x60 [ 348.200817] [<ffffffff8104acd3>] ? do_wait+0x123/0x280 [ 348.201657] [<ffffffff8107b27b>] ? wake_up_new_task+0xfb/0x1a0 [ 348.202494] [<ffffffff81002945>] do_notify_resume+0x65/0x80 [ 348.203331] [<ffffffff81049a70>] ? task_stopped_code+0x50/0x50 [ 348.204166] [<ffffffff814993da>] int_signal+0x12/0x17 [ 348.204999] s2disk D ffff88082f392d40 0 3483 3264 0x00000000 [ 348.205841] ffff8807fc10fbf8 0000000000000082 ffff8807fa5d0000 ffff8807fc10ffd8 [ 348.206699] ffff8807fc10ffd8 ffff8807fc10ffd8 ffff880803542ea0 ffff8807fa5d0000 [ 348.207563] ffff8807f725de40 ffff8807fa5d0000 ffff8807fa5d0000 ffff8807fa5d0000 [ 348.208423] Call Trace: [ 348.209270] [<ffffffff81496df4>] schedule+0x24/0x70 [ 348.210124] [<ffffffff81097aad>] __refrigerator+0x4d/0x140 [ 348.210979] [<ffffffff810a2ba5>] futex_wait_queue_me+0x125/0x140 [ 348.211838] [<ffffffff810a3381>] futex_wait+0x181/0x290 [ 348.212691] [<ffffffff810a4e3c>] do_futex+0x11c/0xb30 [ 348.213545] [<ffffffff810a58e3>] SyS_futex+0x93/0x1a0 [ 348.214389] [<ffffffff81075ba4>] ? finish_task_switch+0x44/0xd0 [ 348.215229] [<ffffffff81079572>] ? schedule_tail+0x22/0xa0 [ 348.216063] [<ffffffff81499152>] system_call_fastpath+0x16/0x1b [ 348.216907] Sched Debug Version: v0.10, 3.11.0-rc2 #1 [ 348.217736] ktime : 347737.351160 [ 348.218572] sched_clk : 348216.906329 [ 348.219406] cpu_clk : 348216.906356 [ 348.220232] jiffies : 4295015036 [ 348.221053] sched_clock_stable : 1 [ 348.221871] [ 348.222674] sysctl_sched [ 348.223478] .sysctl_sched_latency : 24.000000 [ 348.345542] .nr_running : 0 [ 348.346103] .load : 0 [ 348.346660] .runnable_load_avg : 0 [ 348.347219] .blocked_load_avg : 0 [ 348.347774] .tg_load_contrib : 0 [ 348.348327] .tg_runnable_contrib : 0 [ 348.348878] .tg_load_avg : 0 [ 348.349429] .tg->runnable_avg : 5 [ 348.349985] .avg->runnable_avg_sum : 36 [ 348.350539] .avg->runnable_avg_period : 48194 [ 348.351092] [ 348.351092] rt_rq[1]:/system/systemd-hibernate.service [ 348.352186] .rt_nr_running : 0 [ 348.352747] .rt_throttled : 0 [ 348.353307] .rt_time : 0.000000 [ 348.353867] .rt_runtime : 0.000000 [ 348.354421] [ 348.354421] rt_rq[1]:/system/bluetooth.service [ 348.355507] .rt_nr_running : 0 [ 348.356066] .rt_throttled : 0 [ 348.356625] .rt_time : 0.000000 [ 348.357183] .rt_runtime : 0.000000 [ 348.357740] [ 348.357740] rt_rq[1]:/system/udisks2.service [ 348.358841] .rt_nr_running : 0 [ 348.359406] .rt_throttled : 0 [ 348.359972] .rt_time : 0.000000 [ 348.360540] .rt_runtime : 0.000000 [ 348.361108] [ 348.361108] rt_rq[1]:/system/polkit.service [ 348.362228] .rt_nr_running : 0 [ 348.362801] .rt_throttled : 0 [ 348.363375] .rt_time : 0.000000 [ 348.363948] .rt_runtime : 0.000000 [ 348.364521] [ 348.364521] rt_rq[1]:/system/upower.service [ 348.365605] .rt_nr_running : 0 [ 348.366130] .rt_throttled : 0 [ 348.366657] .rt_time : 0.000000 [ 348.367179] .rt_runtime : 0.000000 [ 348.367702] [ 348.367702] rt_rq[1]:/system/postfix.service/control [ 348.368740] .rt_nr_running : 0 [ 348.369269] .rt_throttled : 0 [ 348.369799] .rt_time : 0.000000 [ 348.370323] .rt_runtime : 0.000000 [ 348.370844] [ 348.370844] rt_rq[1]:/system/sshd.service [ 348.371876] .rt_nr_running : 0 [ 348.372408] .rt_throttled : 0 [ 348.372946] .rt_time : 0.000000 [ 348.373489] .rt_runtime : 0.000000 [ 348.374028] [ 348.374028] rt_rq[1]:/system/postfix.service [ 348.375095] .rt_nr_running : 0 [ 348.375641] .rt_throttled : 0 [ 348.376184] .rt_time : 0.000000 [ 348.376732] .rt_runtime : 0.000000 [ 348.377276] [ 348.377276] rt_rq[1]:/system/cron.service [ 348.378354] .rt_nr_running : 0 [ 348.378900] .rt_throttled : 0 [ 348.379447] .rt_time : 0.000000 [ 348.379994] .rt_runtime : 0.000000 [ 348.380541] [ 348.380541] rt_rq[1]:/system/xdm.service [ 348.381614] .rt_nr_running : 0 [ 348.382163] .rt_throttled : 0 [ 348.382714] .rt_time : 0.000000 [ 348.383264] .rt_runtime : 0.000000 [ 348.383811] [ 348.383811] rt_rq[1]:/system/dbus.service [ 348.384893] .rt_nr_running : 0 [ 348.385448] .rt_throttled : 0 [ 348.386000] .rt_time : 0.000000 [ 348.386554] .rt_runtime : 0.000000 [ 348.387105] [ 348.387105] rt_rq[1]:/system/getty@.service/tty1 [ 348.388188] .rt_nr_running : 0 [ 348.388735] .rt_throttled : 0 [ 348.389284] .rt_time : 0.000000 [ 348.389834] .rt_runtime : 0.000000 [ 348.390385] [ 348.390385] rt_rq[1]:/system/getty@.service [ 348.391467] .rt_nr_running : 0 [ 348.392015] .rt_throttled : 0 [ 348.392562] .rt_time : 0.000000 [ 348.393112] .rt_runtime : 0.000000 [ 348.393661] [ 348.393661] rt_rq[1]:/system/systemd-logind.service [ 348.394744] .rt_nr_running : 0 [ 348.395291] .rt_throttled : 0 [ 348.395836] .rt_time : 0.000000 [ 348.396385] .rt_runtime : 0.000000 [ 348.396934] [ 348.396934] rt_rq[1]:/system/rsyslog.service [ 348.398015] .rt_nr_running : 0 [ 348.398564] .rt_throttled : 0 [ 348.399110] .rt_time : 0.000000 [ 348.399659] .rt_runtime : 0.000000 [ 348.400211] [ 348.400211] rt_rq[1]:/system/haveged.service [ 348.401292] .rt_nr_running : 0 [ 348.401842] .rt_throttled : 0 [ 348.402390] .rt_time : 0.000000 [ 348.402940] .rt_runtime : 0.000000 [ 348.403487] [ 348.403487] rt_rq[1]:/system/systemd-fsck@.service [ 348.404567] .rt_nr_running : 0 [ 348.405111] .rt_throttled : 0 [ 348.405656] .rt_time : 0.000000 [ 348.406202] .rt_runtime : 0.000000 [ 348.406750] [ 348.406750] rt_rq[1]:/system/systemd-udevd.service [ 348.407831] .rt_nr_running : 0 [ 348.408379] .rt_throttled : 0 [ 348.408926] .rt_time : 0.000000 [ 348.409475] .rt_runtime : 0.000000 [ 348.410024] [ 348.410024] rt_rq[1]:/system/systemd-journald.service [ 348.411110] .rt_nr_running : 0 [ 348.411659] .rt_throttled : 0 [ 348.412207] .rt_time : 0.000000 [ 348.412756] .rt_runtime : 0.000000 [ 348.413308] [ 348.413308] rt_rq[1]:/system [ 348.414385] .rt_nr_running : 0 [ 348.414931] .rt_throttled : 0 [ 348.415473] .rt_time : 0.000000 [ 348.416019] .rt_runtime : 0.000000 [ 348.416564] [ 348.416564] rt_rq[1]:/ [ 348.417627] .rt_nr_running : 0 [ 348.418163] .rt_throttled : 0 [ 348.418700] .rt_time : 0.000000 [ 348.419240] .rt_runtime : 950.000000 [ 348.419782] [ 348.419782] runnable tasks: [ 348.419782] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [ 348.419782] ---------------------------------------------------------------------------------------------------------- [ 348.421983] [ 348.422555] cpu#2, 2394.479 MHz [ 348.423140] .nr_running : 0 [ 348.423729] .load : 0 [ 348.424313] .nr_switches : 46347 [ 348.424893] .nr_load_updates : 12960 [ 348.425473] .nr_uninterruptible : -42 [ 348.426053] .next_balance : 4295.014754 [ 348.426641] .curr->pid : 0 [ 348.427228] .clock : 347934.367461 [ 348.427814] .cpu_load[0] : 0 [ 348.428394] .cpu_load[1] : 0 [ 348.552446] .rt_nr_running : 0 [ 348.552973] .rt_throttled : 0 [ 348.636728] .rt_time : 0.000000 [ 348.554024] .rt_runtime : 0.000000 [ 348.560864] [ 348.560864] rt_rq[3]:/system/postfix.service [ 348.561921] .rt_nr_running : 0 [ 348.562464] .rt_throttled : 0 [ 348.780964] .rt_nr_running : 0 [ 348.563556] .rt_runtime : 0.000000 [ 348.564097] [ 348.564097] rt_rq[3]:/system/cron.service [ 348.566793] .rt_runtime : 0.000000 [ 348.567332] [ 348.567332] rt_rq[3]:/system/xdm.service [ 348.568396] .rt_nr_running : 0 [ 348.568941] .rt_throttled : 0 [ 348.570035] .rt_runtime : 0.000000 [ 348.570581] [ 348.570581] rt_rq[3]:/system/dbus.service [ 348.571659] .rt_nr_running : 0 [ 348.803324] .cpu_load[4] : 0 [ 348.573864] [ 348.573864] rt_rq[3]:/system/getty@.service/tty1 [ 348.576024] .rt_time : 0.000000 [ 348.576568] .rt_runtime : 0.000000 [ 348.578181] .rt_nr_running : 0 [ 348.578722] .rt_throttled : 0 [ 348.579263] .rt_time : 0.000000 [ 348.580349] [ 348.580349] rt_rq[3]:/system/systemd-logind.service [ 348.583049] .rt_runtime : 0.000000 [ 348.583592] [ 348.583592] rt_rq[3]:/system/rsyslog.service [ 348.586294] .rt_runtime : 0.000000 [ 348.586841] [ 348.586841] rt_rq[3]:/system/haveged.service [ 348.588455] .rt_throttled : 0 [ 348.588998] .rt_time : 0.000000 [ 348.590087] [ 348.590087] rt_rq[3]:/system/systemd-fsck@.service [ 348.591164] .rt_nr_running : 0 [ 348.591706] .rt_throttled : 0 [ 348.592247] .rt_time : 0.000000 [ 348.592791] .rt_runtime : 0.000000 [ 348.593335] [ 348.593335] rt_rq[3]:/system/systemd-udevd.service [ 348.594409] .rt_nr_running : 0 [ 348.594956] .rt_throttled : 0 [ 348.596046] .rt_runtime : 0.000000 [ 348.596592] [ 348.596592] rt_rq[3]:/system/systemd-journald.service [ 348.597675] .rt_nr_running : 0 [ 348.598224] .rt_throttled : 0 [ 348.598769] .rt_time : 0.000000 [ 348.599317] .rt_runtime : 0.000000 [ 348.599868] [ 348.599868] rt_rq[3]:/system [ 348.600942] .rt_nr_running : 0 [ 348.601485] .rt_throttled : 0 [ 348.602027] .rt_time : 0.000000 [ 348.602571] .rt_runtime : 0.000000 [ 348.603115] [ 348.603115] rt_rq[3]:/ [ 348.604181] .rt_nr_running : 0 [ 348.604715] .rt_throttled : 0 [ 348.605252] .rt_time : 0.000000 [ 348.605791] .rt_runtime : 950.000000 [ 348.606331] [ 348.606331] runnable tasks: [ 348.606331] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [ 348.606331] ---------------------------------------------------------------------------------------------------------- [ 348.609111] cpu#4, 2394.479 MHz [ 348.609693] .nr_running : 0 [ 348.610281] .load : 0 [ 348.610866] .nr_switches : 26395 [ 348.611446] .nr_load_updates : 9172 [ 348.612608] .next_balance : 4295.011756 [ 348.613786] .clock : 348434.750881 [ 348.614956] .cpu_load[1] : 0 [ 348.615536] .cpu_load[2] : 0 [ 348.616690] .cpu_load[4] : 0 [ 348.617263] .yld_count : 2324 [ 348.618398] .sched_goidle : 11227 [ 348.619530] .ttwu_count : 16564 [ 348.620668] [ 348.620668] cfs_rq[4]:/ [ 348.621770] .exec_clock : 2510.563054 [ 348.624032] .spread : 0.000000 [ 348.624597] .spread0 : 673.526556 [ 348.626834] .runnable_load_avg : 0 [ 348.627389] .blocked_load_avg : 0 [ 348.629587] .tg->runnable_avg : 4 [ 348.630138] .avg->runnable_avg_sum : 0 [ 348.632321] .rt_nr_running : 0 [ 348.633430] .rt_time : 0.000000 [ 348.763005] .rt_runtime : 0.000000 [ 348.769521] .rt_runtime : 0.000000 [ 348.776606] [ 348.776606] rt_rq[5]:/system/systemd-fsck@.service [ 348.777683] .rt_nr_running : 0 [ 348.782614] .rt_runtime : 0.000000 [ 348.785355] .rt_time : 0.000000 [ 348.787539] .rt_nr_running : 0 [ 348.788081] .rt_throttled : 0 [ 348.792389] .rt_runtime : 950.000000 [ 348.796880] .load : 0 [ 348.797467] .nr_switches : 20163 [ 348.963314] .rt_runtime : 0.000000 [ 348.966042] .rt_time : 0.000000 [ 348.968773] .rt_throttled : 0 [ 348.971503] .rt_nr_running : 0 [ 348.976949] [ 348.976949] rt_rq[7]:/ [ 348.979618] .rt_runtime : 950.000000 [ 348.980156] [ 348.980156] runnable tasks: [ 348.980156] task PID tree-key switches prio exec-runtime sum-exec sum-sleep [ 348.980156] ---------------------------------------------------------------------------------------------------------- [ 348.982352]
On Mon, Jul 22, 2013 at 11:28 PM, Colin Cross <ccross@android.com> wrote: > On Mon, Jul 22, 2013 at 6:41 PM, Rafael J. Wysocki <rjw@sisk.pl> wrote: >> On Monday, July 22, 2013 05:42:49 PM Colin Cross wrote: >>> On Mon, Jul 22, 2013 at 5:32 PM, Linus Torvalds >>> <torvalds@linux-foundation.org> wrote: >>> > On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross <ccross@android.com> wrote: >>> >> >>> >> I think the right solution is to add a flag to the freezing task that >>> >> marks it unfreezable. I think PF_NOFREEZE would work, although it is >>> >> normally used on kernel threads, can you see if the attached patch >>> >> helps? >>> > >>> > Hmm. That does seem to be the right thing to do, but I wonder about >>> > the *other* callers of freeze_processes() IOW, kexec and friends. >>> > >>> > So maybe we should do this in {freeze|thaw}_processes() itself, and >>> > just make the rule be that the caller of freeze_processes() itself is >>> > obviously not frozen, and has to be the same one that then thaws >>> > things? >>> > >>> > Colin? Rafael? Comments? >>> > >>> > Linus >>> >>> I was worried about clearing the flag in thaw_processes(). If a >>> kernel thread with PF_NOFREEZE set ever called thaw_processes(), which >>> autosleep might do, it would clear the flag. Or if a different thread >>> called freeze_processes() and thaw_processes(). >> >> Is that legitimate? > > Nothing precludes it today, but I don't see any need for it. I'll add > a comment when I add the flag. > >>> All the other callers besides the SNAPSHOT_FREEZE ioctl stay in the kernel >>> between freeze_processes() and thaw_processes(), which makes the fanout of >>> places that could call try_to_freeze() much more controllable. >>> >>> Using a new flag that operates like PF_NOFREEZE but doesn't conflict >>> with it, or a nofreeze_depth counter, would also work. >> >> Well, that would be robust enough. At least if the purpose of that new flag >> is clearly specified, people hopefully won't be tempted to optimize it away in >> the future. >> >> Thanks, >> Rafael > > OK, I'll add a new flag. Michael, can you see if this patch works and doesn't throw any warnings during suspend or resume? If the extra process flag is considered too precious for this (there are only 2 left after this patch) I could get the same functionality by having freeze_processes() reject calls from a PF_KTHREAD|PF_NOFREEZE thread, and use PF_KTHREAD to determine if PF_NOFREEZE should be cleared in thaw_processes().
On Tuesday, July 23, 2013 11:29:57 AM Colin Cross wrote: > On Tue, Jul 23, 2013 at 11:08 AM, Michael Leun > <lkml20130126@newton.leun.net> wrote: > > On Mon, 22 Jul 2013 16:55:58 -0700 > > Colin Cross <ccross@android.com> wrote: > > > >> On Mon, Jul 22, 2013 at 4:02 PM, Michael Leun > >> <lkml20130126@newton.leun.net> wrote: > >> > On Mon, 6 May 2013 16:50:18 -0700 > >> > Colin Cross <ccross@android.com> wrote: > >> > > >> >> Avoid waking up every thread sleeping in a futex_wait call during > >> > [...] > >> > > >> > With 3.11-rc s2disk from suspend-utils stopped working: Frozen at > >> > displaying 0% of saving image to disk. > >> > > >> > echo "1" >/sys/power/state still works. > >> > > >> > Bisecting yielded 88c8004fd3a5fdd2378069de86b90b21110d33a4, > >> > reverting that from 3.11-rc2 makes s2disk working again. > >> > > >> > >> I think the expanded use of the freezable_* helpers is exposing an > >> existing bug in hibernation. The SNAPSHOT_FREEZE ioctl calls > >> freeze_processes(), which sets the global system_freezing_cnt and > >> pm_freezing. try_to_freeze_tasks then sends every process except > >> current a signal which causes them all to end up in the refrigerator. > >> The current task then returns back to userspace and continues its work > >> to suspend to disk. If that task ever hits a call to try_to_freeze() > >> in the kernel, it will see system_freezing_cnt and pm_freezing=true > >> and freeze, and suspend to disk will hang forever. It could hit > >> try_to_freeze() because of a signal delivered to the task, or from > >> calling any syscall that uses a freezable_* helper like the one I > >> added to sys_futex. > >> > >> I think the right solution is to add a flag to the freezing task that > >> marks it unfreezable. I think PF_NOFREEZE would work, although it is > >> normally used on kernel threads, can you see if the attached patch > >> helps? > > > > That patch helps. > > > > BTW, the only machine I can reproduce this bug with is an i7-3630QM > > notebook. Cannot reproduce on an Core Duo U1400 and cannot reproduce on > > an i7 M 620. > > > > Are the sysreq backtraces still wanted? If so, any tip, how I could get > > them saved? > > > > > > -- > > MfG, > > > > Michael Leun > > > > Any chance that the failing machine has threads=y in the suspend.conf file? > > Rafael, it appears that swsusp's suspend.c spawns new threads after > calling the SNAPSHOT_FREEZE ioctl. The PF_NOFREEZE (or the new flag) > will get copied to those new threads, but nothing will clear the flag. > Should I just assume that the userspace suspend code will kill those > threads before continuing with suspend? Or maybe add a WARN_ON in the > kernel if any threads besides current have the new flag set when the > suspend ops that assume all of userspace is frozen are called? Those threads should be killed by user space. They are only spawned for image saving/compression/encryption and should be waited for after that. Thanks, Rafael
On Tue, 23 Jul 2013 13:31:49 -0700 Colin Cross <ccross@android.com> wrote: > On Mon, Jul 22, 2013 at 11:28 PM, Colin Cross <ccross@android.com> > wrote: > > On Mon, Jul 22, 2013 at 6:41 PM, Rafael J. Wysocki <rjw@sisk.pl> > > wrote: > >> On Monday, July 22, 2013 05:42:49 PM Colin Cross wrote: > >>> On Mon, Jul 22, 2013 at 5:32 PM, Linus Torvalds > >>> <torvalds@linux-foundation.org> wrote: > >>> > On Mon, Jul 22, 2013 at 4:55 PM, Colin Cross > >>> > <ccross@android.com> wrote: > >>> >> > >>> >> I think the right solution is to add a flag to the freezing > >>> >> task that marks it unfreezable. I think PF_NOFREEZE would > >>> >> work, although it is normally used on kernel threads, can you > >>> >> see if the attached patch helps? > >>> > > >>> > Hmm. That does seem to be the right thing to do, but I wonder > >>> > about the *other* callers of freeze_processes() IOW, kexec and > >>> > friends. > >>> > > >>> > So maybe we should do this in {freeze|thaw}_processes() itself, > >>> > and just make the rule be that the caller of freeze_processes() > >>> > itself is obviously not frozen, and has to be the same one that > >>> > then thaws things? > >>> > > >>> > Colin? Rafael? Comments? > >>> > > >>> > Linus > >>> > >>> I was worried about clearing the flag in thaw_processes(). If a > >>> kernel thread with PF_NOFREEZE set ever called thaw_processes(), > >>> which autosleep might do, it would clear the flag. Or if a > >>> different thread called freeze_processes() and thaw_processes(). > >> > >> Is that legitimate? > > > > Nothing precludes it today, but I don't see any need for it. I'll > > add a comment when I add the flag. > > > >>> All the other callers besides the SNAPSHOT_FREEZE ioctl stay in > >>> the kernel between freeze_processes() and thaw_processes(), which > >>> makes the fanout of places that could call try_to_freeze() much > >>> more controllable. > >>> > >>> Using a new flag that operates like PF_NOFREEZE but doesn't > >>> conflict with it, or a nofreeze_depth counter, would also work. > >> > >> Well, that would be robust enough. At least if the purpose of > >> that new flag is clearly specified, people hopefully won't be > >> tempted to optimize it away in the future. > >> > >> Thanks, > >> Rafael > > > > OK, I'll add a new flag. > > > Michael, can you see if this patch works and doesn't throw any > warnings during suspend or resume? Tried several times with and without threads = y in suspend.conf, tried also to produce high load / much processes / high memory usage. Worked every time, no WARN seen. > If the extra process flag is considered too precious for this > (there are only 2 left after this patch) I could get the > same functionality by having freeze_processes() reject calls > from a PF_KTHREAD|PF_NOFREEZE thread, and use PF_KTHREAD to > determine if PF_NOFREEZE should be cleared in thaw_processes(). If another solution is considered please do not hesitate to send me the patch for another round of check.
diff --git a/kernel/futex.c b/kernel/futex.c index b26dcfc..d710fae 100644 --- a/kernel/futex.c +++ b/kernel/futex.c @@ -61,6 +61,7 @@ #include <linux/nsproxy.h> #include <linux/ptrace.h> #include <linux/sched/rt.h> +#include <linux/freezer.h> #include <asm/futex.h> @@ -1807,7 +1808,7 @@ static void futex_wait_queue_me(struct futex_hash_bucket *hb, struct futex_q *q, * is no timeout, or if it has yet to expire. */ if (!timeout || timeout->task) - schedule(); + freezable_schedule(); } __set_current_state(TASK_RUNNING); }