[Bug] ARM: mxs: STI: console can't wake up from freeze

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi,

i'm faced with the issue that on i.MX28 the console is unable to wake up from
freeze ( suspend to idle). I tested it with Linux 4.9-rc1, 4.8 and 3.18 (
cmdline has
no_console_suspend=1 ) and also with a i.MX23 with the same result. The suspend
seems to work, but there is no reaction to the console after the freeze except
an hung task warning after some time:

echo freeze > /sys/power/state

Strangely the suspend to RAM from console works without any issues:

echo mem > /sys/power/state

Any ideas what could be the problem?

Here is the console output:

root at duckbill:~# echo mem > /sys/power/state
[   44.881170] PM: Syncing filesystems ... [   49.726565] done.
[   49.787188] Freezing user space processes ... (elapsed 0.008 seconds) done.
[   49.803455] Freezing remaining freezable tasks ... (elapsed 0.004 seconds)
done.
[   50.553231] PM: suspend of devices complete after 731.338 msecs
[   50.566850] PM: late suspend of devices complete after 7.436 msecs
[   50.581416] PM: noirq suspend of devices complete after 8.124 msecs
[   50.598957] PM: noirq resume of devices complete after 10.888 msecs

[   50.615757] PM: early resume of devices complete after 7.115 msecs
[   50.641481] Suspended for 1.283 seconds
[   50.646424] PM: resume of devices complete after 24.225 msecs
[   50.660304] Restarting tasks ... [   50.706421] done.
root at duckbill:~# echo freeze > /sys/power/state
[   64.701251] PM: Syncing filesystems ... [   65.992083] done.
[   66.014271] Freezing user space processes ... (elapsed 0.004 seconds) done.
[   66.026151] Freezing remaining freezable tasks ... (elapsed 0.002 seconds)
done.
[   66.204858] PM: suspend of devices complete after 163.009 msecs
[   66.218808] PM: late suspend of devices complete after 7.762 msecs
[   66.232985] PM: noirq suspend of devices complete after 7.887 msecs
[  192.228595] random: crng init done
[  243.817366] INFO: task ext4lazyinit:69 blocked for more than 120 seconds.
[  243.824216]       Not tainted 4.9.0-rc1 #1
[  243.828482] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  243.836359] ext4lazyinit    D c05a9fdc     0    69      2 0x00000000
[  243.843028] [<c05a9fdc>] (__schedule) from [<c05aa8e8>] (schedule+0x3c/0xbc)
[  243.850292] [<c05aa8e8>] (schedule) from [<c05ae768>]
(schedule_timeout+0x23c/0x3d8)
[  243.858247] [<c05ae768>] (schedule_timeout) from [<c05a9cc8>]
(io_schedule_timeout+0xb8/0x13c)
[  243.866934] [<c05a9cc8>] (io_schedule_timeout) from [<c05ab308>]
(T.1434+0xac/0x12c)
[  243.874884] [<c05ab308>] (T.1434) from [<c02c7304>]
(submit_bio_wait+0x50/0x68)
[  243.882419] [<c02c7304>] (submit_bio_wait) from [<c02d96f4>]
(blkdev_issue_zeroout+0x174/0x1ec)
[  243.891323] [<c02d96f4>] (blkdev_issue_zeroout) from [<c0196ae8>]
(ext4_init_inode_table+0x1ac/0x3b0)
[  243.900753] [<c0196ae8>] (ext4_init_inode_table) from [<c01ba40c>]
(ext4_lazyinit_thread+0x280/0x398)
[  243.910177] [<c01ba40c>] (ext4_lazyinit_thread) from [<c003bce4>]
(kthread+0xc4/0xe0)
[  243.918213] [<c003bce4>] (kthread) from [<c000a34c>]
(ret_from_fork+0x14/0x28)
[  243.925479]
[  243.925479] Showing all locks held in the system:
[  243.931849] 2 locks held by khungtaskd/10:
[  243.935987]  #0: [  243.937869]  (
rcu_read_lock[  243.940746] ){......}
, at: [  243.943624] [<c00936ac>] watchdog+0xb4/0x61c
[  243.948054]  #1: [  243.949843]  (
tasklist_lock[  243.952700] ){.+.+..}
, at: [  243.955576] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
[  243.961074] 4 locks held by ext4lazyinit/69:
[  243.965380]  #0: [  243.967273]  (
&type->s_umount_key[  243.970673] #22
){++++++}[  243.973257] , at:
[  243.975320] [<c01ba260>] ext4_lazyinit_thread+0xd4/0x398
[  243.980776]  #1: [  243.982566]  (
sb_writers[  243.985167] #3
){.+.+.+}[  243.987778] , at:
[  243.989861] [<c01ba278>] ext4_lazyinit_thread+0xec/0x398
[  243.995201]  #2: [  243.996973]  (
jbd2_handle[  243.999903] ){++++..}
, at: [  244.002796] [<c01f62b8>] start_this_handle+0xec/0x404
[  244.008014]  #3: [  244.009805]  (
&meta_group_info[i]->alloc_sem[  244.014141] ){++++..}
, at: [  244.017138] [<c01969f4>] ext4_init_inode_table+0xb8/0x3b0
[  244.022619] 4 locks held by bash/386:
[  244.026306]  #0: [  244.028204]  (
sb_writers[  244.030825] #4
){.+.+.+}[  244.033326] , at:
[  244.035390] [<c011f470>] vfs_write+0x194/0x1a4
[  244.039985]  #1: [  244.041772]  (
&of->mutex[  244.044374] ){+.+.+.}
, at: [  244.047366] [<c018ff38>] kernfs_fop_write+0xc0/0x1d0
[  244.052381]  #2: [  244.054154]  (
s_active[  244.056571] #44
){.+.+.+}[  244.059289] , at:
[  244.061364] [<c018ff40>] kernfs_fop_write+0xc8/0x1d0
[  244.066354]  #3: [  244.068247]  (
pm_mutex[  244.070690] ){+.+.+.}
, at: [  244.073576] [<c005b520>] pm_suspend+0x98/0x784
[  244.078179]
[  244.079713] =============================================
[  244.079713]
[  244.086660] INFO: task bash:386 blocked for more than 120 seconds.
[  244.092998]       Not tainted 4.9.0-rc1 #1
[  244.097233] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  244.105109] bash            D c05a9fdc     0   386    289 0x00000000
[  244.111762] [<c05a9fdc>] (__schedule) from [<c05aa8e8>] (schedule+0x3c/0xbc)
[  244.119028] [<c05aa8e8>] (schedule) from [<c005aee4>]
(suspend_devices_and_enter+0x480/0xa24)
[  244.127771] [<c005aee4>] (suspend_devices_and_enter) from [<c005b8a8>]
(pm_suspend+0x420/0x784)
[  244.136551] [<c005b8a8>] (pm_suspend) from [<c0059dd8>]
(state_store+0x80/0xcc)
[  244.144075] [<c0059dd8>] (state_store) from [<c02efed0>]
(kobj_attr_store+0x18/0x1c)
[  244.152030] [<c02efed0>] (kobj_attr_store) from [<c0190e54>]
(sysfs_kf_write+0x48/0x4c)
[  244.160217] [<c0190e54>] (sysfs_kf_write) from [<c018ff74>]
(kernfs_fop_write+0xfc/0x1d0)
[  244.168600] [<c018ff74>] (kernfs_fop_write) from [<c011f1e4>]
(__vfs_write+0x2c/0x124)
[  244.176591] [<c011f1e4>] (__vfs_write) from [<c011f390>]
(vfs_write+0xb4/0x1a4)
[  244.184093] [<c011f390>] (vfs_write) from [<c011f554>] (SyS_write+0x44/0x88)
[  244.191326] [<c011f554>] (SyS_write) from [<c000a2c0>]
(ret_fast_syscall+0x0/0x1c)
[  244.199057]
[  244.199057] Showing all locks held in the system:
[  244.205321] 2 locks held by khungtaskd/10:
[  244.209569]  #0: [  244.211361]  (
rcu_read_lock[  244.214221] ){......}
, at: [  244.217216] [<c00936ac>] watchdog+0xb4/0x61c
[  244.221536]  #1: [  244.223308]  (
tasklist_lock[  244.226157] ){.+.+..}
, at: [  244.229244] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
[  244.234628] 4 locks held by ext4lazyinit/69:
[  244.239047]  #0: [  244.240835]  (
&type->s_umount_key[  244.244214] #22
){++++++}[  244.246796] , at:
[  244.248987] [<c01ba260>] ext4_lazyinit_thread+0xd4/0x398
[  244.254340]  #1: [  244.256116]  (
sb_writers[  244.258845] #3
){.+.+.+}[  244.261355] , at:
[  244.263417] [<c01ba278>] ext4_lazyinit_thread+0xec/0x398
[  244.268876]  #2: [  244.270667]  (
jbd2_handle[  244.273350] ){++++..}
, at: [  244.276230] [<c01f62b8>] start_this_handle+0xec/0x404
[  244.281439]  #3: [  244.283228]  (
&meta_group_info[i]->alloc_sem[  244.287682] ){++++..}
, at: [  244.290589] [<c01969f4>] ext4_init_inode_table+0xb8/0x3b0
[  244.296045] 4 locks held by bash/386:
[  244.299857]  #0: [  244.301644]  (
sb_writers[  244.304241] #4
){.+.+.+}[  244.306738] , at:
[  244.308925] [<c011f470>] vfs_write+0x194/0x1a4
[  244.313408]  #1: [  244.315183]  (
&of->mutex[  244.317895] ){+.+.+.}
, at: [  244.320792] [<c018ff38>] kernfs_fop_write+0xc0/0x1d0
[  244.325791]  #2: [  244.327679]  (
s_active[  244.330126] #44
){.+.+.+}[  244.332713] , at:
[  244.334771] [<c018ff40>] kernfs_fop_write+0xc8/0x1d0
[  244.339881]  #3: [  244.341668]  (
pm_mutex[  244.344087] ){+.+.+.}
, at: [  244.346963] [<c005b520>] pm_suspend+0x98/0x784
[  244.351579]
[  244.353102] =============================================
[  244.353102]

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Russell King - ARM Linux]

