1

Tasker monitor unnecessarily wakes phone up every single minute if there are any time contexts

If I have any time contexts (eg. instant context that runs at 09:00, or a time context that repeats every hour), the tasker monitor wakes up every single minute.  Nothing appears in the run log for this obviously, however you can see it in Battery historian and in the tasker debug log.  Disabling all time contexts stops this from happening.  Enabling a single simple time context causes the activity.  The problem occurs no matter if "Use Reliable Alarms" is enabled or not.

Debug log:

15-05-2020 ReceiverStaticInternal: 10.49.00#m#ReceiverStaticInternal: r: net.dinglisch.android.tasker.ALARUM
15-05-2020 WakeLockManager: 10.49.00#b#WakeLockManager: acquired partial lock for M flags: 1 autorelease: true warn: true
15-05-2020 WakeLockManager: 10.49.00.487#b#WakeLockManager: cancel clear alarm, lastSetTime 0
15-05-2020 WakeLockManager: 10.49.00.488#b#WakeLockManager: cancelled clear alarm
15-05-2020 AlarmChanged: 10.49.00#m#AlarmChanged: System reported alarm changed
15-05-2020 M: 10.49.00.557#m#M: handleStart: finished handling ID 6
15-05-2020 WakeLockManager: 10.49.00#m#WakeLockManager: release: M
15-05-2020 M: 10.49.00.558#b#M: process inbox, size 1 startID: 6 ecode 9998
15-05-2020 : 10.49.00#b#:  eventType / 9998 (java.lang.Integer)
15-05-2020 WakeLockManager: 10.49.00.559#m#WakeLockManager: cancel clear alarm, lastSetTime 1589503740544
15-05-2020 WakeLockManager: 10.49.00.566#m#WakeLockManager: cancelled clear alarm
15-05-2020 M: 10.49.00#b#M: handle time alarm: alarm
15-05-2020 M: 10.49.00#b#M: check instant activation id: 38: not active
15-05-2020 TaskerContext: 10.49.00#b#TaskerContext: hourly repeat now 10.49 start 8.0 end 21.0 repeatVal 1 matchMin 0
15-05-2020 M: 10.49.00#b#M: check instant activation id: 24: not active
15-05-2020 M: 10.49.00#b#M: check instant activation id: 57: not active
15-05-2020 M: 10.49.00#b#M: check instant activation id: 46: not active
15-05-2020 M: 10.49.00#b#M: handleProfileChanges (timeAlarm)
15-05-2020 M: 10.49.00.568#b#M: checkMatchStates: handleChanges: true handle:  Profile Active
15-05-2020 M: 10.49.00#b#M: null, get default name: cust_notification
15-05-2020 M: 10.49.00#b#M: handle monitor changes (timeAlarm:handleProfileChanges)
15-05-2020 M: 10.49.00#b#M: update flags (timeAlarm:handleProfileChanges:handleMonitorChanges): handlerProfiles
15-05-2020 M: 10.49.00#b#M: clear flags (timeAlarm:handleProfileChanges:handleMonitorChanges:updateFlags): handlerProfiles
15-05-2020 M: 10.49.00#b#M: enableDisable updateFlags/timeAlarm:handleProfileChanges:handleMonitorChanges: needed monitors: TIME ACCESS SMS 
15-05-2020 M: 10.49.00#b#M: needed flags:
15-05-2020 M: 10.49.00#b#M: needed pstate-types: 0 access-types: 64
15-05-2020 M: 10.49.00#b#M: cancel cooldown alarm
15-05-2020 M: 10.49.00#b#M: set cooldown alarm for 3139170ms
15-05-2020 M: 10.49.00#b#M: AC refresh cooldown alarm: set
15-05-2020 TaskerContext: 10.49.00#b#TaskerContext: AC setAlarmWrapper/AC: M/cooldown/set: 11.41.19 want: true
15-05-2020 AlarmChanged: 10.49.00#m#AlarmChanged: System reported alarm changed
15-05-2020 M: 10.49.00#b#M: user present: false
15-05-2020 M: 10.49.00#b#M: need user-absent alarm to refresh time alarm
15-05-2020 M: 10.49.00#b#M: startUAAA: need alarm: true
15-05-2020 M: 10.49.00#b#M: wantMotionDetect: true have: true
15-05-2020 M: 10.49.00#b#M: start SM listener
15-05-2020 MTEL: 10.49.00#b#MTEL: cancel: have listener: true have manager: true
15-05-2020 MTEL: 10.49.00#b#MTEL: cancelled
15-05-2020 MTEL: 10.49.00#b#MTEL: requested trigger sensor
15-05-2020 AlarmChanged: 10.49.00#m#AlarmChanged: System reported alarm changed
15-05-2020 M: 10.49.00#b#M: handleProfileChanges: done
15-05-2020 M: 10.49.00#m#M: TIME: handleTimeAlarm: monitor resumption
15-05-2020 M: 10.49.00#m#M: AC cancel time alarm
15-05-2020 M: 10.49.00#m#M: set next time: 10.50.00 15-5-20
15-05-2020 M: 10.49.00#m#M: refresh next time: 10.50
15-05-2020 TaskerContext: 10.49.00#m#TaskerContext: AC setAlarmWrapper/AC: M/refreshTime/setTimeAlarm: 10.50.00 want: true
15-05-2020 AlarmChanged: 10.49.00#m#AlarmChanged: System reported alarm changed
15-05-2020 NLI: 10.49.00#m#NLI: tickerText: 
15-05-2020 NSI: 10.49.00#m#NSI: sendNewNotification: ignore Tasker notification
15-05-2020 ReceiverStaticInternal: 10.50.00#m#ReceiverStaticInternal: r: net.dinglisch.android.tasker.ALARUM
15-05-2020 WakeLockManager: 10.50.00#b#WakeLockManager: acquired partial lock for M flags: 1 autorelease: true warn: true
15-05-2020 WakeLockManager: 10.50.00.408#b#WakeLockManager: cancel clear alarm, lastSetTime 0
15-05-2020 WakeLockManager: 10.50.00.411#b#WakeLockManager: cancelled clear alarm
15-05-2020 AlarmChanged: 10.50.00#m#AlarmChanged: System reported alarm changed
15-05-2020 M: 10.50.00.449#m#M: handleStart: finished handling ID 7
15-05-2020 WakeLockManager: 10.50.00#m#WakeLockManager: release: M
15-05-2020 M: 10.50.00.449#b#M: process inbox, size 1 startID: 7 ecode 9998
15-05-2020 : 10.50.00#b#:  eventType / 9998 (java.lang.Integer)
15-05-2020 WakeLockManager: 10.50.00.453#m#WakeLockManager: cancel clear alarm, lastSetTime 1589503800446
15-05-2020 WakeLockManager: 10.50.00.462#m#WakeLockManager: cancelled clear alarm
15-05-2020 M: 10.50.00#b#M: handle time alarm: alarm
15-05-2020 M: 10.50.00#b#M: check instant activation id: 38: not active
15-05-2020 TaskerContext: 10.50.00#b#TaskerContext: hourly repeat now 10.50 start 8.0 end 21.0 repeatVal 1 matchMin 0
15-05-2020 M: 10.50.00#b#M: check instant activation id: 24: not active
<etc>
Battery android log:
     +5h23m21s960ms (2) 061 c0000000 charge=1725 +running +wake_lock=u0a104:"M" -wifi_radio wake_reason=0:"53:qcom,glink-smem-native-xprt-rpm:91:7781b8.qcom,mpm"
       +5h23m22s008ms (2) 061 80000000 -wake_lock stats=0:"wifi-data: inactive"
       +5h23m22s074ms (2) 061 c0000000 +wake_lock=u0a16:"NlpWakeLock"
       +5h23m22s076ms (1) 061 00000000 -running -wake_lock
       
       +5h24m21s901ms (2) 061 c0000000 +running +wake_lock=u0a104:"M"
       +5h24m21s923ms (1) 061 80000000 -wake_lock
       +5h24m21s923ms (2) 061 c0000000 +wake_lock=1000:"*alarm*:lock_screen_next_alarm" wake_reason=0:"53:qcom,glink-smem-native-xprt-rpm:91:7781b8.qcom,mpm"
       +5h24m21s938ms (1) 061 80000000 -wake_lock
       +5h24m21s959ms (2) 061 c0000000 +wake_lock=u0a16:"NlpWakeLock"
       +5h24m21s961ms (1) 061 80000000 -wake_lock
       +5h24m23s026ms (3) 061 00000000 -running wake_reason=0:"Abort:Pending Wakeup Sources: [timerfd] " -tmpwhitelist=u0a16:"broadcast:u0a16:com.google.android.gms.gcm.HEARTBEAT_ALARM"
       
       +5h25m21s948ms (2) 061 c0000000 +running +wake_lock=u0a104:"M" wake_reason=0:"53:qcom,glink-smem-native-xprt-rpm:91:7781b8.qcom,mpm"
       +5h25m21s993ms (1) 061 80000000 -wake_lock
       +5h25m22s067ms (2) 061 c0000000 +wake_lock=u0a16:"NlpWakeLock"
       +5h25m22s069ms (1) 061 00000000 -running -wake_lock
