ForegroundServiceStartNotAllowedException stopping playback

[joashrajin]

We have many reports from Android 12 users claiming that the app crashes or the audio quality deteriorates with playback while the screen is off.

Here are the logs from 1 customer:

E 17/3 22:25:04 Playback service error
android.app.ForegroundServiceStartNotAllowedException: Service.startForeground() not allowed due to mAllowStartForeground false: service au.com.shiftyjelly.pocketcasts/.core.player.PlaybackService
	at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel(ForegroundServiceStartNotAllowedException.java:54)
	at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel(ForegroundServiceStartNotAllowedException.java:50)
	at android.os.Parcel.readParcelable(Parcel.java:3333)
	at android.os.Parcel.createExceptionOrNull(Parcel.java:2420)
	at android.os.Parcel.createException(Parcel.java:2409)
	at android.os.Parcel.readException(Parcel.java:2392)
	at android.os.Parcel.readException(Parcel.java:2334)
	at android.app.IActivityManager$Stub$Proxy.setServiceForeground(IActivityManager.java:7096)
	at android.app.Service.startForeground(Service.java:733)
	at au.com.shiftyjelly.pocketcasts.core.player.PlaybackService$MediaControllerCallback.onPlaybackStateChangedWithNotification(PlaybackService.kt:10)
	at au.com.shiftyjelly.pocketcasts.core.player.PlaybackService$MediaControllerCallback.access$onPlaybackStateChangedWithNotification(PlaybackService.kt:1)
	at au.com.shiftyjelly.pocketcasts.core.player.PlaybackService$MediaControllerCallback$4.invoke(PlaybackService.kt:3)
	at au.com.shiftyjelly.pocketcasts.core.player.PlaybackService$MediaControllerCallback$4.invoke(PlaybackService.kt:1)
	at ek.l.b(Unknown Source:2)
	at pj.r.onNext(LambdaObserver.java:2)
	at uj.c2$a.d(ObservableObserveOn.java:8)
	at uj.c2$a.run(ObservableObserveOn.java:3)
	at ij.b$b.run(HandlerScheduler.java:1)
	at android.os.Handler.handleCallback(Handler.java:938)
	at android.os.Handler.dispatchMessage(Handler.java:99)
	at android.os.Looper.loopOnce(Looper.java:201)
	at android.os.Looper.loop(Looper.java:288)
	at android.app.ActivityThread.main(ActivityThread.java:7839)
	at java.lang.reflect.Method.invoke(Native Method)
	at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
	at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1003)
Caused by: android.os.RemoteException: Remote stack trace:
	at com.android.server.am.ActiveServices.setServiceForegroundInnerLocked(ActiveServices.java:1837)
	at com.android.server.am.ActiveServices.setServiceForegroundLocked(ActiveServices.java:1350)
	at com.android.server.am.ActivityManagerService.setServiceForeground(ActivityManagerService.java:11903)
	at android.app.IActivityManager$Stub.onTransact(IActivityManager.java:3205)
	at com.android.server.am.ActivityManagerService.onTransact(ActivityManagerService.java:2498)

ApplicationExitInfo(timestamp=18/03/22, 9:35 pm pid=19707 realUid=10237 packageUid=10237 definingUid=10237 user=0 process=au.com.shiftyjelly.pocketcasts reason=9 (EXCESSIVE RESOURCE USAGE) subreason=7 (EXCESSIVE CPU USAGE) status=0 importance=400 pss=158MB rss=175MB description=excessive cpu 22790 during 300121 dur=1781131 limit=2 state=empty trace=null

Device info:

App version : 7.19.2 (7566)
Sync account: [email protected]
Last Sync: 2022-03-18T10:34:59.987Z
Time: 2022-03-18 23:35:09 Local
      2022-03-18 10:35:09 Utc
Background refresh: true

Phone: Google - oriole - Pixel 6 - oriole
Kernel: 5.10.43-android12-9-00007-g9771767708df-ab8009062 - abfarm-release-rbe-64-00086
Android version: 12 SDK 31
Phone ID: 929e6fab-74fe-4a75-8b4d-2fa40c562bf9

#4871871-zen #4885182-zen

Both reported that setting the battery optimization to unrestricted for Pocket Casts resolved it. There have been users, however, who have reported that updating the battery optimization setting has not fixed the issue.

[joashrajin]

+1 at #5338118-zen

[mchowning]

Noting that we have added some changes to 7.20 to prompt users to update their battery optimization setting to unrestricted since that seems to fix the issue for the majority of users. We are also working with Google to address this issue since there appears to be a problem with Android 12.

Some relevant issues from the Google issue tracker:

• https://issuetracker.google.com/issues/229000935
• https://issuetracker.google.com/issues/206864385

A variation of this issue (that can be reproduced in our app) occurs in Google's sample uamp app: https://github.com/android/uamp/issues/485

[mchowning]

This issue reported on the Google issue tracker sounds pretty similar, and Google has a fix they plan to release by the end of August 2022. 🤞

[joashrajin]

+1 at #5408739-zen

[joashrajin]

+1 at #5402329-zen

I've gone back to using a flip case with my Galaxy S22 Ultra, and when the case is closed, Pocket Cast stops playback after a short time. My other apps don't shut down when the case is closed, and I haven't found an Android or Pocket Cast setting that seems applicable.

Logs mention the ForegroundServiceStartNotAllowedException crash occurring. The user confirmed that setting the Battery Usage to 'Unrestricted' fixed the problem.

[joashrajin]

+2 in https://a8c.slack.com/archives/C0294NQ5ZL4/p1658535513642639 + https://a8c.slack.com/archives/C0294NQ5ZL4/p1658967355988439

[mchowning]

There is a cast sdk fix for this kind of issue. I'm a bit skeptical that this will fix all the issues we're seeing, but it might (other people report avoiding that issue by catching the exception, but that doesn't help us much because we still need the service to enter the foreground). Unfortunately, the fix apparently won't be released until the end of Q4 2022.

[joashrajin]

5728303-zd-woothemes

What I'm saying is that it's a bit inconsistent that Pocket Cast can correctly move items to listen history, mark as archived etc, but can't delete. For that I'd suggest having a periodically running check that would go over downloaded, not started, but already archived items and delete these when Pocket Cast is in foreground [...]

The user here is facing the issue where Pocket Casts is using 'Optimized' battery usage and failing to auto-archive/delete episodes when they are casted. The issue seems to be related to the Chromecast bug but since they are a power user, using 'Unrestricted' battery usage causes the battery to die a bit quicker:

I'm getting about 8-10h of Pocket Cast on an optimised battery (heavy user, silence trimming, speed multiplier, hundreds of podcasts syncing, downloading over WiFi or 5G) vs. 4-6h when I give it unlimited battery

[ashiagr]

FYI

Latest Cast SDK (21.2.0) includes this release note:

Fixed ForegroundServiceStartNotAllowedException with the MediaNotificationService.

The SDK version is updated in v7.28 in this PR. Hopefully, we'll stop seeing this issue while casting. 🤞

[mchowning]

Thanks for sharing that @ashiagr ! Checking the crash reports it looks like the exception is still getting thrown in 7.28-rc-2. It' still early though, so maybe once that version is fully released we'll see that this crash is much less frequent. 🤞

[ashiagr]

That PR is still in review 😀. It should get merged in the final 7.28 release.

[mchowning]

🤦 I looked at the wrong PR! Sorry about that.