search

gateship-one / odyssey

Odyssey music player
GNU General Public License v3.0
235 stars 39 forks source link

java.lang.NullPointerException when switching to next track #48

Closed ghost closed 7 years ago

ghost commented 7 years ago

Sometimes (not always), when switching to the next track, a null pointer exception occurs at this line: https://github.com/gateship-one/odyssey/blob/master/app/src/main/java/org/gateshipone/odyssey/playbackservice/GaplessPlayer.java#L491 (I don't have the exception traceback atm, will attach when I get the error again.) My suggestion is to check mCurrentPlayer against null and if it is null just assign mNextPlayer to mCurrentPlayer and start playing mCurrentPlayer.

ghost commented 7 years ago

The logcat output:

02-20 07:16:29.280 27257 27257 E AndroidRuntime: java.lang.NullPointerException: Attempt to invoke virtual method 'void android.media.MediaPlayer.setNextMediaPlayer(android.media.MediaPlayer)' on a null object reference
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at org.gateshipone.odyssey.playbackservice.GaplessPlayer$2.onPrepared(GaplessPlayer.java:491)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at android.media.MediaPlayer$EventHandler.handleMessage(MediaPlayer.java:2872)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at android.os.Handler.dispatchMessage(Handler.java:102)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at android.os.Looper.loop(Looper.java:154)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at android.app.ActivityThread.main(ActivityThread.java:6176)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at java.lang.reflect.Method.invoke(Native Method)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-20 07:16:29.280 27257 27257 E AndroidRuntime:        at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)

EDIT: formatting

djselbeck commented 7 years ago

Thanks for providing this crash report and especially the stack backtrace. We'll investigate.

It looks like the callback for the second MP is trying to access the primary MP that is not available any longer (for some reason)

djselbeck commented 7 years ago

Are you able to reproduce the issue? If yes I would like to send you an test apk with the commit above applied?

Updated Here is an APK of it: https://owncloud.djselbeck.de/index.php/s/ws5ttxEO7LusZIp

It is signed with the release key so depending on your install (F-Droid or Google) you need to reinstall.

ghost commented 7 years ago

Thanks for your quick response. I tried the APK you gave me, however the issue still persists, though it seems it is at a different place this time:

