Log process output

src/Abstractions/NexusMods.Abstractions.Games/RunGameTool.cs

@@ -1,6 +1,5 @@
 using System.Diagnostics;
 using System.Globalization;
-using System.Text;
 using CliWrap;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
@@ -13,14 +12,10 @@
 
 namespace NexusMods.Abstractions.Games;
 
-
 /// <summary>
 /// Marker interface for RunGameTool
 /// </summary>
-public interface IRunGameTool : ITool
-{
-
-}
+public interface IRunGameTool : ITool;
 
 /// <summary>
 /// A tool that launches the game, using first found installation.
@@ -38,9 +33,8 @@ public class RunGameTool<T> : IRunGameTool
     /// Whether this tool should be started through the shell instead of directly.
     /// This allows tools to start their own console, allowing users to interact with it.
     /// </summary>
-    public virtual bool UseShell { get; set; } = false;
-
-
+    protected virtual bool UseShell { get; set; } = false;
+
     /// <summary>
     /// Constructor
     /// </summary>
@@ -123,17 +117,10 @@ public async Task Execute(Loadout.Model loadout, CancellationToken cancellationT
 
     private async Task<CommandResult> RunCommand(CancellationToken cancellationToken, AbsolutePath program)
     {
-        var stdOut = new StringBuilder();
-        var stdErr = new StringBuilder();
         var command = new Command(program.ToString())
-            .WithStandardOutputPipe(PipeTarget.ToStringBuilder(stdOut))
-            .WithStandardErrorPipe(PipeTarget.ToStringBuilder(stdErr))
-            .WithValidation(CommandResultValidation.None)
             .WithWorkingDirectory(program.Parent.ToString());
 
-        var result = await _processFactory.ExecuteAsync(command, cancellationToken);
-        if (result.ExitCode != 0)
-            _logger.LogError("While Running {Filename} : {Error} {Output}", program, stdErr, stdOut);
+        var result = await _processFactory.ExecuteAsync(command, cancellationToken: cancellationToken);
         return result;
     }
 

src/Games/NexusMods.Games.StardewValley/RunGameTools/SmapiRunGameTool.cs

@@ -13,5 +13,5 @@ public SmapiRunGameTool(IServiceProvider serviceProvider, StardewValley game)
     {
     }
 
-    public override bool UseShell { get; set; } = true;
+    protected override bool UseShell { get; set; } = true;
 }

src/NexusMods.App/Commandline/CleanupVerbs.cs

@@ -9,6 +9,7 @@
 using NexusMods.Abstractions.Games;
 using NexusMods.Abstractions.Loadouts;
 using NexusMods.Abstractions.Settings;
+using NexusMods.CrossPlatform;
 using NexusMods.DataModel;
 using NexusMods.MnemonicDB.Abstractions;
 using NexusMods.Paths;

src/NexusMods.App/Program.cs

@@ -10,6 +10,7 @@
 using NexusMods.Abstractions.Telemetry;
 using NexusMods.App.BuildInfo;
 using NexusMods.App.UI;
+using NexusMods.CrossPlatform;
 using NexusMods.CrossPlatform.Process;
 using NexusMods.DataModel;
 using NexusMods.Paths;

src/NexusMods.App/LoggingSettings.cs → src/NexusMods.CrossPlatform/LoggingSettings.cs

@@ -1,9 +1,11 @@
+using JetBrains.Annotations;
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
 using NexusMods.Abstractions.Settings;
+using NexusMods.App.BuildInfo;
 using NexusMods.Paths;
 
-namespace NexusMods.App;
+namespace NexusMods.CrossPlatform;
 
 /// <summary>
 /// Settings related to logging in the Nexus Mods App. 
@@ -41,17 +43,19 @@ public record LoggingSettings : ISettings
     /// <summary>
     /// Gets the minimum logging level.
     /// </summary>
-    public LogLevel MinimumLevel { get; init; } = LogLevel.Debug;
+    public LogLevel MinimumLevel { get; [UsedImplicitly] set; } = LogLevel.Debug;
 
     /// <summary>
     /// When enabled, logs will be written to the console as well as the log file.
     /// </summary>
-    #if DEBUG
-    public bool LogToConsole { get; init; } = true;
-    #else
-    public bool LogToConsole { get; init; } = false;
-    #endif
+    public bool LogToConsole { get; [UsedImplicitly] set; } = CompileConstants.IsDebug;
 
