Antennapod: Phantom Service is Running notification

[orionlee]

App version: Custom build off develop, including #2667 (and a few other changes not merged in develop)

Android version: 7.1.1

Device model: Motorola Moto E4

Current behaviour: Intermittently, AntennaPod produces a notification "Service is Running". For the latest one, I cannot swipe it away.

First occured: since #2667

An example sequence:

I cannot reliably reproduce it, here is the latest sequence leading to it.

1. Started AntennaPod
2. Clicked refresh button on Episodes screen
3. I then noticed the "Service is Running" notification. At the same time, the regular podcast download notification was also showing.
   
   
   
   • I am not sure if "Service is Running" notification appeared before or after clicking episode refresh button.
   
   

More details in the environment / sequences leading to it (in case it matters)

• The build is a debug build. (Though I also encountered the phantom notification in release build in different circumstances)
  
  
  
  • Auto download was enabled; automatic feed refresh was disabled.
  
  
  • It was not playing.
  
  
  • There was a in-progress episode in the queue.
  
  
• Before starting the debug build app, I had played some podcast using release build within the past 30 minutes or so. (The release build was not playing when debug build was started)
• On debug build, I exported and imported the database, restarted the app, and pressed Episode refresh button.

[ByteHamster]

I have improved the service in #2717. If you still have the problem with that branch, I need logcat output directly after the problem happens.

[orionlee]

I have picked up the changes in #2717, and I came across it again this morning from my debug build. (I have both debug and release installed).

@ByteHamster I will send you logcat output separately.

Sequences

