Phone does not suspend

[Pat McGowan]

I am seeing both the MX4 on proposed and the E4.5 on stable exhibit similar behavior
According to the logs they are not able to suspend due to active wakeup sources.
(I am running a BT test kernel on the MX4 3.10.35+)

[Pat McGowan (pat-mcgowan)]

The phone was plugged in from around 5pm to 8pm. Quick drain can be seen from that time on. (The graph incorrectly shows a gain in charge from 2pm which is not possible, I assume it missed some events.

[Pat McGowan (pat-mcgowan)]

The phone was plugged in from around 5pm to 8pm. Quick drain can be seen from that time on. (The graph incorrectly shows a gain in charge from 2pm which is not possible, I assume it missed some events.

[Pat McGowan (pat-mcgowan)]

Actually this is from the previous log, this is repeated thousand of times

Oct 11 05:16:54 ubuntu-phablet kernel: [82715.640877] active wakeup source: MT662x
Oct 11 05:16:54 ubuntu-phablet kernel: [82715.640896] active wakeup source: EINT wakelock
Oct 11 05:16:55 ubuntu-phablet kernel: [82716.655950] active wakeup source: MT662x
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.728492] PM: suspend entry 2015-10-11 09:16:57.752096077 UTC
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.728512] PM: Syncing filesystems ... done.
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.759147] Freezing user space processes ...
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760219] active wakeup source: MT662x
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760250] active wakeup source: EINT wakelock
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760260]
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760275] Freezing of tasks aborted after 0.001 seconds (20 tasks refusing to freeze, wq_busy=0):
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760315]
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.760323] Restarting tasks ... done.
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.762588] msdc: 0,mmc_schedule_delayed_work ret= 1
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.762658] PM: suspend exit 2015-10-11 09:16:57.786272461 UTC
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.762692] WQ warning! work (try_to_suspend, c0f38b2c) execute more than 1 sec, time: 3121820846 ns
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.762946] active wakeup source: MT662x
Oct 11 05:16:57 ubuntu-phablet kernel: [82718.762966] active wakeup source: EINT wakelock
Oct 11 05:16:58 ubuntu-phablet kernel: [82719.775967] active wakeup source: MT662x
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.868468] PM: suspend entry 2015-10-11 09:17:00.892072692 UTC
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.868487] PM: Syncing filesystems ... done.
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.895468] Freezing user space processes ...
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.896555] active wakeup source: MT662x
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.896585]
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.896600] Freezing of tasks aborted after 0.001 seconds (20 tasks refusing to freeze, wq_busy=0):
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.896641]
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.896649] Restarting tasks ... done.
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.898617] msdc: 0,mmc_schedule_delayed_work ret= 1
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.898685] PM: suspend exit 2015-10-11 09:17:00.922299385 UTC
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.898717] WQ warning! work (try_to_suspend, c0f38b2c) execute more than 1 sec, time: 3135993923 ns
Oct 11 05:17:00 ubuntu-phablet kernel: [82721.898757] active wakeup source: MT662x
Oct 11 05:17:01 ubuntu-phablet CRON[11160]: (root) CMD ( cd / && run-parts --report /etc/cron.hourly)

[kevin gunn (kgunn72)]

if it were screen related mir team might be able to help, but this seems to be strictly power mode issue, cmiiaw

[Launchpad Janitor (janitor)]

Status changed to 'Confirmed' because the bug affects multiple users.

[Pat McGowan (pat-mcgowan)]

@yc for thoughts on why that part would cause those wakeups

[Simon Fels (morphis)]

The wakeup source hold here "MT662x" is the combo connectivity chip responsible for WiFi/BT/GPS.

@Pat: Can you describe a bit more what you did with the device before this happened or what it was connected to?

[Pat McGowan (pat-mcgowan)]

@simon as I recall, I was out for the afternoon, I am pretty sure I used a map app to get where I was going
I am suspecting gps here since the other report has wifi abd bt off, and the report at bug #1511312 mentions he usually has gps off

[Yuan-Chen Cheng (ycheng-twn)]

