Make StartupLogger more resilient (#1972)

* Make StartupLogger more resilient

* Update CHANGELOG.md
This commit is contained in:
Paulo Janotti 2023-01-12 08:27:54 -08:00 committed by GitHub
parent dd79e41efc
commit 7ae4916ca9
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
6 changed files with 206 additions and 7 deletions

View File

@ -23,6 +23,9 @@ This component adheres to [Semantic Versioning](https://semver.org/spec/v2.0.0.h
### Fixed
- Fix console error messages `Log: Exception creating FileSink`
[#1885](https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/issues/1885)
### Security
## [0.5.1-beta.3](https://github.com/open-telemetry/opentelemetry-dotnet-instrumentation/releases/tag/v0.5.1-beta.3)

View File

@ -149,6 +149,8 @@ Project("{9A19103F-16F7-4668-BE54-9A1E7A4F7556}") = "TestApplication.Elasticsear
EndProject
Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TestApplication.AspNet.NetFramework", "test\test-applications\integrations\TestApplication.AspNet.NetFramework\TestApplication.AspNet.NetFramework.csproj", "{5FDB5603-21D3-446A-8B50-36DACCF7C2FF}"
EndProject
Project("{FAE04EC0-301F-11D3-BF4B-00C04F79EFBC}") = "TestApplication.MultipleAppDomains.NetFramework", "test\test-applications\integrations\TestApplication.MultipleAppDomains.NetFramework\TestApplication.MultipleAppDomains.NetFramework.csproj", "{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}"
EndProject
Global
GlobalSection(SolutionConfigurationPlatforms) = preSolution
Debug|Any CPU = Debug|Any CPU
@ -693,6 +695,18 @@ Global
{5FDB5603-21D3-446A-8B50-36DACCF7C2FF}.Release|x64.Build.0 = Release|x64
{5FDB5603-21D3-446A-8B50-36DACCF7C2FF}.Release|x86.ActiveCfg = Release|x86
{5FDB5603-21D3-446A-8B50-36DACCF7C2FF}.Release|x86.Build.0 = Release|x86
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|Any CPU.ActiveCfg = Debug|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|Any CPU.Build.0 = Debug|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|x64.ActiveCfg = Debug|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|x64.Build.0 = Debug|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|x86.ActiveCfg = Debug|x86
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Debug|x86.Build.0 = Debug|x86
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|Any CPU.ActiveCfg = Release|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|Any CPU.Build.0 = Release|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|x64.ActiveCfg = Release|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|x64.Build.0 = Release|x64
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|x86.ActiveCfg = Release|x86
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F}.Release|x86.Build.0 = Release|x86
EndGlobalSection
GlobalSection(SolutionProperties) = preSolution
HideSolutionNode = FALSE
@ -747,6 +761,7 @@ Global
{4DCB389E-0499-4104-9991-CCA021667D7A} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
{E1E55FB4-FCFF-4231-9CE7-C6671A3F5421} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
{5FDB5603-21D3-446A-8B50-36DACCF7C2FF} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
{A0338846-2AF8-4D96-ADA7-EBD4F010D08F} = {E409ADD3-9574-465C-AB09-4324D205CC7C}
EndGlobalSection
GlobalSection(ExtensibilityGlobals) = postSolution
SolutionGuid = {160A1D00-1F5B-40F8-A155-621B4459D78F}

View File

@ -15,6 +15,7 @@
// </copyright>
using System.Diagnostics;
using System.Text;
namespace OpenTelemetry.AutoInstrumentation.Loader;
@ -25,25 +26,27 @@ internal static class StartupLogger
private static readonly bool DebugEnabled = IsDebugEnabled();
private static readonly string? LogDirectory = GetLogDirectory();
private static readonly string? StartupLogFilePath = SetStartupLogFilePath();
private static readonly FileSink? LogFileSink = SetLogFileSink();
public static void Log(string message, params object[] args)
{
try
{
if (StartupLogFilePath != null)
if (LogFileSink != null)
{
try
{
using (var fileSink = new FileSink(StartupLogFilePath))
// It is possible a race with multiple threads under the same app domain.
lock (LogFileSink)
{
fileSink.Info($"[{DateTime.UtcNow:O}] {message}{Environment.NewLine}", args);
LogFileSink.Info($"[{DateTime.UtcNow:O}] [ThreadId: {Thread.CurrentThread.ManagedThreadId}] {message}{Environment.NewLine}", args);
}
return;
}
catch (Exception ex)
{
Console.Error.WriteLine($"Log: Exception creating FileSink {ex}");
Console.Error.WriteLine($"Log: Exception writing to FileSink {ex}");
}
}
@ -132,10 +135,32 @@ internal static class StartupLogger
try
{
// Pick up the parts used to build the log file name and minimize the chances
// of file name conflict with other processes.
using var process = Process.GetCurrentProcess();
var appDomainName = AppDomain.CurrentDomain.FriendlyName;
// Do our best to not block other processes on write
return Path.Combine(LogDirectory, $"otel-dotnet-auto-loader-{appDomainName}-{process.Id}.log");
// AppDomain friendly name can contain characters that are invalid in file names,
// remove any of those. For the first assembly loaded by the process this is typically
// expected to be name of the file with the application entry point.
var appDomainFriendlyName = AppDomain.CurrentDomain.FriendlyName;
var invalidChars = new string(Path.GetInvalidFileNameChars()) + new string(Path.GetInvalidPathChars());
var sb = new StringBuilder(appDomainFriendlyName);
for (int i = 0; i < sb.Length; i++)
{
if (invalidChars.IndexOf(sb[i]) != -1)
{
sb[i] = '_';
}
}
appDomainFriendlyName = sb.ToString();
// AppDomain friendly name may not be unique in the same process, use also the id.
// Per documentation the id is an integer that uniquely identifies the application
// domain within the process.
var appDomainId = AppDomain.CurrentDomain.Id;
return Path.Combine(LogDirectory, $"otel-dotnet-auto-loader-{appDomainFriendlyName}-{appDomainId}-{process?.Id}.log");
}
catch
{
@ -144,6 +169,25 @@ internal static class StartupLogger
}
}
private static FileSink? SetLogFileSink()
{
if (StartupLogFilePath == null)
{
return null;
}
try
{
return new FileSink(StartupLogFilePath);
}
catch (Exception ex)
{
Console.Error.WriteLine($"Log: Exception creating FileSink {ex}");
}
return null;
}
private static bool IsDebugEnabled()
{
try

View File

@ -0,0 +1,57 @@
// <copyright file="MultipleAppDomainsTests.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 NETFRAMEWORK
using FluentAssertions;
using IntegrationTests.Helpers;
using Xunit.Abstractions;
namespace IntegrationTests;
public class MultipleAppDomainsTests : TestHelper
{
public MultipleAppDomainsTests(ITestOutputHelper output)
: base("MultipleAppDomains.NetFramework", output)
{
}
[Fact]
[Trait("Category", "EndToEnd")]
public void SubmitsTraces()
{
using var collector = new MockSpansCollector(Output);
SetExporter(collector);
const int expectedSpanCount = 5;
for (var i = 0; i < expectedSpanCount; i++)
{
collector.Expect("TestApplication.StrongNamedValidation");
}
// Use the integrations file that bring the expected instrumentation.
var assemblyPath = GetTestAssemblyPath();
var integrationsFile = Path.Combine(assemblyPath, "StrongNamedTestsIntegrations.json");
File.Exists(integrationsFile).Should().BeTrue();
SetEnvironmentVariable("OTEL_DOTNET_AUTO_INTEGRATIONS_FILE", integrationsFile);
var (_, standardErrorOutput) = RunTestApplication();
// Nothing regarding log should have been logged to the console.
standardErrorOutput.Should().NotContain("Log:");
collector.AssertExpectations();
}
}
#endif

View File

@ -0,0 +1,73 @@
// <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.Reflection;
namespace TestApplication.MultipleAppDomains.NetFramework;
using TestLibrary.InstrumentationTarget;
public static class Program
{
public static void Main(string[] args)
{
// Always execute the code to be instrumented.
var command = new Command();
command.Execute();
const string NoAppDomainsSwitch = "--no-app-domains";
if (args?.Length > 0)
{
if (args.Length == 1 && args[0] == NoAppDomainsSwitch)
{
// Nothing else to do, exit.
return;
}
else
{
throw new Exception($"Unrecognized command-line arguments: \"{string.Join(" ", args)}\"");
}
}
#if NETFRAMEWORK
const int numberOfAppDomains = 4;
var appDomains = new AppDomain[numberOfAppDomains];
var tasks = new List<Task>(numberOfAppDomains);
var applicationCodeBase = Assembly.GetExecutingAssembly().CodeBase;
for (var i = 0; i < appDomains.Length; i++)
{
// Use a name that contains characters that can't be used in file names.
appDomains[i] = AppDomain.CreateDomain("|invalid:in:file:name|");
var targetAppDomain = appDomains[i];
tasks.Add(Task.Run(async () =>
{
targetAppDomain.ExecuteAssembly(applicationCodeBase, new string[] { NoAppDomainsSwitch });
// Ensure concurrent non-completed tasks.
await Task.Delay(TimeSpan.FromSeconds(2.5));
}));
}
Task.WaitAll(tasks.ToArray());
for (var i = 0; i < appDomains.Length; i++)
{
AppDomain.Unload(appDomains[i]);
}
#endif
}
}

View File

@ -0,0 +1,7 @@
<Project Sdk="Microsoft.NET.Sdk">
<ItemGroup>
<ProjectReference Include="..\dependency-libs\TestLibrary.InstrumentationTarget\TestLibrary.InstrumentationTarget.csproj" />
</ItemGroup>
</Project>