On Sun, Oct 23, 2016 at 11:19:26AM +0200, Stefan Wahren wrote:
> Hi,
> 
> i'm faced with the issue that on i.MX28 the console is unable to wake up from
> freeze ( suspend to idle). I tested it with Linux 4.9-rc1, 4.8 and 3.18 (
> cmdline has
> no_console_suspend=1 ) and also with a i.MX23 with the same result. The suspend
> seems to work, but there is no reaction to the console after the freeze except
> an hung task warning after some time:

I bet if you remove "no_console_suspend" (it's not =1) then it'll work.

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line: currently at 9.6Mbps down 400kbps up
according to speedtest.net.

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi Russell,

> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 23. Oktober 2016 um
> 15:31 geschrieben:
> 
> 
> On Sun, Oct 23, 2016 at 11:19:26AM +0200, Stefan Wahren wrote:
> > Hi,
> > 
> > i'm faced with the issue that on i.MX28 the console is unable to wake up
> > from
> > freeze ( suspend to idle). I tested it with Linux 4.9-rc1, 4.8 and 3.18 (
> > cmdline has
> > no_console_suspend=1 ) and also with a i.MX23 with the same result. The
> > suspend
> > seems to work, but there is no reaction to the console after the freeze
> > except
> > an hung task warning after some time:
> 
> I bet if you remove "no_console_suspend" (it's not =1) then it'll work.

unfortunately not:

Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled

echo mem > /sys/power/state

Result: Able to wakeup via Debug UART
Expected result: Able to wakeup via Debug UART

---

Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled

echo freeze > /sys/power/state

Result: Unable to wakeup via Debug UART (no hung task warning)
Expected result: Able to wakeup via Debug UART

---

Setting: no_console_suspend in cmdline, Debug UART as wakeup source enabled

echo mem > /sys/power/state

Result: Able to wakeup via Debug UART
Expected result: Able to wakeup via Debug UART

---

Setting: no_console_suspend in cmdline, Debug UART as wake source enabled

echo freeze > /sys/power/state

Result: Unable to wakeup via Debug UART (hung task warning after some minutes)
Expected result: Able to wakeup Debug via UART

---

Setting: no_console_suspend in cmdline, Debug UART as wake source disabled

echo mem > /sys/power/state

Result: Able to wakeup via Debug UART
Expected result: Able to wakeup via Debug UART

---

Setting: no_console_suspend in cmdline, Debug UART as wake source disabled

echo freeze > /sys/power/state

Result: Unable to wakeup via UART (hung task warning after some minutes)
Expected result: Able to wakeup via Debug UART

---

Here some more relevant information about the setup:

The console is operating on Debug UART which is a ARM PL011. The following
kernel configs are set:

CONFIG_PM_SLEEP=y
CONFIG_SUSPEND=y
CONFIG_SUSPEND_FREEZER=y
CONFIG_PM=y

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Russell King - ARM Linux]

On Sat, Oct 29, 2016 at 01:44:14PM +0200, Stefan Wahren wrote:
> unfortunately not:
> 
> Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled
> 
> echo mem > /sys/power/state
> 
> Result: Able to wakeup via Debug UART
> Expected result: Able to wakeup via Debug UART
> 
> ---
> 
> Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled
> 
> echo freeze > /sys/power/state
> 
> Result: Unable to wakeup via Debug UART (no hung task warning)
> Expected result: Able to wakeup via Debug UART

Okay - I know that certain actions are bypassed when no_console_suspend
is set, which has detrimental effects on some ARM platforms, so it was
worth testing - iirc, working no_console_suspend is reliant on the boot
loader re-setting up the serial port after its lost state.

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line: currently at 9.6Mbps down 400kbps up
according to speedtest.net.

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 31. Oktober 2016 um
> 17:17 geschrieben:
> 
> 
> On Sat, Oct 29, 2016 at 01:44:14PM +0200, Stefan Wahren wrote:
> > unfortunately not:
> > 
> > Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled
> > 
> > echo mem > /sys/power/state
> > 
> > Result: Able to wakeup via Debug UART
> > Expected result: Able to wakeup via Debug UART
> > 
> > ---
> > 
> > Setting: no_console_suspend not in cmdline, Debug UART wakeup source enabled
> > 
> > echo freeze > /sys/power/state
> > 
> > Result: Unable to wakeup via Debug UART (no hung task warning)
> > Expected result: Able to wakeup via Debug UART
> 
> Okay - I know that certain actions are bypassed when no_console_suspend
> is set, which has detrimental effects on some ARM platforms, so it was
> worth testing - iirc, working no_console_suspend is reliant on the boot
> loader re-setting up the serial port after its lost state.
> 

I also made the basic PM debugging tests with the available options for pm_test:

freezer: suspend and resume as expected
devices: suspend and resume as expected
platform: suspend and resume as expected

Since these tests use a clock to wakeup, i assume my issue is related to the
debug UART and its required components.

Btw the irqchip/irq-mxs.c doesn't implement neither the irq_set_wake or the
syscore_ops. Could this be the problem?

FWIW here are the debug outputs for "echo mem > /sys/power/state" (no hang) and
"echo freeze > /sys/power/state" (hang). I need to mention that after adding
initcall_debug to the cmdline "echo mem > /sys/power/state" the system wakeups
immediately after the suspend.

echo mem > /sys/power/state

[   62.010376] PM: Syncing filesystems ... [   65.607842] done.
[   65.660964] Freezing user space processes ... (elapsed 0.007 seconds) done.
[   65.676976] Freezing remaining freezable tasks ... (elapsed 0.003 seconds)
done.
[   65.697881] calling  mmc0:0007+ @ 93, parent: mmc0
[   65.704356] call mmc0:0007+ returned 0 after 1532 usecs
[   65.710605] calling  snd-soc-dummy+ @ 385, parent: platform
[   65.716472] call snd-soc-dummy+ returned 0 after 16 usecs
[   65.722356] calling  duckbill:red:status+ @ 385, parent: leds
[   65.728360] call duckbill:red:status+ returned 0 after 22 usecs
[   65.734417] calling  duckbill:green:status+ @ 385, parent: leds
[   65.740564] call duckbill:green:status+ returned 0 after 18 usecs
[   65.747329] calling  stmp3xxx_rtc_wdt+ @ 385, parent: 80056000.rtc
[   65.753600] call stmp3xxx_rtc_wdt+ returned 0 after 13 usecs
[   65.759529] calling  rtc0+ @ 385, parent: 80056000.rtc
[   65.765084] call rtc0+ returned 0 after 212 usecs
[   65.771252] calling  usb1+ @ 93, parent: ci_hdrc.0
[   65.805743] call usb1+ returned 0 after 28753 usecs
[   65.811994] calling  ci_hdrc.0+ @ 385, parent: 80080000.usb
[   65.819188] call ci_hdrc.0+ returned 0 after 1319 usecs
[   65.824875] calling  800f0000.etherne:00+ @ 385, parent: 800f0000.etherne
[   65.832856] call 800f0000.etherne:00+ returned 0 after 1072 usecs
[   65.839345] calling  Fixed MDIO bus.0+ @ 385, parent: platform
[   65.845388] call Fixed MDIO bus.0+ returned 0 after 13 usecs
[   65.851432] calling  alarmtimer+ @ 385, parent: platform
[   65.858186] call alarmtimer+ returned 0 after 1193 usecs
[   65.868024] calling  leds+ @ 385, parent: soc0
[   65.872567] call leds+ returned 0 after 12 usecs
[   65.877472] calling  regulators:regulator at 0+ @ 385, parent: regulators
[   65.884088] call regulators:regulator at 0+ returned 0 after 14 usecs
[   65.890534] calling  regulators+ @ 385, parent: soc0
[   65.895699] call regulators+ returned 0 after 14 usecs
[   65.900971] calling  iio-hwmon+ @ 385, parent: soc0
[   65.906096] call iio-hwmon+ returned 0 after 15 usecs
[   65.912643] calling  800f0000.ethernet+ @ 385, parent: 80080000.ahb
[   65.920952] call 800f0000.ethernet+ returned 0 after 1743 usecs
[   65.927181] calling  80080000.usb+ @ 385, parent: 80080000.ahb
[   65.933350] call 80080000.usb+ returned 0 after 243 usecs
[   65.939063] calling  80080000.ahb+ @ 385, parent: soc0
[   65.944289] call 80080000.ahb+ returned 0 after 14 usecs
[   65.949867] calling  8007c000.usbphy+ @ 385, parent: 80040000.apbx
[   65.956248] call 8007c000.usbphy+ returned 0 after 15 usecs
[   65.961960] calling  80074000.serial+ @ 385, parent: 80040000.apbx
[   65.968832] call 80074000.serial+ returned 0 after 472 usecs
[   65.974888] calling  80068000.timrot+ @ 385, parent: 80040000.apbx
[   65.981162] call 80068000.timrot+ returned 0 after 13 usecs
[   65.987008] calling  80056000.rtc+ @ 385, parent: 80040000.apbx
[   65.993012] call 80056000.rtc+ returned 0 after 14 usecs
[   65.998601] calling  80040000.apbx+ @ 385, parent: 80000000.apb
[   66.004720] call 80040000.apbx+ returned 0 after 13 usecs
[   66.010259] calling  8002c000.ocotp+ @ 385, parent: 80000000.apbh
[   66.016565] call 8002c000.ocotp+ returned 0 after 14 usecs
[   66.022191] calling  80028000.dcp+ @ 385, parent: 80000000.apbh
[   66.028322] call 80028000.dcp+ returned 0 after 13 usecs
[   66.033833] calling  80024000.dma-apbx+ @ 385, parent: 80000000.apbh
[   66.040396] call 80024000.dma-apbx+ returned 0 after 14 usecs
[   66.046474] calling  80018000.pinctrl:gpio at 4+ @ 385, parent: 80018000.pinctrl
[   66.053695] call 80018000.pinctrl:gpio at 4+ returned 0 after 15 usecs
[   66.060303] calling  80018000.pinctrl:gpio at 3+ @ 385, parent: 80018000.pinctrl
[   66.067640] call 80018000.pinctrl:gpio at 3+ returned 0 after 14 usecs
[   66.074124] calling  80018000.pinctrl:gpio at 2+ @ 385, parent: 80018000.pinctrl
[   66.081478] call 80018000.pinctrl:gpio at 2+ returned 0 after 13 usecs
[   66.088068] calling  80018000.pinctrl:gpio at 1+ @ 385, parent: 80018000.pinctrl
[   66.095426] call 80018000.pinctrl:gpio at 1+ returned 0 after 14 usecs
[   66.101917] calling  80018000.pinctrl:gpio at 0+ @ 385, parent: 80018000.pinctrl
[   66.109292] call 80018000.pinctrl:gpio at 0+ returned 0 after 14 usecs
[   66.115828] calling  80018000.pinctrl+ @ 385, parent: 80000000.apbh
[   66.122177] call 80018000.pinctrl+ returned 0 after 13 usecs
[   66.128103] calling  80010000.ssp+ @ 385, parent: 80000000.apbh
[   66.134173] call 80010000.ssp+ returned 0 after 73 usecs
[   66.139808] calling  80004000.dma-apbh+ @ 385, parent: 80000000.apbh
[   66.146361] call 80004000.dma-apbh+ returned 0 after 14 usecs
[   66.152266] calling  80000000.apbh+ @ 385, parent: 80000000.apb
[   66.158402] call 80000000.apbh+ returned 0 after 14 usecs
[   66.163947] calling  80000000.apb+ @ 385, parent: soc0
[   66.169297] call 80000000.apb+ returned 0 after 13 usecs
[   66.174993] calling  reg-dummy+ @ 385, parent: platform
[   66.180303] call reg-dummy+ returned 0 after 14 usecs
[   66.185780] PM: suspend of devices complete after 491.347 msecs
[   66.199593] PM: late suspend of devices complete after 7.795 msecs
[   66.213823] PM: noirq suspend of devices complete after 7.810 msecs
[   66.220384] PM: Calling sched_clock_suspend+0x0/0x30
[   66.225386] PM: Calling timekeeping_suspend+0x0/0x248
[   66.225386] PM: Calling irq_gc_suspend+0x0/0x6c
[   66.225386] PM: Calling fw_suspend+0x0/0x14
[   66.225386] PM: Calling cpu_pm_suspend+0x0/0x18
[   66.225386] PM: Calling cpu_pm_resume+0x0/0x10
[   66.225386] PM: Calling irq_gc_resume+0x0/0x68
[   66.225386] PM: Calling irq_pm_syscore_resume+0x0/0x8
[   66.225386] PM: Calling timekeeping_resume+0x0/0x388
[   66.225386] PM: Calling sched_clock_resume+0x0/0x50
[   66.235681] PM: noirq resume of devices complete after 9.970 msecs
[   66.249836] PM: early resume of devices complete after 6.354 msecs
[   66.257903] calling  reg-dummy+ @ 385, parent: platform
[   66.263393] call reg-dummy+ returned 0 after 14 usecs
[   66.269048] calling  80000000.apb+ @ 385, parent: soc0
[   66.274433] call 80000000.apb+ returned 0 after 14 usecs
[   66.279854] calling  80000000.apbh+ @ 385, parent: 80000000.apb
[   66.285986] call 80000000.apbh+ returned 0 after 13 usecs
[   66.291488] calling  80004000.dma-apbh+ @ 385, parent: 80000000.apbh
[   66.298050] call 80004000.dma-apbh+ returned 0 after 13 usecs
[   66.304032] calling  80010000.ssp+ @ 385, parent: 80000000.apbh
[   66.310100] call 80010000.ssp+ returned 0 after 71 usecs
[   66.315901] calling  mmc0:0007+ @ 390, parent: mmc0
[   66.322084] call mmc0:0007+ returned 0 after 1186 usecs
[   66.327863] calling  80018000.pinctrl+ @ 385, parent: 80000000.apbh
[   66.334390] call 80018000.pinctrl+ returned 0 after 14 usecs
[   66.340292] calling  80018000.pinctrl:gpio at 0+ @ 385, parent: 80018000.pinctrl
[   66.347660] call 80018000.pinctrl:gpio at 0+ returned 0 after 14 usecs
[   66.354395] calling  80018000.pinctrl:gpio at 1+ @ 385, parent: 80018000.pinctrl
[   66.361622] call 80018000.pinctrl:gpio at 1+ returned 0 after 13 usecs
[   66.368166] calling  80018000.pinctrl:gpio at 2+ @ 385, parent: 80018000.pinctrl
[   66.375520] call 80018000.pinctrl:gpio at 2+ returned 0 after 13 usecs
[   66.381932] calling  80018000.pinctrl:gpio at 3+ @ 385, parent: 80018000.pinctrl
[   66.389309] call 80018000.pinctrl:gpio at 3+ returned 0 after 12 usecs
[   66.399315] calling  80018000.pinctrl:gpio at 4+ @ 385, parent: 80018000.pinctrl
[   66.406746] call 80018000.pinctrl:gpio at 4+ returned 0 after 13 usecs
[   66.413534] calling  80024000.dma-apbx+ @ 385, parent: 80000000.apbh
[   66.420065] call 80024000.dma-apbx+ returned 0 after 15 usecs
[   66.426220] calling  80028000.dcp+ @ 385, parent: 80000000.apbh
[   66.432320] call 80028000.dcp+ returned 0 after 14 usecs
[   66.438018] calling  8002c000.ocotp+ @ 385, parent: 80000000.apbh
[   66.444341] call 8002c000.ocotp+ returned 0 after 14 usecs
[   66.449936] calling  80040000.apbx+ @ 385, parent: 80000000.apb
[   66.456067] call 80040000.apbx+ returned 0 after 13 usecs
[   66.461564] calling  80056000.rtc+ @ 385, parent: 80040000.apbx
[   66.467729] call 80056000.rtc+ returned 0 after 23 usecs
[   66.473447] calling  80068000.timrot+ @ 385, parent: 80040000.apbx
[   66.479804] call 80068000.timrot+ returned 0 after 14 usecs
[   66.485778] calling  80074000.serial+ @ 385, parent: 80040000.apbx
[   66.492439] call 80074000.serial+ returned 0 after 303 usecs
[   66.498644] calling  8007c000.usbphy+ @ 385, parent: 80040000.apbx
[   66.505118] call 8007c000.usbphy+ returned 0 after 14 usecs
[   66.511030] calling  80080000.ahb+ @ 385, parent: soc0
[   66.516461] call 80080000.ahb+ returned 0 after 13 usecs
[   66.522156] calling  80080000.usb+ @ 385, parent: 80080000.ahb
[   66.528349] call 80080000.usb+ returned 0 after 72 usecs
[   66.535063] calling  800f0000.ethernet+ @ 385, parent: 80080000.ahb
[   66.545846] call 800f0000.ethernet+ returned 0 after 4310 usecs
[   66.552190] calling  iio-hwmon+ @ 385, parent: soc0
[   66.557331] call iio-hwmon+ returned 0 after 13 usecs
[   66.562680] calling  regulators+ @ 385, parent: soc0
[   66.567874] call regulators+ returned 0 after 13 usecs
[   66.573247] calling  regulators:regulator at 0+ @ 385, parent: regulators
[   66.580022] call regulators:regulator at 0+ returned 0 after 15 usecs
[   66.587259] calling  leds+ @ 385, parent: soc0
[   66.591800] call leds+ returned 0 after 15 usecs
[   66.598846] calling  alarmtimer+ @ 385, parent: platform
[   66.604503] call alarmtimer+ returned 0 after 23 usecs
[   66.610176] calling  Fixed MDIO bus.0+ @ 385, parent: platform
[   66.616252] call Fixed MDIO bus.0+ returned 0 after 12 usecs
[   66.622674] calling  800f0000.etherne:00+ @ 385, parent: 800f0000.etherne
[   66.630092] call 800f0000.etherne:00+ returned 0 after 387 usecs
[   66.636354] calling  ci_hdrc.0+ @ 385, parent: 80080000.usb
[   66.647310] call ci_hdrc.0+ returned 0 after 5048 usecs
[   66.652757] calling  usb1+ @ 391, parent: ci_hdrc.0
[   66.658084] calling  rtc0+ @ 385, parent: 80056000.rtc
[   66.664251] call usb1+ returned 0 after 6224 usecs
[   66.670162] call rtc0+ returned 0 after 6462 usecs
[   66.675361] calling  stmp3xxx_rtc_wdt+ @ 385, parent: 80056000.rtc
[   66.681633] call stmp3xxx_rtc_wdt+ returned 0 after 13 usecs
[   66.687854] calling  duckbill:green:status+ @ 385, parent: leds
[   66.694074] call duckbill:green:status+ returned 0 after 22 usecs
[   66.700951] calling  duckbill:red:status+ @ 385, parent: leds
[   66.706956] call duckbill:red:status+ returned 0 after 20 usecs
[   66.713180] calling  snd-soc-dummy+ @ 385, parent: platform
[   66.718969] call snd-soc-dummy+ returned 0 after 13 usecs
[   66.725823] PM: resume of devices complete after 469.549 msecs
[   66.739348] Restarting tasks ... [   66.783319] done.

echo freeze > /sys/power/state

[  189.939554] PM: Syncing filesystems ... [  191.084732] done.
[  191.090589] Freezing user space processes ... [  191.100074] (elapsed 0.004
seconds) done.
[  191.104444] Freezing remaining freezable tasks ... (elapsed 0.002 seconds)
done.
[  191.121118] calling  mmc0:0007+ @ 391, parent: mmc0
[  191.126437] calling  snd-soc-dummy+ @ 385, parent: platform
[  191.132104] call snd-soc-dummy+ returned 0 after 14 usecs
[  191.139007] call mmc0:0007+ returned 0 after 12458 usecs
[  191.144846] calling  duckbill:red:status+ @ 385, parent: leds
[  191.150693] call duckbill:red:status+ returned 0 after 20 usecs
[  191.156887] calling  duckbill:green:status+ @ 385, parent: leds
[  191.163035] call duckbill:green:status+ returned 0 after 20 usecs
[  191.169680] calling  stmp3xxx_rtc_wdt+ @ 385, parent: 80056000.rtc
[  191.176097] call stmp3xxx_rtc_wdt+ returned 0 after 14 usecs
[  191.181889] calling  rtc0+ @ 385, parent: 80056000.rtc
[  191.187289] call rtc0+ returned 0 after 58 usecs
[  191.193635] calling  usb1+ @ 391, parent: ci_hdrc.0
[  191.223649] call usb1+ returned 0 after 24451 usecs
[  191.228801] calling  ci_hdrc.0+ @ 385, parent: 80080000.usb
[  191.234867] call ci_hdrc.0+ returned 0 after 249 usecs
[  191.240183] calling  800f0000.etherne:00+ @ 385, parent: 800f0000.etherne
[  191.247628] call 800f0000.etherne:00+ returned 0 after 428 usecs
[  191.254012] calling  Fixed MDIO bus.0+ @ 385, parent: platform
[  191.259933] call Fixed MDIO bus.0+ returned 0 after 12 usecs
[  191.266098] calling  alarmtimer+ @ 385, parent: platform
[  191.271513] call alarmtimer+ returned 0 after 31 usecs
[  191.280964] calling  leds+ @ 385, parent: soc0
[  191.285646] call leds+ returned 0 after 15 usecs
[  191.290408] calling  regulators:regulator at 0+ @ 385, parent: regulators
[  191.297152] call regulators:regulator at 0+ returned 0 after 14 usecs
[  191.303602] calling  regulators+ @ 385, parent: soc0
[  191.308648] call regulators+ returned 0 after 13 usecs
[  191.314044] calling  iio-hwmon+ @ 385, parent: soc0
[  191.319008] call iio-hwmon+ returned 0 after 13 usecs
[  191.324325] calling  800f0000.ethernet+ @ 385, parent: 80080000.ahb
[  191.330828] call 800f0000.ethernet+ returned 0 after 152 usecs
[  191.336942] calling  80080000.usb+ @ 385, parent: 80080000.ahb
[  191.343135] call 80080000.usb+ returned 0 after 62 usecs
[  191.348600] calling  80080000.ahb+ @ 385, parent: soc0
[  191.353949] call 80080000.ahb+ returned 0 after 13 usecs
[  191.359397] calling  8007c000.usbphy+ @ 385, parent: 80040000.apbx
[  191.365789] call 8007c000.usbphy+ returned 0 after 14 usecs
[  191.371504] calling  80074000.serial+ @ 385, parent: 80040000.apbx
[  191.377944] call 80074000.serial+ returned 0 after 51 usecs
[  191.383782] calling  80068000.timrot+ @ 385, parent: 80040000.apbx
[  191.390043] call 80068000.timrot+ returned 0 after 13 usecs
[  191.395885] calling  80056000.rtc+ @ 385, parent: 80040000.apbx
[  191.401889] call 80056000.rtc+ returned 0 after 14 usecs
[  191.407472] calling  80040000.apbx+ @ 385, parent: 80000000.apb
[  191.413607] call 80040000.apbx+ returned 0 after 12 usecs
[  191.419146] calling  8002c000.ocotp+ @ 385, parent: 80000000.apbh
[  191.425447] call 8002c000.ocotp+ returned 0 after 13 usecs
[  191.431064] calling  80028000.dcp+ @ 385, parent: 80000000.apbh
[  191.437198] call 80028000.dcp+ returned 0 after 13 usecs
[  191.442706] calling  80024000.dma-apbx+ @ 385, parent: 80000000.apbh
[  191.449272] call 80024000.dma-apbx+ returned 0 after 14 usecs
[  191.455345] calling  80018000.pinctrl:gpio at 4+ @ 385, parent: 80018000.pinctrl
[  191.462570] call 80018000.pinctrl:gpio at 4+ returned 0 after 14 usecs
[  191.469179] calling  80018000.pinctrl:gpio at 3+ @ 385, parent: 80018000.pinctrl
[  191.476533] call 80018000.pinctrl:gpio at 3+ returned 0 after 13 usecs
[  191.483150] calling  80018000.pinctrl:gpio at 2+ @ 385, parent: 80018000.pinctrl
[  191.490374] call 80018000.pinctrl:gpio at 2+ returned 0 after 15 usecs
[  191.496983] calling  80018000.pinctrl:gpio at 1+ @ 385, parent: 80018000.pinctrl
[  191.504340] call 80018000.pinctrl:gpio at 1+ returned 0 after 14 usecs
[  191.510828] calling  80018000.pinctrl:gpio at 0+ @ 385, parent: 80018000.pinctrl
[  191.518177] call 80018000.pinctrl:gpio at 0+ returned 0 after 13 usecs
[  191.524725] calling  80018000.pinctrl+ @ 385, parent: 80000000.apbh
[  191.531076] call 80018000.pinctrl+ returned 0 after 14 usecs
[  191.536998] calling  80010000.ssp+ @ 385, parent: 80000000.apbh
[  191.543197] call 80010000.ssp+ returned 0 after 72 usecs
[  191.548705] calling  80004000.dma-apbh+ @ 385, parent: 80000000.apbh
[  191.555270] call 80004000.dma-apbh+ returned 0 after 14 usecs
[  191.561178] calling  80000000.apbh+ @ 385, parent: 80000000.apb
[  191.567310] call 80000000.apbh+ returned 0 after 13 usecs
[  191.573063] calling  80000000.apb+ @ 385, parent: soc0
[  191.578290] call 80000000.apb+ returned 0 after 11 usecs
[  191.583997] calling  reg-dummy+ @ 385, parent: platform
[  191.589308] call reg-dummy+ returned 0 after 12 usecs
[  191.594782] PM: suspend of devices complete after 474.663 msecs
[  191.608635] PM: late suspend of devices complete after 7.831 msecs
[  191.622637] PM: noirq suspend of devices complete after 7.569 msecs
[  366.696043] INFO: task ext4lazyinit:70 blocked for more than 120 seconds.
[  366.703046]       Not tainted 4.9.0-rc1 #7
[  366.707188] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  366.715161] ext4lazyinit    D c05aa6ac     0    70      2 0x00000000
[  366.721713] [<c05aa6ac>] (__schedule) from [<c05aafb8>] (schedule+0x3c/0xbc)
[  366.728972] [<c05aafb8>] (schedule) from [<c05aee38>]
(schedule_timeout+0x23c/0x3d8)
[  366.736917] [<c05aee38>] (schedule_timeout) from [<c05aa398>]
(io_schedule_timeout+0xb8/0x13c)
[  366.745721] [<c05aa398>] (io_schedule_timeout) from [<c05ab9d8>]
(T.1434+0xac/0x12c)
[  366.753671] [<c05ab9d8>] (T.1434) from [<c02c7668>]
(submit_bio_wait+0x50/0x68)
[  366.761078] [<c02c7668>] (submit_bio_wait) from [<c02d9a58>]
(blkdev_issue_zeroout+0x174/0x1ec)
[  366.769984] [<c02d9a58>] (blkdev_issue_zeroout) from [<c0196e4c>]
(ext4_init_inode_table+0x1ac/0x3b0)
[  366.779410] [<c0196e4c>] (ext4_init_inode_table) from [<c01ba770>]
(ext4_lazyinit_thread+0x280/0x398)
[  366.788803] [<c01ba770>] (ext4_lazyinit_thread) from [<c003bce4>]
(kthread+0xc4/0xe0)
[  366.796828] [<c003bce4>] (kthread) from [<c000a34c>]
(ret_from_fork+0x14/0x28)
[  366.804200]
[  366.804200] Showing all locks held in the system:
[  366.810465] 2 locks held by khungtaskd/10:
[  366.814707]  #0: [  366.816500]  (
rcu_read_lock[  366.819360] ){......}
, at: [  366.822236] [<c0093a10>] watchdog+0xb4/0x61c
[  366.826656]  #1: [  366.828450]  (
tasklist_lock[  366.831312] ){.+.+..}
, at: [  366.834320] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
[  366.839701] 4 locks held by ext4lazyinit/70:
[  366.844107]  #0: [  366.845897]  (
&type->s_umount_key[  366.849280] #22
){++++++}[  366.851866] , at:
[  366.854044] [<c01ba5c4>] ext4_lazyinit_thread+0xd4/0x398
[  366.859400]  #1: [  366.861178]  (
sb_writers[  366.863897] #3
){.+.+.+}[  366.866412] , at:
[  366.868475] [<c01ba5dc>] ext4_lazyinit_thread+0xec/0x398
[  366.873925]  #2: [  366.875716]  (
jbd2_handle[  366.878405] ){++++..}
, at: [  366.881292] [<c01f661c>] start_this_handle+0xec/0x404
[  366.886492]  #3: [  366.888284]  (
&meta_group_info[i]->alloc_sem[  366.892620] ){++++..}
, at: [  366.895624] [<c0196d58>] ext4_init_inode_table+0xb8/0x3b0
[  366.901093] 4 locks held by bash/385:
[  366.904895]  #0: [  366.906686]  (
sb_writers[  366.909288] #4
){.+.+.+}[  366.911787] , at:
[  366.913972] [<c011f7d4>] vfs_write+0x194/0x1a4
[  366.918456]  #1: [  366.920234]  (
&of->mutex[  366.922824] ){+.+.+.}
, at: [  366.925940] [<c019029c>] kernfs_fop_write+0xc0/0x1d0
[  366.930942]  #2: [  366.932714]  (
s_active[  366.935265] #43
){.+.+.+}[  366.937864] , at:
[  366.939927] [<c01902a4>] kernfs_fop_write+0xc8/0x1d0
[  366.945029]  #3: [  366.946818]  (
pm_mutex[  366.949242] ){+.+.+.}
, at: [  366.952111] [<c005b7e4>] pm_suspend+0x90/0x81c
[  366.956697]
[  366.958229] =============================================

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Russell King - ARM Linux]

