react-native-track-player icon indicating copy to clipboard operation
react-native-track-player copied to clipboard

[bug] android.app.ForegroundServiceStartNotAllowedException: startAndStopEmptyNotificationToAvoidANR

Open elliotdickison opened this issue 2 years ago • 17 comments

Describe the Bug

We recently released 3.2.0-b13a92208eaf9607a12cfa7596dfa6ae4f4a4c8e into production to take advantage of some of the updated Android foreground service logic (thank you!). We saw the long-time android.app.ForegroundServiceStartNotAllowedException bug disappear completely (woohoo!) but this one started popping up at about the same frequency. The issue only occurs in the background. This seems closely related to #1986, but per the discussion on that issue I'm opening a new issue.

Exception java.lang.RuntimeException:
  at android.app.ActivityThread.handleServiceArgs (ActivityThread.java:4839)
  at android.app.ActivityThread.-$$Nest$mhandleServiceArgs
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:2289)
  at android.os.Handler.dispatchMessage (Handler.java:106)
  at android.os.Looper.loopOnce (Looper.java:205)
  at android.os.Looper.loop (Looper.java:294)
  at android.app.ActivityThread.main (ActivityThread.java:8177)
  at java.lang.reflect.Method.invoke
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:552)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:971)
Caused by android.app.ForegroundServiceStartNotAllowedException: Service.startForeground() not allowed due to mAllowStartForeground false: service com.maz.combo3310/com.doublesymmetry.trackplayer.service.MusicService
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:54)
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:50)
  at android.os.Parcel.readParcelableInternal (Parcel.java:4870)
  at android.os.Parcel.readParcelable (Parcel.java:4852)
  at android.os.Parcel.createExceptionOrNull (Parcel.java:3052)
  at android.os.Parcel.createException (Parcel.java:3041)
  at android.os.Parcel.readException (Parcel.java:3024)
  at android.os.Parcel.readException (Parcel.java:2966)
  at android.app.IActivityManager$Stub$Proxy.setServiceForeground (IActivityManager.java:6761)
  at android.app.Service.startForeground (Service.java:775)
  at com.doublesymmetry.trackplayer.service.MusicService.startAndStopEmptyNotificationToAvoidANR (MusicService.kt:125)
  at com.doublesymmetry.trackplayer.service.MusicService.onStartCommand (MusicService.kt:98)
  at android.app.ActivityThread.handleServiceArgs (ActivityThread.java:4821)

Steps To Reproduce

We have yet to reproduce locally on our devices. We have tried forcing the device into doze mode, loading new tracks in the background, playing for extended periods of time, etc. The issue is happening with regular frequency in production with an install base of ~6K

  • Occurring on SDK 33 & 34
  • Only occurs in background
  • Disproportionately occurs on Google Pixel phones (oriole, bluejay, raven, panther). Only ~21% of our install base are using Google devices but ~94% of crashes are on Pixels. Not sure if that's a red herring or not.

Code To Reproduce

Use 3.2.0-b13a92208eaf9607a12cfa7596dfa6ae4f4a4c8e

Replicable on Example App?

We have yet to reproduce the issue even in our app, once we do we'll check the example app.

Environment Info:

react-native-track-player@3.2.0-b13a92208eaf9607a12cfa7596dfa6ae4f4a4c8e

System:
  OS: macOS 13.5.1
  CPU: (8) arm64 Apple M1
  Memory: 249.86 MB / 16.00 GB
  Shell:
    version: "5.9"
    path: /bin/zsh
Binaries:
  Node:
    version: 16.15.0
    path: /private/var/folders/q_/y7w5vfj90n76sww7tczt1yqw0000gn/T/xfs-ba6db6e6/node
  Yarn:
    version: 3.2.1
    path: /private/var/folders/q_/y7w5vfj90n76sww7tczt1yqw0000gn/T/xfs-ba6db6e6/yarn
  npm:
    version: 8.5.5
    path: ~/.asdf/plugins/nodejs/shims/npm
  Watchman:
    version: 2023.07.10.00
    path: /opt/homebrew/bin/watchman
