ANR Context.startForegroundService() did not then call Service.startForeground()

[tobyworks]

Media3 Version

Media3 1.0.0 , target and compile sdk 33

Devices that reproduce the issue

Galaxy S20 FE 5G - Android 13
Pixel 6 - Android 13
Pixel 7 - Android 13

Devices that do not reproduce the issue

Unknown

Reproducible in the demo app?

Yes. in UAMP when targetting compile sdk 33 and media3 1.0.0

Reproduction steps

• Open App
• Kill App
• Press play/pause on bluetooth headset OR adb shell input keyevent 126
• observe crash after some seconds

What i notice is that the service gets recreated when i press the bluetooth controls. How do i circumvent this?

Screen.Recording.2023-04-06.at.18.22.27.mp4

download project: https://transfer.sh/vEey0M/uamp.zip

Expected result

ANR Shouldn't happen

• we are getting ANR's in crashlytics since using Media3 but we cant determine the root cause of this issue maybe you have an idea what might cause these issues.

Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException
Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{e7bf2a3 u0 .....Redacted....../.....MediaLibraryService}
android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException (ActivityThread.java:2245)
android.app.ActivityThread.throwRemoteServiceException (ActivityThread.java:2216)
android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException
android.app.ActivityThread$H.handleMessage (ActivityThread.java:2508)
android.os.Handler.dispatchMessage (Handler.java:106)
android.os.Looper.loopOnce (Looper.java:226)
android.os.Looper.loop (Looper.java:313)



android.app.ActivityThread.main (ActivityThread.java:8757)
java.lang.reflect.Method.invoke (Method.java)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:571)
com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1067)

Actual result

ANR happens

Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException
Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{e7bf2a3 u0 .....Redacted....../.....MediaLibraryService}
android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException (ActivityThread.java:2245)
android.app.ActivityThread.throwRemoteServiceException (ActivityThread.java:2216)
android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException
android.app.ActivityThread$H.handleMessage (ActivityThread.java:2508)
android.os.Handler.dispatchMessage (Handler.java:106)
android.os.Looper.loopOnce (Looper.java:226)
android.os.Looper.loop (Looper.java:313)
android.app.ActivityThread.main (ActivityThread.java:8757)
java.lang.reflect.Method.invoke (Method.java)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:571)
com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1067)

Media

any media

Bug Report

• You will email the zip file produced by adb bugreport to dev.exoplayer@gmail.com after filing this issue.

[tonihei]

@marcbaechinger Do we have some existing GH issue comment thread that explains potential reasons for this and what could go wrong? It interesting to see that more or less of these issues happened on Samsung and Android 13.

[tobyworks]

After some additional testing. this is 100% reproducable on UAMP when targeting SDK 33 and 1.0.0 media3

[tobyworks]

@marcbaechinger Do we have some existing GH issue comment thread that explains potential reasons for this and what could go wrong? It interesting to see that more or less of these issues happened on Samsung and Android 13.

It is explainable why it happens on Samsung mostly. it's because some users remap the bixby button to play pause. So this 'edgecase' is way more likely to happen on those devices.

[marcbaechinger]

We have #167 that is about ForegroundServiceDidNotStartInTimeException.

On a Pixel device the above repro steps can not happen if they are correct:

1 - Open App
2 - Kill App
3 - Press play/pause on bluetooth headset
4 - observe crash after some seconds

The report says it is reproducible with the demo app. The demo app does not have a MediaButtonReceiver configured. so unless someone modified the demo app. Step 3 should just do nothing on a Pixel phone.

So if this is only happening on Samsung devices and it happens with Samsung devices only, then Samsung is doing something differently to vanilla Android. This can be that the system tries to restart the service without a MediaButtonReceiver. If this is the case, then the above bug report shows why this isn't a good idea in my opinion.

@tobyworks Is the comment above reproducible with the demo app intended to be true? How is the demo app service started once the app is killed?

[marcbaechinger]

How does the bixby button start the service and how is an app supposed to prepare the player with which media in this case? How does the bixby button know whether an app supports starting this way?

Does Samsung document this somewhere?

[tobyworks]

@marcbaechinger I advise you to check UAMP targetting sdk 33 and media3 1.0.0.
it's repoducable on my Pixel 6

com.example.android.uamp.next        E  FATAL EXCEPTION: main
                                                                                                    Process: com.example.android.uamp.next, PID: 21384
                                                                                                    android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{62a17b u0 com.example.android.uamp.next/com.example.android.uamp.media.MusicService}
                                                                                                    	at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2001)
                                                                                                    	at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:1975)
                                                                                                    	at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException(Unknown Source:0)
                                                                                                    	at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2237)
                                                                                                    	at android.os.Handler.dispatchMessage(Handler.java:106)
                                                                                                    	at android.os.Looper.loopOnce(Looper.java:201)
                                                                                                    	at android.os.Looper.loop(Looper.java:288)
                                                                                                    	at android.app.ActivityThread.main(ActivityThread.java:7884)
                                                                                                    	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:936)
                                                                                                    	

