Drop log streaming in favour of reading the application log file

Integration tests should become more reliable

Author: giuliov

Next-Release-ChangeLog.md

@@ -30,6 +30,7 @@ Build, Test, Documentation
 ========================
 - Terraform and PowerShell scripts to setup a dev VM.
 - Use latest GitVersion.
+- Drop log streaming in favour of reading the application log file: integration tests should become more reliable.
 
 
 File Hashes

src/aggregator-cli/Instances/AggregatorInstances.cs

@@ -306,6 +306,19 @@ internal async Task<bool> StreamLogsAsync(InstanceName instance, CancellationTok
             return true;
         }
 
+        internal async Task<string> ReadLogAsync(InstanceName instance, string functionName, int logIndex, CancellationToken cancellationToken)
+        {
+            var kudu = GetKudu(instance);
+            logger.WriteVerbose($"Connecting to {instance.PlainName}...");
+
+            // Main takes care of resetting color
+            Console.ForegroundColor = ConsoleColor.Green;
+
+            string logData = await kudu.ReadApplicationLogAsync(functionName, logIndex, cancellationToken);
+            Console.Write(logData);
+            return logData;
+        }
+
         internal async Task<bool> UpdateAsync(InstanceName instance, string requiredVersion, string sourceUrl, CancellationToken cancellationToken)
         {
             // update runtime package

src/aggregator-cli/Kudu/KuduApi.cs

@@ -4,6 +4,7 @@
 using System.Net.Http;
 using System.Net.Http.Headers;
 using System.Text;
+using System.Text.Json;
 using System.Text.RegularExpressions;
 using System.Threading;
 using System.Threading.Tasks;
@@ -88,6 +89,48 @@ internal async Task<HttpRequestMessage> GetRequestAsync(HttpMethod method, strin
             return request;
         }
 
+        public class ListingEntry
+        {
+            public string name { get; set; }
+            public string href { get; set; }
+        }
+
+        internal async Task<string> ReadApplicationLogAsync(string functionName, int logIndex, CancellationToken cancellationToken)
+        {
+            const string FunctionLogPath = "api/vfs/LogFiles/Application/Functions/Function";
+
+            logger.WriteVerbose($"Listing application logs for {functionName}");
+            using (var client = new HttpClient())
+            {
+                ListingEntry[] listingResult = null;
+
+                using (var listingRequest = await GetRequestAsync(HttpMethod.Get, $"{FunctionLogPath}/{functionName}/", cancellationToken))
+                {
+                    var listingResponse = await client.SendAsync(listingRequest, cancellationToken);
+                    var listingStream = await listingResponse.Content.ReadAsStreamAsync();
+                    if (listingResponse.IsSuccessStatusCode)
+                    {
+                        listingResult = await JsonSerializer.DeserializeAsync<ListingEntry[]>(listingStream);
+                    }
+                }
+
+                if (logIndex < 0) logIndex = listingResult.Length - 1;
+                string logName = listingResult[logIndex].name;
+
+                using (var logRequest = await GetRequestAsync(HttpMethod.Get, $"{FunctionLogPath}/{functionName}/{logName}", cancellationToken))
+                {
+                    var logResponse = await client.SendAsync(logRequest, cancellationToken);
+                    string logData = await logResponse.Content.ReadAsStringAsync();
+                    if (!logResponse.IsSuccessStatusCode)
+                    {
+                        logger.WriteError($"Cannot list {functionName}'s {logName} log: {logResponse.ReasonPhrase}");
+                        return null;
+                    }
+                    return logData;
+                }
+            }
+        }
+
         internal async Task StreamLogsAsync(TextWriter output, string lastLinePattern, CancellationToken cancellationToken)
         {
             var regex = new Regex(lastLinePattern);

src/aggregator-cli/TestCommands/CreateTestCommand.cs

@@ -1,4 +1,5 @@
-using System.Threading;
+using System;
+using System.Threading;
 using System.Threading.Tasks;
 using CommandLine;
 
@@ -19,8 +20,10 @@ class CreateTestCommand : CommandBase
         [Option('t', "title", Required = false, Default = "Aggregator CLI Test Task", HelpText = "Title for new Work Item.")]
         public string Title { get; set; }
 
-        [Option('l', "lastLinePattern", Required = false, Default = @"Executed \'Functions\.", HelpText = "RegEx Pattern identifying last line of logs.")]
-        public string LastLinePattern { get; set; }
+        //[Option('l', "lastLinePattern", Required = false, Default = @"Executed \'Functions\.", HelpText = "RegEx Pattern identifying last line of logs.")]
+        //public string LastLinePattern { get; set; }
+        [Option('r', "rule", Required = true, HelpText = "Aggregator rule name.")]
+        public string RuleName { get; set; }
 
         internal override async Task<int> RunAsync(CancellationToken cancellationToken)
         {
@@ -32,9 +35,13 @@ internal override async Task<int> RunAsync(CancellationToken cancellationToken)
             var instances = new AggregatorInstances(context.Azure, context.Logger, context.Naming);
             var boards = new Boards(context.Devops, context.Logger);
 
-            var streamTask = instances.StreamLogsAsync(instance, lastLinePattern: this.LastLinePattern, cancellationToken: cancellationToken);
             int id = await boards.CreateWorkItemAsync(this.Project, this.Title, cancellationToken);
-            streamTask.Wait(cancellationToken);
+
+            // wait for the Event to be processed in AzDO, sent via WebHooks, and the Function to run
+            Thread.Sleep(new TimeSpan(0, 2, 0));
+
+            await instances.ReadLogAsync(instance, this.RuleName, -1, cancellationToken: cancellationToken);
+
             return id > 0 ? 0 : 1;
         }
     }

src/integrationtests-cli/Scenario1_Minimal.cs

@@ -73,7 +73,7 @@ void MapRules()
         [Fact, Order(40)]
         void CreateWorkItemAndCheckTrigger()
         {
-            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instanceName} --project \"{TestLogonData.ProjectName}\" ");
+            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instanceName} --project \"{TestLogonData.ProjectName}\"  --rule {ruleName} ");
             Assert.Equal(0, rc);
             // Sample output from rule:
             //  Returning 'Hello Task #118 from Rule 5!' from 'TestRule5'

