From 8a3f0c2f9ffa7f0c54488e0736355354c0a5b007 Mon Sep 17 00:00:00 2001 From: moprashant <13450721+moprashant@users.noreply.github.com> Date: Tue, 13 Oct 2026 11:13:14 +0530 Subject: [PATCH] Fix Event Hub telemetry logging without an EventContext Use persisted context for ordinary logging states and handle null state safely. Add regression coverage for context-free logs and existing structured event behavior. Co-authored-by: Copilot <223556219+Copilot@users.noreply.github.com> Copilot-Session: d7afa8f5-e846-41bf-bf84-842b11a52ef4 --- .../Logging/EventHubTelemetryLoggerTests.cs | 161 ++++++++++++++++++ .../Logging/EventHubTelemetryLogger.cs | 4 +- 2 files changed, 164 insertions(+), 1 deletion(-) diff --git a/src/VirtualClient/VirtualClient.Core.UnitTests/Logging/EventHubTelemetryLoggerTests.cs b/src/VirtualClient/VirtualClient.Core.UnitTests/Logging/EventHubTelemetryLoggerTests.cs index 6ad45c875a..fa9296cf19 100644 --- a/src/VirtualClient/VirtualClient.Core.UnitTests/Logging/EventHubTelemetryLoggerTests.cs +++ b/src/VirtualClient/VirtualClient.Core.UnitTests/Logging/EventHubTelemetryLoggerTests.cs @@ -140,6 +140,160 @@ public void EventHubTelemetryLoggerEnsuresTimestampsAreInUtcFormat() Assert.AreEqual(expectedTimestamp, eventBody["timestamp"].Value()); } + [Test] + public void EventHubTelemetryLoggerLogsFormattedInformationWithoutAnEventContext() + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + + logger.LogInformation("Processed {Count} items", 42); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual("Processed 42 items", eventBody["message"].ToString()); + Assert.AreEqual((int)LogLevel.Information, eventBody["severityLevel"].Value()); + } + + [TestCase("Plain message")] + [TestCase(null)] + public void EventHubTelemetryLoggerLogsPlainOrNullStateWithoutAnEventContext(string state) + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + + logger.Log(LogLevel.Information, default, state, null, null); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual(state, eventBody["message"]?.Value()); + Assert.AreEqual((int)LogLevel.Information, eventBody["severityLevel"].Value()); + Assert.IsNotNull(eventBody["customDimensions"]); + } + + [TestCase("Plain message")] + [TestCase(null)] + public void EventHubTelemetryLoggerPreservesAnExplicitEventNameWithoutAnEventContext(string state) + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + + logger.Log(LogLevel.Warning, new EventId(1, "NamedEvent"), state, null, (value, error) => "Formatted message"); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual("NamedEvent", eventBody["message"].ToString()); + Assert.AreEqual((int)LogLevel.Warning, eventBody["severityLevel"].Value()); + } + + [TestCase(true)] + [TestCase(false)] + public void EventHubTelemetryLoggerLogsExceptionsWithoutAnEventContext(bool withState) + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + Exception exception = new ArgumentException("Test exception"); + + logger.Log( + LogLevel.Error, + default, + withState ? "Test state" : null, + exception, + (value, error) => $"{value}: {error.Message}"); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + if (withState) + { + Assert.AreEqual("Test state: Test exception", eventBody["message"].ToString()); + } + else + { + StringAssert.Contains("Test exception", eventBody["message"].ToString()); + StringAssert.Contains(nameof(ArgumentException), eventBody["message"].ToString()); + } + + Assert.AreEqual((int)LogLevel.Error, eventBody["severityLevel"].Value()); + } + + [Test] + [NonParallelizable] + public void EventHubTelemetryLoggerUsesPersistedContextForOrdinaryLogs() + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + EventContext originalContext = EventContext.Persisted(); + Guid activityId = Guid.NewGuid(); + Guid parentActivityId = Guid.NewGuid(); + string propertyName = Guid.NewGuid().ToString(); + + try + { + EventContext.Persist(activityId, parentActivityId); + EventContext.PersistentProperties[propertyName] = "Persistent value"; + + logger.LogInformation("Ordinary message"); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual("Ordinary message", eventBody["message"].ToString()); + Assert.AreEqual(activityId.ToString(), eventBody["operation_Id"].ToString()); + Assert.AreEqual(parentActivityId.ToString(), eventBody["operation_ParentId"].ToString()); + Assert.AreEqual("Persistent value", eventBody["customDimensions"][propertyName].ToString()); + } + finally + { + EventContext.PersistentProperties.Remove(propertyName); + EventContext.Persist(originalContext.ActivityId, originalContext.ParentActivityId); + } + } + + [Test] + public void EventHubTelemetryLoggerPreservesStructuredContextWhenLogging() + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + DateTime timestamp = DateTime.UtcNow.AddMinutes(-30); + EventContext context = new EventContext(Guid.NewGuid(), Guid.NewGuid()) + .AddContext("appHost", "Host01") + .AddContext("timestamp", timestamp.ToString("o")) + .AddContext("property1", "Value"); + + logger.Log(LogLevel.Information, new EventId(1, "StructuredEvent"), context, null, null); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual("StructuredEvent", eventBody["message"].ToString()); + Assert.AreEqual(context.ActivityId.ToString(), eventBody["operation_Id"].ToString()); + Assert.AreEqual(context.ParentActivityId.ToString(), eventBody["operation_ParentId"].ToString()); + Assert.AreEqual(context.TransactionId.ToString(), eventBody["customDimensions"]["transactionId"].ToString()); + Assert.AreEqual("Host01", eventBody["appHost"].ToString()); + Assert.AreEqual(timestamp, eventBody["timestamp"].Value()); + Assert.AreEqual("Value", eventBody["customDimensions"]["property1"].ToString()); + } + + [Test] + public void EventHubTelemetryLoggerPreservesOversizedContextHandling() + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Information); + EventContext context = new EventContext(Guid.NewGuid(), Guid.NewGuid()) + .AddContext("largeProperty", new string('a', EventHubTelemetryChannel.MaxEventDataBytes)); + + logger.Log(LogLevel.Information, new EventId(1, "LargeEvent"), context, null, null); + + Assert.AreEqual(1, logger.Events.Count); + JObject eventBody = JObject.Parse(logger.Events[0].EventBody.ToString()); + Assert.AreEqual("LargeEvent", eventBody["message"].ToString()); + Assert.AreEqual(context.ActivityId.ToString(), eventBody["operation_Id"].ToString()); + Assert.AreEqual(context.ParentActivityId.ToString(), eventBody["operation_ParentId"].ToString()); + Assert.AreEqual(bool.TrueString, eventBody["customDimensions"]["exceededSizeLimits"].ToString()); + Assert.IsNull(eventBody["customDimensions"]["largeProperty"]); + Assert.Less(logger.Events[0].Body.Length, EventHubTelemetryChannel.MaxEventDataBytes); + } + + [Test] + public void EventHubTelemetryLoggerDoesNotEmitDisabledLogs() + { + TestEventHubTelemetryLogger logger = new TestEventHubTelemetryLogger(this.mockChannel, LogLevel.Warning); + + logger.LogInformation("Disabled message"); + + Assert.IsEmpty(logger.Events); + } + private class TestEventHubTelemetryLogger : EventHubTelemetryLogger { public TestEventHubTelemetryLogger(EventHubTelemetryChannel channel, LogLevel level) @@ -147,10 +301,17 @@ public TestEventHubTelemetryLogger(EventHubTelemetryChannel channel, LogLevel le { } + public IList Events { get; } = new List(); + public new EventData CreateEventObject(string eventMessage, LogLevel logLevel, DateTime eventTimestamp, EventContext eventContext, object bufferInfo = null) { return base.CreateEventObject(eventMessage, logLevel, eventTimestamp, eventContext, bufferInfo); } + + protected override void AddEventDataToChannel(EventData eventData) + { + this.Events.Add(eventData); + } } } } diff --git a/src/VirtualClient/VirtualClient.Core/Logging/EventHubTelemetryLogger.cs b/src/VirtualClient/VirtualClient.Core/Logging/EventHubTelemetryLogger.cs index 95a778a698..883d001415 100644 --- a/src/VirtualClient/VirtualClient.Core/Logging/EventHubTelemetryLogger.cs +++ b/src/VirtualClient/VirtualClient.Core/Logging/EventHubTelemetryLogger.cs @@ -226,10 +226,12 @@ private EventData CreateEvent(LogLevel logLevel, EventId eventId, TState else { // State context was provided by itself. - eventMessage = state.ToString(); + eventMessage = state?.ToString(); } } + eventContext ??= EventContext.Persisted(); + object bufferInfo = null; if (this.DiagnosticsEnabled) {