로그 강화에 대한 심층 분석

이 기사에서는 로깅 문제와 코드를 인프라 및 비즈니스 코드에서 분리하고 분리하는 방법을 검토하는 것으로 마무리하겠습니다. 이전 기사 에서는 인프라 운영을 위해 DiagnosticSource 및 DiagnosticListener를 사용하여 이를 달성하는 방법을 검토했습니다.

이제 추가 컨텍스트를 사용하여 기록된 데이터를 강화하는 방법을 검토하겠습니다.

기본적으로 기록된 데이터를 강화하는 개념은 로그 메시지와 함께 사용해야 하는 추가 컨텍스트 또는 데이터 등록을 중심으로 이루어집니다. 이 컨텍스트는 간단한 문자열부터 복잡한 개체까지 무엇이든 될 수 있으며, 로그 메시지가 기록되는 순간이 아니라 인프라 또는 비즈니스 코드 내에서 특정 순간에 생성되거나 알려집니다.

따라서 이 코드는 로깅 출력을 생성하지 않거나 실행 체인에 따라 생성되거나 생성되지 않을 수 있는 여러 로그 메시지에 컨텍스트를 연결하기를 원하기 때문에 로그 메시지에 다른 속성을 간단히 추가할 수는 없습니다.

이 컨텍스트는 조건부일 수도 있습니다. 예를 들어 다른 모든 메시지에는 필요하지 않지만 오류 로그 메시지에만 특정 데이터를 추가하는 것과 같습니다.

Serilog는 매우 유연하고 강력하므로 Serilog와 그 강화 기능을 사용할 것입니다. 다른 솔루션도 다양한 성숙도 수준에서 비슷한 기능을 갖고 있으므로 Serilog의 강화 기능과 Microsoft.Extensions.Logging이 기본적으로 제공하는 기능을 비교해 보겠습니다.

Serilog용 기존 Log Enrichers 개요

