v3 build 823 - High Battery Consumption

[fr0stsilver]

Quote

1. Switch to PA 

2. Play song (ad: in an M3U playlist, in the main interface)

3. Go to next song

4. Pause (ad: Using the main interface, not the notification interface)

5. Switch to OS monitor (or any other app)

6. Go to 1.

Usage either increases with 25% (about 2 seconds after switching to OS monitor) or does not increase at all.

Did this about 6 times, and Poweramp is now using 95% CPU. Killing Poweramp puts it back to 0% again. I'm a developer myself and will happily cooperate if you want logs or other information.

@RBEmerson, @Moho Miner, @qwqwas1122, @krazzyvishal

Can you confirm if @dinfinity's method also applies to you guys? And everyone else upcoming please do so as well! This can be very helpful in determining the cause of the problem. Thanks. 

[Si6776]

It would be a shame if this can't get sorted out, as the way playlists work with Poweramp is one of the main reasons that I use it.

Has anyone had the same problems using Android 10?

[fr0stsilver]

12 minutes ago, Crericper said:

@RBEmerson, @Moho Miner, @qwqwas1122, @krazzyvishal

Can you confirm if @dinfinity's method also applies to you guys? And everyone else upcoming as well, please. This can be very helpful in determining the cause of the problem. Thanks! 

To determine CPU usage, you can use SystemPanel. For rooted users, it will show CPU usage for each process individually. For non-rooted users, you probably can determine system load change by using it, but it is very unresponsive and hard to see. So, I'd recommend either go for a temperature change or a battery current change, which can be monitored via lots of apps (including SystemPanel). 

[dinfinity]

1 hour ago, Crericper said:

@RBEmerson, @Moho Miner, @qwqwas1122, @krazzyvishal

Can you confirm if @dinfinity's method also applies to you guys? And everyone else upcoming as well. Please, this can be very helpful in determining the cause of the problem. Thanks! 

Good initiative. Reliable reproduction of an issue is the most important thing towards solving it!

As an addendum, I noticed that playing isn't even required to get the behavior. The updated reproduction instructions are:

1. Switch to PA, with a playlist loaded

2. Go to next song using the main interface, not the notification interface (note: actually playing a song is not required)

3. Switch to OS monitor or SystemPanel (or any other app)

4. Notice that Poweramp CPU usage increases and stays high, specifically that it maxes out a single CPU core

@maxmp: I'll gladly run a development build that outputs a lot of debug logs to logcat to help pinpoint the source of the problem.

@Crericper: Perhaps you can doublecheck whether playback isn't required for reproduction for you as well.

[andrewilley]

So that everyone isn't chasing a wild goose here, could anyone who has experienced this battery drain issue WITHOUT any playlists being involved please post here too? Thanks. 

Andre

[fr0stsilver]

Quick update: Via @dinfinity's new method, I've got the issue reproduced consistantly out of 5 times. This discovery made contribution to log quality as less instance means cleaner log. 

[maxmp]

@dinfinity what is the Poweramp build you're using and device/ROM? Poweramp 852 can play 48 hours non-stop on one battery charge on S9+ @ 9 192 kHz/24bit 50% volume on 3.5 output. No any other player on Play can do that.

PS Also for logs, if you have Developer Settings enabled in your Android, you can do Bug Report there immediately after any issue arises, then share that report via notification / gmail / gpmaxmpz@gmail.com. Thanks!

[Si6776]

35 minutes ago, maxmp said:

@dinfinity what is the Poweramp build you're using and device/ROM? Poweramp 852 can play 48 hours non-stop on one battery charge on S9+ @ 9 192 kHz/24bit 50% volume on 3.5 output. No any other player on Play can do that.

 

I've never seen Device Idle on my S9+.  Can I ask how you managed to close everything else down?

[maxmp]

@Si6776 It's just a phone laying on desk for many hours in Airplane mode.

[hypomaniac-eric]

I listened to music for all afternoon and by 4pm my phone was down to 11%.   Usually my phone is at 20% by 11pm or so during that kind of usage.   I'm really frustrated about it.   It's a Galaxy S9+ in case you didn't know.   

[fr0stsilver]

@maxmp, sorry that the developer logging wasn't functional on my phone. But you may still find this useful. Information below will be based on the log made by rs.pedjaapps.alogcatroot. 

I've reproduced the issue 3 times for logging, each time I ensure CPU goes up before continuing. 

1. Start Poweramp
2. Swipe for next song
3. Switch to SystemPanel and wait
4. Switch back to Poweramp
5. Repeat step 2-4 two more times

