diff --git a/docs/architecture.md b/docs/architecture.md index 4f20a70..4923aed 100644 --- a/docs/architecture.md +++ b/docs/architecture.md @@ -405,6 +405,37 @@ What's **not** verified is the actual Emby round trip - whether produce a transcode that really carries the requested track. That needs a real retest. +**Round 2, after a retest: subtitles specifically still didn't show.** +Found a real gap in the fix above: `applyPlaybackOverrides` was only ever +applied to the *final* stream URL, not to the `PlaybackInfo` **negotiation** +call itself - so `SubtitleMethod=Encode` never reached Emby until after it +had already decided, during negotiation, whether this playback session +would be a full re-encode or a plain remux. Burning a subtitle into the +video is only possible with a real re-encode - appending +`SubtitleMethod=Encode` to a URL for a session Emby had already set up as a +remux plausibly does nothing, regardless of how correct the URL looks. +Fixed by applying `applyPlaybackOverrides` to the negotiation's own params +too (`server/src/index.js`), so Emby is asked to encode *before* it decides +how the session will actually be handled, not just told afterward. +Unit-tested (see session history): the negotiation call now measurably +carries `SubtitleMethod=Encode` whenever a subtitle is requested, same as +the final URL always did. + +Also added `server/src/logger.js`'s `streamLog` (`[watchparty:stream]`, +alongside the party-lifecycle `partyLog` added separately - see "Server-side +logging" below) specifically because two rounds of blind, reasoned-but- +unverified fixes for this one bug is the point where guessing stops being +efficient: one `master.m3u8` request now logs its `itemId` and the +resolved `audio`/`subtitle`/`subtitleMethod`/`quality` values (never the +full URL or params blob - Emby's own `TranscodingUrl` can carry an +`api_key`, confirmed kept out of the log line by a dedicated test case), +so the next retest can confirm from `docker logs`/journalctl alone whether +a requested override actually reached Emby, without needing a devtools +session on whatever machine runs the server. If subtitles still don't show +once this log line confirms `subtitleMethod=Encode` really was sent, the +fault has been narrowed to Emby's own handling of that parameter rather +than anything before it in this app. + ## Assumptions to verify **Confirmed against the real server** (not a guess — actually exercised, @@ -605,10 +636,13 @@ return. Right now it just shows an honest placeholder. Requested once the app was running for real on the user's own server: visibility into what's actually happening, from `docker logs`/journalctl, without needing to reproduce a bug through the UI first. `server/src/logger.js` -is a deliberately tiny `partyLog(message)` (plain `console.log`, prefixed -`[watchparty:party]`, ISO timestamp) plus a `who(userId, userName)` formatter -shared by every call site - no logging library, consistent with this app's -general bias against dependencies it doesn't need. +is deliberately tiny - `partyLog(message)` (`[watchparty:party]`) and +`streamLog(message)` (`[watchparty:stream]`, added a bit later for the +streaming route specifically - see "Player track selection" above), both +plain `console.log` with an ISO timestamp, plus a `who(userId, userName)` +formatter shared by every party-lifecycle call site - no logging library, +consistent with this app's general bias against dependencies it doesn't +need. Covers the party's business lifecycle end to end, called from wherever the state actually changes so every caller is covered without repeating the diff --git a/server/src/index.js b/server/src/index.js index 92522b4..997665e 100644 --- a/server/src/index.js +++ b/server/src/index.js @@ -18,6 +18,7 @@ const { const { embyFetch, proxyEmbyResponse } = require('./embyProxy'); const { PartyManager } = require('./partyManager'); const { attachSocketServer, broadcastLobby, applyLeave } = require('./socketHandler'); +const { streamLog } = require('./logger'); const app = express(); app.set('trust proxy', 1); // behind openresty/nginx - needed for req.secure to reflect the real scheme @@ -245,19 +246,23 @@ app.get('/api/catalog/stream/:itemId/master.m3u8', async (req, res) => { // PlaybackInfo returns a MediaSource with its own ready-to-use // TranscodingUrl carrying whatever Emby actually needs. // - // AudioStreamIndex/SubtitleStreamIndex/MaxStreamingBitrate come from the - // player's language/subtitle/quality pickers, forwarded into the - // negotiation on the off chance Emby's GET-based PlaybackInfo honors them - - // but NOT trusted to have taken effect (this app never sends the + // AudioStreamIndex/SubtitleStreamIndex/MaxStreamingBitrate (and + // SubtitleMethod=Encode, forced by applyPlaybackOverrides whenever a + // subtitle is requested - see its own comment below) come from the + // player's language/subtitle/quality pickers, applied to the negotiation + // itself, not just the final URL. That distinction matters here: whether + // to actually re-encode the video (required to burn in a subtitle) is a + // decision Emby makes *during* PlaybackInfo, not something a later + // query-string tweak on the resulting URL can retroactively change if + // Emby already set up a plain remux. Still not trusted to have taken + // effect on its own, though (this app never sends the // POST-with-DeviceProfile body real Emby web clients use for that - // negotiation, so there's no guarantee a plain GET applies them the same - // way). applyPlaybackOverrides below forces our selection onto whatever - // URL we end up with, Emby-negotiated or hand-built, so a track pick - // can't silently no-op regardless of which path Emby's response takes. + // negotiation, so there's no guarantee a plain GET applies it the same + // way) - applyPlaybackOverrides is applied a second time below, to + // whatever URL we end up with, so a track pick can't silently no-op + // regardless of which path Emby's response takes. const infoParams = new URLSearchParams({ UserId: session.userId }); - for (const key of ['AudioStreamIndex', 'SubtitleStreamIndex', 'MaxStreamingBitrate']) { - if (req.query[key]) infoParams.set(key, req.query[key]); - } + applyPlaybackOverrides(infoParams, req.query); const infoRes = await embyFetch(`/Items/${itemId}/PlaybackInfo?${infoParams}`, session.embyToken); if (!infoRes.ok) { res.status(502).json({ error: 'Impossible de préparer la lecture de ce titre.' }); @@ -281,6 +286,7 @@ app.get('/api/catalog/stream/:itemId/master.m3u8', async (req, res) => { const params = new URLSearchParams(urlQuery || ''); applyPlaybackOverrides(params, req.query); target = `${urlPath}?${params}`; + logStreamRequest(itemId, 'negotiated', params); } else { const params = new URLSearchParams({ UserId: session.userId, @@ -291,11 +297,29 @@ app.get('/api/catalog/stream/:itemId/master.m3u8', async (req, res) => { }); applyPlaybackOverrides(params, req.query); target = `/Videos/${itemId}/master.m3u8?${params}`; + logStreamRequest(itemId, 'fallback', params); } await proxyEmbyResponse(req, res, target, session.embyToken, itemId); }); +// Deliberately logs only these specific override values, never the full +// resolved URL/params blob - Emby's own TranscodingUrl can carry an +// api_key, and that has no business ending up in a log file. Added +// alongside the language/subtitle fix above so it's actually possible to +// confirm from docker logs/journalctl whether a requested override made it +// into the request Emby received, without a devtools session on whatever +// machine is running the server. +function logStreamRequest(itemId, source, params) { + streamLog( + `master.m3u8 itemId=${itemId} source=${source} ` + + `audio=${params.get('AudioStreamIndex') || '(default)'} ` + + `subtitle=${params.get('SubtitleStreamIndex') || '(none)'} ` + + `subtitleMethod=${params.get('SubtitleMethod') || '(none)'} ` + + `quality=${params.get('MaxStreamingBitrate') || '(auto)'}` + ); +} + /** * Forces this app's own audio/subtitle/quality selection onto a transcode * URL, whether that URL came from Emby's own PlaybackInfo negotiation or diff --git a/server/src/logger.js b/server/src/logger.js index 4f4ad97..907bda8 100644 --- a/server/src/logger.js +++ b/server/src/logger.js @@ -18,9 +18,22 @@ function partyLog(message) { console.log(`[watchparty:party] ${new Date().toISOString()} ${message}`); } +// Separate prefix/function for the streaming route (index.js's +// /master.m3u8 handler) - a different concern from the party lifecycle +// above (it's about one HTTP request, not party state), added specifically +// to make the language/subtitle/quality override actually debuggable from +// docker logs/journalctl without needing a browser devtools session on the +// machine running the server. Deliberately logs only the individual +// override values it cares about, never the full resolved URL or params +// blob - Emby's own TranscodingUrl can carry an api_key, and that has no +// business ending up in a log file. +function streamLog(message) { + console.log(`[watchparty:stream] ${new Date().toISOString()} ${message}`); +} + /** `"name(id)"` - the same shape in every party lifecycle log line. */ function who(userId, userName) { return `${userName}(${userId})`; } -module.exports = { partyLog, who }; +module.exports = { partyLog, streamLog, who };