Serilog에는 일부 시나리오에 매우 유용할 수 있는 유용한 강화 기능이 많이 포함되어 있습니다. 이 페이지( https://github.com/serilog/serilog/wiki/Enrichment )를 방문하면 전체 강화 장치 목록과 해당 설명을 볼 수 있습니다.

예를 들어, 일치하는 범위 내에서 기록되는 경우 로그 메시지와 함께 기록되도록 추가 데이터를 푸시할 수 있는 LogContext 및 GlobalLogContext 보강자가 있습니다.

LogContext 보강자는 Microsoft.Extensions.Logging의 로깅 범위 개념과 매우 유사합니다. 기본적으로 둘 다 일부 사용자 지정 데이터를 푸시하고 로그 컨텍스트에서 데이터를 제거하기 위해 삭제해야 하는 IDisposable 개체를 제공합니다.

즉, IDisposable 개체가 범위 내에 있는 한 해당 범위 내에 기록된 모든 로그 메시지에 데이터가 첨부됩니다. 폐기되면 데이터는 더 이상 첨부되지 않습니다.

Serilog 및 Microsoft 설명서는 다음 예를 제공합니다.

 // For Serilog log.Information("No contextual properties"); using (LogContext.PushProperty("A", 1)) { log.Information("Carries property A = 1"); using (LogContext.PushProperty("A", 2)) using (LogContext.PushProperty("B", 1)) { log.Information("Carries A = 2 and B = 1"); } log.Information("Carries property A = 1, again"); } // For Microsoft.Extensions.Logging scopes using (logger.BeginScope(new List<KeyValuePair<string, object>> { new KeyValuePair<string, object>("TransactionId", transactionId), })) { _logger.LogInformation(MyLogEvents.GetItem, "Getting item {Id}", id); todoItem = await _context.TodoItems.FindAsync(id); if (todoItem == null) { _logger.LogWarning(MyLogEvents.GetItemNotFound, "Get({Id}) NOT FOUND", id); return NotFound(); } }

일부 시나리오에서는 유용하지만 상당히 제한적입니다. 이러한 유형의 로그 강화에 대한 가장 좋은 사용법은 범위가 잘 정의되어 있고 범위 생성 순간에 데이터가 알려져 있으며 데이터가 외부 가치가 없다고 확신하는 미들웨어 또는 데코레이터 유형 구현에서입니다. 범위.

예를 들어 이를 사용하여 단일 HTTP 요청 처리 범위 내의 모든 로그 메시지에 상관 관계 ID를 첨부할 수 있습니다.

GlobalLogContext 보강자는 LogContext와 유사하지만 전역적입니다. 즉, 애플리케이션 내에 작성된 모든 로그 메시지에 데이터를 푸시합니다. 그러나 이러한 유형의 강화에 대한 실제 사용 사례는 매우 제한적입니다.

Serilog용 사용자 정의 로그 강화 샘플

실제로 Serilog에 대한 사용자 정의 로그 보강기를 구현하는 것은 매우 쉽습니다. ILogEventEnricher 인터페이스를 구현하고 로거 구성에 보강기를 등록하기만 하면 됩니다. 인터페이스에는 로그 이벤트를 승인하고 원하는 데이터로 강화하는 Enrich 한 가지 메소드만 구현할 수 있습니다.

사용자 정의 로그 보강기에 대한 샘플 구현을 검토해 보겠습니다.

 public sealed class CustomLogEnricher : ILogEventEnricher { private readonly IHttpContextAccessor contextAccessor; public CustomLogEnricher(IHttpContextAccessor contextAccessor) { this.contextAccessor = contextAccessor; } public void Enrich(LogEvent logEvent, ILogEventPropertyFactory propertyFactory) { var source = contextAccessor.HttpContext?.RequestServices.GetService<ICustomLogEnricherSource>(); if (source is null) { return; } var loggedProperties = source.GetCustomProperties(logEvent.Level); foreach (var item in loggedProperties) { var property = item.ProduceProperty(propertyFactory); logEvent.AddOrUpdateProperty(property); } } }

보시다시피 이 강화 도구는 ICustomLogEnricherSource 사용하여 로그 이벤트를 강화하는 데 사용할 사용자 정의 속성을 가져옵니다. 일반적으로 로그 보강자는 수명이 긴 인스턴스이며 싱글톤 패턴도 따릅니다. 즉, 애플리케이션 시작 시 한 번 등록되고 전체 애플리케이션 수명 동안 지속됩니다.

따라서 사용자 지정 속성의 소스에서 보강기를 분리해야 하며 소스는 수명이 제한된 범위 인스턴스일 수 있습니다.

 public sealed class CustomLogEnricherSource : ICustomLogEnricherSource { private readonly Dictionary<string, CustomLogEventProperty> properties = new(); public ICustomLogEnricherSource With<T>(string property, T? value, LogEventLevel logLevel) where T : class { if (value is null) { return this; } properties[property] = new CustomLogEventProperty(property, value, logLevel); return this; } public void Remove(string property) { properties.Remove(property); } public IEnumerable<CustomLogEventProperty> GetCustomProperties(LogEventLevel logLevel) { foreach (var item in properties.Values) { if (item.Level <= logLevel) { yield return item; } } } } // And CustomLogEventProperty is a simple struct (you can make it a class, too): public struct CustomLogEventProperty { private LogEventProperty? propertyValue; public CustomLogEventProperty(string property, object value, LogEventLevel level) { Name = property; Value = value; Level = level; } public string Name { get; } public object Value { get; } public LogEventLevel Level { get; } public LogEventProperty ProduceProperty(ILogEventPropertyFactory propertyFactory) { propertyValue ??= propertyFactory.CreateProperty(Name, Value, destructureObjects: true); return propertyValue; } }

이 구현에는 몇 가지 간단한 세부정보가 있습니다.

• 보강자는 이러한 구성 요소의 다양한 수명과 다양한 책임을 설명하기 위해 로그 메시지의 사용자 지정 속성 소스에서 분리됩니다. 필요한 경우 다양한 애플리케이션 구성 요소가 다양한 사용자 지정 속성을 생성할 수 있으므로 ICustomLogEnricherSource 인스턴스 목록을 사용하여 보강기를 만들 수 있습니다.

• 사용자 정의 속성으로 로그 메시지를 강화해야 하는 모든 구성 요소에 소스( ICustomLogEnricherSource )를 삽입할 수 있습니다. 이상적으로는 사용자 지정 속성을 만료하는 편리한 방법을 제공하지 않으므로 범위가 지정된 인스턴스여야 합니다.

• 보강기와 소스는 로그 메시지의 로그 수준을 기반으로 간단한 필터링 논리를 구현합니다. 그러나 논리는 훨씬 더 복잡할 수 있으며 다른 LogEvent 속성이나 애플리케이션 상태에 의존할 수도 있습니다.

• CustomLogEventProperty 생성된 LogEventProperty 인스턴스를 캐시하여 여러 로그 메시지에 첨부될 수 있으므로 동일한 사용자 정의 속성에 대해 여러 번 생성되는 것을 방지합니다.

또 다른 중요한 세부 사항은 다음 코드 줄인 destructureObjects 매개 변수에 있습니다.

 propertyFactory.CreateProperty(Name, Value, destructureObjects: true);

복잡한 개체(클래스, 레코드, 구조체, 컬렉션 등)를 연결하고 이 매개변수가 true 로 설정되지 않은 경우 Serilog는 개체에 대해 ToString 호출하고 결과를 로그 메시지에 첨부합니다. 레코드에는 모든 공용 속성을 출력하는 ToString 구현이 있고 클래스 및 구조체에 대해 ToString 재정의할 수 있지만 항상 그런 것은 아닙니다.

또한 이러한 출력은 단순한 문자열이기 때문에 구조화된 로깅에 적합하지 않으며 연결된 개체의 속성을 기반으로 로그 메시지를 검색하고 필터링할 수 없습니다. 따라서 여기서는 이 매개변수를 true 로 설정합니다. 단순 유형(값 유형 및 문자열)은 이 매개변수의 어느 값과도 잘 작동합니다.

이 구현의 또 다른 이점은 사용자 정의 속성이 소스에 등록되면 해당 속성이 제거되거나 소스가 삭제될 때까지 모든 로그 메시지에 대해 그대로 유지된다는 점입니다(범위가 지정된 인스턴스여야 함을 기억하세요). 일부 구현에는 사용자 정의 속성의 수명에 대한 더 나은 제어가 필요할 수 있으며 이는 다양한 방법으로 달성할 수 있습니다.

예를 들어 특정 CustomLogEventProperty 구현을 제공하거나 사용자 정의 속성을 제거해야 하는지 확인하는 콜백을 제공합니다.

이 만료 논리는 GetCustomProperties 메서드에서 사용되어 사용자 지정 속성을 사전 확인하고 만료된 경우 소스에서 제거할 수 있습니다.

이것이 비즈니스 및 인프라 코드에서 로깅 문제를 분리하는 데 어떻게 도움이 됩니까?

글쎄, 이상적으로는 로깅 문제를 비즈니스 및 인프라 코드와 혼합하고 싶지 않습니다. 이는 로깅 관련 코드로 비즈니스 및 인프라 코드를 '래핑'할 수 있는 다양한 데코레이터, 미들웨어 및 기타 패턴을 사용하여 달성할 수 있습니다.

그러나 이것이 항상 가능한 것은 아니며 때로는 ICustomLogEnricherSource 와 같은 중간 추상화를 비즈니스 및 인프라 코드에 삽입하고 로깅을 위해 사용자 지정 데이터를 등록하는 것이 더 편리할 수 있습니다.

이런 방식으로 비즈니스 및 인프라 코드는 실제 로깅에 대해 아무것도 알 필요가 없지만 일부 로깅 인식 코드 조각과 혼합됩니다.

어쨌든, 이 코드는 훨씬 덜 결합되고 훨씬 더 테스트 가능합니다. 일부 매우 핫한 경로 시나리오에 대해 성능과 메모리를 전혀 차지하지 않는 무작동 구현을 위해 NullLogEnricherSource 와 같은 기능을 도입할 수도 있습니다.

성능 고려 사항

마이크로소프트가 말했듯이,

로깅은 매우 빨라서 비동기 코드의 성능 비용을 감당할 가치가 없어야 합니다.

따라서 추가 컨텍스트로 로그 메시지를 강화할 때마다 성능에 미치는 영향을 인식해야 합니다. 일반적으로 Serilog 로그 강화 구현은 매우 빠르며 최소한 Microsoft 로깅 범위와 동등하지만 더 많은 데이터를 첨부하면 로그 메시지를 생성하는 데 더 많은 시간이 걸립니다.

더 많은 사용자 정의 속성을 첨부할수록 그 중에는 더 복잡한 개체가 포함되며 로그 메시지를 생성하는 데 더 많은 시간과 메모리가 소요됩니다. 따라서 개발자는 로그 메시지에 어떤 데이터를 첨부할지, 언제 첨부할지, 수명은 어떻게 될지에 대해 매우 신중하게 생각해야 합니다.

다음은 Serilog 로그 보강 및 Microsoft 로깅 범위 모두에 대한 성능 및 메모리 소비를 보여주는 작은 벤치마크 결과 표입니다. 각 벤치마크 방법은 사용자 정의 속성으로 강화하는 다양한 방법으로 20개의 로그 메시지를 생성합니다.

사용자 정의 속성이 첨부되지 않았습니다.

 | Method | Mean | Error | StdDev | Gen0 | Allocated | | SerilogLoggingNoEnrichment | 74.22 us | 1.194 us | 1.116 us | 1.2207 | 21.25 KB | | MicrosoftLoggingNoEnrichment | 72.58 us | 0.733 us | 0.685 us | 1.2207 | 21.25 KB |

각 로그 메시지에는 세 개의 문자열이 첨부되어 있습니다.

 | Method | Mean | Error | StdDev | Gen0 | Allocated | | SerilogLoggingWithContext | 77.47 us | 0.551 us | 0.516 us | 1.7090 | 28.6 KB | | SerilogLoggingWithEnrichment | 79.89 us | 1.482 us | 2.028 us | 1.7090 | 29.75 KB | | MicrosoftLoggingWithEnrichment | 81.86 us | 1.209 us | 1.131 us | 1.8311 | 31.22 KB |

각 로그 메시지에는 세 개의 복잡한 개체(레코드)가 첨부되어 있습니다.

 | Method | Mean | Error | StdDev | Gen0 | Allocated | | SerilogLoggingWithObjectContext | 108.49 us | 1.193 us | 1.058 us | 5.3711 | 88.18 KB | | SerilogLoggingWithObjectEnrichment | 106.07 us | 0.489 us | 0.409 us | 5.3711 | 89.33 KB | | MicrosoftLoggingWithObjectEnrichment | 99.63 us | 1.655 us | 1.468 us | 6.1035 | 100.28 KB |The

Serilog*Context 메서드는 LogContext.PushProperty 사용하고, Serilog*Enrichment 메서드는 문서에 제공된 사용자 지정 강화 및 소스 구현을 사용하는 반면, Microsoft* 메서드는 로깅 범위를 사용합니다.

대부분의 경우 성능과 메모리 소비가 매우 유사하며 복잡한 개체로 보강하는 것이 간단한 유형으로 보강하는 것보다 비용이 더 많이 든다는 것을 알 수 있습니다. 유일한 예외는 로그 메시지에 레코드를 첨부할 때 Microsoft 구현으로 로깅하는 것입니다.

이는 로깅 범위가 복잡한 개체를 분해하지 않고 로그 메시지에 첨부할 때 직렬화를 위해 ToString 메서드를 사용하기 때문입니다. 이로 인해 Microsoft 구현이 약간 더 빨라지지만 더 많은 메모리를 소비합니다.

기본 ToString 구현과 함께 클래스를 사용하면 메모리 소비는 훨씬 줄어들지만 이러한 사용자 정의 개체는 정규화된 유형 이름으로 기록되므로 전혀 쓸모가 없습니다.

그리고 어떤 경우에도 Microsoft 구현을 사용하여 이러한 개체의 속성을 기반으로 로그 메시지를 검색하고 필터링할 수 없습니다. 왜냐하면 개체를 구조화하지 않기 때문입니다.

따라서 이는 우리가 알아야 할 Microsoft 로깅 범위의 제한 사항입니다. 단순 유형은 잘 기록되고 검색 및 필터링이 가능하지만 복잡한 개체는 구조 분해할 수 없습니다.

참고: 이 기사의 벤치마크 소스 코드와 코드 샘플은 GitHub 저장소 에서 찾을 수 있습니다.

결론

적절한 로그 강화는 코드 개발 및 유지 관리를 위한 '삶의 질 향상'입니다. 이를 통해 로그 메시지 생성 시 알려지지 않은 로그 메시지에 추가 컨텍스트를 첨부할 수 있습니다.

이 컨텍스트는 간단한 문자열부터 복잡한 객체까지 무엇이든 될 수 있으며, 인프라 또는 비즈니스 코드 내에서 특정 시점에 생성되거나 알려집니다.

이는 인프라 및 비즈니스 코드에서 로깅 및 관찰 가능성 코드를 분리하고 코드를 보다 유지 관리, 테스트 및 읽기 쉽게 만드는 방법입니다.

참고자료

• Serilog 로그 강화 - https://github.com/serilog/serilog/wiki/Enrichment
• Microsoft 로깅 범위 - https://learn.microsoft.com/en-us/aspnet/core/fundamentals/logging/?view=aspnetcore-8.0#log-scopes
• 이 기사의 코드 샘플 - https://github.com/dmitry-slabko/log-enrichment-pub