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

Unable to start service MusicService with null: android.app.ForegroundServiceStartNotAllowedException: Service.startForeground() not allowed due to mAllowStartForeground false

Open bradfloodx opened this issue 1 year ago • 64 comments

Describe the Bug Daily crash reports of Unable to start service com.doublesymmetry.trackplayer.service.MusicService with null: android.app.ForegroundServiceStartNotAllowedException: Service.startForeground() not allowed due to mAllowStartForeground false

Steps To Reproduce Unknown. Will update if I can replicate consistently.

Code To Reproduce NA

Replicable on Example App? Not yet.

Environment Info:

How I can Help Looking into it.

bradfloodx avatar Jan 31 '24 00:01 bradfloodx

Looking at all the older issues related to this, it appears this issue should be fixed in 4.0.1, but it's not for me. Still getting this crash report several times a day :(

bradfloodx avatar Jan 31 '24 00:01 bradfloodx

Stack trace from BugSnag:

ActivityThread.java:4880 android.app.ActivityThread.handleServiceArgs
Unknown android.app.ActivityThread.-$$Nest$mhandleServiceArgs
ActivityThread.java:2314 android.app.ActivityThread$H.handleMessage
Handler.java:106 android.os.Handler.dispatchMessage
Looper.java:205 android.os.Looper.loopOnce
Looper.java:294 android.os.Looper.loop
ActivityThread.java:8248 android.app.ActivityThread.main
Method.java:-2 java.lang.reflect.Method.invoke
RuntimeInit.java:552 com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run
ZygoteInit.java:971 com.android.internal.os.ZygoteInit.main
Caused By: android.app.ForegroundServiceStartNotAllowedException · Service.startForeground() not allowed due to mAllowStartForeground false: service com.tutusgumboots.evergrace/com.doublesymmetry.trackplayer.service.MusicService
ForegroundServiceStartNotAllowedException.java:54 android.app.ForegroundServiceStartNotAllowedException$1.createFromParcel

bradfloodx avatar Jan 31 '24 00:01 bradfloodx

after some research I dont think this is supposed to be fixed in recent versions, really.

The root cause is android disabled starting a foreground service from a background activity since 8 or 12. Because RNTP does kill the foreground service quite liberally, this quickly becomes a problem once the activity is sent to background/cached process. There are ways around it, like disabling battery optimization; but the fact the foreground service is killed and restarted is a problem itself; unlike the flutter alternative (audio_service) RNTP actually does NOT correctly link service back to activity, so it introduces another problem where closing activity may not kill service. So the options are:

  1. do NOT kill foreground service like https://github.com/lovegaoshi/react-native-track-player/commit/9afe35b163c84bf69ba484699dc8aac94dfc00cb this will keep the process to be always running, never backgrounded/cached; this will obviously introduce more battery use; I observed ~0.5-1% battery use over 5 hours or so on Samsung S21. do note Youtube (revanced) and AIMP also do this and this is how I intend to go with. flutter's audio_service basically also have this as an option: https://github.com/ryanheise/audio_service/issues/994#issuecomment-1423601924

  2. turn off battery optimization, which effectively does 1.

  3. turn on ways to enable starting a foreground service from a background activity like SYSTEM_ALERT_WINDOW

  4. target android 7?

I seriously doubt a real solution exists (some if logic to MS.kt L123) otherwise the flutter folks would have found it already. But no one reported a reliable way to reproduce this bug either. For example, I can force terminate the service, app goes to background, though the notification lingers; if I interact with the notification then this is an exception allowed to start foreground service, I dont really understand how this bug happens

lovegaoshi avatar Jan 31 '24 02:01 lovegaoshi

Great info thanks @lovegaoshi I'm going to go with your 1. commit for now and see if it helps my crashes :)

bradfloodx avatar Feb 02 '24 00:02 bradfloodx

patch-package patch here if anyone else wants to try it

diff --git a/node_modules/react-native-track-player/android/src/main/java/com/doublesymmetry/trackplayer/service/MusicService.kt b/node_modules/react-native-track-player/android/src/main/java/com/doublesymmetry/trackplayer/service/MusicService.kt
index 9d6d869..a0a150e 100644
--- a/node_modules/react-native-track-player/android/src/main/java/com/doublesymmetry/trackplayer/service/MusicService.kt
+++ b/node_modules/react-native-track-player/android/src/main/java/com/doublesymmetry/trackplayer/service/MusicService.kt
@@ -587,9 +587,10 @@ class MusicService : HeadlessJsTaskService() {
                             scope.launch {
                                 delay(stopForegroundGracePeriod.toLong() * 1000)
                                 if (shouldStopForeground()) {
-                                    @Suppress("DEPRECATION")
-                                    stopForeground(removeNotificationWhenNotOngoing)
-                                    Timber.d("Notification has been stopped")
+                                	Timber.d("Notification should have been stopped - quick fix hack")
+                                    //@Suppress("DEPRECATION")
+                                    //stopForeground(removeNotificationWhenNotOngoing)
+                                    //Timber.d("Notification has been stopped")
                                 }
                             }
                         }