Managers:
  CocoaPods:
    version: 1.12.1
    path: /Users/elliot/.asdf/shims/pod
SDKs:
  iOS SDK:
    Platforms:
      - DriverKit 22.1
      - iOS 16.1
      - macOS 13.0
      - tvOS 16.1
      - watchOS 9.1
  Android SDK:
    API Levels:
      - "28"
      - "31"
      - "33"
    Build Tools:
      - 28.0.3
      - 29.0.2
      - 30.0.2
      - 30.0.3
      - 31.0.0
      - 33.0.0
    System Images:
      - android-31 | ARM 64 v8a
      - android-S | Google APIs ARM 64 v8a
      - android-S | Google Play ARM 64 v8a
    Android NDK: Not Found
IDEs:
  Android Studio: 2021.1 AI-211.7628.21.2111.8193401
  Xcode:
    version: 14.1/14B47b
    path: /usr/bin/xcodebuild
Languages:
  Java:
    version: 11.0.11
    path: /usr/bin/javac
  Ruby:
    version: 3.1.3
    path: /Users/elliot/.asdf/shims/ruby
npmPackages:
  "@react-native-community/cli": Not Found
  react: Not Found
  react-native: Not Found
  react-native-macos: Not Found
npmGlobalPackages:
  "*react-native*": Not Found
Android:
  hermesEnabled: yes
  newArchEnabled: no
iOS:
  hermesEnabled: yes
  newArchEnabled: no

How I can Help What can you do to help resolve this? Have you investigated the underlying JS or Swift/Android code causing this bug? Can you create a Pull Request with a fix?

elliotdickison avatar Oct 23 '23 23:10 elliotdickison

It seems to me that Android 14 is making this issue worse. I was seeing this error but way less than the previous one, but it seems that this new one is increasing after Android 14.

we're currently with RC08 in production and we hope to release a new version of our app until the end of this week with final version 4 of the library image image

marcvictorpassarelli avatar Oct 24 '23 13:10 marcvictorpassarelli

we have the same problem on android 14. :(

AlkanV avatar Oct 24 '23 19:10 AlkanV

seems very similar to the flutter folks experiencing, related to battery optimization https://github.com/ryanheise/audio_service/issues/994

lovegaoshi avatar Oct 25 '23 16:10 lovegaoshi

Hi everyone, just wanted to kindly ask you if you made any progress on this issue, thanks in advance.

agora-andrea avatar Nov 08 '23 22:11 agora-andrea

I’m seeing the exact same crash reports while using version 4.0.1

bkostjens avatar Nov 14 '23 21:11 bkostjens

Also happening on prod using > "react-native-track-player": "^3.2.0-7b02a2d2a51370819b91ea8da1fe835a617c3199",

Caused by java.lang.SecurityException: Starting FGS with type mediaPlayback  targetSDK=34 requires permissions: all of the permissions allOf=true [android.permission.FOREGROUND_SERVICE_MEDIA_PLAYBACK] 
       at android.os.Parcel.createExceptionOrNull(Parcel.java:3057)
       at android.os.Parcel.createException(Parcel.java:3041)
       at android.os.Parcel.readException(Parcel.java:3024)
       at android.os.Parcel.readException(Parcel.java:2966)
       at android.app.IActivityManager$Stub$Proxy.setServiceForeground(IActivityManager.java:6761)
       at android.app.Service.startForeground(Service.java:775)
       at com.doublesymmetry.trackplayer.service.MusicService.startAndStopEmptyNotificationToAvoidANR(MusicService.kt:115)
       at com.doublesymmetry.trackplayer.service.MusicService.onStartCommand(MusicService.kt:92)
       at android.app.ActivityThread.handleServiceArgs(ActivityThread.java:4821)
       at android.app.ActivityThread.-$$Nest$mhandleServiceArgs()
       at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2289)
       at android.os.Handler.dispatchMessage(Handler.java:106)
       at android.os.Looper.loopOnce(Looper.java:205)
       at android.os.Looper.loop(Looper.java:294)
       at android.app.ActivityThread.main(ActivityThread.java:8177)
       at java.lang.reflect.Method.invoke(Method.java)
       at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:552)
       at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:971)