If you want i can zip my project of UAMP and send it.

Edit: updated my original post with a video of it happening on my Pixel 6

[marcbaechinger]

I can not repro with UAMP either I'm afraid. For the same reasons I think. There is no MediaButtonReceiver for UAMP.

Without this receiver, a play command issued over Bluetooth is not routed to the app. So either the app is not completely killed, or UAMP has been modified and a MediaButtonReceiver has been added.

However, the root problem is that something is starting the service and the service does not start playback. When an app wants to support being started by whatever means while it is not running (never started or killed) and no app is binding to the service, then the app must immediately start playback so that the service is put into the foreground. Note that in the case that the service is started by an intent (like for instance by the MediaButtonreceiver), there is only the service running and no app is bound to the service. So as per system restrictions, the service must be put into foreground immediately after service starts. This is achieved by preparing the player with the last used media item or similar, and then start playback. I think it's in the responsibility of the app to do that.

The session demo service does not have a MediaButtonReceiver configured. It does not expect to be started without an app having bound to the service at the beginning. If this is done either way, the crash is logical because the preparation and start of playback is missing.

From this I don't think this is a bug of the library. I apologize that neither the session demo nor UAMP currently support this feature, so it is not well documented.

Can you let me know how you think the play command from BT is routed to UAMP without the receiver? Can you after you have killed the app, run adb shell dumpsys media_session and paste the output here?

[tobyworks]

Have you tried it in UAMP project that i sent you? it is 100% reproducable in that configuration. Nothing has been changed. besides the bump in target sdk and media 3

Here;s the log:

MEDIA SESSION SERVICE (dumpsys media_session)

5 sessions listeners.
Global priority session is com.android.server.telecom/HeadsetMediaButton (userId=0)
  HeadsetMediaButton com.android.server.telecom/HeadsetMediaButton (userId=0)
    ownerPid=1888, ownerUid=1000, userId=0
    package=com.android.server.telecom
    launchIntent=null
    mediaButtonReceiver=null
    active=false
    flags=65537
    rating type=0
    controllers: 0
    state=null
    audioAttrs=AudioAttributes: usage=USAGE_VOICE_COMMUNICATION content=CONTENT_TYPE_SPEECH flags=0x800 tags= bundle=null
    volumeType=1, controlType=2, max=0, current=0
    metadata: null
    queueTitle=null, size=0
User Records:
Record for full_user=0
  Volume key long-press listener: null
  Volume key long-press listener package:
  Media key listener: null
  Media key listener package:
  OnMediaKeyEventDispatchedListener: added 0 listener(s)
  OnMediaKeyEventSessionChangedListener: added 1 listener(s)
    from com.android.bluetooth
  Last MediaButtonReceiver: MBR {pi=PendingIntent{c9283b3: PendingIntentRecord{df4cd70 com.example.android.uamp.next startForegroundService}}, type=3}
  Media button session is null
  Sessions Stack - have 3 sessions:
    AudioService grit.storytel.app/AudioService (userId=0)
      ownerPid=15703, ownerUid=10650, userId=0
      package=grit.storytel.app
      launchIntent=PendingIntent{867af93: PendingIntentRecord{a56bbd0 grit.storytel.app startActivity}}
      mediaButtonReceiver=null
      active=true
      flags=3
      rating type=0
      controllers: 4
      state=PlaybackState {state=2, position=37591797, buffered position=0, speed=1.0, updated=574570336, actions=223564, custom actions=[Action:mName='jump 15 seconds back, mIcon=2131231756, mExtras=null, Action:mName='jump 15 seconds ahead, mIcon=2131231177, mExtras=null], active item id=-1, error=null}
      audioAttrs=AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_UNKNOWN flags=0x800 tags= bundle=null
      volumeType=1, controlType=2, max=0, current=0
      metadata: size=13, description=Androids: The Team that Built the Android Operating System, Chet Haase, Androids: The Team that Built the Android Operating System
      queueTitle=null, size=0
    BluetoothMediaBrowserService com.google.android.bluetooth/BluetoothMediaBrowserService (userId=0)
      ownerPid=15193, ownerUid=1002, userId=0
      package=com.google.android.bluetooth
      launchIntent=null
      mediaButtonReceiver=null
      active=false
      flags=3
      rating type=0
      controllers: 0
      state=PlaybackState {state=7, position=0, buffered position=0, speed=0.0, updated=574560378, actions=0, custom actions=[], active item id=-1, error=Bluetooth audio disconnected}
      audioAttrs=AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_UNKNOWN flags=0x800 tags= bundle=null
      volumeType=1, controlType=2, max=0, current=0
      metadata: null
      queueTitle=Now Playing, size=0
    BluetoothMediaBrowserService com.google.android.bluetooth/BluetoothMediaBrowserService (userId=0)
      ownerPid=15193, ownerUid=1002, userId=0
      package=com.google.android.bluetooth
      launchIntent=null
      mediaButtonReceiver=null
      active=false
      flags=3
      rating type=0
      controllers: 0
      state=PlaybackState {state=7, position=0, buffered position=0, speed=0.0, updated=574561390, actions=0, custom actions=[], active item id=-1, error=Bluetooth audio disconnected}
      audioAttrs=AudioAttributes: usage=USAGE_MEDIA content=CONTENT_TYPE_UNKNOWN flags=0x800 tags= bundle=null
      volumeType=1, controlType=2, max=0, current=0
      metadata: null
      queueTitle=Now Playing, size=0
