Add telemetry around runner update process. (#1497)

* Add telemetry around runner update process.

* .

* .

* .

src/Runner.Common/RunnerServer.cs

@@ -51,7 +51,7 @@ namespace GitHub.Runner.Common
         Task<PackageMetadata> GetPackageAsync(string packageType, string platform, string version, bool includeToken, CancellationToken cancellationToken);
 
         // agent update
-        Task<TaskAgent> UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState);
+        Task<TaskAgent> UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState, string trace);
     }
 
     public sealed class RunnerServer : RunnerService, IRunnerServer
@@ -341,25 +341,10 @@ namespace GitHub.Runner.Common
             return _genericTaskAgentClient.GetPackageAsync(packageType, platform, version, includeToken, cancellationToken: cancellationToken);
         }
 
-        public Task<TaskAgent> UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState)
+        public Task<TaskAgent> UpdateAgentUpdateStateAsync(int agentPoolId, int agentId, string currentState, string trace)
         {
             CheckConnection(RunnerConnectionType.Generic);
-            return _genericTaskAgentClient.UpdateAgentUpdateStateAsync(agentPoolId, agentId, currentState);
+            return _genericTaskAgentClient.UpdateAgentUpdateStateAsync(agentPoolId, agentId, currentState, trace);
-        }
-
-        //-----------------------------------------------------------------
-        // Runner Auth Url
-        //-----------------------------------------------------------------
-        public Task<string> 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);
         }
     }
 }

src/Runner.Listener/SelfUpdater.cs

@@ -13,6 +13,7 @@ using GitHub.Services.WebApi;
 using GitHub.Services.Common;
 using GitHub.Runner.Common;
 using GitHub.Runner.Sdk;
+using System.Text;
 
 namespace GitHub.Runner.Listener
 {
@@ -63,23 +64,25 @@ namespace GitHub.Runner.Listener
 
                 // 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 @@ namespace GitHub.Runner.Listener
                 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 @@ namespace GitHub.Runner.Listener
         /// </summary>
         /// <param name="token"></param>
         /// <returns></returns>
-        private async Task DownloadLatestRunner(CancellationToken token)
+        private async Task<string> 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 @@ namespace GitHub.Runner.Listener
             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 @@ namespace GitHub.Runner.Listener
                         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 @@ namespace GitHub.Runner.Listener
                                     //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 @@ namespace GitHub.Runner.Listener
                     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 @@ namespace GitHub.Runner.Listener
                     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 @@ namespace GitHub.Runner.Listener
                 }
             }
 
+            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 @@ namespace GitHub.Runner.Listener
                 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 @@ namespace GitHub.Runner.Listener
             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)
             {

src/Sdk/DTGenerated/Generated/TaskAgentHttpClientBase.cs

@@ -768,6 +768,7 @@ namespace GitHub.DistributedTask.WebApi
         /// <param name="poolId"></param>
         /// <param name="agentId"></param>
         /// <param name="currentState"></param>
+        /// <param name="updateTrace"></param>
         /// <param name="userState"></param>
         /// <param name="cancellationToken">The cancellation token to cancel operation.</param>
         [EditorBrowsable(EditorBrowsableState.Never)]
@@ -775,6 +776,7 @@ namespace GitHub.DistributedTask.WebApi
             int poolId,
             int agentId,
             string currentState,
+            string updateTrace,
             object userState = null,
             CancellationToken cancellationToken = default)
         {
@@ -784,6 +786,7 @@ namespace GitHub.DistributedTask.WebApi
 
             List<KeyValuePair<string, string>> queryParams = new List<KeyValuePair<string, string>>();
             queryParams.Add("currentState", currentState);
+            queryParams.Add("updateTrace", updateTrace);
 
             return SendAsync<TaskAgent>(
                 httpMethod,
@@ -794,65 +797,5 @@ namespace GitHub.DistributedTask.WebApi
                 userState: userState,
                 cancellationToken: cancellationToken);
         }
-
-        /// <summary>
-        /// [Preview API]
-        /// </summary>
-        /// <param name="poolId"></param>
-        /// <param name="agentId"></param>
-        /// <param name="userState"></param>
-        /// <param name="cancellationToken">The cancellation token to cancel operation.</param>
-        public Task<String> 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<String>(
-                httpMethod,
-                locationId,
-                routeValues: routeValues,
-                version: new ApiResourceVersion(6.0, 1),
-                userState: userState,
-                cancellationToken: cancellationToken);
-        }
-
-        /// <summary>
-        /// [Preview API]
-        /// </summary>
-        /// <param name="poolId"></param>
-        /// <param name="agentId"></param>
-        /// <param name="error"></param>
-        /// <param name="userState"></param>
-        /// <param name="cancellationToken">The cancellation token to cancel operation.</param>
-        [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<string>(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;
-            }
-        }
     }
 }