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 a83eea458955abb29193d7d3ff96f47cbf1880dc..bf595161ecb4f91a91e7a8957809e78ea1e1f59f 100644 (file)
--- 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 b006154037d4a56c5c23986ff632700d5f9a2af8..9f71353ed777d713269c82cbe278cb7f24c61776 100644 (file)
--- 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 231275f7b1fb463a6b92f9b77633fb7ee94d5a83..98f2ba022014f6d85198e98abfa025dd87dcd962 100644 (file)
--- 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)