@pat, I guess you only saw it once, right ? I also hit by something similar long ago, but only happened once:
https://bugs.launchpad.net/bugs/1461589 (private bug)

[Pat McGowan (pat-mcgowan)]

This happened again this weekend. I am pretty sure its every time you use GPS from an app, will try to confirm.

[Pat McGowan (pat-mcgowan)]

Now seeing this repeated every few secs

Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.682920] PM: suspend entry 2015-11-02 14:07:20.071298692 UTC
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.682938] PM: Syncing filesystems ... done.
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.715728] Freezing user space processes ...
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716807] active wakeup source: WLAN timeout
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716834] active wakeup source: EINT wakelock
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716845]
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716859] Freezing of tasks aborted after 0.001 seconds (20 tasks refusing to freeze, wq_busy=0):
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716903]
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.716911] Restarting tasks ... done.
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.718951] msdc: 0,mmc_schedule_delayed_work ret= 1
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.719022] PM: suspend exit 2015-11-02 14:07:20.107407923 UTC
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.719052] WQ warning! work (try_to_suspend, c0eaab2c) execute more than 1 sec, time: 1017252385 ns
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.719090] active wakeup source: WLAN timeout
Nov 2 09:07:20 ubuntu-phablet kernel: [ 5513.719110] active wakeup source: EINT wakelock
Nov 2 09:07:21 ubuntu-phablet kernel: [ 5514.693126] PM: suspend entry 2015-11-02 14:07:21.081505154 UTC

[Pat McGowan (pat-mcgowan)]

Use google maps, get location, put it in the background
Recieved a couple texts when suspended, eventually got into the same state as earlier

Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.001763] PM: suspend entry 2015-11-02 14:57:01.474846087 UTC
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.001782] PM: Syncing filesystems ... done.
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.033651] Freezing user space processes ...
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035298] active wakeup source: MT662x
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035326] active wakeup source: EINT wakelock
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035337]
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035350] Freezing of tasks aborted after 0.001 seconds (20 tasks refusing to freeze, wq_busy=0):
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035391]
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.035399] Restarting tasks ... done.
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.037492] msdc: 0,mmc_schedule_delayed_work ret= 1
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.037559] PM: suspend exit 2015-11-02 14:57:01.510651010 UTC
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.037590] WQ warning! work (try_to_suspend, c0eaab2c) execute more than 1 sec, time: 3117540769 ns
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.037626] active wakeup source: MT662x
Nov 2 09:57:01 ubuntu-phablet kernel: [ 361.037647] active wakeup source: EINT wakelock
Nov 2 09:57:02 ubuntu-phablet kernel: [ 362.047413] active wakeup source: MT662x

[Pat McGowan (pat-mcgowan)]

Wifi was off for last comment

[Pat McGowan (pat-mcgowan)]

Happens every time I use location from a map app.
Battery drains around 2.5%+ overnight, should be less than 1%

[Pat McGowan (pat-mcgowan)]

to clarify that was 2.5% per hr

[Pat McGowan (pat-mcgowan)]

E4.5 log after a reboot

[Pat McGowan (pat-mcgowan)]

MX4 log after a reboot

[Pat McGowan (pat-mcgowan)]

/proc/wakeup_reason from MX4

[Pat McGowan (pat-mcgowan)]

Running suspend-blocker on the logs shows the krillin is suspended, despite the log containing reports of "suspended 0 seconds"

Suspends:
  6 suspends aborted (9.09%).
  60 suspends succeeded (90.91%).
  total time: 1735.045357 seconds (95.52%).
  minimum: 0.077456 seconds.
  maximum: 119.005703 seconds.
  mean: 28.917423 seconds.
  mode: 14.000000 seconds.
  median: 15.945897 seconds.

Time between successful suspends:
  total time: 81.430986 seconds (4.48%).
  minimum: 0.072164 seconds.
  maximum: 7.749603 seconds.
  mean: 1.380186 seconds.
  mode: 1.000000 seconds.
  median: 1.002277 seconds.

[vampireechidna (vampireechidna)]