Version Info:
Tasker Version: 5.9.2
Phone: Oneplus 5 
OS: OxygenOS 9.0.11 (Android 9).  Not rooted.
 
Follow

6 replies

Votes Newest Oldest

Hi. Just to confirm, this has always been like this, right? Or are you a new Tasker user?

Comment
B

Happily using tasker for many years :)  It hasn't always been this way but I'm not sure exactly when it started.  Its been 6 months+ since I last looked at a battery historian graph, and I don't think it was happening back then.

I found a two of my old android bugreports that notepad++ had messily left behind, and ran them back through battery historian - it definitely wasn't happening in 2017-11-05, or 2019-05-02 (my tasker version would have been whatever was up to date in the play store at the time).  Same phone in each case, although the OS would have been patched in line with usual oneplus patches.

Thanks.

Comment

Thank you :) I never touched the code that manages wakelocks so it must be something else that's causing the changes... Are you by any chance able to use older versions of Tasker to check if it has the same issue for you? Just to help narrow down what the issue could be... Thanks in advance! Also, maybe it's easier to communicate via email to get this fixed sooner. Could you please do that?

LF

I might be completely wrong, but doesn't this line means you have a profile that repeats every minute?

10.49 start 8.0 end 21.0 repeatVal 1 matchMin 0