+    /// <summary>
+    /// Gets the retention span for process logs.
+    /// </summary>
+    public TimeSpan ProcessLogRetentionSpan { get; } = TimeSpan.FromDays(7);
+
+    /// <inheritdoc/>
     public static ISettingsBuilder Configure(ISettingsBuilder settingsBuilder)
     {
         // TODO: put in some section
@@ -76,7 +80,7 @@ public static ISettingsBuilder Configure(ISettingsBuilder settingsBuilder)
                     )
                     .RequiresRestart()
                 )
-                .AddPropertyToUI(x => x.LogToConsole, propertybuilder => propertybuilder
+                .AddPropertyToUI(x => x.LogToConsole, propertyBuilder => propertyBuilder
                     .AddToSection(sectionId)
                     .WithDisplayName("Log to Console")
                     .WithDescription("When enabled, logs will be written to the console as well as the log file.")

src/NexusMods.CrossPlatform/NexusMods.CrossPlatform.csproj

@@ -41,4 +41,13 @@
         <DependentUpon>IProtocolRegistration.cs</DependentUpon>
       </Compile>
     </ItemGroup>
+
+    <ItemGroup>
+      <ProjectReference Include="..\Abstractions\NexusMods.Abstractions.Settings\NexusMods.Abstractions.Settings.csproj" />
+      <ProjectReference Include="..\NexusMods.App.BuildInfo\NexusMods.App.BuildInfo.csproj" />
+    </ItemGroup>
+
+    <ItemGroup>
+      <ProjectReference Include="..\Abstractions\NexusMods.Abstractions.Settings\NexusMods.Abstractions.Settings.csproj" />
+    </ItemGroup>
 </Project>

src/NexusMods.CrossPlatform/Process/AOSInterop.cs

@@ -34,7 +34,10 @@ protected AOSInterop(ILoggerFactory loggerFactory, IProcessFactory processFactor
     public async Task OpenUrl(Uri url, bool fireAndForget = false, CancellationToken cancellationToken = default)
     {
         var command = CreateCommand(url);
-        var task = _processFactory.ExecuteAsync(command, cancellationToken);
+
+        // NOTE(erri120): don't log the process output of the browser
+        var isWeb = url.Scheme.Equals("http", StringComparison.OrdinalIgnoreCase) || url.Scheme.Equals("https", StringComparison.OrdinalIgnoreCase);
+        var task = _processFactory.ExecuteAsync(command, logProcessOutput: !isWeb, cancellationToken: cancellationToken);
 
         try
         {

src/NexusMods.CrossPlatform/Process/FakeProcessFactory.cs

@@ -19,7 +19,9 @@ public FakeProcessFactory(int exitCode)
         _exitCode = exitCode;
     }
 
-    public async Task<CommandResult> ExecuteAsync(Command command,
+    public async Task<CommandResult> ExecuteAsync(
+        Command command,
+        bool logProcessOutput = true,
         CancellationToken cancellationToken = default)
     {
         Callback?.Invoke(command);

src/NexusMods.CrossPlatform/Process/IProcessFactory.cs

@@ -10,10 +10,11 @@ public interface IProcessFactory
     /// <summary>
     /// Executes the given command that starts the process.
     /// </summary>
-    /// <param name="command">The command to execute.</param>
+    /// <param name="command"></param>
+    /// <param name="logProcessOutput"></param>
     /// <param name="cancellationToken">Allows you to cancel the task, killing the process prematurely.</param>
-    Task<CommandResult> ExecuteAsync(Command command, CancellationToken cancellationToken = default);
-    
+    Task<CommandResult> ExecuteAsync(Command command, bool logProcessOutput = true, CancellationToken cancellationToken = default);
+
     /// <summary>
     /// Executes the gives process asynchronously.
     /// </summary>

src/NexusMods.CrossPlatform/Process/OSInteropLinux.cs

@@ -14,19 +14,26 @@ public class OSInteropLinux : AOSInterop
     /// <summary>
     /// Constructor.
     /// </summary>
-    public OSInteropLinux(ILoggerFactory loggerFactory, IProcessFactory processFactory, IFileSystem fileSystem)
-        : base(loggerFactory, processFactory)
+    public OSInteropLinux(
+        ILoggerFactory loggerFactory,
+        IProcessFactory processFactory,
+        IFileSystem fileSystem) : base(loggerFactory, processFactory)
     {
         _fileSystem = fileSystem;
     }
 
     /// <inheritdoc/>
     protected override Command CreateCommand(Uri uri)
     {
+        // From the man page (https://man.archlinux.org/man/xdg-open.1):
+        // In case of success the process launched from the .desktop file will not be forked off and therefore
+        // may result in xdg-open running for a very long time.
+        // This behaviour intentionally differs from most desktop specific openers to allow terminal based applications
+        // to run using the same terminal xdg-open was called from.
+
         return Cli.Wrap("xdg-open").WithArguments(new[] { uri.ToString() }, escape: true);
     }
-
-
+
     /// <inheritdoc />
     public override AbsolutePath GetOwnExe()
     {

src/NexusMods.CrossPlatform/Process/ProcessFactory.cs

@@ -1,5 +1,8 @@
 using CliWrap;
 using Microsoft.Extensions.Logging;
+using NexusMods.Abstractions.Settings;
+using NexusMods.Paths;
+using NexusMods.Paths.Utilities;
 
 namespace NexusMods.CrossPlatform.Process;
 
@@ -9,18 +12,100 @@ namespace NexusMods.CrossPlatform.Process;
 public class ProcessFactory : IProcessFactory
 {
     private readonly ILogger _logger;
+    private readonly IFileSystem _fileSystem;
+    private readonly AbsolutePath _processLogsFolder;
 
     /// <summary>
     /// Constructor.
     /// </summary>
-    public ProcessFactory(ILogger<ProcessFactory> logger)
+    public ProcessFactory(
+        ILogger<ProcessFactory> logger,
+        IFileSystem fileSystem,
+        ISettingsManager settingsManager)
     {
         _logger = logger;
+        _fileSystem = fileSystem;
+
+        _processLogsFolder = LoggingSettings.GetLogBaseFolder(fileSystem.OS, fileSystem).Combine("ProcessLogs");
+        _logger.LogInformation("Using process log folder at {Path}", _processLogsFolder);
+
+        _processLogsFolder.CreateDirectory();
+
+        CleanupOldLogFiles(logger, _processLogsFolder, settingsManager);
+    }
+
+    private static void CleanupOldLogFiles(ILogger logger, AbsolutePath processLogsFolder, ISettingsManager settingsManager)
+    {
+        var loggingSettings = settingsManager.Get<LoggingSettings>();
+        var retentionSpan = loggingSettings.ProcessLogRetentionSpan;
+
+        var filesToDelete = processLogsFolder
+            .EnumerateFiles()
+            .Where(x => DateTime.Now - x.FileInfo.CreationTime >= retentionSpan)
+            .ToArray();
+
+        foreach (var file in filesToDelete)
+        {
+            try
+            {
+                file.Delete();
+            }
+            catch (Exception e)
+            {
+                logger.LogError(e, "Failed to delete expired log file {Path}", file);
+            }
+        }
     }
 
     /// <inheritdoc />
-    public async Task<CommandResult> ExecuteAsync(Command command,
+    public async Task<CommandResult> ExecuteAsync(
+        Command command,
+        bool logProcessOutput = true,
         CancellationToken cancellationToken = default)
+    {
+        if (!logProcessOutput)
+        {
+            return await ExecuteAsync(command, cancellationToken);
+        }
+
+        var fileName = GetFileName(command);
+
+        var logFileName = $"{fileName}-{DateTime.Now:s}";
+        var stdOutFilePath = _processLogsFolder.Combine(logFileName + ".stdout.log");
+        var stdErrFilePath = _processLogsFolder.Combine(logFileName + ".stderr.log");
+        _logger.LogInformation("Using process logs {StdOutLogPath} and {StdErrLogPath}", stdOutFilePath, stdErrFilePath);
+
+        await using (var stdOutStream = stdOutFilePath.Open(FileMode.Create, FileAccess.ReadWrite, FileShare.Read))
+        await using (var stdErrStream = stdErrFilePath.Open(FileMode.Create, FileAccess.ReadWrite, FileShare.Read))
+        {
+            var stdOutPipe = PipeTarget.ToStream(stdOutStream, autoFlush: true);
+            var stdErrPipe = PipeTarget.ToStream(stdErrStream, autoFlush: true);
+
+            var mergedStdOutPipe = command.StandardOutputPipe == PipeTarget.Null ? stdOutPipe : PipeTarget.Merge(command.StandardOutputPipe, stdOutPipe);
+            var mergedStdErrPipe = command.StandardErrorPipe == PipeTarget.Null ? stdErrPipe : PipeTarget.Merge(command.StandardErrorPipe, stdErrPipe);
+
+            command = command
+                .WithStandardOutputPipe(mergedStdOutPipe)
+                .WithStandardErrorPipe(mergedStdErrPipe);
+
+            var result = await ExecuteAsync(command, cancellationToken);
+            _logger.LogInformation("Command `{Command}` finished after {RunTime} seconds with exit Code {ExitCode}", command.ToString(), result.RunTime.TotalSeconds, result.ExitCode);
+
+            return result;
+        }
+    }
+
+    private string GetFileName(Command command)
+    {
+        if (PathHelpers.IsRooted(command.TargetFilePath, _fileSystem.OS))
+        {
+            return _fileSystem.FromUnsanitizedFullPath(command.TargetFilePath).FileName;
+        }
+
+        return new RelativePath(command.TargetFilePath).FileName.ToString();
+    }
+
+    private async Task<CommandResult> ExecuteAsync(Command command, CancellationToken cancellationToken)
     {
         _logger.LogInformation("Executing command `{Command}`", command.ToString());
         return await command.ExecuteAsync(cancellationToken);
@@ -34,7 +119,7 @@ public Task ExecuteProcessAsync(System.Diagnostics.Process process, Cancellation
         process.EnableRaisingEvents = true;
         var hasExited = false;
 
-        process.Exited += (sender, args) =>
+        process.Exited += (_, _) =>
         {
             hasExited = true;
             tcs.SetResult();

src/NexusMods.CrossPlatform/ProtocolRegistration/ProtocolRegistrationLinux.cs

@@ -21,8 +21,6 @@ public class ProtocolRegistrationLinux : IProtocolRegistration
     /// <summary>
     /// Constructor.
     /// </summary>
-    /// <param name="processFactory"></param>
-    /// <param name="fileSystem"></param>
     public ProtocolRegistrationLinux(IProcessFactory processFactory, IFileSystem fileSystem, IOSInterop osInterop)
     {
         _processFactory = processFactory;

tests/NexusMods.CrossPlatform.Tests/NexusMods.CrossPlatform.Tests.csproj

@@ -1,6 +1,7 @@
 <Project Sdk="Microsoft.NET.Sdk">
     <ItemGroup>
         <ProjectReference Include="..\..\src\NexusMods.CrossPlatform\NexusMods.CrossPlatform.csproj" />
+        <ProjectReference Include="..\..\src\NexusMods.Settings\NexusMods.Settings.csproj" />
     </ItemGroup>
     <ItemGroup>
       <None Update="xunit.runner.json">

tests/NexusMods.CrossPlatform.Tests/OSInteropTests.cs

@@ -55,6 +55,7 @@ private static async Task TestWithCommand(
             .ExecuteAsync(Arg.Is<Command>(command =>
                     command.TargetFilePath == targetFilePath &&
                     command.Arguments == arguments),
+                Arg.Any<bool>(),
                 Arg.Any<CancellationToken>()
             )
             .Returns(Task.FromResult(new CommandResult(0, DateTimeOffset.Now, DateTimeOffset.Now)));
@@ -66,6 +67,7 @@ await processFactory
             .Received(1)
             .ExecuteAsync(
                 Arg.Any<Command>(),
+                Arg.Any<bool>(),
                 Arg.Any<CancellationToken>()
             );
     }

tests/NexusMods.CrossPlatform.Tests/ProtocolRegistrationTests.Linux.cs

@@ -34,7 +34,7 @@ public async Task ShouldError_IsSelfHandler_Linux()
         const string protocol = "foo";
         var processFactory = new FakeProcessFactory(0)
         {
-            StandardOutput = "no\n"
+            StandardOutput = "no\n",
         };
 
         var protocolRegistration = new ProtocolRegistrationLinux(processFactory, FileSystem.Shared, interop);

tests/NexusMods.CrossPlatform.Tests/Startup.cs

@@ -1,6 +1,8 @@
 using Microsoft.Extensions.DependencyInjection;
 using Microsoft.Extensions.Logging;
+using NexusMods.Abstractions.Settings;
 using NexusMods.Paths;
+using NexusMods.Settings;
 using Xunit.DependencyInjection;
 
 namespace NexusMods.CrossPlatform.Tests;
@@ -10,6 +12,8 @@ public class Startup
     public void ConfigureServices(IServiceCollection container)
     {
         container
+            .AddSettingsManager()
+            .AddSettings<LoggingSettings>()
             .AddFileSystem()
             .AddCrossPlatform()
             .AddSkippableFactSupport()