It seems that battery life has become greatly reduced on my MX4 since the last OTA-7 update.
I'm unsure if this is something to do with my daily use of the phone or if this is a known problem.
having left the device on charge during the night, by mid day with little interaction it 50% full.
Granted I have the wifi enabled and Bluetooth for connection to my vehicle.
I'm not doing anything different today than what I've done before the recent update.

Was advise to submit the Syslog to this bug.

[Pat McGowan (pat-mcgowan)]

With Bluetooth disabled the MX4 does suspend so I suspect the test kernel for my issue, will try reverting

[Pat McGowan (pat-mcgowan)]

marking invalid as it works fine with the shipping kernel

[Julia Palandri (julia-palandri)]

@Pat you mentioned a testing kernel on the MX4, but not on the BQ. If this happens in the BQ as well running a stable kernel that means we're still chasing this bug, right?

[Pat McGowan (pat-mcgowan)]

@Julia yes there could be a bug still on BQ

[Simon Fels (morphis)]

I tried to reproduce this with two MX4:

- First one running rc-proposed, the newer kernel with upgraded bluetooth stack and bluez4.
- Second one running rc-proposed, the newer kernel with upgraded bluetooth stack and bluez5.

Pat was running the first combination. I saw similar kernel suspend aborts due to the wakeup source MT662x being still active but not such a huge battery drain as Pat had. My battery only lost around 15-20% in ~20h where I just plugged it into my laptop for a few min to fetch a recent syslog in between. The rest of the time the phone was just laying around being paired and connect to a bluetooth device, being connected to a WiFi network and got a GPS fix before I turned the screen off.

Statistics look like this:

Resume wakeup causes:
  EINT, 909 100.00%

Suspend failure causes:
  tasks freezer abort 536 99.81%
  devices failed to suspend 1 0.19%

Suspends:
  588 suspends aborted (39.28%).
  909 suspends succeeded (60.72%).
  total time: 10361.993895 seconds (87.08%).
  minimum: 0.400780 seconds.
  maximum: 74.526359 seconds.
  mean: 11.399333 seconds.
  mode: 14.000000 seconds.
  median: 13.158011 seconds.

Time between successful suspends:
  total time: 1537.561435 seconds (12.92%).
  minimum: 0.897107 seconds.
  maximum: 11.649660 seconds.
  mean: 1.693350 seconds.
  mode: 1.000000 seconds.
  median: 1.030588 seconds.

[Simon Fels (morphis)]

Worth to mentioned but doesn't prove anything yet: When turning bluetooth off

Nov 13 06:06:18 ubuntu-phablet kernel: [60938.696811] [HCI-STP][I]hci_stp_close:hdev(0xd91de000)
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.696829] [HCI-STP][I]hci_stp_flush:done
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.696841] Flush type = 0 Rx Queue
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.696856] ############ BT OFF ====>>sec=1447394778, usec=940213
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.710524] ############ BT OFF <====>sec=1447394778, usec=953871
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.710541] [HCI-STP][I]hci_stp_close:WMT turn off BT OK!
Nov 13 06:06:18 ubuntu-phablet kernel: [60938.742769] [CONN-MD-DFT][I]conn_md_thread:no msg queued in msg queue...
....
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.707955] PM: suspend entry 2015-11-13 06:06:35.951294414 UTC
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.707976] PM: Syncing filesystems ... done.
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.732748] Freezing user space processes ...
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.733966] active wakeup source: MT662x
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.733995]
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.734010] Freezing of tasks aborted after 0.001 seconds (24 tasks refusing to freeze, wq_busy=0):
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.734051]
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.734060] Restarting tasks ... done.
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.736030] msdc: 0,mmc_schedule_delayed_work ret= 1
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.736098] PM: suspend exit 2015-11-13 06:06:35.979446414 UTC
Nov 13 06:06:35 ubuntu-phablet kernel: [60955.736116] WQ warning! work (try_to_suspend, c0eaab2c) execute more than 1 sec, time: 635923103499 ns

So suspend still fails even if BT is turned off.

[Simon Fels (morphis)]

Disabling WiFi as next step lets the device suspend (but being woken up by EINT shortly afterwards again).

[Simon Fels (morphis)]

