From 494cc3b8e12821a51c6480712991deb28cc6273e Mon Sep 17 00:00:00 2001 From: Eric Coissac Date: Tue, 31 Mar 2026 15:43:12 +0200 Subject: [PATCH] :recycle: improve playlist reattachment and enhance OpenHome state logging - Skip renderer queue clear when rebinding to same container, triggering gentle refresh instead - Add detailed tracing for STOP commands across renderers and OpenHome clients - Improve `playback_state()` error handling with fallback to Transitioning for empty states - Log queue state (length, current index/track ID) in `play_next` - Add caller location tracing to OpenHome transport actions (`seek_id`, `delete_all`) - Enhance IdArrayResponse logging with raw XML children for debugging - Support both `` and elements in Transport State responses --- .DS_Store | Bin 18436 -> 18436 bytes pmocontrol/src/control_point.rs | 44 ++++++++++++++++-- .../src/music_renderer/musicrenderer.rs | 11 +++++ .../src/music_renderer/openhome_renderer.rs | 30 +++++++++--- pmocontrol/src/queue/openhome.rs | 11 +++++ .../src/upnp_clients/openhome_client.rs | 29 ++++++++++-- 6 files changed, 111 insertions(+), 14 deletions(-) diff --git a/.DS_Store b/.DS_Store index eb344ba742cb9f4682b87c67b026cc93f58d7a32..58e2f0f507227499b386c330e07dc0c68d077235 100644 GIT binary patch delta 78 zcmZpfz}PZ@ae_Z%&&Gh={ETLsc?6cTZhk4M#5J+OY%{llDnDxl0}xK0DZFr Result<(), ControlPointError> { + // If already bound to the same container on the same server, don't clear the + // renderer queue — that would interrupt active playback. Instead, just trigger + // a gentle refresh (which uses LCS and preserves the currently playing track). + let renderer = self.music_renderer_by_id(renderer_id).ok_or_else(|| { + ControlPointError::ControlPoint(format!("Renderer {} not found", renderer_id.0)) + })?; + + let already_bound = renderer + .get_playlist_binding() + .map(|b| b.server_id == *server_id && b.container_id == container_id) + .unwrap_or(false); + + if already_bound { + debug!( + renderer = renderer_id.0.as_str(), + server = server_id.0.as_str(), + container = container_id, + auto_play, + "Re-attach to same container: skipping clear, triggering gentle refresh" + ); + let mut binding = renderer.get_playlist_binding().unwrap(); + binding.pending_refresh = true; + binding.auto_play_on_refresh = auto_play; + renderer.set_playlist_binding(Some(binding)); + + let mut auto_start_cb = |rid: &DeviceId| self.play_current_from_queue(rid); + let callback: Option<&mut dyn FnMut(&DeviceId) -> Result<(), ControlPointError>> = + if auto_play { + Some(&mut auto_start_cb) + } else { + None + }; + return refresh_attached_queue_for( + &self.registry, + renderer_id, + &self.event_bus, + callback, + ); + } + // CRITICAL: When attaching a new playlist to a renderer, we must UNCONDITIONALLY // clear the RENDERER queue first (but NOT the local queue cache, which will be // replaced by refresh_attached_queue_for() using replace_entire_playlist()). @@ -1170,10 +1210,6 @@ impl ControlPoint { "Attaching new playlist: clearing renderer queue" ); - // Prepare the renderer for the new playlist (backend-agnostic) - let renderer = self.music_renderer_by_id(renderer_id).ok_or_else(|| { - ControlPointError::ControlPoint(format!("Renderer {} not found", renderer_id.0)) - })?; renderer.clear_for_playlist_attach()?; // Sync backend state to local cache (backend-agnostic) diff --git a/pmocontrol/src/music_renderer/musicrenderer.rs b/pmocontrol/src/music_renderer/musicrenderer.rs index f91c8fb0..fdaeea79 100644 --- a/pmocontrol/src/music_renderer/musicrenderer.rs +++ b/pmocontrol/src/music_renderer/musicrenderer.rs @@ -849,6 +849,10 @@ impl MusicRenderer { } // Then stop playback (ignore errors if already stopped) + tracing::trace!( + renderer = self.id().0.as_str(), + "STOP command via clear_for_playlist_attach" + ); backend.stop().or_else(|err| { warn!( renderer = self.id().0.as_str(), @@ -964,6 +968,7 @@ impl MusicRenderer { } /// Transport control: stop + #[track_caller] pub fn stop(&self) -> Result<(), ControlPointError> { // Reset the has_played flag when stopping playback. // This ensures that if we start a new track, the flag will be false @@ -971,6 +976,12 @@ impl MusicRenderer { // transient STOPPED states during track initialization. self.clear_has_played_flag(); + let caller = std::panic::Location::caller(); + tracing::trace!( + renderer = self.info.friendly_name(), + caller = %caller, + "STOP command sent to renderer" + ); self.lock_backend_for("stop").stop() } diff --git a/pmocontrol/src/music_renderer/openhome_renderer.rs b/pmocontrol/src/music_renderer/openhome_renderer.rs index f046dcd4..fdef765e 100644 --- a/pmocontrol/src/music_renderer/openhome_renderer.rs +++ b/pmocontrol/src/music_renderer/openhome_renderer.rs @@ -342,13 +342,25 @@ impl VolumeControl for OpenHomeRenderer { impl PlaybackStatus for OpenHomeRenderer { fn playback_state(&self) -> Result { let client = self.playlist_client_for("playback_state")?; - let raw = client.transport_state()?; - let mapped = map_openhome_state(&raw); - tracing::trace!( - raw_state = raw.as_str(), - mapped_state = ?mapped, - "OpenHome TransportState" - ); + let raw = client.transport_state().map_err(|err| { + tracing::warn!( + error = %err, + "OpenHome transport_state() failed — state change detection disabled" + ); + err + })?; + let mapped = if raw.is_empty() { + tracing::trace!("OpenHome TransportState: empty (device initializing)"); + PlaybackState::Transitioning + } else { + let mapped = map_openhome_state(&raw); + tracing::trace!( + raw_state = raw.as_str(), + mapped_state = ?mapped, + "OpenHome TransportState" + ); + mapped + }; Ok(mapped) } } @@ -550,9 +562,13 @@ impl QueueTransportControl for OpenHomeRenderer { .map_err(|_| ControlPointError::QueueError("Queue mutex poisoned".into()))?; let len = queue.len().unwrap_or(0); let current = queue.current_index().ok().flatten(); + let current_track_id = queue.current_track().ok().flatten(); + let all_ids = queue.track_ids().ok().unwrap_or_default(); tracing::trace!( queue_len = len, current_index = ?current, + current_track_id = ?current_track_id, + all_track_ids = ?all_ids, "OpenHome play_next: advancing queue" ); if !queue.advance()? { diff --git a/pmocontrol/src/queue/openhome.rs b/pmocontrol/src/queue/openhome.rs index 9b0d5eca..dc34859a 100644 --- a/pmocontrol/src/queue/openhome.rs +++ b/pmocontrol/src/queue/openhome.rs @@ -869,6 +869,13 @@ impl QueueBackend for OpenHomeQueue { // Cache miss or expired - fetch from service (keep lock held to prevent concurrent calls) let ids = self.playlist_client.id_array()?; + tracing::trace!( + renderer = self.renderer_id.0.as_str(), + ids_count = ids.len(), + ids = ?ids, + "track_ids: cache miss, fetched from Pizzicato" + ); + // Update cache before releasing lock cache.set(ids.clone()); @@ -1008,6 +1015,10 @@ impl QueueBackend for OpenHomeQueue { self.playlist_client.seek_id(track_id)?; } else { self.ensure_playlist_source_selected()?; + tracing::trace!( + renderer = self.renderer_id.0.as_str(), + "STOP command via set_index(None) on OpenHome playlist" + ); self.playlist_client.stop()?; } // Invalidate caches (seek_id/stop modifies playlist state and current track) diff --git a/pmocontrol/src/upnp_clients/openhome_client.rs b/pmocontrol/src/upnp_clients/openhome_client.rs index dd8080d3..34bc26e3 100644 --- a/pmocontrol/src/upnp_clients/openhome_client.rs +++ b/pmocontrol/src/upnp_clients/openhome_client.rs @@ -2,8 +2,9 @@ use crate::errors::ControlPointError; use crate::model::TrackMetadata; use crate::soap_client::{ decode_base64, ensure_success_with_envelope as ensure_success, extract_child_text, - extract_child_text_any, extract_child_text_local, extract_child_text_optional, - extract_child_text_optional_local, find_child_with_suffix, handle_action_response, + extract_child_text_allow_empty, extract_child_text_any, extract_child_text_local, + extract_child_text_optional, extract_child_text_optional_local, find_child_with_suffix, + handle_action_response, invoke_upnp_action, parse_bool, parse_visible_flag, }; use anyhow::{Result, anyhow}; @@ -270,7 +271,8 @@ impl OhPlaylistClient { ControlPointError::UpnpMissingReturnValue("TransportStateResponse".to_string()) })?; - let state = extract_child_text_any(response, &["State", "Value"])?; + // upmpdcli returns , other implementations may use + let state = extract_child_text_any(response, &["Value", "State"])?; Ok(state) } @@ -331,7 +333,10 @@ impl OhPlaylistClient { handle_action_response("SeekSecondAbsolute", &call_result) } + #[track_caller] pub fn delete_id(&self, id: u32) -> Result<(), ControlPointError> { + let caller = std::panic::Location::caller(); + tracing::trace!(control_url = self.control_url.as_str(), id, caller = %caller, "OpenHome DeleteId"); let id_str = id.to_string(); let args = [("Value", id_str.as_str())]; @@ -379,7 +384,10 @@ impl OhPlaylistClient { } } + #[track_caller] pub fn delete_all(&self) -> Result<(), ControlPointError> { + let caller = std::panic::Location::caller(); + tracing::trace!(control_url = self.control_url.as_str(), caller = %caller, "OpenHome DeleteAll"); let call_result = invoke_upnp_action(&self.control_url, &self.service_type, "DeleteAll", &[])?; handle_action_response("DeleteAll", &call_result) @@ -409,6 +417,21 @@ impl OhPlaylistClient { let response = find_child_with_suffix(&envelope.body.content, "IdArrayResponse") .ok_or_else(|| ControlPointError::upnp_missing_return_value("IdArrayResponse"))?; + // Log the raw IdArrayResponse XML for debugging + { + let raw_children: Vec = response.children.iter() + .map(|n: &xmltree::XMLNode| match n { + xmltree::XMLNode::Element(e) => format!("{}={:?}", e.name, e.get_text()), + _ => String::new(), + }) + .filter(|s| !s.is_empty()) + .collect(); + tracing::trace!( + children = ?raw_children, + "id_array: IdArrayResponse children" + ); + } + // Try to extract the array element. If missing, assume empty playlist. let array_text = match extract_child_text_any(response, &["Array", "IdArray", "Value"]) { Ok(text) => text,