Skip to content

Commit

Permalink
[AzureMonitorDistro] Add field validation to Integration Tests (part1) (
Browse files Browse the repository at this point in the history
#44429)

* saving work in progress. new class to validate telemetry fields. new logging to debug locally.

* cleanup

* additional logging and null checks

* comment
  • Loading branch information
TimothyMothra committed Jun 11, 2024
1 parent 2e5ed97 commit 724a605
Show file tree
Hide file tree
Showing 4 changed files with 1,102 additions and 65 deletions.
Original file line number Diff line number Diff line change
@@ -1,7 +1,9 @@
// Copyright (c) Microsoft Corporation. All rights reserved.
// Licensed under the MIT License.

using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Net.Http;
using System.Threading.Tasks;

Expand All @@ -16,6 +18,7 @@
using OpenTelemetry.Metrics;
using OpenTelemetry.Resources;
using OpenTelemetry.Trace;
using static Azure.Monitor.OpenTelemetry.AspNetCore.Integration.Tests.TelemetryValidationHelper;

#if NET6_0_OR_GREATER
namespace Azure.Monitor.OpenTelemetry.AspNetCore.Integration.Tests
Expand All @@ -38,9 +41,18 @@ public DistroWebAppLiveTests(bool isAsync) : base(isAsync) { }

[RecordedTest]
[SyncOnly] // This test cannot run concurrently with another test because OTel instruments the process and will cause side effects.
//[Ignore("Test fails in Mac-OS.")]
public async Task VerifyDistro()
{
Console.WriteLine($"Integration test '{nameof(VerifyDistro)}' running in mode '{TestEnvironment.Mode}'");

// DEVELOPER TIP: This test implicitly checks for telemetry within the last 30 minutes.
// When working locally, this has the benefit of "priming" telemetry so that additional runs can complete faster without waiting for ingestion.
// This can negatively impact the test results if you are debugging locally and making changes to the telemetry.
// To mitigate this, you can include a timestamp in the query to only check for telemetry created since this test started.
// IMPORTANT: we cannot include timestamps in the Recorded test because it breaks queries during playback.
// C#: var testStartTimeStamp = DateTime.UtcNow.ToString("yyyy-MM-ddTHH:mm:ss.fffffffZ");
// QUERY: | where TimeGenerated >= datetime({ testStartTimeStamp})

// SETUP TELEMETRY CLIENT (FOR QUERYING LOG ANALYTICS)
_logsQueryClient = InstrumentClient(new LogsQueryClient(
TestEnvironment.LogsEndpoint,
Expand Down Expand Up @@ -73,6 +85,7 @@ public async Task VerifyDistro()
.ConfigureResource(x => x.AddAttributes(resourceAttributes))
.UseAzureMonitor(options =>
{
options.EnableLiveMetrics = false;
options.ConnectionString = TestEnvironment.ConnectionString;
});

Expand Down Expand Up @@ -104,41 +117,79 @@ public async Task VerifyDistro()

// ASSERT
// NOTE: The following queries are using the LogAnalytics schema.
// TODO: NEED TO PERFORM COLUMN LEVEL VALIDATIONS.
await VerifyTelemetry(
await QueryAndVerifyDependency(
description: "Dependency for invoking HttpClient, from testhost",
query: $"AppDependencies | where Data == '{TestServerUrl}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated");
query: $"AppDependencies | where Data == '{TestServerUrl}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated",
expectedAppDependency: new ExpectedAppDependency
{
Data = TestServerUrl,
AppRoleName = RoleName,
});

await VerifyTelemetry(
await QueryAndVerifyRequest(
description: "RequestTelemetry, from WebApp",
query: $"AppRequests | where Url == '{TestServerUrl}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated");
query: $"AppRequests | where Url == '{TestServerUrl}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated",
expectedAppRequest: new ExpectedAppRequest
{
Url = TestServerUrl,
AppRoleName = RoleName,
});

await VerifyTelemetry(
await QueryAndVerifyMetric(
description: "Metric for outgoing request, from testhost",
query: $"AppMetrics | where Name == 'http.client.duration' | where AppRoleName == '{RoleName}' | where Properties.['net.peer.name'] == 'localhost' | top 1 by TimeGenerated");
query: $"AppMetrics | where Name == 'http.client.request.duration' | where AppRoleName == '{RoleName}' | where Properties.['server.address'] == 'localhost' | top 1 by TimeGenerated",
expectedAppMetric: new ExpectedAppMetric
{
Name = "http.client.request.duration",
AppRoleName = RoleName,
Properties = new List<KeyValuePair<string, string>>
{
new("server.address", "localhost"),
},
});

await VerifyTelemetry(
await QueryAndVerifyMetric(
description: "Metric for incoming request, from WebApp",
query: $"AppMetrics | where Name == 'http.server.duration' | where AppRoleName == '{RoleName}' | where Properties.['net.host.name'] == 'localhost' | top 1 by TimeGenerated");
query: $"AppMetrics | where Name == 'http.server.request.duration' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated",
expectedAppMetric: new ExpectedAppMetric
{
Name = "http.server.request.duration",
AppRoleName = RoleName,
Properties = new(),
});

await VerifyTelemetry(
await QueryAndVerifyTrace(
description: "ILogger LogInformation, from WebApp",
query: $"AppTraces | where Message == '{LogMessage}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated");
query: $"AppTraces | where Message == '{LogMessage}' | where AppRoleName == '{RoleName}' | top 1 by TimeGenerated",
expectedAppTrace: new ExpectedAppTrace
{
Message = LogMessage,
AppRoleName = RoleName,
});
}

private async Task VerifyTelemetry(string description, string query)
private async Task QueryAndVerifyDependency(string description, string query, ExpectedAppDependency expectedAppDependency)
{
LogsTable? table = await _logsQueryClient!.CheckForRecordAsync(query);
LogsTable? logsTable = await _logsQueryClient!.QueryTelemetryAsync(description, query);
ValidateExpectedTelemetry(description, logsTable, expectedAppDependency);
}

var rowCount = table?.Rows.Count;
if (rowCount == null || rowCount == 0)
{
Assert.Fail($"No telemetry records were found: {description}");
}
else
{
Assert.Pass();
}
private async Task QueryAndVerifyRequest(string description, string query, ExpectedAppRequest expectedAppRequest)
{
LogsTable? logsTable = await _logsQueryClient!.QueryTelemetryAsync(description, query);
ValidateExpectedTelemetry(description, logsTable, expectedAppRequest);
}

private async Task QueryAndVerifyMetric(string description, string query, ExpectedAppMetric expectedAppMetric)
{
LogsTable? logsTable = await _logsQueryClient!.QueryTelemetryAsync(description, query);
ValidateExpectedTelemetry(description, logsTable, expectedAppMetric);
}

private async Task QueryAndVerifyTrace(string description, string query, ExpectedAppTrace expectedAppTrace)
{
LogsTable? logsTable = await _logsQueryClient!.QueryTelemetryAsync(description, query);
ValidateExpectedTelemetry(description, logsTable, expectedAppTrace);
}
}
}
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -2,47 +2,46 @@
// Licensed under the MIT License.

using System;
using System.Diagnostics;
using System.Threading.Tasks;
using Azure.Monitor.Query;
using Azure.Monitor.Query.Models;
using NUnit.Framework;

namespace Azure.Monitor.OpenTelemetry.AspNetCore.Integration.Tests
{
internal static class LogsQueryClientExtensions
{
private static string s_workspaceId = string.Empty;
private static TimeSpan s_queryDelay = TimeSpan.FromSeconds(30);

public static void SetQueryWorkSpaceId(this LogsQueryClient client, string workspaceId) => s_workspaceId = workspaceId;

public static async Task<LogsTable?> CheckForRecordAsync(this LogsQueryClient client, string query)
public static async Task<LogsTable?> QueryTelemetryAsync(this LogsQueryClient client, string description, string query)
{
LogsTable? table = null;
int count = 0;
Debug.WriteLine($"UnitTest: Query Telemetry ({description})");
TestContext.Out.WriteLine($"Query Telemetry ({description})");

// Try every 30 secs for total of 5 minutes.
int maxTries = 10;
while (count == 0 && maxTries > 0)
for (int attempt = 1; attempt <= maxTries; attempt++)
{
Response<LogsQueryResult> response = await client.QueryWorkspaceAsync(
s_workspaceId,
query,
new QueryTimeRange(TimeSpan.FromMinutes(30)));

table = response.Value.Table;

count = table.Rows.Count;

if (count > 0)
if (response.Value.Table.Rows.Count > 0)
{
break;
return response.Value.Table;
}

maxTries--;

await Task.Delay(TimeSpan.FromSeconds(30));
Debug.WriteLine($"UnitTest: Query attempt {attempt}/{maxTries} returned no records. Waiting {s_queryDelay.TotalSeconds} seconds...");
TestContext.Out.WriteLine($"Query attempt {attempt}/{maxTries} returned no records. Waiting {s_queryDelay.TotalSeconds} seconds...");
await Task.Delay(s_queryDelay);
}

return table;
return null;
}
}
}
Loading

0 comments on commit 724a605

Please sign in to comment.