02-21 12:50:29.096 24949 24949 V OdysseyGaplessPlayer: MyPid: 24949 MyTid: 24949
02-21 12:50:29.104  2871  2916 W AppOps  : Finishing op nesting under-run: uid 1000 pkg android code 24 time=0 duration=0 nesting=0
02-21 12:50:29.255 24408 24408 W System.err: android.os.RemoteException
02-21 12:50:29.266 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.getPBS(PlaybackServiceConnection.java:103)
02-21 12:50:29.267 24408 24408 W System.err:    at org.gateshipone.odyssey.adapter.CurrentPlaylistAdapter.<init>(CurrentPlaylistAdapter.java:59)
02-21 12:50:29.267 24408 24408 W System.err:    at org.gateshipone.odyssey.views.CurrentPlaylistView.registerPBServiceConnection(CurrentPlaylistView.java:78)
02-21 12:50:29.267 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView$ServiceConnectionListener.onConnect(NowPlayingView.java:1280)
02-21 12:50:29.267 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.onServiceConnected(PlaybackServiceConnection.java:67)
02-21 12:50:29.267 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-21 12:50:29.267 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-21 12:50:29.267 24408 24408 W System.err:    at android.os.Handler.handleCallback(Handler.java:751)
02-21 12:50:29.267 24408 24408 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-21 12:50:29.267 24408 24408 W System.err:    at android.os.Looper.loop(Looper.java:154)
02-21 12:50:29.268 24408 24408 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:6176)
02-21 12:50:29.268 24408 24408 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
02-21 12:50:29.268 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-21 12:50:29.268 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)
02-21 12:50:29.273 24408 24408 W System.err: android.os.RemoteException
02-21 12:50:29.273 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.getPBS(PlaybackServiceConnection.java:103)
02-21 12:50:29.273 24408 24408 W System.err:    at org.gateshipone.odyssey.views.CurrentPlaylistView.registerPBServiceConnection(CurrentPlaylistView.java:86)
02-21 12:50:29.273 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView$ServiceConnectionListener.onConnect(NowPlayingView.java:1280)
02-21 12:50:29.273 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.onServiceConnected(PlaybackServiceConnection.java:67)
02-21 12:50:29.273 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-21 12:50:29.274 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-21 12:50:29.274 24408 24408 W System.err:    at android.os.Handler.handleCallback(Handler.java:751)
02-21 12:50:29.274 24408 24408 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-21 12:50:29.274 24408 24408 W System.err:    at android.os.Looper.loop(Looper.java:154)
02-21 12:50:29.274 24408 24408 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:6176)
02-21 12:50:29.274 24408 24408 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
02-21 12:50:29.274 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-21 12:50:29.274 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)
02-21 12:50:29.275 24408 24408 W System.err: android.os.RemoteException
02-21 12:50:29.275 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.getPBS(PlaybackServiceConnection.java:103)
02-21 12:50:29.275 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.updateStatus(NowPlayingView.java:1046)
02-21 12:50:29.276 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.access$2500(NowPlayingView.java:76)
02-21 12:50:29.276 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView$ServiceConnectionListener.onConnect(NowPlayingView.java:1283)
02-21 12:50:29.276 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.onServiceConnected(PlaybackServiceConnection.java:67)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Handler.handleCallback(Handler.java:751)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Looper.loop(Looper.java:154)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:6176)
02-21 12:50:29.276 24408 24408 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
02-21 12:50:29.276 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-21 12:50:29.276 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)
02-21 12:50:29.282 24408 24408 W System.err: android.os.RemoteException
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.getPBS(PlaybackServiceConnection.java:103)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.updateTrackPosition(NowPlayingView.java:1171)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.updateStatus(NowPlayingView.java:1101)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.access$2500(NowPlayingView.java:76)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView$ServiceConnectionListener.onConnect(NowPlayingView.java:1283)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.onServiceConnected(PlaybackServiceConnection.java:67)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Handler.handleCallback(Handler.java:751)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-21 12:50:29.276 24408 24408 W System.err:    at android.os.Looper.loop(Looper.java:154)
02-21 12:50:29.276 24408 24408 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:6176)
02-21 12:50:29.276 24408 24408 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
02-21 12:50:29.276 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-21 12:50:29.276 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)
02-21 12:50:29.282 24408 24408 W System.err: android.os.RemoteException
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.getPBS(PlaybackServiceConnection.java:103)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.updateTrackPosition(NowPlayingView.java:1171)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.updateStatus(NowPlayingView.java:1101)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView.access$2500(NowPlayingView.java:76)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.views.NowPlayingView$ServiceConnectionListener.onConnect(NowPlayingView.java:1283)
02-21 12:50:29.283 24408 24408 W System.err:    at org.gateshipone.odyssey.playbackservice.PlaybackServiceConnection.onServiceConnected(PlaybackServiceConnection.java:67)
02-21 12:50:29.284 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher.doConnected(LoadedApk.java:1453)
02-21 12:50:29.284 24408 24408 W System.err:    at android.app.LoadedApk$ServiceDispatcher$RunConnection.run(LoadedApk.java:1481)
02-21 12:50:29.284 24408 24408 W System.err:    at android.os.Handler.handleCallback(Handler.java:751)
02-21 12:50:29.284 24408 24408 W System.err:    at android.os.Handler.dispatchMessage(Handler.java:95)
02-21 12:50:29.284 24408 24408 W System.err:    at android.os.Looper.loop(Looper.java:154)
02-21 12:50:29.284 24408 24408 W System.err:    at android.app.ActivityThread.main(ActivityThread.java:6176)
02-21 12:50:29.284 24408 24408 W System.err:    at java.lang.reflect.Method.invoke(Native Method)
02-21 12:50:29.284 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit$MethodAndArgsCaller.run(ZygoteInit.java:888)
02-21 12:50:29.284 24408 24408 W System.err:    at com.android.internal.os.ZygoteInit.main(ZygoteInit.java:778)
djselbeck commented 7 years ago

Thanks for your time in investigating this, is this the complete crash log? Looks like there might be missing something above?

ghost commented 7 years ago

No problem. I think this is the full log but I can test it again in half an hour and see if there's anything else.

ghost commented 7 years ago

Now, I got this error instead:

