From 6746f708f2c2f306ea04270b93cfed2e28eb36c9 Mon Sep 17 00:00:00 2001 From: Vasily Date: Thu, 3 Oct 2019 16:17:35 +0300 Subject: [PATCH 01/16] Revert "Revert "Fix premature stop when streaming"" This reverts commit 575b96d03a2cf98a0e5dd9d9f7329adca34c0311. --- .../Playback/Hls/DynamicHlsService.cs | 15 +++------------ 1 file changed, 3 insertions(+), 12 deletions(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index f5f7536843..8fa6c3dac0 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -965,14 +965,6 @@ namespace MediaBrowser.Api.Playback.Hls var outputTsArg = Path.Combine(Path.GetDirectoryName(outputPath), Path.GetFileNameWithoutExtension(outputPath)) + "%d" + GetSegmentFileExtension(state.Request); - var timeDeltaParam = string.Empty; - - if (isEncoding && state.TargetFramerate > 0) - { - float startTime = 1 / (state.TargetFramerate.Value * 2); - timeDeltaParam = string.Format(CultureInfo.InvariantCulture, "-segment_time_delta {0:F3}", startTime); - } - var segmentFormat = GetSegmentFileExtension(state.Request).TrimStart('.'); if (string.Equals(segmentFormat, "ts", StringComparison.OrdinalIgnoreCase)) { @@ -980,7 +972,7 @@ namespace MediaBrowser.Api.Playback.Hls } return string.Format( - "{0} {1} -map_metadata -1 -map_chapters -1 -threads {2} {3} {4} {5} -f segment -max_delay 5000000 -avoid_negative_ts disabled -start_at_zero -segment_time {6} {10} -individual_header_trailer 0 -segment_format {11} -segment_list_type m3u8 -segment_start_number {7} -segment_list \"{8}\" -y \"{9}\"", + "{0} {1} -map_metadata -1 -map_chapters -1 -threads {2} {3} {4} {5} -f hls -max_delay 5000000 -avoid_negative_ts disabled -start_at_zero -hls_time {6} -individual_header_trailer 0 -hls_segment_type {7} -start_number {8} -hls_segment_filename \"{9}\" -hls_playlist_type vod -hls_list_size 0 -y \"{10}\"", inputModifier, EncodingHelper.GetInputArgument(state, encodingOptions), threads, @@ -988,11 +980,10 @@ namespace MediaBrowser.Api.Playback.Hls GetVideoArguments(state, encodingOptions), GetAudioArguments(state, encodingOptions), state.SegmentLength.ToString(CultureInfo.InvariantCulture), + segmentFormat, startNumberParam, - outputPath, outputTsArg, - timeDeltaParam, - segmentFormat + outputPath ).Trim(); } } From c1f9107b8be9b3cbd26e15773998c7ac6598e7f9 Mon Sep 17 00:00:00 2001 From: Vasily Date: Thu, 3 Oct 2019 18:50:39 +0300 Subject: [PATCH 02/16] Add more logging Trying to fix hls muxer plus ffmpeg 4.1+ combo Try to fix waiting for segment being ready This is needed because hls muxer in ffmpeg >= 4.1 creates the playlist only when it finishes transcoding. Also cleaned up logs a bit. Lower log level for "StartFfmpeg finished" to debug --- .../Playback/BaseStreamingService.cs | 7 ++- .../Playback/Hls/DynamicHlsService.cs | 47 ++++++++----------- deployment/debian-package-x64/docker-build.sh | 1 + 3 files changed, 27 insertions(+), 28 deletions(-) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index 8c4ccfa22c..700883c963 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -289,16 +289,20 @@ namespace MediaBrowser.Api.Playback throw; } + Logger.LogDebug("Launched ffmpeg process"); state.TranscodingJob = transcodingJob; // Important - don't await the log task or we won't be able to kill ffmpeg when the user stops playback _ = new JobLogger(Logger).StartStreamingLog(state, process.StandardError.BaseStream, logStream); // Wait for the file to exist before proceeeding - while (!File.Exists(state.WaitForPath ?? outputPath) && !transcodingJob.HasExited) + var waitFor = state.WaitForPath ?? outputPath; + Logger.LogDebug("Waiting for the creation of '{0}'", waitFor); + while (!File.Exists(waitFor) && !transcodingJob.HasExited) { await Task.Delay(100, cancellationTokenSource.Token).ConfigureAwait(false); } + Logger.LogDebug("File '{0}' created or transcoding has finished", waitFor); if (state.IsInputVideo && transcodingJob.Type == TranscodingJobType.Progressive && !transcodingJob.HasExited) { @@ -314,6 +318,7 @@ namespace MediaBrowser.Api.Playback { StartThrottler(state, transcodingJob); } + Logger.LogDebug("StartFfMpeg() finished successfully"); return transcodingJob; } diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 8fa6c3dac0..15dd5add4a 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -243,6 +243,7 @@ namespace MediaBrowser.Api.Playback.Hls request.StartTimeTicks = GetStartPositionTicks(state, requestedIndex); + state.WaitForPath = segmentPath; job = await StartFfMpeg(state, playlistPath, cancellationTokenSource).ConfigureAwait(false); } catch @@ -458,16 +459,15 @@ namespace MediaBrowser.Api.Playback.Hls TranscodingJob transcodingJob, CancellationToken cancellationToken) { - var segmentFileExists = File.Exists(segmentPath); - - // If all transcoding has completed, just return immediately - if (transcodingJob != null && transcodingJob.HasExited && segmentFileExists) + var segmentExists = File.Exists(segmentPath); + if (segmentExists) { - return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); - } + if (transcodingJob != null && transcodingJob.HasExited) + { + // Transcoding job is over, so assume all existing files are ready + return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); + } - if (segmentFileExists) - { var currentTranscodingIndex = GetCurrentTranscodingIndex(playlistPath, segmentExtension); // If requested segment is less than transcoding position, we can't transcode backwards, so assume it's ready @@ -477,33 +477,26 @@ namespace MediaBrowser.Api.Playback.Hls } } - var segmentFilename = Path.GetFileName(segmentPath); - + var nextSegmentPath = GetSegmentPath(state, playlistPath, segmentIndex + 1); while (!cancellationToken.IsCancellationRequested) { - try + // To be considered ready, the segment file has to exist AND + // either the transcoding job should be done or next segment should also exit + if (segmentExists) { - var text = File.ReadAllText(playlistPath, Encoding.UTF8); - - // If it appears in the playlist, it's done - if (text.IndexOf(segmentFilename, StringComparison.OrdinalIgnoreCase) != -1) + if ((transcodingJob != null && transcodingJob.HasExited) || File.Exists(nextSegmentPath)) { - if (!segmentFileExists) - { - segmentFileExists = File.Exists(segmentPath); - } - if (segmentFileExists) - { - return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); - } - //break; + return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } } - catch (IOException) + else { - // May get an error if the file is locked + segmentExists = File.Exists(segmentPath); + if (segmentExists) + { + continue; // avoid unnecessary waiting if segment just became available + } } - await Task.Delay(100, cancellationToken).ConfigureAwait(false); } diff --git a/deployment/debian-package-x64/docker-build.sh b/deployment/debian-package-x64/docker-build.sh index 97bc45a060..5911923d78 100755 --- a/deployment/debian-package-x64/docker-build.sh +++ b/deployment/debian-package-x64/docker-build.sh @@ -20,6 +20,7 @@ if [[ -n ${web_branch} ]]; then checkout -b origin/${web_branch} fi yarn install +yarn build mkdir -p ${web_target} mv dist/* ${web_target}/ popd From 7aea9266d05ddd0673c390e102833c154b3ff9f6 Mon Sep 17 00:00:00 2001 From: Vasily Date: Tue, 8 Oct 2019 16:34:43 +0300 Subject: [PATCH 03/16] Stop waiting for a segment to become ready if there's no alive transcode Remove extra quotes in logging Fix typo in comment --- .../Playback/BaseStreamingService.cs | 4 ++-- .../Playback/Hls/DynamicHlsService.cs | 22 +++++++++++++++---- 2 files changed, 20 insertions(+), 6 deletions(-) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index 700883c963..2e9c1c3d4c 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -297,12 +297,12 @@ namespace MediaBrowser.Api.Playback // Wait for the file to exist before proceeeding var waitFor = state.WaitForPath ?? outputPath; - Logger.LogDebug("Waiting for the creation of '{0}'", waitFor); + Logger.LogDebug("Waiting for the creation of {0}", waitFor); while (!File.Exists(waitFor) && !transcodingJob.HasExited) { await Task.Delay(100, cancellationTokenSource.Token).ConfigureAwait(false); } - Logger.LogDebug("File '{0}' created or transcoding has finished", waitFor); + Logger.LogDebug("File {0} created or transcoding has finished", waitFor); if (state.IsInputVideo && transcodingJob.Type == TranscodingJobType.Progressive && !transcodingJob.HasExited) { diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 15dd5add4a..a06a2f84d9 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -192,6 +192,7 @@ namespace MediaBrowser.Api.Playback.Hls if (File.Exists(segmentPath)) { job = ApiEntryPoint.Instance.OnTranscodeBeginRequest(playlistPath, TranscodingJobType); + Logger.LogDebug("returning {0} [it exists, try 1]", segmentPath); return await GetSegmentResult(state, playlistPath, segmentPath, segmentExtension, requestedIndex, job, cancellationToken).ConfigureAwait(false); } @@ -207,6 +208,7 @@ namespace MediaBrowser.Api.Playback.Hls job = ApiEntryPoint.Instance.OnTranscodeBeginRequest(playlistPath, TranscodingJobType); transcodingLock.Release(); released = true; + Logger.LogDebug("returning {0} [it exists, try 2]", segmentPath); return await GetSegmentResult(state, playlistPath, segmentPath, segmentExtension, requestedIndex, job, cancellationToken).ConfigureAwait(false); } else @@ -278,7 +280,7 @@ namespace MediaBrowser.Api.Playback.Hls // await Task.Delay(50, cancellationToken).ConfigureAwait(false); //} - Logger.LogInformation("returning {0}", segmentPath); + Logger.LogDebug("returning {0} [general case]", segmentPath); job = job ?? ApiEntryPoint.Instance.OnTranscodeBeginRequest(playlistPath, TranscodingJobType); return await GetSegmentResult(state, playlistPath, segmentPath, segmentExtension, requestedIndex, job, cancellationToken).ConfigureAwait(false); } @@ -465,6 +467,7 @@ namespace MediaBrowser.Api.Playback.Hls if (transcodingJob != null && transcodingJob.HasExited) { // Transcoding job is over, so assume all existing files are ready + Logger.LogDebug("serving up {0} as transcode is over", segmentPath); return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } @@ -473,19 +476,21 @@ namespace MediaBrowser.Api.Playback.Hls // If requested segment is less than transcoding position, we can't transcode backwards, so assume it's ready if (segmentIndex < currentTranscodingIndex) { + Logger.LogDebug("serving up {0} as transcode index {1} is past requested point {2}", segmentPath, segmentIndex, currentTranscodingIndex); return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } } var nextSegmentPath = GetSegmentPath(state, playlistPath, segmentIndex + 1); - while (!cancellationToken.IsCancellationRequested) + while (!cancellationToken.IsCancellationRequested && transcodingJob != null && !transcodingJob.HasExited) { // To be considered ready, the segment file has to exist AND - // either the transcoding job should be done or next segment should also exit + // either the transcoding job should be done or next segment should also exist if (segmentExists) { - if ((transcodingJob != null && transcodingJob.HasExited) || File.Exists(nextSegmentPath)) + if (transcodingJob.HasExited || File.Exists(nextSegmentPath)) { + Logger.LogDebug("serving up {0} as it deemed ready", segmentPath); return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } } @@ -501,6 +506,14 @@ namespace MediaBrowser.Api.Playback.Hls } cancellationToken.ThrowIfCancellationRequested(); + if (!File.Exists(segmentPath)) + { + Logger.LogWarning("cannot serve {0} as transcoding quit before we got there", segmentPath); + } + else + { + Logger.LogDebug("serving {0} as it's on disk and transcoding stopped", segmentPath); + } return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } @@ -514,6 +527,7 @@ namespace MediaBrowser.Api.Playback.Hls FileShare = FileShareMode.ReadWrite, OnComplete = () => { + Logger.LogDebug("finished serving {0}", segmentPath); if (transcodingJob != null) { transcodingJob.DownloadPositionTicks = Math.Max(transcodingJob.DownloadPositionTicks ?? segmentEndingPositionTicks, segmentEndingPositionTicks); From 3740228100b15c9feae1864f5652674af69e582c Mon Sep 17 00:00:00 2001 From: Vasily Date: Tue, 8 Oct 2019 17:00:16 +0300 Subject: [PATCH 04/16] Don't start waiting for a segment which doesn't exist if transcoding is not running --- .../Playback/Hls/DynamicHlsService.cs | 48 +++++++++++-------- 1 file changed, 28 insertions(+), 20 deletions(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index a06a2f84d9..43cf924274 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -482,38 +482,46 @@ namespace MediaBrowser.Api.Playback.Hls } var nextSegmentPath = GetSegmentPath(state, playlistPath, segmentIndex + 1); - while (!cancellationToken.IsCancellationRequested && transcodingJob != null && !transcodingJob.HasExited) + if (transcodingJob != null) { - // To be considered ready, the segment file has to exist AND - // either the transcoding job should be done or next segment should also exist - if (segmentExists) + while (!cancellationToken.IsCancellationRequested && !transcodingJob.HasExited) { - if (transcodingJob.HasExited || File.Exists(nextSegmentPath)) + // To be considered ready, the segment file has to exist AND + // either the transcoding job should be done or next segment should also exist + if (segmentExists) { - Logger.LogDebug("serving up {0} as it deemed ready", segmentPath); - return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); + if (transcodingJob.HasExited || File.Exists(nextSegmentPath)) + { + Logger.LogDebug("serving up {0} as it deemed ready", segmentPath); + return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); + } } - } - else - { - segmentExists = File.Exists(segmentPath); - if (segmentExists) + else { - continue; // avoid unnecessary waiting if segment just became available + segmentExists = File.Exists(segmentPath); + if (segmentExists) + { + continue; // avoid unnecessary waiting if segment just became available + } } + await Task.Delay(100, cancellationToken).ConfigureAwait(false); } - await Task.Delay(100, cancellationToken).ConfigureAwait(false); - } - cancellationToken.ThrowIfCancellationRequested(); - if (!File.Exists(segmentPath)) - { - Logger.LogWarning("cannot serve {0} as transcoding quit before we got there", segmentPath); + cancellationToken.ThrowIfCancellationRequested(); + if (!File.Exists(segmentPath)) + { + Logger.LogWarning("cannot serve {0} as transcoding quit before we got there", segmentPath); + } + else + { + Logger.LogDebug("serving {0} as it's on disk and transcoding stopped", segmentPath); + } } else { - Logger.LogDebug("serving {0} as it's on disk and transcoding stopped", segmentPath); + Logger.LogWarning("cannot serve {0} as it doesn't exist and no transcode is running", segmentPath); } + return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } From 986ea5c636ead098446cca31ea737d2f361a05d8 Mon Sep 17 00:00:00 2001 From: Vasily Date: Wed, 9 Oct 2019 12:55:09 +0300 Subject: [PATCH 05/16] Fix log message - log args were swapped --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 43cf924274..069dd41d02 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -476,7 +476,7 @@ namespace MediaBrowser.Api.Playback.Hls // If requested segment is less than transcoding position, we can't transcode backwards, so assume it's ready if (segmentIndex < currentTranscodingIndex) { - Logger.LogDebug("serving up {0} as transcode index {1} is past requested point {2}", segmentPath, segmentIndex, currentTranscodingIndex); + Logger.LogDebug("serving up {0} as transcode index {1} is past requested point {2}", segmentPath, currentTranscodingIndex, segmentIndex); return await GetSegmentResult(state, segmentPath, segmentIndex, transcodingJob).ConfigureAwait(false); } } From 2f6879e8699e53c3d140dacd9af8c207bdf8cb74 Mon Sep 17 00:00:00 2001 From: Vasily Date: Wed, 9 Oct 2019 13:46:01 +0300 Subject: [PATCH 06/16] Add limiting max keyframe interval when full transcoding --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 12 ++++++++++++ 1 file changed, 12 insertions(+) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 069dd41d02..8cbe4af1e8 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -927,6 +927,18 @@ namespace MediaBrowser.Api.Playback.Hls " -force_key_frames:0 \"expr:gte(t,{0}+n_forced*{1})\"", GetStartNumber(state) * state.SegmentLength, state.SegmentLength.ToString(CultureInfo.InvariantCulture)); + if (state.TargetFramerate.HasValue) + { + // This is to make sure keyframe interval is limited to our segment, + // as forcing keyframes is not enough. + // Example: we ecoded half of desired length, then codec detected + // scene cut and inserted a keyframe; next forced keyframe would + // be created outside of segment, which breaks seeking. + keyFrameArg += string.Format( + " -g {0} -keyint_min {0}", + (int)(state.SegmentLength * state.TargetFramerate) + ); + } var hasGraphicalSubs = state.SubtitleStream != null && !state.SubtitleStream.IsTextSubtitleStream && state.SubtitleDeliveryMethod == SubtitleDeliveryMethod.Encode; From 82f8345aa5ae65a8a934a4f2d29afdbc3836d875 Mon Sep 17 00:00:00 2001 From: Vasily Date: Thu, 10 Oct 2019 18:47:02 +0300 Subject: [PATCH 07/16] Log to debug all HTTP 500 response urls --- Emby.Server.Implementations/HttpServer/HttpListenerHost.cs | 4 ++++ 1 file changed, 4 insertions(+) diff --git a/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs b/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs index e4f98acb9b..0ebdf7d178 100644 --- a/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs +++ b/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs @@ -539,6 +539,10 @@ namespace Emby.Server.Implementations.HttpServer } finally { + if (httpRes.StatusCode >= 500) + { + _logger.LogDebug("Sending HTTP Response 500 in response to {Url}", urlToLog); + } stopWatch.Stop(); var elapsed = stopWatch.Elapsed; if (elapsed.TotalMilliseconds > 500) From 1bd12083c3d7eda02bd7e3b785f4853620dc6cc9 Mon Sep 17 00:00:00 2001 From: Vasily Date: Mon, 14 Oct 2019 13:12:10 +0300 Subject: [PATCH 08/16] Respect non-inversed setting of "enable break on non-keyframes" --- MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs | 3 ++- 1 file changed, 2 insertions(+), 1 deletion(-) diff --git a/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs b/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs index 991fc0b001..0aa0679045 100644 --- a/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs +++ b/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs @@ -2168,7 +2168,8 @@ namespace MediaBrowser.Controller.MediaEncoding // Important: If this is ever re-enabled, make sure not to use it with wtv because it breaks seeking if (!string.Equals(state.InputContainer, "wtv", StringComparison.OrdinalIgnoreCase) && state.TranscodingType != TranscodingJobType.Progressive - && state.EnableBreakOnNonKeyFrames(outputVideoCodec)) + && !state.EnableBreakOnNonKeyFrames(outputVideoCodec) && + (state.BaseRequest.StartTimeTicks ?? 0) > 0) { inputModifier += " -noaccurate_seek"; } From 3132280b0748efd6ded7d8c9d8795506ef8c30ed Mon Sep 17 00:00:00 2001 From: Vasily Date: Mon, 14 Oct 2019 13:13:04 +0300 Subject: [PATCH 09/16] * Make sure force_key_frames expression arguments are properly converted to strings * Fore usage of keyframe cuts only in HLS --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 13 +++++++++++-- 1 file changed, 11 insertions(+), 2 deletions(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 8cbe4af1e8..1b93eaaa57 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -925,7 +925,7 @@ namespace MediaBrowser.Api.Playback.Hls { var keyFrameArg = string.Format( " -force_key_frames:0 \"expr:gte(t,{0}+n_forced*{1})\"", - GetStartNumber(state) * state.SegmentLength, + (GetStartNumber(state) * state.SegmentLength).ToString(CultureInfo.InvariantCulture), state.SegmentLength.ToString(CultureInfo.InvariantCulture)); if (state.TargetFramerate.HasValue) { @@ -936,7 +936,7 @@ namespace MediaBrowser.Api.Playback.Hls // be created outside of segment, which breaks seeking. keyFrameArg += string.Format( " -g {0} -keyint_min {0}", - (int)(state.SegmentLength * state.TargetFramerate) + ((int)(state.SegmentLength * state.TargetFramerate)).ToString(CultureInfo.InvariantCulture) ); } @@ -982,6 +982,15 @@ namespace MediaBrowser.Api.Playback.Hls var threads = EncodingHelper.GetNumberOfThreads(state, encodingOptions, videoCodec); + if (state.BaseRequest.BreakOnNonKeyFrames) + { + // FIXME: this is actually a workaround, as ideally it really should be the client which decides whether non-keyframe + // breakpoints are supported; but current implementation always uses "ffmpeg input seeking" which is liable + // to produce a missing part of video stream before first keyframe is encountered, which may lead to + // awkward cases like a few starting HLS segments having no video whatsoever, which breaks hls.js + Logger.LogInformation("Current HLS implementation doesn't support non-keyframe breaks but one is requested, ignoring that request"); + state.BaseRequest.BreakOnNonKeyFrames = false; + } var inputModifier = EncodingHelper.GetInputModifier(state, encodingOptions); // If isEncoding is true we're actually starting ffmpeg From adccc18298f4ebba511b68d5af9e72f78de5e5e8 Mon Sep 17 00:00:00 2001 From: Vasily Date: Mon, 14 Oct 2019 13:15:41 +0300 Subject: [PATCH 10/16] Revert "yarn build" as it is fixed in master, fix typo --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 2 +- deployment/debian-package-x64/docker-build.sh | 1 - 2 files changed, 1 insertion(+), 2 deletions(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 1b93eaaa57..a95db53e42 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -931,7 +931,7 @@ namespace MediaBrowser.Api.Playback.Hls { // This is to make sure keyframe interval is limited to our segment, // as forcing keyframes is not enough. - // Example: we ecoded half of desired length, then codec detected + // Example: we encoded half of desired length, then codec detected // scene cut and inserted a keyframe; next forced keyframe would // be created outside of segment, which breaks seeking. keyFrameArg += string.Format( diff --git a/deployment/debian-package-x64/docker-build.sh b/deployment/debian-package-x64/docker-build.sh index 5911923d78..97bc45a060 100755 --- a/deployment/debian-package-x64/docker-build.sh +++ b/deployment/debian-package-x64/docker-build.sh @@ -20,7 +20,6 @@ if [[ -n ${web_branch} ]]; then checkout -b origin/${web_branch} fi yarn install -yarn build mkdir -p ${web_target} mv dist/* ${web_target}/ popd From 6b6fede2e0b1c1edd06af3bcdbf5c5ad04d07638 Mon Sep 17 00:00:00 2001 From: Vasily Date: Wed, 16 Oct 2019 16:13:59 +0300 Subject: [PATCH 11/16] Address review comments --- .../HttpServer/HttpListenerHost.cs | 1 + MediaBrowser.Api/Playback/BaseStreamingService.cs | 8 ++++---- 2 files changed, 5 insertions(+), 4 deletions(-) diff --git a/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs b/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs index 0ebdf7d178..cd2a7dcf06 100644 --- a/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs +++ b/Emby.Server.Implementations/HttpServer/HttpListenerHost.cs @@ -543,6 +543,7 @@ namespace Emby.Server.Implementations.HttpServer { _logger.LogDebug("Sending HTTP Response 500 in response to {Url}", urlToLog); } + stopWatch.Stop(); var elapsed = stopWatch.Elapsed; if (elapsed.TotalMilliseconds > 500) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index 2e9c1c3d4c..fa8fbe261c 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -296,13 +296,13 @@ namespace MediaBrowser.Api.Playback _ = new JobLogger(Logger).StartStreamingLog(state, process.StandardError.BaseStream, logStream); // Wait for the file to exist before proceeeding - var waitFor = state.WaitForPath ?? outputPath; - Logger.LogDebug("Waiting for the creation of {0}", waitFor); - while (!File.Exists(waitFor) && !transcodingJob.HasExited) + var ffmpegTargetFile = state.WaitForPath ?? outputPath; + Logger.LogDebug("Waiting for the creation of {0}", ffmpegTargetFile); + while (!File.Exists(ffmpegTargetFile) && !transcodingJob.HasExited) { await Task.Delay(100, cancellationTokenSource.Token).ConfigureAwait(false); } - Logger.LogDebug("File {0} created or transcoding has finished", waitFor); + Logger.LogDebug("File {0} created or transcoding has finished", ffmpegTargetFile); if (state.IsInputVideo && transcodingJob.Type == TranscodingJobType.Progressive && !transcodingJob.HasExited) { From ae2b95024f8da21910bf3d3706aa5eff8d66f4a1 Mon Sep 17 00:00:00 2001 From: Vasily Date: Mon, 21 Oct 2019 11:58:04 +0300 Subject: [PATCH 12/16] Update MediaBrowser.Api/Playback/BaseStreamingService.cs Co-Authored-By: Bond-009 --- MediaBrowser.Api/Playback/BaseStreamingService.cs | 1 + 1 file changed, 1 insertion(+) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index fa8fbe261c..7bfe0e0cea 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -302,6 +302,7 @@ namespace MediaBrowser.Api.Playback { await Task.Delay(100, cancellationTokenSource.Token).ConfigureAwait(false); } + Logger.LogDebug("File {0} created or transcoding has finished", ffmpegTargetFile); if (state.IsInputVideo && transcodingJob.Type == TranscodingJobType.Progressive && !transcodingJob.HasExited) From 3743137c312581412c00c29907f7c8c2ca884ffc Mon Sep 17 00:00:00 2001 From: Vasily Date: Mon, 21 Oct 2019 12:04:57 +0300 Subject: [PATCH 13/16] Address Bond-009 review comments --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 10 +++++----- .../MediaEncoding/EncodingHelper.cs | 4 ++-- 2 files changed, 7 insertions(+), 7 deletions(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index a95db53e42..709069153c 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -923,10 +923,10 @@ namespace MediaBrowser.Api.Playback.Hls } else { - var keyFrameArg = string.Format( + var keyFrameArg = string.Format(CultureInfo.InvariantCulture, " -force_key_frames:0 \"expr:gte(t,{0}+n_forced*{1})\"", - (GetStartNumber(state) * state.SegmentLength).ToString(CultureInfo.InvariantCulture), - state.SegmentLength.ToString(CultureInfo.InvariantCulture)); + GetStartNumber(state) * state.SegmentLength, + state.SegmentLength); if (state.TargetFramerate.HasValue) { // This is to make sure keyframe interval is limited to our segment, @@ -934,9 +934,9 @@ namespace MediaBrowser.Api.Playback.Hls // Example: we encoded half of desired length, then codec detected // scene cut and inserted a keyframe; next forced keyframe would // be created outside of segment, which breaks seeking. - keyFrameArg += string.Format( + keyFrameArg += string.Format(CultureInfo.InvariantCulture, " -g {0} -keyint_min {0}", - ((int)(state.SegmentLength * state.TargetFramerate)).ToString(CultureInfo.InvariantCulture) + (int)(state.SegmentLength * state.TargetFramerate) ); } diff --git a/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs b/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs index 0aa0679045..0f4e449725 100644 --- a/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs +++ b/MediaBrowser.Controller/MediaEncoding/EncodingHelper.cs @@ -2168,8 +2168,8 @@ namespace MediaBrowser.Controller.MediaEncoding // Important: If this is ever re-enabled, make sure not to use it with wtv because it breaks seeking if (!string.Equals(state.InputContainer, "wtv", StringComparison.OrdinalIgnoreCase) && state.TranscodingType != TranscodingJobType.Progressive - && !state.EnableBreakOnNonKeyFrames(outputVideoCodec) && - (state.BaseRequest.StartTimeTicks ?? 0) > 0) + && !state.EnableBreakOnNonKeyFrames(outputVideoCodec) + && (state.BaseRequest.StartTimeTicks ?? 0) > 0) { inputModifier += " -noaccurate_seek"; } From dd7ae7747e770ef4545fbe6aeb5b1ab327a3550a Mon Sep 17 00:00:00 2001 From: Vasily Date: Sun, 27 Oct 2019 16:47:00 +0300 Subject: [PATCH 14/16] Apply suggestions from code review Co-Authored-By: Bond-009 --- MediaBrowser.Api/Playback/BaseStreamingService.cs | 1 + MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 7 +++++-- 2 files changed, 6 insertions(+), 2 deletions(-) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index 7bfe0e0cea..3fc1e099f8 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -321,6 +321,7 @@ namespace MediaBrowser.Api.Playback } Logger.LogDebug("StartFfMpeg() finished successfully"); + return transcodingJob; } diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 709069153c..9654af4639 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -504,6 +504,7 @@ namespace MediaBrowser.Api.Playback.Hls continue; // avoid unnecessary waiting if segment just became available } } + await Task.Delay(100, cancellationToken).ConfigureAwait(false); } @@ -923,7 +924,8 @@ namespace MediaBrowser.Api.Playback.Hls } else { - var keyFrameArg = string.Format(CultureInfo.InvariantCulture, + var keyFrameArg = string.Format( + CultureInfo.InvariantCulture, " -force_key_frames:0 \"expr:gte(t,{0}+n_forced*{1})\"", GetStartNumber(state) * state.SegmentLength, state.SegmentLength); @@ -934,7 +936,8 @@ namespace MediaBrowser.Api.Playback.Hls // Example: we encoded half of desired length, then codec detected // scene cut and inserted a keyframe; next forced keyframe would // be created outside of segment, which breaks seeking. - keyFrameArg += string.Format(CultureInfo.InvariantCulture, + keyFrameArg += string.Format( + CultureInfo.InvariantCulture, " -g {0} -keyint_min {0}", (int)(state.SegmentLength * state.TargetFramerate) ); From 8cf8c36708ae57257810c77120828285a22d2799 Mon Sep 17 00:00:00 2001 From: Vasily Date: Sun, 27 Oct 2019 16:48:42 +0300 Subject: [PATCH 15/16] Move throwing if cancelled after logging that fact --- MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs index 9654af4639..9ecb5fe8c5 100644 --- a/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs +++ b/MediaBrowser.Api/Playback/Hls/DynamicHlsService.cs @@ -508,7 +508,6 @@ namespace MediaBrowser.Api.Playback.Hls await Task.Delay(100, cancellationToken).ConfigureAwait(false); } - cancellationToken.ThrowIfCancellationRequested(); if (!File.Exists(segmentPath)) { Logger.LogWarning("cannot serve {0} as transcoding quit before we got there", segmentPath); @@ -517,6 +516,7 @@ namespace MediaBrowser.Api.Playback.Hls { Logger.LogDebug("serving {0} as it's on disk and transcoding stopped", segmentPath); } + cancellationToken.ThrowIfCancellationRequested(); } else { From d4474d493b6813135d3b2bf2e9e4f8a4756bf594 Mon Sep 17 00:00:00 2001 From: Joshua Boniface Date: Sun, 3 Nov 2019 12:39:45 -0500 Subject: [PATCH 16/16] Remove extraneous newline --- MediaBrowser.Api/Playback/BaseStreamingService.cs | 1 - 1 file changed, 1 deletion(-) diff --git a/MediaBrowser.Api/Playback/BaseStreamingService.cs b/MediaBrowser.Api/Playback/BaseStreamingService.cs index 3fc1e099f8..7bfe0e0cea 100644 --- a/MediaBrowser.Api/Playback/BaseStreamingService.cs +++ b/MediaBrowser.Api/Playback/BaseStreamingService.cs @@ -321,7 +321,6 @@ namespace MediaBrowser.Api.Playback } Logger.LogDebug("StartFfMpeg() finished successfully"); - return transcodingJob; }