From 03b6702a6a36ee0e6249aad3f2335005e05c921e Mon Sep 17 00:00:00 2001 From: Christopher Homberger Date: Wed, 11 Dec 2024 18:03:46 +0100 Subject: [PATCH 1/4] fix verbose breaks jsonl logger --- src/Runner.Client/ExternalToolHelper.cs | 22 +-- src/Runner.Client/Program.cs | 243 +++++++++++++----------- 2 files changed, 141 insertions(+), 124 deletions(-) diff --git a/src/Runner.Client/ExternalToolHelper.cs b/src/Runner.Client/ExternalToolHelper.cs index 152513587df..5c1c1aabcdc 100644 --- a/src/Runner.Client/ExternalToolHelper.cs +++ b/src/Runner.Client/ExternalToolHelper.cs @@ -46,7 +46,7 @@ private static string runnerOfficialUrl(string runner_URL, string runner12_VERSI return $"{runner_URL}/v{runner12_VERSION}/runner-v{runner12_VERSION}-{os}-{arch}.{suffix}"; } - private static async Task DownloadTool(string link, string destDirectory, CancellationToken token, string tarextraopts = "", bool unwrap = false) { + private static async Task DownloadTool(Program.Parameters parameters, string link, string destDirectory, CancellationToken token, string tarextraopts = "", bool unwrap = false) { Console.WriteLine($"Downloading from {link} to {destDirectory}"); string tempDirectory = Path.Combine(GitHub.Runner.Sdk.GharunUtil.GetLocalStorage(), "temp" + System.Guid.NewGuid().ToString()); var stagingDirectory = Path.Combine(tempDirectory, "_staging"); @@ -117,7 +117,7 @@ private static async Task DownloadTool(string link, string destDirectory, Cancel string tar = WhichUtil.Which("tar", require: true); // tar -xzf - using (var processInvoker = new ProcessInvoker(new Program.TraceWriter())) + using (var processInvoker = new ProcessInvoker(new Program.TraceWriter(parameters))) { processInvoker.OutputDataReceived += new EventHandler((sender, args) => { @@ -164,7 +164,7 @@ private static async Task DownloadTool(string link, string destDirectory, Cancel IOUtil.DeleteDirectory(tempDirectory, CancellationToken.None); } } - public static async Task GetAgent(string name, string version, CancellationToken token) { + internal static async Task GetAgent(Program.Parameters parameters, string name, string version, CancellationToken token) { // Allow versions like v3.0.0 and not only 3.0.0 version = version.Substring(version.IndexOf("v") + 1); var azagent = name == "azagent"; @@ -180,14 +180,14 @@ public static async Task GetAgent(string name, string version, Cancellat // Note use the vsts package, because container operations have node6 hardcoded as trampoline Func AURL = azagent ? (arch, ext) => $"https://vstsagentpackage.azureedge.net/agent/{version}/vsts-agent-{arch}-{version}.{ext}" : (arch, ext) => $"https://github.com/actions/runner/releases/download/v{version}/actions-runner-{arch}-{version}.{ext}"; var _tools = new Dictionary> { - { "windows/386", dest => DownloadTool(AURL("win-x86", "zip"), dest, token, unwrap: false)}, - { "windows/amd64", dest => DownloadTool(AURL("win-x64", "zip"), dest, token, unwrap: false)}, - { "windows/arm64", dest => DownloadTool(AURL("win-arm64", "zip"), dest, token, unwrap: false)}, - { "linux/amd64", dest => DownloadTool(AURL("linux-x64", "tar.gz"), dest, token, unwrap: false)}, - { "linux/arm", dest => DownloadTool(AURL("linux-arm", "tar.gz"), dest, token, unwrap: false)}, - { "linux/arm64", dest => DownloadTool(AURL("linux-arm64", "tar.gz"), dest, token, unwrap: false)}, - { "osx/amd64", dest => DownloadTool(AURL("osx-x64", "tar.gz"), dest, token, unwrap: false)}, - { "osx/arm64", dest => DownloadTool(AURL("osx-arm64", "tar.gz"), dest, token, unwrap: false)}, + { "windows/386", dest => DownloadTool(parameters, AURL("win-x86", "zip"), dest, token, unwrap: false)}, + { "windows/amd64", dest => DownloadTool(parameters, AURL("win-x64", "zip"), dest, token, unwrap: false)}, + { "windows/arm64", dest => DownloadTool(parameters, AURL("win-arm64", "zip"), dest, token, unwrap: false)}, + { "linux/amd64", dest => DownloadTool(parameters, AURL("linux-x64", "tar.gz"), dest, token, unwrap: false)}, + { "linux/arm", dest => DownloadTool(parameters, AURL("linux-arm", "tar.gz"), dest, token, unwrap: false)}, + { "linux/arm64", dest => DownloadTool(parameters, AURL("linux-arm64", "tar.gz"), dest, token, unwrap: false)}, + { "osx/amd64", dest => DownloadTool(parameters, AURL("osx-x64", "tar.gz"), dest, token, unwrap: false)}, + { "osx/arm64", dest => DownloadTool(parameters, AURL("osx-arm64", "tar.gz"), dest, token, unwrap: false)}, }; if(_tools.TryGetValue(platform, out Func download)) { await download(Path.Combine(externalsPath, name, version)); diff --git a/src/Runner.Client/Program.cs b/src/Runner.Client/Program.cs index 2b7b0b92179..6210bda6da5 100644 --- a/src/Runner.Client/Program.cs +++ b/src/Runner.Client/Program.cs @@ -72,21 +72,21 @@ private class WebConsoleEvent { public class TraceWriter : GitHub.Runner.Sdk.ITraceWriter { - private bool verbose; - public TraceWriter(bool verbose = false) { - this.verbose = verbose; + private Parameters parameters; + public TraceWriter(Parameters parameters) { + this.parameters = parameters; } public void Info(string message) { - if(verbose) { - Console.WriteLine(message); + if(parameters.Verbose) { + WriteLogMessage(parameters, "trace", message); } } public void Verbose(string message) { - if(verbose) { - Console.WriteLine(message); + if(parameters.Verbose) { + WriteLogMessage(parameters, "trace", message); } } } @@ -108,7 +108,7 @@ private class DownloadInfo { public string contentLocation {get;set;} } - private class Parameters { + public class Parameters { public string[] WorkflowFiles { get; set; } public string Server { get; set; } public string Payload { get; set; } @@ -216,22 +216,19 @@ private static string ReadSecret() { return input.ToString(); } - private static void OnError(object sender, ErrorEventArgs e) => - PrintException(e.GetException()); - - private static void PrintException(Exception ex) + private static void PrintException(Parameters parameters, Exception ex) { if (ex != null) { - Console.WriteLine($"Message: {ex.Message}"); - Console.WriteLine("Stacktrace:"); - Console.WriteLine(ex.StackTrace); - Console.WriteLine(); - PrintException(ex.InnerException); + WriteLogMessage(parameters, "trace", $"Message: {ex.Message}"); + WriteLogMessage(parameters, "trace", "Stacktrace:"); + WriteLogMessage(parameters, "trace", ex.StackTrace); + WriteLogMessage(parameters, "trace", ""); + PrintException(parameters, ex.InnerException); } } - private static async Task IsIgnored(string dir, string path) { + private static async Task IsIgnored(Parameters parameters, string dir, string path) { if(path.StartsWith(".git/") || path.StartsWith(".git\\")) { return true; } @@ -246,7 +243,7 @@ private static async Task IsIgnored(string dir, string path) { } } }; - GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(false)); + GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; var binpath = Path.GetDirectoryName(Assembly.GetEntryAssembly().Location); var git = WhichUtil.Which("git", true); @@ -263,9 +260,6 @@ private static async Task IsIgnored(string dir, string path) { } private static async Task CreateRunner(string binpath, Parameters parameters, List listener, Channel workerchannel, CancellationTokenSource source) { - EventHandler _out = (s, e) => { - Console.WriteLine(e.Data); - }; #if !OS_LINUX && !OS_WINDOWS && !OS_OSX && !X64 && !X86 && !ARM && !ARM64 var dotnet = Sdk.Utils.DotNetMuxer.MuxerPath ?? WhichUtil.Which("dotnet", true); string ext = ".dll"; @@ -284,12 +278,17 @@ private static async Task CreateRunner(string binpath, Parameters parameter int attempt = 1; while(!source.IsCancellationRequested) { try { - var inv = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); - if(parameters.Verbose) { + var inv = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); + EventHandler _out = (s, e) => + { + WriteLogMessage(parameters, "trace", e.Data); + }; + if (parameters.Verbose) + { inv.OutputDataReceived += _out; inv.ErrorDataReceived += _out; } - + var systemEnv = System.Environment.GetEnvironmentVariables(); var runnerEnv = new Dictionary(); foreach(var e in systemEnv.Keys) { @@ -325,7 +324,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter int execAttempt = 1; while(true) { try { - var runnerlistener = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + var runnerlistener = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); if(parameters.Verbose) { runnerlistener.OutputDataReceived += _out; runnerlistener.ErrorDataReceived += _out; @@ -355,7 +354,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter if(execAttempt++ <= 3) { await Task.Delay(500); } else { - Console.Error.WriteLine("Failed to start actions runner after 3 attempts"); + WriteLogMessage(parameters, "error", "Failed to start actions runner after 3 attempts"); int delattempt = 1; while(true) { try { @@ -363,7 +362,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter break; } catch { if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -379,7 +378,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter if(attempt++ <= 3) { await Task.Delay(500); } else { - Console.Error.WriteLine("Failed to auto-configure actions runner after 3 attempts"); + WriteLogMessage(parameters, "error", "Failed to auto-configure actions runner after 3 attempts"); int delattempt = 1; while(true) { try { @@ -387,7 +386,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter break; } catch { if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -399,7 +398,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter } } } finally { - Console.WriteLine("Stopped Runner"); + WriteLogMessage(parameters, "trace", "Stopped Runner"); if(!parameters.KeepContainer && !parameters.KeepRunnerDirectory) { int delattempt = 1; while(true) { @@ -411,7 +410,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter break; } if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -422,9 +421,9 @@ private static async Task CreateRunner(string binpath, Parameters parameter } if(parameters.KeepContainer || parameters.NoReuse) { if(!source.IsCancellationRequested) { - Console.WriteLine("Recreate Runner"); + WriteLogMessage(parameters, "trace", "Recreate Runner"); if(await CreateRunner(binpath, parameters, listener, workerchannel, source) != 0 && !source.IsCancellationRequested) { - Console.WriteLine("Failed to recreate Runner, exiting..."); + WriteLogMessage(parameters, "trace", "Failed to recreate Runner, exiting..."); source.Cancel(); } } @@ -432,9 +431,21 @@ private static async Task CreateRunner(string binpath, Parameters parameter return 0; } + private static void WriteLogMessage(Parameters parameters, string level, string msg) + { + if (parameters.Json) + { + Console.WriteLine(JsonConvert.SerializeObject(new { level, msg })); + } + else + { + Console.WriteLine(msg); + } + } + private static async Task CreateExternalRunner(string binpath, Parameters parameters, List listener, Channel workerchannel, CancellationTokenSource source) { EventHandler _out = (s, e) => { - Console.WriteLine(e.Data); + WriteLogMessage(parameters, "trace", e.Data); }; var azure = string.Equals(parameters.Event, "azpipelines", StringComparison.OrdinalIgnoreCase); var prefix = azure ? "Agent" : "Runner"; @@ -470,7 +481,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p int attempt = 1; while(!source.IsCancellationRequested) { try { - var inv = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + var inv = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); if(parameters.Verbose) { inv.OutputDataReceived += _out; inv.ErrorDataReceived += _out; @@ -513,7 +524,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p while(true) { file = runner; try { - var runnerlistener = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + var runnerlistener = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); if(parameters.Verbose) { runnerlistener.OutputDataReceived += _out; runnerlistener.ErrorDataReceived += _out; @@ -574,12 +585,12 @@ private static async Task CreateExternalRunner(string binpath, Parameters p if(source.IsCancellationRequested) { return 1; } - Console.Error.WriteLine("runner crashed after listening for jobs"); + WriteLogMessage(parameters, "error", "runner crashed after listening for jobs"); } else { if(execAttempt++ <= 3) { await Task.Delay(500); } else { - Console.Error.WriteLine("Failed to start actions runner after 3 attempts"); + WriteLogMessage(parameters, "error", "Failed to start actions runner after 3 attempts"); int delattempt = 1; while(true) { try { @@ -587,7 +598,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p break; } catch { if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -604,7 +615,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p if(attempt++ <= 3) { await Task.Delay(500); } else { - Console.Error.WriteLine("Failed to auto-configure actions runner after 3 attempts"); + WriteLogMessage(parameters, "error", "Failed to auto-configure actions runner after 3 attempts"); int delattempt = 1; while(true) { try { @@ -612,7 +623,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p break; } catch { if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -624,7 +635,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p } } } finally { - Console.WriteLine("Stopped Runner"); + WriteLogMessage(parameters, "trace", "Stopped Runner"); if(!parameters.KeepContainer && !parameters.KeepRunnerDirectory) { int delattempt = 1; while(true) { @@ -636,7 +647,7 @@ private static async Task CreateExternalRunner(string binpath, Parameters p break; } if(delattempt++ >= 3) { - await Console.Error.WriteLineAsync($"Failed to cleanup {tmpdir} after 3 attempts"); + WriteLogMessage(parameters, "error", $"Failed to cleanup {tmpdir} after 3 attempts"); break; } else { await Task.Delay(500); @@ -647,9 +658,9 @@ private static async Task CreateExternalRunner(string binpath, Parameters p } if(parameters.KeepContainer || parameters.NoReuse) { if(!source.IsCancellationRequested) { - Console.WriteLine("Recreate Runner"); + WriteLogMessage(parameters, "info", "Recreate Runner"); if(await CreateExternalRunner(binpath, parameters, listener, workerchannel, source) != 0 && !source.IsCancellationRequested) { - Console.WriteLine("Failed to recreate Runner, exiting..."); + WriteLogMessage(parameters, "trace", "Failed to recreate Runner, exiting..."); source.Cancel(); } } @@ -770,34 +781,40 @@ public Task ReadFile(string repositoryAndRef, string path) } public class TraceWriter : GitHub.DistributedTask.ObjectTemplating.ITraceWriter { + private Parameters parameters; + + public TraceWriter(Parameters parameters) { + this.parameters = parameters; + } + public void Error(string format, params object[] args) { if(args?.Length == 1 && args[0] is Exception ex) { - Console.Error.WriteLine(string.Format("{0} {1}", format, ex.Message)); + WriteLogMessage(parameters, "error", string.Format("{0} {1}", format, ex.Message)); return; } try { - Console.Error.WriteLine(args?.Length > 0 ? string.Format(format, args) : format); + WriteLogMessage(parameters, "error", args?.Length > 0 ? string.Format(format, args) : format); } catch { - Console.Error.WriteLine(format); + WriteLogMessage(parameters, "error", format); } } public void Info(string format, params object[] args) { try { - Console.WriteLine(args?.Length > 0 ? string.Format(format, args) : format); + WriteLogMessage(parameters, "info", args?.Length > 0 ? string.Format(format, args) : format); } catch { - Console.WriteLine(format); + WriteLogMessage(parameters, "info", format); } } public void Verbose(string format, params object[] args) { try { - Console.WriteLine(args?.Length > 0 ? string.Format(format, args) : format); + WriteLogMessage(parameters, "trace", args?.Length > 0 ? string.Format(format, args) : format); } catch { - Console.WriteLine(format); + WriteLogMessage(parameters, "trace", format); } } } @@ -813,7 +830,7 @@ public static async Task ExpandCurrentPipeline(Parameters handle, string var (secs, vars) = await ReadSecretsAndVariables(handle); var context = new Runner.Server.Azure.Devops.Context { FileProvider = new MyFileProvider(handle), - TraceWriter = handle.Quiet ? new EmptyTraceWriter() : new TraceWriter(), + TraceWriter = handle.Quiet ? new EmptyTraceWriter() : new TraceWriter(handle), Flags = GitHub.DistributedTask.Expressions2.ExpressionFlags.DTExpressionsV1 | GitHub.DistributedTask.Expressions2.ExpressionFlags.ExtendedDirectives | GitHub.DistributedTask.Expressions2.ExpressionFlags.AllowAnyForInsert, VariablesProvider = new VariablesProvider { Variables = vars } }; @@ -1228,7 +1245,7 @@ static int Main(string[] args) } if(errors.Count > 0) { foreach(var error in errors) { - Console.Error.WriteLine(error); + WriteLogMessage(parameters, "error", error); } return 1; } @@ -1246,7 +1263,7 @@ static int Main(string[] args) return; } e.Cancel = !canceled; - Console.WriteLine($"CTRL+C received {(e.Cancel ? "Shutting down... CTRL+C again to Terminate" : "Terminating")}"); + WriteLogMessage(parameters, "info", $"CTRL+C received {(e.Cancel ? "Shutting down... CTRL+C again to Terminate" : "Terminating")}"); canceled = true; source.Cancel(); }; @@ -1256,7 +1273,7 @@ static int Main(string[] args) parameters.RunnerVersion = "3.243.1"; } if(!string.IsNullOrEmpty(parameters.RunnerVersion)) { - parameters.RunnerPath = Directory.GetParent(await ExternalToolHelper.GetAgent(azure ? "azagent" : "runner", parameters.RunnerVersion, source.Token)).Parent.FullName; + parameters.RunnerPath = Directory.GetParent(await ExternalToolHelper.GetAgent(parameters, azure ? "azagent" : "runner", parameters.RunnerVersion, source.Token)).Parent.FullName; } } List listener = new List(); @@ -1264,14 +1281,14 @@ static int Main(string[] args) if(!expandAzurePipeline && (parameters.Server == null || parameters.StartServer || parameters.StartRunner)) { var binpath = Path.GetDirectoryName(Assembly.GetEntryAssembly().Location); EventHandler _out = (s, e) => { - Console.WriteLine(e.Data); + WriteLogMessage(parameters, "trace", e.Data); }; if(parameters.StartRunner) { if(parameters.Server == null) { parameters.Server = "http://localhost:5000"; } } else { - Console.WriteLine("Starting Server..."); + WriteLogMessage(parameters, "info", "Starting Server..."); string listeningAddr = parameters.Server; if(parameters.Server == null) { listeningAddr = "http://*:0"; @@ -1305,11 +1322,11 @@ static int Main(string[] args) } } if(parameters.Server == null) { - Console.WriteLine("Failed to autodetect non loopback ip, docker actions will fail to connect"); + WriteLogMessage(parameters, "warn", "Failed to autodetect non loopback ip, docker actions will fail to connect"); parameters.Server = "http://localhost:0"; } } - GitHub.Runner.Sdk.ProcessInvoker invoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + GitHub.Runner.Sdk.ProcessInvoker invoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); if(parameters.Verbose) { invoker.OutputDataReceived += _out; invoker.ErrorDataReceived += _out; @@ -1392,10 +1409,10 @@ static int Main(string[] args) serverEnv[kv.Key] = kv.Value; } if(parameters.Verbose) { - Console.WriteLine($"serverEnv: {(serverEnv.Select(kv => $"{kv.Key}={kv.Value}").Aggregate((l, nl) => string.IsNullOrEmpty(l) ? nl : $"{l}\n{nl}"))}"); + WriteLogMessage(parameters, "info", $"serverEnv: {(serverEnv.Select(kv => $"{kv.Key}={kv.Value}").Aggregate((l, nl) => string.IsNullOrEmpty(l) ? nl : $"{l}\n{nl}"))}"); } var x = await invoker.ExecuteAsync(binpath, file, arguments, serverEnv, false, null, true, runToken.Token); - Console.WriteLine("Stopped Server"); + WriteLogMessage(parameters, "info", "Stopped Server"); File.Delete(serverconfigfileName); } }); @@ -1409,12 +1426,12 @@ static int Main(string[] args) var caddr = new UriBuilder(line); caddr.Host = uri.Host; parameters.Server = caddr.Uri.ToString().Trim('/'); - Console.WriteLine($"The server is listening on {line} / {parameters.Server}"); + WriteLogMessage(parameters, "info", $"The server is listening on {line} / {parameters.Server}"); } }); if(await Task.WhenAny(serveriptask, servertask) == servertask) { if(!canceled) { - Console.Error.WriteLine("Failed to start server, rerun with `-v` to find out what is wrong"); + WriteLogMessage(parameters, "error", "Failed to start server, rerun with `-v` to find out what is wrong"); } return 1; } @@ -1423,7 +1440,7 @@ static int Main(string[] args) } if(parameters.Parallel > 0) { - Console.WriteLine($"Starting {parameters.Parallel} Runner{(parameters.Parallel != 1 ? "s" : "")}..."); + WriteLogMessage(parameters, "info", $"Starting {parameters.Parallel} Runner{(parameters.Parallel != 1 ? "s" : "")}..."); var workerchannel = Channel.CreateBounded(1); for(int i = 0; i < parameters.Parallel; i++) { if(string.IsNullOrEmpty(parameters.RunnerPath)) { @@ -1435,17 +1452,17 @@ static int Main(string[] args) var task = workerchannel.Reader.ReadAsync().AsTask(); if(await Task.WhenAny(listener.Append(task)) != task) { if(!canceled) { - Console.Error.WriteLine("Fatal: Failed to start Runner or Server crashed"); + WriteLogMessage(parameters, "error", "Fatal: Failed to start Runner or Server crashed"); } return 1; } - Console.WriteLine($"First runner is listening for jobs"); + WriteLogMessage(parameters, "info", $"First runner is listening for jobs"); } if(parameters.StartServer || parameters.StartRunner) { var exitAfterEnterEnv = System.Environment.GetEnvironmentVariable("RUNNER_CLIENT_EXIT_AFTER_ENTER"); var exitAfterEnter = Debugger.IsAttached && exitAfterEnterEnv != "0" || exitAfterEnterEnv == "1"; - Console.WriteLine($"Press {(exitAfterEnter ? "Enter or CTRL+C" : "CTRL+C")} to stop the {(parameters.StartServer ? "Server" : (parameters.Parallel != 1 ? "Runners" : "Runner"))}"); + WriteLogMessage(parameters, "info", $"Press {(exitAfterEnter ? "Enter or CTRL+C" : "CTRL+C")} to stop the {(parameters.StartServer ? "Server" : (parameters.Parallel != 1 ? "Runners" : "Runner"))}"); try { if(exitAfterEnter) { @@ -1652,23 +1669,23 @@ await Task.WhenAny(Task.Run(() => { using(FileSystemWatcher watcher = new FileSystemWatcher(parameters.Directory ?? ".") {IncludeSubdirectories = true}) { watcher.Created += (s, f) => { var path = Path.GetRelativePath(parameters.Directory ?? ".", f.FullPath); - Console.WriteLine($"Added {path}"); + WriteLogMessage(parameters, "info", $"Added {path}"); added.Enqueue(path); }; watcher.Deleted += (s, f) => { var path = Path.GetRelativePath(parameters.Directory ?? ".", f.FullPath); - Console.WriteLine($"Removed {path}"); + WriteLogMessage(parameters, "info", $"Removed {path}"); removed.Enqueue(path); }; watcher.Changed += (s, f) => { var path = Path.GetRelativePath(parameters.Directory ?? ".", f.FullPath); - Console.WriteLine($"Changed {path}"); + WriteLogMessage(parameters, "info", $"Changed {path}"); changed.Enqueue(path); }; watcher.Renamed += (s, f) => { var path = Path.GetRelativePath(parameters.Directory ?? ".", f.FullPath); var oldpath = Path.GetRelativePath(parameters.Directory ?? ".", f.OldFullPath); - Console.WriteLine($"Renamed {oldpath} to {path}"); + WriteLogMessage(parameters, "info", $"Renamed {oldpath} to {path}"); if(oldpath != f.OldFullPath) { removed.Enqueue(oldpath); } @@ -1676,10 +1693,10 @@ await Task.WhenAny(Task.Run(() => { added.Enqueue(path); } }; - watcher.Error += OnError; + watcher.Error += (s, e) => PrintException(parameters, e.GetException()); watcher.EnableRaisingEvents = true; - Console.WriteLine("Watching for changes"); + WriteLogMessage(parameters, "info", "Watching for changes"); string addedFile = null; string changedFile = null; @@ -1687,24 +1704,24 @@ await Task.WhenAny(Task.Run(() => { try { do { await Task.Delay(2000, source.Token); - } while(!(added.TryDequeue(out addedFile) && !await IsIgnored(parameters.Directory ?? ".", addedFile)) && !(changed.TryDequeue(out changedFile) && !await IsIgnored(parameters.Directory ?? ".", changedFile)) && !(removed.TryDequeue(out removedFile) && !await IsIgnored(parameters.Directory ?? ".", removedFile))); + } while(!(added.TryDequeue(out addedFile) && !await IsIgnored(parameters, parameters.Directory ?? ".", addedFile)) && !(changed.TryDequeue(out changedFile) && !await IsIgnored(parameters, parameters.Directory ?? ".", changedFile)) && !(removed.TryDequeue(out removedFile) && !await IsIgnored(parameters, parameters.Directory ?? ".", removedFile))); } catch(TaskCanceledException) { } while(addedFile != null || added.TryDequeue(out addedFile)) { - if(!await IsIgnored(parameters.Directory ?? ".", addedFile)) { + if(!await IsIgnored(parameters, parameters.Directory ?? ".", addedFile)) { addedFiles.Add(addedFile.Replace('\\', '/')); } addedFile = null; } while(changedFile != null || changed.TryDequeue(out changedFile)) { - if(!await IsIgnored(parameters.Directory ?? ".", changedFile)) { + if(!await IsIgnored(parameters, parameters.Directory ?? ".", changedFile)) { changedFiles.Add(changedFile.Replace('\\', '/')); } changedFile = null; } while(removedFile != null || removed.TryDequeue(out removedFile)) { - if(!await IsIgnored(parameters.Directory ?? ".", removedFile)) { + if(!await IsIgnored(parameters, parameters.Directory ?? ".", removedFile)) { removedFiles.Add(removedFile.Replace('\\', '/')); } removedFile = null; @@ -1726,17 +1743,17 @@ await Task.WhenAny(Task.Run(() => { try { workflows = Directory.GetFiles(pWorkflows, "*.yml", new EnumerationOptions { RecurseSubdirectories = false, MatchType = MatchType.Win32, AttributesToSkip = 0, IgnoreInaccessible = true }).Concat(Directory.GetFiles(pWorkflows, "*.yaml", new EnumerationOptions { RecurseSubdirectories = false, MatchType = MatchType.Win32, AttributesToSkip = 0, IgnoreInaccessible = true })).ToArray(); if((workflows == null || workflows.Length == 0)) { - Console.Error.WriteLine($"No workflow *.yml / *.yaml file found inside of {pWorkflows}"); + WriteLogMessage(parameters, "error", $"No workflow *.yml / *.yaml file found inside of {pWorkflows}"); return 1; } } catch { - Console.Error.WriteLine($"Failed to read directory {pWorkflows}"); + WriteLogMessage(parameters, "error", $"Failed to read directory {pWorkflows}"); return 1; } } else if (File.Exists(pWorkflows)) { workflows = new[] { pWorkflows }; } else { - Console.Error.WriteLine($"No such file or directory {pWorkflows}"); + WriteLogMessage(parameters, "error", $"No such file or directory {pWorkflows}"); return 1; } } @@ -1745,11 +1762,11 @@ await Task.WhenAny(Task.Run(() => { foreach(var workflow in workflows) { var name = Path.GetRelativePath(parameters.Directory ?? ".", workflow).Replace('\\', '/'); var res = await AzurePipelinesExpander.ExpandCurrentPipeline(parameters, name); - Console.WriteLine(res); + WriteLogMessage(parameters, "info", res); } return 0; } catch (Exception except) { - Console.WriteLine($"Exception: {except.Message}, {except.StackTrace}"); + WriteLogMessage(parameters, "error", $"Exception: {except.Message}, {except.StackTrace}"); return 1; } finally { cancelWorkflow = null; @@ -1775,7 +1792,7 @@ await Task.WhenAny(Task.Run(() => { var name = Path.GetRelativePath(parameters.Directory ?? ".", w).Replace('\\', '/'); mp.Add(new StreamContent(workflow), name, name); } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {w}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {w}, Details: {ex.Message}"); return 1; } } @@ -1787,7 +1804,7 @@ await Task.WhenAny(Task.Run(() => { try { wenv.AddRange(Util.ReadEnvFile(file)); } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {file}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {file}, Details: {ex.Message}"); return 1; } } @@ -1797,7 +1814,7 @@ await Task.WhenAny(Task.Run(() => { try { wsecrets.AddRange(Util.ReadEnvFile(file)); } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {file}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {file}, Details: {ex.Message}"); return 1; } } @@ -1876,7 +1893,7 @@ await Task.WhenAny(Task.Run(() => { var git = WhichUtil.Which("git", true); GitHub.Runner.Sdk.ProcessInvoker gitinvoker; if(string.IsNullOrEmpty(Ref)) { - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; var binpath = Path.GetDirectoryName(Assembly.GetEntryAssembly().Location); await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, "tag --points-at HEAD", new Dictionary(), source.Token); @@ -1885,7 +1902,7 @@ await Task.WhenAny(Task.Run(() => { } } if(string.IsNullOrEmpty(Ref) || string.IsNullOrEmpty(repofullname)) { - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, "symbolic-ref HEAD", new Dictionary(), source.Token); if(line != null) { @@ -1895,14 +1912,14 @@ await Task.WhenAny(Task.Run(() => { } if(string.IsNullOrEmpty(repofullname)) { line = null; - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, $"for-each-ref --format=%(upstream:short) {_ref}", new Dictionary(), source.Token); if(line != null && line != "") { var remote = line.Substring(0, line.IndexOf('/')); if(parameters.DefaultBranch == null) { line = null; - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, $"symbolic-ref refs/remotes/{remote}/HEAD", new Dictionary(), source.Token); if(line != null && line.StartsWith($"refs/remotes/{remote}/")) { @@ -1911,7 +1928,7 @@ await Task.WhenAny(Task.Run(() => { } } line = null; - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, $"remote get-url {remote}", new Dictionary(), source.Token); if(line != null) { @@ -1929,23 +1946,23 @@ await Task.WhenAny(Task.Run(() => { } } } else { - await Console.Error.WriteLineAsync("No default github.ref found"); + WriteLogMessage(parameters, "error", "No default github.ref found"); } } if(string.IsNullOrEmpty(sha)) { line = null; - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; await gitinvoker.ExecuteAsync(parameters.Directory ?? Path.GetFullPath("."), git, "rev-parse HEAD", new Dictionary(), source.Token); if(line != null && line != "HEAD" /* on failure git returns HEAD instead of a sha */) { sha = line; line = null; } else { - await Console.Error.WriteLineAsync("Couldn't retrieve github.sha"); + WriteLogMessage(parameters, "error", "Couldn't retrieve github.sha"); } } } catch { - await Console.Error.WriteLineAsync("Failed to detect git repo the github context may have invalid values"); + WriteLogMessage(parameters, "error", "Failed to detect git repo the github context may have invalid values"); } if(string.IsNullOrEmpty(repofullname) || !repofullname.Contains('/')) { repofullname = "Unknown/Unknown"; @@ -1988,7 +2005,7 @@ await Task.WhenAny(Task.Run(() => { payloadContent.Merge(obj, new JsonMergeSettings { MergeArrayHandling = MergeArrayHandling.Replace }); } } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {parameters.Payload}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {parameters.Payload}, Details: {ex.Message}"); return 1; } } else if(parameters.NoDefaultPayload) { @@ -2002,7 +2019,7 @@ await Task.WhenAny(Task.Run(() => { try { Util.ReadEnvFile(file, (k, v) => inputs[k] = v); } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {file}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {file}, Details: {ex.Message}"); return 1; } } @@ -2024,7 +2041,7 @@ await Task.WhenAny(Task.Run(() => { try { Util.ReadEnvFile(file, (k, v) => inputs[k] = v); } catch(Exception ex) { - Console.WriteLine($"Failed to read file: {file}, Details: {ex.Message}"); + WriteLogMessage(parameters, "error", $"Failed to read file: {file}, Details: {ex.Message}"); return 1; } } @@ -2063,7 +2080,7 @@ await Task.WhenAny(Task.Run(() => { List jobs = new List(); var forceCancelWorkflow = () => { cancelWorkflow = null; - Console.WriteLine($"CTRL+C received Force Cancel Running Jobs"); + WriteLogMessage(parameters, "info", $"CTRL+C received Force Cancel Running Jobs"); var runIds = (from j in jobs.ToArray() select j.runid).ToHashSet(); foreach(var runId in runIds) { client.PostAsync(GetForceCancelWorkflowUrl(b.ToString(), runId), null, CancellationToken.None); @@ -2071,7 +2088,7 @@ await Task.WhenAny(Task.Run(() => { }; cancelWorkflow = () => { cancelWorkflow = forceCancelWorkflow; - Console.WriteLine($"CTRL+C received Cancel Running Jobs"); + WriteLogMessage(parameters, "info", $"CTRL+C received Cancel Running Jobs"); var runIds = (from j in jobs.ToArray() select j.runid).ToHashSet(); foreach(var runId in runIds) { client.PostAsync(GetCancelWorkflowUrl(b.ToString(), runId), null, CancellationToken.None); @@ -2141,8 +2158,8 @@ await Task.WhenAny(Task.Run(() => { break; } if(parameters.Trace) { - Console.WriteLine($"##[Trace]{line}"); - Console.WriteLine($"##[Trace]{data}"); + WriteLogMessage(parameters, "trace", $"##[Trace]{line}"); + WriteLogMessage(parameters, "trace", $"##[Trace]{data}"); } if(!parameters.Quiet && line == "event: log") { var e = JsonConvert.DeserializeObject(data); @@ -2396,7 +2413,7 @@ await Task.WhenAny(Task.Run(() => { WriteLogLine((int)rec.Color, $"{rec.TimeLine[0].Name}", $"Workflow {_workflow.runid} Completed with Status: {result.ToString()}"); } } else { - Console.WriteLine($"Workflow {_workflow.runid} finished with status {result.ToString()}"); + WriteLogMessage(parameters, "info", $"Workflow {_workflow.runid} finished with status {result.ToString()}"); } hasErrors |= !_workflow.Success; hasAny = true; @@ -2438,7 +2455,7 @@ await Task.WhenAny(Task.Run(() => { try { var artfactBasePath = Path.Combine(parameters.ArtifactOutputDir, runId.ToString(), artifact.name); Directory.CreateDirectory(artfactBasePath); - Console.WriteLine($"Downloading {runId}/{artifact.name}"); + WriteLogMessage(parameters, "info", $"Downloading {runId}/{artifact.name}"); var files = JsonConvert.DeserializeObject>(await client.GetStringAsync(artifact.fileContainerResourceUrl)); foreach(var file in files.Value) { try { @@ -2468,7 +2485,7 @@ await Task.WhenAny(Task.Run(() => { try { var logBasePath = Path.Combine(parameters.LogOutputDir, job.runid.ToString(), special.Replace(job.name, "-")); Directory.CreateDirectory(logBasePath); - Console.WriteLine($"Downloading Logs {job.runid}/{special.Replace(job.name, "-")}"); + WriteLogMessage(parameters, "info", $"Downloading Logs {job.runid}/{special.Replace(job.name, "-")}"); var timeLineRecords = JsonConvert.DeserializeObject>(await client.GetStringAsync(parameters.Server + $"/_apis/v1/Timeline/{job.TimeLineId.ToString()}")); foreach(var timeLineRecord in timeLineRecords) { try { @@ -2493,15 +2510,15 @@ await Task.WhenAny(Task.Run(() => { } } if(hasErrors) { - Console.WriteLine("All Workflows finished, at least one workflow failed"); + WriteLogMessage(parameters, "error", "All Workflows finished, at least one workflow failed"); } else if(!hasAny) { - Console.WriteLine("All Workflows skipped, due to filters"); + WriteLogMessage(parameters, "info", "All Workflows skipped, due to filters"); } else { - Console.WriteLine("All Workflows finished successfully"); + WriteLogMessage(parameters, "info", "All Workflows finished successfully"); } return hasErrors ? 1 : 0; } catch (Exception except) { - Console.WriteLine($"Exception: {except.Message}, {except.StackTrace}"); + WriteLogMessage(parameters, "info", $"Exception: {except.Message}, {except.StackTrace}"); return 1; } finally { cancelWorkflow = null; @@ -2783,7 +2800,7 @@ private static async Task CollectRepoFiles(string root, string wd, RepoDownload } else if(file.StartsWith("120")) { //Symlink submoduleTasks.Add(async () => { - GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); string dest = null; gitinvoker.OutputDataReceived += (s, e) => { dest = e.Data; @@ -2809,7 +2826,7 @@ private static async Task CollectRepoFiles(string root, string wd, RepoDownload } } }; - GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + GitHub.Runner.Sdk.ProcessInvoker gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += handleoutput; var binpath = Path.GetDirectoryName(Assembly.GetEntryAssembly().Location); var git = WhichUtil.Which("git", true); @@ -2818,7 +2835,7 @@ private static async Task CollectRepoFiles(string root, string wd, RepoDownload foreach (var submodule in submoduleTasks) { await submodule(); } - gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters.Verbose)); + gitinvoker = new GitHub.Runner.Sdk.ProcessInvoker(new TraceWriter(parameters)); gitinvoker.OutputDataReceived += (s, e) => { var files = e.Data.Split('\0'); foreach(var filename in files) { From d235f387fe34464cbd55d61ba763cd4cd9fce2e2 Mon Sep 17 00:00:00 2001 From: ChristopherHX Date: Wed, 11 Dec 2024 18:11:51 +0100 Subject: [PATCH 2/4] Apply suggestions from code review --- src/Runner.Client/Program.cs | 12 ++++++++---- 1 file changed, 8 insertions(+), 4 deletions(-) diff --git a/src/Runner.Client/Program.cs b/src/Runner.Client/Program.cs index 6210bda6da5..7ef13f9a785 100644 --- a/src/Runner.Client/Program.cs +++ b/src/Runner.Client/Program.cs @@ -398,7 +398,7 @@ private static async Task CreateRunner(string binpath, Parameters parameter } } } finally { - WriteLogMessage(parameters, "trace", "Stopped Runner"); + WriteLogMessage(parameters, "info", "Stopped Runner"); if(!parameters.KeepContainer && !parameters.KeepRunnerDirectory) { int delattempt = 1; while(true) { @@ -421,9 +421,9 @@ private static async Task CreateRunner(string binpath, Parameters parameter } if(parameters.KeepContainer || parameters.NoReuse) { if(!source.IsCancellationRequested) { - WriteLogMessage(parameters, "trace", "Recreate Runner"); + WriteLogMessage(parameters, "info", "Recreate Runner"); if(await CreateRunner(binpath, parameters, listener, workerchannel, source) != 0 && !source.IsCancellationRequested) { - WriteLogMessage(parameters, "trace", "Failed to recreate Runner, exiting..."); + WriteLogMessage(parameters, "error", "Failed to recreate Runner, exiting..."); source.Cancel(); } } @@ -437,6 +437,10 @@ private static void WriteLogMessage(Parameters parameters, string level, string { Console.WriteLine(JsonConvert.SerializeObject(new { level, msg })); } + else if(level == "error") + { + Console.Error.WriteLine(msg); + } else { Console.WriteLine(msg); @@ -2518,7 +2522,7 @@ await Task.WhenAny(Task.Run(() => { } return hasErrors ? 1 : 0; } catch (Exception except) { - WriteLogMessage(parameters, "info", $"Exception: {except.Message}, {except.StackTrace}"); + WriteLogMessage(parameters, "error", $"Exception: {except.Message}, {except.StackTrace}"); return 1; } finally { cancelWorkflow = null; From 213c5c9725caa2376f9f283551bd2dd898d63f66 Mon Sep 17 00:00:00 2001 From: Christopher Homberger Date: Wed, 11 Dec 2024 20:19:09 +0100 Subject: [PATCH 3/4] fix last log level --- src/Runner.Client/Program.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Runner.Client/Program.cs b/src/Runner.Client/Program.cs index 7ef13f9a785..397c56aba85 100644 --- a/src/Runner.Client/Program.cs +++ b/src/Runner.Client/Program.cs @@ -1413,7 +1413,7 @@ static int Main(string[] args) serverEnv[kv.Key] = kv.Value; } if(parameters.Verbose) { - WriteLogMessage(parameters, "info", $"serverEnv: {(serverEnv.Select(kv => $"{kv.Key}={kv.Value}").Aggregate((l, nl) => string.IsNullOrEmpty(l) ? nl : $"{l}\n{nl}"))}"); + WriteLogMessage(parameters, "trace", $"serverEnv: {(serverEnv.Select(kv => $"{kv.Key}={kv.Value}").Aggregate((l, nl) => string.IsNullOrEmpty(l) ? nl : $"{l}\n{nl}"))}"); } var x = await invoker.ExecuteAsync(binpath, file, arguments, serverEnv, false, null, true, runToken.Token); WriteLogMessage(parameters, "info", "Stopped Server"); From 84af31a26ce13113780c712cdfced2543f5da7a8 Mon Sep 17 00:00:00 2001 From: Christopher Homberger Date: Wed, 11 Dec 2024 20:28:17 +0100 Subject: [PATCH 4/4] add timestamp --- src/Runner.Client/Program.cs | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/src/Runner.Client/Program.cs b/src/Runner.Client/Program.cs index 397c56aba85..0c310d13197 100644 --- a/src/Runner.Client/Program.cs +++ b/src/Runner.Client/Program.cs @@ -435,7 +435,7 @@ private static void WriteLogMessage(Parameters parameters, string level, string { if (parameters.Json) { - Console.WriteLine(JsonConvert.SerializeObject(new { level, msg })); + Console.WriteLine(JsonConvert.SerializeObject(new { level, msg, time = System.DateTime.Now })); } else if(level == "error") {