Tunein streams keep getting stuck at sync

fallenicarus · February 6, 2017, 11:13pm

Bunch of tune in streams keep getting stuck at the sync state after playing streams for a short period of time. Sometimes they recover back and keep on playing after some silence, but sometimes they are stuck longer. Which means I need to go in and reset the stream by restarting it.

Is there any guidelines for preventing this behavior? Or how to debug them?

kingosticks · February 6, 2017, 11:27pm

Turn on debug logging. https://docs.mopidy.com/en/latest/troubleshooting/

fallenicarus · February 6, 2017, 11:47pm

How do I turn on debugging for tunein - I knows its smoething to do with loglevels but I dont see an example for this and havent had much luck. I know how to do debugging when running as command line but I am looking to get debugging info when running as a service .

Could you share an example?

kingosticks · February 7, 2017, 2:47pm

Yeh, sorry, it is a bit trickier for the service. Basically, the logging in /var/log/mopidy/mopidy.log is controlled from /etc/mopidy/logging.conf. And this is separate from the normal console logging that is controlled via things like loglevels/*. When running as a service, the normal console logging is sent to the journal and can be displayed using journalctl.

The confusing difference between the two worlds is something already identified as needing improving.

So, to actually answer your question, you can do it a few ways, here are two:

Add the following to /etc/mopidy/mopidy.conf and then view it with sudo journalctl -u mopidy -f

[loglevels]
mopidy_tunein = debug

Alternatively, edit /etc/mopidy/logging.conf and change it to level = DEBUG. This will give you DEBUG logging in /var/log/mopidy/mopidy.log for everything so you’ll have to pick out the relevant bits.

There are other ways, there are probably better ways, but that should get you started.

For this particular issue, you might find that it’s actually Mopidy core rather than the Tunein extension that’s responsible for the issue you are having, so the 2nd option might be better. Have you seen https://github.com/mopidy/mopidy/issues/1280 ?

fallenicarus · February 7, 2017, 6:11pm

You were right that it wasnt the tunein portion but mopidy core itself. If you can think of a better way to highlight the issue to get help for me please let me know - I can create a new topic?

Here is a snippet of the log file - towards the end of the file where there are all the get time position requests the stream just shows sync on musicbox and no audio plays.

I will look through the other issue you pointed out to and see if that helps - looking at high level it may?I will try it out later today .

2017-02-07 13:03:24,531 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:03:24,535 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:03:24,542 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:03:25,319 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":212}'
2017-02-07 13:03:26,334 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":213}'
2017-02-07 13:03:26,351 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":214}'
2017-02-07 13:03:27,403 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":215}'
2017-02-07 13:03:28,422 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":216}'
2017-02-07 13:03:30,080 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":217}'
2017-02-07 13:03:31,105 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":218}'
2017-02-07 13:03:31,374 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":219}'
2017-02-07 13:03:31,387 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":220}'
2017-02-07 13:03:32,459 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":221}'
2017-02-07 13:03:32,478 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":222}'
2017-02-07 13:03:33,541 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":223}'
2017-02-07 13:03:34,597 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":224}'
2017-02-07 13:03:35,506 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:03:35,517 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:03:35,519 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:03:35,523 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:03:35,636 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":225}'
2017-02-07 13:03:35,654 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":226}'
2017-02-07 13:03:36,678 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":227}'
2017-02-07 13:03:36,707 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":228}'
2017-02-07 13:03:37,802 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":229}'
2017-02-07 13:03:37,829 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":230}'
2017-02-07 13:03:37,859 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":231}'
2017-02-07 13:03:38,964 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":232}'
2017-02-07 13:03:38,989 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":233}'
2017-02-07 13:03:39,018 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":234}'
2017-02-07 13:03:40,144 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":235}'
2017-02-07 13:03:40,174 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":236}'
2017-02-07 13:03:41,275 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":237}'
2017-02-07 13:03:41,314 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":238}'
2017-02-07 13:03:42,425 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":239}'
2017-02-07 13:03:42,439 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":240}'
2017-02-07 13:03:43,460 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":241}'
2017-02-07 13:03:44,492 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":242}'
2017-02-07 13:03:44,507 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":243}'
2017-02-07 13:03:44,599 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":244}'
2017-02-07 13:03:45,694 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":245}'
2017-02-07 13:03:46,521 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:03:46,542 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:03:46,546 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:03:46,555 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:03:46,730 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":246}'
2017-02-07 13:03:47,861 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":247}'
2017-02-07 13:03:47,891 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":248}'
2017-02-07 13:03:49,013 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":249}'
2017-02-07 13:03:49,042 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":250}'
2017-02-07 13:03:50,175 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":251}'
2017-02-07 13:03:50,204 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":252}'
2017-02-07 13:03:51,230 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":253}'
2017-02-07 13:03:51,247 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":254}'
2017-02-07 13:03:52,284 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":255}'
2017-02-07 13:03:52,303 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":256}'
2017-02-07 13:03:52,319 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":257}'
2017-02-07 13:03:53,371 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":258}'
2017-02-07 13:03:54,399 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":259}'
2017-02-07 13:03:54,416 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":260}'
2017-02-07 13:03:55,450 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":261}'
2017-02-07 13:03:56,522 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":262}'
2017-02-07 13:03:56,539 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":263}'
2017-02-07 13:03:56,564 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":264}'
2017-02-07 13:03:57,508 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:03:57,529 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:03:57,533 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:03:57,539 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:03:57,623 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":265}'
2017-02-07 13:03:58,661 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":266}'
2017-02-07 13:03:58,677 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":267}'
2017-02-07 13:03:58,696 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":268}'
2017-02-07 13:03:59,724 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":269}'
2017-02-07 13:03:59,744 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":270}'
2017-02-07 13:04:00,800 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":271}'
2017-02-07 13:04:00,821 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":272}'
2017-02-07 13:04:01,872 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":273}'
2017-02-07 13:04:01,888 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":274}'
2017-02-07 13:04:02,920 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":275}'
2017-02-07 13:04:02,938 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":276}'
2017-02-07 13:04:04,036 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":277}'
2017-02-07 13:04:04,102 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":278}'
2017-02-07 13:04:04,123 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":279}'
2017-02-07 13:04:05,199 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":280}'
2017-02-07 13:04:05,222 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":281}'
2017-02-07 13:04:06,273 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":282}'
2017-02-07 13:04:06,292 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":283}'
2017-02-07 13:04:07,305 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":284}'
2017-02-07 13:04:07,323 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":285}'
2017-02-07 13:04:08,370 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":286}'
2017-02-07 13:04:08,514 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:04:08,532 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:04:08,536 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:04:08,543 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:04:09,406 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":287}'
2017-02-07 13:04:09,425 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":288}'
2017-02-07 13:04:10,477 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":289}'
2017-02-07 13:04:10,506 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":290}'
2017-02-07 13:04:11,603 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":291}'
2017-02-07 13:04:11,624 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":292}'
2017-02-07 13:04:11,656 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":293}'
2017-02-07 13:04:12,758 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":294}'
2017-02-07 13:04:12,777 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":295}'
2017-02-07 13:04:13,813 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":296}'
2017-02-07 13:04:13,837 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":297}'
2017-02-07 13:04:14,927 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":298}'
2017-02-07 13:04:14,946 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":299}'
2017-02-07 13:04:16,026 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":300}'
2017-02-07 13:04:16,049 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":301}'
2017-02-07 13:04:17,092 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":302}'
2017-02-07 13:04:17,124 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":303}'
2017-02-07 13:04:17,145 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":304}'
2017-02-07 13:04:18,229 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":305}'
2017-02-07 13:04:18,249 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":306}'
2017-02-07 13:04:19,320 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":307}'
2017-02-07 13:04:19,508 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:04:19,520 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:04:19,523 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:04:19,528 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:04:20,369 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":308}'
2017-02-07 13:04:21,414 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":309}'
2017-02-07 13:04:21,436 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":310}'
2017-02-07 13:04:22,465 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":311}'
2017-02-07 13:04:22,483 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":312}'
2017-02-07 13:04:23,529 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":313}'
2017-02-07 13:04:23,570 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":314}'
2017-02-07 13:04:24,652 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":315}'
2017-02-07 13:04:25,698 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":316}'
2017-02-07 13:04:25,715 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":317}'
2017-02-07 13:04:26,769 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":318}'
2017-02-07 13:04:26,788 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":319}'
2017-02-07 13:04:27,818 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":320}'
2017-02-07 13:04:28,863 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":321}'
2017-02-07 13:04:28,882 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":322}'
2017-02-07 13:04:29,933 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":323}'
2017-02-07 13:04:30,529 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: status
2017-02-07 13:04:30,549 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    volume: 13
    repeat: 0
    random: 0
    single: 0
    consume: 0
    playlist: 4
    playlistlength: 1
    xfade: 0
    state: play
    song: None
    songid: 1
    nextsong: 0
    nextsongid: 2
    time: 176:0
    elapsed: 176.926
    bitrate: 0
    OK
2017-02-07 13:04:30,554 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Request from [::ffff:192.168.1.144]:48128: currentsong
2017-02-07 13:04:30,561 DEBUG [8943:MpdSession-15] mopidy.mpd.session: Response to [::ffff:192.168.1.144]:48128: 
    file: tunein:station:s133026
    Time: 0
    Artist: Suno 1024
    Album: Suno 1024
    Title: Zabardast Hits
    X-AlbumUri: tunein:station:s133026
    X-AlbumImage: http://cdn-radiotime-logos.tunein.com/s133026q.png
    OK
2017-02-07 13:04:30,967 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":324}'
2017-02-07 13:04:30,986 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":325}'
2017-02-07 13:04:32,022 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":326}'
2017-02-07 13:04:32,038 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":327}'
2017-02-07 13:04:33,088 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":328}'
2017-02-07 13:04:33,118 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":329}'
2017-02-07 13:04:34,162 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":330}'
2017-02-07 13:04:35,212 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":331}'
2017-02-07 13:04:36,236 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":332}'
2017-02-07 13:04:36,256 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":333}'
2017-02-07 13:04:37,305 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":334}'
2017-02-07 13:04:37,325 DEBUG [8943:HttpServer] mopidy.http.handlers: Received WebSocket message from 192.168.1.136: u'{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":335}'

fallenicarus · February 8, 2017, 3:37am

Played around with this a bit more today. Here is a quick rundown:

The setup where I have issues involves mopidy output to a fifo pipe to use with snapcast to setup multi-room audio
Somehow there are 2 issues happening:
– One, is where there are sync issues and audio skips - this is something do with snapcast and how it synchronizes music. I can reduce the skipping a bit with playing around with the buffer. But its still annoying…
– second, the bigger issue is where it appears that mopidy acts like its writing to fifo but snapcast doesnt read anything from the pipe and the timestamp on the pipe doesnt change.

I am not sure what else I can debug - maybe gstreamer as a debug element helps? Its def not just mopidy or snapcast…

Topic		Replies	Views
Turning on loglevels to identify buffering issues General	0	566	February 4, 2017
Iris Icecast playback stuck in a loop (MOVED) General	18	1508	May 22, 2020
Not switching to next track in queue with gapless playback to Icecast General	3	749	November 13, 2023
Sudo service mopidy status - shows errors General	0	1111	October 25, 2015
Status not changing General	3	570	August 16, 2021

Tunein streams keep getting stuck at sync

Related Topics