fix(player,reporting): report real positions, and count an audio-only episode as watched
Returning to the foreground before the background-audio stream had started
playing handed the frontend 0.0s, so the video reloaded at StartTimeTicks=0 —
the episode restarted from the beginning — and the stop report that followed
wrote that zero to Jellyfin as the resume point. Caught on device: locked at
18.4s, unlocked 3.5s later with ExoPlayer still IDLE.
The base that turns a handoff's relative timeline into the episode's is applied
once at the native tick boundary (DR-159), so before the first tick nothing has
applied it. The same blind spot covers webview-rendered media, where nothing is
loaded into the native backend at all and its position is a permanent 0 — which
is why 14 of 14 stop reports in a 35-minute trace were zeroes, one landing 40s
after the frontend had correctly reported 15:22 for the same episode.
- absolute_position(): the maximum of the backend's reading, the last position
webview media reported, and the handoff base. Exact rather than heuristic —
at most one term is ever meaningful, and the base is a floor the stream
cannot physically be behind. duration() gains the same fallback.
- Withhold zero-position stop reports. A zero is never information, and
Jellyfin stores the reported position as the resume point, so sending one
only ever destroys a real one.
- Report progress from the controller's own position ticks, through the 30s
throttler it already shared with the native audio path.
/Sessions/Playing/Progress was previously requested zero times in 35 minutes.
- Report a finished audio-only episode stopped at its runtime before advancing,
so Jellyfin's 90% rule marks it played. Nothing else can: the webview is
suspended and its <video> was torn down at the handoff.
- Split the handoff by source — a downloaded file takes no base and a real
seek, a stream keeps its StartTimeTicks base and no seek — and stop routing a
downloaded handoff's absolute seek through the stream rebuild, which refuses
a non-remote source outright.
Reports go through a PlaybackReportSink, which also collapses three copies of
spawn-a-task-and-hope into one and is what let each of these be written as a
failing test first.
TRACES: UR-005, UR-025, UR-040, UR-071 | DR-178, DR-179, DR-180 |
UT-176, UT-177, UT-178, UT-179, UT-180, UT-181
This commit is contained in:
+705
-109
@@ -55,6 +55,75 @@ pub use android::{
|
||||
set_remote_volume_handler, MediaCommandHandler, RemoteVolumeHandler,
|
||||
};
|
||||
|
||||
/// Where the player's playback reports go.
|
||||
///
|
||||
/// The controller's side of reporting is "send this, don't make me wait": a slow
|
||||
/// or failing sync must never stall playback, so every send is fire-and-forget.
|
||||
/// Production wires this to [`PlaybackReporter`] (local DB, server sync, offline
|
||||
/// queueing); tests capture the operations instead of standing up a database and
|
||||
/// an HTTP client, which is what let the missing reports below be written as
|
||||
/// failing tests rather than found on a device.
|
||||
///
|
||||
/// TRACES: UR-025 | DR-179
|
||||
pub trait PlaybackReportSink: Send + Sync {
|
||||
/// Deliver `operation`. Must not block the caller.
|
||||
fn send(&self, operation: PlaybackOperation);
|
||||
}
|
||||
|
||||
/// The production sink: hands each operation to the `PlaybackReporter`.
|
||||
///
|
||||
/// Reports originate on whatever thread playback ended or ticked on — including
|
||||
/// JNI callbacks with no Tokio runtime attached — so the spawn falls back to a
|
||||
/// throwaway runtime on its own thread rather than assuming one is current.
|
||||
struct ReporterSink {
|
||||
reporter: Arc<TokioMutex<Option<PlaybackReporter>>>,
|
||||
}
|
||||
|
||||
impl PlaybackReportSink for ReporterSink {
|
||||
fn send(&self, operation: PlaybackOperation) {
|
||||
let reporter = self.reporter.clone();
|
||||
let task = async move {
|
||||
let guard = reporter.lock().await;
|
||||
let Some(reporter) = guard.as_ref() else {
|
||||
warn!("[PlayerController] PlaybackReporter not initialized; dropping report");
|
||||
return;
|
||||
};
|
||||
// `report` decides local-vs-server and queues for sync itself.
|
||||
if let Err(e) = reporter.report(operation, true).await {
|
||||
log::error!("[PlayerController] Failed to report playback: {}", e);
|
||||
}
|
||||
};
|
||||
|
||||
if let Ok(handle) = tokio::runtime::Handle::try_current() {
|
||||
handle.spawn(task);
|
||||
} else {
|
||||
std::thread::spawn(move || match tokio::runtime::Runtime::new() {
|
||||
Ok(rt) => rt.block_on(task),
|
||||
Err(e) => log::error!(
|
||||
"[PlayerController] No runtime available to report playback: {}",
|
||||
e
|
||||
),
|
||||
});
|
||||
}
|
||||
}
|
||||
}
|
||||
|
||||
/// The position to report when a stream ends naturally.
|
||||
///
|
||||
/// The item's runtime when we know it, because the point of the report is to say
|
||||
/// the episode *finished* and Jellyfin decides that by percentage — the last
|
||||
/// position actually observed can be seconds short, and on a handoff whose ticks
|
||||
/// stopped early it can be nowhere near the end. Without a runtime the best
|
||||
/// available answer is where playback got to.
|
||||
///
|
||||
/// TRACES: UR-025, UR-040 | DR-179 | UT-179
|
||||
fn completion_report_position(runtime: Option<f64>, last_position: f64) -> f64 {
|
||||
match runtime {
|
||||
Some(runtime) if runtime > 0.0 => runtime,
|
||||
_ => last_position.max(0.0),
|
||||
}
|
||||
}
|
||||
|
||||
/// Seconds added per attempt before retrying a stream that failed with an error.
|
||||
///
|
||||
/// Attempt 1 waits this long, attempt 2 twice as long, and so on — a spread that
|
||||
@@ -127,6 +196,7 @@ use crate::playback_reporting::{
|
||||
};
|
||||
use crate::repository::MediaRepository;
|
||||
use crate::settings::AudioSettings;
|
||||
use crate::utils::conversions::seconds_to_ticks;
|
||||
|
||||
/// Central player controller that coordinates playback
|
||||
pub struct PlayerController {
|
||||
@@ -153,9 +223,12 @@ pub struct PlayerController {
|
||||
// Playback reporting (dual sync: local DB + server)
|
||||
playback_reporter: Arc<TokioMutex<Option<PlaybackReporter>>>,
|
||||
|
||||
// Event throttler to prevent spam from position updates
|
||||
// Will be used when position update hooks are added to backends
|
||||
#[allow(dead_code)]
|
||||
// Where playback reports go. Swappable so tests can assert on what the
|
||||
// player tells Jellyfin. See `PlaybackReportSink`.
|
||||
reports: Arc<Mutex<Arc<dyn PlaybackReportSink>>>,
|
||||
|
||||
// Bounds progress reports to one per item per 30s. Position ticks arrive
|
||||
// four times a second; the server needs a resume point, not a firehose.
|
||||
position_throttler: Arc<EventThrottler>,
|
||||
|
||||
// End reason tracking for autoplay decision making
|
||||
@@ -209,6 +282,19 @@ pub struct PlayerController {
|
||||
// competing intents to take opposing actions. `None` means no webview media
|
||||
// is active and the native backend is authoritative. See DR-097.
|
||||
html5_playing: Arc<Mutex<Option<bool>>>,
|
||||
|
||||
// Last position/duration reported by webview-rendered media.
|
||||
//
|
||||
// On the webview path the `<video>` element IS the player: nothing is loaded
|
||||
// into the native backend, so `backend.position()` is a permanent 0. Those
|
||||
// reports used to be re-emitted to the frontend and then dropped, which is
|
||||
// why every position the *backend* sent to Jellyfin — including the stop
|
||||
// report that sets the resume point — was zero, overwriting the correct one
|
||||
// the frontend had just sent. Storing them here makes
|
||||
// `absolute_position()` answer for both rendering paths.
|
||||
//
|
||||
// TRACES: UR-005, UR-025 | DR-178
|
||||
reported_time: Arc<Mutex<stream_end::ObservedTime>>,
|
||||
}
|
||||
|
||||
impl PlayerController {
|
||||
@@ -217,6 +303,9 @@ impl PlayerController {
|
||||
playback_reporter: Arc<TokioMutex<Option<PlaybackReporter>>>,
|
||||
position_throttler: Arc<EventThrottler>,
|
||||
) -> Self {
|
||||
let reports: Arc<dyn PlaybackReportSink> = Arc::new(ReporterSink {
|
||||
reporter: playback_reporter.clone(),
|
||||
});
|
||||
let controller = Self {
|
||||
backend: Arc::new(Mutex::new(backend)),
|
||||
queue: Arc::new(Mutex::new(QueueManager::new())),
|
||||
@@ -228,6 +317,7 @@ impl PlayerController {
|
||||
event_emitter: Arc::new(Mutex::new(None)),
|
||||
countdown_cancel: Arc::new(Mutex::new(None)),
|
||||
playback_reporter,
|
||||
reports: Arc::new(Mutex::new(reports)),
|
||||
position_throttler,
|
||||
end_reason: Arc::new(Mutex::new(None)),
|
||||
autoplay_episode_count: Arc::new(Mutex::new(0)),
|
||||
@@ -235,6 +325,7 @@ impl PlayerController {
|
||||
background_audio_active: Arc::new(Mutex::new(false)),
|
||||
stream_resume: Arc::new(Mutex::new(stream_end::ResumeTracker::default())),
|
||||
html5_playing: Arc::new(Mutex::new(None)),
|
||||
reported_time: Arc::new(Mutex::new(stream_end::ObservedTime::default())),
|
||||
};
|
||||
|
||||
// Start background timer thread for sleep timer countdown
|
||||
@@ -394,6 +485,12 @@ impl PlayerController {
|
||||
);
|
||||
|
||||
self.reset_autoplay_count();
|
||||
// A different item is current; the last one's reported position must not
|
||||
// be reported against it. This path is how webview-rendered video is
|
||||
// queued (no backend load at all), so it is exactly where a stale
|
||||
// reading would otherwise survive.
|
||||
// TRACES: UR-005 | DR-178
|
||||
self.clear_reported_time();
|
||||
|
||||
let mut queue = self.queue.lock_safe();
|
||||
queue.set_queue(vec![item], 0);
|
||||
@@ -414,11 +511,12 @@ impl PlayerController {
|
||||
backend.play()?;
|
||||
drop(backend);
|
||||
|
||||
// A different item is loading; the last one's reported position must not
|
||||
// be attributed to it.
|
||||
self.clear_reported_time();
|
||||
|
||||
// Report playback start using PlaybackReporter (dual sync: local DB + server)
|
||||
if let Some(jellyfin_id) = item.jellyfin_id() {
|
||||
let jellyfin_id = jellyfin_id.to_string();
|
||||
let reporter = self.playback_reporter.clone();
|
||||
|
||||
// Build playback context from item metadata
|
||||
let context = if item.album_id.is_some() {
|
||||
Some(PlaybackContext {
|
||||
@@ -429,53 +527,23 @@ impl PlayerController {
|
||||
None
|
||||
};
|
||||
|
||||
// Spawn on Tokio runtime if available, otherwise use a new thread
|
||||
if let Ok(handle) = tokio::runtime::Handle::try_current() {
|
||||
handle.spawn(async move {
|
||||
let reporter_guard = reporter.lock().await;
|
||||
if let Some(reporter_instance) = reporter_guard.as_ref() {
|
||||
log::info!("[PlayerController] Reporting playback start via PlaybackReporter: {}", jellyfin_id);
|
||||
// Where this stream actually begins. Zero for an ordinary load, but a
|
||||
// background-audio handoff loads a stream whose zero is the handoff
|
||||
// point — telling the server the session started at 0:00 there both
|
||||
// misreports the session and, being a position, competes with the
|
||||
// real one.
|
||||
let position = self.absolute_position();
|
||||
|
||||
let operation = PlaybackOperation::Start {
|
||||
item_id: jellyfin_id.clone(),
|
||||
position_ticks: 0,
|
||||
context,
|
||||
};
|
||||
|
||||
// Note: PlaybackReporter internally checks connectivity
|
||||
// We pass is_online=true as default; reporter will check actual status
|
||||
match reporter_instance.report(operation, true).await {
|
||||
Ok(_) => log::info!("[PlayerController] Successfully reported playback start (local DB + server sync)"),
|
||||
Err(e) => log::error!("[PlayerController] Failed to report playback start: {}", e),
|
||||
}
|
||||
} else {
|
||||
log::warn!("[PlayerController] PlaybackReporter not initialized - using fallback JellyfinClient");
|
||||
// Fallback to legacy JellyfinClient (will be removed after full migration)
|
||||
}
|
||||
});
|
||||
} else {
|
||||
// Fallback: spawn in a new thread with its own runtime
|
||||
std::thread::spawn(move || {
|
||||
let rt = tokio::runtime::Runtime::new().unwrap();
|
||||
rt.block_on(async move {
|
||||
let reporter_guard = reporter.lock().await;
|
||||
if let Some(reporter_instance) = reporter_guard.as_ref() {
|
||||
log::info!("[PlayerController] Reporting playback start via PlaybackReporter: {}", jellyfin_id);
|
||||
|
||||
let operation = PlaybackOperation::Start {
|
||||
item_id: jellyfin_id.clone(),
|
||||
position_ticks: 0,
|
||||
context,
|
||||
};
|
||||
|
||||
match reporter_instance.report(operation, true).await {
|
||||
Ok(_) => log::info!("[PlayerController] Successfully reported playback start"),
|
||||
Err(e) => log::error!("[PlayerController] Failed to report playback start: {}", e),
|
||||
}
|
||||
}
|
||||
});
|
||||
});
|
||||
}
|
||||
log::info!(
|
||||
"[PlayerController] Reporting playback start: {} @ {:.1}s",
|
||||
jellyfin_id,
|
||||
position
|
||||
);
|
||||
self.report(PlaybackOperation::Start {
|
||||
item_id: jellyfin_id.to_string(),
|
||||
position_ticks: seconds_to_ticks(position),
|
||||
context,
|
||||
});
|
||||
}
|
||||
|
||||
Ok(())
|
||||
@@ -634,66 +702,56 @@ impl PlayerController {
|
||||
.and_then(|item| item.jellyfin_id().map(|s| s.to_string()))
|
||||
};
|
||||
|
||||
let position_ticks = {
|
||||
let backend = self.backend.lock_safe();
|
||||
(backend.position() * 10_000_000.0) as i64
|
||||
};
|
||||
// Read across every rendering path BEFORE stopping: the backend zeroes
|
||||
// its position on stop, and the element that was reporting is gone.
|
||||
let position = self.absolute_position();
|
||||
|
||||
let mut backend = self.backend.lock_safe();
|
||||
backend.stop()?;
|
||||
drop(backend);
|
||||
self.clear_reported_time();
|
||||
|
||||
// Report playback stopped using PlaybackReporter (dual sync: local DB + server)
|
||||
if let Some(jellyfin_id) = jellyfin_id {
|
||||
let reporter = self.playback_reporter.clone();
|
||||
|
||||
// Spawn on Tokio runtime if available, otherwise use a new thread
|
||||
if let Ok(handle) = tokio::runtime::Handle::try_current() {
|
||||
handle.spawn(async move {
|
||||
let reporter_guard = reporter.lock().await;
|
||||
if let Some(reporter_instance) = reporter_guard.as_ref() {
|
||||
log::info!("[PlayerController] Reporting playback stopped via PlaybackReporter: {}", jellyfin_id);
|
||||
|
||||
let operation = PlaybackOperation::Stopped {
|
||||
item_id: jellyfin_id.clone(),
|
||||
position_ticks,
|
||||
};
|
||||
|
||||
match reporter_instance.report(operation, true).await {
|
||||
Ok(_) => log::info!("[PlayerController] Successfully reported playback stopped (local DB + server sync)"),
|
||||
Err(e) => log::error!("[PlayerController] Failed to report playback stopped: {}", e),
|
||||
}
|
||||
} else {
|
||||
log::warn!("[PlayerController] PlaybackReporter not initialized");
|
||||
}
|
||||
});
|
||||
} else {
|
||||
// Fallback: spawn in a new thread with its own runtime
|
||||
std::thread::spawn(move || {
|
||||
let rt = tokio::runtime::Runtime::new().unwrap();
|
||||
rt.block_on(async move {
|
||||
let reporter_guard = reporter.lock().await;
|
||||
if let Some(reporter_instance) = reporter_guard.as_ref() {
|
||||
log::info!("[PlayerController] Reporting playback stopped via PlaybackReporter: {}", jellyfin_id);
|
||||
|
||||
let operation = PlaybackOperation::Stopped {
|
||||
item_id: jellyfin_id.clone(),
|
||||
position_ticks,
|
||||
};
|
||||
|
||||
match reporter_instance.report(operation, true).await {
|
||||
Ok(_) => log::info!("[PlayerController] Successfully reported playback stopped"),
|
||||
Err(e) => log::error!("[PlayerController] Failed to report playback stopped: {}", e),
|
||||
}
|
||||
}
|
||||
});
|
||||
});
|
||||
}
|
||||
self.report_stopped_at(jellyfin_id, position);
|
||||
}
|
||||
|
||||
Ok(())
|
||||
}
|
||||
|
||||
/// Tell Jellyfin playback stopped at `position`, unless that position is
|
||||
/// zero.
|
||||
///
|
||||
/// Jellyfin stores the reported position as the resume point, so a zero is
|
||||
/// not a harmless no-op — it is an instruction to forget where the viewer
|
||||
/// was. And it is never *information*: nobody watched zero seconds of
|
||||
/// anything, so every zero this app ever sent came from asking a player that
|
||||
/// was not rendering the media (webview video, or a handoff whose first tick
|
||||
/// had not landed). On a device trace, 14 of 14 stop reports in 35 minutes
|
||||
/// were zeroes, one of them 40s after the frontend had correctly reported
|
||||
/// 15:22 for the same episode.
|
||||
///
|
||||
/// TRACES: UR-025, UR-005 | DR-179 | UT-178
|
||||
fn report_stopped_at(&self, jellyfin_id: String, position: f64) {
|
||||
if position <= 0.0 {
|
||||
debug!(
|
||||
"[PlayerController] Withholding zero-position stop report for {} \
|
||||
(nothing played; reporting it would clear the resume point)",
|
||||
jellyfin_id
|
||||
);
|
||||
return;
|
||||
}
|
||||
|
||||
log::info!(
|
||||
"[PlayerController] Reporting playback stopped: {} @ {:.1}s",
|
||||
jellyfin_id,
|
||||
position
|
||||
);
|
||||
self.report(PlaybackOperation::Stopped {
|
||||
item_id: jellyfin_id,
|
||||
position_ticks: seconds_to_ticks(position),
|
||||
});
|
||||
}
|
||||
|
||||
/// Skip to next track
|
||||
///
|
||||
/// Note: load_and_play sets EndReason::NewTrackLoaded to prevent autoplay
|
||||
@@ -783,11 +841,18 @@ impl PlayerController {
|
||||
///
|
||||
/// TRACES: UR-040, UR-005 | DR-159 | UT-155
|
||||
pub async fn seek_absolute(&self, position: f64) -> Result<(), String> {
|
||||
// Only a *streamed* handoff needs the rebuild. A downloaded file seeks
|
||||
// like any other file — and `resume_stream_at` refuses a non-remote
|
||||
// source, so sending one through here fails the seek outright.
|
||||
// TRACES: UR-071 | DR-180 | UT-181
|
||||
let rebuild = self.is_background_audio_active() && {
|
||||
let queue = self.queue.lock_safe();
|
||||
queue
|
||||
.current()
|
||||
.map(Self::is_audio_only_video)
|
||||
.map(|item| {
|
||||
Self::is_audio_only_video(item)
|
||||
&& matches!(item.source, MediaSource::Remote { .. })
|
||||
})
|
||||
.unwrap_or(false)
|
||||
};
|
||||
|
||||
@@ -825,9 +890,97 @@ impl PlayerController {
|
||||
self.backend.lock_safe().position()
|
||||
}
|
||||
|
||||
/// Get duration
|
||||
/// The position on the **item's own timeline**, whatever is rendering it.
|
||||
///
|
||||
/// This is what every outbound position must be taken from — the resume point
|
||||
/// sent to Jellyfin, the point the video reloads at when a handoff ends, the
|
||||
/// truncation comparison. `position()` alone answers for exactly one of the
|
||||
/// three ways this app plays media, and reads 0 for the other two:
|
||||
///
|
||||
/// - **Webview `<video>`/`<audio>`**: nothing is loaded into the native
|
||||
/// backend, so its position is a permanent 0. The element's own reports are
|
||||
/// the only reading there is.
|
||||
/// - **Background-audio handoff**: the audio-only stream's zero is the
|
||||
/// handoff point, and the base is added at the native tick boundary
|
||||
/// (DR-159) — so before the first tick lands, nothing has applied it.
|
||||
/// Flooring at the base is exact rather than approximate: the stream cannot
|
||||
/// physically be behind its own starting point.
|
||||
/// - **Native playback**: the backend is authoritative and both other terms
|
||||
/// are zero, so the max is its own value.
|
||||
///
|
||||
/// Returning to the foreground during that pre-first-tick window is what
|
||||
/// restarted an episode from 0:00 and wiped its server-side resume point.
|
||||
///
|
||||
/// TRACES: UR-040, UR-005, UR-025 | DR-178 | UT-176, UT-177
|
||||
pub fn absolute_position(&self) -> f64 {
|
||||
let native = self.backend.lock_safe().position().max(0.0);
|
||||
let reported = self.reported_time.lock_safe().last_position();
|
||||
let base = if self.is_background_audio_active() {
|
||||
*self.background_audio_base.lock_safe()
|
||||
} else {
|
||||
0.0
|
||||
};
|
||||
|
||||
native.max(reported).max(base)
|
||||
}
|
||||
|
||||
/// The duration last reported by webview-rendered media, if any.
|
||||
///
|
||||
/// TRACES: UR-005 | DR-178 | UT-177
|
||||
pub fn observed_duration(&self) -> Option<f64> {
|
||||
self.reported_time.lock_safe().last_duration()
|
||||
}
|
||||
|
||||
/// Forget what webview-rendered media reported.
|
||||
///
|
||||
/// Called wherever that element stops being the player — it was torn down,
|
||||
/// a handoff took over, or a different item is loading. A stale position
|
||||
/// outliving its element would be reported against whatever plays next.
|
||||
///
|
||||
/// TRACES: UR-005 | DR-178 | UT-177
|
||||
fn clear_reported_time(&self) {
|
||||
self.reported_time.lock_safe().reset();
|
||||
}
|
||||
|
||||
/// Replace the sink playback reports go to. Tests capture; production wires
|
||||
/// the `PlaybackReporter` at construction and never swaps it.
|
||||
///
|
||||
/// TRACES: UR-025 | DR-179
|
||||
#[cfg_attr(not(test), allow(dead_code))]
|
||||
pub fn set_report_sink(&self, sink: Arc<dyn PlaybackReportSink>) {
|
||||
*self.reports.lock_safe() = sink;
|
||||
}
|
||||
|
||||
/// Send a playback report. Fire-and-forget by contract, so callers can do
|
||||
/// this while holding nothing and waiting for nothing.
|
||||
///
|
||||
/// TRACES: UR-025 | DR-179
|
||||
fn report(&self, operation: PlaybackOperation) {
|
||||
let sink = self.reports.lock_safe().clone();
|
||||
sink.send(operation);
|
||||
}
|
||||
|
||||
/// The Jellyfin id of whatever is currently queued, if it has one.
|
||||
fn current_jellyfin_id(&self) -> Option<String> {
|
||||
let queue = self.queue.lock_safe();
|
||||
queue
|
||||
.current()
|
||||
.and_then(|item| item.jellyfin_id().map(|id| id.to_string()))
|
||||
}
|
||||
|
||||
/// Get duration.
|
||||
///
|
||||
/// Falls back to what webview-rendered media reported for the same reason
|
||||
/// [`absolute_position`](Self::absolute_position) does: on that path nothing
|
||||
/// is loaded into the native backend, so its duration is `None` and the
|
||||
/// element's report is the only one there is.
|
||||
///
|
||||
/// TRACES: UR-005 | DR-178
|
||||
pub fn duration(&self) -> Option<f64> {
|
||||
self.backend.lock_safe().duration()
|
||||
self.backend
|
||||
.lock_safe()
|
||||
.duration()
|
||||
.or_else(|| self.observed_duration())
|
||||
}
|
||||
|
||||
/// Get queue reference
|
||||
@@ -1063,7 +1216,7 @@ impl PlayerController {
|
||||
// "stopped"/"idle" mean the element is gone, so hand authority back to
|
||||
// the native backend — otherwise music playback would keep emitting
|
||||
// ControlCommands at a element that no longer exists.
|
||||
{
|
||||
let element_gone = {
|
||||
let mut tracked = self.html5_playing.lock_safe();
|
||||
*tracked = match state.as_str() {
|
||||
"playing" => Some(true),
|
||||
@@ -1074,6 +1227,12 @@ impl PlayerController {
|
||||
// "stopped"/"idle": element is gone, native backend resumes authority.
|
||||
_ => None,
|
||||
};
|
||||
tracked.is_none()
|
||||
};
|
||||
// Its last position goes with it: whatever plays next is loaded into the
|
||||
// native backend, and a stale reading would be reported against that.
|
||||
if element_gone {
|
||||
self.clear_reported_time();
|
||||
}
|
||||
if let Some(emitter) = self.event_emitter.lock_safe().as_ref() {
|
||||
emitter.emit(PlayerStatusEvent::StateChanged { state, media_id });
|
||||
@@ -1090,9 +1249,50 @@ impl PlayerController {
|
||||
if self.is_background_audio_active() {
|
||||
return;
|
||||
}
|
||||
// The element is the player on this path, so this tick is the position —
|
||||
// for the resume point, the stop report and everything else that asks.
|
||||
self.reported_time.lock_safe().record(position, duration);
|
||||
|
||||
if let Some(emitter) = self.event_emitter.lock_safe().as_ref() {
|
||||
emitter.emit(PlayerStatusEvent::PositionUpdate { position, duration });
|
||||
}
|
||||
|
||||
self.report_progress_throttled(position);
|
||||
}
|
||||
|
||||
/// Send a throttled progress report to Jellyfin.
|
||||
///
|
||||
/// Progress is what makes a position survive anything other than a clean
|
||||
/// exit — a crash, a swipe-away, a battery death — and lets another device
|
||||
/// resume mid-episode. Webview-rendered media reported none: the frontend
|
||||
/// service writes progress to the local DB only, and Rust had no position
|
||||
/// for it to report. A device trace covering 35 minutes of playback hit
|
||||
/// `/Sessions/Playing/Progress` exactly zero times.
|
||||
///
|
||||
/// The throttler is the one the controller already owned for this purpose
|
||||
/// (30s per item), so ticks arriving four times a second cost one request
|
||||
/// per half-minute.
|
||||
///
|
||||
/// TRACES: UR-005, UR-025 | DR-179 | UT-180
|
||||
fn report_progress_throttled(&self, position: f64) {
|
||||
if position <= 0.0 {
|
||||
return;
|
||||
}
|
||||
let Some(item_id) = self.current_jellyfin_id() else {
|
||||
return;
|
||||
};
|
||||
if !self.position_throttler.should_report(&item_id) {
|
||||
return;
|
||||
}
|
||||
|
||||
self.report(PlaybackOperation::Progress {
|
||||
item_id: item_id.clone(),
|
||||
position_ticks: seconds_to_ticks(position),
|
||||
// Ticks only arrive while the element is playing; a pause is carried
|
||||
// by the state report, not by a position that stopped moving.
|
||||
is_paused: false,
|
||||
});
|
||||
self.position_throttler.mark_reported(&item_id);
|
||||
}
|
||||
|
||||
/// Report that the HTML5 <video> element finished loading and knows its
|
||||
@@ -1186,6 +1386,11 @@ impl PlayerController {
|
||||
return Ok(AutoplayDecision::Stop);
|
||||
};
|
||||
|
||||
// The item is genuinely finished (a truncated stream returned above), so
|
||||
// report it before anything advances — after an advance the queue's
|
||||
// current item is the *next* episode and this one is unreachable.
|
||||
self.report_completion(¤t);
|
||||
|
||||
// Check sleep timer state
|
||||
let timer_mode = {
|
||||
let timer = self.sleep_timer.lock_safe();
|
||||
@@ -1293,6 +1498,43 @@ impl PlayerController {
|
||||
}
|
||||
}
|
||||
|
||||
/// Report an item that just finished as stopped at its runtime, so Jellyfin
|
||||
/// marks it played.
|
||||
///
|
||||
/// Jellyfin decides "watched" from the `PlaybackStopped` report and its
|
||||
/// position — no report, no completion, however much of the episode was
|
||||
/// actually heard. In the foreground the frontend sends one when the
|
||||
/// `<video>` ends. In background audio-only mode there is nobody: the webview
|
||||
/// is suspended and its element was torn down at the handoff, while the
|
||||
/// backend drove the advance to the next episode and said nothing about the
|
||||
/// one that ended. An episode listened to end-to-end on the lockscreen
|
||||
/// therefore never counted, and (before DR-179) was often reset to 0 by the
|
||||
/// stop report that followed.
|
||||
///
|
||||
/// Scoped to the audio-only handoff — the case the frontend provably cannot
|
||||
/// report — so foreground playback keeps its single existing report rather
|
||||
/// than gaining a second one. Music tracks ending natively remain
|
||||
/// unreported; that is the same gap through a different door and wants its
|
||||
/// own change.
|
||||
///
|
||||
/// TRACES: UR-040, UR-025 | DR-179 | UT-179
|
||||
fn report_completion(&self, item: &MediaItem) {
|
||||
if !Self::is_audio_only_video(item) {
|
||||
return;
|
||||
}
|
||||
let Some(jellyfin_id) = item.jellyfin_id().map(|id| id.to_string()) else {
|
||||
return;
|
||||
};
|
||||
|
||||
let position = completion_report_position(item.duration, self.absolute_position());
|
||||
log::info!(
|
||||
"[PlayerController] Audio-only {} finished — reporting complete at {:.1}s",
|
||||
jellyfin_id,
|
||||
position
|
||||
);
|
||||
self.report_stopped_at(jellyfin_id, position);
|
||||
}
|
||||
|
||||
/// Record the base offset of a background-audio handoff (the position the
|
||||
/// video was handed off at, which is the audio stream's zero).
|
||||
///
|
||||
@@ -1315,6 +1557,9 @@ impl PlayerController {
|
||||
self.set_background_audio_base(position);
|
||||
*self.background_audio_active.lock_safe() = true;
|
||||
*self.html5_playing.lock_safe() = None;
|
||||
// The element is being torn down; its last position describes a video
|
||||
// that is no longer playing, and the base describes the one that is.
|
||||
self.clear_reported_time();
|
||||
}
|
||||
|
||||
/// Leave a background-audio handoff, returning the base offset to add to the
|
||||
@@ -1422,10 +1667,11 @@ impl PlayerController {
|
||||
return None;
|
||||
}
|
||||
|
||||
// Already absolute: the Android position tick shifts by the handoff base
|
||||
// before anything sees the value, so adding it again here would
|
||||
// double-count it. (DR-159)
|
||||
let absolute = self.position().max(0.0);
|
||||
// The Android position tick shifts by the handoff base before anything
|
||||
// sees the value, so adding it again here would double-count it
|
||||
// (DR-159) — `absolute_position` floors at the base instead, which is
|
||||
// what a stream that died before its first tick needs. (DR-178)
|
||||
let absolute = self.absolute_position();
|
||||
|
||||
match self.stream_resume.lock_safe().allow_attempt(absolute) {
|
||||
Some(attempt) => Some((absolute, attempt)),
|
||||
@@ -1938,6 +2184,57 @@ mod tests {
|
||||
}
|
||||
}
|
||||
|
||||
/// Captures what the controller reports to Jellyfin, so tests can assert on
|
||||
/// the operations themselves rather than on a database and an HTTP client.
|
||||
struct CapturingReports {
|
||||
operations: std::sync::Mutex<Vec<PlaybackOperation>>,
|
||||
}
|
||||
|
||||
impl CapturingReports {
|
||||
fn new() -> Self {
|
||||
Self {
|
||||
operations: std::sync::Mutex::new(Vec::new()),
|
||||
}
|
||||
}
|
||||
|
||||
/// Every `Stopped` report as `(item_id, position_seconds)`.
|
||||
fn stops(&self) -> Vec<(String, f64)> {
|
||||
self.operations
|
||||
.lock_safe()
|
||||
.iter()
|
||||
.filter_map(|op| match op {
|
||||
PlaybackOperation::Stopped {
|
||||
item_id,
|
||||
position_ticks,
|
||||
} => Some((item_id.clone(), *position_ticks as f64 / 10_000_000.0)),
|
||||
_ => None,
|
||||
})
|
||||
.collect()
|
||||
}
|
||||
|
||||
/// Every `Progress` report as `(item_id, position_seconds)`.
|
||||
fn progress(&self) -> Vec<(String, f64)> {
|
||||
self.operations
|
||||
.lock_safe()
|
||||
.iter()
|
||||
.filter_map(|op| match op {
|
||||
PlaybackOperation::Progress {
|
||||
item_id,
|
||||
position_ticks,
|
||||
..
|
||||
} => Some((item_id.clone(), *position_ticks as f64 / 10_000_000.0)),
|
||||
_ => None,
|
||||
})
|
||||
.collect()
|
||||
}
|
||||
}
|
||||
|
||||
impl PlaybackReportSink for CapturingReports {
|
||||
fn send(&self, operation: PlaybackOperation) {
|
||||
self.operations.lock_safe().push(operation);
|
||||
}
|
||||
}
|
||||
|
||||
#[test]
|
||||
fn test_report_html5_state_emits_state_changed() {
|
||||
let controller = PlayerController::default();
|
||||
@@ -3613,6 +3910,39 @@ mod tests {
|
||||
}
|
||||
}
|
||||
|
||||
/// The same episode handed off from a **downloaded file** — the handoff's
|
||||
/// other source, which starts at the episode's own zero rather than at the
|
||||
/// handoff point.
|
||||
fn local_audio_only_episode(runtime_seconds: f64) -> MediaItem {
|
||||
MediaItem {
|
||||
source: MediaSource::Local {
|
||||
file_path: std::path::PathBuf::from("/downloads/ep2.mkv"),
|
||||
jellyfin_item_id: Some("ep2".to_string()),
|
||||
},
|
||||
..audio_only_episode(runtime_seconds)
|
||||
}
|
||||
}
|
||||
|
||||
/// A file seeks like a file. The rebuild path exists because a chunked
|
||||
/// length-less transcode cannot honour a seek, which is not true of local
|
||||
/// media — and `resume_stream_at` refuses a non-remote source outright, so
|
||||
/// routing a lockscreen scrub through it fails the seek instead of doing it.
|
||||
///
|
||||
/// TRACES: UR-040, UR-071 | DR-180 | UT-181
|
||||
#[tokio::test]
|
||||
async fn test_seek_absolute_on_a_downloaded_handoff_is_an_ordinary_seek() {
|
||||
let controller = PlayerController::default();
|
||||
controller
|
||||
.play_queue(vec![local_audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
// A downloaded handoff claims no base: the file's zero is the episode's.
|
||||
controller.enter_background_audio(0.0);
|
||||
|
||||
controller.seek_absolute(900.0).await.unwrap();
|
||||
|
||||
assert_eq!(controller.position(), 900.0);
|
||||
}
|
||||
|
||||
/// A flaky connection truncates the progressive mp3 transcode that carries
|
||||
/// background audio-only playback. ExoPlayer sees end-of-input on a stream
|
||||
/// with no reliable length, so it reports STATE_ENDED ten minutes into a
|
||||
@@ -3723,6 +4053,272 @@ mod tests {
|
||||
);
|
||||
}
|
||||
|
||||
// ===== Position authority and reporting (DR-178, DR-179) =====
|
||||
//
|
||||
// Every position that leaves the app — the resume point Jellyfin stores, the
|
||||
// point the video reloads at on the way back from a handoff, the truncation
|
||||
// maths — is read off the controller. The device trace showed all of them
|
||||
// reading 0: the native backend is not the player on the webview path, and
|
||||
// during a handoff its base is only applied once ExoPlayer has ticked, which
|
||||
// it has not while the audio-only transcode is still opening.
|
||||
|
||||
/// Returning to the foreground before the audio-only stream has started
|
||||
/// playing hands back the handoff's own starting point, never zero.
|
||||
///
|
||||
/// Observed on device: locked at 18.4s, unlocked 3.5s later with ExoPlayer
|
||||
/// still `IDLE`, `player_exit_background_audio` returned `0.0`, and the video
|
||||
/// reloaded with `StartTimeTicks=0` — the episode restarted from the
|
||||
/// beginning, and the `Stopped` report that followed wiped the server's
|
||||
/// resume point too.
|
||||
///
|
||||
/// TRACES: UR-040 | DR-178 | UT-176
|
||||
#[test]
|
||||
fn test_absolute_position_floors_at_the_handoff_base() {
|
||||
let controller = PlayerController::default();
|
||||
controller.enter_background_audio(18.4);
|
||||
|
||||
// No tick has landed, so nothing has applied the base yet.
|
||||
assert_eq!(controller.position(), 0.0);
|
||||
assert_eq!(
|
||||
controller.absolute_position(),
|
||||
18.4,
|
||||
"the audio stream's zero IS the handoff point, so the position can \
|
||||
never legitimately read below it"
|
||||
);
|
||||
}
|
||||
|
||||
/// Once ticks are flowing the base has already been applied at the native
|
||||
/// boundary (DR-159), so flooring must not add it a second time.
|
||||
///
|
||||
/// TRACES: UR-040 | DR-178 | UT-176
|
||||
#[test]
|
||||
fn test_absolute_position_does_not_double_count_the_handoff_base() {
|
||||
let controller = PlayerController::default();
|
||||
controller.enter_background_audio(18.4);
|
||||
|
||||
// What the real backend reports after a tick: already absolute.
|
||||
controller.seek(120.0).unwrap();
|
||||
|
||||
assert_eq!(controller.absolute_position(), 120.0);
|
||||
}
|
||||
|
||||
/// On the webview path the `<video>` element is the player and the native
|
||||
/// backend holds nothing, so the position it reports is the only one there
|
||||
/// is. It used to be re-emitted to the frontend and then dropped, leaving
|
||||
/// every backend-side report at 0.
|
||||
///
|
||||
/// TRACES: UR-005, UR-025 | DR-178 | UT-177
|
||||
#[test]
|
||||
fn test_webview_position_reports_become_the_controllers_position() {
|
||||
let controller = PlayerController::default();
|
||||
|
||||
controller.report_html5_position(253.4, 2640.0);
|
||||
|
||||
assert_eq!(controller.absolute_position(), 253.4);
|
||||
assert_eq!(controller.observed_duration(), Some(2640.0));
|
||||
}
|
||||
|
||||
/// A torn-down element's last position must not outlive it: the next thing
|
||||
/// to play is loaded into the native backend, and a stale 253s would be
|
||||
/// reported against it.
|
||||
///
|
||||
/// TRACES: UR-005 | DR-178 | UT-177
|
||||
#[test]
|
||||
fn test_webview_teardown_clears_the_observed_position() {
|
||||
let controller = PlayerController::default();
|
||||
controller.report_html5_position(253.4, 2640.0);
|
||||
|
||||
controller.report_html5_state("stopped".to_string(), None);
|
||||
|
||||
assert_eq!(controller.absolute_position(), 0.0);
|
||||
}
|
||||
|
||||
/// Entering a handoff tears the element down, so its position stops being
|
||||
/// the answer at that exact moment — the native audio player's does.
|
||||
///
|
||||
/// TRACES: UR-040 | DR-178 | UT-177
|
||||
#[test]
|
||||
fn test_entering_a_handoff_drops_the_torn_down_elements_position() {
|
||||
let controller = PlayerController::default();
|
||||
controller.report_html5_position(253.4, 2640.0);
|
||||
|
||||
controller.enter_background_audio(18.4);
|
||||
|
||||
assert_eq!(
|
||||
controller.absolute_position(),
|
||||
18.4,
|
||||
"the video element is gone; only the handoff base describes the \
|
||||
stream that is now playing"
|
||||
);
|
||||
}
|
||||
|
||||
/// Nobody ever watched zero seconds of anything. A `Stopped` at 0 carries no
|
||||
/// information and Jellyfin stores it as the resume point, so the only thing
|
||||
/// it can do is destroy one — which is what the device trace caught it doing
|
||||
/// 14 times in 35 minutes, including 40s after the frontend had correctly
|
||||
/// reported 922s for the same episode.
|
||||
///
|
||||
/// TRACES: UR-025 | DR-179 | UT-178
|
||||
#[tokio::test]
|
||||
async fn test_a_stop_at_zero_is_never_reported() {
|
||||
let controller = PlayerController::default();
|
||||
let reports = Arc::new(CapturingReports::new());
|
||||
controller.set_report_sink(reports.clone());
|
||||
controller
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
|
||||
// Nothing ever played: the backend is at 0 and no element reported in.
|
||||
controller.stop().unwrap();
|
||||
|
||||
assert!(
|
||||
reports.stops().is_empty(),
|
||||
"a zero-position stop must be withheld, not sent; got {:?}",
|
||||
reports.stops()
|
||||
);
|
||||
}
|
||||
|
||||
/// A real position is still reported, so withholding zero cannot be
|
||||
/// mistaken for withholding everything — from either rendering path.
|
||||
///
|
||||
/// The webview half is the one that was broken: the element reports 253s, the
|
||||
/// native backend holds nothing, and the stop report went out as 0 and
|
||||
/// overwrote the resume point the frontend had just written correctly.
|
||||
///
|
||||
/// TRACES: UR-025 | DR-178, DR-179 | UT-178
|
||||
#[tokio::test]
|
||||
async fn test_a_stop_reports_the_position_actually_reached() {
|
||||
// Webview-rendered: the element is the only thing that knows.
|
||||
let webview = PlayerController::default();
|
||||
let webview_reports = Arc::new(CapturingReports::new());
|
||||
webview.set_report_sink(webview_reports.clone());
|
||||
webview
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
webview.report_html5_position(253.0, 1500.0);
|
||||
|
||||
webview.stop().unwrap();
|
||||
|
||||
assert_eq!(webview_reports.stops(), vec![("ep2".to_string(), 253.0)]);
|
||||
|
||||
// Natively rendered: the backend is authoritative and still is.
|
||||
let native = PlayerController::default();
|
||||
let native_reports = Arc::new(CapturingReports::new());
|
||||
native.set_report_sink(native_reports.clone());
|
||||
native
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
native.seek(253.0).unwrap();
|
||||
|
||||
native.stop().unwrap();
|
||||
|
||||
assert_eq!(native_reports.stops(), vec![("ep2".to_string(), 253.0)]);
|
||||
}
|
||||
|
||||
/// An episode listened to end-to-end on the lockscreen must count as
|
||||
/// watched. Jellyfin decides that on the `PlaybackStopped` report — no
|
||||
/// report, no completion — and in background audio-only mode there is
|
||||
/// nobody else to send one: the webview is suspended and its `<video>` was
|
||||
/// torn down at the handoff, so the frontend's end-of-playback reporting
|
||||
/// cannot run. The backend advanced to the next episode and said nothing
|
||||
/// about the one that finished.
|
||||
///
|
||||
/// TRACES: UR-040, UR-025 | DR-179 | UT-179
|
||||
#[tokio::test]
|
||||
async fn test_a_finished_audio_only_episode_is_reported_complete() {
|
||||
let controller = PlayerController::default();
|
||||
let reports = Arc::new(CapturingReports::new());
|
||||
controller.set_report_sink(reports.clone());
|
||||
controller.set_repository(Arc::new(MockEpisodeRepo::season(3)));
|
||||
controller
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
// Played out to the end of the 25-minute episode.
|
||||
controller.seek(1499.0).unwrap();
|
||||
controller.take_end_reason();
|
||||
|
||||
controller.on_playback_ended().await.unwrap();
|
||||
|
||||
assert_eq!(
|
||||
reports.stops(),
|
||||
vec![("ep2".to_string(), 1500.0)],
|
||||
"the finished episode must be reported stopped at its runtime, or \
|
||||
Jellyfin's ≥90% rule never marks it played"
|
||||
);
|
||||
}
|
||||
|
||||
/// The completion report is for ends that are really ends. A truncated
|
||||
/// stream is about to be re-opened and the episode is nowhere near over, so
|
||||
/// reporting it stopped would tell Jellyfin the opposite of the truth.
|
||||
///
|
||||
/// TRACES: UR-040, UR-025 | DR-179 | UT-179
|
||||
#[tokio::test]
|
||||
async fn test_a_truncated_stream_reports_no_completion() {
|
||||
let controller = PlayerController::default();
|
||||
let reports = Arc::new(CapturingReports::new());
|
||||
controller.set_report_sink(reports.clone());
|
||||
controller.set_repository(Arc::new(MockEpisodeRepo::season(3)));
|
||||
controller
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
controller.seek(600.0).unwrap();
|
||||
controller.take_end_reason();
|
||||
|
||||
let decision = controller.on_playback_ended().await.unwrap();
|
||||
|
||||
assert!(matches!(decision, AutoplayDecision::ResumeStream { .. }));
|
||||
assert!(
|
||||
reports.stops().is_empty(),
|
||||
"a dropped connection is not a finished episode; got {:?}",
|
||||
reports.stops()
|
||||
);
|
||||
}
|
||||
|
||||
/// Position ticks reach Jellyfin while playback is still going, so closing
|
||||
/// the app — or losing it to a crash — cannot cost the whole session. The
|
||||
/// device trace requested `/Sessions/Playing/Progress` exactly zero times in
|
||||
/// 35 minutes: the frontend service writes progress to the local DB only,
|
||||
/// and nothing on the Rust side reported it for webview-rendered media.
|
||||
///
|
||||
/// TRACES: UR-005, UR-025 | DR-179 | UT-180
|
||||
#[tokio::test]
|
||||
async fn test_webview_position_ticks_report_progress_to_the_server() {
|
||||
let controller = PlayerController::default();
|
||||
let reports = Arc::new(CapturingReports::new());
|
||||
controller.set_report_sink(reports.clone());
|
||||
controller
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
|
||||
controller.report_html5_position(253.4, 1500.0);
|
||||
|
||||
assert_eq!(reports.progress(), vec![("ep2".to_string(), 253.4)]);
|
||||
}
|
||||
|
||||
/// Ticks arrive four times a second; reports must not. The throttler the
|
||||
/// controller already owns bounds them to one per item per 30s.
|
||||
///
|
||||
/// TRACES: UR-005 | DR-179 | UT-180
|
||||
#[tokio::test]
|
||||
async fn test_progress_reports_are_throttled_not_sent_per_tick() {
|
||||
let controller = PlayerController::default();
|
||||
let reports = Arc::new(CapturingReports::new());
|
||||
controller.set_report_sink(reports.clone());
|
||||
controller
|
||||
.play_queue(vec![audio_only_episode(1500.0)], 0)
|
||||
.unwrap();
|
||||
|
||||
for tick in 0..12 {
|
||||
controller.report_html5_position(250.0 + tick as f64 * 0.25, 1500.0);
|
||||
}
|
||||
|
||||
assert_eq!(
|
||||
reports.progress().len(),
|
||||
1,
|
||||
"twelve ticks inside one throttle window are one report"
|
||||
);
|
||||
}
|
||||
|
||||
/// The truncation check compares the position against the item's runtime, so
|
||||
/// both must be on the same timeline.
|
||||
///
|
||||
|
||||
@@ -144,6 +144,18 @@ impl ObservedTime {
|
||||
live.filter(|p| *p >= 0.0).unwrap_or(self.position)
|
||||
}
|
||||
|
||||
/// The last observed position, with no live reading to prefer — the case
|
||||
/// where the *reporter* is the only source there is (webview-rendered media,
|
||||
/// which the native backend cannot see at all).
|
||||
pub fn last_position(&self) -> f64 {
|
||||
self.position
|
||||
}
|
||||
|
||||
/// The last observed duration, if one was ever established.
|
||||
pub fn last_duration(&self) -> Option<f64> {
|
||||
self.duration
|
||||
}
|
||||
|
||||
/// The live reading if there is one, else the last observed value.
|
||||
pub fn duration_or_last(&self, live: Option<f64>) -> Option<f64> {
|
||||
live.filter(|d| *d > 0.0).or(self.duration)
|
||||
|
||||
Reference in New Issue
Block a user