02-21 17:28:56.678 27740 27756 E AndroidRuntime: FATAL EXCEPTION: OdysseyPBSHandler
02-21 17:28:56.678 27740 27756 E AndroidRuntime: Process: org.gateshipone.odyssey:serviceProcess, PID: 27740
02-21 17:28:56.678 27740 27756 E AndroidRuntime: java.lang.NullPointerException: Attempt to invoke virtual method 'void android.media.MediaPlayer.setNextMediaPlayer(android.media.MediaPlayer)' on a null object reference
02-21 17:28:56.678 27740 27756 E AndroidRuntime:        at org.gateshipone.odyssey.playbackservice.GaplessPlayer$2.onPrepared(GaplessPlayer.java:504)
02-21 17:28:56.678 27740 27756 E AndroidRuntime:        at android.media.MediaPlayer$EventHandler.handleMessage(MediaPlayer.java:2872)
02-21 17:28:56.678 27740 27756 E AndroidRuntime:        at android.os.Handler.dispatchMessage(Handler.java:102)
02-21 17:28:56.678 27740 27756 E AndroidRuntime:        at android.os.Looper.loop(Looper.java:154)
02-21 17:28:56.678 27740 27756 E AndroidRuntime:        at android.os.HandlerThread.run(HandlerThread.java:61)

It seems like the same error happened.

ghost commented 7 years ago

Also, I didn't write out my device details, would that help? Android Version: 7.1.1 ROM: Resurrection Remix Device: GT-I9300 (Samsung Galaxy S3)

djselbeck commented 7 years ago

Really strange. Should not be happening, I have to recheck every edge case. Of course a if(null != ...) could help but actually it really shouldn't occur :).

ghost commented 7 years ago

The weird thing is, it happens completely randomly. It sometimes plays fine for an entire day and starts crashing every 2 songs the next day. Anyway, thanks for spending time on this.

djselbeck commented 7 years ago

Just to be sure. Does this happen when manually switching to the next track or when a track finishes and the next starts?

ghost commented 7 years ago

It only happens when the track automatically changes, if I change the track myself it never crashes.

ghost commented 7 years ago

I should also mention that this also only happens when Odyssey is in the background and/or swiped off in the recents list. We already know it is a PlaybackService issue, maybe this is ART going a bit overboard and GC'ing mCurrentPlayer when it finishes playing?

djselbeck commented 7 years ago

Ok, I assumed the other case. Now I think I know what happens on your Phone.

Usually it is: Primary MP prepare async -> Primary MP prepared: start playback, start next song preparing (second MP) -> Second MP prepared | Until here it should be done within seconds (at most). After playback of the song android automatically switches to next song.

Now for your phone it has to be like: Primary MP prepare async -> Primary MP prepared: start playback, start next song preparing (second MP) -> Second MP not prepared when the song finishes. The current MP is released and nulled, the old second MP now starts actual preparing and finishes but now current MP is not available anymore -> crash.

This can be the only case where mCurrentMediaPlayer is null. The case that the second MP prepares after the primary MP is finished never happend to any of our devices and is simply not implemented.

We can do it but actual it is a bit weird that this happens. Looks like your MediaPlayer is blocked some how. I'll think about a workaround. Should be possible to catch this and start the second MP then.

The GC cannot wipe the current MP if GaplessPlayer holds a reference to it. Are you absolutely sure this only happens in the background? Sounds like a coincidence

djselbeck commented 7 years ago

https://owncloud.djselbeck.de/index.php/s/fzC9ViB4pVgJrYs include a new test version with the WO above.

I can only debug with the head so I can not guarantee any progress ;). Please report back if it changes anything.

ghost commented 7 years ago

Sorry for not replying yesterday. The last APK you gave me fixed it I think, no crashes so far. Also I think the second player not loading might be my phone being outdated ;P

djselbeck commented 7 years ago

Thanks for your response. Glad to hear that the issue has disappeared.

If it reoccurs feel free to write again :)

ghost commented 7 years ago

Which release are you pushing this as? I'd be really glad if you pushed this bugfix to F-Droid.

djselbeck commented 7 years ago

We are releasing a new version today. If we integrate this fix or not is not yet set. But if not we try to release it as fast as possible.

gnome17 commented 7 years ago

We released a new version which includes the fix for your issue. It will be available on F-Droid in the next few days we think.

If your issue reoccurs please reopen the issue.