suspend to ram fails on new pinephone kernel >= 5.16.x (often when charger is not plugged in)

Experienced the same with sxmo on pmos edge

As a workaround (to keep battery life) I've replaced the call to rtcwake by zzz

Suspend to ram with zzz only works if the phone was powered through usb while booting (there are some error messages in dmesg when suspend fails but I don't remember and am currently using my phone ;)

By fdlamotte on 2022-03-29T14:24:49

Yeah, I'm experiencing that behavior too: the rtcwake call will work if I just plug in the power.

By Zach DeCook on 2022-03-29T14:24:49

changed title from suspend to ram fails on new pinephone kernel to suspend to ram fails on new pinephone kernel when charger is not plugged in

By Zach DeCook on 2022-03-29T18:11:14

changed the description

By Zach DeCook on 2022-03-29T18:11:14

changed title from suspend to ram fails on new pinephone kernel when charger is not plugged in to suspend to ram fails on new pinephone kernel (often when charger is not plugged in)

By Zach DeCook on 2022-03-30T13:21:18

On my side, I can't use rtcwake even when plugged.

But if my phone was booted unplugged, zzz fails and I have this message in dmesg (looping until the phone is plugged)

musb_bus_suspend 2521: trying to suspend as a_wait_bcon while active

The good news is that I once plugged, zzz works again to suspend (even if unplugged), so I don't need to reboot.

By fdlamotte on 2022-03-31T06:56:44

Additional data point: I've been running the kernel since march 16th and suspend hasn't failed for me on Phosh.

Maybe this gets fixed by just using the latest tag from megi, can you try this one?

!3050 (closed)

(once CI built the kernel, testing with mrtest add 3050 should work.)

By Oliver Smith on 2022-03-31T12:52:20

The issue remains the same for me after installing that and rebooting: rtcwake -m mem fails maybe half of the time (with write error), but will always succeed if I plug in the charger.

It does seem like whether the charger was plugged in when it booted and/or having a high battery percentage makes it more likely that it will work.

Doing a cold boot doesn't seem to have an effect. (If this is relevant data: My modem switch is switched off).

In dmesg, I get a bunch of

[  XX.XXXXXX] musb_bus_suspend 2521⋮ trying to suspend as a_wait_bcon while active

(Which it seems @fdlamotte isn't getting, except when using zzz?) Plugging in the charger stops all those messages from endlessly flowing and emits some anx7688 messages about HARD_RST-ing some "idiot firmware is bored" (which I guess I find mildly amusing).

By Zach DeCook on 2022-03-31T12:52:20

I now have an hint on why rtcwake did not work, I was not using the -m mem flag, now I have the exact same behavior with rtcwake and zzz => time to get rid of zzz ;)

By fdlamotte on 2022-03-31T13:48:52

Thanks @ollieparanoid I successfully applied !3050 (closed)

But it did not solve my issue (that might not be the same as @earboxer since I can't even make rtcwake work)

One little thing I've come across is that rtcwake does not trigger the musb_bus_suspend message loop in dmesg

By fdlamotte on 2022-03-31T10:43:51

I confirm this new kernel tag doesnt solve the issue here either

By Willow on 2022-04-01T08:41:59

Maybe it's a model-specific thing.

If you don't remember which one you ordered, you probably have 1.2b. cat /sys/firmware/devicetree/base/model should tell you "Pine64 PinePhone (1.2)".

user	model	suspend to ram Always Works on kernel 5.17?
@earboxer	1.2b	No
@ollieparanoid	??	Yes
@fdlamotte	1.2b	No
@StacyHarper	1.2a	No
@davidegirardi	???	not on -r1
@milesalan	1.2	No
@elagost	1.2	No

If there's some other relevant data for this issue, I'd love to add it to this table.

By Zach DeCook on 2022-04-04T23:10:08

I have 1.2b

By fdlamotte on 2022-04-01T15:13:27

I got the postmarketOS Community Edition so 1.2a if I understand correct

By Willow on 2022-04-01T15:19:58

I was about to say that I only tested loginctl suspend and not rtcwake. So I tested both now... and both are working for me. I've tried multiple times in a row.

user@pine64-pinephone ~ % doas rtcwake -m mem -s 5
rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Sun Apr  3 16:37:25 2022
user@pine64-pinephone ~ %

user@pine64-pinephone ~ % cat /sys/firmware/devicetree/base/model
Pine64 PinePhone (1.2)%                                                                                                                                                                                                                        
user@pine64-pinephone ~ % uname -a 
Linux pine64-pinephone 5.17.0-rc8 #2-postmarketos-allwinner SMP PREEMPT Sat Apr 2 15:09:08 UTC 202 aarch64 GNU/Linux

I ran these tests on phosh, installed rtcwake from sxmo-utils.

I powered off the phone and powered it on again without being connected to the charger, as it was mentioned above that this may influence it. Then I tested again, and same result, it works flawlessly for me.

By Oliver Smith on 2022-04-03T17:02:34

I wanted to try loginctl but I figured out that I didn't have elogind package installed.

After install, before pluging usb-c loginctl "suspend does" nothing (not even messages in dmesg), after pluging the phone it works.

I have not dig much more but just wanted to report that if that helps. Don't know about all these daemons but it could be something with sxmo-images base install ...

By fdlamotte on 2022-04-03T17:28:39

Pine64 PinePhone Braveheart (1.1) here:

$ doas rtcwake -m mem -s 5
rtcwake: assuming RTC uses UTC ...
rtcwake: wakeup from "mem" using /dev/rtc0 at Wed Apr 13 12:04:06 2022
rtcwake: write error

By Dimitris Kardarakos on 2022-04-13T12:05:36

Just did some tests on another pinephone (also 1.2b with no SIM).

First updated the os, kernel to 5.17 and with sxmo same symptoms as with the other phone.

Installed phosh over sxmo, after reboot "rtcwake -m mem" did the same as with sxmo, same messages in dmesg. Also tried to wait for the phone to suspend and it never happened (always possible to ssh into the phone). After plugging usb-c, the phone correctly enters crust (and can't ssh). So I have the same behavior with phosh and sxmo ...

By fdlamotte on 2022-04-01T19:58:01

Should we downgrade it to linux-postmarketos-allwinner-5.16.4_git20220131-r1 ? (or the latest working version if that isnt 5.16.4_git20220131)

By Willow on 2022-04-03T17:02:36

I don't think we should downgrade the kernel. This would only be a workaround, and there's already another workaround (using zzz instead of rtcwake) that doesn't have such a big impact.

But the proper thing would be figuring out why this is caused.

So I can't reproduce it on phosh (see above)... some ideas:

Could it be a bug in rtcwake? If zzz works and rtcwake does not, one way to look further at it could be running strace on both and figuring out that way what they do differently.
Could it be a bug in sxmo? Just guessing, but maybe there's logic to prevent suspend when certain processes are running (like the sleep-inhibitor on which we depend in postmarketos-base-ui), and that doesn't work right and therefore prevents suspend? It might be worth testing with phosh too booted from sd card for the ones who can reproduce this, just to rule this out.
Are you sure that the problem is caused by a kernel upgrade? Meaning, can somebody downgrade the kernel on just their phone and verify that it works again?
- Maybe bisect the kernel to figure out which patch caused this?

By Oliver Smith on 2022-04-03T17:02:36

You're probably right, it must be our fault, as we are not that many having the issue ... I may try with a fresh install if I find some time and dig in the differences ... what I am sure is that the issue appeared right after upgrading into 5.17, as I use my phone a lot, it appeared immediately.

Over the difference between rtcwake and zzz, on my install rtcwake does not work worse or better than zzz, I was only using rtcwake badly (without the -m mem option) ...

The only workaround that I found (apart from downgrading the kernel) is to plug the charging cable to stop the messages with musb_bus_suspend. But then it works ok for me so it is ok ... I just prey for not having to reboot my phone without a usb-c plug at hand ;)

By fdlamotte on 2022-04-03T17:15:13

In my case suspend to RAM does work with version 5.17.0-rc8, from the linux-postmarketos-allwinner-5.17.0_git20220313 -r0 package, but it does not work with version -r1.

I am using Phosh and I have waked enabled to make gnome-clocks wake the phone when an alarm has to ring. Suspend to RAM is managed by pmos-tweaks.

Edit: @earboxer I have a 1.2b board. Edit2: I am getting trying to suspend as a_wait_bcon while active messages with -r0 too. I probably didn't notice before because the phone suspends in the end and the only symptom is that it asks for the SIM PIN maybe once per day.

By Davide Girardi on 2022-04-08T06:25:47

Quickly tested fresh installs of the latest edge images for phosh and sxmo from edge :

20220330-1731-postmarketOS-edge-phosh-18-pine64-pinephone.img
20220330-1804-postmarketOS-edge-sxmo-de-sway-1.8.2-pine64-pinephone.img

With phosh suspend works (with loginctl suspend as I didn't want to mess with wifi and install things), with sxmo it doesn't (with rtcwake -m mem -s 10)

By fdlamotte on 2022-04-03T19:16:28

Broken on my Pinephone as well. Testing on fbp which essentially just disables all wakeup sources and then writes mem to /sys/power/state.

What gets spammed in dmesg -w right before suspend fails on my 1.2 Pinephone:

musb_bus_suspend 2521: trying to suspend as a_wait_bcon while active

and then:

PM: dpm_run_callback(): usb_dev_suspend+0x0/0x20 returns -16
usb usb5: PM: failed to suspend async: error -16

I'd be curious to build kernel with MUSB config flags set to M and then remove musb modules before suspend.

By Miles Alan on 2022-04-03T20:58:50

I downgraded 'linux-postmarketos-allwinner=5.16.4_git20220131-r2' and I confirm I dont have the issue anymore.

It looks like we have multiple problems with this 5.17.0_git20220313-r1. Dmesg output lots of trying to suspend as a_wait_bcon while active and also some of OOM killer triggers.

Here are the full dmesg output before and after the downgrade (containing two output files):

https://paste.sr.ht/~stacyharper/b0bc4c7fc7c9062189993559a90006fbf40a30a9

amended: as you can see, connecting the usb charger made the trying to suspend as a_wait_bcon while active to stop. It allowed me to suspend. After that I may suspend 1/2 times if I disconnect the charger.

By Willow on 2022-04-05T11:53:57

I've experienced the same issue on a fresh install of edge, phosh, pinephone 1.2. MR 3050 did not solve it for me either.

By Adam Thiede on 2022-04-04T20:27:32

This particular driver (musb) logs debug messages via Linux tracing infrastructure,
and not to dmesg.

https://elixir.bootlin.com/linux/latest/source/drivers/usb/musb/musb_trace.c#L13

So you'd need to have a kernel with tracing enabled, and then enable it from
kernel command line arguments, via option:

  trace_event=musb:*

Then you can get the trace from /sys/kernel/debug/trace/...

It will be hard to get the trace, due to the nature of the bug. Trace buffer
is a cyclic buffer, so it will quickly overflow, and you'll just get the
log for the loop itself, not what happened before it was entered.

So you'd have to patch the kernel and add some mechanism to hard-break
the loop, when you detect it happening inside the musb_bus_suspend
function. (for example via a static counter variable, allow to run that
function 100 times, and then preventing the loop somehow, which will
depend on what info is gathered from the trace.

Here's a patch that may prevent the loop after a few cycles, to be able to get useful trace:

https://megous.com/dl/tmp/0001-usb-musb-add-loop-blocker.patch

Alternatively, this patch will direct musb debug output to kernel log:

https://megous.com/dl/tmp/musb-printk.patch

You'll have to disable all logging to all consoles, for it to not disturb the USB timings and introduce its own issues, and just dump the log via dmesg.

If loop stopping code will not work, then it will be hard to get a useful log of what happened prior to the loop.

By megous on 2022-04-05T11:04:35

mentioned in merge request !3050 (closed)

By Oliver Smith on 2022-04-06T07:52:57

Thanks a lot @megous!

So for everybody who can reproduce this problem, I've updated !3050 (closed) to temporarily include 0001-usb-musb-add-loop-blocker.patch and set the kernel parameter. We already had CONFIG_TRACING_SUPPORT=y in the kernel config.

It might be that adding the kernel parameter didn't work since there (at least used to be) a limit for max characters we can put in the u-boot config for the kernel command-line, and we were close to the limit before. So it might get cut off and not work, I didn't have time to test that.

Please attempt to create a useful trace:

wait until !3050 (closed) is built (or build it yourself)
mrtest add 3050 to install the new kernel and device package
reboot
verify that the kernel parameter was added as intended (if it didn't work, attempt to fix that... maybe using the musb-printk.patch is easier?)
reproduce the bug
get the trace from /sys/kernel/debug/trace/...

EDIT: the kernel from the MR is lacking tracing kernel config options, so the trace can't be produced with it yet. see below.

By Oliver Smith on 2022-04-07T07:59:07

So I tried the patch above via mrtest and it works:

pine64-pinephone:~# dmesg | grep "Kernel command line"
[    0.000000] Kernel command line: init=/init.sh rw console=tty0 console=ttyS0,115200 earlycon=uart,mmio32,0x01c28000 panic=10 consoleblank=0 loglevel=1 PMOS_NO_OUTPUT_REDIRECT PMOS_FORCE_PARTITION_RESIZE pmos_boot=/dev/mmcblk2p1 pmos_root=/dev/mmcblk2p2 trace_event=musb:*
pine64-pinephone:~# dmesg | grep -A 2 -B 2 "loop prevented"
[  193.203584] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[  193.203644] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[  193.203652] musb_bus_suspend 2531: loop prevented
[  193.203709] done.
[  193.203760] PM: suspend exit

But no trace event is recorded:

pine64-pinephone:~# ls /sys/kernel/debug/trace
ls: cannot access '/sys/kernel/debug/trace': No such file or directory
pine64-pinephone:~# gunzip -c /proc/config.gz  | grep CONFIG_TRACING_SUPPORT
CONFIG_TRACING_SUPPORT=y

Though as I am new to kernel debugging I may have overlooked something trivial.

Edit: I am on the 1.2b

By Emilio Dorigatti on 2022-04-06T16:56:56

I wonder if this warning is relevant:

[    0.000000] Kernel command line: init=/init.sh rw console=tty0 console=ttyS0,115200 earlycon=uart,mmio32,0x01c28000 panic=10 consoleblank=0 loglevel=1 PMOS_NO_OUTPUT_REDIRECT PMOS_FORCE_PARTITION_RESIZE pmos_boot=/dev/mmcblk0p1 pmos_root=/dev/mmcblk0p2 trace_event=musb:*
[    0.000000] Unknown kernel command line parameters "PMOS_NO_OUTPUT_REDIRECT PMOS_FORCE_PARTITION_RESIZE pmos_boot=/dev/mmcblk0p1 pmos_root=/dev/mmcblk0p2 trace_event=musb:*", will be passed to user space.

By Zach DeCook on 2022-04-06T16:56:56

Did a new install of edge on an SD card and added the relevant MR kernel/device packages.

pinephone:~$ apk list -I|grep linux-postmarketos
linux-postmarketos-allwinner-5.17.0_git20220323-r1 aarch64 {linux-postmarketos-allwinner} (GPL-2.0-only) [installed]
pinephone:~$ uname -a
Linux pinephone 5.17.0 #2-postmarketos-allwinner SMP PREEMPT Wed Apr 6 07:54:01 UTC 202 aarch64 Linux
pinephone:~$ cat /proc/cmdline
init=/init.sh rw console=tty0 console=ttyS0,115200 earlycon=uart,mmio32,0x01c28000 panic=10 consoleblank=0 loglevel=1 PMOS_NO_OUTPUT_REDIRECT PMOS_FORCE_PARTITION_RESIZE pmos_boot=/dev/mmcblk0p1 pmos_root=/dev/mmcblk0p2 trace_event=musb:*

I too got no trace. This seems to suspend appropriately as well. But my modem doesn't come back after suspend now.

[  448.403779] usb 2-1: device descriptor read/64, error -110
[  464.024009] usb 2-1: device descriptor read/64, error -110
[  464.260046] usb 2-1: new high-speed USB device number 13 using ehci-platform
[  469.652086] usb 2-1: device descriptor read/64, error -110
[  485.272315] usb 2-1: device descriptor read/64, error -110
[  485.380382] usb usb2-port1: attempt power cycle
[  485.588310] usb 2-1: new high-speed USB device number 14 using ehci-platform
[  496.356474] usb 2-1: device not accepting address 14, error -110
[  496.484492] usb 2-1: new high-speed USB device number 15 using ehci-platform

edit - modem came back just as I wrote this. On my main install, I've kept the kernel at 5.16.4, and have had no suspend or modem loss problems.

By Adam Thiede on 2022-04-06T13:39:46

Trace is in /sys/kernel/debug/tracing/trace file.

By megous on 2022-04-06T14:45:38

The only "trace" files I can find in /sys are /sys/kernel/slab/*/trace

By Zach DeCook on 2022-04-06T14:47:14

In addition, full dmesg output is needed too, to cross-reference the trace with.

By megous on 2022-04-06T14:53:18

Here's my dmesg output: https://paste.sr.ht/blob/8b90b986e33fbdc5babe86d133752ccb4eaf6924

My experience was pretty much the same as @edorigatti's, but the suspend only happens if I call rtcwake -m mem -s 60 a second time. (not included in the above log).

By Zach DeCook on 2022-04-06T14:53:18

Do you have debugfs mounted?

By megous on 2022-04-06T14:58:33

Yes:

~$ cat /proc/mounts | grep debugfs
debugfs /sys/kernel/debug debugfs rw,nosuid,nodev,noexec,relatime 0 0

By Zach DeCook on 2022-04-06T14:58:33

Looks like it blocks the suspend initially, and then musb_bus_suspend keeps getting called after PM: suspend exit. Hrm. -16 is EBUSY from musb_bus_suspend

[  399.878155] PM: suspend entry (deep)
[  399.878351] Filesystems sync: 0.000 seconds
[  399.879284] Freezing user space processes ... (elapsed 0.002 seconds) done.
[  399.882041] OOM killer disabled.
[  399.882047] Freezing remaining freezable tasks ... (elapsed 0.001 seconds) done.
[  399.883528] printk: Suspending console(s) (use no_console_suspend to debug)
[  399.885172] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[  399.885220] PM: dpm_run_callback(): usb_dev_suspend+0x0/0x20 returns -16
[  399.885259] usb usb5: PM: failed to suspend async: error -16
[  400.405015] PM: Some devices failed to suspend, or early wake event detected
[  400.425746] OOM killer enabled.
[  400.426003] Restarting tasks ... done.
[  400.428614] PM: suspend exit
[  400.432661] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[  400.433007] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[  400.433077] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active

By megous on 2022-04-06T15:02:55

I guess you don't have tracing properly enabled in the kernel, or you may need to mount tracefs somewhere manually. For me it's enough to mount debugfs and it contains tracing subdirectory. I'm not sure what's up with your kernel.

By megous on 2022-04-06T15:05:59

It's enabled by CONFIG_TRACING.

By megous on 2022-04-06T17:09:07

I enabled CONFIG_TRACING (see !3063 (53b64bff)), and built (with .ci/build_changed_aports.py aarch64) and installed it, but I still don't have a trace anywhere in /sys/kernel/debug.

When I try to mount it, I get

doas mount -t tracefs tracefs /tmp/tracing
mount: /tmp/tracing: unknown filesystem type 'tracefs'.
       dmesg(1) may have more information after failed mount system call.

(with nothing added to dmesg)

By Zach DeCook on 2022-04-06T17:09:07

Just because you added it to config file, doesn't mean ther kenel config system will accept it. It's best enabled via menuconfig, because these options have some interdependncies, which are easier handled that way, rather than manually. (If you search for it in /proc/config.gz you'll likely find it still disabled)

Anyway, insetead of fighting with tracing, it may be easier to use the patch to enabled logging to kernel log.

https://megous.com/dl/tmp/musb-printk.patch

By megous on 2022-04-06T18:06:38

Thanks for that info! I've built it again with the musb-printk patch, and this is what I get:

https://paste.sr.ht/blob/442f6ff6e95379a2006f7ab60cb3ae5939d10917

[   55.761452] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[   55.761466] port status 00000104
[   55.761529] Root port suspended, power e0
[   55.761537] bogus rh suspend? a_wait_bcon
[   55.761542] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[   55.761556] port status 00000104
[   55.761620] Root port suspended, power e0
[   55.761628] bogus rh suspend? a_wait_bcon
[   55.761634] musb_bus_suspend 2523: trying to suspend as a_wait_bcon while active
[   55.761643] musb_bus_suspend 2531: loop prevented

By Zach DeCook on 2022-04-06T19:47:35

Thanks @earboxer!

@megous: this is the trace you asked for, right? if you have time, it would be great if you could take a look.

By Oliver Smith on 2022-04-10T16:02:08

Yes. I compared it with a working suspend/resume and it's pretty much the same other than ->is_active being true for you, which makes the initial suspend fail and then produces the loop somehow. Next step would be figuring out why is_active is true.

By megous on 2022-04-14T08:57:47

CONFIG_TRACING_SUPPORT is something else, and does not enable tracing.

By megous on 2022-04-07T07:57:56

I see. There's a whole bunch of tracing options in Kernel hacking > Tracers, which ones would you need? I think these are the configs you use, but since they don't mention CONFIG_TRACING I'm not sure where they inherit the defaults from: https://github.com/megous/linux/tree/3c21ce2225ed70086783d87f8fbeb2d6026c7034/arch/arm64/configs

By Oliver Smith on 2022-04-07T07:57:56

I just experienced the fail to suspend/dmesg flood on 5.16.4. So it may not be related specifically to the 5.17 release.

By Adam Thiede on 2022-04-06T16:08:15

I've updated !3050 (closed) to just log to dmesg. I think we should merge this to master in the meantime since this obviously affects a lot of people, but waiting a bit so people can review the MR.

By Oliver Smith on 2022-04-10T16:00:52

I have downgraded the firmware to Biktorgj 0.5.9 (from 0.6.1) and I don't have the issue since

By Vincent Maurin on 2022-04-21T20:58:31

FWIW I've also been using Biktor's firmware, currently 0.6.3.

By Oliver Smith on 2022-04-21T20:58:31

So it happened to me again today with 0.5.9, so it doesn't fix the issue, but it seems way more stable (one problem over 4 days, while it was more than daily with 0.6.1)

By Vincent Maurin on 2022-04-24T13:43:14

Now that's an interesting coincidence, because the modem is on another USB port that doesn't have anything to do with musb. (Another data point: I don't run the modem at all in my testing.)

In dmesg posted by @earboxer there are no entries that would show startup of the modem. So that's another weirdness.

By megous on 2022-04-22T02:20:45

Yeah, I was running with the modem switched off (and could pretty reliably reproduce the issue). I've since switched to using this as my main phone (with SIM card and modem on) so I can test again and get another dmesg log for you if you want.

(but currently the workaround patch has presumably been running fine for me, though maybe I'm more proactive about keeping it plugged in since I rely on it more).

By Zach DeCook on 2022-04-22T02:20:45

I've spent an evening figuring out how to move forward with this and concluded that it's best to downgrade the kernel on edge from 5.17 to the 5.15 based kernel we use on stable (v21.12).

Summary:

I'm seeing this myself now, sometimes. It seems that it doesn't happen when the battery is nearly fully charged, only when it's about half empty. This lines up with reports here and here.
Downgrading to 5.16.x is not enough as Adam reported in #1478 (comment 903106319)
Looking at git log; as megi said, there's no relevant changes. The only change in the musb dir touches omap2430.c (23907106, which we don't use on the pinephone), everything else is the same since December 2021 (ce1d37cb).
The "loop prevented" hack catches the issue sometimes, but not always as reported here. So this means there's at least one other code path where this can happen.
I've also read some of the musb kernel driver code and the traces posted above, and given the above problems it really doesn't seem easy to figure this out. A bisect would probably help if somebody could do it, of course it takes quite some time and one would need to be able to reliably test the problem on each revision of the bisect.

I think we should stay on the 5.15 based kernel in edge, until we have reason to believe that the bug was fixed (hopefully somebody can do the bisect), or until some time passes and we just try the next kernel. Then give that next kernel a lot of testing, especially related to suspend, before merging it. This is not a great solution, but given that we've been trying to figure this out collectively for 3 weeks already and all have limited time to spend on this, it seems the best we can do.

Thanks to everybody who gave their input on this!

By Oliver Smith on 2022-04-22T02:29:50

I wonder what the main strategy for the bisect would be, that 5.17-megi is not a direct descendant of 5.15-megi.

Like: bisect between 5.15 and 5.17, picking up the 400-500 patches from https://xff.cz/kernels/ which are from the last ancestor?

By Zach DeCook on 2022-04-22T02:29:50

I'd find the common ancestor, make sure that the bug can't be reproduced there, switch to 5.17-megi, make sure the bug can be reproduced, and then start the bisect.

By Oliver Smith on 2022-04-22T07:18:45

bisect would look like:

try with mainline, if you can reproduce it (might be possible, because it seems to happen in peripheral mode of the USB port, which I think is default on mainline - you'd just have to make sure to compile both host and peripheral modes into the musb driver)
if yes, then bisect

otherwise:

pick out only minimal relevant changes for making pp USB work (anx7688 driver + some small relevant changes + latest DT for pinephone from my branch)
make it into a single patch
bisect mainline as above, but apply this patch at each step (making it minimal will ensure it's unlikely to cause conflicts)

By megous on 2022-04-22T08:16:45

I can replicate the behavior reliably (boot with a USB cable connected, disconnect the cable, reboot the phone and wait for suspend to be triggered) and my rig can build a kernel in less than 15 minutes.

However, I'm not proficient with git and not a kernel expert either.

So, if someone can take care of a branch with the bisected kernel sources, I could handle the building and testing part of each bisected rev.

Let me know.

By Bobby The Builder on 2022-04-26T22:18:14

Nice, that helped. Now I can finally reproduce it, too.

By megous on 2022-04-27T02:36:15

Hmm, so it happened only once. How it doesn't happen anymore with the same steps.

By megous on 2022-04-27T02:45:13

mentioned in merge request !3086 (merged)

By Oliver Smith on 2022-04-21T20:56:39

Kernel downgrade MR: !3086 (merged)

I'll leave this issue intentionally open since the downgrade is of course only a workaround.

By Oliver Smith on 2022-04-21T21:08:14

changed title from suspend to ram fails on new pinephone kernel (often when charger is not plugged in) to suspend to ram fails on new pinephone kernel >= 5.16.x (often when charger is not plugged in)

By Oliver Smith on 2022-04-21T21:09:06

added device-pine64-pinephone type::bug labels

For what it's worth I've been on 5.16.4 and haven't experienced it for the past week. I'm not sure what triggered it the first time but it has not happened since. I am also on 0.6.1 of the FOSS modem firmware.

By Adam Thiede on 2022-04-24T12:23:36

Thanks for reporting back! Yeah let's go with 5.16.4 then, according to lots of reports it's very stable.

By Oliver Smith on 2022-04-24T12:23:36

What's weird is that HCI side of the musb driver where this bug happens supposedly should not be used at all, because A64 uses a switch that delegates USB host mode to standard ehci0/ohci0 HW interfaces, which are implemented in a completely different driver.

https://megous.com/dl/tmp/15d7ebf18d2409fc.png (musb HW block highlighted)

In fact HCI side of musb HW block is cut off by the HW switch when USB0 is in host mode. And in peripheral mode, I don't see why musb driver would be calling some functions for host side implementation at all, or why they would not be gated somehow at runtime. I believe musb HCI should not be active at all ever, in host or peripheral modes. Maybe

It doesn't help that there are no docs for musb HW, and the driver is not exaclty grokable without understanding how USB OTG is supposed to work in detail.

What might be interesting to try is to cut out host mode code, but still allow to set peripheral-mode = "otg" in DT.

By megous on 2022-04-22T08:38:49

Then at least there will be no way for host code to crash and loop like that, because the code will not be there. ;)

By megous on 2022-04-22T08:48:28

Downgrade to 5.16.4 has been merged, binary package will be available soon. Use apk upgrade -a as always to get it.

By Oliver Smith on 2022-04-25T06:30:37

Try this patch: https://megous.com/dl/tmp/0001-usb-musb-sunxi-Avoid-enabling-host-side-code-on-SoCs.patch

By megous on 2022-04-27T05:07:33

mentioned in merge request !3097 (merged)

By Bobby The Builder on 2022-04-27T14:30:04

@megous thank you

I tested 5.17.2 (!3050 (closed)) + your patch and I haven't had any issue with it.

I'm live with orange-pi-5.17-20220427-0710 (5.17.4 !3097 (merged)) and it does look good.

By Bobby The Builder on 2022-04-27T14:31:27

Side note: Now, when I plug a USB cable the phone does wake up if it's suspended; Before it wasn't waking up and I had to press the power button.

2 problems solved in one patch

By Bobby The Builder on 2022-04-27T14:41:37

Good. :) Thanks for testing.

By megous on 2022-04-27T14:52:16

My issue is maybe not the same, but it could help for testing and debugging.

I have noticed that with FOSS Firmware 0.6.1 and the latest kernels (both the 5.17 and the recently downgraded 5.16 version), that my phone was warming up while being idle, and the battery was draining very fast, or draining while plugged in. The only "clue" I was able to get is the following "loop" logs from the firmware linux

Apr 27 07:11:38 mdm9607 kern.info kernel: [  131.907111] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:12:05 mdm9607 kern.info kernel: [  158.756608] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:12:09 mdm9607 kern.info kernel: [  162.532651] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:12:35 mdm9607 kern.info kernel: [  188.740602] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:12:38 mdm9607 kern.info kernel: [  191.810411] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:13:05 mdm9607 kern.info kernel: [  218.764613] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:13:09 mdm9607 kern.info kernel: [  222.559484] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:13:35 mdm9607 kern.info kernel: [  248.764746] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:13:38 mdm9607 kern.info kernel: [  251.842685] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:14:05 mdm9607 kern.info kernel: [  278.764921] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:14:09 mdm9607 kern.info kernel: [  282.561384] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:14:35 mdm9607 kern.info kernel: [  308.741116] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:14:38 mdm9607 kern.info kernel: [  311.879912] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received
Apr 27 07:15:05 mdm9607 kern.info kernel: [  338.765279] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_RESUME_EVENT received
Apr 27 07:15:09 mdm9607 kern.info kernel: [  342.225483] msm_hsusb msm_hsusb: CI13XXX_CONTROLLER_SUSPEND_EVENT received

It is just an extract, it continues until I was actually connecting via adb shell. What I did then and that seems to mitigate the issue is to change the power control option to on in /usr/lib/udev/rules.d/80-modem-eg25.rules (the default installed by the package is auto).

For me this problem is almost then always reproducible by :

having FOSS 0.6.1 firmware
having auto in /usr/lib/udev/rules.d/80-modem-eg25.rules
turning off completely the phone
plugin in the charging USB cable
plugin in the cable results the phone to boot
then once booter, pressing the power button to "dim" the screen
after some time, it will get warmer and the battery is not charging/discharging

By Vincent Maurin on 2022-04-28T07:06:42

You should create another issues for that, because this one will get closed, soon.

By Ondřej Jirman on 2022-04-28T08:40:29

Heating without any apparent system load visible in htop can be comming up from interrupt "storms", or some other hidden things inside the kernel that are not accounted for.

You can check /proc/interrupts to see if there are some interrupts that are accumulating very quickly (at rate >1000/s) when there's no apparent system activity. (both in the pinephone and in the modem)

The messages you posted are separated by many seconds apart. Likely not enough to indicate any problem that would result in heating te phone too much.

By Ondřej Jirman on 2022-04-28T08:48:09

@megous Thank you a lot for the patch. This could get my PinePhone daily-driver ready again.

One question about the kernel version: I dual-use pmOS edge and 21.12 on two different SD-cards with SWMO installed. The edge version shows the bug as expected. But the 21.12 version shows the bug too with a 5.15.13 kernel. Is it possible that the bug also affects kernel versions <= 5.16.4?

In this case the downgrade to 5.16.4 would be useless and it should be considered to patch the stable version of pmOS too, if this makes sense.

By x engineering on 2022-05-01T21:33:55

Thanks for the report! Added the kernel upgrade to the next service pack planned here: #1514 (closed)

By Oliver Smith on 2022-05-01T21:33:55

suspend to ram fails on new pinephone kernel >= 5.16.x (often when charger is not plugged in)

Describe your issue

What's the expected behavior?

What's the current behavior?

How to reproduce your issue?

What device are you using?

On what postmarketOS version did you encounter the issue?

On what environment did you encounter the issue?

Phone environments

Other

How did you get postmarketOS image?

What's the build date of the image? (in yyyy-mm-dd format)

Additional information

Child items 0

Activity