mopidy icon indicating copy to clipboard operation
mopidy copied to clipboard

Erroneous stream_title_changed event for previous track on track change

Open kingosticks opened this issue 4 years ago • 1 comments

This follows-on from #1871. This current state is as follows

  • As before, all tags emitted between about-to-finish and STREAM_START are added to our _pending_tags structure. This may contain tags belonging to the old track or nothing at all.
  • As before, once we get STREAM_START we promote the current contents of _pending_tags to be our actual current _tags.
  • Any intermediate tag values, arriving after about-to-finish and before STREAM_START, are never seen. I don't think that's a problem to worry about as it's a very short space of time.

  • At this point, STREAM_START has arrived for the new track and we send tags_changed with our values from _tags if we have anything, even though these values are actually from the previous track.
  • Meanwhile the async change to the new track may have already finished and we've sent events (including metadata) for that new track. So current_track now corresponds to the new track.
  • Core handles that "old" tags_changed event by forwarding it on to the frontends. But it's now in a situation where current_track is the new track but the tags it's forwarding actually belong to the previous track. The result of that is stream_title_changed with the old track title is erroneously emitted to frontends.
  • This was worse before https://github.com/mopidy/mopidy/pull/1875 where our _stream_title state would get stuck with this wrong title (https://github.com/mopidy/mopidy-mpd/issues/23) even after tags for the new track arrived.

Example log showing a stream_title_changed event of {'title': 'Set Guitars To Kill'} (the old track) after the track changes to 'A Little Bit Of Solidarity Goes A Long Way'.

Dummy-24 DEBUG    2020-03-16 23:56:49,207 Got about-to-finish event.
Dummy-24 DEBUG    2020-03-16 23:56:49,208 Running about-to-finish callback.
LocalBackend-3 DEBUG    2020-03-16 23:56:49,210 Backend translated URI from local:track:And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/02-and_so_i_watch_you_from_afar-a_little_bit_of_solidarity_goes_a_long_way.mp3 to file:///home/nick/Music/And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/02-and_so_i_watch_you_from_afar-a_little_bit_of_solidarity_goes_a_long_way.mp3
Dummy-24 DEBUG    2020-03-16 23:56:49,214 Got source-setup signal: element=GstFileSrc

MainThread DEBUG    2020-03-16 23:56:51,237 Got TAG bus message: tags={'title': ['Set Guitars To Kill'], 'artist': ['And So I Watch You From Afar'], 'album': ['Self Titled'], 'datetime': ['2009-04-13'], 'track-number': [1], 'genre': ['Instrumental Rock'], 'container-format': ['ID3 tag'], 'private-id3v2-frame': [b'TLAN\x00\x00\x00\x04\x00\x00\x00eng', b'TXXX\x00\x00\x00\x14\x00\x00\x00Rip date\x002009-04-14', b'TXXX\x00\x00\x00\n\x00\x00\x00Source\x00CD', b'TXXX\x00\x00\x00\x1c\x00\x00\x00Release type\x00Normal release'], 'track-count': [11], 'encoder': ['LAME 3.97 (-V2 --vbr-new)'], 'publisher': ['Smalltown America'], 'private-data': [b'\x02\x00\xfb1K\x00'], 'has-crc': [False], 'channel-mode': ['joint-stereo'], 'audio-codec': ['MPEG-1 Layer 3 (MP3)'], 'minimum-bitrate': [31850], 'maximum-bitrate': [319725], 'bitrate': [252000]}
MainThread DEBUG    2020-03-16 23:56:52,345 Got STREAM_START bus message
MainThread DEBUG    2020-03-16 23:56:52,345 Audio event: stream_changed(uri='file:///home/nick/Music/And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/02-and_so_i_watch_you_from_afar-a_little_bit_of_solidarity_goes_a_long_way.mp3')
MainThread DEBUG    2020-03-16 23:56:52,346 Sending stream_changed to AudioListener: {'uri': 'file:///home/nick/Music/And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/02-and_so_i_watch_you_from_afar-a_little_bit_of_solidarity_goes_a_long_way.mp3'}

Dummy-37 DEBUG    2020-03-16 23:56:52,346 Got SEGMENT pad event: rate=1.0 format=time start=0 stop=18446744073709551615 position=0

MainThread DEBUG    2020-03-16 23:56:52,347 Audio event: tags_changed(tags=dict_keys(['title', 'artist', 'album', 'datetime', 'track-number', 'genre', 'container-format', 'private-id3v2-frame', 'track-count', 'encoder', 'publisher', 'private-data', 'has-crc', 'channel-mode', 'audio-codec', 'minimum-bitrate', 'maximum-bitrate', 'bitrate']))

Core-7 DEBUG    2020-03-16 23:56:52,348 Triggering track playback ended event

Dummy-37 DEBUG    2020-03-16 23:56:52,348 Audio event: position_changed(position=0)

Core-7 DEBUG    2020-03-16 23:56:52,349 Sending track_playback_ended to CoreListener: {'tl_track': TlTrack(tlid=28, track=Track(album=Album(date='2009-04-13', name='Self Titled', num_tracks=11, uri='local:album:md5:5bdacb653bbd94bd6d1cbc68dc1854da'), artists=[Artist(name='And So I Watch You From Afar', uri='local:artist:md5:f69d2a608336108f1d645744c63d6dea')], date='2009-04-13', genre='Instrumental Rock', last_modified=1310599762000, length=329639, name='Set Guitars To Kill', track_no=1, uri='local:track:And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/01-and_so_i_watch_you_from_afar-set_guitars_to_kill.mp3')), 'time_position': 329639}

