From 5b8ff174c602b775d40949daead9cf347dc01c9e Mon Sep 17 00:00:00 2001 From: Tingluo Huang Date: Mon, 22 Nov 2021 18:27:57 -0500 Subject: [PATCH] Add telemetry around runner update process. (#1497) * Add telemetry around runner update process. * . * . * . --- src/Runner.Common/RunnerServer.cs | 21 +------ src/Runner.Listener/SelfUpdater.cs | 42 ++++++++++--- .../Generated/TaskAgentHttpClientBase.cs | 63 +------------------ 3 files changed, 40 insertions(+), 86 deletions(-) diff --git a/src/Runner.Common/RunnerServer.cs b/src/Runner.Common/RunnerServer.cs index 1b15dbe2566..f377622c6bd 100644 --- a/src/Runner.Common/RunnerServer.cs +++ b/src/Runner.Common/RunnerServer.cs @@ -51,7 +51,7 @@ public interface IRunnerServer : IRunnerService Task GetPackageAsync(string packageType, string platform, string version, bool includeToken, CancellationToken cancellationToken); // agent update - Task UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState); + Task UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState, string trace); } public sealed class RunnerServer : RunnerService, IRunnerServer @@ -341,25 +341,10 @@ public Task GetPackageAsync(string packageType, string platform return _genericTaskAgentClient.GetPackageAsync(packageType, platform, version, includeToken, cancellationToken: cancellationToken); } - public Task UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState) + public Task UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState, string trace) { CheckConnection(RunnerConnectionType.Generic); - return _genericTaskAgentClient.UpdateAgentUpdateStateAsync(agentPoolId, agentId, currentState); - } - - //----------------------------------------------------------------- - // Runner Auth Url - //----------------------------------------------------------------- - public Task GetRunnerAuthUrlAsync(int runnerPoolId, int runnerId) - { - CheckConnection(RunnerConnectionType.MessageQueue); - return _messageTaskAgentClient.GetAgentAuthUrlAsync(runnerPoolId, runnerId); - } - - public Task ReportRunnerAuthUrlErrorAsync(int runnerPoolId, int runnerId, string error) - { - CheckConnection(RunnerConnectionType.MessageQueue); - return _messageTaskAgentClient.ReportAgentAuthUrlMigrationErrorAsync(runnerPoolId, runnerId, error); + return _genericTaskAgentClient.UpdateAgentUpdateStateAsync(agentPoolId, agentId, currentState, trace); } } } diff --git a/src/Runner.Listener/SelfUpdater.cs b/src/Runner.Listener/SelfUpdater.cs index 399552169dd..7b74a5d90ce 100644 --- a/src/Runner.Listener/SelfUpdater.cs +++ b/src/Runner.Listener/SelfUpdater.cs @@ -13,6 +13,7 @@ using GitHub.Services.Common; using GitHub.Runner.Common; using GitHub.Runner.Sdk; +using System.Text; namespace GitHub.Runner.Listener { @@ -63,23 +64,25 @@ public async Task SelfUpdate(AgentRefreshMessage updateMessage, IJobDispat // Print console line that warn user not shutdown runner. await UpdateRunnerUpdateStateAsync("Runner update in progress, do not shutdown runner."); - await UpdateRunnerUpdateStateAsync($"Downloading {_targetPackage.Version} runner"); + await UpdateRunnerUpdateStateAsync($"Downloading {_targetPackage.Version} runner", $"RunnerPlatform: {_targetPackage.Platform}"); - await DownloadLatestRunner(token); + var downloadTrace = await DownloadLatestRunner(token); Trace.Info($"Download latest runner and unzip into runner root."); // wait till all running job finish - await UpdateRunnerUpdateStateAsync("Waiting for current job finish running."); + await UpdateRunnerUpdateStateAsync("Waiting for current job finish running.", downloadTrace); await jobDispatcher.WaitAsync(token); Trace.Info($"All running job has exited."); // We need to keep runner backup around for macOS until we fixed https://github.com/actions/runner/issues/743 // delete runner backup + var stopWatch = Stopwatch.StartNew(); DeletePreviousVersionRunnerBackup(token); Trace.Info($"Delete old version runner backup."); + stopWatch.Stop(); // generate update script from template - await UpdateRunnerUpdateStateAsync("Generate and execute update script."); + await UpdateRunnerUpdateStateAsync("Generate and execute update script.", $"DeleteRunnerBackupTime: {stopWatch.ElapsedMilliseconds}ms"); string updateScript = GenerateUpdateScript(restartInteractiveRunner); Trace.Info($"Generate update script into: {updateScript}"); @@ -96,7 +99,7 @@ public async Task SelfUpdate(AgentRefreshMessage updateMessage, IJobDispat invokeScript.Start(); Trace.Info($"Update script start running"); - await UpdateRunnerUpdateStateAsync("Runner will exit shortly for update, should be back online within 10 seconds."); + await UpdateRunnerUpdateStateAsync("Runner will exit shortly for update, should be back online within 10 seconds.", $"RestartInteractiveRunner: {restartInteractiveRunner}"); return true; } @@ -150,8 +153,10 @@ private async Task UpdateNeeded(string targetVersion, CancellationToken to /// /// /// - private async Task DownloadLatestRunner(CancellationToken token) + private async Task DownloadLatestRunner(CancellationToken token) { + var traceStringBuilder = new StringBuilder(); + traceStringBuilder.AppendLine($"DownloadUrl: {_targetPackage.DownloadUrl}"); string latestRunnerDirectory = Path.Combine(HostContext.GetDirectory(WellKnownDirectory.Work), Constants.Path.UpdateDirectory); IOUtil.DeleteDirectory(latestRunnerDirectory, token); Directory.CreateDirectory(latestRunnerDirectory); @@ -160,6 +165,7 @@ private async Task DownloadLatestRunner(CancellationToken token) string archiveFile = null; bool downloadSucceeded = false; + var stopWatch = Stopwatch.StartNew(); try { // Download the runner, using multiple attempts in order to be resilient against any networking/CDN issues @@ -210,6 +216,7 @@ private async Task DownloadLatestRunner(CancellationToken token) try { Trace.Info($"Download runner: begin download"); + long downloadSize = 0; //open zip stream in async mode using (HttpClient httpClient = new HttpClient(HostContext.CreateHttpClientHandler())) @@ -228,11 +235,16 @@ private async Task DownloadLatestRunner(CancellationToken token) //81920 is the default used by System.IO.Stream.CopyTo and is under the large object heap threshold (85k). await result.CopyToAsync(fs, 81920, downloadCts.Token); await fs.FlushAsync(downloadCts.Token); + downloadSize = fs.Length; } } Trace.Info($"Download runner: finished download"); downloadSucceeded = true; + stopWatch.Stop(); + traceStringBuilder.AppendLine($"PackageDownloadTime: {stopWatch.ElapsedMilliseconds}ms"); + traceStringBuilder.AppendLine($"Attempts: {attempt}"); + traceStringBuilder.AppendLine($"PackageSize: {downloadSize / 1024 / 1024}MB"); break; } catch (OperationCanceledException) when (token.IsCancellationRequested) @@ -257,6 +269,7 @@ private async Task DownloadLatestRunner(CancellationToken token) throw new TaskCanceledException($"Runner package '{archiveFile}' failed after {Constants.RunnerDownloadRetryMaxAttempts} download attempts"); } + stopWatch.Restart(); // If we got this far, we know that we've successfully downloaded the runner package // Validate Hash Matches if it is provided using (FileStream stream = File.OpenRead(archiveFile)) @@ -320,7 +333,9 @@ private async Task DownloadLatestRunner(CancellationToken token) throw new NotSupportedException($"{archiveFile}"); } + stopWatch.Stop(); Trace.Info($"Finished getting latest runner package at: {latestRunnerDirectory}."); + traceStringBuilder.AppendLine($"PackageExtractTime: {stopWatch.ElapsedMilliseconds}ms"); } finally { @@ -340,6 +355,7 @@ private async Task DownloadLatestRunner(CancellationToken token) } } + stopWatch.Restart(); // copy latest runner into runner root folder // copy bin from _work/_update -> bin.version under root string binVersionDir = Path.Combine(HostContext.GetDirectory(WellKnownDirectory.Root), $"{Constants.Path.BinDirectory}.{_targetPackage.Version}"); @@ -365,6 +381,11 @@ private async Task DownloadLatestRunner(CancellationToken token) IOUtil.DeleteFile(destination); file.CopyTo(destination, true); } + + stopWatch.Stop(); + traceStringBuilder.AppendLine($"CopyRunnerToRootTime: {stopWatch.ElapsedMilliseconds}ms"); + + return traceStringBuilder.ToString(); } private void DeletePreviousVersionRunnerBackup(CancellationToken token) @@ -484,13 +505,18 @@ private string GenerateUpdateScript(bool restartInteractiveRunner) return updateScript; } - private async Task UpdateRunnerUpdateStateAsync(string currentState) + private async Task UpdateRunnerUpdateStateAsync(string currentState, string trace = "") { _terminal.WriteLine(currentState); + if (!string.IsNullOrEmpty(trace)) + { + Trace.Info(trace); + } + try { - await _runnerServer.UpdateAgentUpdateStateAsync(_poolId, _agentId, currentState); + await _runnerServer.UpdateAgentUpdateStateAsync(_poolId, _agentId, currentState, trace); } catch (VssResourceNotFoundException) { diff --git a/src/Sdk/DTGenerated/Generated/TaskAgentHttpClientBase.cs b/src/Sdk/DTGenerated/Generated/TaskAgentHttpClientBase.cs index dd92cad4edd..29fe07c0d3f 100644 --- a/src/Sdk/DTGenerated/Generated/TaskAgentHttpClientBase.cs +++ b/src/Sdk/DTGenerated/Generated/TaskAgentHttpClientBase.cs @@ -768,6 +768,7 @@ public TaskAgentHttpClientBase(Uri baseUrl, HttpMessageHandler pipeline, bool di /// /// /// + /// /// /// The cancellation token to cancel operation. [EditorBrowsable(EditorBrowsableState.Never)] @@ -775,6 +776,7 @@ public TaskAgentHttpClientBase(Uri baseUrl, HttpMessageHandler pipeline, bool di int poolId, int agentId, string currentState, + string updateTrace, object userState = null, CancellationToken cancellationToken = default) { @@ -784,6 +786,7 @@ public TaskAgentHttpClientBase(Uri baseUrl, HttpMessageHandler pipeline, bool di List> queryParams = new List>(); queryParams.Add("currentState", currentState); + queryParams.Add("updateTrace", updateTrace); return SendAsync( httpMethod, @@ -794,65 +797,5 @@ public TaskAgentHttpClientBase(Uri baseUrl, HttpMessageHandler pipeline, bool di userState: userState, cancellationToken: cancellationToken); } - - /// - /// [Preview API] - /// - /// - /// - /// - /// The cancellation token to cancel operation. - public Task GetAgentAuthUrlAsync( - int poolId, - int agentId, - object userState = null, - CancellationToken cancellationToken = default) - { - HttpMethod httpMethod = new HttpMethod("GET"); - Guid locationId = new Guid("a82a119c-1e46-44b6-8d75-c82a79cf975b"); - object routeValues = new { poolId = poolId, agentId = agentId }; - - return SendAsync( - httpMethod, - locationId, - routeValues: routeValues, - version: new ApiResourceVersion(6.0, 1), - userState: userState, - cancellationToken: cancellationToken); - } - - /// - /// [Preview API] - /// - /// - /// - /// - /// - /// The cancellation token to cancel operation. - [EditorBrowsable(EditorBrowsableState.Never)] - public virtual async Task ReportAgentAuthUrlMigrationErrorAsync( - int poolId, - int agentId, - string error, - object userState = null, - CancellationToken cancellationToken = default) - { - HttpMethod httpMethod = new HttpMethod("POST"); - Guid locationId = new Guid("a82a119c-1e46-44b6-8d75-c82a79cf975b"); - object routeValues = new { poolId = poolId, agentId = agentId }; - HttpContent content = new ObjectContent(error, new VssJsonMediaTypeFormatter(true)); - - using (HttpResponseMessage response = await SendAsync( - httpMethod, - locationId, - routeValues: routeValues, - version: new ApiResourceVersion(6.0, 1), - userState: userState, - cancellationToken: cancellationToken, - content: content).ConfigureAwait(false)) - { - return; - } - } } }