On Mon, Oct 31, 2016 at 08:54:33PM +0100, Stefan Wahren wrote:
> [  366.696043] INFO: task ext4lazyinit:70 blocked for more than 120 seconds.
> [  366.703046]       Not tainted 4.9.0-rc1 #7
> [  366.707188] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
> message.
> [  366.715161] ext4lazyinit    D c05aa6ac     0    70      2 0x00000000

This looks like a very different problem - I guess one for ext4 people.

> [  366.721713] [<c05aa6ac>] (__schedule) from [<c05aafb8>] (schedule+0x3c/0xbc)
> [  366.728972] [<c05aafb8>] (schedule) from [<c05aee38>]
> (schedule_timeout+0x23c/0x3d8)
> [  366.736917] [<c05aee38>] (schedule_timeout) from [<c05aa398>]
> (io_schedule_timeout+0xb8/0x13c)
> [  366.745721] [<c05aa398>] (io_schedule_timeout) from [<c05ab9d8>]
> (T.1434+0xac/0x12c)
> [  366.753671] [<c05ab9d8>] (T.1434) from [<c02c7668>]
> (submit_bio_wait+0x50/0x68)
> [  366.761078] [<c02c7668>] (submit_bio_wait) from [<c02d9a58>]
> (blkdev_issue_zeroout+0x174/0x1ec)
> [  366.769984] [<c02d9a58>] (blkdev_issue_zeroout) from [<c0196e4c>]
> (ext4_init_inode_table+0x1ac/0x3b0)
> [  366.779410] [<c0196e4c>] (ext4_init_inode_table) from [<c01ba770>]
> (ext4_lazyinit_thread+0x280/0x398)
> [  366.788803] [<c01ba770>] (ext4_lazyinit_thread) from [<c003bce4>]
> (kthread+0xc4/0xe0)
> [  366.796828] [<c003bce4>] (kthread) from [<c000a34c>]
> (ret_from_fork+0x14/0x28)
> [  366.804200]
> [  366.804200] Showing all locks held in the system:
> [  366.810465] 2 locks held by khungtaskd/10:
> [  366.814707]  #0: [  366.816500]  (
> rcu_read_lock[  366.819360] ){......}
> , at: [  366.822236] [<c0093a10>] watchdog+0xb4/0x61c
> [  366.826656]  #1: [  366.828450]  (
> tasklist_lock[  366.831312] ){.+.+..}
> , at: [  366.834320] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
> [  366.839701] 4 locks held by ext4lazyinit/70:
> [  366.844107]  #0: [  366.845897]  (
> &type->s_umount_key[  366.849280] #22
> ){++++++}[  366.851866] , at:
> [  366.854044] [<c01ba5c4>] ext4_lazyinit_thread+0xd4/0x398
> [  366.859400]  #1: [  366.861178]  (
> sb_writers[  366.863897] #3
> ){.+.+.+}[  366.866412] , at:
> [  366.868475] [<c01ba5dc>] ext4_lazyinit_thread+0xec/0x398
> [  366.873925]  #2: [  366.875716]  (
> jbd2_handle[  366.878405] ){++++..}
> , at: [  366.881292] [<c01f661c>] start_this_handle+0xec/0x404
> [  366.886492]  #3: [  366.888284]  (
> &meta_group_info[i]->alloc_sem[  366.892620] ){++++..}
> , at: [  366.895624] [<c0196d58>] ext4_init_inode_table+0xb8/0x3b0
> [  366.901093] 4 locks held by bash/385:
> [  366.904895]  #0: [  366.906686]  (
> sb_writers[  366.909288] #4
> ){.+.+.+}[  366.911787] , at:
> [  366.913972] [<c011f7d4>] vfs_write+0x194/0x1a4
> [  366.918456]  #1: [  366.920234]  (
> &of->mutex[  366.922824] ){+.+.+.}
> , at: [  366.925940] [<c019029c>] kernfs_fop_write+0xc0/0x1d0
> [  366.930942]  #2: [  366.932714]  (
> s_active[  366.935265] #43
> ){.+.+.+}[  366.937864] , at:
> [  366.939927] [<c01902a4>] kernfs_fop_write+0xc8/0x1d0
> [  366.945029]  #3: [  366.946818]  (
> pm_mutex[  366.949242] ){+.+.+.}
> , at: [  366.952111] [<c005b7e4>] pm_suspend+0x90/0x81c
> [  366.956697]
> [  366.958229] =============================================

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line: currently at 9.6Mbps down 400kbps up
according to speedtest.net.

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi,

