@blacklight
Your log:
Just ends at
DEBUG 2019-01-03 20:33:35,417 [22147:MainThread] mopidy.audio.gst
Got TAG bus message: tags={‘album’: [u’Mer De Noms’], ‘track-number’: [4], ‘has-crc’: [False], ‘artist’: [u’A Perfect Circle’], ‘nominal-bitrate’: [192000], ‘datetime’: [u’1999’], ‘genre’: [u’Alternative Rock’], ‘title’: [u’Judith’], ‘container-format’: [u’ID3 tag’], ‘audio-codec’: [u’MPEG-1 Layer 3 (MP3)‘], ‘channel-mode’: [u’stereo’]}
Why is that? That’s pretty much exactly the point at which mine goes on to change READY->PAUSED and then PAUSED->PLAYING.
BLACKLIGHT
========
DEBUG 2019-01-03 20:33:35,300 [22147:MpdSession-15] mopidy.mpd.session
Request from [[::ffff:127.0.0.1]:6600]: play
DEBUG 2019-01-03 20:33:35,318 [22147:Audio-2] mopidy.audio.gst
Changing state to GST_STATE_READY: result=GST_STATE_CHANGE_SUCCESS
DEBUG 2019-01-03 20:33:35,318 [22147:MainThread] mopidy.audio.gst
Got STATE_CHANGED bus message: old=GST_STATE_NULL new=GST_STATE_READY pending=GST_STATE_VOID_PENDING
DEBUG 2019-01-03 20:33:35,338 [22147:Audio-2] mopidy.audio.gst
Got source-setup signal: element=GstFileSrc
DEBUG 2019-01-03 20:33:35,340 [22147:Audio-2] mopidy.audio.gst
Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_ASYNC
DEBUG 2019-01-03 20:33:35,389 [22147:MainThread] mopidy.audio.gst
Got STREAM_START bus message
DEBUG 2019-01-03 20:33:35,389 [22147:MainThread] mopidy.audio.actor
Audio event: stream_changed(uri='file:///mnt/hd/media/music/A%20Perfect%20Circle/Mer%20De%20Noms/04%20Judith.mp3')
DEBUG 2019-01-03 20:33:35,389 [22147:MainThread] mopidy.listener
Sending stream_changed to AudioListener: {'uri': 'file:///mnt/hd/media/music/A%20Perfect%20Circle/Mer%20De%20Noms/04%20Judith.mp3'}
DEBUG 2019-01-03 20:33:35,389 [22147:Core-9] mopidy.core.playback
Changing state: stopped -> playing
DEBUG 2019-01-03 20:33:35,389 [22147:Core-9] mopidy.core.playback
Triggering playback state change event
DEBUG 2019-01-03 20:33:35,395 [22147:Dummy-16] mopidy.audio.gst
Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
DEBUG 2019-01-03 20:33:35,395 [22147:Dummy-16] mopidy.audio.actor
Audio event: position_changed(position=0)
DEBUG 2019-01-03 20:33:35,408 [22147:Dummy-16] mopidy.listener
Sending position_changed to AudioListener: {'position': 0}
DEBUG 2019-01-03 20:33:35,417 [22147:MainThread] mopidy.audio.gst
Got TAG bus message:
<EOF> ?????
ME
===
DEBUG 2019-01-03 23:18:07,943 [19552:MpdSession-12] mopidy.mpd.session
Request from [[::ffff:127.0.0.1]:6601]: play
DEBUG 2019-01-03 23:18:07,961 [19552:Audio-2] mopidy.audio.gst
Changing state to GST_STATE_READY: result=GST_STATE_CHANGE_SUCCESS
DEBUG 2019-01-03 23:18:07,962 [19552:MainThread] mopidy.audio.gst
Got STATE_CHANGED bus message: old=GST_STATE_NULL new=GST_STATE_READY pending=GST_STATE_VOID_PENDING
DEBUG 2019-01-03 23:18:07,978 [19552:Audio-2] mopidy.audio.gst
Got source-setup signal: element=GstFileSrc
DEBUG 2019-01-03 23:18:07,981 [19552:Audio-2] mopidy.audio.gst
Changing state to GST_STATE_PLAYING: result=GST_STATE_CHANGE_ASYNC
DEBUG 2019-01-03 23:18:08,091 [19552:MainThread] mopidy.audio.gst
Got STREAM_START bus message
DEBUG 2019-01-03 23:18:08,091 [19552:MainThread] mopidy.audio.actor
Audio event: stream_changed(uri='file:///home/nick/Music/A%20Perfect%20Circle%20-%20Mer%20de%20Noms/04%20Judith.mp3')
DEBUG 2019-01-03 23:18:08,092 [19552:MainThread] mopidy.listener
Sending stream_changed to AudioListener: {'uri': 'file:///home/nick/Music/A%20Perfect%20Circle%20-%20Mer%20de%20Noms/04%20Judith.mp3'}
DEBUG 2019-01-03 23:18:08,092 [19552:Core-7] mopidy.core.playback
Changing state: stopped -> playing
DEBUG 2019-01-03 23:18:08,092 [19552:Core-7] mopidy.core.playback
Triggering playback state change event
DEBUG 2019-01-03 23:18:08,103 [19552:Dummy-13] mopidy.audio.gst
Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0
DEBUG 2019-01-03 23:18:08,103 [19552:Dummy-13] mopidy.audio.actor
Audio event: position_changed(position=0)
DEBUG 2019-01-03 23:18:08,103 [19552:Dummy-13] mopidy.listener
Sending position_changed to AudioListener: {'position': 0}
DEBUG 2019-01-03 23:18:08,112 [19552:MainThread] mopidy.audio.gst
Got TAG bus message:
DEBUG 2019-01-03 23:18:08,115 [19552:MainThread] mopidy.audio.gst
Got STATE_CHANGED bus message: old=GST_STATE_READY new=GST_STATE_PAUSED pending=GST_STATE_PLAYING
DEBUG 2019-01-03 23:18:08,115 [19552:MainThread] mopidy.audio.gst
Got ASYNC_DONE bus message.
DEBUG 2019-01-03 23:18:08,116 [19552:MainThread] mopidy.audio.gst
Got STATE_CHANGED bus message: old=GST_STATE_PAUSED new=GST_STATE_PLAYING pending=GST_STATE_VOID_PENDING
DEBUG 2019-01-03 23:18:08,116 [19552:MainThread] mopidy.audio.actor
Audio event: state_changed(old_state=stopped, new_state=playing, target_state=None)