Audio playback (lastly played comes first)
  uid=10205 packages=com.android.systemui
  uid=10756 packages=com.example.android.uamp.next
Media session config:
  media_button_receiver_fgs_allowlist_duration_ms: [cur: 10000, def: 10000]
  media_session_calback_fgs_allowlist_duration_ms: [cur: 10000, def: 10000]
  media_session_callback_fgs_while_in_use_temp_allow_duration_ms: [cur: 10000, def: 10000]

[eXaLy]

On the media3 branch

[marcbaechinger]

I haven't. I just saw there is actually a second manifest in UAMP that has a receiver.

Thanks for the logs:

Last MediaButtonReceiver: MBR {pi=PendingIntent{c9283b3: PendingIntentRecord{df4cd70 com.example.android.uamp.next startForegroundService}}, type=3}

Let me flash my device. I'm currently on UDC and need to flash to Android 13.

You still need to implement this in your app. If we can show it's not working with UAMP, what would it tell us? That the app needs to implement starting playback. Your app would need to do the same.

[tobyworks]

I haven't. I just saw there is actually a second manifest in UAMP that has a receiver.

Just now tested by commenting the receiver in common module. It also happens without the Manifest Entry. the button receiver is only used for pre API 21 afaik.

You still need to implement this in your app. If we can show it's not working with UAMP, what would it tell us? That the app needs to implement starting playback. Your app would need to do the same.

But we can't right now because implicitly the service get's started by MediaLibraryService. And we dont have full control over that. What i did notice is that when pressing a MEDIA_PLAY_BUTTON the Service's onStartCommand gets called with a keyevent. So i was thinking of going that path to circumvent the button event as a temporary hack, but not sure how. Because implicitly the Context.startForegroundService() is already called.

 override fun onStartCommand(intent: Intent?, flags: Int, startId: Int): Int {
//        return super.onStartCommand(intent, flags, startId)
        val keyEvent = intent?.extras?.get("android.intent.extra.KEY_EVENT") as? KeyEvent
            ?: return super.onStartCommand(intent, flags, startId)
        return when(keyEvent.keyCode){
            KeyEvent.KEYCODE_MEDIA_PLAY,
            KeyEvent.KEYCODE_MEDIA_PAUSE,
            KeyEvent.KEYCODE_MEDIA_PLAY_PAUSE,
            KeyEvent.KEYCODE_MEDIA_STOP -> {
               // do some hack to ignore the start command
               }
        }
    }

Btw @eXaLy is my collegue who will take over this issue from me.

[marcbaechinger]

I will look into this and make sure that we put this into the session demo and UAMP.

the button receiver is only used for pre API 21 afaik.

I think you are correct that for API 21 and lower, the MediaButtonReceiver is also required when the app is running.

If the app is not running and the session is correctly destroyed, then this doc https://developer.android.com/guide/topics/media-apps/mediabuttons says you are not entirely correct.

"If you are running Android 8.0 (API level 26) or later, the system tries to find the last app with a MediaSession that played audio locally. If the session is still active Android sends the event directly to it. Otherwise, if the session is not active and it has a mediabutton receiver, Android sends the event to the receiver, which will restart the session and so it can receive the event."

[tobyworks]

Do you have an idea how you will or your colleagues will fix this in UAMP so we can do it aswell asap. Right now our users are not happy with the update we did and are giving 1 star reviews because of it.

[marcbaechinger]

I have added some sample code in #167 I think it's best to keep the discussion around ForegroundServiceDidNotStartInTimeException in one place. I close this issue as a duplicate. Lets continue the conversation in the other bug. Thanks for your report!