Add environment variable to set minimum log level

Agent/Phantom.Agent.Services/Backups/BackupManager.cs

@@ -55,7 +55,7 @@ sealed partial class BackupManager {
 
 		public async Task<BackupCreationResult> CreateBackup() {
 			logger.Information("Backup started.");
-			session.AddOutputListener(listener.OnOutput, 0);
+			session.AddOutputListener(listener.OnOutput, maxLinesToReadFromHistory: 0);
 			try {
 				var resultBuilder = new BackupCreationResult.Builder();
 				

Agent/Phantom.Agent.Services/Backups/BackupScheduler.cs

@@ -11,13 +11,13 @@ sealed class BackupScheduler : CancellableBackgroundTask {
 	private static readonly TimeSpan InitialDelay = TimeSpan.FromMinutes(2);
 	private static readonly TimeSpan BackupInterval = TimeSpan.FromMinutes(30);
 	private static readonly TimeSpan BackupFailureRetryDelay = TimeSpan.FromMinutes(5);
-	private static readonly TimeSpan OnlinePlayersCheckInterval = TimeSpan.FromMinutes(1);
 
 	private readonly string loggerName;
 	private readonly BackupManager backupManager;
 	private readonly InstanceSession session;
 	private readonly int serverPort;
 	private readonly ServerStatusProtocol serverStatusProtocol;
+	private readonly ManualResetEventSlim serverOutputWhileWaitingForOnlinePlayers = new ();
 
 	public BackupScheduler(TaskManager taskManager, BackupManager backupManager, InstanceSession session, int serverPort, string loggerName) : base(PhantomLogger.Create<BackupScheduler>(loggerName), taskManager, "Backup scheduler for " + loggerName) {
 		this.loggerName = loggerName;
@@ -38,7 +38,7 @@ sealed class BackupScheduler : CancellableBackgroundTask {
 				await Task.Delay(BackupFailureRetryDelay, CancellationToken);
 			}
 			else {
-				Logger.Warning("Scheduling next backup in {Minutes} minutes.", BackupInterval.TotalMinutes);
+				Logger.Information("Scheduling next backup in {Minutes} minutes.", BackupInterval.TotalMinutes);
 				await Task.Delay(BackupInterval, CancellationToken);
 				await WaitForOnlinePlayers();
 			}
@@ -52,24 +52,41 @@ sealed class BackupScheduler : CancellableBackgroundTask {
 	private async Task WaitForOnlinePlayers() {
 		bool needsToLogOfflinePlayersMessage = true;
 		
-		while (!CancellationToken.IsCancellationRequested) {
+		session.AddOutputListener(ServerOutputListener, maxLinesToReadFromHistory: 0);
-			var onlinePlayerCount = await serverStatusProtocol.GetOnlinePlayerCount(serverPort, CancellationToken);
+		try {
-			if (onlinePlayerCount == null) {
+			while (!CancellationToken.IsCancellationRequested) {
-				Logger.Warning("Could not detect whether any players are online, starting a new backup.");
+				serverOutputWhileWaitingForOnlinePlayers.Reset();
-				break;
-			}
 				
-			if (onlinePlayerCount > 0) {
+				var onlinePlayerCount = await serverStatusProtocol.GetOnlinePlayerCount(serverPort, CancellationToken);
-				Logger.Information("Players are online, starting a new backup.");
+				if (onlinePlayerCount == null) {
-				break;
+					Logger.Warning("Could not detect whether any players are online, starting a new backup.");
-			}
+					break;
+				}
 
-			if (needsToLogOfflinePlayersMessage) {
+				if (onlinePlayerCount > 0) {
-				needsToLogOfflinePlayersMessage = false;
+					Logger.Information("Players are online, starting a new backup.");
-				Logger.Information("No players are online, waiting for someone to join before starting a new backup.");
+					break;
-			}
+				}
 
-			await Task.Delay(OnlinePlayersCheckInterval, CancellationToken);
+				if (needsToLogOfflinePlayersMessage) {
+					needsToLogOfflinePlayersMessage = false;
+					Logger.Information("No players are online, waiting for someone to join before starting a new backup.");
+				}
+
+				await Task.Delay(TimeSpan.FromSeconds(10), CancellationToken);
+				
+				Logger.Verbose("Waiting for server output before checking for online players again...");
+				await serverOutputWhileWaitingForOnlinePlayers.WaitHandle.WaitOneAsync(CancellationToken);
+			}
+		} finally {
+			session.RemoveOutputListener(ServerOutputListener);
+		}
+	}
+
+	private void ServerOutputListener(object? sender, string line) {
+		if (!serverOutputWhileWaitingForOnlinePlayers.IsSet) {
+			serverOutputWhileWaitingForOnlinePlayers.Set();
+			Logger.Verbose("Detected server output, signalling to check for online players again.");
 		}
 	}
 }

Common/Phantom.Common.Logging/DefaultLogLevel.cs

@@ -0,0 +1,42 @@
+using System.Diagnostics.CodeAnalysis;
+using Serilog.Events;
+
+namespace Phantom.Common.Logging; 
+
+static class DefaultLogLevel {
+	private const string ENVIRONMENT_VARIABLE = "LOG_LEVEL";
+	
+	public static LogEventLevel Value { get; } = GetDefaultLevel();
+	
+	public static LogEventLevel Coerce(LogEventLevel level) {
+		return level < Value ? Value : level;
+	}
+	
+	private static LogEventLevel GetDefaultLevel() {
+		var level = Environment.GetEnvironmentVariable(ENVIRONMENT_VARIABLE);
+		return level switch {
+			"VERBOSE"     => LogEventLevel.Verbose,
+			"DEBUG"       => LogEventLevel.Debug,
+			"INFORMATION" => LogEventLevel.Information,
+			"WARNING"     => LogEventLevel.Warning,
+			"ERROR"       => LogEventLevel.Error,
+			null          => GetDefaultLevelFallback(),
+			_             => LogEnvironmentVariableErrorAndExit(level)
+		};
+	}
+
+	private static LogEventLevel GetDefaultLevelFallback() {
+		#if DEBUG
+		return LogEventLevel.Verbose;
+		#else
+		return LogEventLevel.Information;
+		#endif
+	}
+
+	[DoesNotReturn]
+	private static LogEventLevel LogEnvironmentVariableErrorAndExit(string logLevel) {
+		Console.Error.WriteLine("Invalid value of environment variable {0}: {1}", ENVIRONMENT_VARIABLE, logLevel);
+		Environment.Exit(1);
+		return LogEventLevel.Fatal;
+	}
+}

Common/Phantom.Common.Logging/PhantomLogger.cs

@@ -7,28 +7,21 @@ using Serilog.Sinks.SystemConsole.Themes;
 namespace Phantom.Common.Logging;
 
 public static class PhantomLogger {
-	public static Logger Root { get; } = CreateBaseLogger("[{Timestamp:HH:mm:ss} {Level:u}] {Message:lj}{NewLine}{Exception}");
+	public static Logger Root { get; } = CreateLogger("[{Timestamp:HH:mm:ss} {Level:u}] {Message:lj}{NewLine}{Exception}");
-	private static Logger Base { get; } = CreateBaseLogger("[{Timestamp:HH:mm:ss} {Level:u}] [{Category}] {Message:lj}{NewLine}{Exception}");
+	private static Logger Base { get; } = CreateLogger("[{Timestamp:HH:mm:ss} {Level:u}] [{Category}] {Message:lj}{NewLine}{Exception}");
 	
-	private static LogEventLevel GetDefaultLevel() {
+	private static Logger CreateLogger(string template) {
-		#if DEBUG
+		return new LoggerConfiguration()
-		return LogEventLevel.Verbose;
+		       .MinimumLevel.Is(DefaultLogLevel.Value)
-		#else
+		       .MinimumLevel.Override("Microsoft", DefaultLogLevel.Coerce(LogEventLevel.Information))
-		return LogEventLevel.Information;
+		       .MinimumLevel.Override("Microsoft.AspNetCore", DefaultLogLevel.Coerce(LogEventLevel.Warning))
-		#endif
+		       .MinimumLevel.Override("Microsoft.EntityFrameworkCore.Database.Command", DefaultLogLevel.Coerce(LogEventLevel.Warning))
+		       .Filter.ByExcluding(static e => e.Exception is OperationCanceledException)
+		       .Enrich.FromLogContext()
+		       .WriteTo.Console(outputTemplate: template, formatProvider: CultureInfo.InvariantCulture, theme: AnsiConsoleTheme.Literate)
+		       .CreateLogger();
 	}
 
-	private static Logger CreateBaseLogger(string template) =>
-		new LoggerConfiguration()
-			.MinimumLevel.Is(GetDefaultLevel())
-			.MinimumLevel.Override("Microsoft", LogEventLevel.Information)
-			.MinimumLevel.Override("Microsoft.AspNetCore", LogEventLevel.Warning)
-			.MinimumLevel.Override("Microsoft.EntityFrameworkCore.Database.Command", LogEventLevel.Warning)
-			.Filter.ByExcluding(static e => e.Exception is OperationCanceledException)
-			.Enrich.FromLogContext()
-			.WriteTo.Console(outputTemplate: template, formatProvider: CultureInfo.InvariantCulture, theme: AnsiConsoleTheme.Literate)
-			.CreateLogger();
-
 	public static ILogger Create(string name) {
 		return Base.ForContext("Category", name);
 	}

README.md

@@ -97,6 +97,18 @@ Use volumes to persist either the whole `/data` folder, or just `/data/data` if
   - `ALLOWED_SERVER_PORTS` is a comma-separated list of ports and port ranges that can be used as Minecraft Server ports. Example: `25565,25900,26000-27000`
   - `ALLOWED_RCON_PORTS` is a comma-separated list of ports and port ranges that can be used as Minecraft RCON ports. Example: `25575,25901,36000-37000`
 
+## Logging
+
+Both the Server and Agent support a `LOG_LEVEL` environment variable to set the minimum log level. Possible values:
+
+* `VERBOSE`
+* `DEBUG`
+* `INFORMATION`
+* `WARNING`
+* `ERROR`
+
+If the environment variable is omitted, the log level is set to `VERBOSE` for Debug builds and `INFORMATION` for Release builds.
+
 # Development
 
 The repository includes a [Rider](https://www.jetbrains.com/rider/) projects with several run configurations. The `.workdir` folder in the root of the repository is used for storage. Here's how to get started:

Utils/Phantom.Utils.Runtime/WaitHandleExtensions.cs

@@ -0,0 +1,27 @@
+namespace Phantom.Utils.Runtime;
+
+public static class WaitHandleExtensions {
+	public static Task WaitOneAsync(this WaitHandle waitHandle, CancellationToken cancellationToken = default) {
+		var taskCompletionSource = new TaskCompletionSource();
+
+		void SetResult(object? state, bool timedOut) {
+			taskCompletionSource.TrySetResult();
+		}
+
+		void SetCancelled() {
+			taskCompletionSource.TrySetCanceled(cancellationToken);
+		}
+
+		var waitRegistration = ThreadPool.RegisterWaitForSingleObject(waitHandle, SetResult, null, Timeout.InfiniteTimeSpan, true);
+		var tokenRegistration = cancellationToken.Register(SetCancelled, useSynchronizationContext: false);
+
+		void Cleanup(Task t) {
+			waitRegistration.Unregister(null);
+			tokenRegistration.Dispose();
+		}
+
+		var task = taskCompletionSource.Task;
+		task.ContinueWith(Cleanup, CancellationToken.None);
+		return task;
+	}
+}