[add Rui]

> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 1. November 2016 um
> 10:23 geschrieben:
> 
> 
> On Mon, Oct 31, 2016 at 08:54:33PM +0100, Stefan Wahren wrote:
> > [  366.696043] INFO: task ext4lazyinit:70 blocked for more than 120 seconds.
> > [  366.703046]       Not tainted 4.9.0-rc1 #7
> > [  366.707188] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables
> > this
> > message.
> > [  366.715161] ext4lazyinit    D c05aa6ac     0    70      2 0x00000000
> 
> This looks like a very different problem - I guess one for ext4 people.
> 

i investigated the issue more further. This trace wasn't representative, because
the stacktrace is different in most cases. The "endless loop" is located in
freeze_enter(). So i added some debug messages:

-------------------------------->8------------------------------------
diff --git a/kernel/power/suspend.c b/kernel/power/suspend.c
index 1e7f5da..079c08d 100644
--- a/kernel/power/suspend.c
+++ b/kernel/power/suspend.c
@@ -67,17 +67,20 @@ static void freeze_enter(void)
 	spin_unlock_irq(&suspend_freeze_lock);
 
 	get_online_cpus();
+	pr_info("PM: calling cpuidle_resume()\n");
 	cpuidle_resume();
 
 	/* Push all the CPUs into the idle loop. */
