From: Marcel van der Veldt Date: Fri, 7 Nov 2025 11:48:38 +0000 (+0100) Subject: Add more debugging of stopped streams X-Git-Url: https://git.kitaultman.com/?a=commitdiff_plain;h=7b9c879720374627f5a9e1d424bbf69bec859304;p=music-assistant-server.git Add more debugging of stopped streams --- diff --git a/music_assistant/controllers/players/player_controller.py b/music_assistant/controllers/players/player_controller.py index a83eea45..bf595161 100644 --- a/music_assistant/controllers/players/player_controller.py +++ b/music_assistant/controllers/players/player_controller.py @@ -351,6 +351,7 @@ class PlayerController(CoreController): - player_id: player_id of the player to handle the command. """ player = self._get_player_with_redirect(player_id) + player.mark_stop_called() # Redirect to queue controller if it is active if active_queue := self.get_active_queue(player): await self.mass.player_queues.stop(active_queue.queue_id) diff --git a/music_assistant/controllers/streams.py b/music_assistant/controllers/streams.py index b0061540..9f71353e 100644 --- a/music_assistant/controllers/streams.py +++ b/music_assistant/controllers/streams.py @@ -497,19 +497,18 @@ class StreamsController(CoreController): if queue_item.media_type == MediaType.RADIO: # keep very short buffer for radio streams # to keep them (more or less) realtime and prevent time outs - read_rate_input_args = ["-readrate", "1.01", "-readrate_initial_burst", "2"] + read_rate_input_args = ["-readrate", "1.0", "-readrate_initial_burst", "2"] elif "Network_Module" in user_agent or "transferMode.dlna.org" in request.headers: # and ofcourse we have an exception of the exception. Where most players actually NEED # the readrate filter to avoid disconnecting, some other players (DLNA/MusicCast) # actually fail when the filter is used. So we disable it completely for those players. read_rate_input_args = None # disable readrate for DLNA players else: - # allow buffer ahead of 8 seconds and read slightly faster than realtime - read_rate_input_args = ["-readrate", "1.2", "-readrate_initial_burst", "10"] + # allow buffer ahead of 10 seconds and read 1.5x faster than realtime + read_rate_input_args = ["-readrate", "1.5", "-readrate_initial_burst", "10"] first_chunk_received = False bytes_sent = 0 - premature_disconnect = False async for chunk in get_ffmpeg_stream( audio_input=audio_input, input_format=pcm_format, @@ -533,29 +532,22 @@ class StreamsController(CoreController): queue_item.queue_id, queue_item.queue_item_id ) except (BrokenPipeError, ConnectionResetError, ConnectionError) as err: - premature_disconnect = True - self.logger.warning( - "Player %s disconnected prematurely from stream for %s (%s) - " - "sent %d bytes, error: %s", - queue.display_name, - queue_item.name, - queue_item.uri, - bytes_sent, - err.__class__.__name__, - ) + if first_chunk_received and not queue_player.stop_called: + # Player disconnected (unexpected) after receiving at least some data + # This could indicate buffering issues, network problems, + # or player-specific issues + bytes_expected = get_chunksize(output_format, queue_item.duration or 3600) + self.logger.warning( + "Player %s disconnected prematurely from stream for %s (%s) - " + "error: %s, sent %d bytes, expected (approx) bytes=%d", + queue.display_name, + queue_item.name, + queue_item.uri, + err.__class__.__name__, + bytes_sent, + bytes_expected, + ) break - if premature_disconnect and first_chunk_received: - # Player disconnected after receiving at least some data - # This could indicate buffering issues, network problems, or player-specific issues - seconds_sent = bytes_sent / output_format.pcm_sample_size if output_format else 0 - self.logger.info( - "Stream statistics for %s: bytes sent=%d, approx seconds=%.1f, " - "expected duration=%.1f", - queue_item.name, - bytes_sent, - seconds_sent, - queue_item.duration or 0, - ) if queue_item.streamdetails.stream_error: self.logger.error( "Error streaming QueueItem %s (%s) to %s - will try to skip to next item", diff --git a/music_assistant/models/player.py b/music_assistant/models/player.py index 231275f7..98f2ba02 100644 --- a/music_assistant/models/player.py +++ b/music_assistant/models/player.py @@ -1254,6 +1254,18 @@ class Player(ABC): ): self._state.group_members.set([self.player_id, *self._state.group_members]) + # track stop called state + if ( + prev_state.playback_state == PlaybackState.IDLE + and self._state.playback_state != PlaybackState.IDLE + ): + self.__stop_called = False + elif ( + prev_state.playback_state != PlaybackState.IDLE + and self._state.playback_state == PlaybackState.IDLE + ): + self.__stop_called = True + # Auto correct player state if player is synced (or group child) # This is because some players/providers do not accurately update this info # for the sync child's. @@ -1438,6 +1450,23 @@ class Player(ABC): self.__active_mass_source = value self.update_state() + __stop_called: bool = False + + def mark_stop_called(self) -> None: + """Mark that the STOP command was called on the player.""" + self.__stop_called = True + + @property + def stop_called(self) -> bool: + """ + Return True if the STOP command was called on the player. + + This is used to differentiate between a user-initiated stop + and a natural end of playback (e.g. end of track/queue). + mainly for debugging/logging purposes by the streams controller. + """ + return self.__stop_called + def __hash__(self) -> int: """Return a hash of the Player.""" return hash(self.player_id)