diff --git a/src/OpenTelemetry.Exporter.Geneva/GenevaLogExporter.cs b/src/OpenTelemetry.Exporter.Geneva/GenevaLogExporter.cs index 886a852438..3fe8ed502e 100644 --- a/src/OpenTelemetry.Exporter.Geneva/GenevaLogExporter.cs +++ b/src/OpenTelemetry.Exporter.Geneva/GenevaLogExporter.cs @@ -181,22 +181,19 @@ internal bool IsUsingUnixDomainSocket internal int SerializeLogRecord(LogRecord logRecord) { - bool isUnstructuredLog = true; IReadOnlyList> listKvp; if (logRecord.State == null) { + // When State is null, OTel SDK guarantees StateValues is populated + // TODO: Debug.Assert? listKvp = logRecord.StateValues; } else { + // Attempt to see if State could be ROL_KVP. listKvp = logRecord.State as IReadOnlyList>; } - if (listKvp != null) - { - isUnstructuredLog = listKvp.Count == 1; - } - var name = logRecord.CategoryName; // If user configured explicit TableName, use it. @@ -325,81 +322,72 @@ internal int SerializeLogRecord(LogRecord logRecord) cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, name); cntFields += 1; - if (isUnstructuredLog) + bool hasEnvProperties = false; + bool bodyPopulated = false; + for (int i = 0; i < listKvp?.Count; i++) + { + var entry = listKvp[i]; + + // Iteration #1 - Get those fields which become dedicated columns + // i.e all Part B fields and opt-in Part C fields. + if (entry.Key == "{OriginalFormat}") + { + cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "body"); + cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, logRecord.FormattedMessage ?? Convert.ToString(entry.Value, CultureInfo.InvariantCulture)); + cntFields += 1; + bodyPopulated = true; + continue; + } + else if (this.m_customFields == null || this.m_customFields.ContainsKey(entry.Key)) + { + // TODO: the above null check can be optimized and avoided inside foreach. + if (entry.Value != null) + { + // null is not supported. + cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, entry.Key); + cursor = MessagePackSerializer.Serialize(buffer, cursor, entry.Value); + cntFields += 1; + } + } + else + { + hasEnvProperties = true; + continue; + } + } + + if (!bodyPopulated && logRecord.FormattedMessage != null) { cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "body"); - cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, logRecord.FormattedMessage ?? (listKvp != null ? Convert.ToString(listKvp[0].Value, CultureInfo.InvariantCulture) : Convert.ToString(logRecord.State, CultureInfo.InvariantCulture))); + cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, logRecord.FormattedMessage); cntFields += 1; } - else + + if (hasEnvProperties) { - bool hasEnvProperties = false; - bool bodyPopulated = false; + // Iteration #2 - Get all "other" fields and collapse them into single field + // named "env_properties". + ushort envPropertiesCount = 0; + cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "env_properties"); + cursor = MessagePackSerializer.WriteMapHeader(buffer, cursor, ushort.MaxValue); + int idxMapSizeEnvPropertiesPatch = cursor - 2; for (int i = 0; i < listKvp.Count; i++) { var entry = listKvp[i]; - - // Iteration #1 - Get those fields which become dedicated column - // i.e all PartB fields and opt-in part c fields. - if (entry.Key == "{OriginalFormat}") + if (entry.Key == "{OriginalFormat}" || this.m_customFields.ContainsKey(entry.Key)) { - cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "body"); - cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, logRecord.FormattedMessage ?? Convert.ToString(entry.Value, CultureInfo.InvariantCulture)); - cntFields += 1; - bodyPopulated = true; continue; } - else if (this.m_customFields == null || this.m_customFields.ContainsKey(entry.Key)) - { - // TODO: the above null check can be optimized and avoided inside foreach. - if (entry.Value != null) - { - // Geneva doesn't support null. - cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, entry.Key); - cursor = MessagePackSerializer.Serialize(buffer, cursor, entry.Value); - cntFields += 1; - } - } else { - hasEnvProperties = true; - continue; + cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, entry.Key); + cursor = MessagePackSerializer.Serialize(buffer, cursor, entry.Value); + envPropertiesCount += 1; } } - if (!bodyPopulated && logRecord.FormattedMessage != null) - { - cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "body"); - cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, logRecord.FormattedMessage); - cntFields += 1; - } - - if (hasEnvProperties) - { - // Iteration #2 - Get all "other" fields and collapse them into single field - // named "env_properties". - ushort envPropertiesCount = 0; - cursor = MessagePackSerializer.SerializeAsciiString(buffer, cursor, "env_properties"); - cursor = MessagePackSerializer.WriteMapHeader(buffer, cursor, ushort.MaxValue); - int idxMapSizeEnvPropertiesPatch = cursor - 2; - for (int i = 0; i < listKvp.Count; i++) - { - var entry = listKvp[i]; - if (entry.Key == "{OriginalFormat}" || this.m_customFields.ContainsKey(entry.Key)) - { - continue; - } - else - { - cursor = MessagePackSerializer.SerializeUnicodeString(buffer, cursor, entry.Key); - cursor = MessagePackSerializer.Serialize(buffer, cursor, entry.Value); - envPropertiesCount += 1; - } - } - - cntFields += 1; - MessagePackSerializer.WriteUInt16(buffer, idxMapSizeEnvPropertiesPatch, envPropertiesCount); - } + cntFields += 1; + MessagePackSerializer.WriteUInt16(buffer, idxMapSizeEnvPropertiesPatch, envPropertiesCount); } var eventId = logRecord.EventId; diff --git a/test/OpenTelemetry.Exporter.Geneva.Tests/GenevaLogExporterTests.cs b/test/OpenTelemetry.Exporter.Geneva.Tests/GenevaLogExporterTests.cs index d002226cda..b2d7d4482f 100644 --- a/test/OpenTelemetry.Exporter.Geneva.Tests/GenevaLogExporterTests.cs +++ b/test/OpenTelemetry.Exporter.Geneva.Tests/GenevaLogExporterTests.cs @@ -261,8 +261,15 @@ public void SerializationTestWithILoggerLogMethod(bool includeFormattedMessage) _ = exporter.SerializeLogRecord(logRecordList[0]); object fluentdData = MessagePack.MessagePackSerializer.Deserialize(m_buffer.Value, MessagePack.Resolvers.ContractlessStandardResolver.Instance); var body = GetField(fluentdData, "body"); - string expectedBody = includeFormattedMessage ? "Formatted Message" : null; - Assert.Equal(expectedBody, body); + if (includeFormattedMessage) + { + Assert.Equal("Formatted Message", body); + } + else + { + Assert.Null(body); + } + Assert.Equal("Value1", GetField(fluentdData, "Key1")); Assert.Equal("Value2", GetField(fluentdData, "Key2")); @@ -284,8 +291,14 @@ public void SerializationTestWithILoggerLogMethod(bool includeFormattedMessage) _ = exporter.SerializeLogRecord(logRecordList[0]); fluentdData = MessagePack.MessagePackSerializer.Deserialize(m_buffer.Value, MessagePack.Resolvers.ContractlessStandardResolver.Instance); body = GetField(fluentdData, "body"); - expectedBody = includeFormattedMessage ? "Formatted Message" : "somestringasdata"; - Assert.Equal(expectedBody, body); + if (includeFormattedMessage) + { + Assert.Equal("Formatted Message", body); + } + else + { + Assert.Null(body); + } // ARRANGE logRecordList.Clear(); @@ -306,9 +319,42 @@ public void SerializationTestWithILoggerLogMethod(bool includeFormattedMessage) fluentdData = MessagePack.MessagePackSerializer.Deserialize(m_buffer.Value, MessagePack.Resolvers.ContractlessStandardResolver.Instance); body = GetField(fluentdData, "body"); - // Formatter is null, hence body is always the ToString() of the data - expectedBody = "somestringasdata"; - Assert.Equal(expectedBody, body); + // Formatter is null, hence body is always null + Assert.Null(body); + + // ARRANGE + logRecordList.Clear(); + + // ACT + // This is treated as Structured logging as the state can be converted to IReadOnlyList> + logger.Log( + logLevel: LogLevel.Information, + eventId: default, + new List>() + { + new KeyValuePair("Key1", "Value1"), + }, + exception: null, + formatter: (state, ex) => "Example formatted message."); + + // VALIDATE + Assert.Single(logRecordList); + m_buffer = typeof(GenevaLogExporter).GetField("m_buffer", BindingFlags.NonPublic | BindingFlags.Static).GetValue(exporter) as ThreadLocal; + _ = exporter.SerializeLogRecord(logRecordList[0]); + fluentdData = MessagePack.MessagePackSerializer.Deserialize(m_buffer.Value, MessagePack.Resolvers.ContractlessStandardResolver.Instance); + Assert.Equal("Value1", GetField(fluentdData, "Key1")); + + body = GetField(fluentdData, "body"); + + // Only populate body if FormattedMessage is enabled + if (includeFormattedMessage) + { + Assert.Equal("Example formatted message.", body); + } + else + { + Assert.Null(body); + } } finally { @@ -333,7 +379,7 @@ public void SerializationTestWithILoggerLogMethod(bool includeFormattedMessage) [InlineData(true, false, true)] [InlineData(true, true, true)] [Trait("Platform", "Any")] - public void SuccessfulSerialization(bool hasTableNameMapping, bool hasCustomFields, bool parseStateValues) + public void SerializationTestWithILoggerLogWithTemplates(bool hasTableNameMapping, bool hasCustomFields, bool parseStateValues) { string path = string.Empty; Socket server = null; @@ -427,29 +473,13 @@ public void SuccessfulSerialization(bool hasTableNameMapping, bool hasCustomFiel logger.Log(LogLevel.Error, 101, "Log a {customField} and {property}", "CustomFieldValue", "PropertyValue"); logger.Log(LogLevel.Critical, 101, "Log a {customField} and {property}", "CustomFieldValue", "PropertyValue"); logger.LogInformation("Hello World!"); // unstructured logging - - logger.Log(LogLevel.Information, default, "Hello World!", null, null); // unstructured logging using a non-extension method call - - // logging custom state - // This is treated as structured logging as the state can be converted to IReadOnlyList> - logger.Log( - LogLevel.Information, - default, - new List>() - { - new KeyValuePair("Key1", "Value1"), - new KeyValuePair("Key2", "Value2"), - }, - null, - (state, ex) => "Formatted Exception!"); - logger.LogError(new InvalidOperationException("Oops! Food is spoiled!"), "Hello from {food} {price}.", "artichoke", 3.99); var loggerWithDefaultCategory = loggerFactory.CreateLogger("DefaultCategory"); loggerWithDefaultCategory.LogInformation("Basic test"); - // logRecordList should have two logRecord entries after the logger.LogInformation calls - Assert.Equal(14, logRecordList.Count); + // logRecordList should have 12 logRecord entries as there were 12 Log calls + Assert.Equal(12, logRecordList.Count); var m_buffer = typeof(GenevaLogExporter).GetField("m_buffer", BindingFlags.NonPublic | BindingFlags.Static).GetValue(exporter) as ThreadLocal;