Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

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

Closed
ghost opened this issue Feb 20, 2017 · 20 comments
Closed

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

ghost opened this issue Feb 20, 2017 · 20 comments

Comments

@ghost
Copy link

ghost commented Feb 20, 2017

Sometimes (not always), when switching to the next track, a null pointer exception occurs at this line:
https:/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
Copy link
Author

ghost commented Feb 20, 2017 •
edited by ghost
Loading

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
Copy link
Member

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 added a commit that referenced this issue Feb 20, 2017
@djselbeck
Possible fix for race condition of issue #48 in GaplessPlayer
633dd54
@djselbeck
Copy link
Member

djselbeck commented Feb 20, 2017 •
edited
Loading

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.

djselbeck added a commit that referenced this issue Feb 20, 2017
@djselbeck
Possible fix for race condition of issue #48 in GaplessPlayer
853f298
@ghost
Copy link
Author

ghost commented Feb 21, 2017 •
edited by ghost
Loading

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
Copy link
Member

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

@ghost
Copy link
Author

ghost commented Feb 21, 2017

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
Copy link
Author

ghost commented Feb 21, 2017

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
Copy link
Author

ghost commented Feb 21, 2017

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
Copy link
Member

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
Copy link
Author

ghost commented Feb 21, 2017

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
Copy link
Member

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

@ghost
Copy link
Author

ghost commented Feb 21, 2017

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

@ghost
Copy link
Author

ghost commented Feb 21, 2017

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
Copy link
Member

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 added a commit that referenced this issue Feb 21, 2017
@djselbeck
Issue #48, start second MP if it became the primary MP before finishi…
3d457db 
…ng preparing as a workaround
@djselbeck
Copy link
Member

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
Copy link
Author

ghost commented Feb 23, 2017

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
Copy link
Member

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

If it reoccurs feel free to write again :)

@ghost
Copy link
Author

ghost commented Feb 24, 2017

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

@djselbeck
Copy link
Member

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
Copy link
Member

gnome17 commented Feb 24, 2017

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.

@gnome17 gnome17 closed this as completed Feb 24, 2017
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@djselbeck @gnome17