feat: more improvements to next troubleshooting (#2974)

* feat: more stream selection with next troubleshooting

* feat: improve next logging

* feat: log next troubleshooting speed

ErsatzTV.Application/Playouts/Commands/SyncNextPlayoutHandler.cs

@@ -253,6 +253,8 @@ public partial class SyncNextPlayoutHandler(
                     maybeGlobalWatermark,
                     playoutOffset,
                     playoutItem,
+                    Option<List<Subtitle>>.None,
+                    shouldLogMessages: false,
                     cancellationToken);
 
                 foreach (var nextPlayoutItem in maybeNextPlayoutItem)

ErsatzTV.Application/Streaming/NextLogger.cs

@@ -0,0 +1,33 @@
+using System.Text.RegularExpressions;
+using Microsoft.Extensions.Logging;
+
+namespace ErsatzTV.Application.Streaming;
+
+public partial class NextLogger
+{
+    [GeneratedRegex(
+        @"^\[\S+ (?<level>TRACE|DEBUG|INFO|WARN|ERROR) (?<target>[^\]]+)\] (?<msg>.*)$",
+        RegexOptions.Singleline)]
+    private static partial Regex NextLogLine();
+
+    public static void LogNextLine(string line, ILogger logger)
+    {
+        Match match = NextLogLine().Match(line);
+        if (!match.Success)
+        {
+            logger.LogDebug("{Line:l}", line);
+            return;
+        }
+
+        LogLevel level = match.Groups["level"].Value switch
+        {
+            "ERROR" => LogLevel.Error,
+            "WARN" => LogLevel.Warning,
+            "INFO" => LogLevel.Information,
+            "TRACE" => LogLevel.Trace,
+            _ => LogLevel.Debug
+        };
+
+        logger.Log(level, "[{Target:l}] {Line:l}", match.Groups["target"].Value, match.Groups["msg"].Value);
+    }
+}

ErsatzTV.Application/Streaming/NextSessionWorker.cs

@@ -120,8 +120,8 @@ public class NextSessionWorker(
             CommandResult commandResult = await Cli.Wrap(channelBinary)
                 .WithArguments(arguments)
                 .WithStandardInputPipe(PipeSource.FromString(channelConfig.ToJson()))
-                .WithStandardOutputPipe(PipeTarget.ToDelegate(l => logger.LogDebug("{Line}", l)))
-                .WithStandardErrorPipe(PipeTarget.ToDelegate(l => logger.LogDebug("{Line}", l)))
+                .WithStandardOutputPipe(PipeTarget.ToDelegate(l => NextLogger.LogNextLine(l, logger)))
+                .WithStandardErrorPipe(PipeTarget.ToDelegate(l => NextLogger.LogNextLine(l, logger)))
                 //.WithStandardOutputPipe(PipeTarget.ToDelegate(progressParser.ParseLine))
                 .WithValidation(CommandResultValidation.None)
                 .ExecuteAsync(_cancellationTokenSource.Token);

ErsatzTV.Application/Troubleshooting/Commands/PrepareTroubleshootingPlaybackHandler.cs

@@ -195,6 +195,7 @@ public class PrepareTroubleshootingPlaybackHandler(
             Name = "ETV",
             Number = FileSystemLayout.TranscodeTroubleshootingChannel,
             FFmpegProfile = ffmpegProfile,
+            StreamingEngine = request.StreamingEngine,
             StreamingMode = request.StreamingMode,
             StreamSelectorMode = ChannelStreamSelectorMode.Troubleshooting,
             SubtitleMode = SubtitleMode
@@ -354,6 +355,8 @@ public class PrepareTroubleshootingPlaybackHandler(
                 watermarks.HeadOrNone().Map(wm => wm.Watermark),
                 TimeSpan.Zero,
                 playoutItem,
+                await GetSubtitles(mediaItem, request),
+                shouldLogMessages: true,
                 cancellationToken);
 
         foreach (var nextPlayoutItem in maybeNextPlayoutItem)

ErsatzTV.Application/Troubleshooting/Commands/StartTroubleshootingPlaybackHandler.cs

@@ -1,12 +1,15 @@
+using System.IO.Abstractions;
 using System.IO.Pipelines;
 using System.Runtime.InteropServices;
 using System.Text.Json;
 using System.Text.Json.Serialization;
 using CliWrap;
+using ErsatzTV.Application.Streaming;
 using ErsatzTV.Core;
 using ErsatzTV.Core.Domain;
 using ErsatzTV.Core.FFmpeg;
 using ErsatzTV.Core.Interfaces.Locking;
+using ErsatzTV.Core.Interfaces.Metadata;
 using ErsatzTV.Core.Interfaces.Streaming;
 using ErsatzTV.Core.Interfaces.Troubleshooting;
 using ErsatzTV.Core.Notifications;
@@ -25,6 +28,8 @@ public class StartTroubleshootingPlaybackHandler(
     IGraphicsEngine graphicsEngine,
     InMemoryLogService logService,
     LoggingLevelSwitches loggingLevelSwitches,
+    ILocalFileSystem localFileSystem,
+    IFileSystem fileSystem,
     ILogger<StartTroubleshootingPlaybackHandler> logger)
     : IRequestHandler<StartTroubleshootingPlayback>
 {
@@ -147,11 +152,11 @@ public class StartTroubleshootingPlaybackHandler(
 
                 var outputPipe = request.StreamingEngine is StreamingEngine.Legacy
                     ? PipeTarget.ToDelegate(progressParser.ParseLine)
-                    : PipeTarget.ToDelegate(l => logger.LogDebug("{Line}", l));
+                    : PipeTarget.ToDelegate(l => NextLogger.LogNextLine(l, logger));
 
                 var errorPipe = request.StreamingEngine is StreamingEngine.Legacy
                     ? PipeTarget.Null
-                    : PipeTarget.ToDelegate(l => logger.LogDebug("{Line}", l));
+                    : PipeTarget.ToDelegate(l => NextLogger.LogNextLine(l, logger));
 
                 CommandResult commandResult = await processWithPipe
                     .WithWorkingDirectory(FileSystemLayout.TranscodeTroubleshootingFolder)
@@ -160,7 +165,31 @@ public class StartTroubleshootingPlaybackHandler(
                     .WithValidation(CommandResultValidation.None)
                     .ExecuteAsync(linkedCts.Token);
 
-                logger.LogDebug("Troubleshooting playback completed with exit code {ExitCode}", commandResult.ExitCode);
+                string processName = request.StreamingEngine is StreamingEngine.Legacy
+                    ? "ffmpeg"
+                    : "ersatztv-channel";
+
+                logger.LogDebug(
+                    "Troubleshooting playback ({ProcessName}) completed with exit code {ExitCode}",
+                    processName,
+                    commandResult.ExitCode);
+
+                if (request.StreamingEngine is StreamingEngine.Next)
+                {
+                    foreach (string dir in localFileSystem.ListSubdirectories(
+                                 FileSystemLayout.TranscodeTroubleshootingFolder))
+                    {
+                        foreach (string file in localFileSystem.ListFiles(dir, "ffreport.log"))
+                        {
+                            foreach (string line in await fileSystem.File.ReadAllLinesAsync(file, cancellationToken))
+                            {
+                                progressParser.ParseLine(line);
+                            }
+
+                            break;
+                        }
+                    }
+                }
 
                 progressParser.LogSpeed(
                     request.MediaItemInfo.Map(i => i.Id),

ErsatzTV.Core/InMemoryLogService.cs

@@ -2,6 +2,7 @@ using Serilog.Core;
 using Serilog.Events;
 using System.Collections.Concurrent;
 using System.Globalization;
+using Serilog.Formatting.Display;
 
 namespace ErsatzTV.Core;
 
@@ -9,6 +10,10 @@ public class InMemorySink : ILogEventSink
 {
     private readonly ConcurrentDictionary<Guid, ConcurrentQueue<string>> _logs = new();
 
+    private static readonly MessageTemplateTextFormatter Formatter = new(
+        "[{Timestamp:HH:mm:ss} {Level}] {Message:lj}{NewLine}{Exception}",
+        CultureInfo.InvariantCulture);
+
     public void Emit(LogEvent logEvent)
     {
         if (logEvent.Properties.TryGetValue(InMemoryLogService.CorrelationIdKey, out var correlationIdValue) &&
@@ -18,15 +23,8 @@ public class InMemorySink : ILogEventSink
 
             using (var writer = new StringWriter())
             {
-                writer.Write($"[{logEvent.Timestamp:HH:mm:ss} {logEvent.Level}] ");
-                logEvent.RenderMessage(writer, CultureInfo.CurrentCulture);
-                if (logEvent.Exception != null)
-                {
-                    writer.WriteLine();
-                    writer.Write(logEvent.Exception);
-                }
-
-                logQueue.Enqueue(writer.ToString());
+                Formatter.Format(logEvent, writer);
+                logQueue.Enqueue(writer.ToString().TrimEnd());
             }
 
             while (logQueue.Count > 100)

ErsatzTV.Core/Interfaces/Scheduling/IPlayoutItemConverter.cs

@@ -14,5 +14,7 @@ public interface IPlayoutItemConverter
         Option<ChannelWatermark> maybeGlobalWatermark,
         TimeSpan playoutOffset,
         PlayoutItem playoutItem,
+        Option<List<Subtitle>> subtitles,
+        bool shouldLogMessages,
         CancellationToken cancellationToken);
 }

ErsatzTV.Infrastructure/Scheduling/PlayoutItemConverter.cs

@@ -67,6 +67,8 @@ public class PlayoutItemConverter(
             maybeGlobalWatermark,
             playoutOffset,
             playoutItem,
+            Option<List<Subtitle>>.None,
+            false,
             cancellationToken);
     }
 
@@ -75,6 +77,8 @@ public class PlayoutItemConverter(
         Option<ChannelWatermark> maybeGlobalWatermark,
         TimeSpan playoutOffset,
         PlayoutItem playoutItem,
+        Option<List<Subtitle>> subtitles,
+        bool shouldLogMessages,
         CancellationToken cancellationToken)
     {
         if (playoutItem is not DynamicPlayoutItem &&
@@ -200,6 +204,8 @@ public class PlayoutItemConverter(
                     playoutItem.PreferredAudioTitle ?? channel.PreferredAudioTitle,
                     playoutItem.PreferredSubtitleLanguageCode ?? channel.PreferredSubtitleLanguageCode,
                     playoutItem.SubtitleMode ?? channel.SubtitleMode,
+                    subtitles,
+                    shouldLogMessages,
                     cancellationToken);
                 await SelectWatermark(
                     maybeGlobalWatermark,
@@ -360,9 +366,15 @@ public class PlayoutItemConverter(
         string preferredAudioTitle,
         string preferredSubtitleLanguage,
         ChannelSubtitleMode subtitleMode,
+        Option<List<Subtitle>> subtitles,
+        bool shouldLogMessages,
         CancellationToken cancellationToken)
     {
-        List<Subtitle> allSubtitles = await GetSubtitles(channel, audioVersion.MediaItem, playoutItem.Id, playoutItem.InPoint);
+        List<Subtitle> allSubtitles = await subtitles.IfNoneAsync(
+            await GetSubtitles(channel, audioVersion.MediaItem, playoutItem.Id, playoutItem.InPoint));
+
+        // TODO: external image subtitles
+        allSubtitles.RemoveAll(s => s.IsImage && s.SubtitleKind is not SubtitleKind.Embedded);
 
         Option<MediaStream> maybeAudioStream = Option<MediaStream>.None;
         Option<Subtitle> maybeSubtitle = Option<Subtitle>.None;
@@ -374,7 +386,7 @@ public class PlayoutItemConverter(
                 nextPlayoutItem.Start,
                 audioVersion,
                 allSubtitles,
-                shouldLogMessages: false);
+                shouldLogMessages);
             maybeAudioStream = result.AudioStream;
             maybeSubtitle = result.Subtitle;
         }
@@ -388,7 +400,7 @@ public class PlayoutItemConverter(
                     channel,
                     preferredAudioLanguage,
                     preferredAudioTitle,
-                    shouldLogMessages: false,
+                    shouldLogMessages,
                     cancellationToken);
 
             maybeSubtitle =
@@ -397,7 +409,7 @@ public class PlayoutItemConverter(
                     channel,
                     preferredSubtitleLanguage,
                     subtitleMode,
-                    shouldLogMessages: false,
+                    shouldLogMessages,
                     cancellationToken);
         }
 
@@ -585,9 +597,6 @@ public class PlayoutItemConverter(
             allSubtitles.RemoveAll(s => s.Codec == "eia_608");
         }
 
-        // TODO: external image subtitles
-        allSubtitles.RemoveAll(s => s.IsImage && s.SubtitleKind is not SubtitleKind.Embedded);
-
         return allSubtitles;
     }
 

ErsatzTV/Pages/Troubleshooting/PlaybackTroubleshooting.razor

@@ -81,20 +81,17 @@
                     }
                 </MudSelect>
             </MudStack>
-            @if (_streamingEngine is StreamingEngine.Legacy)
-            {
-                <MudStack Row="true" Breakpoint="Breakpoint.SmAndDown" Class="form-field-stack gap-md-8 mb-5">
-                    <div class="d-flex">
-                        <MudText>Stream Selector</MudText>
-                    </div>
-                    <MudSelect @bind-Value="_streamSelector" For="@(() => _streamSelector)" Clearable="true" Disabled="@(_streamSelectors.Count == 0)">
-                        @foreach (string selector in _streamSelectors)
-                        {
-                            <MudSelectItem T="string" Value="@selector">@selector</MudSelectItem>
-                        }
-                    </MudSelect>
-                </MudStack>
-            }
+            <MudStack Row="true" Breakpoint="Breakpoint.SmAndDown" Class="form-field-stack gap-md-8 mb-5">
+                <div class="d-flex">
+                    <MudText>Stream Selector</MudText>
+                </div>
+                <MudSelect @bind-Value="_streamSelector" For="@(() => _streamSelector)" Clearable="true" Disabled="@(_streamSelectors.Count == 0)">
+                    @foreach (string selector in _streamSelectors)
+                    {
+                        <MudSelectItem T="string" Value="@selector">@selector</MudSelectItem>
+                    }
+                </MudSelect>
+            </MudStack>
             @if (_channelMode)
             {
                 <MudStack Row="true" Breakpoint="Breakpoint.SmAndDown" Class="form-field-stack gap-md-8 mb-5">