and a debug log with verbosity level 4
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.seek","params":{"time_position":0},"jsonrpc":"2.0","id":113}'
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Sending flushing seek: position=0
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.audio.gst Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.audio.actor Audio event: position_changed(position=0)
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.listener Sending position_changed to AudioListener: {'position': 0}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 113, "result": true}'
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering seeked event
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PAUSED pending=GST_STATE_PAUSED
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending seeked to CoreListener: {'time_position': 0}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=paused, target_state=None)
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'paused', 'target_state': None}
Apr 08 17:04:22 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got ASYNC_DONE bus message.
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.play","jsonrpc":"2.0","id":114}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Changing state: paused -> playing
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'paused', 'new_state': 'playing'}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback resumed event
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PLAYING pending=GST_STATE_VOID_PENDING
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=playing, target_state=None)
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'playing', 'target_state': None}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_resumed to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 4}
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 114, "result": null}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":115}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 115, "result": 16}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":116}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 116, "result": 19}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":117}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 117, "result": 40}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":118}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 118, "result": 47}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":119}'
Apr 08 17:04:26 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 119, "result": 50}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":120}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 120, "result": 333}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":121}'
Apr 08 17:04:27 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 121, "result": 854}'
Apr 08 17:04:28 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":122}'
Apr 08 17:04:28 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 122, "result": 1888}'
Apr 08 17:04:30 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":123}'
Apr 08 17:04:30 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 123, "result": 3920}'
Apr 08 17:04:34 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":124}'
Apr 08 17:04:34 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 124, "result": 7958}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":51},"jsonrpc":"2.0","id":125}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=51)
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 125, "result": true}'
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 51}
Apr 08 17:04:35 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 51}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":83},"jsonrpc":"2.0","id":126}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 126, "result": true}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.mixer.set_volume","params":{"volume":83},"jsonrpc":"2.0","id":127}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 127, "result": true}'
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:04:36 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:04:42 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":128}'
Apr 08 17:04:42 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 128, "result": 15992}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.pause","jsonrpc":"2.0","id":129}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PAUSED: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Changing state: playing -> paused
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'playing', 'new_state': 'paused'}
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback paused event
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_paused to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 27789}
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 129, "result": null}'
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PLAYING new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=playing, new_state=paused, target_state=None)
Apr 08 17:04:54 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'playing', 'new_state': 'paused', 'target_state': None}
Apr 08 17:05:04 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.index","jsonrpc":"2.0","id":130}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 130, "result": 0}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.add","params":{"at_position":1,"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":131}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [FileBackend-3 (_actor_loop)] mopidy.file.library Looking up file URI: file:///mnt/fanfaredoor1.wav
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element decodebin7: have-audio;
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element fakesink3: GstMessageTag, taglist=(taglist)"taglist\,\ container-format\=\(string\)WAV\,...
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element pipeline5: GstMessageAsyncDone, running-time=(guint64)18446744073709551615;
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.tracklist Triggering event: tracklist_changed()
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending tracklist_changed to CoreListener: {}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 131, "result": [{"__model__": "TlTrack", "tlid": 3, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}]}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.stop","jsonrpc":"2.0","id":132}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_NULL: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Changing state: paused -> stopped
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'paused', 'new_state': 'stopped'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 132, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.tracklist.get_tl_tracks","jsonrpc":"2.0","id":133}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 133, "result": [{"__model__": "TlTrack", "tlid": 2, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}, {"__model__": "TlTrack", "tlid": 3, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}]}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.play","params":{"tlid":3},"jsonrpc":"2.0","id":134}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.actor Position query failed
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_READY: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_NULL new=GST_STATE_READY pending=GST_STATE_VOID_PENDING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.actor Flags: 2
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.mixer Mixer event: volume_changed(volume=83)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [SoftwareMixer-1 (_actor_loop)] mopidy.listener Sending volume_changed to MixerListener: {'volume': 83}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Got source-setup signal: element=GstFileSrc
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.actor Running source-setup callback
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_ASYNC
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending volume_changed to CoreListener: {'volume': 83}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 134, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.get_images","params":{"uris":[]},"jsonrpc":"2.0","id":135}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 135, "result": {}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_current_tl_track","jsonrpc":"2.0","id":136}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 136, "result": {"__model__": "TlTrack", "tlid": 2, "track": {"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_stream_title","jsonrpc":"2.0","id":137}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.audio.gst Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 137, "result": null}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.audio.actor Audio event: position_changed(position=0)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STREAM_START bus message
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Dummy-12] mopidy.listener Sending position_changed to AudioListener: {'position': 0}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: stream_changed(uri='file:///mnt/fanfaredoor1.wav')
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending stream_changed to AudioListener: {'uri': 'file:///mnt/fanfaredoor1.wav'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback ended event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_ended to CoreListener: {'tl_track': TlTrack(tlid=2, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 0}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Changing state: stopped -> playing
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'stopped', 'new_state': 'playing'}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback started event
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_started to CoreListener: {'tl_track': TlTrack(tlid=3, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav'))}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got TAG bus message: tags={'container-format': ['WAV'], 'bitrate': [1411200], 'audio-codec': ['Uncompressed 16-bit PCM audio'], 'midi-base-note': [60]}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: tags_changed(tags=['container-format', 'bitrate', 'audio-codec', 'midi-base-note'])
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending tags_changed to AudioListener: {'tags': ['container-format', 'bitrate', 'audio-codec', 'midi-base-note']}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_READY new=GST_STATE_PAUSED pending=GST_STATE_PLAYING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got ASYNC_DONE bus message.
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":138}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 138, "result": 20}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PLAYING pending=GST_STATE_VOID_PENDING
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=paused, new_state=playing, target_state=None)
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'paused', 'new_state': 'playing', 'target_state': None}
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.get_images","params":{"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":139}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 139, "result": {"file:///mnt/fanfaredoor1.wav": []}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":140}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 140, "result": 40}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":141}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 141, "result": 51}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.library.lookup","params":{"uris":["file:///mnt/fanfaredoor1.wav"]},"jsonrpc":"2.0","id":142}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [FileBackend-3 (_actor_loop)] mopidy.file.library Looking up file URI: file:///mnt/fanfaredoor1.wav
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element decodebin9: have-audio;
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element fakesink4: GstMessageTag, taglist=(taglist)"taglist\,\ container-format\=\(string\)WAV\,...
Apr 08 17:05:11 MMclient mopidy[691]: TRACE [FileBackend-3 (_actor_loop)] mopidy.audio.scan element pipeline6: GstMessageAsyncDone, running-time=(guint64)18446744073709551615;
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 142, "result": {"file:///mnt/fanfaredoor1.wav": [{"__model__": "Track", "uri": "file:///mnt/fanfaredoor1.wav", "name": "fanfaredoor1.wav", "length": 200000, "bitrate": 1411200}]}}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":143}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 143, "result": 329}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":144}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 144, "result": 849}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":145}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 145, "result": 1882}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":146}'
Apr 08 17:05:11 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 146, "result": 4136}'
Apr 08 17:05:12 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":147}'
Apr 08 17:05:12 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 147, "result": 8170}'
Apr 08 17:05:20 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.get_time_position","jsonrpc":"2.0","id":148}'
Apr 08 17:05:20 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 148, "result": 16209}'
Apr 08 17:05:27 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Received WebSocket message from 192.168.0.118: '{"method":"core.playback.pause","jsonrpc":"2.0","id":149}'
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Audio-2 (_actor_loop)] mopidy.audio.gst Changing state to GST_STATE_PAUSED: result=GST_STATE_CHANGE_SUCCESS
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Changing state: playing -> paused
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering playback state change event
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending playback_state_changed to CoreListener: {'old_state': 'playing', 'new_state': 'paused'}
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.core.playback Triggering track playback paused event
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [Core-6 (_actor_loop)] mopidy.listener Sending track_playback_paused to CoreListener: {'tl_track': TlTrack(tlid=3, track=Track(bitrate=1411200, length=200000, name='fanfaredoor1.wav', uri='file:///mnt/fanfaredoor1.wav')), 'time_position': 23103}
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [HttpServer] mopidy.http.handlers Sent WebSocket message to 192.168.0.118: '{"jsonrpc": "2.0", "id": 149, "result": null}'
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.gst Got STATE_CHANGED bus message: old=GST_STATE_PLAYING new=GST_STATE_PAUSED pending=GST_STATE_VOID_PENDING
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [MainThread] mopidy.audio.actor Audio event: state_changed(old_state=playing, new_state=paused, target_state=None)
Apr 08 17:05:40 MMclient mopidy[691]: DEBUG [MainThread] mopidy.listener Sending state_changed to AudioListener: {'old_state': 'playing', 'new_state': 'paused', 'target_state': None}