bradfloodx avatar Feb 02 '24 01:02 bradfloodx

I'm seeing some absurd wakelock and cpu use duration that could be RN apps specific, as MusicService doesnt release wakelocks (headlessJsTaskService). One possible solution could be to move wakelock within: see https://github.com/lovegaoshi/react-native-track-player/commit/2daba94fb05d0bedef6e4e168c9b0f8e32f531a8 and https://github.com/lyswhut/react-native-track-player/commit/bb80e13aa8ed97224ebd3a9cce39e629d0043999

though since AS moved their energy profiler to system trace, I dont know where to find wakelock profiling information anymore, if this my suspicion on the wakelock is even correct

lovegaoshi avatar Feb 02 '24 14:02 lovegaoshi

ive been pretty satisfied with my wakelock patch above and the barrey use, and keeping foregrounf service is veru nice.

the wakelock patch needs to expose wakelock as public and makes more sense to patch after the Aa work.

lovegaoshi avatar Feb 04 '24 16:02 lovegaoshi

IMG_6948

do NOT kill foreground service like https://github.com/lovegaoshi/react-native-track-player/commit/9afe35b163c84bf69ba484699dc8aac94dfc00cb

Unfortunately this did not change things for me in prod :(

I'll try your wake lock fix and let you know how that goes :)

bradfloodx avatar Feb 07 '24 04:02 bradfloodx

im out of wits :/ so it has to be where it's listing foreground tasks and its returning null..? i cant reproduce so cant help

On Tue, Feb 6, 2024, 8:28 PM Brad SF @.***> wrote:

IMG_6948.jpeg (view on web) https://github.com/doublesymmetry/react-native-track-player/assets/1085976/1972cb0e-2673-40ae-9f23-c1bd537369ff

do NOT kill foreground service like @.*** https://github.com/lovegaoshi/react-native-track-player/commit/9afe35b163c84bf69ba484699dc8aac94dfc00cb

Unfortunately this did not change things for me in prod :(

I'll try your wake lock fix and let you know how that goes :)

— Reply to this email directly, view it on GitHub https://github.com/doublesymmetry/react-native-track-player/issues/2244#issuecomment-1931260986, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZMOVVUM3PZYUUZ2FMRT2ALYSL7IBAVCNFSM6AAAAABCSFD5U2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSMZRGI3DAOJYGY . You are receiving this because you were mentioned.Message ID: @.*** com>

lovegaoshi avatar Feb 07 '24 05:02 lovegaoshi

We are seeing a lot of these errors as well, resulting quite a few crashes for the user. The error does seem to only occur on devices running Android 14.

image

TobiDevloft avatar Feb 08 '24 09:02 TobiDevloft

Seems to be a duplicate of:

https://github.com/doublesymmetry/react-native-track-player/issues/2231 https://github.com/doublesymmetry/react-native-track-player/issues/2198

and several closed issues.

Is that something you guys have on your radar? @dcvz

TobiDevloft avatar Feb 08 '24 10:02 TobiDevloft

We have shipped the workaround of not killing the foreground service and found it to be effective so far. @brad-sf it is likely that you either did not apply the patch correctly or the continued issue you're seeing is from old versions that are still being used by your users.

mmmoussa avatar Feb 10 '24 18:02 mmmoussa

We have shipped the workaround of not killing the foreground service and found it to be effective so far. @brad-sf it is likely that you either did not apply the patch correctly or the continued issue you're seeing is from old versions that are stibeing used by your user

@mmmoussa this workaround that you mention is avaialble in the current version of the framework? or is located somewhere else?

I just started to investigate this issue and I see a lot of users experiencing this behaviour.

StriderHND avatar Feb 14 '24 01:02 StriderHND

It's getting on my nerves that there are hundreds of reported crashes related to this issue everyday. The app was just deployed with latest version 4.0.1 few days ago and Its downgrading the UX. Is there a workaround for this? @brad-sf how is the result for the wake lock fix?

Screenshot 2024-02-14 at 12 43 09 PM

kyo-torstar avatar Feb 14 '24 18:02 kyo-torstar

@mmmoussa whats this workaround? how can we fix that?

NadeemKhanFh avatar Feb 15 '24 10:02 NadeemKhanFh

this is the crashlytics log I have, and the function caused the crash has a remark related to https://github.com/doublesymmetry/react-native-track-player/issues/1666 Screenshot 2024-02-15 at 9 27 55 AM

kyo-torstar avatar Feb 15 '24 14:02 kyo-torstar

According to the crash logs, they all happened within the 1st second. I wonder if it is related to the TrackPlayer.setupPlayer() function call while the app is bootstrapping in the background. Screenshot 2024-02-15 at 9 57 40 AM

kyo-torstar avatar Feb 15 '24 14:02 kyo-torstar

whats ur MS.kt L125? nightly is stopForeground i doubt that is the one; if it's startForeground(EMPTY_NOTIFICATION_ID, notification) and android 14 u can try https://github.com/lovegaoshi/react-native-track-player/commit/1145e2da93647cab93bf118cbf22177433fbe642 (add foreground service type to startForeground) but i doubt it helps

lovegaoshi avatar Feb 15 '24 15:02 lovegaoshi

Th

whats ur MS.kt L125? nightly is stopForeground i doubt that is the one; if it's startForeground(EMPTY_NOTIFICATION_ID, notification) and android 14 u can try lovegaoshi@1145e2d (add foreground service type to startForeground) but i doubt it helps

its caused by stopForeground(true) on L125 MusicService.kt. But tracing backward, I find the initial call should be onStartCommand, a function triggered by HeadlessJsTaskService. Therefore, on the frontend react native, TrackPlayer.registerPlaybackService function call may cause the crash. Screenshot 2024-02-15 at 10 21 05 AM

kyo-torstar avatar Feb 15 '24 15:02 kyo-torstar

and can you reliably reproduce instead from crash logs?

On Thu, Feb 15, 2024, 7:27 AM kyo-torstar @.***> wrote:

Th

whats ur MS.kt L125? nightly is stopForeground i doubt that is the one; if it's startForeground(EMPTY_NOTIFICATION_ID, notification) and android 14 u can try @.*** https://github.com/lovegaoshi/react-native-track-player/commit/1145e2da93647cab93bf118cbf22177433fbe642 (add foreground service type to startForeground) but i doubt it helps

its caused by stopForeground(true) on L125 MusicService.kt. But tracing backward, I find the initial call should be onStartCommand, a function triggered by HeadlessJsTaskService. Therefore, on the frontend react native, TrackPlayer.registerPlaybackService function call may cause the crash. Screenshot.2024-02-15.at.10.21.05.AM.png (view on web) https://github.com/doublesymmetry/react-native-track-player/assets/120053121/50930d7f-c80f-442d-b249-329617e322ee

— Reply to this email directly, view it on GitHub https://github.com/doublesymmetry/react-native-track-player/issues/2244#issuecomment-1946322517, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZMOVVX4KYXZDYJOZMG6ZB3YTYSMJAVCNFSM6AAAAABCSFD5U2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNBWGMZDENJRG4 . You are receiving this because you were mentioned.Message ID: @.*** com>

lovegaoshi avatar Feb 15 '24 15:02 lovegaoshi

and can you reliably reproduce instead from crash logs? On Thu, Feb 15, 2024, 7:27 AM kyo-torstar @.> wrote: Th whats ur MS.kt L125? nightly is stopForeground i doubt that is the one; if it's startForeground(EMPTY_NOTIFICATION_ID, notification) and android 14 u can try @. <lovegaoshi@1145e2d> (add foreground service type to startForeground) but i doubt it helps its caused by stopForeground(true) on L125 MusicService.kt. But tracing backward, I find the initial call should be onStartCommand, a function triggered by HeadlessJsTaskService. Therefore, on the frontend react native, TrackPlayer.registerPlaybackService function call may cause the crash. Screenshot.2024-02-15.at.10.21.05.AM.png (view on web) https://github.com/doublesymmetry/react-native-track-player/assets/120053121/50930d7f-c80f-442d-b249-329617e322ee — Reply to this email directly, view it on GitHub <#2244 (comment)>, or unsubscribe https://github.com/notifications/unsubscribe-auth/AZMOVVX4KYXZDYJOZMG6ZB3YTYSMJAVCNFSM6AAAAABCSFD5U2VHI2DSMVQWIX3LMV43OSLTON2WKQ3PNVWWK3TUHMYTSNBWGMZDENJRG4 . You are receiving this because you were mentioned.Message ID: @.*** com>

we reproduced it few times only but we could not conclude the reliable step to replicate it. It looks random that it may relate to racing conditions upon bootstrap. I modified the startup function as following:

setTimeout(() => {
  TrackPlayer.registerPlaybackService(() =>
    require('@services/TrackPlayerService'),
  );

  setTimeout(async () => {
    await TrackPlayer.setupPlayer();
    await TrackPlayer.updateOptions(options); 
  }, 3000);
}, 3000);

kyo-torstar avatar Feb 15 '24 16:02 kyo-torstar

I'm definitely getting LESS of this crash report since trialing the patch fix above.

But yes I agree there also appears to be some remaining crashes related to a race condition because they fire immediately on app launch (according to crash logs).

I'll try the above setTimeout and see if that clears all the errors.

If that's the case I guess we have two issues.. one on launch and one in general usage.

bradfloodx avatar Feb 20 '24 06:02 bradfloodx

@brad-sf @lovegaoshi I look deeper, It should be related to the setupPlayer function being called when the app is in the background state. There should be a glimpse of moment the app is in background state when setupPlayer is called. It should be triggered by this

        Intent(context, MusicService::class.java).also { intent ->
            if (Build.VERSION.SDK_INT >= Build.VERSION_CODES.O) {
                context.startForegroundService(intent)
            } else {
                context.startService(intent)
            }
            context.bindService(intent, this, Context.BIND_AUTO_CREATE)
        }

To minimize the possibility of this from happening, we can do something like

TrackPlayer.registerPlaybackService(() =>
  require('@services/TrackPlayerService'),
);
const setupDelay = 1000;

const useTrackPlayer = () => {
  const [isServiceRegistered, setIsServiceRegistered] = useState(false);
  useEffect(() => {
      let initTimer = setTimeout(() => {
        if (state.appState === 'active' && !isServiceRegistered) {
          // inside this function calls:
          // await TrackPlayer.setupPlayer();
          // await TrackPlayer.updateOptions(options);
          // setIsServiceRegistered(true);
          initAudioPlayer(playerStatus); 
        }
      }, setupDelay);
  
      return () => {
        clearTimeout(initTimer);
      };
    }, [state, isServiceRegistered]);
}

This is a temp workaround, the solution should be applied at the setupPlayer function in MusicService.kt, a foreground has to be done

if (isAppOnForeground((context))) {
  // promise.reject here
}
...
Intent(context, MusicService::class.java).also { intent ->
...

The Java implementation from https://reactnative.dev/docs/headless-js-android

    private boolean isAppOnForeground(Context context) {
        /**
         We need to check if app is in foreground otherwise the app will crash.
         https://stackoverflow.com/questions/8489993/check-android-application-is-in-foreground-or-not
         **/
        ActivityManager activityManager = (ActivityManager) context.getSystemService(Context.ACTIVITY_SERVICE);
        List<ActivityManager.RunningAppProcessInfo> appProcesses =
                activityManager.getRunningAppProcesses();
        if (appProcesses == null) {
            return false;
        }
        final String packageName = context.getPackageName();
        for (ActivityManager.RunningAppProcessInfo appProcess : appProcesses) {
            if (appProcess.importance ==
                    ActivityManager.RunningAppProcessInfo.IMPORTANCE_FOREGROUND &&
                    appProcess.processName.equals(packageName)) {
                return true;
            }
        }
        return false;
    }

kyo-torstar avatar Feb 20 '24 13:02 kyo-torstar

But why is your app in the background state when it's starting up? unless I immediately press back when opening the app, and startService is caught in that way? it would really help if there's a reproducible repo; I've never seen the example app or my app going ANR when starting up.

lovegaoshi avatar Feb 20 '24 17:02 lovegaoshi

Screenshot 2024-02-20 at 1 23 54 PM

the crash logs all show that they happen less than a second. It could be the reason the setupPlayer function is called during app start. e.g. I put setupPlayer in the App.tsx function body, for example

useEffect(() => {
  setupPlayer()
}, []) 

kyo-torstar avatar Feb 20 '24 18:02 kyo-torstar

Related to https://issuetracker.google.com/issues/307329994 ?

trix0 avatar Feb 27 '24 08:02 trix0

Related to https://issuetracker.google.com/issues/307329994 ?

possibly, but it looks like no one can reproduce it locally. This was what I thought when I was trying to reproduce the crash as I experience no crash. However, I found several crash logs related to my tests later. I think the app was crashed and was restarted when It was brought back from background / during bootstrap.

kyo-torstar avatar Feb 27 '24 15:02 kyo-torstar

update to potential fix: https://issuetracker.google.com/issues/307329994#comment56 further reference: https://stackoverflow.com/questions/77680265/service-startforeground-not-allowed-due-to-mallowstartforeground-false-androi

@Override
public int onStartCommand(Intent intent, int flags, int startId) {
    if (intent != null) {
        startForeground();    //or wherever you call it: check the Intent before!
    }
}

kyo-torstar avatar Mar 04 '24 15:03 kyo-torstar

@kyo-torstar where we will write this code?

Nadimkhan120 avatar Mar 04 '24 16:03 Nadimkhan120

youd wrap startAndStopEmptyNotificationToAvoidANR() https://github.com/lovegaoshi/react-native-track-player/commit/95c26d92815c1f9d55b0c401e1fd4244e2f98c77 but why is this (service killed n restarted due to oom) related to crush on app start? has anyone done log intent before app crash?

lovegaoshi avatar Mar 05 '24 20:03 lovegaoshi