Playback views not updating in app

[joemarshall]

On the android app version. Android 5.1.

I select a Spotify playlist, and either play the playlist, or play one song off it, and it plays fine. But the tracks and now playing views don't update to show it.

If I close and reopen the app the views are fine, but they don't update again. If I click next track, view doesn't update either.

The debug log shows event playback state changed messages coming through, it's just like they're not triggering view updates.

[tkem]

Thanks for reporting! Since there are several versions of the Android app in use, can you please confirm this is version 1.6.2 (as shown on the About page). You also mentioned in PM that this issue does not exist when you use the Web client version of Mopidy Mobile (installed on the server). Is this correct?

[joemarshall]

Yep 1.6.2 and web client running in chrome is fine.

[tkem]

This is very strange, since basically there's not much of a difference between the Web client and the Android app.

[tkem]

Tried to reproduce this with current version of the app, but no luck. Since you do not have this issue with the Web client, this might be related to network issues. Do you see any connection-related messages in the log, such as "reconnecting, or do you experience this every time you use Mopidy Mobile? Did this work for you in previous versions of the app, if any?

[joemarshall]

Oh, messed around more, and sometimes it does happen in the chrome browser on my android too and chrome on PC too.

Firefox on PC seems better than chrome. It is also much faster - in firefox, I click next track, and usually it seems instant, or takes at most half a second to change. In chrome it sometimes seems to take 1-2 seconds to skip track.

When it is broken, I think it gets into a state such that commands from the UI send data to mopidy, but mopidy isn't sending push notifications (or whatever they are in websockets) back. It's like it is dropping half of the websocket connection or something.

So for example: 1) Changing track: If I click next track on working PC chrome, it puts up the spinny wait for a bit, then the spinny wait disappears for a moment, then it reappears and refreshes the track information.

If I click next to a track on broken Android, the spinny wait appears, then disappears, but never reappears, and I have to manually pull down to refresh correctly.

2) If I change track on another computer When not broken I see a spinny wait, then the track updates. Loads of debug log messages.

When broken: No debug messages, nothing happens.

Could it possibly be something to do with this: http://stackoverflow.com/questions/12665887/chrome-websocket-connection-delay

ie. are you creating multiple websocket connections in a way that chrome doesn't like or something? I've seen it break in chrome PC, chrome android, and Android 5 webview, which I assume is Chrome based.

[tkem]

As long as you don't see any reconnecting messages in the app log, there should be only a single WebSocket connection. I'll have to dig into https://github.com/mopidy/mopidy.js to see how it does handle reconnects, but my guess is that it doesn't leave dropped connections open or something. However, if you don't see any playbackStopped/playbackStarted events from the Mopidy server in the app log after/during a track change, this explains the behavior of the UI. Leaves the question why no events are sent or received. BTW, which version of Mopidy (server) are you running?

[tkem]

Server logs may also be if interest, if the cause for this is really dropped events. "Broadcast of WebSocket message ... failed" would indicate this, AFAICS.

[tkem]

Note the above more message will only show up when running mopidy server with debug messages enabled.

[joemarshall]

Mopidy 1.1.1, from apt-get mopidy On raspbian jessie.

Mopidy seems quite slow generally - in musicbox webclient it can take 5 seconds ot change track sometimes.

Log file with -v attached. I loaded up a playlist, went to now playing, clicked refresh (otherwise it wouldn't let me seek at all because it thinks nothing is playing), then clicked next track four or so times (the music changed, but the display didn't).

mopidylog.txt

[tkem]

Well, thanks for your efforts! Will look into that later, but on first quick scan it seems like all the necessary events are sent to CoreListener and I don't see anything special. Setup also very much like my own (Raspi2, Jessie, Mopidy 1.1.1), but still can't reproduce. Need to think. Am 16.11.2015 17:59 schrieb "joemarshall" notifications@github.com:

Mopidy 1.1.1, from apt-get mopidy On raspbian jessie.

Mopidy seems quite slow generally - in musicbox webclient it can take 5 seconds ot change track sometimes.

Log file with -v attached. I loaded up a playlist, went to now playing, clicked refresh (otherwise it wouldn't let me seek at all because it thinks nothing is playing), then clicked next track four or so times (the music changed, but the display didn't).

mopidylog.txt https://github.com/tkem/mopidy-mobile/files/35725/mopidylog.txt

— Reply to this email directly or view it on GitHub https://github.com/tkem/mopidy-mobile/issues/145#issuecomment-157096885.

[tkem]

Only thing suspicious in the log I found is:

WARNING  2015-11-16 16:56:20,374 [17357:Audio-2] py.warnings
  /usr/lib/python2.7/dist-packages/mopidy/audio/actor.py:714: Warning: /build/glib2.0-tTvduh/glib2.0-2.42.1/./gobject/gsignal.c:2579: instance '0xb3a10398' has no handler with id '151'
  result = self._playbin.set_state(state)

But we probably need @adamcik or @jodal to make sense of this. Otherwise, I couldn't find anything hinting at why playback events would not reach the HTTP/WebSocket client.

Wild guess/last spark of hope: From the logs I see you mostly use the spotify backend. Have you tried other backends, like the file/local ones?

[jodal]

I'm not confident about what the cause is of the glib warning, but hopefully it'll disappear with the move to PyGI and Gstreamer 1.x.

