ILogger integration fix for net6 when WebApplicationBuilder is used

CHANGELOG.md

@@ -28,6 +28,9 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
 
 ### Fixed
 
+- Fixed log emission issue for ASP.NET Core 6.0 apps when bytecode
+  instrumentation is enabled and `WebApplicationBuilder` is used
+
 ### Security
 
 ## [1.0.2](https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/releases/tag/v1.0.2)

OpenTelemetry.AutoInstrumentation.sln

@@ -203,7 +203,9 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "TestApplication.Azure", "te
 EndProject
 Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "TestApplication.Wcf.Client.DotNet", "test\test-applications\integrations\TestApplication.Wcf.Client.DotNet\TestApplication.Wcf.Client.DotNet.csproj", "{EDE168E0-DBCD-4DE3-B55A-4B633ED6565E}"
 EndProject
-Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TestApplication.Razor", "test\test-applications\integrations\TestApplication.Razor\TestApplication.Razor.csproj", "{1C76773E-2582-40DB-A720-3798E3928876}"
+Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "TestApplication.Razor", "test\test-applications\integrations\TestApplication.Razor\TestApplication.Razor.csproj", "{1C76773E-2582-40DB-A720-3798E3928876}"
+EndProject
+Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "TestApplication.MinimalApi", "test\test-applications\integrations\TestApplication.MinimalApi\TestApplication.MinimalApi.csproj", "{803A3DD1-016E-4713-8066-A1C81A6ADBA3}"
 EndProject
 Global
 	GlobalSection(SolutionConfigurationPlatforms) = preSolution
@@ -977,6 +979,18 @@ Global
 		{1C76773E-2582-40DB-A720-3798E3928876}.Release|x64.Build.0 = Release|x64
 		{1C76773E-2582-40DB-A720-3798E3928876}.Release|x86.ActiveCfg = Release|x86
 		{1C76773E-2582-40DB-A720-3798E3928876}.Release|x86.Build.0 = Release|x86
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|Any CPU.ActiveCfg = Debug|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|Any CPU.Build.0 = Debug|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|x64.ActiveCfg = Debug|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|x64.Build.0 = Debug|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|x86.ActiveCfg = Debug|x86
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Debug|x86.Build.0 = Debug|x86
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|Any CPU.ActiveCfg = Release|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|Any CPU.Build.0 = Release|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|x64.ActiveCfg = Release|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|x64.Build.0 = Release|x64
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|x86.ActiveCfg = Release|x86
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3}.Release|x86.Build.0 = Release|x86
 	EndGlobalSection
 	GlobalSection(SolutionProperties) = preSolution
 		HideSolutionNode = FALSE
@@ -1051,6 +1065,7 @@ Global
 		{3A125210-A784-4982-ACDB-C3442E414E44} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
 		{EDE168E0-DBCD-4DE3-B55A-4B633ED6565E} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
 		{1C76773E-2582-40DB-A720-3798E3928876} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
+		{803A3DD1-016E-4713-8066-A1C81A6ADBA3} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
 	EndGlobalSection
 	GlobalSection(ExtensibilityGlobals) = postSolution
 		SolutionGuid = {160A1D00-1F5B-40F8-A155-621B4459D78F}

src/OpenTelemetry.AutoInstrumentation/Instrumentations/Logger/LoggingBuilderIntegration.cs