Generally I see aborted suspends because of the MT662x wakeup source also on rc-proposed with its current kernel but not in such a high frequency as Pat or I saw them before.

[Simon Fels (morphis)]

QA did a test run and measure power usage on an MX4 device. Results are stored at http://people.canonical.com/~platform-qa/power-results/?Chttp://people.canonical.com/~platform-qa/power-results/?C=M;O=D=M;O=D Test run number is 166.

According to QA they don't show anything significant difference to normal runs.

[Colin Ian King (colin-king)]

From the syslog in comment #2,

Suspend blocking wakelocks:
  None

Resume wakeup causes:
  EINT, 553 97.88%
  CLDMA_MD 6 1.06%
  CLDMA_MD, 6 1.06%

Suspend failure causes:
  tasks freezer abort 2548 99.96%
  devices failed to suspend 1 0.04%

Time between successful suspends:
   Interval (seconds) Frequency Cumulative Time (Seconds)
     0.500 - 0.999 222 39.78% 207.71 1.64%
     1.000 - 1.999 222 39.78% 324.46 2.56%
     2.000 - 3.999 69 12.37% 186.37 1.47%
     4.000 - 7.999 33 5.91% 177.43 1.40%
     8.000 - 15.999 4 0.72% 32.98 0.26%
    16.000 - 31.999 0 0.00% 0.00 0.00%
    32.000 - 63.999 1 0.18% 54.62 0.43%
    64.000 - 127.999 1 0.18% 127.39 1.01%
   128.000 - 255.999 0 0.00% 0.00 0.00%
   256.000 - 511.999 2 0.36% 632.91 5.00%
   512.000 - 1023.999 1 0.18% 1014.42 8.02%
  1024.000 - 2047.999 1 0.18% 1989.64 15.72%
  2048.000 - 4095.999 1 0.18% 2373.90 18.76%
  4096.000 - 8191.999 1 0.18% 5532.61 43.72%

Duration of successful suspends:
   Interval (seconds) Frequency Cumulative Time (Seconds)
     0.250 - 0.499 7 1.25% 2.70 0.04%
     0.500 - 0.999 15 2.68% 11.42 0.18%
     1.000 - 1.999 22 3.94% 31.21 0.48%
     2.000 - 3.999 68 12.16% 192.50 2.98%
     4.000 - 7.999 340 60.82% 1959.54 30.29%
     8.000 - 15.999 12 2.15% 139.92 2.16%
    16.000 - 31.999 31 5.55% 705.55 10.91%
    32.000 - 63.999 53 9.48% 2672.92 41.32%
    64.000 - 127.999 11 1.97% 752.79 11.64%

Suspends:
  2584 suspends aborted (82.21%).
  559 suspends succeeded (17.79%).
  total time: 6468.553336 seconds (33.83%).
  minimum: 0.333752 seconds.
  maximum: 106.062716 seconds.
  mean: 11.571652 seconds.
  mode: 6.000000 seconds.
  median: 5.974301 seconds.

Time between successful suspends:
  total time: 12654.471830 seconds (66.17%).
  minimum: 0.898421 seconds.
  maximum: 5532.614185 seconds.
  mean: 22.678265 seconds.
  mode: 1.000000 seconds.
  median: 1.155373 seconds.

[Simon Fels (morphis)]

Marked as In-Progress for system-image now too as BlueZ5 has landed in the overlay ppa.

[Simon Fels (morphis)]

Have a MX4 being active now for more than 3 days and not getting this problem with rc-proposed (which has BlueZ 5 merged) again

simon@nirvana ...-bluez5-upgrade/suspend-problem-arale % ~/Work/ubuntu2/suspend-blocker/suspend-blocker syslog
syslog:
Suspends:
  421 suspends aborted (13.66%).
  2661 suspends succeeded (86.34%).
  total time: 14336.580655 seconds (24.56%).
  minimum: 0.273411 seconds.
  maximum: 29.424044 seconds.
  mean: 5.387667 seconds.
  mode: 2.000000 seconds.
  median: 4.020927 seconds.