As for playback events, I believe there's something missing there in the develop branch after the merge of the first batch of gapless fixes, but in Mopidy 1.1.1 there is no known problem with that.

[tkem]

Thanks @jodal, didn't think it was connected to the OP's issue, but what do I know ;-)

[joemarshall]

I've tried local and spotify backends.

It works fine with musicbox, although it sometimes takes aaages (like 7 seconds) to change track. Is there any kind of timeout there?

If I have time I'll try building the android app myself, although I'm not sure how one debugs a cordova/ionic app.

[tkem]

For debugging a Cordova app on your phone/tablet, you can actually use Chrome on your desktop. https://developer.chrome.com/devtools/docs/remote-debugging#debugging-webviews Works quite well, actually. Sorry I'm not of much help here, but still cannot reproduce this.

[joemarshall]

Aha. I've got the app in broken state, with chrome debugger on it and fixed the bug. How amazing is chrome debugger. Messages were getting to the app, but causing a load of exceptions.

The problem was on line 33 of connection.js, where it calls string.startsWith.

Turns out string.startsWith is only supported by very recent versions of the chrome webview. On my phone, whilst I had latest chrome, I didn't have 'android webview' installed from play store, so it was just using the one that came with my phone originally. The fix was to install "android webview" from play store, so it updates to the latest version.

I think you could be on the safe side and add a startswith definition to connection.js anyway, like the below, and I think this would fix it without needing the webview update:

if ( typeof String.prototype.startsWith != 'function' ) {
  String.prototype.startsWith = function( str ) {
    return this.substring( 0, str.length ) === str;
  }
};

Details of the error below because I was pasting them in here as I debugged anyway.:

I'm getting typeerrors in mopidy.js that come up whenever I change track (. So I guess the websocket messages are getting as far as mopidy.js just fine, but not getting through to the main html listeners..

mopidy.js:24 Uncaught TypeError: websocket:incomingMessage listener threw error: undefined is not a function
mopidy.js:24 Uncaught TypeError: event:playbackStateChanged listener threw error: undefined is not a function
mopidy.js:24 Uncaught TypeError: websocket:incomingMessage listener threw error: undefined is not a function
mopidy.js:24 Uncaught TypeError: event:trackPlaybackStarted listener threw error: undefined is not a function

In mopidy.js line 152, it is calling notifyListener(event, toNotify[i], args); for two listeners in native code, the first one is okay, the second one (toNotify[1]) is throwing the exception.

I put a dump of the call stack into the console, if I start up the android app, then switch tracks from mopidy on my PC browser, the android app does this (with my extra dump of stack traces from exceptions added in):

uncaught TypeError: websocket:incomingMessage listener threw error: undefined is not a function
ionic.bundle.js:21157 cache(0) miss for spotify:track:7Ctju5iILqGbvMKG6CgTl9
ionic.bundle.js:21157 websocket:outgoingMessage Object {method: "core.library.get_images", params: Object, jsonrpc: "2.0", id: 14}
mopidy.js:18 TypeError: undefined is not a function
    at Mopidy.notify (file:///android_asset/www/app/services/connection.js:33:20)
    at notifyListener (file:///android_asset/www/lib/mopidy/dist/mopidy.js:63:35)
    at Mopidy.object.emit (file:///android_asset/www/lib/mopidy/dist/mopidy.js:153:17)
    at Mopidy._send (file:///android_asset/www/lib/mopidy/dist/mopidy.js:2765:14)
    at Mopidy.<anonymous> (file:///android_asset/www/lib/mopidy/dist/mopidy.js:2869:25)
    at file:///android_asset/www/app/services/coverart.js:184:31
    at processQueue (file:///android_asset/www/lib/ionic/release/js/ionic.bundle.js:23394:28)
    at file:///android_asset/www/lib/ionic/release/js/ionic.bundle.js:23410:27
    at Scope.$eval (file:///android_asset/www/lib/ionic/release/js/ionic.bundle.js:24673:28)
    at Scope.$digest (file:///android_asset/www/lib/ionic/release/js/ionic.bundle.js:24484:31)
ionic.bundle.js:21157 websocket:incomingMessage MessageEvent {ports: Array[0], data: "{"jsonrpc": "2.0", "id": 14, "result": {"spotify:t…2d9e208e48d7d8621a57bde06fdbc7", "height": 64}]}}", source: null, lastEventId: "", origin: "ws://192.168.1.96:6680"…}
mopidy.js:18 TypeError: undefined is not a function
    at Mopidy.notify (file:///android_asset/www/app/services/connection.js:33:20)
    at notifyListener (file:///android_asset/www/lib/mopidy/dist/mopidy.js:63:35)
    at Mopidy.object.emit (file:///android_asset/www/lib/mopidy/dist/mopidy.js:153:17)
    at Mopidy.<anonymous> (file:///android_asset/www/lib/mopidy/dist/mopidy.js:2703:14)
mopidy.js:25 Uncaught TypeError: websocket:outgoingMessage listener threw error: undefined is not a function
mopidy.js:25 Uncaught TypeError: websocket:incomingMessage listener threw error: undefined is not a function

[tkem]

Thanks, @joemarshall, amazing work! I didn't realize startsWith() was ES6. Shame on me. Will fix this to simply use substring or whatever and publish an update ASAP. Will also scan other files for use of startsWith.