androidx
MediaLibraryService throws ForegroundServiceDidNotStartInTimeException
Media3 Version
1.0.0-beta02
Devices that reproduce the issue
Firebase crashlytics report these devices:
- Galaxy Note20 running Android 12
- Galaxy S21 FE 5G running Android 12
- Xiaomi 11T Pro running Android 12
- Redmi Note 9 Pro running Android 11
Devices that do not reproduce the issue
No response
Reproducible in the demo app?
Not tested
Reproduction steps
It's happened on some devices. I think It has related to MediaController not properly handling the service.
Expected result
not crash?
Actual result
Fatal Exception: android.app.ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{ac0645b u0 player.PlaybackService}
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:2147)
at android.app.ActivityThread.access$2900(ActivityThread.java:310)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2376)
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:8669)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
Media
Bug Report
- [ ] You will email the zip file produced by
adb bugreportto [email protected] after filing this issue.
I've also seen this in Crashlytics, although I'm myself have been unable to reproduce this.
Thanks for reporting!
Do you have some more context what command has been sent to the service when this happens?
I'm asking because I probably have found an execution path that could cause this problem, but I can not repro this and hence I can not verify a fix.
I think the reason for this could be that the pending intent of 'pause' is starting a foreground service and then does not call Service.startForeground().
I will provide a fix for the case described above. However, I can't be really sure whether this is the root case of the exception above because I can't repro now. I think it may be a corner case that sends the pause command when the service actually has been destroyed, but that's a wild guess.
You have already reported that this happens on Android 12. Can you let me know the targetSkdVersion that you use for the app that is producing the stack trace above?
So in my case, I have both target & compile SDK set to 33.
Full stacktrace:
Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{ad7d394 u0 com.vanniktech.rssreader/com.vanniktech.feature.rssreader.itemdownload.RssReaderItemDownloadBackgroundService}
at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2006)
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:1977)
at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException()
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2242)
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:7898)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
@marcbaechinger
My project is an online streaming application that streams songs. So basic commands are play/pause/seek/stop.
and the targetSkdVersion is 32
This crash is reported a lot And when are we gonna get stable v1? any news?
***** EDIT ***** I found the reason. when you play a song and then pause it and close the app the notification remains If you click on play, after a few seconds it will crash. service is not foreground but notification is not dismissed and the problem is when pressing the play button it will crash
Hi, I reproduce the crash with media session demo app
here is the stack trace. I don't know if It's the exact same, but in bottom of crash it contains the ForegroundServiceDidNotStartInTimeException exception.
It happens in the background playing when pressing play/pause a few times On both the Lock screen and unlocked.
Also, the crash is insanely reporting in crashlytics for me!
2022-09-23 11:59:43.721 7087-7087/androidx.media3.demo.session E/AbstractFuture: RuntimeException while executing runnable androidx.media3.demo.session.MainActivity$$ExternalSyntheticLambda2@51ce0f3 with executor MoreExecutors.directExecutor()
java.util.concurrent.CancellationException: Task was cancelled.
at com.google.common.util.concurrent.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1496)
at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:586)
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:547)
at androidx.media3.demo.session.MainActivity.getBrowser(MainActivity.kt:42)
at androidx.media3.demo.session.MainActivity.pushRoot(MainActivity.kt:160)
at androidx.media3.demo.session.MainActivity.initializeBrowser$lambda-3(MainActivity.kt:108)
at androidx.media3.demo.session.MainActivity.$r8$lambda$zcr2almQqmFxiCBoT1PwekCQLVg(Unknown Source:0)
at androidx.media3.demo.session.MainActivity$$ExternalSyntheticLambda2.run(Unknown Source:2)
at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:31)
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1277)
at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:1038)
at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:665)
at androidx.media3.session.MediaController.releaseFuture(MediaController.java:479)
at androidx.media3.demo.session.MainActivity.releaseBrowser(MainActivity.kt:112)
at androidx.media3.demo.session.MainActivity.onStop(MainActivity.kt:97)
at android.app.Instrumentation.callActivityOnStop(Instrumentation.java:1496)
at android.app.Activity.performStop(Activity.java:8502)
at android.app.ActivityThread.callActivityOnStop(ActivityThread.java:5298)
at android.app.ActivityThread.performStopActivityInner(ActivityThread.java:5278)
at android.app.ActivityThread.handleStopActivity(ActivityThread.java:5343)
at android.app.servertransaction.StopActivityItem.execute(StopActivityItem.java:43)
at android.app.servertransaction.ActivityTransactionItem.execute(ActivityTransactionItem.java:45)
at android.app.servertransaction.TransactionExecutor.executeLifecycleState(TransactionExecutor.java:176)
at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:97)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2282)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loopOnce(Looper.java:210)
at android.os.Looper.loop(Looper.java:299)
at android.app.ActivityThread.main(ActivityThread.java:8250)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:556)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1045)
2022-09-23 11:59:43.800 7087-7087/androidx.media3.demo.session E/AbstractFuture: RuntimeException while executing runnable androidx.media3.demo.session.PlayerActivity$$ExternalSyntheticLambda3@82c155b with executor MoreExecutors.directExecutor()
java.util.concurrent.CancellationException: Task was cancelled.
at com.google.common.util.concurrent.AbstractFuture.cancellationExceptionWithCause(AbstractFuture.java:1496)
at com.google.common.util.concurrent.AbstractFuture.getDoneValue(AbstractFuture.java:586)
at com.google.common.util.concurrent.AbstractFuture.get(AbstractFuture.java:547)
at androidx.media3.demo.session.PlayerActivity.getController(PlayerActivity.kt:44)
at androidx.media3.demo.session.PlayerActivity.setController(PlayerActivity.kt:128)
at androidx.media3.demo.session.PlayerActivity.initializeController$lambda-4(PlayerActivity.kt:120)
at androidx.media3.demo.session.PlayerActivity.$r8$lambda$_NhsfsieB1wweFfLvjToeliIJGM(Unknown Source:0)
at androidx.media3.demo.session.PlayerActivity$$ExternalSyntheticLambda3.run(Unknown Source:2)
at com.google.common.util.concurrent.DirectExecutor.execute(DirectExecutor.java:31)
at com.google.common.util.concurrent.AbstractFuture.executeListener(AbstractFuture.java:1277)
at com.google.common.util.concurrent.AbstractFuture.complete(AbstractFuture.java:1038)
at com.google.common.util.concurrent.AbstractFuture.cancel(AbstractFuture.java:665)
at androidx.media3.session.MediaController.releaseFuture(MediaController.java:479)
at androidx.media3.demo.session.PlayerActivity.releaseController(PlayerActivity.kt:124)
at androidx.media3.demo.session.PlayerActivity.onStop(PlayerActivity.kt:102)
at android.app.Instrumentation.callActivityOnStop(Instrumentation.java:1496)
at android.app.Activity.performStop(Activity.java:8502)
at android.app.ActivityThread.callActivityOnStop(ActivityThread.java:5298)
at android.app.ActivityThread.performStopActivityInner(ActivityThread.java:5278)
at android.app.ActivityThread.handleStopActivity(ActivityThread.java:5343)
at android.app.servertransaction.StopActivityItem.execute(StopActivityItem.java:43)
at android.app.servertransaction.ActivityTransactionItem.execute(ActivityTransactionItem.java:45)
at android.app.servertransaction.TransactionExecutor.executeLifecycleState(TransactionExecutor.java:176)
at android.app.servertransaction.TransactionExecutor.execute(TransactionExecutor.java:97)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2282)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loopOnce(Looper.java:210)
at android.os.Looper.loop(Looper.java:299)
at android.app.ActivityThread.main(ActivityThread.java:8250)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:556)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1045)
2022-09-23 11:59:48.639 8393-8393/androidx.media3.demo.session E/AndroidRuntime: FATAL EXCEPTION: main
Process: androidx.media3.demo.session, PID: 8393
android.app.ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{73168c0 u0 androidx.media3.demo.session/.PlaybackService}
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:1995)
at android.app.ActivityThread.access$2800(ActivityThread.java:271)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2220)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loopOnce(Looper.java:210)
at android.os.Looper.loop(Looper.java:299)
at android.app.ActivityThread.main(ActivityThread.java:8250)
at java.lang.reflect.Method.invoke(Native Method)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:556)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1045)
Thanks for digging some further. That give me some further data points.
when you play a song and then pause it and close the app the notification remains.
Yes, indeed, these cases are always about closing the app and having only the service playing in the background. As soon as your app is in the foreground with a controller connected you are bound to the service, and you will never see such an exception.
If you click on play, after a few seconds it will crash.
With the default behaviour of the MediaSessionService (your app does not override updateNotification()), I don't think that play should produce a ForegroundServiceDidNotStartInTimeException, because after you pressed play, playWhenReady is true and the player is not STATE_IDLE which results in service.startForeground() being called. With play I would only expect a ForegroundServiceStartNotAllowedException in some cases but not when pressing PLAY on a notification on Android 12 (PendingIntent with exception) and Android 13 (MediaSession with exemption).
I still think it's the PAUSE case for which we will provide a fix.
Hi @marcbaechinger, When we can expect this bug fix on the repo? and any news about the next release?
This should be fixed with this commit. Please re-open if you think you still see this issue with this commit.
I'm still a little bit concerned it's not a complete fix.
if (Util.SDK_INT >= 26 && command == COMMAND_PLAY_PAUSE) {
if (Util.SDK_INT >= 26
&& command == COMMAND_PLAY_PAUSE
&& !mediaSession.getPlayer().getPlayWhenReady()) {
Seems racy, the pending intent in the notification can be clicked on after something else has just toggled this.
Also do you have a test for playback stopped by suppression? I assume this will work because it's temporary and the session is still active?
Assigning to @christosts who is working on mapping commands to the MediaSessionCompat actions.
The commit above restored to what we had before and has afterwards been removed by myself by mistake.
We should probably consider splitting COMMAND_PLAY_PAUSE to COMMAND_PLAY and COMMAND_PAUSE?
@yschimke This issue is about a ForegroundServiceDidNotStartInTimeException of the MediaSessionService. My understanding/hypothesis is that this is related to the first command arriving in onStartCommand as a pending intent when the service is not yet running (onCreate called immediately before onStartCommand). My understanding is based on a possibly faulty code path that I found and described above and that the exception is observed on Android 12 and 11 where the notification still sends pending intents (as opposed to Android 13). Where do you see the risk of a race condition with another intent or media session command in such a case when the service is not yet started?
By design, the service is started by creating a controller/browser and binding to the service. The service shouldn't be started by a pending intent (not Context.startForegroundService(intent)) that are only coming from the notification - which needs a running service.
For this reason, I agree that this is about a race condition or an invalid state but elsewhere (stale notification?). I couldn't repro, because I do not understand from where a pending intent for PAUSE arrives when the service is not running. When the service is stopped, the notification is removed and there shouldn't be a way to send a PAUSE intent in this case. If such an intent is sent by an app, the app is just not using the service correctly I think. Not saying this is the case, as I have no evidence that this is an app problem.
I agree that I'm not sure that this fixes the problem, but I think it removes the ForegroundServiceDidNotStartInTimeException (admittedly to the expense of another Exception that we hopefully better understand). Because in such a case of a PAUSE command when the service is not yet started, we probably now are at risk of a ForegroundStartNotAllowedException.
If you have any way to repro this ForegroundServiceDidNotStartInTimeException please let me know. I'm thankful for any input that makes me understand better how this exception is produced.
When can we expect a new release of the media3 library? This issue is affecting almost 2% of our users.
We have many reports in Crashlytics of users facing this issue, however I believe it's not causing crashes (although they get reported as one), as I can see in our database that the users who face the crash can listen to the app audios and complete the full playback. We have not been able to reproduce it ourselves so far.
Another annoying thing is that we get different reports in Crashlytics that are not getting grouped as the same issue, and it's spamming us with many different issues that are essentially the same.
Android 12 examples:
Fatal Exception: android.app.ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{eac8ccc u0 xxx/.feature.player.service.PlayerService}
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:2152)
at android.app.ActivityThread.access$2800(ActivityThread.java:315)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2381)
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:8751)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
Different report, same issue:
Fatal Exception: android.app.ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{24fb927 u0 xxx/.feature.player.service.PlayerService}
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:2147)
at android.app.ActivityThread.access$2900(ActivityThread.java:310)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2376)
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:8663)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:567)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
Another:
Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{9086cb9 u0 xxx/.feature.player.service.PlayerService}
at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2206)
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:2177)
at android.app.ActivityThread.access$2900(ActivityThread.java:324)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2435)
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:8855)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:571)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1135)
And many more.
Android 11 example:
Fatal Exception: android.app.RemoteServiceException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{5632ffb u0 xxx/.feature.player.service.PlayerService}
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2248)
at android.os.Handler.dispatchMessage(Handler.java:106)
at android.os.Looper.loop(Looper.java:246)
at android.app.ActivityThread.main(ActivityThread.java:8550)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:602)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:1130)
We have around 15 different reports of this same issue with slightly different line numbers throwing the error in the last 7 days. Do you have any insights or recommendations on what to do?
If you still see this problem please expand your comment a bit and provide some more infos to make your ask actionable. You should at least tell us the version of the library you are using (should be 1.0.0-beta03 that has the latest fixes), what OS you are running on and what is the targetSdk of your app. Then please add the evidence of the issue that you are seeing. Best is a bug report right after you see this issue. Happy to look into this, else I consider this issue fixed as per the commits above and will close.
Our app release with media3 updated to 1.0.0-beta03 is just being rolled out. But we already received 2 crash reports. From Pixel 6 and 7, both on Android 13. targetSdk is 33.
Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{2a2abb8 u0 com.package.name/.feature.player.service.PlayerService}
at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2006)
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:1977)
at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException(ActivityThread.java)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2242)
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:7898)
at java.lang.reflect.Method.invoke(Method.java)
at com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run(RuntimeInit.java:548)
at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:936)
same here with beta3 and target sdk 33. Devices are 100% samsung with android 12 and 13
for Android 13 got this stacktrace:
Fatal Exception: android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException
Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{4d9015f u0 com.package.name/.feature.player.service.PlayerService}
android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException (ActivityThread.java:2242)
android.app.ActivityThread.throwRemoteServiceException (ActivityThread.java:2213)
android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException (ActivityThread.java)
android.app.ActivityThread$H.handleMessage (ActivityThread.java:2505)
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:8741)
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)
and for android 12:
Fatal Exception: android.app.ForegroundServiceDidNotStartInTimeException
Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{d5a5909 u0 com.package.name/.feature.player.service.PlayerService}
android.app.ActivityThread.throwRemoteServiceException (ActivityThread.java:2147)
android.app.ActivityThread.access$2900 (ActivityThread.java:310)
android.app.ActivityThread$H.handleMessage (ActivityThread.java:2376)
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:8663)
java.lang.reflect.Method.invoke (Method.java)
com.android.internal.os.RuntimeInit$MethodAndArgsCaller.run (RuntimeInit.java:567)
com.android.internal.os.ZygoteInit.main (ZygoteInit.java:1135)
It occurs 100% in background and considered as a repeated crash by firebase
@AndrazP @tfighieraFreebox
Is you app using a androidx.media.session.MediaButtonReceiver? If your app is having a media button receiver, then the system may start your service and then sends an Intent with action android.intent.action.MEDIA_BUTTON.
I'm asking because in such a case the service is allowed to be started as a foreground service (ContextCompat.startForegroundService(...)) as per exemption. Your service then needs to handle that intent and immediately start playback to make the MediaNotificationManager start in the foreground.
This is a potential source for a ForegroundServiceDidNotStartInTimeException that I was just able to repro. Just adding this as for your information and investigation.
We don't use MediaButtonReceiver but we use a custom media notification provider
internal class MusicNotificationProvider(private val context: Context, private val session: MediaSession) : MediaNotification.Provider {
private val notificationManager = context.getSystemService(Context.NOTIFICATION_SERVICE) as NotificationManager
private val coverLoader = MusicCoverLoader() // basically use SimpleBitmapLoader()
private val defaultCoverBitmap by lazy { ContextCompat.getDrawable(context, R.drawable.img_music)!!.toBitmap() }
override fun createNotification(
mediaSession: MediaSession,
customLayout: ImmutableList<CommandButton>,
actionFactory: ActionFactory,
onNotificationChangedCallback: MediaNotification.Provider.Callback
): MediaNotification {
ensureNotificationChannel()
val player = mediaSession.player
val builder = NotificationCompat.Builder(context, NOTIFICATION_CHANNEL_ID)
val mediaStyle = MediaStyleNotificationHelper.MediaStyle(session)
MediaNotificationCommandProvider.getMediaButtons(context, player.availableCommands, player.playWhenReady && player.isPlaying)
.also { buttons ->
val commandRange = List(min(buttons.size, 3)) { it } // initialize a list from 0 to N
mediaStyle.setShowActionsInCompactView(*commandRange.toIntArray())
}
.forEach { commandButton ->
if (commandButton.sessionCommand != null) {
actionFactory.createCustomActionFromCustomCommandButton(mediaSession, commandButton)
} else {
val icon = IconCompat.createWithResource(context, commandButton.iconResId)
actionFactory.createMediaAction(mediaSession, icon, commandButton.displayName, commandButton.playerCommand)
}.let(builder::addAction)
}
// Set metadata info in the notification.
val metadata = player.mediaMetadata
coverLoader.loadArtworkBitmap(metadata) { bitmap: Bitmap?, fromCache: Boolean ->
try {
if (bitmap == null) {
builder.setLargeIcon(defaultCoverBitmap)
} else {
builder.setLargeIcon(bitmap)
}
} catch (e: ExecutionException) {
Log.w(javaClass.simpleName, "Failed to load bitmap", e)
}
if (!fromCache) {
onNotificationChangedCallback.onNotificationChanged(MediaNotification(NOTIFICATION_ID, builder.build()))
}
}
val contentIntent = createHierarchy(player.currentMediaItem, player.mediaItemCount)
val notification = builder
.setContentTitle(metadata.title)
.setContentText(metadata.artist)
.setDeleteIntent(actionFactory.createMediaActionPendingIntent(mediaSession, Player.COMMAND_STOP.toLong()))
.setOnlyAlertOnce(true)
.setSmallIcon(smallIconResId)
.setStyle(mediaStyle)
.setContentIntent(contentIntent)
.setVisibility(NotificationCompat.VISIBILITY_PUBLIC)
.setOngoing(false)
.build()
return MediaNotification(NOTIFICATION_ID, notification)
}
private fun createHierarchy(currentMediaItem: MediaItem?, mediaItemCount: Int): PendingIntent {
val resumeExtras = createResumeExtras(currentMediaItem, mediaItemCount)
return NavDeepLinkBuilder(context)
.setGraph(R.navigation.main)
.setDestination(R.id.main)
.setArguments(resumeExtras)
.createPendingIntent()
}
private fun createResumeExtras(currentMediaItem: MediaItem?, mediaItemCount: Int): Bundle? {
// (...)
return null
}
override fun handleCustomCommand(session: MediaSession, action: String, extras: Bundle): Boolean {
return false
}
private fun ensureNotificationChannel() {
if (Build.VERSION.SDK_INT <= Build.VERSION_CODES.O || notificationManager.getNotificationChannel(NOTIFICATION_CHANNEL_ID) != null) {
return
}
val channel = NotificationChannel(NOTIFICATION_CHANNEL_ID, NOTIFICATION_CHANNEL_NAME, NotificationManager.IMPORTANCE_LOW)
notificationManager.createNotificationChannel(channel)
}
I found two way to reproduce the crash. With demo-session from this project (100%) :
- Play track
- Pause track
- Kill app
- Use a bluetooth command (e.g. play/pause from headphone)
- The app crashes after around 30 seconds.
Since onTaskRemoved is called but onDestroy is not from PlaybackService, the mediaLibrarySession is not released and mediaButtonIntent is not canceled from MediaSessionImpl.
With uamp, branch media 3 :
- Open app
- Kill app (don't play track, it's important to not trigger onStartCommand)
- Use a bluetooth command (e.g. play/pause from headphone)
- The app crashes after around 30 seconds.
This case is different, onTaskRemoved and onDestroy are not called. Since uamp doesn't release MediaBrowser in Activity onStop, the service is not destroyed.
A possible solution could be a combination of the two projects. In the demo-session app, you can release the mediaLibrarySession in onTaskRemoved, and in uamp, you can release the MediaBrowserService in onStop from the Activity.
However, this solution doesn't meet my needs and seems quite fragile.
Do you see any restrictions to stop using getForegroundService in MediaSessionImpl ?
I would sugest :
Intent intent = new Intent(Intent.ACTION_MEDIA_BUTTON, sessionUri);
intent.setComponent(mbrComponent);
mediaButtonIntent = PendingIntent.getService(context, 0, intent, pendingIntentFlagMutable);
broadcastReceiver = null;
Or same approach as before media 3 :
Intent intent = new Intent(Intent.ACTION_MEDIA_BUTTON, sessionUri);
intent.setComponent(mbrComponent);
mediaButtonIntent = PendingIntent.getBroadcast(context, 0/* requestCode, ignored */, intent, pendingIntentFlagMutable);
broadcastReceiver = null;
@marcbaechinger let me know if you need a more detailed bug report.
Thanks for your report. Please add the Android version the session demo app is running on and the version of Media3 which is specifically important for this topic. I will then assume you didn't manually change the session demos targetSdkVersion.
With demo-session from this project (100%) :
- Play track
- Pause track
- Kill app
- Use a bluetooth command (e.g. play/pause from headphone)
- The app crashes after around 30 seconds.
Just for me to understand the theory. The session demo app does not use a MediaButtonReceiver. So from your understanding, what is starting the session demo app after the step Kill the app?
When you run adb shell dumpsys media_session after the step kill app, do you still see a session?
Since onTaskRemoved is called but onDestroy is not from PlaybackService,
This should not be indeed. Why do you think that onDestroy() is not called? What version of the session demo are you running? Do you still see the service not being terminated properly with the newest version? See also this comment and this commit
I tested on Android 13 from the origin/release branch. I did not modify the code, only added some log statements.
From my understanding, since the MediaSession is not released, then the mediaButtonIntent is not cancelled, resulting in the mediaButtonIntent being the cause of the app starting.
The onDestroy() method is not called immediately after I close the app. If I send a Bluetooth command before it is called, the app crashes.
So yeah calling stopself() as you did in origin/main in onTaskremoved() solved the issue.
Additionally, my demo-session app has been crashing even though I wasn't using it and I had closed the app several hours before. I am unsure of how to reproduce this issue as I was not trying to do so
Logs when app crashes
Logs when app crashes
androidx.media3.demo.session ----------------------------
2023-01-16 12:37:01.559 18892-18892 AudioMediaPlayerWrapper pid-18892 W The session was destroyed androidx.media3.demo.session
2023-01-16 12:37:01.559 18892-18892 MediaPlayerList pid-18892 D sessionUpdatedCallback(): packageName: androidx.media3.demo.session
2023-01-16 12:37:01.560 18892-18892 MediaPlayerList pid-18892 D Removing media player androidx.media3.demo.session
2023-01-16 12:37:01.560 18892-18892 MediaPlayerList pid-18892 D androidx.media3.demo.session doesn't have a browse service. Recycle player ID.
2023-01-16 12:37:01.562 4850-4850 smedia pid-4850 I SMediaSessionHelper.releaseActiveController(true): 'androidx.media3.demo.session'
2023-01-16 12:37:01.563 1529-4408 ActivityManager pid-1529 W Scheduling restart of crashed service androidx.media3.demo.session/.PlaybackService in 1000ms for start-requested
2023-01-16 12:37:01.563 4850-4850 smedia pid-4850 I SMediaSessionHelper.setActiveController(true): 'androidx.media3.demo.session' -> 'com.qobuz.music' [0]
2023-01-16 12:37:02.593 1529-1621 ActivityManager pid-1529 I Start proc 6290:androidx.media3.demo.session/u0a343 for service {androidx.media3.demo.session/androidx.media3.demo.session.PlaybackService}
2023-01-16 12:37:02.612 6290-6290 a3.demo.session pid-6290 I Late-enabling -Xcheck:jni
2023-01-16 12:37:02.668 1529-4408 ActivityManager pid-1529 W Stopping service due to app idle: u0a343 -27s89ms androidx.media3.demo.session/.PlaybackService
---------------------------- PROCESS STARTED (6290) for package androidx.media3.demo.session ----------------------------
2023-01-16 12:37:02.708 6290-6290 ziparchive androidx.media3.demo.session W Unable to open '/data/app/~~1znDYYxwlJkA7hGgj1NJeQ==/androidx.media3.demo.session-WJZPDymZrypATPytlSBleA==/base.dm': No such file or directory
2023-01-16 12:37:02.708 6290-6290 ziparchive androidx.media3.demo.session W Unable to open '/data/app/~~1znDYYxwlJkA7hGgj1NJeQ==/androidx.media3.demo.session-WJZPDymZrypATPytlSBleA==/base.dm': No such file or directory
2023-01-16 12:37:02.844 1529-4388 PendingIntentHolder pid-1529 D Sending KeyEvent { action=ACTION_DOWN, keyCode=KEYCODE_MEDIA_PLAY, scanCode=0, metaState=0, flags=0x0, repeatCount=0, eventTime=0, downTime=0, deviceId=-1, source=0x0, displayId=0 } to the last known PendingIntent PendingIntent{b9f9cea: PendingIntentRecord{bc14bdb androidx.media3.demo.session startForegroundService}}
2023-01-16 12:37:02.849 1529-4388 ActivityManager pid-1529 I Background started FGS: Allowed [callingPackage: androidx.media3.demo.session; callingUid: 10343; uidState: SVC ; intent: Intent { act=android.intent.action.MEDIA_BUTTON dat=androidx.media3.session.MediaSessionImpl:/... flg=0x10000000 cmp=androidx.media3.demo.session/.PlaybackService (has extras) }; code:MEDIA_BUTTON; tempAllowListReason:<,reasonCode:MEDIA_BUTTON,duration:10000,callingUid:1000>; targetSdkVersion:30; callerTargetSdkVersion:30; startForegroundCount:0; bindFromPackage:null]
2023-01-16 12:37:02.890 1529-4388 PendingIntentHolder pid-1529 D Sending KeyEvent { action=ACTION_UP, keyCode=KEYCODE_MEDIA_PLAY, scanCode=0, metaState=0, flags=0x0, repeatCount=0, eventTime=0, downTime=0, deviceId=-1, source=0x0, displayId=0 } to the last known PendingIntent PendingIntent{b9f9cea: PendingIntentRecord{bc14bdb androidx.media3.demo.session startForegroundService}}
2023-01-16 12:37:02.929 6290-6290 nativeloader androidx.media3.demo.session D Configuring classloader-namespace for other apk /data/app/~~1znDYYxwlJkA7hGgj1NJeQ==/androidx.media3.demo.session-WJZPDymZrypATPytlSBleA==/base.apk. target_sdk_version=30, uses_libraries=, library_path=/data/app/~~1znDYYxwlJkA7hGgj1NJeQ==/androidx.media3.demo.session-WJZPDymZrypATPytlSBleA==/lib/arm64, permitted_path=/data:/mnt/expand:/data/user/0/androidx.media3.demo.session
2023-01-16 12:37:02.941 6290-6290 GraphicsEnvironment androidx.media3.demo.session V ANGLE Developer option for 'androidx.media3.demo.session' set to: 'default'
2023-01-16 12:37:02.942 6290-6290 GraphicsEnvironment androidx.media3.demo.session V ANGLE GameManagerService for androidx.media3.demo.session: false
2023-01-16 12:37:02.942 6290-6290 GraphicsEnvironment androidx.media3.demo.session V Neither updatable production driver nor prerelease driver is supported.
2023-01-16 12:37:02.944 6290-6290 NetworkSecurityConfig androidx.media3.demo.session D No Network Security Config specified, using platform default
2023-01-16 12:37:02.944 6290-6290 NetworkSecurityConfig androidx.media3.demo.session D No Network Security Config specified, using platform default
2023-01-16 12:37:02.945 6290-6290 MultiDex androidx.media3.demo.session I VM with version 2.1.0 has multidex support
2023-01-16 12:37:02.945 6290-6290 MultiDex androidx.media3.demo.session I Installing application
2023-01-16 12:37:02.945 6290-6290 MultiDex androidx.media3.demo.session I VM has multidex support, MultiDex support library is disabled.
2023-01-16 12:37:02.945 6290-6290 ActivityThread androidx.media3.demo.session I handleStopService: token=android.os.BinderProxy@41b3328 not found.
2023-01-16 12:37:02.954 6290-6290 MusicService: androidx.media3.demo.session I onCreate
2023-01-16 12:37:02.971 6290-6290 ExoPlayerImpl androidx.media3.demo.session I Init 21b2841 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33]
2023-01-16 12:37:02.985 6290-6290 a3.demo.session androidx.media3.demo.session W Accessing hidden method Landroid/media/AudioTrack;->getLatency()I (unsupported, reflection, allowed)
2023-01-16 12:37:03.008 1529-1620 BroadcastQueue pid-1529 W Exported Denial: sending Intent { act=android.net.conn.CONNECTIVITY_CHANGE flg=0x4200010 (has extras) }, action: android.net.conn.CONNECTIVITY_CHANGE from null (uid=-1) due to receiver ProcessRecord{789cd8c 6290:androidx.media3.demo.session/u0a343} (uid 10343) not specifying RECEIVER_EXPORTED
2023-01-16 12:37:03.071 6290-6290 Compatibil...geReporter androidx.media3.demo.session D Compat change id reported: 160794467; UID 10343; state: DISABLED
2023-01-16 12:37:03.086 1529-4388 MediaSessionService pid-1529 D Media button session is changed to androidx.media3.demo.session/androidx.media3.session.id. (userId=0)
2023-01-16 12:37:03.090 18892-18892 MediaPlayerList pid-18892 I Adding wrapped media player: androidx.media3.demo.session at key: 12
2023-01-16 12:37:03.090 18892-18892 MediaPlayerList pid-18892 I onMediaKeyEventSessionChanged: token=androidx.media3.demo.session
2023-01-16 12:37:03.092 18892-18892 MediaPlayerList pid-18892 D setActivePlayer(): setting player to androidx.media3.demo.session
2023-01-16 12:37:03.095 18892-18892 AudioMediaPlayerWrapper pid-18892 V onQueueChanged(): androidx.media3.demo.session tried to update with no queue
2023-01-16 12:37:03.098 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=0, position=0, buffered position=0, speed=0.0, updated=77542300, actions=3669967, custom actions=[], active item id=0, error=null}
2023-01-16 12:37:03.099 18892-18892 MediaPlayerList pid-18892 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 12:37:03.099 18892-18892 MediaPlayerList pid-18892 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 12:37:03.099 6290-6290 MusicService: androidx.media3.demo.session I onDestroy
2023-01-16 12:37:03.099 6290-6290 ExoPlayerImpl androidx.media3.demo.session I Release 21b2841 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33] [media3.common, media3.exoplayer, media3.decoder, media3.session]
2023-01-16 12:37:03.101 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][0][null]
2023-01-16 12:37:03.102 18892-18892 MediaPlayerList pid-18892 I onMediaKeyEventSessionChanged: packageName=androidx.media3.demo.session
2023-01-16 12:37:03.102 18892-18892 MediaPlayerList pid-18892 W androidx.media3.demo.session is already the active player
2023-01-16 12:37:03.102 18892-18892 AudioMediaPlayerWrapper pid-18892 W The session was destroyed androidx.media3.demo.session
2023-01-16 12:37:03.102 18892-18892 MediaPlayerList pid-18892 D sessionUpdatedCallback(): packageName: androidx.media3.demo.session
2023-01-16 12:37:03.103 6290-6290 MusicService: androidx.media3.demo.session I onCreate
2023-01-16 12:37:03.103 1529-2784 ActivityManager pid-1529 W Service done with onDestroy, but executeNesting=2: ServiceRecord{5fb3e6a u0 androidx.media3.demo.session/.PlaybackService}
2023-01-16 12:37:03.103 6290-6290 ExoPlayerImpl androidx.media3.demo.session I Init 615b658 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33]
2023-01-16 12:37:03.103 18892-18892 MediaPlayerList pid-18892 D Removing media player androidx.media3.demo.session
2023-01-16 12:37:03.103 18892-18892 MediaPlayerList pid-18892 D androidx.media3.demo.session doesn't have a browse service. Recycle player ID.
2023-01-16 12:37:03.110 1529-4388 MediaSessionService pid-1529 D Media button session is changed to androidx.media3.demo.session/androidx.media3.session.id. (userId=0)
2023-01-16 12:37:03.114 18892-18892 MediaPlayerList pid-18892 I Adding wrapped media player: androidx.media3.demo.session at key: 12
2023-01-16 12:37:03.114 18892-18892 MediaPlayerList pid-18892 I onMediaKeyEventSessionChanged: token=androidx.media3.demo.session
2023-01-16 12:37:03.115 18892-18892 MediaPlayerList pid-18892 D setActivePlayer(): setting player to androidx.media3.demo.session
2023-01-16 12:37:03.115 6290-6290 MusicService: androidx.media3.demo.session I onStartCommand
2023-01-16 12:37:03.117 18892-18892 MediaPlayerList pid-18892 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 12:37:03.117 18892-18892 MediaPlayerList pid-18892 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 12:37:03.118 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][0][77542316]
2023-01-16 12:37:03.118 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:03.121 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][0][77542316]
2023-01-16 12:37:03.122 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:03.134 6290-6290 MusicService: androidx.media3.demo.session I onStartCommand
2023-01-16 12:37:03.142 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77542343, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:03.142 18892-18892 AudioMediaPlayerWrapper pid-18892 V trySendMediaUpdate(): Metadata has been updated for androidx.media3.demo.session
2023-01-16 12:37:03.143 1529-4388 MediaFocusControl pid-1529 I requestAudioFocus() from uid/pid 10343/6290 AA=USAGE_MEDIA/CONTENT_TYPE_UNKNOWN clientId=android.media.AudioManager@f707ab3androidx.media3.exoplayer.AudioFocusManager$AudioFocusListener@1b8f870 callingPack=androidx.media3.demo.session req=1 flags=0x0 sdk=30
2023-01-16 12:37:03.146 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77542348, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:03.146 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:04.611 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77542348]
2023-01-16 12:37:04.615 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:06.123 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77545322, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:06.123 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:07.610 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77545322]
2023-01-16 12:37:07.611 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:09.132 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77548327, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:09.132 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:10.625 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77548327]
2023-01-16 12:37:10.630 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:12.149 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77551347, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:12.150 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:13.634 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77551347]
2023-01-16 12:37:13.636 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:15.157 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77554356, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:15.157 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:16.638 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77554356]
2023-01-16 12:37:16.642 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:18.167 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77557367, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:18.167 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:19.643 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77557367]
2023-01-16 12:37:19.645 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:21.174 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77560373, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:21.178 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:22.659 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77560373]
2023-01-16 12:37:22.666 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:24.176 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77563377, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:24.176 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:25.670 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77563377]
2023-01-16 12:37:25.674 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:27.188 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77566385, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:27.193 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:28.684 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77566385]
2023-01-16 12:37:28.688 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:30.194 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77569394, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
2023-01-16 12:37:30.195 18892-18892 AudioMediaPlayerWrapper pid-18892 W onPlaybackStateChanged(): androidx.media3.demo.session tried to update with no new data
2023-01-16 12:37:31.693 4850-4850 smedia pid-4850 I SMediaSessionUtils.findPlayingItem(): [1] P -> [androidx.media3.demo.session][1][77569394]
2023-01-16 12:37:31.697 4850-4850 smedia pid-4850 I SMediaSessionUtils.findNonPlayingItem(): [1][androidx.media3.demo.session] META is NULL
2023-01-16 12:37:32.856 1529-1620 ActivityManager pid-1529 W Bringing down service while still waiting for start foreground: ServiceRecord{ccc3678 u0 androidx.media3.demo.session/.PlaybackService}
2023-01-16 12:37:32.863 6290-6290 MusicService: androidx.media3.demo.session I onDestroy
2023-01-16 12:37:32.863 6290-6290 ExoPlayerImpl androidx.media3.demo.session I Release 615b658 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33] [media3.common, media3.exoplayer, media3.decoder, media3.session]
2023-01-16 12:37:32.879 18892-18892 MediaPlayerList pid-18892 I onMediaKeyEventSessionChanged: packageName=androidx.media3.demo.session
2023-01-16 12:37:32.879 18892-18892 MediaPlayerList pid-18892 W androidx.media3.demo.session is already the active player
--------- beginning of crash
2023-01-16 12:37:32.885 6290-6290 AndroidRuntime androidx.media3.demo.session D Shutting down VM
2023-01-16 12:37:32.886 6290-6290 AndroidRuntime androidx.media3.demo.session E FATAL EXCEPTION: main
Process: androidx.media3.demo.session, PID: 6290
android.app.RemoteServiceException$ForegroundServiceDidNotStartInTimeException: Context.startForegroundService() did not then call Service.startForeground(): ServiceRecord{ccc3678 u0 androidx.media3.demo.session/.PlaybackService}
at android.app.ActivityThread.generateForegroundServiceDidNotStartInTimeException(ActivityThread.java:2005)
at android.app.ActivityThread.throwRemoteServiceException(ActivityThread.java:1976)
at android.app.ActivityThread.-$$Nest$mthrowRemoteServiceException(Unknown Source:0)
at android.app.ActivityThread$H.handleMessage(ActivityThread.java:2241)
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:7872)
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)
2023-01-16 12:37:32.888 18892-18892 AudioMediaPlayerWrapper pid-18892 W The session was destroyed androidx.media3.demo.session
2023-01-16 12:37:32.888 18892-18892 MediaPlayerList pid-18892 D sessionUpdatedCallback(): packageName: androidx.media3.demo.session
2023-01-16 12:37:32.890 18892-18892 MediaPlayerList pid-18892 D Removing media player androidx.media3.demo.session
2023-01-16 12:37:32.890 18892-18892 MediaPlayerList pid-18892 D androidx.media3.demo.session doesn't have a browse service. Recycle player ID.
2023-01-16 12:37:32.895 1529-1609 ActivityManager pid-1529 I Showing crash dialog for package androidx.media3.demo.session u0
2023-01-16 12:37:32.946 1529-1609 CoreBackPreview pid-1529 D Window{332fc2d u0 Application Error: androidx.media3.demo.session}: Setting back callback OnBackInvokedCallbackInfo{mCallback=android.window.WindowOnBackInvokedDispatcher$OnBackInvokedCallbackWrapper@63483e5, mPriority=0}
And to let you know, i wanted to share the log when i activate my bluetooth and the app is closed. It may explain why the app crashes after several hours.
Logs when bluetooth is activated
Logs when bluetooth is activated
2023-01-16 13:20:26.084 1529-1649 AppsFilter pid-1529 I interaction: PackageSetting{7b0b2ba androidx.media3.demo.session/10343} -> PackageSetting{9e6b20d com.instagram.android/10266} BLOCKED
2023-01-16 13:20:33.189 16518-16518 AvrcpBrows...yerWrapper pid-16518 I Wrapping Media Browser androidx.media3.demo.session
2023-01-16 13:20:33.351 9925-9925 MusicService: androidx.media3.demo.session I onCreate
2023-01-16 13:20:33.351 9925-9925 ExoPlayerImpl androidx.media3.demo.session I Init 228b205 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33]
2023-01-16 13:20:33.371 1529-3681 MediaSessionService pid-1529 D Media button session is changed to androidx.media3.demo.session/androidx.media3.session.id. (userId=0)
2023-01-16 13:20:33.376 9925-9925 MusicService: androidx.media3.demo.session I onBind
2023-01-16 13:20:33.521 16518-16518 MediaPlayerList pid-16518 I Adding wrapped media player: androidx.media3.demo.session at key: 6
2023-01-16 13:20:33.521 16518-16518 MediaPlayerList pid-16518 I onMediaKeyEventSessionChanged: token=androidx.media3.demo.session
2023-01-16 13:20:33.534 16518-16518 MediaPlayerList pid-16518 D setActivePlayer(): setting player to androidx.media3.demo.session
2023-01-16 13:20:33.559 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.559 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.563 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.563 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.567 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.567 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.572 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.572 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.589 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.589 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.651 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.651 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.689 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.689 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.721 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.721 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.777 16518-16518 AvrcpBrows...yerWrapper pid-16518 I onConnected: androidx.media3.demo.session is connected
2023-01-16 13:20:33.777 16518-16518 AvrcpBrows...rConnector pid-16518 D Browse player callback called: package=androidx.media3.demo.session : status=0
2023-01-16 13:20:33.787 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.787 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.798 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.798 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.802 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.802 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.819 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.819 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:33.851 16518-16518 AvrcpBrows...rConnector pid-16518 I Checking root contents for androidx.media3.demo.session
2023-01-16 13:20:33.860 9925-9925 MusicService: androidx.media3.demo.session I onDestroy
2023-01-16 13:20:33.863 9925-9925 ExoPlayerImpl androidx.media3.demo.session I Release 228b205 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33] [media3.common, media3.exoplayer, media3.decoder, media3.session]
2023-01-16 13:20:33.974 9925-9925 MusicService: androidx.media3.demo.session I onCreate
2023-01-16 13:20:33.974 9925-9925 ExoPlayerImpl androidx.media3.demo.session I Init 3d6c7b9 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33]
2023-01-16 13:20:33.981 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:33.981 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.016 16518-16518 MediaPlayerList pid-16518 I onMediaKeyEventSessionChanged: packageName=androidx.media3.demo.session
2023-01-16 13:20:34.016 16518-16518 MediaPlayerList pid-16518 W androidx.media3.demo.session is already the active player
2023-01-16 13:20:34.030 1529-4391 MediaSessionService pid-1529 D Media button session is changed to androidx.media3.demo.session/androidx.media3.session.id. (userId=0)
2023-01-16 13:20:34.040 9925-9925 MusicService: androidx.media3.demo.session I onBind
2023-01-16 13:20:34.074 16518-16518 AudioMediaPlayerWrapper pid-16518 W The session was destroyed androidx.media3.demo.session
2023-01-16 13:20:34.074 16518-16518 MediaPlayerList pid-16518 D sessionUpdatedCallback(): packageName: androidx.media3.demo.session
2023-01-16 13:20:34.080 16518-16518 MediaPlayerList pid-16518 D Removing media player androidx.media3.demo.session
2023-01-16 13:20:34.080 16518-16518 MediaPlayerList pid-16518 D androidx.media3.demo.session doesn't have a browse service. Recycle player ID.
2023-01-16 13:20:34.098 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.098 16518-16518 MediaPlayerList pid-16518 I Adding wrapped media player: androidx.media3.demo.session at key: 6
2023-01-16 13:20:34.098 16518-16518 MediaPlayerList pid-16518 I onMediaKeyEventSessionChanged: token=androidx.media3.demo.session
2023-01-16 13:20:34.100 16518-16518 MediaPlayerList pid-16518 D setActivePlayer(): setting player to androidx.media3.demo.session
2023-01-16 13:20:34.103 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.103 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.107 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.107 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.119 16518-16518 AvrcpBrows...yerWrapper pid-16518 I onConnected: androidx.media3.demo.session is connected
2023-01-16 13:20:34.119 16518-16518 AvrcpBrows...yerWrapper pid-16518 I getFolderItems: Connected to browsable player: androidx.media3.demo.session
2023-01-16 13:20:34.121 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.121 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.135 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.135 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.146 16518-16518 AvrcpBrows...rConnector pid-16518 I Successfully added package to results: androidx.media3.demo.session
2023-01-16 13:20:34.148 9925-9925 MusicService: androidx.media3.demo.session I onDestroy
2023-01-16 13:20:34.149 9925-9925 ExoPlayerImpl androidx.media3.demo.session I Release 3d6c7b9 [AndroidXMedia3/1.0.0-beta03] [cheetah, Pixel 7 Pro, Google, 33] [media3.common, media3.exoplayer, media3.decoder, media3.session]
2023-01-16 13:20:34.150 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.150 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.161 16518-16518 MediaPlayerList pid-16518 D onActiveSessionsChanged: controller: androidx.media3.demo.session
2023-01-16 13:20:34.161 16518-16518 MediaPlayerList pid-16518 D Already have a controller for the player: androidx.media3.demo.session, updating instead
2023-01-16 13:20:34.177 16518-16518 MediaPlayerList pid-16518 I onMediaKeyEventSessionChanged: packageName=androidx.media3.demo.session
2023-01-16 13:20:34.177 16518-16518 MediaPlayerList pid-16518 W androidx.media3.demo.session is already the active player
2023-01-16 13:20:34.177 16518-16518 AudioMediaPlayerWrapper pid-16518 W The session was destroyed androidx.media3.demo.session
2023-01-16 13:20:34.177 16518-16518 MediaPlayerList pid-16518 D sessionUpdatedCallback(): packageName: androidx.media3.demo.session
2023-01-16 13:20:34.178 16518-16518 MediaPlayerList pid-16518 D Removing media player androidx.media3.demo.session
2023-01-16 13:20:34.178 16518-16518 MediaPlayerList pid-16518 D androidx.media3.demo.session doesn't have a browse service. Recycle player ID.
2023-01-16 13:20:43.190 16518-16518 MediaPlayerList pid-16518 D Adding Browser Wrapper for androidx.media3.demo.session with id 6
Thanks for the logs.
I'm not sure whether changing the media button intent to use startService is the right approach, because in the play case we actually want to start the service in the foreground. We would then run into another exception in such a case.
For your reported case documented by the logs above I think the service has been crashed by the system:
2023-01-16 12:37:01.563 1529-4408 ActivityManager pid-1529 W Scheduling restart of crashed service androidx.media3.demo.session/.PlaybackService in 1000ms for start-requested
This happens because the service wasn't terminated when the user has removed the app from the list of tasks (aka. the user has killed the app). If the user does this while the service is not playing (aka the service is not in the foreground), the service needs to be properly terminated which you can do in onTaskRemoved.
I think the log line from above tells us that the user has removed the app from the list of recent apps and the ActivityManager crashes the service and restarts the service. I think then your service re-creates the session which puts the MediaButtonReceiver back in place. When the user then uses the media button on the BT headset, the session tries to start playback. The session exists but the player is still in STATE_IDLE, meaning it has an empty playlist and is not yet prepared. I conclude this from the logs at the moment when the BT command arrives that reports the session state:
2023-01-16 12:37:30.194 18892-18892 AudioMediaPlayerWrapper pid-18892 V onPlaybackStateChanged(): androidx.media3.demo.session : PlaybackState {state=1, position=0, buffered position=0, speed=0.0, updated=77569394, actions=3669967, custom actions=[Action:mName='Désactiver le mode aléatoire, mIcon=2131230853, mExtras=Bundle[EMPTY_PARCEL]], active item id=0, error=null}
state=1 => STOPPED, speed=0.0 => paused
So, the BT event now arrives and tries to start playback. If this would work, then the service is put in the foreground and we are all happy. However, the player is in state STATE_IDLE and can't start playback and accordingly the service is not put to foreground and produces the ForegroundServiceDidNotStartInTimeException that you report. I would expect this being a problem not only on Android 13 but since Android 8.
So unfortunately the answer to this report is that it's a bit more complicated and a bit more work for apps that want to support resuming playback after the app has been terminated by the user. The reasons is not that Media3 folks wants it like that, the reason is that Media3 needs to follow the platform restrictions to not make problems for apps. Full playback resumption support includes these three things:
- When the user terminates the app while playback being paused (while the service is not in Foreground), the service needs to be terminated.
If you see this line
2023-01-16 12:37:01.563 1529-4408 ActivityManager pid-1529 W Scheduling restart of crashed service androidx.media3.demo.session/.PlaybackService in 1000ms for start-requested
something isn't well.
- An app that wants to support resuming playback by BT headset media button after termination, must use a
MediaButtonReceiverto enable playback resumption. - An app that want to support resuming playback from the notification after termination, must implement playback resumption with a
MediaLibraryService/MediaBrowserService.
Summarizing this investigation I don't think there is a change in the service (like moving to an Intent from getService()) that would help. The current implementation works including playback resumption as explained above and there is no change that could make things easier for developers without running into exceptions that come from the restrictions around foreground services.
If there is a chance to make life easier for developers we are very happy to do that but as of now I don't know of such a case. Please tell me if you think differently.
In #299 the question was raised how an app can start playback when started by a BT headset play command with a media button receiver in place. In such a case the service is started with an Intent with action ACTION_MEDIA_BUTTON and an app needs to start playback to not run into a ForegroundServiceDidNotStartInTimeException.
There is currently no API for this. We are planning to add a media button receiver to Media3. When we do this we will probably add some API that makes the process easier. This is not a preview of that API, but simply a solution how apps can start playback after being started with a pending intent with action ACTION_MEDIA_BUTTON from a BT headset to avoid the ForegroundServiceDidNotStartInTimeException.
What worked for me in the session demo is the following. Roughly this includes:
- When the service is destroyed, the app needs to store the currently played item and the category that is playing (and probably the current playing position). It's up to the app what to store and how this is done. My sample code uses simple
SharedPreferencesto store and restore a basic media item. - The app overrides
onStartCommandand detects when theplaykey event is sent by the BT headset and the player has an empty playlist. - In this case the app adds the last recent media to the player and returns the result of
super.onStartCommand. The library will then prepare the player and callplaywith the first item. When thisplaycommand succeeds, the service is started in the foreground that prevents theForegroundServiceDidNotStartInTimeExceptionexception when started from BT headsets. - Then the app can, optionally, start an async load all the items that were in the last playlist. In the code below for the demo session, the album of the lat played item is loaded. Once loaded, the items of the last playlist are added to the player (the currently playing item is untouched to not interrupt playback).
The code below shows how I implemented this as a prototype with the PlaybackService of the session demo app. This is not a recommendation of the best way to do it, but a proof of concept that worked well for me when I tested with the session demo app. If you experience the ForegroundServiceDidNotStartInTimeException when started from BT headsets, this can be a way to avoid that.
This is a minimal sample that show the idea only. You may want to persist more data like the category, the current position and the like. You also want to sanitize (eg. null-checks when restoring data) the code better than this example :)
override fun onStartCommand(intent: Intent?, flags: Int, startId: Int): Int {
if (isMediaButtonPlayEvent(intent) && player.mediaItemCount == 0) {
val mediaItem = restoreLastRecentPlayedItem()
// Set a media item here to not fall into ENDED state when the player is prepared with an empty playlist
player.setMediaItem(mediaItem)
scope.launch {
// load category async
val mediaItems = loadCategory("[artist]${mediaItem.mediaMetadata.artist}")
// add all items of the category except the playing one is untouched to not interrupt playback
var currentIndex = 0
for (item in mediaItems!!) {
if (item.mediaId == player.currentMediaItem?.mediaId) {
break
}
currentIndex++
}
if (currentIndex > 0) {
player.addMediaItems(0, mediaItems.subList(0, currentIndex))
}
if (currentIndex < mediaItems.size - 1) {
player.addMediaItems(
currentIndex + 1,
mediaItems.subList(currentIndex + 1, mediaItems.size)
)
}
}
}
return super.onStartCommand(intent, flags, startId)
}
private fun isMediaButtonPlayEvent(intent: Intent?): Boolean {
intent ?: return false
if (intent.action == Intent.ACTION_MEDIA_BUTTON) {
val keyEvent = intent.getParcelableExtra<KeyEvent>(Intent.EXTRA_KEY_EVENT)
if (
keyEvent!!.keyCode == KeyEvent.KEYCODE_MEDIA_PLAY_PAUSE ||
keyEvent.keyCode == KeyEvent.KEYCODE_MEDIA_PLAY
) {
return true
}
}
return false
}
private fun saveLastRecentPlayedItem(mediaItem: MediaItem?) {
mediaItem ?: return
val preferences = getSharedPreferences(RECENT_ITEM_SHARED_PREF_NAME, Context.MODE_PRIVATE)
val editor = preferences.edit()
editor.putString(RECENT_ITEM_SHARED_PREF_KEY_MEDIA_ID, mediaItem.mediaId)
editor.putString(RECENT_ITEM_SHARED_PREF_KEY_URI, mediaItem.localConfiguration!!.uri.toString())
editor.putString(RECENT_ITEM_SHARED_PREF_KEY_TITLE, mediaItem.mediaMetadata.title.toString())
editor.putString(RECENT_ITEM_SHARED_PREF_KEY_ARTIST, mediaItem.mediaMetadata.artist.toString())
editor.putString(
RECENT_ITEM_SHARED_PREF_KEY_ARTWORK_URI,
mediaItem.mediaMetadata.artworkUri.toString()
)
editor.apply()
}
private fun restoreLastRecentPlayedItem(): MediaItem {
val preferences = getSharedPreferences(RECENT_ITEM_SHARED_PREF_NAME, Context.MODE_PRIVATE)
val mediaUri = Uri.parse(preferences.getString(RECENT_ITEM_SHARED_PREF_KEY_URI, ""))
val artworkUri = Uri.parse(preferences.getString(RECENT_ITEM_SHARED_PREF_KEY_ARTWORK_URI, ""))
val mediaId =
preferences.getString(RECENT_ITEM_SHARED_PREF_KEY_MEDIA_ID, UUID.randomUUID().toString())
val mediaMetadata =
MediaMetadata.Builder()
.setTitle(preferences.getString(RECENT_ITEM_SHARED_PREF_KEY_TITLE, ""))
.setArtist(preferences.getString(RECENT_ITEM_SHARED_PREF_KEY_ARTIST, ""))
.setArtworkUri(artworkUri)
.build()
return MediaItem.Builder()
.setUri(mediaUri)
.setMediaId(mediaId!!)
.setMediaMetadata(mediaMetadata)
.build()
}
private suspend fun loadCategory(parentId: String): List<MediaItem>? {
return withContext(Dispatchers.IO) {
Thread.sleep(1_000L)
MediaItemTree.getChildren(parentId)
}
}
Thanks for the code example.
Note that there are more potential KEYCODEs that would trigger this service as onStartCommand as well, besides KEYCODE_MEDIA_PLAY_PAUSE and KEYCODE_MEDIA_PLAY. Probably sufficient enough to check only on Intent.ACTION_MEDIA_BUTTON as action as condition.
I'm not sure I agree. I would be careful with selecting other events than play. The reason for this is that only a PLAY command will put the service into foreground. All other events will probably still result in a ForegroundServiceDidNotStartInTimeException.
I'm actually not sure where these other commands would come from. Can you clarify who you think would send such a ACTION_MEDIA_BUTTON that is not a play command when the app is not running? I haven't verified this, but I would expect that the system only delivers BT headset play commands when there is no active session. If you see that other key events are delivered to your service when the service/app is not yet started, can you please take a bug report and upload here so I can investigate this case? The reason is simply that in such a case there is not much an app can do to avoid the crash (except probably immediately terminating the service), so I'd think the system should drop all other events except play.
Not sure if someone mentioned it before, but here are the steps to reproduce ForegroundServiceDidNotStartInTimeException/ ANR: Context.startForegroundService() did not then call Service.startForeground()... in the demo-session app:
- Open demo-session app
- Click "Artist folder" then "The Kyoto Collection"
- Press the play button
- Press the pause button
- Hit the home button
- Run
adb shell am kill androidx.media3.demo.sessionin your terminal - Press play on the media notification
- Wait
- 💥
This is not a surprise. Without having tested this I think that in the scenario above onTaskRemoved is not called which is important to properly shut down the app and the service. The stale media notification still being there indicates that this is the case and the service wasn't destroyed.
Given the only way a user can terminate the app is by dismissing the activity from the recent apps, this method would be called and the app is terminated correctly. If you kill an app with adb which isn't a common way how users terminate the app, then the app is put in the inconsistent state that you describe.
The bug is that the notification is not removed and the reason for this is that the app is killed by a dev tool. I can imagine the same happens when you kill the app in the app info. There is a note that when doing this, apps may not properly work anymore.