Time between successful suspends:
  total time: 44043.299598 seconds (75.44%).
  minimum: 0.907498 seconds.
  maximum: 38991.833792 seconds.
  mean: 16.557631 seconds.
  mode: 1.000000 seconds.
  median: 1.220935 seconds.
simon@nirvana ...-bluez5-upgrade/suspend-problem-arale % adb shell
uphablet@ubuntu-phablet:~$ uptime
 08:33:51 up 3 days, 13:00, 1 user, load average: 0.00, 0.01, 0.02

[Simon Fels (morphis)]

@Pat: Are you running rc-proposed? If yes, did you see anything over the weekend which looks like this is still happening with bluez5 being merged?

[Pat McGowan (pat-mcgowan)]

My test MX4 did suspend reasonably over a period of several hours, trying my daily driver now

[Pat McGowan (pat-mcgowan)]

On my MX4 after half a day of use

Suspends:
  6826 suspends aborted (99.53%).
  32 suspends succeeded (0.47%).

Battery dropped 50% overnight

[Simon Fels (morphis)]

Added some debug statements to the arale kernel and now waiting for the problem to reappear here to find out more details.

[Simon Fels (morphis)]

If somebody else wants to do this too the used boot.img for arale is attached here.

[Ubuntu Foundations Team Bug Bot (crichton)]

The attachment "0001-Add-STP-MT662x-wakelock-traces.patch" seems to be a patch. If it isn't, please remove the "patch" flag from the attachment, remove the "patch" tag, and if you are a member of the ~ubuntu-reviewers, unsubscribe the team.

[This is an automated message performed by a Launchpad user owned by ~brian-murray, for any issues please contact him.]

[Pat McGowan (pat-mcgowan)]

Log with debugging kernel, pretty high fail to suspend rate

Suspends:
  262 suspends aborted (38.93%).
  411 suspends succeeded (61.07%).
  total time: 7293.604631 seconds (84.86%).
  minimum: 0.319212 seconds.
  maximum: 1359.032827 seconds.
  mean: 17.745997 seconds.
  mode: 6.000000 seconds.
  median: 6.060202 seconds.

Time between successful suspends:
  total time: 1300.874846 seconds (15.14%).
  minimum: 0.000080 seconds.
  maximum: 308.381052 seconds.
  mean: 3.172865 seconds.
  mode: 1.000000 seconds.
  median: 1.186014 seconds.

[Simon Fels (morphis)]

I went through Pats log file and it looks basically like this: The system doesn't go into sleep mode as their is still ongoing data flowing over the transport to the BT/WiFi/GPS combo chip. If that is real or a bug isn't clear yet. I am currently going through the responsible driver and see how this is actually supposed to work.

[Simon Fels (morphis)]

I looked through the code in the mx4 kernel now a bit more and the reason for the hold wakelock is that there is simply data flowing. What triggers the data flow or what data is actually flowing is not clear yet but I don't see any HCI frames receiving on the bluetooth stack side so far when this happens.

Next steps are to find a proper fix:

1. Find out what is actually sending data and why
2. Look into the difference between mx4 and krillin on the kernel side and see if that helps us
3. Trace the trigger through the whole MTK stack and see what is actually causing the activity

[Pat McGowan (pat-mcgowan)]

syslog with phone plugged in and charging for several hours, then unplugged, then charging again. All raidios on but did not connect to BT.
suspend-blocker is no longer able to parse the log output so unsure the suspend success.

[Simon Fels (morphis)]

@Pat: Does it print out something like:

Suspend blocking wakelocks:
  None

Resume wakeup causes:
  None

Suspend failure causes:
  None

Suspends:
  0 suspends aborted (0.00%).
  0 suspends succeeded (0.00%).
  total time: 0.000000 seconds (0.00%).
  minimum: 0.000000 seconds.
  maximum: 0.000000 seconds.
  mean: 0.000000 seconds.
  mode: 0.000000 seconds.
  median: 0.000000 seconds.

Time between successful suspends:
  total time: 0.000000 seconds (0.00%).
  minimum: 0.000000 seconds.
  maximum: 0.000000 seconds.
  mean: 0.000000 seconds.
  mode: 0.000000 seconds.
  median: 0.000000 seconds.