• I have not used debug build for 1+ days.
• Happened in background:
  
  
  
  • ~8:40am: release build was run (by automation app)
  
  
  • ~8:50am: release build tried to auto update its subscriptions (AntennaPod's built-in schedule)
  
  

• In frontground:

  • ~9:00am: I turned on the screen, and noticed debug build notification that Service is running.
  • I could not swipe away the notification.
  • I opened the debug build, and verified its settings.
  • Later on, I found debug build's "Service is running" notification was replaced by AntennaPod's media playback notification (of the in-progress episode on debug build). I did not do any playback with debug build (and release build for that matter).

• Debug build settings:

  • Persistent playback control is on.
  • subscriptions auto update is disabled.
  • Auto media download is enabled (the queue is already full for any download)

One other observation that might have impact

• I came across (in a few occasion) when I have both debug and release build (both based on #2667) running scheduled subscriptions update (every 15 minutes, custom build), somehow the two ended up synchronized (with the new JobService-based update in #2667), updating at the same time.
• I first thought it might be something related to #2649 (debug/release interfering with one another). However, a check on JobService API documentation convinced me that is not the case.
• I could not reproduce it either, and dropped the matter.

[orionlee]

2. I encountered the "Service is Running" notification again. The sequence is almost the same as the comment above (checking the phone in the morning), except that both debug build and release build show "Service is Running" notifications.

• No logcat output available, as by the time I tried to collect them, they were gone.
• I also found the "Service is Running" notification is gone, once I start playing some podcasts: the normal media playback notification is then shown.

[orionlee]

More variations. @ByteHamster I will send the log to you separately.

4. The notification is probably not triggered by subscriptions update.
Similar to the sequence above, except I saw "Service is Running" notification, on both release and debug builds, before the daily morning subscriptions update on release build.

5. It is as if AntennaPod somehow tried to bring up media playback notification, without me starting any playback.
The details of the sequence

• I checked the phone after morning subscriptions update. There was no AntennaPod related notifications.
• I opened AntennaPod and checked my queue. I did not play anything.
• Sometime later (1-2 hours), I noticed AntennaPod notifications show up:
  
  
  
  • release build: Media playback notification (with the latest episode I played). I had not played anything by then though.
  
  
  • debug build: "Service is Running" notification.
  
  
• I had not tried done any playback by then, yet the notifications show up.

[ByteHamster]

I also found the "Service is Running" notification is gone, once I start playing some podcasts: the normal media playback notification is then shown

That is because the playback notification uses the same ID (it should replace the "Service is running" notification by design)

release build: Media playback notification (with the latest episode I played).

The playback notification with the latest episode you played instead of the "Service is running" notification is a good sign. That means that the service is actually stopped (you can swipe away the notification). That is significantly less bad than a notification that can not be swiped away.

[orionlee]

@ByteHamster I have validated your hypothesis that PlaybackService has been started even before API26 changes.

On my phone, I still have the official 1.6.5 build installed (but have not run for a while). I verified that the PlaybackService of the official 1.6.5 has also been silently started. ( with ActivityManager.getRunningServices() )

I also just noticed you made further commits in #2717, and will pick it up and test it.

[orionlee]

Phantom "Service is Running" notifications still show up, after I pick up commit c2ace741563f33d507ae7fd425ad659298cbd655 in #2717.

I checked logcat output, there is none with tag PlaybackService.

Just to be sure: I have added the commit to my debug build, but not release build. I don't think it matters, but if it does, please let me know.

@ByteHamster I plan to customize PlaybackService to trace its life cycle / notification points. Let me know if you have any specific suggestion, or if you are already on it.

[orionlee]

I created a custom build for debug, based on #2717 latest commit 9fb695822a49037a60bb4c0f0df005e262fa3b12, logging PlaybackService life cycle methods, notifications, start/stop foreground, and playback callbacks (controlling start/stop/etc) to a file. There should be some usable logs within a day or so.

In scanning the codes, I noticed there are 2 parallel code paths handling a logical stop that seem to be doing similar things, but I am not familiar with PlaybackService enough to be sure if they are (logically) the same:

In mediaPlayerCallback object's statusChanged() method:

// just recently re-introduced in #2717, used to be NO-OP in 1.6.5
                case STOPPED:
                    writePlaybackPreferencesNoMediaPlaying();
                    stopSelf();
                    break;

In handleKeycode() method:

            case KeyEvent.KEYCODE_MEDIA_STOP:
                if (status == PlayerStatus.PLAYING) {
                    mediaPlayer.pause(true, true);
                    started = false;
                }

                stopForeground(true); // gets rid of persistent notification
                return true;

[orionlee]

I located the problem, with some logs from a custom build based on #2717.

The logs are attached to the end. The sequence leading to phantom "Service is Running" (on PlaybackService)

• onCreated() invoked, creating the "Service is running" notification (startForeground() with createBasicNotification())
• onStartCommand() invoked, with intent extras including keyCode:127 (KEYCODE_MEDIA_PAUSE), and playable:null
• onStartCommand() ultimately calls setupNotification(null) , which returns with no-op.
• stopForeground() was never called by the end of the sequence.

So I think in setupNotification(), when there is nothing to be played, it can call stopForeground(true) before return, in line 1221 (for this specific case), and in line 1232 (similar logic).

A caveat is I don't know for sure if calling stopForeground() will result in exception when the service is not in foreground state - I don't believe so but not 100% sure.

Relevant log:

6/9/18 2:05:02 AM PDT  D/PlaybackService  Service created.
6/9/18 2:05:02 AM PDT  D/PlaybackService    in createBasicNotification()
6/9/18 2:05:02 AM PDT  D/PlaybackService    startForegroundAndLog() - id:1 , notification:Notification(pri=-2 contentView=null vibrate=null sound=null defaults=0x0 flags=0x0 color=0x00000000 vis=PRIVATE)
6/9/18 2:05:02 AM PDT  D/PlaybackService  OnStartCommand called. intent:Intent { cmp=de.danoeh.antennapod.debug/de.danoeh.antennapod.core.service.playback.PlaybackService (has extras) } , keyCode:127 , castDisconnect:false , playable:null ; flags:0 , startId:1
6/9/18 2:05:02 AM PDT  D/PlaybackService    Handling keycode: 127
6/9/18 2:05:02 AM PDT  D/PlaybackService    in setupNotification() - playable:null

[orionlee]

It'd be cleaner if the code can states explicitly that if there is nothing to play, call stopForeground(true).

[orionlee]

One more thought about the issue:
(@ByteHamster probably has a good answer that I miss. But I'm raising it here just in case).

The phantom "Service is Running" stems from that starting with #2667 , onCreate() creates a foreground service notification (that wasn't there before #2667), to address Android 8 background service limiting.

My thought is: can we do away the (early) creation of foreground service notification in onCreate()? More specifically, wouldn't it be sufficient to guarantee that by the end on onStartCommand(), a foreground service notification is created (when there is something to be played) ?

My reasoning is as follows: PlaybackService can be used accessed via two means, starting the service, or binding to it.

• case starting the service: onStartCommand() is invoked, so if it can guarantee that a foreground service notification is there (when there is something to be played) by the end of the call, PlaybackService won't be killed prematurely.

• case binding to the service: onBind() is invoked. Android system still guarantees the service will remain available until it is unbound. There is no need to create foreground service notification in this scenario.

[ByteHamster]

can we do away the (early) creation of foreground service notification in onCreate()? More specifically, wouldn't it be sufficient to guarantee that by the end on onStartCommand(), a foreground service notification is created (when there is something to be played)?

Would be possible, but in this case we have to ensure that in every case, within 5 seconds, a notification is displayed or the service is stopped. Otherwise, it will crash and display a "App stopped working" message.

case binding to the service: onBind() is invoked

I changed the service recently that it is only started and bound to if it is actually playing. Therefore, we need the notification anyway.

So I think in setupNotification(), when there is nothing to be played, it can call stopForeground(true) before return, in line 1221 (for this specific case), and in line 1232 (similar logic).

Just doing that will let the notification flicker when pressing pause deliberately. I just added the following, hoping that it does not break anything...

if (!started) {
   stopSelf();
}

Would you mind trying it out? :)

[ByteHamster]

I have not seen the notification for months. If the issue is not resolved, feel free to re-open.

[kriegaex]

Version 1.7.1, Galaxy S7, Android 8. The message "service is running" appeared today, I cannot swipe it away. Please re-open.

[orionlee]

I have not seen the problem for a while.

@kriegaex A possible temporary workaround is to launch AntennaPod, play something and stop. The message should be replaced by a regular media playback notification that can be swiped.

[kriegaex]

I got rid of it for now by opening settings - apps - AntennaPod - force exit (or whatever it is called in English). Basically I killed the process. After restarting it once, until now the message has not re-appeared, but it was only half a day so far. Please investigate where the message comes from in a non-beta version and under which circumstances it might be shown. Thanks.

[kriegaex]

It just occurred again, so shutting the app down completely was not really helpful.

[orionlee]

@kiregaex Could you obtain relevant logcat log (those with PlaybackService tag)? It will require you to install a debug build on your device.

If getting log is not possible, I have two thoughts.. @ByteHamster, your thoughts?

1. In PlaybackService.setupNotification(), there is a code branch that the currently does not stopService() that we might want to add one.

    private synchronized void setupNotification(final Playable playable) { // Line 1212
...
                if (!Thread.currentThread().isInterrupted() && started) {
......
                } else if (!started) {   // <-- add this
                        stopService();   // <-- add this
                }
......
}                

I am not sure if it's the cause of the cases @kriegaex reported, but adding it should not hurt at the minimal.

1. @ByteHamster in the past you mentioned that it is possible to remove the startForeground() call in onCreate(), the initiator of the "Service is running" notification, as long as "we have to ensure that in every case, within 5 seconds, a notification is displayed or the service is stopped. Otherwise, it will crash and display a "App stopped working" message."

   a. Are you concerned onStartCommand() implementation might miss some cases? Or,
   b. is the "Service is running" notification a defensive measure to avoid the app from crashing in case there are bugs in other parts of the code?

[kriegaex]

I am sorry, but on my device I will not install anything other than what I can get from the Google Play store. It is not rooted and I am not an Android developer. I would be comfortable with testing, even debugging snapshots or betas on my PC, but not on my mobile phone. I do not have proper tooling set up for it anyway.

[orionlee]

So far it looks like any fix can't be really tested without @kriegaex , which needs to involve an official alpha/beta test. I can't speak for such test. @ByteHamster or @mfietz can address it better.

[ByteHamster]

In PlaybackService.setupNotification(), there is a code branch that the currently does not stopService() that we might want to add one.

Adding the code as you suggested is the same as just moving the if statement outside the thread. I did that in #2934. I did not yet notice problems but I am also not sure if it helps.

a. Are you concerned onStartCommand() implementation might miss some cases? Or,
b. is the "Service is running" notification a defensive measure to avoid the app from crashing in case there are bugs in other parts of the code?

To be honest, I forgot why I did that :sweat_smile: I just remember that it was once in onStartCommand and I moved it to onStartCommand. We are obviously missing some cases if the notification still appears.

[orionlee]

@ByteHamster I am trying to tackle the problem from a different angle: Given PlaybackService start/stop/notification logic is dispersed and somewhat hard to reason, I take a look at a Google's sample apps that should do similar things that seem to have a clearer logic:

https://github.com/googlesamples/android-MediaBrowserService/blob/master/Application/src/main/java/com/example/android/mediasession/service/MusicService.java

(Assuming it works correctly on Android 8+ devices. I can't verify but it seems to be so)

---

The sample's service state logic is easier to understand: in essence, service state changes upon playback state, i.e., onPlaybackStateChange(PlaybackStateCompat)

• PLAYING: startForegroundService() (if not started already); startForeground() aka make it foreground and show notification
• PAUSED: stopForeground(false) ; update notification
• STOPPED: stopForeground(true) ; stopSelf()

There is no special code to preemptively start the service in foreground (with dummy notification) in onCreate(). I think the initial playback goes into the following sequence.

1. Service's onCreate()
2. soon afterwards, the actual playing started, it goes to PLAYING playback state
3. Upon reaching PLAYING state, make the service a foreground.

As long as steps 1 - 3 never takes more than 5 seconds, the service will stay foreground successfully.

---

If such approach is promising, we can adapt it to PlaybackService, centralizing all foreground service / notification code in a ServiceStateManager inner class , and invokes it upon playback state changes, which might be one of the following:

1. sessionCallback member's onPlay() methods, etc.
2. mediaPlayerCallback (a PlaybackServiceMediaPlayer.PSMPCallback) member's statusChanged() method. It is closer to what the sample does.

[orionlee]

@ByteHamster I probably can try to fix the issue cleanly using the above approach in 1 - 2 weeks. Let me know your thoughts.

[ByteHamster]

I will probably not have time in the next few weeks. Sounds great to have the playback service cleaned up. Not really happy with my PR myself.

[orionlee]

@ByteHamster I'll try to do some prototype in the next few days. Then I'll have a better sense of if the approach is sound.

[orionlee]

I looked more into the codes.

AntennaPod also starts playing differently from Google sample app. If AntennaPod can use the approach in Google sample, I believe service start/stop logic can be cleaned up as suggested above with a centralized ServiceStateManager.

In showing player UI, AntennaPod (in PlaybackController) does startForegroundService() upon showing the UI before doing any playing, while Google Sample App does only bindService(), and upon playing the media, startForegroundService().

@ByteHamster is there any reason that AntennaPod cannot mimic Google Sample? By using Google Sample's approach, no code outside PlaybackService needs to deal with service start/stop, which then allows it to use the centralized ServiceStateManager within PlaybackService to manage it.

The comparison of the flow:

| | | AntennaPod | Google Sample App |
| ------ | ------ | ------ | ------ |
| During Player UI initialization, in PlaybackController |
| | | startForegroundService() | bindService() |
| | |  in Service:
 create Notification during onCreate() | |
| | | bindService() | |
| Upon pressing play/pause button, in PlaybackController |
| | | call service to play | call service to play |
| | | |  in Service:
 1) startForegroundService()
 2) create Notification |

Note: Google Sample's (rough) equivalent of PlaybackController is MediaBrowserHelper. It uses MediaBrowserCompat and MediaControllerCompat to indirectly access the service while AntennaPod's PlaybackController access the service directly.

[hanswundersam]

I can confirm the same issue on a Pixel phone with LineageOS 16 (Android 9 but without Gapps) and AntennaPod 1.7.2b from F-droid. The app seems to randomly pop up a "Service is running" notification with no user interaction and no way to remove it except by killing AntennaPod.

[ByteHamster]

You can just play a podcast and pause it to make the notification go away.

Unfortunately, it is hard to fix this issue without log files. I would be happy to get a logcat output directly after the notification shows from someone who has this issue.

[hanswundersam]

Thank you @ByteHamster, play and pause indeed works around it. I've never used logcat but will read it up, try to create one and send you the output. Thanks a million for your contributions to AntennaPod and other code!

[mnoram]

logcat.txt

App version: 1.7.2b commit b89271329
Android version: 9
Device model: Samsung Galaxy S9+
Current behaviour: Was attached to car stereo and playing through Android Auto interface by USB. During this bluetooth headset was also attached but not being used. Auto pause on disconnect from car USB. 30+ minutes later the paused notification of currently playing podcast was still shown (I think). Pushed "play" on the bluetooth headset and the playing notification disappeared and was replaced by the "Service is Running" notification. Upon clicking this Antennapod opened to a completely blank/empty "currently playing" screen. Click the back arrow at top left to go to queue and clicked play on the top item. Everything went back to normal.

I tried to grab the logcat but I'm not sure I got there in time. Its not a "crash" per se so I think the logcat only started capturing when I opened the logs app.

[ByteHamster]

Thanks a lot, @mnoram. I will go over the logs as soon as I have time. This might take a bit, though.

[ByteHamster]

Thanks!! I just looked at the logs (because I was curious and couldn't keep my hands off it). I can finally reproduce the problem! That will allow to finally fix this bug. Steps to reproduce:

• Start AntennaPod
• Finish playing last item in queue (so that the ExternalPlayerFragment goes away)
• Force stop AntennaPod
• Send media button play event:
  > adb shell am start-foreground-service --ei de.danoeh.antennapod.core.service.extra.MediaButtonReceiver.KEYCODE 126 de.danoeh.antennapod.debug/de.danoeh.antennapod.core.service.playback.PlaybackService

[mnoram]

Just leaving an FYI. I switched media player from Sonic to Exoplayer, which solved an Android Auto missing buttons issue, but the same behavior persisted. While playing I turned car off. Then pressed play button on Bluetooth headset and the "service is running" notification appeared but nothing played.

[dcjkfgdjhd]

I have the same issue.

Sometimes the service just appears randomly.

But what also seems to cause it, is the following: When AntennaPod is completely inactive (app closed, no notification) and if I then send a "Media Control: Pause" command to AntennaPod from Tasker.

What makes this so annoying, is that Android does not allow me to hide that notification. It does not appear individually as a notification type in the Android notification dialogue. So it only goes away if I _completely_ disallow AntennaPod to show _any_ notifications, which I don't want to do.

[devinberg]

I've just started experiencing this issue over the last few days. Running version 1.8.3 on Android 9.

[flavorjones]

@devinberg see 0b60a8a which recently tried to address this.

[sebastianelsner]

I am having this issue as well. The advice ("play an episode and contact us.") in the commit mentioned above works. Contacting via this channel :)

[ByteHamster]

Thanks @sebastianelsner! Sounds like you are using AntennaPod 2.0.0, which I thought should no longer display the notification. If you do use 2.0.0, could you please create a new issue for that? Then we can analyze the problem (which probably has a different cause than the one originally reported+fixed here).

[kriegaex]

2.0.0? My version is 1.8.1, the Google Play store does not seems to have a more recent version. What am I missing here?

[ByteHamster]

@kriegaex 2.0.0 is currently available for 50% of the users who joined the beta channel and will be rolled out to everyone as soon as possible.

[sebastianelsner]

The version I use is 1.8.1. If its fixed in 2.0 please ignore me :)