+	pr_info("PM: calling wake_up_all_idle_cpus()\n");
 	wake_up_all_idle_cpus();
-	pr_debug("PM: suspend-to-idle\n");
+	pr_info("PM: suspend-to-idle\n");
 	/* Make the current CPU wait so it can enter the idle loop too. */
 	wait_event(suspend_freeze_wait_head,
 		   suspend_freeze_state == FREEZE_STATE_WAKE);
-	pr_debug("PM: resume from suspend-to-idle\n");
+	pr_info("PM: resume from suspend-to-idle\n");
 
 	cpuidle_pause();
+	pr_info("PM: called cpuidle_pause()\n");
 	put_online_cpus();
 
 	spin_lock_irq(&suspend_freeze_lock);
@@ -91,6 +94,8 @@ void freeze_wake(void)
 {
 	unsigned long flags;
 
+	pr_info("PM: freeze_wake()\n");
+
 	spin_lock_irqsave(&suspend_freeze_lock, flags);
 	if (suspend_freeze_state > FREEZE_STATE_NONE) {
 		suspend_freeze_state = FREEZE_STATE_WAKE;

-------------------------------->8------------------------------------

and repeated the test cases for freeze which shows none the representative
stacktraces:

1. cmdline contains no_console_suspend

* echo freeze > /sys/power/state

...
[  139.371308] PM: suspend of devices complete after 1342.721 msecs
[  139.385203] PM: late suspend of devices complete after 7.668 msecs
[  139.399428] PM: noirq suspend of devices complete after 7.936 msecs
[  139.406639] PM: calling cpuidle_resume()
[  139.410619] PM: calling wake_up_all_idle_cpus()
[  139.415339] PM: suspend-to-idle

>>> no reaction to input via Debug UART

[  366.683570] INFO: task bash:373 blocked for more than 120 seconds.
[  366.689814]       Not tainted 4.9.0-rc1-dirty #14
[  366.694705] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this
message.
[  366.702685] bash            D c05aa6ec     0   373    275 0x00000000
[  366.709227] [<c05aa6ec>] (__schedule) from [<c05aaff8>] (schedule+0x3c/0xbc)
[  366.716495] [<c05aaff8>] (schedule) from [<c005b588>]
(suspend_devices_and_enter+0x888/0xa78)
[  366.725228] [<c005b588>] (suspend_devices_and_enter) from [<c005bea4>]
(pm_suspend+0x72c/0x81c)
[  366.734150] [<c005bea4>] (pm_suspend) from [<c005a008>]
(state_store+0x80/0xcc)
[  366.741554] [<c005a008>] (state_store) from [<c02f0270>]
(kobj_attr_store+0x18/0x1c)
[  366.749515] [<c02f0270>] (kobj_attr_store) from [<c01911e8>]
(sysfs_kf_write+0x48/0x4c)
[  366.757735] [<c01911e8>] (sysfs_kf_write) from [<c0190308>]
(kernfs_fop_write+0xfc/0x1d0)
[  366.766130] [<c0190308>] (kernfs_fop_write) from [<c011f578>]
(__vfs_write+0x2c/0x124)
[  366.774255] [<c011f578>] (__vfs_write) from [<c011f724>]
(vfs_write+0xb4/0x1a4)
[  366.781640] [<c011f724>] (vfs_write) from [<c011f8e8>] (SyS_write+0x44/0x88)
[  366.788890] [<c011f8e8>] (SyS_write) from [<c000a2c0>]
(ret_fast_syscall+0x0/0x1c)
[  366.796627]
[  366.796627] Showing all locks held in the system:
[  366.803011] 2 locks held by khungtaskd/10:
[  366.807149]  #0: [  366.808931]  (
rcu_read_lock[  366.811784] ){......}
, at: [  366.814813] [<c0093a40>] watchdog+0xb4/0x61c
[  366.819128]  #1: [  366.820902]  (
tasklist_lock[  366.823876] ){.+.+..}
, at: [  366.826765] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
[  366.832151] 4 locks held by bash/373:
[  366.835973]  #0: [  366.837765]  (
sb_writers[  366.840365] #4
){.+.+.+}[  366.842987] , at:
[  366.845079] [<c011f804>] vfs_write+0x194/0x1a4
[  366.849551]  #1: [  366.851324]  (
&of->mutex[  366.854058] ){+.+.+.}
, at: [  366.856944] [<c01902cc>] kernfs_fop_write+0xc0/0x1d0
[  366.861941]  #2: [  366.863839]  (
s_active[  366.866288] #43
){.+.+.+}[  366.868877] , at:
[  366.870938] [<c01902d4>] kernfs_fop_write+0xc8/0x1d0
[  366.876053]  #3: [  366.877843]  (
pm_mutex[  366.880272] ){+.+.+.}
, at: [  366.883266] [<c005b808>] pm_suspend+0x90/0x81c
[  366.887757]
[  366.889268] =============================================
[  366.889268]