If yes, that is right. The log file does not contain any suspend attempt (from the kernel side) and your phone will never try to suspend as long as a usb cable is plugged in.

[Pat McGowan (pat-mcgowan)]

I think I long ago added a bug on that, when plugged in to a charger we should certainly suspend, its not an active USB data connection so we should not hold the wakelock in that case.

[Pat McGowan (pat-mcgowan)]

Latest log

Suspend blocking wakelocks:
  None

Resume wakeup causes:
  EINT, 170 98.84%
  CLDMA_MD 1 0.58%
  CLDMA_MD, 1 0.58%

Suspend failure causes:
  tasks freezer abort 783 99.87%
  devices failed to suspend 1 0.13%

Time between successful suspends:
   Interval (seconds) Frequency Cumulative Time (Seconds)
     0.250 - 0.499 1 0.59% 0.42 0.02%
     0.500 - 0.999 66 38.82% 61.81 2.23%
     1.000 - 1.999 63 37.06% 94.71 3.42%
     2.000 - 3.999 18 10.59% 41.06 1.48%
     4.000 - 7.999 15 8.82% 87.16 3.15%
     8.000 - 15.999 0 0.00% 0.00 0.00%
    16.000 - 31.999 1 0.59% 16.47 0.60%
    32.000 - 63.999 0 0.00% 0.00 0.00%
    64.000 - 127.999 0 0.00% 0.00 0.00%
   128.000 - 255.999 4 2.35% 634.54 22.92%
   256.000 - 511.999 1 0.59% 261.71 9.45%
   512.000 - 1023.999 0 0.00% 0.00 0.00%
  1024.000 - 2047.999 1 0.59% 1570.61 56.73%

Duration of successful suspends:
   Interval (seconds) Frequency Cumulative Time (Seconds)
     0.250 - 0.499 3 1.75% 1.13 0.04%
     0.500 - 0.999 0 0.00% 0.00 0.00%
     1.000 - 1.999 10 5.85% 12.97 0.48%
     2.000 - 3.999 17 9.94% 48.77 1.81%
     4.000 - 7.999 91 53.22% 514.08 19.12%
     8.000 - 15.999 11 6.43% 122.08 4.54%
    16.000 - 31.999 9 5.26% 212.36 7.90%
    32.000 - 63.999 22 12.87% 1165.36 43.35%
    64.000 - 127.999 8 4.68% 611.53 22.75%

Suspends:
  789 suspends aborted (82.19%).
  171 suspends succeeded (17.81%).
  total time: 2688.280289 seconds (49.27%).
  minimum: 0.365635 seconds.
  maximum: 124.066354 seconds.
  mean: 15.720937 seconds.
  mode: 6.000000 seconds.
  median: 6.060716 seconds.

Time between successful suspends:
  total time: 2768.483611 seconds (50.73%).
  minimum: 0.424609 seconds.
  maximum: 1570.606069 seconds.
  mean: 16.285198 seconds.
  mode: 1.000000 seconds.
  median: 1.247488 seconds.

[Pat McGowan (pat-mcgowan)]

With the latest kernel with fix for temperature controller reports things are much improved.

Resume wakeup causes:
  EINT, 2903 94.47%
  CLDMA_MD 85 2.77%
  CLDMA_MD, 85 2.77%

Suspend failure causes:
  tasks freezer abort 113 99.12%
  devices failed to suspend 1 0.88%

254 suspends aborted (7.83%).
2988 suspends succeeded (92.17%).

[Simon Fels (morphis)]

Attached is the log from Pat which shows the actual problem together with some verbose logging.

From the log the reason for the continous hold wakelock MT662x are therm events we're receiving from the WiFi/BT/.. combo chip. They start to flood at one point which will keep the device awake. One krillin interestingly we don't have support for this enabled at all and those events just never come in. What triggers the flood of therm events isn't clear yet but a first attempt to just disable them gave very good results as Pat showed above.

I've uploaded a fix for this to get some more eyes on this.

[Pat McGowan (pat-mcgowan)]

Device part 20160106-6a15a0b