Comment
B

Lucas: No that's 1 hour :)

Joao: I'm working on it.  I'll send you an email when I figure this out.  I've had some weird results, but now I think it is related to a combination of 2 things, one of which is a profile that runs every 2 minutes, but is disabled apart from when I go for a bike ride on Saturdays ... and I can't figure out what the other thing is :)  However I did change this profile recently, so whatever the root issue is, its probably been in tasker forever.

Comment
B

I wasn't sure which email address you meant for me to use?  I used support at jaoapps.com.  Let me know if that is ok.  Thanks.

Comment
B
Summary of what I emailed to João after further investigating what was going on:
 
The problem
The tasker monitor sets an alarm to wakeup for disabled profiles with time contexts as if they were enabled.  There's a chance this isn't isolated to time context (more info further below).
 
Note if you are testing with an otherwise empty config, you need at least one other profile with a time context that is enabled otherwise the problem is hidden.
 
Expected behaviour
My expected behaviour is the monitor should not set alarms to wakeup for time contexts of disabled profiles - especially repeating ones.
 
Gory bit...
I had a disabled profile with a 2 minute repeating time context.  Tasker seems to wakeup 1 minute after the last wakeup, before sleeping and waiting for the next user-absent alarm.  For example, with a repeating 5 minute context, tasker will go into sleep/wakeup cycles of 1 minute, 4 minutes, 1 minute, 4 minutes etc.  In my case as my disabled profile had a 2 minute repeat, this led to a wakeup every single minute.  
 
