Jellystat: 1.1.11 (cyfershepard/jellystat:latest)
Jellyfin: 10.11.11
Database: PostgreSQL 18
First off, thanks for Jellystat — it's been running on my server for months and it's the main way I get a read on what actually gets watched.
I think I've hit a bug where TV episode watch time gets badly under-recorded. I've dug into it fairly deep, and I want to flag up front that there's a trap in what looks like the obvious fix, so it's worth reading the "one order-of-operations note" bit below before patching anything.
What I noticed
An episode on my Activity page showed 6 minutes 44 seconds of total playback. The episode is 39 minutes long and the user watched it start to finish. Other rows looked plausible, so I went looking in the database.
What seems to be happening
If a session briefly drops out of /Sessions mid-episode, ActivityMonitor closes out the watchdog row and treats what follows as a new segment. That part is fine. The problem is what happens to the second segment.
On flush, the code looks for a recent row for the same item and tries to merge into it. If the merge is rejected, though, the segment doesn't fall through to an insert — it gets filtered out of playbackToInsert too, because that filter only checks item/episode/user identity and never asks whether the merge actually succeeded:
playbackToInsert = playbackToInsert.filter(
(pb) =>
pb.PlaybackDuration >= MINIMUM_SECONDS_TO_INCLUDE_PLAYBACK &&
!ExistingRecords.some(
(er) => er.NowPlayingItemId === pb.NowPlayingItemId && er.EpisodeId === pb.EpisodeId && er.UserId === pb.UserId,
),
);So the segment is dropped with no row written and nothing in the log. The comment just above already describes the intended behaviour ("insert new row if updating existing exceeds the runtime") — it just doesn't happen.
Here's the flush sequence for the 6m 44s episode. The last line is the segment that vanished:
02:19:14 New Data Inserted: 1 <- episode starts
02:25:59 Removed Data from WD Count: 1
02:25:59 Activity inserted/updated Count: 1 <- 404s written
02:26:10 New Data Inserted: 1 <- playback resumes
02:57:57 Removed Data from WD Count: 1 <- ~1907s segment, no insert follows
404 + 1907 = 2311s, which is 38m 31s of a 39m 02s episode. So the recorded 404s is genuinely just the first fragment.
Why it hits TV every time
The merge is gated on this:
newDurationWithingRunTime =
(Number(existing.PlaybackDuration) + Number(playbackData.PlaybackDuration)) * 10000000 <=
Number(existing.RunTimeTicks);
RunTimeTicks comes from jf_recent_playback_activity(), which resolves it as:
COALESCE(i."RunTimeTicks", e."RunTimeTicks")
FROM jf_playback_activity a
LEFT JOIN jf_library_items i ON a."NowPlayingItemId" = i."Id"
LEFT JOIN jf_library_episodes e ON a."EpisodeId" = e."EpisodeId"
For episodes, a."NowPlayingItemId" is the SeriesId (set in getSessionsNotInWatchDog via SeriesId || Id), so i lands on the series row rather than the episode. Jellyfin stores RunTimeTicks = 0 on a lot of series, which is reasonable enough on its side — a series doesn't really have a runtime. But COALESCE skips NULL and not zero, so that zero wins and the episode's actual runtime never gets used.
That leaves RunTimeTicks at 0, so the guard evaluates X <= 0 and can never pass. pg-promise parses int8 as a JS number, so isNumber(0) is true and the guard isn't skipped either.
The divide-by-zero guard added for #267 interacts with this too. Because the CASE ... > 0 ... ELSE 1.0 branch fires, Progress comes back as a constant 1.0 for every TV row, which always satisfies the Progress <= 80.0 resume-candidate test — so the drop path is taken every time rather than avoided. I don't think that guard was wrong to add; the zero just ended up travelling further than expected and reaching a caller that can't tell a sentinel from a real value.
Straight from the live function on my install:
{"ep":"Truth Is the Shrewdest Lie","dur":404,"rt":0,"rtType":"number","prog":1}
{"ep":"The Choice of Failure","dur":2406,"rt":0,"rtType":"number","prog":1}
Movies aren't affected — there NowPlayingItemId is the movie's own Id, so i."RunTimeTicks" is correct. Series that do carry a nominal runtime are affected more mildly: the guard compares against the series nominal instead of the real episode length, so it still drops segments on longer-than-nominal episodes.
Quick way to tell if you're affected
SELECT count(*) FILTER (WHERE "RunTimeTicks" = 0) AS zero_runtime_series,
count(*) AS total_series
FROM jf_library_items WHERE "Type" = 'Series';On mine that's 873 of 1844.
Reproducing it
- Pick a series where
jf_library_items."RunTimeTicks" is 0.
- Start an episode and let it run a few minutes.
- Get the session to drop out of
/Sessions briefly — switching audio or subtitle track during a transcode did it reliably for me.
- Watch the rest of the episode.
- Only the first few minutes end up recorded.
One order-of-operations note
This is the bit I'd most want to flag. Fixing the drop on its own would make things worse rather than better.
If the insert path is corrected but RunTimeTicks is still 0, then the merge still fails for every TV segment — except now each one inserts its own row instead of being discarded. That turns quietly-lost time into a pile of duplicate plays per episode, which reads like #343 all over again and would make #448 noticeably worse.
So the runtime resolution needs to land with or before the insert fix, not after it.
Suggested fixes
1. Resolve the episode runtime first, and treat 0 as unknown.
COALESCE(NULLIF(e."RunTimeTicks", 0), NULLIF(i."RunTimeTicks", 0))
e only matches when EpisodeId is set, so movies fall through to i and keep their current behaviour exactly. This also makes Progress a real percentage again, which the <= 80% resume test depends on to mean anything. The > 0 guard from #267 should stay.
Since migrations are tracked in knex_migrations, this needs to be a new migration file rather than an edit to 077, otherwise existing installs won't pick it up.
2. Don't discard a segment whose merge was rejected. Something like:
const mergedIds = new Set(ExistingDataToUpdate.map((pb) => pb.Id));
playbackToInsert = playbackToInsert.filter(
(pb) => pb.PlaybackDuration >= MINIMUM_SECONDS_TO_INCLUDE_PLAYBACK && !mergedIds.has(pb.Id),
);
ExistingDataToUpdate is already computed by that point and the merge branch reassigns playbackData.Id = existingrow.Id, so this cleanly separates "already merged" from "needs its own row".
More generally, it'd be worth having that guard fail open rather than closed — if the runtime can't be determined, recording the segment seems safer than dropping it. That way a future mismatch shows up as a slightly odd number instead of silently missing time.
What I actually verified, and what I didn't
I confirmed the flush sequence in my own container logs, checked RunTimeTicks/Progress coming back through the app's own db layer, and diffed ActivityMonitor.js against main — it's byte-identical to what's in the 1.1.11 image, so this doesn't look like something already fixed.
What I haven't checked is how common zero-runtime series are on other people's libraries. It's 47% of mine, but that's a sample of one.
I've patched the SQL side locally and it's been clean since, with real runtimes and sensible progress values for both TV and movies. Happy to put up PRs for either or both of the above if that's useful — I'd suggest keeping them separate, since the SQL change is small and self-contained while the insert-path change touches merge behaviour you've clearly had to tune before.
Possibly related
Jellystat: 1.1.11 (
cyfershepard/jellystat:latest)Jellyfin: 10.11.11
Database: PostgreSQL 18
First off, thanks for Jellystat — it's been running on my server for months and it's the main way I get a read on what actually gets watched.
I think I've hit a bug where TV episode watch time gets badly under-recorded. I've dug into it fairly deep, and I want to flag up front that there's a trap in what looks like the obvious fix, so it's worth reading the "one order-of-operations note" bit below before patching anything.
What I noticed
An episode on my Activity page showed 6 minutes 44 seconds of total playback. The episode is 39 minutes long and the user watched it start to finish. Other rows looked plausible, so I went looking in the database.
What seems to be happening
If a session briefly drops out of
/Sessionsmid-episode,ActivityMonitorcloses out the watchdog row and treats what follows as a new segment. That part is fine. The problem is what happens to the second segment.On flush, the code looks for a recent row for the same item and tries to merge into it. If the merge is rejected, though, the segment doesn't fall through to an insert — it gets filtered out of
playbackToInserttoo, because that filter only checks item/episode/user identity and never asks whether the merge actually succeeded:So the segment is dropped with no row written and nothing in the log. The comment just above already describes the intended behaviour ("insert new row if updating existing exceeds the runtime") — it just doesn't happen.
Here's the flush sequence for the 6m 44s episode. The last line is the segment that vanished:
404 + 1907 = 2311s, which is 38m 31s of a 39m 02s episode. So the recorded 404s is genuinely just the first fragment.
Why it hits TV every time
The merge is gated on this:
RunTimeTickscomes fromjf_recent_playback_activity(), which resolves it as:For episodes,
a."NowPlayingItemId"is the SeriesId (set ingetSessionsNotInWatchDogviaSeriesId || Id), soilands on the series row rather than the episode. Jellyfin storesRunTimeTicks = 0on a lot of series, which is reasonable enough on its side — a series doesn't really have a runtime. ButCOALESCEskips NULL and not zero, so that zero wins and the episode's actual runtime never gets used.That leaves
RunTimeTicksat 0, so the guard evaluatesX <= 0and can never pass.pg-promiseparsesint8as a JS number, soisNumber(0)istrueand the guard isn't skipped either.The divide-by-zero guard added for #267 interacts with this too. Because the
CASE ... > 0 ... ELSE 1.0branch fires,Progresscomes back as a constant1.0for every TV row, which always satisfies theProgress <= 80.0resume-candidate test — so the drop path is taken every time rather than avoided. I don't think that guard was wrong to add; the zero just ended up travelling further than expected and reaching a caller that can't tell a sentinel from a real value.Straight from the live function on my install:
Movies aren't affected — there
NowPlayingItemIdis the movie's ownId, soi."RunTimeTicks"is correct. Series that do carry a nominal runtime are affected more mildly: the guard compares against the series nominal instead of the real episode length, so it still drops segments on longer-than-nominal episodes.Quick way to tell if you're affected
On mine that's 873 of 1844.
Reproducing it
jf_library_items."RunTimeTicks"is 0./Sessionsbriefly — switching audio or subtitle track during a transcode did it reliably for me.One order-of-operations note
This is the bit I'd most want to flag. Fixing the drop on its own would make things worse rather than better.
If the insert path is corrected but
RunTimeTicksis still 0, then the merge still fails for every TV segment — except now each one inserts its own row instead of being discarded. That turns quietly-lost time into a pile of duplicate plays per episode, which reads like #343 all over again and would make #448 noticeably worse.So the runtime resolution needs to land with or before the insert fix, not after it.
Suggested fixes
1. Resolve the episode runtime first, and treat 0 as unknown.
eonly matches whenEpisodeIdis set, so movies fall through toiand keep their current behaviour exactly. This also makesProgressa real percentage again, which the<= 80%resume test depends on to mean anything. The> 0guard from #267 should stay.Since migrations are tracked in
knex_migrations, this needs to be a new migration file rather than an edit to077, otherwise existing installs won't pick it up.2. Don't discard a segment whose merge was rejected. Something like:
ExistingDataToUpdateis already computed by that point and the merge branch reassignsplaybackData.Id = existingrow.Id, so this cleanly separates "already merged" from "needs its own row".More generally, it'd be worth having that guard fail open rather than closed — if the runtime can't be determined, recording the segment seems safer than dropping it. That way a future mismatch shows up as a slightly odd number instead of silently missing time.
What I actually verified, and what I didn't
I confirmed the flush sequence in my own container logs, checked
RunTimeTicks/Progresscoming back through the app's own db layer, and diffedActivityMonitor.jsagainstmain— it's byte-identical to what's in the 1.1.11 image, so this doesn't look like something already fixed.What I haven't checked is how common zero-runtime series are on other people's libraries. It's 47% of mine, but that's a sample of one.
I've patched the SQL side locally and it's been clean since, with real runtimes and sensible progress values for both TV and movies. Happy to put up PRs for either or both of the above if that's useful — I'd suggest keeping them separate, since the SQL change is small and self-contained while the insert-path change touches merge behaviour you've clearly had to tune before.
Possibly related