ILogger integration - part 2 (#1315)

* add log processor

* fix changelog

* macros

* more conditional compilations

* improve struct

* remove duplicated stuff

* remove Sdk.CreateLoggerProviderBuilder

* clean up

* update changelog

Co-authored-by: Cijo Thomas <cithomas@microsoft.com>
This commit is contained in:
Reiley Yang 2020-10-05 10:13:03 -07:00 committed by GitHub
parent 1f04397c26
commit d1a3f53324
No known key found for this signature in database
GPG Key ID: 4AEE18F83AFDEB23
11 changed files with 630 additions and 47 deletions

View File

@ -0,0 +1,85 @@
// <copyright file="MyProcessor.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;
using System.Collections.Generic;
using System.Diagnostics;
using OpenTelemetry;
using OpenTelemetry.Logs;
internal class MyProcessor : LogProcessor
{
private readonly string name;
public MyProcessor(string name = "MyProcessor")
{
this.name = name;
}
public override void OnLog(in LogRecord record)
{
var state = record.State;
if (state is IReadOnlyCollection<KeyValuePair<string, object>> dict)
{
var isUnstructuredLog = dict.Count == 1;
if (isUnstructuredLog)
{
foreach (var entry in dict)
{
Console.WriteLine($"{record.Timestamp:yyyy-MM-ddTHH:mm:ss.fffffffZ} {record.CategoryName}({record.LogLevel}, Id={record.EventId}): {entry.Value}");
}
}
else
{
Console.WriteLine($"{record.Timestamp:yyyy-MM-ddTHH:mm:ss.fffffffZ} {record.CategoryName}({record.LogLevel}, Id={record.EventId}):");
foreach (var entry in dict)
{
if (string.Equals(entry.Key, "{OriginalFormat}", StringComparison.Ordinal))
{
Console.WriteLine($" $format: {entry.Value}");
continue;
}
Console.WriteLine($" {entry.Key}: {entry.Value}");
}
}
if (record.Exception != null)
{
Console.WriteLine($" $exception: {record.Exception}");
}
}
}
protected override bool OnForceFlush(int timeoutMilliseconds)
{
Console.WriteLine($"{this.name}.OnForceFlush({timeoutMilliseconds})");
return true;
}
protected override bool OnShutdown(int timeoutMilliseconds)
{
Console.WriteLine($"{this.name}.OnShutdown({timeoutMilliseconds})");
return true;
}
protected override void Dispose(bool disposing)
{
Console.WriteLine($"{this.name}.Dispose({disposing})");
}
}

View File

@ -15,17 +15,31 @@
// </copyright>
using System.Collections.Generic;
#if NETCOREAPP2_1
using Microsoft.Extensions.DependencyInjection;
#endif
using Microsoft.Extensions.Logging;
using OpenTelemetry;
public class Program
{
public static void Main()
{
#if NETCOREAPP2_1
var serviceCollection = new ServiceCollection().AddLogging(builder =>
#else
using var loggerFactory = LoggerFactory.Create(builder =>
#endif
{
builder.AddOpenTelemetry();
builder.AddOpenTelemetry(options => options.AddProcessor(new MyProcessor()));
});
#if NETCOREAPP2_1
using var serviceProvider = serviceCollection.BuildServiceProvider();
var logger = serviceProvider.GetRequiredService<ILogger<Program>>();
#else
var logger = loggerFactory.CreateLogger<Program>();
#endif
// unstructured log
logger.LogInformation("Hello, World!");

View File

@ -1,6 +1,18 @@
<Project Sdk="Microsoft.NET.Sdk">
<PropertyGroup>
<TargetFramework>netcoreapp3.1</TargetFramework>
</PropertyGroup>
<ItemGroup>
<PackageReference Include="Microsoft.Extensions.Logging" Version="$(MicrosoftExtensionsLoggingPkgVer)" />
<ProjectReference Include="$(RepoRoot)\src\OpenTelemetry\OpenTelemetry.csproj" />
</ItemGroup>
<ItemGroup Condition="'$(TargetFramework)' == 'netcoreapp2.1'">
<PackageReference Include="Microsoft.Extensions.Logging" Version="2.1.1" />
<PackageReference Include="Microsoft.Extensions.DependencyInjection" Version="2.1.1" />
</ItemGroup>
<ItemGroup Condition="'$(TargetFramework)' != 'netcoreapp2.1'">
<PackageReference Include="Microsoft.Extensions.Logging" Version="$(MicrosoftExtensionsLoggingPkgVer)" />
</ItemGroup>
</Project>

View File

@ -2,8 +2,6 @@
## Unreleased
* Added `ILogger`/`Microsoft.Extensions.Logging` integration
([#1308](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1308))
* `IActivityTagEnumerator` is now `IActivityEnumerator<T>`. Added
`EnumerateLinks` extension method on `Activity` for retrieving links
efficiently

View File

@ -10,6 +10,9 @@
* Renamed `SamplingDecision` options (`NotRecord` to `Drop`, `Record` to
`RecordOnly`, and `RecordAndSampled` to `RecordAndSample`)
([#1297](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1297))
* Added `ILogger`/`Microsoft.Extensions.Logging` integration
([#1308](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1308))
([#1315](https://github.com/open-telemetry/opentelemetry-dotnet/pull/1315))
## 0.6.0-beta.1

View File

@ -0,0 +1,191 @@
// <copyright file="CompositeLogProcessor.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 NETSTANDARD2_0
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.Threading;
using OpenTelemetry.Internal;
namespace OpenTelemetry.Logs
{
public class CompositeLogProcessor : LogProcessor
{
private DoublyLinkedListNode<LogProcessor> head;
private DoublyLinkedListNode<LogProcessor> tail;
private bool disposed;
public CompositeLogProcessor(IEnumerable<LogProcessor> processors)
{
if (processors == null)
{
throw new ArgumentNullException(nameof(processors));
}
using var iter = processors.GetEnumerator();
if (!iter.MoveNext())
{
throw new ArgumentException($"{nameof(processors)} collection is empty");
}
this.head = new DoublyLinkedListNode<LogProcessor>(iter.Current);
this.tail = this.head;
while (iter.MoveNext())
{
this.AddProcessor(iter.Current);
}
}
public CompositeLogProcessor AddProcessor(LogProcessor processor)
{
if (processor == null)
{
throw new ArgumentNullException(nameof(processor));
}
var node = new DoublyLinkedListNode<LogProcessor>(processor)
{
Previous = this.tail,
};
this.tail.Next = node;
this.tail = node;
return this;
}
/// <inheritdoc/>
public override void OnLog(in LogRecord record)
{
var cur = this.head;
while (cur != null)
{
cur.Value.OnLog(record);
cur = cur.Next;
}
}
/// <inheritdoc/>
protected override bool OnForceFlush(int timeoutMilliseconds)
{
var cur = this.head;
var sw = Stopwatch.StartNew();
while (cur != null)
{
if (timeoutMilliseconds == Timeout.Infinite)
{
_ = cur.Value.ForceFlush(Timeout.Infinite);
}
else
{
var timeout = (long)timeoutMilliseconds - sw.ElapsedMilliseconds;
if (timeout <= 0)
{
return false;
}
var succeeded = cur.Value.ForceFlush((int)timeout);
if (!succeeded)
{
return false;
}
}
cur = cur.Next;
}
return true;
}
/// <inheritdoc/>
protected override bool OnShutdown(int timeoutMilliseconds)
{
var cur = this.head;
var result = true;
var sw = Stopwatch.StartNew();
while (cur != null)
{
if (timeoutMilliseconds == Timeout.Infinite)
{
result = cur.Value.Shutdown(Timeout.Infinite) && result;
}
else
{
var timeout = (long)timeoutMilliseconds - sw.ElapsedMilliseconds;
// notify all the processors, even if we run overtime
result = cur.Value.Shutdown((int)Math.Max(timeout, 0)) && result;
}
cur = cur.Next;
}
return result;
}
protected override void Dispose(bool disposing)
{
if (this.disposed)
{
return;
}
if (disposing)
{
var cur = this.head;
while (cur != null)
{
try
{
cur.Value?.Dispose();
}
catch (Exception ex)
{
OpenTelemetrySdkEventSource.Log.SpanProcessorException(nameof(this.Dispose), ex);
}
cur = cur.Next;
}
}
this.disposed = true;
}
private class DoublyLinkedListNode<T>
{
public readonly T Value;
public DoublyLinkedListNode(T value)
{
this.Value = value;
}
public DoublyLinkedListNode<T> Previous { get; set; }
public DoublyLinkedListNode<T> Next { get; set; }
}
}
}
#endif

View File

@ -0,0 +1,185 @@
// <copyright file="LogProcessor.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 NETSTANDARD2_0
using System;
using System.Threading;
using OpenTelemetry.Internal;
namespace OpenTelemetry.Logs
{
/// <summary>
/// Log processor base class.
/// </summary>
public abstract class LogProcessor : IDisposable
{
private int shutdownCount;
/// <summary>
/// Called synchronously when a <see cref="LogRecord"/> is recorded.
/// </summary>
/// <param name="record">
/// The log record.
/// </param>
/// <remarks>
/// This function is called synchronously on the thread which generated
/// the log record. This function should be thread-safe, and should not
/// block indefinitely or throw exceptions.
/// </remarks>
public virtual void OnLog(in LogRecord record)
{
}
/// <summary>
/// Flushes the <see cref="LogProcessor"/>, blocks the current
/// thread until flush completed, shutdown signaled or timed out.
/// </summary>
/// <param name="timeoutMilliseconds">
/// The number of milliseconds to wait, or <c>Timeout.Infinite</c> to
/// wait indefinitely.
/// </param>
/// <returns>
/// Returns <c>true</c> when flush succeeded; otherwise, <c>false</c>.
/// </returns>
/// <exception cref="System.ArgumentOutOfRangeException">
/// Thrown when the <c>timeoutMilliseconds</c> is smaller than -1.
/// </exception>
/// <remarks>
/// This function guarantees thread-safety.
/// </remarks>
public bool ForceFlush(int timeoutMilliseconds = Timeout.Infinite)
{
if (timeoutMilliseconds < 0 && timeoutMilliseconds != Timeout.Infinite)
{
throw new ArgumentOutOfRangeException(nameof(timeoutMilliseconds));
}
try
{
return this.OnForceFlush(timeoutMilliseconds);
}
catch (Exception ex)
{
// TODO: replace this with a better internal logging
OpenTelemetrySdkEventSource.Log.SpanProcessorException(nameof(this.ForceFlush), ex);
return false;
}
}
/// <summary>
/// Attempts to shutdown the <see cref="LogProcessor"/>, blocks
/// the current thread until shutdown completed or timed out.
/// </summary>
/// <param name="timeoutMilliseconds">
/// The number of milliseconds to wait, or <c>Timeout.Infinite</c> to
/// wait indefinitely.
/// </param>
/// <returns>
/// Returns <c>true</c> when shutdown succeeded; otherwise, <c>false</c>.
/// </returns>
/// <exception cref="System.ArgumentOutOfRangeException">
/// Thrown when the <c>timeoutMilliseconds</c> is smaller than -1.
/// </exception>
/// <remarks>
/// This function guarantees thread-safety. Only the first call will
/// win, subsequent calls will be no-op.
/// </remarks>
public bool Shutdown(int timeoutMilliseconds = Timeout.Infinite)
{
if (timeoutMilliseconds < 0 && timeoutMilliseconds != Timeout.Infinite)
{
throw new ArgumentOutOfRangeException(nameof(timeoutMilliseconds));
}
if (Interlocked.Increment(ref this.shutdownCount) > 1)
{
return false; // shutdown already called
}
try
{
return this.OnShutdown(timeoutMilliseconds);
}
catch (Exception ex)
{
OpenTelemetrySdkEventSource.Log.SpanProcessorException(nameof(this.Shutdown), ex);
return false;
}
}
/// <inheritdoc/>
public void Dispose()
{
this.Dispose(true);
GC.SuppressFinalize(this);
}
/// <summary>
/// Called by <c>ForceFlush</c>. This function should block the current
/// thread until flush completed, shutdown signaled or timed out.
/// </summary>
/// <param name="timeoutMilliseconds">
/// The number of milliseconds to wait, or <c>Timeout.Infinite</c> to
/// wait indefinitely.
/// </param>
/// <returns>
/// Returns <c>true</c> when flush succeeded; otherwise, <c>false</c>.
/// </returns>
/// <remarks>
/// This function is called synchronously on the thread which called
/// <c>ForceFlush</c>. This function should be thread-safe, and should
/// not throw exceptions.
/// </remarks>
protected virtual bool OnForceFlush(int timeoutMilliseconds)
{
return true;
}
/// <summary>
/// Called by <c>Shutdown</c>. This function should block the current
/// thread until shutdown completed or timed out.
/// </summary>
/// <param name="timeoutMilliseconds">
/// The number of milliseconds to wait, or <c>Timeout.Infinite</c> to
/// wait indefinitely.
/// </param>
/// <returns>
/// Returns <c>true</c> when shutdown succeeded; otherwise, <c>false</c>.
/// </returns>
/// <remarks>
/// This function is called synchronously on the thread which made the
/// first call to <c>Shutdown</c>. This function should not throw
/// exceptions.
/// </remarks>
protected virtual bool OnShutdown(int timeoutMilliseconds)
{
return true;
}
/// <summary>
/// Releases the unmanaged resources used by this class and optionally
/// releases the managed resources.
/// </summary>
/// <param name="disposing">
/// <see langword="true"/> to release both managed and unmanaged resources;
/// <see langword="false"/> to release only unmanaged resources.
/// </param>
protected virtual void Dispose(bool disposing)
{
}
}
}
#endif

View File

@ -0,0 +1,51 @@
// <copyright file="LogRecord.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 NETSTANDARD2_0
using System;
using Microsoft.Extensions.Logging;
namespace OpenTelemetry.Logs
{
/// <summary>
/// Log record base class.
/// </summary>
public readonly struct LogRecord
{
internal LogRecord(DateTime timestamp, string categoryName, LogLevel logLevel, EventId eventId, object state, Exception exception)
{
this.Timestamp = timestamp;
this.CategoryName = categoryName;
this.LogLevel = logLevel;
this.EventId = eventId;
this.State = state;
this.Exception = exception;
}
public DateTime Timestamp { get; }
public string CategoryName { get; }
public LogLevel LogLevel { get; }
public EventId EventId { get; }
public object State { get; }
public Exception Exception { get; }
}
}
#endif

View File

@ -16,7 +16,6 @@
#if NETSTANDARD2_0
using System;
using System.Collections.Generic;
using System.Runtime.InteropServices;
using System.Threading;
using Microsoft.Extensions.Logging;
@ -26,15 +25,12 @@ namespace OpenTelemetry.Logs
internal class OpenTelemetryLogger : ILogger
{
private readonly string categoryName;
private readonly OpenTelemetryLoggerProvider provider;
internal OpenTelemetryLogger(string categoryName, OpenTelemetryLoggerOptions options)
internal OpenTelemetryLogger(string categoryName, OpenTelemetryLoggerProvider provider)
{
this.categoryName = categoryName ?? throw new ArgumentNullException(nameof(categoryName));
if (options == null)
{
throw new ArgumentNullException(nameof(options));
}
this.provider = provider ?? throw new ArgumentNullException(nameof(provider));
}
internal IExternalScopeProvider ScopeProvider { get; set; }
@ -46,40 +42,9 @@ namespace OpenTelemetry.Logs
return;
}
var timestamp = DateTime.UtcNow;
var record = new LogRecord(DateTime.UtcNow, this.categoryName, logLevel, eventId, state, exception);
if (state is IReadOnlyCollection<KeyValuePair<string, object>> dict)
{
var isUnstructuredLog = dict.Count == 1;
// TODO: remove the console output after finished the plumbing work to log processors/exporters
if (isUnstructuredLog)
{
foreach (var entry in dict)
{
Console.WriteLine($"{this.categoryName}({logLevel}, Id={eventId}): {entry.Value}");
}
}
else
{
Console.WriteLine($"{this.categoryName}({logLevel}, Id={eventId}):");
foreach (var entry in dict)
{
if (string.Equals(entry.Key, "{OriginalFormat}", StringComparison.Ordinal))
{
Console.WriteLine($" $format: {entry.Value}");
continue;
}
Console.WriteLine($" {entry.Key}: {entry.Value}");
}
}
if (exception != null)
{
Console.WriteLine($" $exception: {exception}");
}
}
this.provider.Processor?.OnLog(record);
}
public bool IsEnabled(LogLevel logLevel)

View File

@ -15,12 +15,32 @@
// </copyright>
#if NETSTANDARD2_0
using System;
using System.Collections.Generic;
using Microsoft.Extensions.Logging;
namespace OpenTelemetry.Logs
{
public class OpenTelemetryLoggerOptions
{
internal readonly List<LogProcessor> Processors = new List<LogProcessor>();
/// <summary>
/// Adds processor to the options.
/// </summary>
/// <param name="processor">Log processor to add.</param>
/// <returns>Returns <see cref="OpenTelemetryLoggerOptions"/> for chaining.</returns>
public OpenTelemetryLoggerOptions AddProcessor(LogProcessor processor)
{
if (processor == null)
{
throw new ArgumentNullException(nameof(processor));
}
this.Processors.Add(processor);
return this;
}
}
}
#endif

View File

@ -25,14 +25,26 @@ namespace OpenTelemetry.Logs
[ProviderAlias("OpenTelemetry")]
public class OpenTelemetryLoggerProvider : ILoggerProvider, ISupportExternalScope
{
private readonly IOptionsMonitor<OpenTelemetryLoggerOptions> options;
internal LogProcessor Processor;
private readonly OpenTelemetryLoggerOptions options;
private readonly IDictionary<string, ILogger> loggers;
private bool disposed;
private IExternalScopeProvider scopeProvider;
public OpenTelemetryLoggerProvider(IOptionsMonitor<OpenTelemetryLoggerOptions> options)
: this(options.CurrentValue)
{
this.options = options;
}
internal OpenTelemetryLoggerProvider(OpenTelemetryLoggerOptions options)
{
this.options = options ?? throw new ArgumentNullException(nameof(options));
this.loggers = new Dictionary<string, ILogger>(StringComparer.Ordinal);
foreach (var processor in options.Processors)
{
this.AddProcessor(processor);
}
}
internal IExternalScopeProvider ScopeProvider
@ -65,14 +77,61 @@ namespace OpenTelemetry.Logs
return logger;
}
logger = new OpenTelemetryLogger(categoryName, this.options.CurrentValue);
logger = new OpenTelemetryLogger(categoryName, this);
this.loggers.Add(categoryName, logger);
return logger;
}
}
/// <inheritdoc/>
public void Dispose()
{
this.Dispose(true);
GC.SuppressFinalize(this);
}
internal OpenTelemetryLoggerProvider AddProcessor(LogProcessor processor)
{
if (processor == null)
{
throw new ArgumentNullException(nameof(processor));
}
if (this.Processor == null)
{
this.Processor = processor;
}
else if (this.Processor is CompositeLogProcessor compositeProcessor)
{
compositeProcessor.AddProcessor(processor);
}
else
{
this.Processor = new CompositeLogProcessor(new[]
{
this.Processor,
processor,
});
}
return this;
}
protected void Dispose(bool disposing)
{
if (this.disposed)
{
return;
}
if (disposing)
{
// Wait for up to 5 seconds grace period
this.Processor?.Shutdown(5000);
this.Processor?.Dispose();
}
this.disposed = true;
}
}
}