termux-wake-lock and termux-wake-unlock take ~10 seconds in widgets on Android 12L

[ghost]

termux-wake-lock and termux-wake-unlock, run by Python's os.system(), have begun taking some 10 seconds each on an Android 12L device (a Samsung Fold4), when called from a Termux:Widget script only.

These calls are useful for auto-locking in long-running widgets. They formerly returned immediately on Android 10 (a Note20 Ultra), and paused for 2-3 seconds on Android 12 (a Fold3). The 10-second pauses on 12L are new. The calls still run for 2-3 seconds outside the widget on 12L, but two 10-second pauses are naturally subpar for widget users.

As a workaround, running the lock and unlock calls in the background avoids the pauses, but this is brittle. Widget scripts in the subject program cannot run in parallel in general, but starting and stopping multiple widget scripts in rapid succession may leave the lock in an arbitrary state on 12L because backgrounded calls overlap (atypical, but possible).

It's impossible to know if this reflects Samsung or Android changes without more test devices and/or time; just reporting it as an otherwise satisfied Termux:Widget customer.

Context: this is part of a PC<=>Android content-sync package which uses Termux heavily, at https://learning-python.com/android-deltas-sync/. The widget scripts are simple shims that look like the following:

#!/data/data/com.termux/files/usr/bin/python3 

# EDIT if needed
runee = '/sdcard/Download/android-deltas-sync/sync-changes-part2-phone.py'

import sys, os
trace = lambda *args: None
auto_wakelock = True                       # environment vars don't work

if auto_wakelock:
    trace('(acquiring wakelock)')
    os.system('termux-wake-lock &')        # keep cpu running (but don't wait)

os.system(sys.executable + ' ' + runee)    # run package's main script 

if auto_wakelock:
    trace('(releasing wakelock)')
    os.system('termux-wake-unlock &')      # release wake lock (but don't wait)

input('Bye (press enter)')                 # keep console open till enter/return

[agnostic-apollo]

The 2-3 second delay may be related to termux/termux-tools#15 and needs to be investigated but shouldn't happen on next termux-app update due to termux-am-socket usage.

https://github.com/termux/termux-tools/blob/8853fbda62cf74616b839219157e1a7471dca9d7/scripts/termux-wake-lock.in#L9

The 10s delay could be due to intent to TermuxService taking lot of time to be sent/received. You can check the exact times with logcat after setting both apps to verbose log level.

https://github.com/termux/termux-widget#debugging

[ghost]

Okay; here's a simple Bash test script that removes a few variables:

date
echo 'Lock'
termux-wake-lock
date
echo 'Unlock'
termux-wake-unlock
date
read -p 'Press enter' ignore

Attached is a screenshot showing this script run in the console; another showing the same script run in a widget; and a logcat from the session. Termux app versions are captured as well, and all attachments are from the 12L Fold4. As shown, the calls take roughly 9-10 seconds in the widget, and 2-3 outside it.

But this story is actually growing a bit stranger. On further testing, I've found that restarting the Android 12L test device will temporarily alleviate the problem: immediately after the restart, the lock and unlock calls run for 2-3 seconds in the widget, just like they do outside the widget.

However, this doesn't last: after the device is allowed to sleep (e.g., by pressing the power button and waiting a few minutes), the calls go right back to taking 9-10 seconds in the widget again. Weird; maybe sleep—or Samsung's flavor of it—is somehow triggering the longer delays?

Data point: in the logcat, there is a 6-second pause at the line dex2oat64: setting boot class path... for widget runs only. That would roughly account for the diff between 2-3 and 9-10 seconds, but there are a lot of moving parts, and I'm already dangerously above my pay grade on this.

So as it stands, restarting the phone is a work-around of sorts for the 10-second delays, but only until the next sleep state restores them. Backgrounding the calls avoids widget pauses either way, but gets dicey when the 10-second delays kick in.

Attachments:

logcat#1.txt

[ghost]

Update: after upgrading the Fold4 to Android 13 in early 2023, the Termux:Widget wakelock-call pauses have largely gone away. On 13, the calls still take 2-3 seconds outside of widgets as before, but now just 3-4 seconds in widgets instead of 12L's 10.

The shorter 3-4 second widget pauses are still long enough to warrant backgrounding, but this is a trivial workaround, and the pauses may be further addressed by other Termux changes noted on this thread.

So, barring new reports, this seems close worthy at this point. No idea if it was fixed in Samsung or Android code, but nondeterminism seems a norm on this platform.

[agnostic-apollo]

termux/termux-tools@5dbde2e4 may be the reason for shorter delays.

[ghost]

Thanks; this fix is clearly related. But possibly dumb question: I'm using the same versions of Termux and Termux:Widget on Android 13 as I did on 12L, and both seem to predate the fix; could this fix have influenced the results anyhow? I'm wondering if the fix will address the 2-3 second delays, but the 12L 10sec pauses was something else.

[agnostic-apollo]

The app versions don't matter. If you are using latest or fixed version of termux-tools package, then there shouldn't be a 3-4s delay if it worked, I haven't tested it myself. The 10s delay will need to be checked if something else.

[ghost]

Looks like I wasn't using the latest termux-tools. FWIW, I still get the 3-4s delays on 13 after upgrading to stable 1.35.0, though this may be unique to my install.

The 10s delays in 12L were probably something else, but this is now academic (for me, at least); my Samsung/12L testing context is no more, and backgrounding suffices.

[CtrlAltCuteness]

Unknown if related but using Termux:Tasker without the checkbox enabled to run it in the terminal for Termux apparently adds a lot more time to run the code.

Samsung Galaxy S21 5G
(Apparently adb logcat constantly spits data out, so I'd need a proper filter to assist without sending MB's worth of it)

#!/data/data/com.termux/files/usr/bin/python
import subprocess, time
started = time.time()
result = subprocess.run(
    '/data/data/com.termux/files/usr/bin/termux-battery-status',
    text=True, stdin=subprocess.DEVNULL,
    stdout=subprocess.PIPE, stderr=subprocess.STDOUT
)
finished = time.time()
print(f'Time elapsed: {finished - started} second(s)\nExit status: {result.returncode}\nOutput:\n{result.stdout}')

Note that without Termux:Tasker to start the script, (or with it but having it pop up Termux's terminal,) has it run in about 3 seconds on my system.

I could guess that the long wait is due to Termux running in the background instead of the foreground.

[agnostic-apollo]

Maybe background processes having lesser cpu priority is causing dex2oat to take longer, cause even 3s is a lot, let alone 10. You should be able to confirm if dex2oat is happening with logcat as shown above. Before i spend time looking more into this, add -Xnoimage-dex2oat to $PREFIX/bin/am as suggested at termux/termux-api#552 (comment) and see if that fixes the lag.

The termux-tools update would only fix termux-wake-* commands since they call dalvikvm directly, but it won't fix termux-battery-status, which is part of termux-api-package, since it uses $PREFIX/bin/am, which calls /system/bin/app_process, which would use dalvikvm.

The termux-tools update would not fix termux-wake-* from termux-tools package or termux-battery-status from termux-api-package package, since they use $PREFIX/bin/am, which calls /system/bin/app_process, which would internally use dalvikvm, without using the $PREFIX/bin/dalvikvm script.

https://github.com/termux/TermuxAm/blob/50f9d301811a22fc6a891b975600a21a3d152957/am-libexec-packaged#L4

https://github.com/termux/termux-api-package/blob/0fd5e3136cfed8ec2e50492d3d2c381f52f8022d/termux-api.c#L233