2. cmdline contains no_console_suspend

* echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
* echo freeze > /sys/power/state

the same as in 1.

3. cmdline doesn't contains no_console_suspend

* echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
* echo freeze > /sys/power/state

[  161.093187] PM: Syncing filesystems ... [  161.734413] done.
[  161.793242] Freezing user space processes ... (elapsed 0.008 seconds) done.
[  161.809797] Freezing remaining freezable tasks ... (elapsed 0.004 seconds)
done.
[  161.821953] Suspending console(s) (use no_console_suspend to debug)

>>>> no reaction to Debug UART

I expected that in all 3 cases freeze_wake() will be called. Why not?

Here my config again:

CONFIG_PM_SLEEP=y
CONFIG_SUSPEND=y
CONFIG_SUSPEND_FREEZER=y
CONFIG_PM=y
CONFIG_CPU_IDLE is not set

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Zhang Rui]

On Sat, 2016-11-05 at 12:07 +0100, Stefan Wahren wrote:
> Hi,
> 
> [add Rui]
> 
> > 
> > Russell King - ARM Linux <linux@armlinux.org.uk> hat am 1. November
> > 2016 um
> > 10:23 geschrieben:
> > 
> > 
> > On Mon, Oct 31, 2016 at 08:54:33PM +0100, Stefan Wahren wrote:
> > > 
> > > [??366.696043] INFO: task ext4lazyinit:70 blocked for more than
> > > 120 seconds.
> > > [??366.703046]???????Not tainted 4.9.0-rc1 #7
> > > [??366.707188] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > > disables
> > > this
> > > message.
> > > [??366.715161] ext4lazyinit????D c05aa6ac?????0????70??????2
> > > 0x00000000
> > This looks like a very different problem - I guess one for ext4
> > people.
> > 
> i investigated the issue more further. This trace wasn't
> representative, because
> the stacktrace is different in most cases. The "endless loop" is
> located in
> freeze_enter(). So i added some debug messages:
> 
is this a regression?

> -------------------------------->8-----------------------------------
> -
> diff --git a/kernel/power/suspend.c b/kernel/power/suspend.c
> index 1e7f5da..079c08d 100644
> --- a/kernel/power/suspend.c
> +++ b/kernel/power/suspend.c
> @@ -67,17 +67,20 @@ static void freeze_enter(void)
> ?	spin_unlock_irq(&suspend_freeze_lock);
> ?
> ?	get_online_cpus();
> +	pr_info("PM: calling cpuidle_resume()\n");
> ?	cpuidle_resume();
> ?
> ?	/* Push all the CPUs into the idle loop. */
> +	pr_info("PM: calling wake_up_all_idle_cpus()\n");
> ?	wake_up_all_idle_cpus();
> -	pr_debug("PM: suspend-to-idle\n");
> +	pr_info("PM: suspend-to-idle\n");
> ?	/* Make the current CPU wait so it can enter the idle loop
> too. */
> ?	wait_event(suspend_freeze_wait_head,
> ?		???suspend_freeze_state == FREEZE_STATE_WAKE);
> -	pr_debug("PM: resume from suspend-to-idle\n");
> +	pr_info("PM: resume from suspend-to-idle\n");
> ?
> ?	cpuidle_pause();
> +	pr_info("PM: called cpuidle_pause()\n");
> ?	put_online_cpus();
> ?
> ?	spin_lock_irq(&suspend_freeze_lock);
> @@ -91,6 +94,8 @@ void freeze_wake(void)
> ?{
> ?	unsigned long flags;
> ?
> +	pr_info("PM: freeze_wake()\n");
> +
> ?	spin_lock_irqsave(&suspend_freeze_lock, flags);
> ?	if (suspend_freeze_state > FREEZE_STATE_NONE) {
> ?		suspend_freeze_state = FREEZE_STATE_WAKE;
> 
> -------------------------------->8-----------------------------------
> -
> 
> and repeated the test cases for freeze which shows none the
> representative
> stacktraces:
> 
> 1. cmdline contains no_console_suspend
> 
> * echo freeze > /sys/power/state
> 
> ...
> [??139.371308] PM: suspend of devices complete after 1342.721 msecs
> [??139.385203] PM: late suspend of devices complete after 7.668 msecs
> [??139.399428] PM: noirq suspend of devices complete after 7.936
> msecs
> [??139.406639] PM: calling cpuidle_resume()
> [??139.410619] PM: calling wake_up_all_idle_cpus()
> [??139.415339] PM: suspend-to-idle
> 
> > 
> > > 
> > > > 
> > > > no reaction to input via Debug UART
> [??366.683570] INFO: task bash:373 blocked for more than 120 seconds.
> [??366.689814]???????Not tainted 4.9.0-rc1-dirty #14
> [??366.694705] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> disables this
> message.
> [??366.702685] bash????????????D c05aa6ec?????0???373????275
> 0x00000000
> [??366.709227] [<c05aa6ec>] (__schedule) from [<c05aaff8>]
> (schedule+0x3c/0xbc)
> [??366.716495] [<c05aaff8>] (schedule) from [<c005b588>]
> (suspend_devices_and_enter+0x888/0xa78)
> [??366.725228] [<c005b588>] (suspend_devices_and_enter) from
> [<c005bea4>]
> (pm_suspend+0x72c/0x81c)
> [??366.734150] [<c005bea4>] (pm_suspend) from [<c005a008>]
> (state_store+0x80/0xcc)
> [??366.741554] [<c005a008>] (state_store) from [<c02f0270>]
> (kobj_attr_store+0x18/0x1c)
> [??366.749515] [<c02f0270>] (kobj_attr_store) from [<c01911e8>]
> (sysfs_kf_write+0x48/0x4c)
> [??366.757735] [<c01911e8>] (sysfs_kf_write) from [<c0190308>]
> (kernfs_fop_write+0xfc/0x1d0)
> [??366.766130] [<c0190308>] (kernfs_fop_write) from [<c011f578>]
> (__vfs_write+0x2c/0x124)
> [??366.774255] [<c011f578>] (__vfs_write) from [<c011f724>]
> (vfs_write+0xb4/0x1a4)
> [??366.781640] [<c011f724>] (vfs_write) from [<c011f8e8>]
> (SyS_write+0x44/0x88)
> [??366.788890] [<c011f8e8>] (SyS_write) from [<c000a2c0>]
> (ret_fast_syscall+0x0/0x1c)
> [??366.796627]
> [??366.796627] Showing all locks held in the system:
> [??366.803011] 2 locks held by khungtaskd/10:
> [??366.807149]??#0: [??366.808931]??(
> rcu_read_lock[??366.811784] ){......}
> , at: [??366.814813] [<c0093a40>] watchdog+0xb4/0x61c
> [??366.819128]??#1: [??366.820902]??(
> tasklist_lock[??366.823876] ){.+.+..}
> , at: [??366.826765] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
> [??366.832151] 4 locks held by bash/373:
> [??366.835973]??#0: [??366.837765]??(
> sb_writers[??366.840365] #4
> ){.+.+.+}[??366.842987] , at:
> [??366.845079] [<c011f804>] vfs_write+0x194/0x1a4
> [??366.849551]??#1: [??366.851324]??(
> &of->mutex[??366.854058] ){+.+.+.}
> , at: [??366.856944] [<c01902cc>] kernfs_fop_write+0xc0/0x1d0
> [??366.861941]??#2: [??366.863839]??(
> s_active[??366.866288] #43
> ){.+.+.+}[??366.868877] , at:
> [??366.870938] [<c01902d4>] kernfs_fop_write+0xc8/0x1d0
> [??366.876053]??#3: [??366.877843]??(
> pm_mutex[??366.880272] ){+.+.+.}
> , at: [??366.883266] [<c005b808>] pm_suspend+0x90/0x81c
> [??366.887757]
> [??366.889268] =============================================
> [??366.889268]
> 
> 2. cmdline contains no_console_suspend
> 
> * echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
> * echo freeze > /sys/power/state
> 
> the same as in 1.
> 
> 3. cmdline doesn't contains no_console_suspend
> 
> * echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
> * echo freeze > /sys/power/state
> 
> [??161.093187] PM: Syncing filesystems ... [??161.734413] done.
> [??161.793242] Freezing user space processes ... (elapsed 0.008
> seconds) done.
> [??161.809797] Freezing remaining freezable tasks ... (elapsed 0.004
> seconds)
> done.
> [??161.821953] Suspending console(s) (use no_console_suspend to
> debug)
> 
> >?
> > > > > no reaction to Debug UART

