From 06cd5891ca36aa01fcff800b8e0caabc22144078 Mon Sep 17 00:00:00 2001 From: hippy Date: Tue, 16 Apr 2024 22:38:40 -0700 Subject: [PATCH] dh: Add ServicePointOnExceptionLogging handler --- .../ServicePointLoggingHandler.cs | 37 +----------- .../ServicePointOnExceptionLoggingHandler.cs | 45 ++++++++++++++ .../misc/ServicePointHelpers.cs | 46 ++++++++++++++ ...vicePointOnExceptionLoggingHandlerTests.cs | 60 +++++++++++++++++++ 4 files changed, 152 insertions(+), 36 deletions(-) create mode 100644 src/rm.DelegatingHandlers/ServicePointOnExceptionLoggingHandler.cs create mode 100644 src/rm.DelegatingHandlers/misc/ServicePointHelpers.cs create mode 100644 tests/rm.DelegatingHandlersTest/ServicePointOnExceptionLoggingHandlerTests.cs diff --git a/src/rm.DelegatingHandlers/ServicePointLoggingHandler.cs b/src/rm.DelegatingHandlers/ServicePointLoggingHandler.cs index b93b1fc..2400780 100644 --- a/src/rm.DelegatingHandlers/ServicePointLoggingHandler.cs +++ b/src/rm.DelegatingHandlers/ServicePointLoggingHandler.cs @@ -4,8 +4,6 @@ using System.Threading; using System.Threading.Tasks; using Serilog; -using Serilog.Core; -using Serilog.Core.Enrichers; namespace rm.DelegatingHandlers; @@ -36,40 +34,7 @@ protected override async Task SendAsync( finally { var servicePoint = ServicePointManager.FindServicePoint(request.RequestUri); - - var props = - new ILogEventEnricher[] - { - // global - new PropertyEnricher("CheckCertificateRevocationList", ServicePointManager.CheckCertificateRevocationList), - new PropertyEnricher("DefaultConnectionLimit", ServicePointManager.DefaultConnectionLimit), - new PropertyEnricher("DefaultNonPersistentConnectionLimit", ServicePointManager.DefaultNonPersistentConnectionLimit), - new PropertyEnricher("DefaultPersistentConnectionLimit", ServicePointManager.DefaultPersistentConnectionLimit), - new PropertyEnricher("DnsRefreshTimeout", ServicePointManager.DnsRefreshTimeout), - new PropertyEnricher("EnableDnsRoundRobin", ServicePointManager.EnableDnsRoundRobin), - new PropertyEnricher("EncryptionPolicy", ServicePointManager.EncryptionPolicy), - new PropertyEnricher("Expect100Continue", ServicePointManager.Expect100Continue), - new PropertyEnricher("MaxServicePointIdleTime", ServicePointManager.MaxServicePointIdleTime), - new PropertyEnricher("MaxServicePoints", ServicePointManager.MaxServicePoints), - new PropertyEnricher("ReusePort", ServicePointManager.ReusePort), - new PropertyEnricher("SecurityProtocol", ServicePointManager.SecurityProtocol), - new PropertyEnricher("UseNagleAlgorithm", ServicePointManager.UseNagleAlgorithm), - - // servicePoint - new PropertyEnricher("host.Key", $"{servicePoint.Address.Scheme}://{servicePoint.Address.Host}"), - new PropertyEnricher("host.Address", servicePoint.Address), - new PropertyEnricher("host.ConnectionName", servicePoint.ConnectionName), - new PropertyEnricher("host.ProtocolVersion", servicePoint.ProtocolVersion), - new PropertyEnricher("host.Expect100Continue", servicePoint.Expect100Continue), - new PropertyEnricher("host.UseNagleAlgorithm", servicePoint.UseNagleAlgorithm), - new PropertyEnricher("host.SupportsPipelining", servicePoint.SupportsPipelining), - new PropertyEnricher("host.ConnectionLimit", servicePoint.ConnectionLimit), - new PropertyEnricher("host.CurrentConnections", servicePoint.CurrentConnections), - new PropertyEnricher("host.ConnectionLeaseTimeout", servicePoint.ConnectionLeaseTimeout), - new PropertyEnricher("host.IdleSince", servicePoint.IdleSince), - new PropertyEnricher("host.MaxIdleTime", servicePoint.MaxIdleTime), - new PropertyEnricher("host.ReceiveBufferSize", servicePoint.ReceiveBufferSize), - }; + var props = ServicePointHelpers.GetServicePointEnrichers(servicePoint); logger.ForContext(props) .Information("ServicePoint stats"); diff --git a/src/rm.DelegatingHandlers/ServicePointOnExceptionLoggingHandler.cs b/src/rm.DelegatingHandlers/ServicePointOnExceptionLoggingHandler.cs new file mode 100644 index 0000000..d3e48c8 --- /dev/null +++ b/src/rm.DelegatingHandlers/ServicePointOnExceptionLoggingHandler.cs @@ -0,0 +1,45 @@ +using System; +using System.Net; +using System.Net.Http; +using System.Threading; +using System.Threading.Tasks; +using Serilog; + +namespace rm.DelegatingHandlers; + +/// +/// Logs stats for with exception. +/// +public class ServicePointOnExceptionLoggingHandler : DelegatingHandler +{ + private readonly ILogger logger; + + /// + public ServicePointOnExceptionLoggingHandler( + ILogger logger) + { + this.logger = logger?.ForContext(GetType()) + ?? throw new ArgumentNullException(nameof(logger)); + } + + protected override async Task SendAsync( + HttpRequestMessage request, + CancellationToken cancellationToken) + { + try + { + return await base.SendAsync(request, cancellationToken) + .ConfigureAwait(false); + } + catch (Exception ex) + { + var servicePoint = ServicePointManager.FindServicePoint(request.RequestUri); + var props = ServicePointHelpers.GetServicePointEnrichers(servicePoint); + + logger.ForContext(props) + .Error(ex, "ServicePoint stats"); + + throw; + } + } +} diff --git a/src/rm.DelegatingHandlers/misc/ServicePointHelpers.cs b/src/rm.DelegatingHandlers/misc/ServicePointHelpers.cs new file mode 100644 index 0000000..bdd753d --- /dev/null +++ b/src/rm.DelegatingHandlers/misc/ServicePointHelpers.cs @@ -0,0 +1,46 @@ +using System.Net; +using Serilog.Core; +using Serilog.Core.Enrichers; + +namespace rm.DelegatingHandlers; + +public static class ServicePointHelpers +{ + public static ILogEventEnricher[] GetServicePointEnrichers(ServicePoint servicePoint) + { + return + new[] + { + // global + new PropertyEnricher("CheckCertificateRevocationList", ServicePointManager.CheckCertificateRevocationList), + new PropertyEnricher("DefaultConnectionLimit", ServicePointManager.DefaultConnectionLimit), + new PropertyEnricher("DefaultNonPersistentConnectionLimit", ServicePointManager.DefaultNonPersistentConnectionLimit), + new PropertyEnricher("DefaultPersistentConnectionLimit", ServicePointManager.DefaultPersistentConnectionLimit), + new PropertyEnricher("DnsRefreshTimeout", ServicePointManager.DnsRefreshTimeout), + new PropertyEnricher("EnableDnsRoundRobin", ServicePointManager.EnableDnsRoundRobin), + new PropertyEnricher("EncryptionPolicy", ServicePointManager.EncryptionPolicy), + new PropertyEnricher("Expect100Continue", ServicePointManager.Expect100Continue), + new PropertyEnricher("MaxServicePointIdleTime", ServicePointManager.MaxServicePointIdleTime), + new PropertyEnricher("MaxServicePoints", ServicePointManager.MaxServicePoints), + new PropertyEnricher("ReusePort", ServicePointManager.ReusePort), + new PropertyEnricher("SecurityProtocol", ServicePointManager.SecurityProtocol), + new PropertyEnricher("UseNagleAlgorithm", ServicePointManager.UseNagleAlgorithm), + + // servicePoint + // see https://stackoverflow.com/questions/75168666/should-i-pass-the-full-url-or-just-the-domain-to-servicepointmanager-findservice + new PropertyEnricher("host.Key", $"{servicePoint.Address.Scheme}://{servicePoint.Address.DnsSafeHost}"), + new PropertyEnricher("host.Address", servicePoint.Address), + new PropertyEnricher("host.ConnectionName", servicePoint.ConnectionName), + new PropertyEnricher("host.ProtocolVersion", servicePoint.ProtocolVersion), + new PropertyEnricher("host.Expect100Continue", servicePoint.Expect100Continue), + new PropertyEnricher("host.UseNagleAlgorithm", servicePoint.UseNagleAlgorithm), + new PropertyEnricher("host.SupportsPipelining", servicePoint.SupportsPipelining), + new PropertyEnricher("host.ConnectionLimit", servicePoint.ConnectionLimit), + new PropertyEnricher("host.CurrentConnections", servicePoint.CurrentConnections), + new PropertyEnricher("host.ConnectionLeaseTimeout", servicePoint.ConnectionLeaseTimeout), + new PropertyEnricher("host.IdleSince", servicePoint.IdleSince), + new PropertyEnricher("host.MaxIdleTime", servicePoint.MaxIdleTime), + new PropertyEnricher("host.ReceiveBufferSize", servicePoint.ReceiveBufferSize), + }; + } +} diff --git a/tests/rm.DelegatingHandlersTest/ServicePointOnExceptionLoggingHandlerTests.cs b/tests/rm.DelegatingHandlersTest/ServicePointOnExceptionLoggingHandlerTests.cs new file mode 100644 index 0000000..ce55208 --- /dev/null +++ b/tests/rm.DelegatingHandlersTest/ServicePointOnExceptionLoggingHandlerTests.cs @@ -0,0 +1,60 @@ +using System.Net.Http; +using AutoFixture; +using AutoFixture.AutoMoq; +using Moq; +using NUnit.Framework; +using rm.DelegatingHandlers; +using Serilog; +using Serilog.Core; + +namespace rm.DelegatingHandlersTest; + +[TestFixture] +public class ServicePointOnExceptionLoggingHandlerTests +{ + [Test] + public async Task Does_Not_Log_ServicePoint_Stats() + { + var fixture = new Fixture().Customize(new AutoMoqCustomization()); + + var loggerMock = fixture.Freeze>(); + loggerMock.Setup(x => x.ForContext(It.IsAny())).Returns(loggerMock.Object); + loggerMock.Setup(x => x.ForContext(It.IsAny>())).Returns(loggerMock.Object); + var servicePointOnExceptionLoggingHandler = new ServicePointOnExceptionLoggingHandler(loggerMock.Object); + + using var invoker = HttpMessageInvokerFactory.Create( + fixture.Create(), servicePointOnExceptionLoggingHandler); + + using var requestMessage = fixture.Create(); + using var _ = await invoker.SendAsync(requestMessage, CancellationToken.None); + + loggerMock.Verify((x) => + x.Error(It.IsAny()), + Times.Never); + } + + [Test] + public void Logs_ServicePoint_Stats_During_Exception() + { + var fixture = new Fixture().Customize(new AutoMoqCustomization()); + + var loggerMock = fixture.Freeze>(); + loggerMock.Setup(x => x.ForContext(It.IsAny())).Returns(loggerMock.Object); + loggerMock.Setup(x => x.ForContext(It.IsAny>())).Returns(loggerMock.Object); + var servicePointOnExceptionLoggingHandler = new ServicePointOnExceptionLoggingHandler(loggerMock.Object); + var throwingHandler = new ThrowingHandler(new TurnDownForWhatException()); + + using var invoker = HttpMessageInvokerFactory.Create( + fixture.Create(), servicePointOnExceptionLoggingHandler, throwingHandler); + + using var requestMessage = fixture.Create(); + var ex = Assert.ThrowsAsync(async () => + { + using var _ = await invoker.SendAsync(requestMessage, CancellationToken.None); + }); + + loggerMock.Verify((x) => + x.Error(ex, "ServicePoint stats"), + Times.Once); + } +}