@@ -47,7 +47,7 @@ internal static CallTargetReturn OnMethodEnd<TTarget>(TTarget instance, Exceptio
         if (instance is not null)
         {
             var logBuilderExtensionsType = Type.GetType("OpenTelemetry.AutoInstrumentation.Logger.LogBuilderExtensions, OpenTelemetry.AutoInstrumentation");
-            var methodInfo = logBuilderExtensionsType?.GetMethod("AddOpenTelemetryLogs");
+            var methodInfo = logBuilderExtensionsType?.GetMethod("AddOpenTelemetryLogsFromIntegration");
             methodInfo?.Invoke(null, new[] { (object)instance });
         }
 

src/OpenTelemetry.AutoInstrumentation/Logger/LogBuilderExtensions.cs

@@ -25,7 +25,27 @@ namespace OpenTelemetry.AutoInstrumentation.Logger;
 
 internal static class LogBuilderExtensions
 {
+    private static bool? _autoInstrumentationStartupAssemblyConfigured;
     private static Type? _loggingProviderSdkType;
+    private static Type? _applicationLifetimeType;
+
+    public static void AddOpenTelemetryLogsFromIntegration(this ILoggingBuilder builder)
+    {
+        // For Net6, if HostingStartupAssembly is configured, we don't want to call integration again for host's ServiceCollection.
+        // OpenTelemetryLogger-related services were already added to WebApplicationServiceCollection and will
+        // be copied to host's ServiceCollection later. We can't depend on integration's
+        // capability to detect if integration was called before (by checking if ServiceDescriptor with
+        // given type is already added to ServiceCollection) as copying services from WebApplicationServiceCollection
+        // to host's ServiceCollection happens AFTER integration is called.
+
+        // All of this additional checking is NOT needed for net7. There we can rely on integration's capability
+        // to detect if integration was called before, because WebApplicationServiceCollection is not used when building host.
+
+        if (builder.Services is ServiceCollection && !(IsNet6() && IsAutoInstrumentationStartupAssemblyConfigured() && IsHostServiceCollection(builder.Services)))
+        {
+            AddOpenTelemetryLogs(builder);
+        }
+    }
 
     public static ILoggingBuilder AddOpenTelemetryLogs(this ILoggingBuilder builder)
     {
@@ -96,5 +116,31 @@ public static ILoggingBuilder AddOpenTelemetryLogs(this ILoggingBuilder builder)
 
         return builder;
     }
+
+    private static bool IsAutoInstrumentationStartupAssemblyConfigured()
+    {
+        // If autoinstrumentation's HostingStartupAssembly is configured, assume integration was already called.
+        _autoInstrumentationStartupAssemblyConfigured ??= IsAutoInstrumentationStartupAssemblySet();
+        return _autoInstrumentationStartupAssemblyConfigured.Value;
+    }
+
+    private static bool IsNet6()
+    {
+        var frameworkDescription = FrameworkDescription.Instance;
+        return frameworkDescription.Name == ".NET" && frameworkDescription.ProductVersion.StartsWith("6");
+    }
+
+    private static bool IsHostServiceCollection(IServiceCollection builderServices)
+    {
+        _applicationLifetimeType ??= Type.GetType("Microsoft.Extensions.Hosting.Internal.ApplicationLifetime, Microsoft.Extensions.Hosting");
+        var applicationLifetimeDescriptor = builderServices.FirstOrDefault(sd => sd.ImplementationType == _applicationLifetimeType);
+        return applicationLifetimeDescriptor != null;
+    }
+
+    private static bool IsAutoInstrumentationStartupAssemblySet()
+    {
+        var environmentVariable = Environment.GetEnvironmentVariable("ASPNETCORE_HOSTINGSTARTUPASSEMBLIES");
+        return environmentVariable != null && environmentVariable.Contains("OpenTelemetry.AutoInstrumentation.AspNetCoreBootstrapper");
+    }
 }
 #endif

test/IntegrationTests/MinimalApiTests.cs

@@ -0,0 +1,69 @@
+// <copyright file="MinimalApiTests.cs" company="OpenTelemetry Authors">
+// Copyright The OpenTelemetry Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+// </copyright>
+
+#if NET6_0_OR_GREATER
+
+using IntegrationTests.Helpers;
+using OpenTelemetry.Proto.Logs.V1;
+using Xunit.Abstractions;
+
+namespace IntegrationTests;
+
+public class MinimalApiTests : TestHelper
+{
+    public MinimalApiTests(ITestOutputHelper output)
+        : base("MinimalApi", output)
+    {
+    }
+
+    [Theory]
+    [InlineData(true, true)]
+    [InlineData(true, false)]
+    [InlineData(false, true)]
+    [Trait("Category", "EndToEnd")]
+    public async Task SubmitsLogsWithoutDuplicates(bool enableByteCodeInstrumentation, bool enableHostingStartupAssembly)
+    {
+        using var collector = new MockLogsCollector(Output);
+        SetExporter(collector);
+
+        collector.ExpectCollected(ValidateSingleAppLogRecord, "App log record should be exported once.");
+
+        SetEnvironmentVariable("OTEL_DOTNET_AUTO_LOGS_INCLUDE_FORMATTED_MESSAGE", "true");
+
+        if (enableByteCodeInstrumentation)
+        {
+            EnableBytecodeInstrumentation();
+        }
+
+        if (enableHostingStartupAssembly)
+        {
+            SetEnvironmentVariable("ASPNETCORE_HOSTINGSTARTUPASSEMBLIES", "OpenTelemetry.AutoInstrumentation.AspNetCoreBootstrapper");
+        }
+
+        RunTestApplication();
+
+        // wait for fixed amount of time for logs to be collected before asserting
+        await Task.Delay(TimeSpan.FromSeconds(10));
+
+        collector.AssertCollected();
+    }
+
+    private static bool ValidateSingleAppLogRecord(IEnumerable<LogRecord> records)
+    {
+        return records.Count(lr => Convert.ToString(lr.Body) == "{ \"stringValue\": \"Request received.\" }") == 1;
+    }
+}
+#endif

test/test-applications/integrations/TestApplication.MinimalApi/Program.cs

@@ -0,0 +1,36 @@
+// <copyright file="Program.cs" company="OpenTelemetry Authors">
+// Copyright The OpenTelemetry Authors
+//
+// Licensed under the Apache License, Version 2.0 (the "License");
+// you may not use this file except in compliance with the License.
+// You may obtain a copy of the License at
+//
+//     http://www.apache.org/licenses/LICENSE-2.0
+//
+// Unless required by applicable law or agreed to in writing, software
+// distributed under the License is distributed on an "AS IS" BASIS,
+// WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
+// See the License for the specific language governing permissions and
+// limitations under the License.
+// </copyright>
+
+using System.Net.Http;
+using Microsoft.AspNetCore.Hosting.Server;
+using Microsoft.AspNetCore.Hosting.Server.Features;
+
+var builder = WebApplication.CreateBuilder(args);
+using var app = builder.Build();
+app.MapGet("/test", (ILogger<Program> logger) =>
+{
+    logger.LogInformation("Request received.");
+    return "Hello World!";
+});
+
+app.Start();
+
+var server = (IServer?)app.Services.GetService(typeof(IServer));
+var addressFeature = server?.Features.Get<IServerAddressesFeature>();
+var address = addressFeature?.Addresses.First();
+
+using var httpClient = new HttpClient();
+httpClient.GetAsync($"{address}/test").Wait();

test/test-applications/integrations/TestApplication.MinimalApi/Properties/launchSettings.json

@@ -0,0 +1,49 @@
+{
+  "iisSettings": {
+    "windowsAuthentication": false,
+    "anonymousAuthentication": true,
+    "iisExpress": {
+      "applicationUrl": "http://localhost:19686",
+      "sslPort": 44323
+    }
+  },
+  "profiles": {
+    "http": {
+      "commandName": "Project",
+      "dotnetRunMessages": true,
+      "launchBrowser": true,
+      "applicationUrl": "http://localhost:5102",
+      "environmentVariables": {
+        "ASPNETCORE_ENVIRONMENT": "Development"
+      }
+    },
+    "https": {
+      "commandName": "Project",
+      "dotnetRunMessages": true,
+      "launchBrowser": true,
+      "applicationUrl": "https://localhost:7273;http://localhost:5102",
+      "environmentVariables": {
+        "ASPNETCORE_ENVIRONMENT": "Development"
+      }
+    },
+    "instrumented": {
+      "commandName": "Project",
+      "launchBrowser": false,
+      "environmentVariables": {
+        "ASPNETCORE_ENVIRONMENT": "Development",
+        "CORECLR_ENABLE_PROFILING": "1",
+        "ASPNETCORE_HOSTINGSTARTUPASSEMBLIES": "OpenTelemetry.AutoInstrumentation.AspNetCoreBootstrapper",
+        "CORECLR_PROFILER": "{918728DD-259F-4A6A-AC2B-B85E1B658318}",
+        "CORECLR_PROFILER_PATH": "$(SolutionDir)bin\\tracer-home\\win-x64\\OpenTelemetry.AutoInstrumentation.Native.dll",
+        "DOTNET_ADDITIONAL_DEPS": "$(SolutionDir)bin\\tracer-home\\AdditionalDeps",
+        "DOTNET_SHARED_STORE": "$(SolutionDir)bin\\tracer-home\\store",
+        "DOTNET_STARTUP_HOOKS": "$(SolutionDir)bin\\tracer-home\\net\\OpenTelemetry.AutoInstrumentation.StartupHook.dll",
+        "OTEL_DOTNET_AUTO_HOME": "$(SolutionDir)bin\\tracer-home",
+        "OTEL_DOTNET_AUTO_LOGS_CONSOLE_EXPORTER_ENABLED": "true"
+      },
+      "use64Bit": true,
+      "nativeDebugging": true,
+      "applicationUrl": "http://localhost:54568"
+    }
+  }
+}

test/test-applications/integrations/TestApplication.MinimalApi/TestApplication.MinimalApi.csproj

@@ -0,0 +1,7 @@
+<Project Sdk="Microsoft.NET.Sdk.Web">
+
+  <PropertyGroup>
+    <TargetFrameworks>net7.0;net6.0</TargetFrameworks>
+  </PropertyGroup>
+
+</Project>

test/test-applications/integrations/TestApplication.MinimalApi/appsettings.Development.json

@@ -0,0 +1,8 @@
+{
+  "Logging": {
+    "LogLevel": {
+      "Default": "Information",
+      "Microsoft.AspNetCore": "Warning"
+    }
+  }
+}

test/test-applications/integrations/TestApplication.MinimalApi/appsettings.json

@@ -0,0 +1,9 @@
+{
+  "Logging": {
+    "LogLevel": {
+      "Default": "Information",
+      "Microsoft.AspNetCore": "Warning"
+    }
+  },
+  "AllowedHosts": "*"
+}