Debug log example showing cycle mentioned above (this isn't a problem, just showing evidence of the above)
For this, I had deleted my repeating time profiles apart from one that repeats every 60 minutes, and set display off all checks to 60 minutes as well.
 
At 01:00 even though it knows the next userabsentrefresh is at 02:00, it sets an alarm to go off in 1 minute: 

25-05-2020 M: 01.00.00#b#M: need user-absent alarm to refresh time alarm
25-05-2020 M: 01.00.00#b#M: startUAAA: need alarm: true
25-05-2020 M: 01.00.00#b#M: not listening SM, set alarm for 3600000
25-05-2020 M: 01.00.00#b#M: startUserAbsentAlarm: L or greater, no repeating
25-05-2020 M: 01.00.00#b#M: start user-absent updates: 3600 secs, repeating: false
25-05-2020 TaskerContext: 01.00.00#b#TaskerContext: AC setAlarmWrapper/SEI: M/userAbsentRefresh: 02.00.00 want: false
25-05-2020 M: 01.00.00#b#M: handleProfileChanges: done
25-05-2020 M: 01.00.00#m#M: TIME: handleTimeAlarm: monitor resumption
25-05-2020 M: 01.00.00#m#M: AC cancel time alarm
25-05-2020 M: 01.00.00#m#M: set next time: 01.01.00 25-5-20
25-05-2020 M: 01.00.00#m#M: refresh next time: 01.01
25-05-2020 TaskerContext: 01.00.00#m#TaskerContext: AC setAlarmWrapper/SEI: M/refreshTime/setTimeAlarm: 01.01.00 want: false
25-05-2020 NLI: 01.00.00#m#NLI: tickerText:
25-05-2020 NSI: 01.00.00#m#NSI: sendNewNotification: ignore Tasker notification

At 01:01 it wakes up, does nothing much, then goes back to sleep until 02:00
<wakeup bit snipped>
25-05-2020 M: 01.01.00#b#M: don't start user-absent updates alarm / SM listener, alarm already set
25-05-2020 M: 01.01.00#b#M: handleProfileChanges: done
25-05-2020 M: 01.01.00#m#M: TIME: handleTimeAlarm: monitor resumption
25-05-2020 M: 01.01.00#m#M: AC cancel time alarm
25-05-2020 M: 01.01.00#m#M: set next time: 02.00.00 25-5-20
25-05-2020 M: 01.01.00#m#M: refresh next time: 02.00
25-05-2020 TaskerContext: 01.01.00#m#TaskerContext: AC setAlarmWrapper/SEI: M/refreshTime/setTimeAlarm: 02.00.00 want: false
25-05-2020 NLI: 01.01.00#m#NLI: tickerText:
25-05-2020 NSI: 01.01.00#m#NSI: sendNewNotification: ignore Tasker notification

<actually wakes up at 02:00:00>

 
Might not just be for time contexts
The problem might (?) not be just for time contexts - I have always noticed that the tasker monitor registers a receiver for android.intent.action.BATTERY_CHANGED for a "Battery Changed" context - even when the profile containing that context is consistently disabled.  This means tasker is being woken up every time the battery temp changes by 0.1 degree or whatever, even though its for a disabled profile.  So through the night tasker also keeps getting woken up as the temperature cools - for a profile that is disabled.  This one doesn't bother me much but it might hint at the root of the issue.  Relevent debug log entry:
 
25-05-2020 M: 08.56.54#b#M: register receiver action: android.intent.action.BATTERY_CHANGED
25-05-2020 ReceiverDynamic: 08.56.54#b#ReceiverDynamic: onReceive: pID: 6 action: android.intent.action.BATTERY_CHANGED
 
 
 
Comment
Reply