src/integrationtests-cli/Scenario3_MultiInstance.cs

@@ -107,7 +107,7 @@ void ListMappings(string instancePrefix, string rule)
         void CreateWorkItemAndCheckTrigger(string instancePrefix, string rule)
         {
             string instance = instancePrefix + TestLogonData.UniqueSuffix;
-            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instance} --project \"{TestLogonData.ProjectName}\" ");
+            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instance} --project \"{TestLogonData.ProjectName}\" --rule {rule} ");
             Assert.Equal(0, rc);
             // Sample output from rule:
             //  Returning 'Hello Task #118 from Rule 5!' from 'TestRule5'
@@ -132,7 +132,7 @@ void RemapRules()
         void CreateAnotherWorkItemAndCheckTrigger(string instancePrefix, string rule)
         {
             string instance = instancePrefix + TestLogonData.UniqueSuffix;
-            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instance} --project \"{TestLogonData.ProjectName}\" ");
+            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --resourceGroup {TestLogonData.ResourceGroup} --instance {instance} --project \"{TestLogonData.ProjectName}\" --rule {rule} ");
             Assert.Equal(0, rc);
             // Sample output from rule:
             //  Returning 'Hello Task #118 from Rule 5!' from 'TestRule5'

src/integrationtests-cli/Scenario4_NamingTemplate.cs

@@ -108,7 +108,7 @@ void ListMappings(string instancePrefix, string rule)
         void CreateWorkItemAndCheckTrigger(string instancePrefix, string rule)
         {
             string instance = instancePrefix + TestLogonData.UniqueSuffix;
-            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --namingTemplate {TemplateFile} --resourceGroup {ResourceGroupName} --instance {instance} --project \"{TestLogonData.ProjectName}\" ");
+            (int rc, string output) = RunAggregatorCommand($"test.create --verbose --namingTemplate {TemplateFile} --resourceGroup {ResourceGroupName} --instance {instance} --project \"{TestLogonData.ProjectName}\" --rule {rule} ");
             Assert.Equal(0, rc);
             // Sample output from rule:
             //  Returning 'Hello Task #118 from Rule 5!' from 'test5'