MainThread DEBUG    2020-03-16 23:56:52,349 Sending tags_changed to AudioListener: {'tags': dict_keys(['title', 'artist', 'album', 'datetime', 'track-number', 'genre', 'container-format', 'private-id3v2-frame', 'track-count', 'encoder', 'publisher', 'private-data', 'has-crc', 'channel-mode', 'audio-codec', 'minimum-bitrate', 'maximum-bitrate', 'bitrate'])}

Dummy-37 DEBUG    2020-03-16 23:56:52,350 Sending position_changed to AudioListener: {'position': 0}

Core-7 DEBUG    2020-03-16 23:56:52,351 Changing state: playing -> playing
Core-7 DEBUG    2020-03-16 23:56:52,354 Triggering playback state change event
Core-7 DEBUG    2020-03-16 23:56:52,354 Sending playback_state_changed to CoreListener: {'old_state': 'playing', 'new_state': 'playing'}
Core-7 DEBUG    2020-03-16 23:56:52,355 Triggering track playback started event

MpdFrontend-8 DEBUG    2020-03-16 23:56:52,356 Sending player to MpdSession: {}

Core-7 DEBUG    2020-03-16 23:56:52,356 Sending track_playback_started to CoreListener: {'tl_track': TlTrack(tlid=29, track=Track(album=Album(date='2009-04-13', name='Self Titled', num_tracks=11, uri='local:album:md5:5bdacb653bbd94bd6d1cbc68dc1854da'), artists=[Artist(name='And So I Watch You From Afar', uri='local:artist:md5:f69d2a608336108f1d645744c63d6dea')], date='2009-04-13', genre='Instrumental Rock', last_modified=1310599762000, length=205871, name='A Little Bit Of Solidarity Goes A Long Way', track_no=2, uri='local:track:And%20So%20I%20Watch%20You%20From%20Afar%20-%20Self%20Titled%20%282009%29/02-and_so_i_watch_you_from_afar-a_little_bit_of_solidarity_goes_a_long_way.mp3'))}
Core-7 DEBUG    2020-03-16 23:56:52,360 Sending stream_title_changed to CoreListener: {'title': 'Set Guitars To Kill'}

MpdFrontend-8 DEBUG    2020-03-16 23:56:52,361 Sending player to MpdSession: {}

MainThread DEBUG    2020-03-16 23:56:52,365 Got TAG bus message: tags={'title': ['A Little Bit Of Solidarity Goes A Long Way'], 'artist': ['And So I Watch You From Afar'], 'album': ['Self Titled'], 'datetime': ['2009-04-13'], 'track-number': [2], 'genre': ['Instrumental Rock'], 'container-format': ['ID3 tag'], 'private-id3v2-frame': [b'TLAN\x00\x00\x00\x04\x00\x00\x00eng', b'TXXX\x00\x00\x00\x14\x00\x00\x00Rip date\x002009-04-14', b'TXXX\x00\x00\x00\n\x00\x00\x00Source\x00CD', b'TXXX\x00\x00\x00\x1c\x00\x00\x00Release type\x00Normal release'], 'track-count': [11], 'encoder': ['LAME 3.97 (-V2 --vbr-new)'], 'publisher': ['Smalltown America'], 'private-data': [b'\x02\x00\xef\x1e\xc9\x00']}
MainThread DEBUG    2020-03-16 23:56:52,366 Audio event: tags_changed(tags=['title', 'track-number', 'private-data'])
MainThread DEBUG    2020-03-16 23:56:52,367 Sending tags_changed to AudioListener: {'tags': ['title', 'track-number', 'private-data']}
MainThread DEBUG    2020-03-16 23:56:52,369 Got TAG bus message: tags={'title': ['A Little Bit Of Solidarity Goes A Long Way'], 'artist': ['And So I Watch You From Afar'], 'album': ['Self Titled'], 'datetime': ['2009-04-13'], 'track-number': [2], 'genre': ['Instrumental Rock'], 'container-format': ['ID3 tag'], 'private-id3v2-frame': [b'TLAN\x00\x00\x00\x04\x00\x00\x00eng', b'TXXX\x00\x00\x00\x14\x00\x00\x00Rip date\x002009-04-14', b'TXXX\x00\x00\x00\n\x00\x00\x00Source\x00CD', b'TXXX\x00\x00\x00\x1c\x00\x00\x00Release type\x00Normal release'], 'track-count': [11], 'encoder': ['LAME 3.97 (-V2 --vbr-new)'], 'publisher': ['Smalltown America'], 'private-data': [b'\x02\x00\xef\x1e\xc9\x00'], 'has-crc': [False], 'channel-mode': ['joint-stereo'], 'audio-codec': ['MPEG-1 Layer 3 (MP3)']}
MainThread DEBUG    2020-03-16 23:56:52,416 Got TAG bus message: tags={'title': ['A Little Bit Of Solidarity Goes A Long Way'], 'artist': ['And So I Watch You From Afar'], 'album': ['Self Titled'], 'datetime': ['2009-04-13'], 'track-number': [2], 'genre': ['Instrumental Rock'], 'container-format': ['I

Note that this doesn't happen with all files, some mp3s I have do not emit any tags after about-to-finish which means we don't emit that tags_changed event as part of our STREAM_START handling.

This comment provides some context regarding the old tags we still receive from the pipeline.

kingosticks avatar Mar 17 '20 00:03 kingosticks

# TODO: Do not emit stream title changes for plain tracks. We need a
# better way to decide if something is a stream.

Just spitballing here could couldn't this be partially solved by having the appropriate backend extension emit a flag on track change? Something like is_stream?

TrollDecker avatar May 18 '21 16:05 TrollDecker