From 06e6c99c03f70023e40e35bd2804e3916e2ec0de Mon Sep 17 00:00:00 2001 From: gion Date: Wed, 15 Apr 2020 18:15:28 +0200 Subject: [PATCH] Disable syncing after several attempts Refactor syncplay manager Attempt fixing Safari issues (timeupdate event not firing) --- src/components/syncplay/groupSelectionMenu.js | 29 +- src/components/syncplay/syncplayManager.js | 428 +++++++++++++----- src/workers/syncplay/syncplay.worker.js | 90 ++++ webpack.dev.js | 4 + webpack.prod.js | 4 + 5 files changed, 437 insertions(+), 118 deletions(-) create mode 100644 src/workers/syncplay/syncplay.worker.js diff --git a/src/components/syncplay/groupSelectionMenu.js b/src/components/syncplay/groupSelectionMenu.js index 1b490db803..c907d338a4 100644 --- a/src/components/syncplay/groupSelectionMenu.js +++ b/src/components/syncplay/groupSelectionMenu.js @@ -13,7 +13,7 @@ import playbackPermissionManager from 'playbackPermissionManager'; * Gets active player id. * @returns {string} The player's id. */ -function getActivePlayerId() { +function getActivePlayerId () { var info = playbackManager.getPlayerInfo(); return info ? info.id : null; } @@ -21,7 +21,7 @@ function getActivePlayerId() { /** * Used to avoid console logs about uncaught promises */ -function emptyCallback() { +function emptyCallback () { // avoid console logs about uncaught promises } @@ -31,15 +31,23 @@ function emptyCallback() { * @param {Object} user - Current user. * @param {Object} apiClient - ApiClient. */ -function showNewJoinGroupSelection(button, user, apiClient) { +function showNewJoinGroupSelection (button, user, apiClient) { let sessionId = getActivePlayerId(); sessionId = sessionId ? sessionId : "none"; const inSession = sessionId !== "none"; const policy = user.localUser ? user.localUser.Policy : {}; + let playingItemId; + try { + const playState = playbackManager.getPlayerState(); + playingItemId = playState.NowPlayingItem.Id; + } catch (error) { + playingItemId = ""; + } apiClient.sendSyncplayCommand(sessionId, "ListGroups").then(function (response) { response.json().then(function (groups) { var menuItems = groups.map(function (group) { + // TODO: update running time if group is playing? var name = datetime.getDisplayRunningTime(group.PositionTicks); if (!inSession) { name = group.PlayingItemName; @@ -90,7 +98,8 @@ function showNewJoinGroupSelection(button, user, apiClient) { apiClient.sendSyncplayCommand(sessionId, "NewGroup"); } else { apiClient.sendSyncplayCommand(sessionId, "JoinGroup", { - GroupId: id + GroupId: id, + PlayingItemId: playingItemId }); } }, emptyCallback); @@ -112,8 +121,16 @@ function showNewJoinGroupSelection(button, user, apiClient) { * @param {Object} user - Current user. * @param {Object} apiClient - ApiClient. */ -function showLeaveGroupSelection(button, user, apiClient) { +function showLeaveGroupSelection (button, user, apiClient) { const sessionId = getActivePlayerId(); + if (!sessionId) { + syncplayManager.signalError(); + toast({ + // TODO: translate + text: "Syncplay error occured." + }); + return; + } const menuItems = [{ @@ -151,7 +168,7 @@ events.on(syncplayManager, 'SyncplayEnabled', function (e, enabled) { * Shows a menu to handle Syncplay groups. * @param {HTMLElement} button - Element where to place the menu. */ -export function show(button) { +export function show (button) { loading.show(); // TODO: should feature be disabled if playback permission is missing? diff --git a/src/components/syncplay/syncplayManager.js b/src/components/syncplay/syncplayManager.js index 8619508e28..86b7ec34af 100644 --- a/src/components/syncplay/syncplayManager.js +++ b/src/components/syncplay/syncplayManager.js @@ -32,7 +32,7 @@ function waitForEvent(emitter, eventType) { * @returns {string} The player's id. */ function getActivePlayerId() { - var info = playbackManager.getPlayerInfo(); + var info = playbackManager.getPlayerInfo(); return info ? info.id : null; } @@ -42,7 +42,9 @@ function getActivePlayerId() { const MaxAcceptedDelaySpeedToSync = 50; // milliseconds, delay after which SpeedToSync is enabled const MaxAcceptedDelaySkipToSync = 300; // milliseconds, delay after which SkipToSync is enabled const SyncMethodThreshold = 2000; // milliseconds, switches between SpeedToSync or SkipToSync -const SpeedUpToSyncTime = 1000; // milliseconds, duration in which the playback is sped up +const SpeedToSyncTime = 1000; // milliseconds, duration in which the playback is sped up +const MaxAttemptsSpeedToSync = 3; // attempts before disabling SpeedToSync +const MaxAttemptsSync = 5; // attempts before disabling syncing at all /** * Time estimation @@ -60,6 +62,9 @@ class SyncplayManager { this.syncEnabled = false; this.playbackDiffMillis = 0; // used for stats this.syncMethod = "None"; // used for stats + this.syncAttempts = 0; + this.lastSyncTime = new Date(); + this.syncWatcherTimeout = null; // interval that watches playback time and syncs it this.lastPlaybackWaiting = null; // used to determine if player's buffering this.minBufferingThresholdMillis = 1000; @@ -86,7 +91,16 @@ class SyncplayManager { events.on(playbackManager, "playerchange", () => { this.onPlayerChange(); }); + + events.on(playbackManager, "playbackstart", (player, state) => { + events.trigger(this, 'PlaybackStart', [player, state]); + }); + this.bindToPlayer(playbackManager.getCurrentPlayer()); + + events.on(this, "TimeUpdate", (event) => { + this.syncPlaybackTime(); + }); } /** @@ -110,53 +124,9 @@ class SyncplayManager { * @param {Object} e The time update event. */ onTimeUpdate (e) { + // NOTICE: this event is unreliable, at least in Safari + // which just stops firing the event after a while. events.trigger(this, "TimeUpdate", [e]); - - if (this.lastCommand && this.lastCommand.Command === 'Play' && !this.isBuffering()) { - var currentTime = new Date(); - var playAtTime = this.lastCommand.When; - - var state = playbackManager.getPlayerState().PlayState; - // Estimate PositionTicks on server - var ServerPositionTicks = this.lastCommand.PositionTicks + ((currentTime - playAtTime) - this.timeDiff) * 10000; - // Measure delay that needs to be recovered - // diff might be caused by the player internally starting the playback - var diff = ServerPositionTicks - state.PositionTicks; - var diffMillis = diff / 10000; - - this.playbackDiffMillis = diffMillis; - - // console.debug("Syncplay onTimeUpdate", diffMillis, state.PositionTicks, ServerPositionTicks); - - if (this.syncEnabled) { - var absDiffMillis = Math.abs(diffMillis); - // TODO: SpeedToSync sounds bad on songs - if (this.playbackRateSupported && absDiffMillis > MaxAcceptedDelaySpeedToSync && absDiffMillis < SyncMethodThreshold) { - // SpeedToSync method - var speed = 1 + diffMillis / SpeedUpToSyncTime; - - this.currentPlayer.setPlaybackRate(speed); - this.syncEnabled = false; - this.showSyncIcon("SpeedToSync (x" + speed + ")"); - - this.syncTimeout = setTimeout(() => { - this.currentPlayer.setPlaybackRate(1); - this.syncEnabled = true; - this.clearSyncIcon(); - }, SpeedUpToSyncTime); - } else if (absDiffMillis > MaxAcceptedDelaySkipToSync) { - // SkipToSync method - playbackManager.syncplay_seek(ServerPositionTicks); - this.syncEnabled = false; - this.showSyncIcon("SkipToSync"); - - this.syncTimeout = setTimeout(() => { - this.syncEnabled = true; - this.clearSyncIcon(); - }, this.syncMethodThreshold / 2); - } - } - } } /** @@ -256,34 +226,7 @@ class SyncplayManager { processGroupUpdate (cmd, apiClient) { switch (cmd.Type) { case 'PrepareSession': - var serverId = apiClient.serverInfo().Id; - playbackManager.play({ - ids: cmd.Data.ItemIds, - startPositionTicks: cmd.Data.StartPositionTicks, - mediaSourceId: cmd.Data.MediaSourceId, - audioStreamIndex: cmd.Data.AudioStreamIndex, - subtitleStreamIndex: cmd.Data.SubtitleStreamIndex, - startIndex: cmd.Data.StartIndex, - serverId: serverId - }).then(() => { - waitForEvent(this, "PlayerChange").then(() => { - playbackManager.pause(); - var sessionId = getActivePlayerId(); - if (!sessionId) { - console.error("Missing sessionId!"); - toast({ - text: "Failed to enable Syncplay!" - }); - return; - } - // Sometimes JoinGroup fails, maybe because server hasn't been updated yet - setTimeout(() => { - apiClient.sendSyncplayCommand(sessionId, "JoinGroup", { - GroupId: cmd.GroupId - }); - }, 500); - }); - }); + this.prepareSession(apiClient, cmd.GroupId, cmd.Data); break; case 'UserJoined': toast({ @@ -296,31 +239,12 @@ class SyncplayManager { }); break; case 'GroupJoined': - toast({ - text: globalize.translate('MessageSyncplayEnabled') - }); - // Enable Syncplay - this.syncplayEnabledAt = new Date(cmd.Data); - this.syncplayReady = false; - events.trigger(this, "SyncplayEnabled", [true]); - waitForEvent(this, "SyncplayReady").then(() => { - this.processCommand(this.queuedCommand, apiClient); - this.queuedCommand = null; - }); - this.injectPlaybackManager(); - this.startPing(); + const enabledAt = new Date(cmd.Data); + this.enableSyncplay(apiClient, enabledAt, true); break; case 'NotInGroup': case 'GroupLeft': - toast({ - text: globalize.translate('MessageSyncplayDisabled') - }); - // Disable Syncplay - this.syncplayEnabledAt = null; - this.syncplayReady = false; - events.trigger(this, "SyncplayEnabled", [false]); - this.restorePlaybackManager(); - this.stopPing(); + this.disableSyncplay(true); break; case 'GroupWait': toast({ @@ -355,8 +279,9 @@ class SyncplayManager { } cmd.When = new Date(cmd.When); + cmd.EmittedAt = new Date(cmd.EmitttedAt); - if (cmd.When < this.syncplayEnabledAt) { + if (cmd.EmitttedAt < this.syncplayEnabledAt) { console.debug("Syncplay processCommand: ignoring old command", cmd); return; } @@ -390,6 +315,114 @@ class SyncplayManager { } } + /** + * Prepares this client to join a group by loading the required content. + * @param {Object} apiClient The ApiClient. + * @param {string} groupId The group to join. + * @param {Object} sessionData Info about the content to load. + */ + prepareSession (apiClient, groupId, sessionData) { + var serverId = apiClient.serverInfo().Id; + playbackManager.play({ + ids: sessionData.ItemIds, + startPositionTicks: sessionData.StartPositionTicks, + mediaSourceId: sessionData.MediaSourceId, + audioStreamIndex: sessionData.AudioStreamIndex, + subtitleStreamIndex: sessionData.SubtitleStreamIndex, + startIndex: sessionData.StartIndex, + serverId: serverId + }).then(() => { + // TODO: switch to PlaybackStart maybe? + waitForEvent(this, "PlayerChange").then(() => { + playbackManager.pause(); + var sessionId = getActivePlayerId(); + if (!sessionId) { + console.error("Missing sessionId!"); + toast({ + // TODO: translate + text: "Failed to enable Syncplay! Missing session id." + }); + return; + } + // Get playing item id + let playingItemId; + try { + const playState = playbackManager.getPlayerState(); + playingItemId = playState.NowPlayingItem.Id; + } catch (error) { + playingItemId = ""; + } + // Sometimes JoinGroup fails, maybe because server hasn't been updated yet + setTimeout(() => { + apiClient.sendSyncplayCommand(sessionId, "JoinGroup", { + GroupId: groupId, + PlayingItemId: playingItemId + }); + }, 500); + }); + }).catch((error) => { + console.error(error); + toast({ + // TODO: translate + text: "Failed to enable Syncplay! Media error." + }); + }); + } + + /** + * Enables Syncplay. + * @param {Object} apiClient The ApiClient. + * @param {Date} enabledAt When Syncplay has been enabled. Server side date. + * @param {boolean} showMessage Display message. + */ + enableSyncplay (apiClient, enabledAt, showMessage = false) { + this.syncplayEnabledAt = enabledAt; + this.syncplayReady = false; + events.trigger(this, "SyncplayEnabled", [true]); + waitForEvent(this, "SyncplayReady").then(() => { + this.processCommand(this.queuedCommand, apiClient); + this.queuedCommand = null; + }); + this.injectPlaybackManager(); + this.startPing(); + + if (showMessage) { + toast({ + text: globalize.translate('MessageSyncplayEnabled') + }); + } + } + + /** + * Disables Syncplay. + * @param {boolean} showMessage Display message. + */ + disableSyncplay (showMessage = false) { + this.syncplayEnabledAt = null; + this.syncplayReady = false; + this.lastCommand = null; + this.queuedCommand = null; + this.syncEnabled = false; + events.trigger(this, "SyncplayEnabled", [false]); + this.restorePlaybackManager(); + this.stopPing(); + this.stopSyncWatcher(); + + if (showMessage) { + toast({ + text: globalize.translate('MessageSyncplayDisabled') + }); + } + } + + /** + * Gets Syncplay status. + * @returns {boolean} _true_ if user joined a group, _false_ otherwise. + */ + isSyncplayEnabled () { + return this.syncplayEnabledAt !== null ? true : false; + } + /** * Schedules a resume playback on the player at the specified clock time. * @param {Date} playAtTime The server's UTC time at which to resume playback. @@ -408,8 +441,9 @@ class SyncplayManager { playbackManager.syncplay_unpause(); this.syncTimeout = setTimeout(() => { - this.syncEnabled = true - }, this.syncMethodThreshold / 2); + this.syncEnabled = true; + this.startSyncWatcher(); + }, SyncMethodThreshold / 2); }, playTimeout); @@ -421,8 +455,9 @@ class SyncplayManager { playbackManager.syncplay_seek(serverPositionTicks); this.syncTimeout = setTimeout(() => { - this.syncEnabled = true - }, this.syncMethodThreshold / 2); + this.syncEnabled = true; + this.startSyncWatcher(); + }, SyncMethodThreshold / 2); } } @@ -471,6 +506,7 @@ class SyncplayManager { clearTimeout(this.syncTimeout); this.syncEnabled = false; + this.stopSyncWatcher(); if (this.currentPlayer) { this.currentPlayer.setPlaybackRate(1); } @@ -587,6 +623,15 @@ class SyncplayManager { var apiClient = connectionManager.currentApiClient(); var sessionId = getActivePlayerId(); + if (!sessionId) { + this.signalError(); + toast({ + // TODO: translate + text: "Syncplay error occured." + }); + return; + } + var pingStartTime = new Date(); apiClient.sendSyncplayCommand(sessionId, "GetUtcTime").then((response) => { var pingEndTime = new Date(); @@ -614,6 +659,13 @@ class SyncplayManager { this.requestPing(); }); + }).catch((error) => { + console.error(error); + this.signalError(); + toast({ + // TODO: translate + text: "Syncplay error occured." + }); }); }, this.pingIntervalTimeout); @@ -627,7 +679,7 @@ class SyncplayManager { this.notifySyncplayReady = true; this.pingStop = false; this.initTimeDiff = this.initTimeDiff > this.greedyPingCount ? 1 : this.initTimeDiff; - this.pingIntervalTimeout = this.pingIntervalTimeoutGreedy; + this.pingIntervalTimeout = PingIntervalTimeoutGreedy; this.requestPing(); } @@ -643,6 +695,159 @@ class SyncplayManager { } } + /** + * Attempts to sync playback time with estimated server time. + * + * When sync is enabled, the following will be checked: + * - check if local playback time is close enough to the server playback time + * If it is not, then a playback time sync will be attempted. + * Two methods of syncing are available: + * - SpeedToSync: speeds up the media for some time to catch up (default is one second) + * - SkipToSync: seeks the media to the estimated correct time + * SpeedToSync aims to reduce the delay as much as possible, whereas SkipToSync is less pretentious. + */ + syncPlaybackTime () { + // Attempt to sync only when media is playing. + if (!this.lastCommand || this.lastCommand.Command !== 'Play' || this.isBuffering()) return; + + const currentTime = new Date(); + + // Avoid overloading the browser + const elapsed = currentTime - this.lastSyncTime; + if (elapsed < SyncMethodThreshold / 2) return; + this.lastSyncTime = currentTime; + this.notifySyncWatcher(); + + const playAtTime = this.lastCommand.When; + + const CurrentPositionTicks = playbackManager.currentTime(); + // Estimate PositionTicks on server + const ServerPositionTicks = this.lastCommand.PositionTicks + ((currentTime - playAtTime) - this.timeDiff) * 10000; + // Measure delay that needs to be recovered + // diff might be caused by the player internally starting the playback + const diff = ServerPositionTicks - CurrentPositionTicks; + const diffMillis = diff / 10000; + + this.playbackDiffMillis = diffMillis; + + // console.debug("Syncplay onTimeUpdate", diffMillis, CurrentPositionTicks, ServerPositionTicks); + + if (this.syncEnabled) { + const absDiffMillis = Math.abs(diffMillis); + // TODO: SpeedToSync sounds bad on songs + // TODO: SpeedToSync is failing on Safari (Mojave); even if playbackRate is supported, some delay seems to exist + if (this.playbackRateSupported && absDiffMillis > MaxAcceptedDelaySpeedToSync && absDiffMillis < SyncMethodThreshold) { + // Disable SpeedToSync if it keeps failing + if (this.syncAttempts > MaxAttemptsSpeedToSync) { + this.playbackRateSupported = false; + } + // SpeedToSync method + const speed = 1 + diffMillis / SpeedToSyncTime; + + this.currentPlayer.setPlaybackRate(speed); + this.syncEnabled = false; + this.syncAttempts++; + this.showSyncIcon("SpeedToSync (x" + speed + ")"); + + this.syncTimeout = setTimeout(() => { + this.currentPlayer.setPlaybackRate(1); + this.syncEnabled = true; + this.clearSyncIcon(); + }, SpeedToSyncTime); + } else if (absDiffMillis > MaxAcceptedDelaySkipToSync) { + // Disable SkipToSync if it keeps failing + if (this.syncAttempts > MaxAttemptsSync) { + this.syncEnabled = false; + this.showSyncIcon("Sync disabled (too many attempts)"); + } + // SkipToSync method + playbackManager.syncplay_seek(ServerPositionTicks); + this.syncEnabled = false; + this.syncAttempts++; + this.showSyncIcon("SkipToSync (" + this.syncAttempts + ")"); + + this.syncTimeout = setTimeout(() => { + this.syncEnabled = true; + this.clearSyncIcon(); + }, SyncMethodThreshold / 2); + } else { + // Playback is synced + if (this.syncAttempts > 0) { + // console.debug("Playback has been synced after", this.syncAttempts, "attempts."); + } + this.syncAttempts = 0; + } + } + } + + /** + * Signals the worker to start watching sync. Also creates the worker if needed. + * + * This additional fail-safe has been added because on Safari the timeupdate event fails after a while. + */ + startSyncWatcher () { + // SPOILER ALERT: this idea fails too on Safari... Keeping it here for future investigations + return; + if (window.Worker) { + // Start worker if needed + if (!this.worker) { + this.worker = new Worker("workers/syncplay/syncplay.worker.js"); + this.worker.onmessage = (event) => { + const message = event.data; + switch (message.type) { + case "TriggerSync": + // TODO: player state might not reflect the real playback position, + // thus calling syncPlaybackTime outside a timeupdate event might not really sync to the right point + this.syncPlaybackTime(); + break; + default: + console.error("Syncplay: unknown message from worker:", message.type); + break; + } + }; + this.worker.onerror = (event) => { + console.error("Syncplay: worker error", event); + }; + this.worker.onmessageerror = (event) => { + console.error("Syncplay: worker message error", event); + }; + } + // Start watcher + this.worker.postMessage({ + type: "StartSyncWatcher", + data: { + interval: SyncMethodThreshold / 2, + threshold: SyncMethodThreshold + } + }); + } else { + console.debug("Syncplay: workers not supported."); + } + } + + /** + * Signals the worker to stop watching sync. + */ + stopSyncWatcher () { + if (this.worker) { + this.worker.postMessage({ + type: "StopSyncWatcher" + }); + } + } + + /** + * Signals new state to worker. + */ + notifySyncWatcher () { + if (this.worker) { + this.worker.postMessage({ + type: "UpdateLastSyncTime", + data: this.lastSyncTime + }); + } + } + /** * Converts server time to local time. * @param {Date} server The time to convert. @@ -663,14 +868,6 @@ class SyncplayManager { return new Date(local.getTime() - this.timeDiff); } - /** - * Gets Syncplay status. - * @returns {boolean} _true_ if user joined a group, _false_ otherwise. - */ - isSyncplayEnabled () { - return this.syncplayEnabledAt !== null ? true : false; - } - /** * Gets Syncplay stats. * @returns {Object} The Syncplay stats. @@ -698,6 +895,13 @@ class SyncplayManager { this.syncMethod = "None"; events.trigger(this, "SyncplayError", [false]); } + + /** + * Signals an error state, which disables and resets Syncplay for a new session. + */ + signalError () { + this.disableSyncplay(); + } } /** SyncplayManager singleton. */ diff --git a/src/workers/syncplay/syncplay.worker.js b/src/workers/syncplay/syncplay.worker.js new file mode 100644 index 0000000000..bd8d2bd60f --- /dev/null +++ b/src/workers/syncplay/syncplay.worker.js @@ -0,0 +1,90 @@ +var SyncTimeThreshold = 2000; // milliseconds, overwritten by startSyncWatcher +var SyncWatcherInterval = 1000; // milliseconds, overwritten by startSyncWatcher +var lastSyncTime = new Date(); // internal state +var syncWatcher; // holds value from setInterval + +/** + * Sends a message to the UI worker. + * @param {string} type + * @param {*} data + */ +function sendMessage (type, data) { + postMessage({ + type: type, + data: data + }); + +} + +/** + * Updates the state. + * @param {Date} syncTime The new state. + */ +function updateLastSyncTime (syncTime) { + lastSyncTime = syncTime; +} + +/** + * Starts sync watcher. + * @param {Object} options Additional options to configure the watcher, like _interval_ and _threshold_. + */ +function startSyncWatcher(options) { + stopSyncWatcher(); + if (options) { + if (options.interval) { + SyncWatcherInterval = options.interval; + } + if (options.threshold) { + SyncTimeThreshold = options.threshold; + } + } + syncWatcher = setInterval(syncWatcherCallback, SyncWatcherInterval); +} + +/** + * Stops sync watcher. + */ +function stopSyncWatcher () { + if (syncWatcher) { + clearInterval(syncWatcher); + syncWatcher = null; + } +} + +/** + * Oversees playback sync and makes sure that it gets called regularly. + */ +function syncWatcherCallback () { + const currentTime = new Date(); + const elapsed = currentTime - lastSyncTime; + if (elapsed > SyncTimeThreshold) { + sendMessage("TriggerSync"); + } +} + +/** + * Handles messages from UI worker. + * @param {MessageEvent} event The message to handle. + */ +function handleMessage (event) { + const message = event.data; + switch (message.type) { + case "UpdateLastSyncTime": + updateLastSyncTime(message.data); + break; + case "StartSyncWatcher": + startSyncWatcher(message.data); + break; + case "StopSyncWatcher": + stopSyncWatcher(); + break; + default: + console.error("Unknown message type:", message.type); + break; + } +} + +// Listen for messages +addEventListener("message", function (event) { + handleMessage(event); +}); diff --git a/webpack.dev.js b/webpack.dev.js index d8879fe808..544d32d63e 100644 --- a/webpack.dev.js +++ b/webpack.dev.js @@ -48,6 +48,10 @@ module.exports = merge(common, { { test: /\.(wav)$/i, use: ["file-loader"] + }, + { + test: /\.worker.js$/, + use: ["worker"] } ] } diff --git a/webpack.prod.js b/webpack.prod.js index cc4c57b9f4..7b5f2ff6c0 100644 --- a/webpack.prod.js +++ b/webpack.prod.js @@ -41,6 +41,10 @@ module.exports = merge(common, { { test: /\.(wav)$/i, use: ["file-loader"] + }, + { + test: /\.worker.js$/, + use: ["worker"] } ] }