Then the system does not have any response? or the system freezes and
wakes up as expected?

> I expected that in all 3 cases freeze_wake() will be called. Why not?
> 
> Here my config again:
> 
> CONFIG_PM_SLEEP=y
> CONFIG_SUSPEND=y
> CONFIG_SUSPEND_FREEZER=y
> CONFIG_PM=y
> CONFIG_CPU_IDLE is not set

hmmm, why not have CONFIG_CPU_IDLE set?

thanks,
rui

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi Rui,

> Zhang Rui <rui.zhang@intel.com> hat am 5. November 2016 um 12:39 geschrieben:
> 
> 
> On Sat, 2016-11-05 at 12:07 +0100, Stefan Wahren wrote:
> > Hi,
> > 
> > [add Rui]
> > 
> > > 
> > > Russell King - ARM Linux <linux@armlinux.org.uk> hat am 1. November
> > > 2016 um
> > > 10:23 geschrieben:
> > > 
> > > 
> > > On Mon, Oct 31, 2016 at 08:54:33PM +0100, Stefan Wahren wrote:
> > > > 
> > > > [??366.696043] INFO: task ext4lazyinit:70 blocked for more than
> > > > 120 seconds.
> > > > [??366.703046]???????Not tainted 4.9.0-rc1 #7
> > > > [??366.707188] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > > > disables
> > > > this
> > > > message.
> > > > [??366.715161] ext4lazyinit????D c05aa6ac?????0????70??????2
> > > > 0x00000000
> > > This looks like a very different problem - I guess one for ext4
> > > people.
> > > 
> > i investigated the issue more further. This trace wasn't
> > representative, because
> > the stacktrace is different in most cases. The "endless loop" is
> > located in
> > freeze_enter(). So i added some debug messages:
> > 
> is this a regression?

i've never seen this working on MXS platform, but maybe i hit a corner case. The
oldest kernel that i tested was 3.18 and this issue was reproducible. Should i
test an older version?

> > 
> > and repeated the test cases for freeze which shows none the
> > representative
> > stacktraces:
> > 
> > 1. cmdline contains no_console_suspend
> > 
> > * echo freeze > /sys/power/state
> > 
> > ...
> > [??139.371308] PM: suspend of devices complete after 1342.721 msecs
> > [??139.385203] PM: late suspend of devices complete after 7.668 msecs
> > [??139.399428] PM: noirq suspend of devices complete after 7.936
> > msecs
> > [??139.406639] PM: calling cpuidle_resume()
> > [??139.410619] PM: calling wake_up_all_idle_cpus()
> > [??139.415339] PM: suspend-to-idle
> > 
> > > 
> > > > 
> > > > > 
> > > > > no reaction to input via Debug UART
> > [??366.683570] INFO: task bash:373 blocked for more than 120 seconds.
> > [??366.689814]???????Not tainted 4.9.0-rc1-dirty #14
> > [??366.694705] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs"
> > disables this
> > message.
> > [??366.702685] bash????????????D c05aa6ec?????0???373????275
> > 0x00000000
> > [??366.709227] [<c05aa6ec>] (__schedule) from [<c05aaff8>]
> > (schedule+0x3c/0xbc)
> > [??366.716495] [<c05aaff8>] (schedule) from [<c005b588>]
> > (suspend_devices_and_enter+0x888/0xa78)
> > [??366.725228] [<c005b588>] (suspend_devices_and_enter) from
> > [<c005bea4>]
> > (pm_suspend+0x72c/0x81c)
> > [??366.734150] [<c005bea4>] (pm_suspend) from [<c005a008>]
> > (state_store+0x80/0xcc)
> > [??366.741554] [<c005a008>] (state_store) from [<c02f0270>]
> > (kobj_attr_store+0x18/0x1c)
> > [??366.749515] [<c02f0270>] (kobj_attr_store) from [<c01911e8>]
> > (sysfs_kf_write+0x48/0x4c)
> > [??366.757735] [<c01911e8>] (sysfs_kf_write) from [<c0190308>]
> > (kernfs_fop_write+0xfc/0x1d0)
> > [??366.766130] [<c0190308>] (kernfs_fop_write) from [<c011f578>]
> > (__vfs_write+0x2c/0x124)
> > [??366.774255] [<c011f578>] (__vfs_write) from [<c011f724>]
> > (vfs_write+0xb4/0x1a4)
> > [??366.781640] [<c011f724>] (vfs_write) from [<c011f8e8>]
> > (SyS_write+0x44/0x88)
> > [??366.788890] [<c011f8e8>] (SyS_write) from [<c000a2c0>]
> > (ret_fast_syscall+0x0/0x1c)
> > [??366.796627]
> > [??366.796627] Showing all locks held in the system:
> > [??366.803011] 2 locks held by khungtaskd/10:
> > [??366.807149]??#0: [??366.808931]??(
> > rcu_read_lock[??366.811784] ){......}
> > , at: [??366.814813] [<c0093a40>] watchdog+0xb4/0x61c
> > [??366.819128]??#1: [??366.820902]??(
> > tasklist_lock[??366.823876] ){.+.+..}
> > , at: [??366.826765] [<c0051dbc>] debug_show_all_locks+0x28/0x1bc
> > [??366.832151] 4 locks held by bash/373:
> > [??366.835973]??#0: [??366.837765]??(
> > sb_writers[??366.840365] #4
> > ){.+.+.+}[??366.842987] , at:
> > [??366.845079] [<c011f804>] vfs_write+0x194/0x1a4
> > [??366.849551]??#1: [??366.851324]??(
> > &of->mutex[??366.854058] ){+.+.+.}
> > , at: [??366.856944] [<c01902cc>] kernfs_fop_write+0xc0/0x1d0
> > [??366.861941]??#2: [??366.863839]??(
> > s_active[??366.866288] #43
> > ){.+.+.+}[??366.868877] , at:
> > [??366.870938] [<c01902d4>] kernfs_fop_write+0xc8/0x1d0
> > [??366.876053]??#3: [??366.877843]??(
> > pm_mutex[??366.880272] ){+.+.+.}
> > , at: [??366.883266] [<c005b808>] pm_suspend+0x90/0x81c
> > [??366.887757]
> > [??366.889268] =============================================
> > [??366.889268]
> > 
> > 2. cmdline contains no_console_suspend
> > 
> > * echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
> > * echo freeze > /sys/power/state
> > 
> > the same as in 1.
> > 
> > 3. cmdline doesn't contains no_console_suspend
> > 
> > * echo enabled > /sys/class/tty/ttyAMA0/power/wakeup
> > * echo freeze > /sys/power/state
> > 
> > [??161.093187] PM: Syncing filesystems ... [??161.734413] done.
> > [??161.793242] Freezing user space processes ... (elapsed 0.008
> > seconds) done.
> > [??161.809797] Freezing remaining freezable tasks ... (elapsed 0.004
> > seconds)
> > done.
> > [??161.821953] Suspending console(s) (use no_console_suspend to
> > debug)
> > 
> > >?
> > > > > > no reaction to Debug UART
> 
> Then the system does not have any response? or the system freezes and
> wakes up as expected?

The system doesn't react to any input from Debug UART and after 2 minutes i got
the following stacktrace about hung task. But i didn't get any change to come
back to the console. Interestingly basic PM debugging tests doesn't show this
issue. Also "echo mem > /sys/power/state" doesn't cause this issue.

> 
> > I expected that in all 3 cases freeze_wake() will be called. Why not?
> > 
> > Here my config again:
> > 
> > CONFIG_PM_SLEEP=y
> > CONFIG_SUSPEND=y
> > CONFIG_SUSPEND_FREEZER=y
> > CONFIG_PM=y
> > CONFIG_CPU_IDLE is not set
> 
> hmmm, why not have CONFIG_CPU_IDLE set?

I'm using mxs_defconfig which doesn't select the ARM CPU idle. Is this
necessary?

> 
> thanks,
> rui

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Daniel Lezcano]

On Sat, Nov 05, 2016 at 01:01:26PM +0100, Stefan Wahren wrote:

[?... ]

> > > CONFIG_SUSPEND=y
> > > CONFIG_SUSPEND_FREEZER=y
> > > CONFIG_PM=y
> > > CONFIG_CPU_IDLE is not set
> > 
> > hmmm, why not have CONFIG_CPU_IDLE set?
> 
> I'm using mxs_defconfig which doesn't select the ARM CPU idle. Is this
> necessary?

Very likely :) suspend_freezer and cpuidle are tied together.

Moreover, while reading the code, it appears without CONFIG_CPU_IDLE the
function cpuidle_idle_call is constantly failing, ending up by having the
cpu looping again and again in the idle loop. The function stubs return
-ENODEV in the cpuidle's header when CONFIG_CPU_IDLE is not set.

If I'm not wrong the traces should show the cpu actually does never go
to suspend. As soon as it enters the state, it should exit immediately
without an interrupt event.

Probably there is an inconsistent configuration leaving the kernel with
a strange wakeup condition or a race with the short the suspend/resume
cycle delay.

First test would be to enable CONFIG_CPU_IDLE.

If it is confirmed, it would be nice to feed bugzilla.

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi Daniel,