daviluisb avatar Nov 16 '23 19:11 daviluisb

track-player 4.0.1 - [ google husky (Pixel 8 Pro) ] - [ Android 14 (SDK 34) ]

Exception java.lang.RuntimeException:
  at android.app.ActivityThread.handleServiceArgs (ActivityThread.java:5261)
  at android.app.ActivityThread.-$$Nest$mhandleServiceArgs
  at android.app.ActivityThread$H.handleMessage (ActivityThread.java:2447)
  at android.os.Handler.dispatchMessage (Handler.java:106)
  at android.os.Looper.loopOnce (Looper.java:226)
  at android.os.Looper.loop (Looper.java:313)
  at android.app.ActivityThread.main (ActivityThread.java:8762)
  at java.lang.reflect.Method.invoke
  at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:604)
  at com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1067)
Caused by android.app.ForegroundServiceStartNotAllowedException:
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:54)
  at android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel (ForegroundServiceStartNotAllowedException.java:50)
  at android.os.Parcel.readParcelableInternal (Parcel.java:4787)
  at android.os.Parcel.readParcelable (Parcel.java:4755)
  at android.os.Parcel.createExceptionOrNull (Parcel.java:3018)
  at android.os.Parcel.createException (Parcel.java:3007)
  at android.os.Parcel.readException (Parcel.java:2990)
  at android.os.Parcel.readException (Parcel.java:2932)
  at android.app.IActivityManager$Stub$Proxy.setServiceForeground (IActivityManager.java:6991)
  at android.app.Service.startForeground (Service.java:743)
  at com.doublesymmetry.trackplayer.service.MusicService.startAndStopEmptyNotificationToAvoidANR (MusicService.kt:123)
  at com.doublesymmetry.trackplayer.service.MusicService.onStartCommand (MusicService.kt:98)
  at android.app.ActivityThread.handleServiceArgs (ActivityThread.java:5243)

Involved Devices: image

bkostjens avatar Nov 17 '23 08:11 bkostjens

Just got same on Pixel 7 on Android 14

kesha-antonov avatar Dec 17 '23 10:12 kesha-antonov

Also seeing this with v4.0.1 — any thoughts on cause, workaround?

EDIT: I just released an app update that uses TrackPlayer and:

  • the crashes seem to be isolated: ~90% Pixel phones / ~90% Android 14
  • about 25% of all Android 14 Pixel phones are affected
  • // the above is a pretty small sample size (~600 Android devices)

mihaibulic2 avatar Dec 29 '23 02:12 mihaibulic2

ping - anythoughts?

mihaibulic2 avatar Jan 08 '24 03:01 mihaibulic2

This issue is stale because it has been open 90 days with no activity. Remove stale label or comment or this will be closed in 7 days.

github-actions[bot] avatar Apr 08 '24 01:04 github-actions[bot]

Not stale, still happening frequently. Just haven’t had time to investigate further yet.

elliotdickison avatar Apr 09 '24 01:04 elliotdickison

any solution for this folks ?

nateshmbhat avatar Jun 15 '24 08:06 nateshmbhat

This is still an issue AFAIK, @nateshmbhat I'm sure the maintainers would welcome a PR!

Our best guess so far as to the scenario under which this occurs:

  1. User opens app, plays something, pauses playback
  2. Android kills the app's main activity after a period of inactivity (very normal Android behavior)
  3. The notification stays open
  4. The user taps the notification
  5. The app crashes and the notification closes

elliotdickison avatar Jul 08 '24 23:07 elliotdickison