Then I've filtered the log with keyword "maxmp", which should only return Poweramp related instances. 

Here's a screenshot of the filtered & formatted log. I circled everything related to the suspecious "dsp_thread". I have also included a text-based log. 

Hope you find this useful, thanks! 

alogcat.2019-11-07-14-24-07+1100.txt

[fr0stsilver]

After some extra digging, found this: 

Quote

W(25788) {"eventType":3,"eventTypeName":"ConditionWait","seq":36,"pid":25788,"uid":10382,"processName":"com.maxmpz.audioplayer","packageName":"com.maxmpz.audioplayer","threadId":25788,"threadName":"main","beginTime":3210750,"endTime":3214770,"policy":0,"priority":-10,"schedGroup":0,"runningTime":0,"runnableTime":0,"sleepingTime":0,"endRealTime":0,"eventFlags":1,"monitorId":502570013224,"awakenReason":1,"stack":["java.lang.Thread.join(Thread.java:1268)","com.maxmpz.audioplayer.player.PlayerService.onDestroy","android.app.ActivityThread.handleStopService","-.-wrap26","android.app.ActivityThread$H.handleMessage","android.os.Handler.dispatchMessage","android.os.Looper.loop","android.app.ActivityThread.main","java.lang.reflect.Method.invoke","com.android.internal.os.Zygote$MethodAndArgsCaller.run","com.android.internal.os.ZygoteInit.main"]}  (MIUI-BLOCK-MONITOR)

Seems like it is waiting for a thread to stop: 