> Daniel Lezcano <daniel.lezcano@linaro.org> hat am 5. November 2016 um 14:00
> geschrieben:
> 
> 
> On Sat, Nov 05, 2016 at 01:01:26PM +0100, Stefan Wahren wrote:
> 
> [?... ]
> 
> > > > CONFIG_SUSPEND=y
> > > > CONFIG_SUSPEND_FREEZER=y
> > > > CONFIG_PM=y
> > > > CONFIG_CPU_IDLE is not set
> > > 
> > > hmmm, why not have CONFIG_CPU_IDLE set?
> > 
> > I'm using mxs_defconfig which doesn't select the ARM CPU idle. Is this
> > necessary?
> 
> Very likely :) suspend_freezer and cpuidle are tied together.
> 
> Moreover, while reading the code, it appears without CONFIG_CPU_IDLE the
> function cpuidle_idle_call is constantly failing, ending up by having the
> cpu looping again and again in the idle loop. The function stubs return
> -ENODEV in the cpuidle's header when CONFIG_CPU_IDLE is not set.
> 
> If I'm not wrong the traces should show the cpu actually does never go
> to suspend. As soon as it enters the state, it should exit immediately
> without an interrupt event.
> 
> Probably there is an inconsistent configuration leaving the kernel with
> a strange wakeup condition or a race with the short the suspend/resume
> cycle delay.
> 
> First test would be to enable CONFIG_CPU_IDLE.
> 
> If it is confirmed, it would be nice to feed bugzilla.

first i tried with CONFIG_CPU_IDLE=Y and then additionally with
CONFIG_ARM_CPUIDLE=y.

In both cases the issue is still reproducible.

As i wrote in my email before, i added a pr_info() into freeze_wake. But i never
see the output of this message. So i assume freeze_wake is never called. Again,
how could this happen?

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Russell King - ARM Linux]

On Sat, Nov 05, 2016 at 04:28:37PM +0100, Stefan Wahren wrote:
> As i wrote in my email before, i added a pr_info() into freeze_wake.
> But i never see the output of this message. So i assume freeze_wake
> is never called. Again, how could this happen?

Hmm, so the bit that you're getting stuck on is:

        wait_event(suspend_freeze_wait_head,
                   suspend_freeze_state == FREEZE_STATE_WAKE);

Now there's two things about this here - it's a non-interruptible wait,
so I think the hung task detection may trigger on that (I'm not entirely
sure on that point though, and I don't have time this evening to read
the code to find out.)

The second thing is, that in order to pass this point, something has to
call freeze_wake().

There's not that many possibilities for that:

$ git grep freeze_wake drivers kernel
drivers/base/power/wakeup.c:    freeze_wake();
drivers/base/power/wakeup.c:    freeze_wake();
kernel/power/suspend.c:void freeze_wake(void)
kernel/power/suspend.c:EXPORT_SYMBOL_GPL(freeze_wake);

One of those is pm_system_wakeup(), the other is wakeup_source_activate()
via wakeup_source_report_event() via __pm_stay_awake() or
__pm_wakeup_event().

Looking at the results of:

$ grep 'pm_wakeup_event\|pm_stay_awake\|pm_system_wakeup' drivers kernel -r

it looks like for freeze support to work, various drivers need to call
one of these functions.

The iMX serial driver doesn't call any of these functions, so I can't
see how we'd get past this point - and from that grep you'll see nothing
in kernel/irq touches any of these functions.

Documentation/power/suspend-and-interrupts.txt does a very poor job
(which is typical) of describing what the requirements are for
"suspend-to-idle", it doesn't really say that any of the above
functions must be called and it doesn't say who's responsible for
calling these functions.  It does talk about "pm_system_wakeup()"
for "rare cases".

So my conclusion, based on the poor documentation and the results of
my greps, is that "freeze" aka "suspend-to-idle" is not supported on
the majority of hardware, and attempting to use it will result in the
system locking up in exactly the way you're seeing.

-- 
RMK's Patch system: http://www.armlinux.org.uk/developer/patches/
FTTC broadband for 0.8mile line: currently at 9.6Mbps down 400kbps up
according to speedtest.net.

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

Hi,

> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 5. November 2016 um
> 19:05 geschrieben:
> 
> 
> On Sat, Nov 05, 2016 at 04:28:37PM +0100, Stefan Wahren wrote:
> > As i wrote in my email before, i added a pr_info() into freeze_wake.
> > But i never see the output of this message. So i assume freeze_wake
> > is never called. Again, how could this happen?
> 
> Hmm, so the bit that you're getting stuck on is:
> 
>         wait_event(suspend_freeze_wait_head,
>                    suspend_freeze_state == FREEZE_STATE_WAKE);
> 

thanks for all the feedback. The real cause for this issue is in the irqchip
driver. I fixed it with this patch:

diff --git a/drivers/irqchip/irq-mxs.c b/drivers/irqchip/irq-mxs.c
index 1730470..05fa9f7 100644
--- a/drivers/irqchip/irq-mxs.c
+++ b/drivers/irqchip/irq-mxs.c
@@ -131,12 +131,16 @@ static void asm9260_unmask_irq(struct irq_data *d)
 	.irq_ack = icoll_ack_irq,
 	.irq_mask = icoll_mask_irq,
 	.irq_unmask = icoll_unmask_irq,
+	.flags = IRQCHIP_MASK_ON_SUSPEND |
+		 IRQCHIP_SKIP_SET_WAKE,
 };
 
 static struct irq_chip asm9260_icoll_chip = {
 	.irq_ack = icoll_ack_irq,
 	.irq_mask = asm9260_mask_irq,
 	.irq_unmask = asm9260_unmask_irq,
+	.flags = IRQCHIP_MASK_ON_SUSPEND |
+		 IRQCHIP_SKIP_SET_WAKE,
 };
 
 asmlinkage void __exception_irq_entry icoll_handle_irq(struct pt_regs *regs)

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Daniel Lezcano]

On 06/11/2016 11:20, Stefan Wahren wrote:
> Hi,
> 
>> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 5. November 2016 um
>> 19:05 geschrieben:
>>
>>
>> On Sat, Nov 05, 2016 at 04:28:37PM +0100, Stefan Wahren wrote:
>>> As i wrote in my email before, i added a pr_info() into freeze_wake.
>>> But i never see the output of this message. So i assume freeze_wake
>>> is never called. Again, how could this happen?
>>
>> Hmm, so the bit that you're getting stuck on is:
>>
>>         wait_event(suspend_freeze_wait_head,
>>                    suspend_freeze_state == FREEZE_STATE_WAKE);
>>
> 
> thanks for all the feedback. The real cause for this issue is in the irqchip
> driver. I fixed it with this patch:

Mind to give some details ?


> diff --git a/drivers/irqchip/irq-mxs.c b/drivers/irqchip/irq-mxs.c
> index 1730470..05fa9f7 100644
> --- a/drivers/irqchip/irq-mxs.c
> +++ b/drivers/irqchip/irq-mxs.c
> @@ -131,12 +131,16 @@ static void asm9260_unmask_irq(struct irq_data *d)
>  	.irq_ack = icoll_ack_irq,
>  	.irq_mask = icoll_mask_irq,
>  	.irq_unmask = icoll_unmask_irq,
> +	.flags = IRQCHIP_MASK_ON_SUSPEND |
> +		 IRQCHIP_SKIP_SET_WAKE,
>  };
>  
>  static struct irq_chip asm9260_icoll_chip = {
>  	.irq_ack = icoll_ack_irq,
>  	.irq_mask = asm9260_mask_irq,
>  	.irq_unmask = asm9260_unmask_irq,
> +	.flags = IRQCHIP_MASK_ON_SUSPEND |
> +		 IRQCHIP_SKIP_SET_WAKE,
>  };
>  
>  asmlinkage void __exception_irq_entry icoll_handle_irq(struct pt_regs *regs)
> 


-- 
 <http://www.linaro.org/> Linaro.org ? Open source software for ARM SoCs

Follow Linaro:  <http://www.facebook.com/pages/Linaro> Facebook |
<http://twitter.com/#!/linaroorg> Twitter |
<http://www.linaro.org/linaro-blog/> Blog

[Bug] ARM: mxs: STI: console can't wake up from freeze

[Stefan Wahren]

> Daniel Lezcano <daniel.lezcano@linaro.org> hat am 6. November 2016 um 15:55
> geschrieben:
> 
> 
> On 06/11/2016 11:20, Stefan Wahren wrote:
> > Hi,
> > 
> >> Russell King - ARM Linux <linux@armlinux.org.uk> hat am 5. November 2016 um
> >> 19:05 geschrieben:
> >>
> >>
> >> On Sat, Nov 05, 2016 at 04:28:37PM +0100, Stefan Wahren wrote:
> >>> As i wrote in my email before, i added a pr_info() into freeze_wake.
> >>> But i never see the output of this message. So i assume freeze_wake
> >>> is never called. Again, how could this happen?
> >>
> >> Hmm, so the bit that you're getting stuck on is:
> >>
> >>         wait_event(suspend_freeze_wait_head,
> >>                    suspend_freeze_state == FREEZE_STATE_WAKE);
> >>
> > 
> > thanks for all the feedback. The real cause for this issue is in the irqchip
> > driver. I fixed it with this patch:
> 
> Mind to give some details ?
> 

No. AFAIK the serial_core already handles the suspend to idle. But it requires
that enable_irq_wake for the UART IRQ succeed. Unfortunately the irq-mxs (like a
couple of other irqchip drivers) neither implemented set_irq_wake or set
IRQCHIP_SKIP_SET_WAKE so enable_irq_wake will fail with -ENXIO and the UART
won't be setup as wakeup source. As the mxs interrupt controller doesn't provide
any facility to setup wakeup source i choose to use IRQCHIP_SKIP_SET_WAKE.

Instead of failing silently it would be better if sysfs won't allow to enable
wakeup source in this case or at least the serial core should complains about
it.