"awakenReason":1,"stack":["java.lang.Thread.join(Thread.java:1268)","com.maxmpz.audioplayer.player.PlayerService.onDestroy","android.app.ActivityThread.handleStopService"...

As: 

Quote

java.lang.Thread.join()

Joining Threads in Java. java.lang.Thread class provides the join() method which allows one thread to wait until another thread completes its execution. If t is a Thread object whose thread is currently executing, then t.join() will make sure that t is terminated before the next instruction is executed by the program.

[dinfinity]

13 hours ago, maxmp said:

@dinfinity what is the Poweramp build you're using and device/ROM? Poweramp 852 can play 48 hours non-stop on one battery charge on S9+ @ 9 192 kHz/24bit 50% volume on 3.5 output. No any other player on Play can do that.

PS Also for logs, if you have Developer Settings enabled in your Android, you can do Bug Report there immediately after any issue arises, then share that report via notification / gmail / gpmaxmpz@gmail.com. Thanks!

@maxmp: Device:

• Blackberry Priv (STV100-4)
• Android 6.0.1
• Security patch level October 5 2017 (Thanks, Blackberry)
• Kernel 3.10.84

I will submit the report later today!

[dinfinity]

4 hours ago, Crericper said:

After some extra digging, found this: 

Seems like it is waiting for a thread to stop: 

"awakenReason":1,"stack":["java.lang.Thread.join(Thread.java:1268)","com.maxmpz.audioplayer.player.PlayerService.onDestroy","android.app.ActivityThread.handleStopService"...

As: 

Nice work! com.maxmpz.audioplayer.player.PlayerService.onDestroy would be the significant bit here. The application generating the log seems to be a MIUI monitor app, but it still gives valuable information about PA.

Looking at "beginTime":3210750," and endTime":3214770",  it seems that the MIUI monitor gives off a warning because the onDestroy method is taking more than 4 seconds. This is probably because something in that onDestroy method is stuck in an infinite loop as hypothesized before.

[fr0stsilver]

Ah, forgot to post my device & info. In case if you need @maxmp. 

Model: Xiaomi MI 6
Android: 8.0.0
ROM: MIUI 10 9.3.21 Beta
Security patch level: 2019-04-05
Kernel: 4.4.78-perf-ge57b3e5

CPU: Snapdragon 835 8-Core @ 2.45GHz
RAM: 6.00GB
Avaliable Storage: 9.37GB

Poweramp version: v3-build-852-arm64-play
SHA-1: 3dfe11e642d0cdc8cb2941198f732ca2007e93e3
Unlocker version: 3-build-301
SHA-1: e9e324843197257366074a3027eda6ed3adf5f25

@dinfinity, I believe that's the case as well! That instance have also appeared in the first log I've posted. (Notice there's the orange chunk below.)

Here quotes: 

On 11/1/2019 at 10:12 PM, Crericper said:

I've reproduced the bug twice and logged it with LogcatX. Inside this screenshot, the selected 3 lines seems suspicious. 

Log_2019-11-01_22-09-24.zip 33.89 kB · 1 download

 

[RBEmerson]

21 hours ago, andrewilley said:

So that everyone isn't chasing a wild goose here, could anyone who has experienced this battery drain issue WITHOUT any playlists being involved please post here too? Thanks. 

Andre

I think you're saying to just start playing songs without queuing or playlists. For example, pick the first file in a artist collection? Or start from the first file in a folder? 

[andrewilley]

3 minutes ago, RBEmerson said:

I think you're saying to just start playing songs without queuing or playlists. For example, pick the first file in a artist collection? Or start from the first file in a folder? 

Yes, I wanted to check if anyone still experiences this battery drain issue in normal (album for example) playback rather than in playlists. It might help to know.

Andre

[WiGgLr]

It's possible that is what made the issue intermittent for me, I mix up both methods of playing music. I couldn't tell you the correlation between having the issue and the method to play music though, as I've downgraded to a version where I don't have an issue and stuck with that.

[maxmp]

Thanks for the logs, unfortunately nothing suspicious there. dsp_thread is the main thread doing music processing in Poweramp. It does nothing when music is not playing and from your logs it’s properly shutting down. Poweramp gives max 4000ms for player service (and thus dsp_thread and all other threads) to shutdown, in your case it maxes this timeout, most probably, due to android audiosystem (audiotrack) not releasing (that can take up to 10seconds in some cases). Unfortunately we can’t wait more as Android gives us max 5 second to shutdown without ANR.

[fr0stsilver]

1. Switch to PA, with a playlist loaded
2. Go to next song using the main interface, not the notification interface (note: actually playing a song is not required)
3. Switch to OS monitor or SystemPanel (or any other app)
4. Notice that Poweramp CPU usage increases and stays high, specifically that it maxes out a single CPU core

@maxmp, have you got the bug successfully reproduced on your end? Or is that the case where the bug only applies to only me and @dinfinity? 

[dinfinity]

On 11/6/2019 at 9:20 PM, maxmp said:

@dinfinity what is the Poweramp build you're using and device/ROM?

@maxmp: Forgot to post this info.

v3-build-852-arm64-play [852004-ce3a07c4]

Full Version

64 bit

[fr0stsilver]

This is the log for pa launched at 'Folder'. I logged this with the same steps performed as before. But this time pa did not wait for any kind of weird thread. 

alogcat.2019-11-08-07-41-10+1100.txt

[dinfinity]

On 11/6/2019 at 9:20 PM, maxmp said:

@dinfinity [...]

PS Also for logs, if you have Developer Settings enabled in your Android, you can do Bug Report there immediately after any issue arises, then share that report via notification / gmail / gpmaxmpz@gmail.com. Thanks!

@maxmp: Sent you the bug report. I suspect this is the culprit:

"player service thread" prio=5 tid=9 Suspended
  | group="main" sCount=1 dsCount=0 obj=0x12c07340 self=0x7f78b8fc00
  | sysTid=21390 nice=0 cgrp=bg_non_interactive sched=0/0 handle=0x7f7618d3a0
  | state=S schedstat=( 0 0 0 ) utm=3765 stm=66 core=5 HZ=100
  | stack=0x7f7608b000-0x7f7608d000 stackSize=1036KB
  | held mutexes=
  at ׅ.tg$D.D(":702)
  at ׅ.tg$D.ׅ(":696)
  at ׅ.tg$L.ׅ(":759)
  at ׅ.tg.ׅ(":645)
  at ׅ.px.release(":5034)
  at com.maxmpz.audioplayer.player.PlayerService.llll(":3093)
  - locked <0x014f9035> (a java.lang.Object)
  at com.maxmpz.audioplayer.player.PlayerService$v0.ׅ(":1145)
  at ׅ.pz.handleMessage(":29)
  at android.os.Handler.dispatchMessage(Handler.java:102)
  at android.os.Looper.loop(Looper.java:148)
  at android.os.HandlerThread.run(HandlerThread.java:61)

(utm is high and this seems to be the only thread that is not waiting/native waiting)

[hypomaniac-eric]

My battery issue seems to happen no matter what screen I'm on so far.    I usally keep in on the Main? Screen (playback) as in the one with the big album cover and buttons.   Is that the main screen?  Many times I don't even look at the screen as i turn on the bluetooth headphones connect and it starts playing and I"m doing yardwork or projects.   

[maxmp]

@dinfinity thanks for the log, it was helpful. Yes, in this use scenario the thread loops forever, fixed for the next build which will be pushed asap.