diff --git a/src/Grpc.AspNetCore.Server/Internal/GrpcEventSource.cs b/src/Grpc.AspNetCore.Server/Internal/GrpcEventSource.cs index dfe4ae248..c06a1bc9c 100644 --- a/src/Grpc.AspNetCore.Server/Internal/GrpcEventSource.cs +++ b/src/Grpc.AspNetCore.Server/Internal/GrpcEventSource.cs @@ -16,13 +16,14 @@ #endregion +using System.Diagnostics; using System.Diagnostics.Tracing; using System.Runtime.CompilerServices; using Grpc.Core; namespace Grpc.AspNetCore.Server.Internal; -internal class GrpcEventSource : EventSource +internal sealed class GrpcEventSource : EventSource { public static readonly GrpcEventSource Log = new GrpcEventSource(); @@ -68,6 +69,8 @@ internal GrpcEventSource(string eventSourceName) [Event(eventId: 1, Level = EventLevel.Verbose)] public void CallStart(string method) { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _totalCalls); Interlocked.Increment(ref _currentCalls); @@ -78,6 +81,8 @@ public void CallStart(string method) [Event(eventId: 2, Level = EventLevel.Verbose)] public void CallStop() { + AssertEventSourceEnabled(); + Interlocked.Decrement(ref _currentCalls); WriteEvent(2); @@ -87,6 +92,8 @@ public void CallStop() [Event(eventId: 3, Level = EventLevel.Error)] public void CallFailed(StatusCode statusCode) { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _callsFailed); WriteEvent(3, (int)statusCode); @@ -96,6 +103,8 @@ public void CallFailed(StatusCode statusCode) [Event(eventId: 4, Level = EventLevel.Error)] public void CallDeadlineExceeded() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _callsDeadlineExceeded); WriteEvent(4); @@ -105,6 +114,8 @@ public void CallDeadlineExceeded() [Event(eventId: 5, Level = EventLevel.Verbose)] public void MessageSent() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _messageSent); WriteEvent(5); @@ -114,6 +125,8 @@ public void MessageSent() [Event(eventId: 6, Level = EventLevel.Verbose)] public void MessageReceived() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _messageReceived); WriteEvent(6); @@ -123,11 +136,20 @@ public void MessageReceived() [Event(eventId: 7, Level = EventLevel.Verbose)] public void CallUnimplemented(string method) { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _callsUnimplemented); WriteEvent(7, method); } + [Conditional("DEBUG")] + [NonEvent] + private void AssertEventSourceEnabled() + { + Debug.Assert(IsEnabled(), "Event source should be enabled."); + } + protected override void OnEventCommand(EventCommandEventArgs command) { if (command.Command == EventCommand.Enable) diff --git a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs index 8a1c65de6..9af4990d0 100644 --- a/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs +++ b/src/Grpc.AspNetCore.Server/Internal/HttpContextServerCallContext.cs @@ -297,9 +297,15 @@ private void LogCallEnd() } if (_status.StatusCode != StatusCode.OK) { - GrpcEventSource.Log.CallFailed(_status.StatusCode); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallFailed(_status.StatusCode); + } + } + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallStop(); } - GrpcEventSource.Log.CallStop(); } protected override WriteOptions? WriteOptionsCore { get; set; } @@ -379,7 +385,10 @@ public void Initialize(ISystemClock? clock = null) _activity.AddTag(GrpcServerConstants.ActivityMethodTag, MethodCore); } - GrpcEventSource.Log.CallStart(MethodCore); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallStart(MethodCore); + } var timeout = GetTimeout(); @@ -459,7 +468,10 @@ private TimeSpan GetTimeout() internal async Task DeadlineExceededAsync() { GrpcServerLog.DeadlineExceeded(Logger, GetTimeout()); - GrpcEventSource.Log.CallDeadlineExceeded(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallDeadlineExceeded(); + } var status = new Status(StatusCode.DeadlineExceeded, "Deadline Exceeded"); diff --git a/src/Grpc.AspNetCore.Server/Internal/PipeExtensions.cs b/src/Grpc.AspNetCore.Server/Internal/PipeExtensions.cs index 028d32881..977f31202 100644 --- a/src/Grpc.AspNetCore.Server/Internal/PipeExtensions.cs +++ b/src/Grpc.AspNetCore.Server/Internal/PipeExtensions.cs @@ -65,7 +65,10 @@ public static async Task WriteSingleMessageAsync(this PipeWriter pipe serializer(response, serializationContext); GrpcServerLog.MessageSent(serverCallContext.Logger); - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } } catch (Exception ex) { @@ -112,7 +115,10 @@ public static async Task WriteStreamedMessageAsync(this PipeWriter pi } GrpcServerLog.MessageSent(serverCallContext.Logger); - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } } catch (Exception ex) { @@ -226,8 +232,10 @@ public static async ValueTask ReadSingleMessageAsync(this PipeReader input serverCallContext.DeserializationContext.SetPayload(null); GrpcServerLog.ReceivedMessage(logger); - - GrpcEventSource.Log.MessageReceived(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageReceived(); + } // Store the request // Need to verify the request completes with no additional data @@ -318,8 +326,10 @@ public static async ValueTask ReadSingleMessageAsync(this PipeReader input serverCallContext.DeserializationContext.SetPayload(null); GrpcServerLog.ReceivedMessage(logger); - - GrpcEventSource.Log.MessageReceived(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageReceived(); + } return request; } diff --git a/src/Grpc.AspNetCore.Server/Internal/ServerCallHandlerFactory.cs b/src/Grpc.AspNetCore.Server/Internal/ServerCallHandlerFactory.cs index efc9317ac..c1426dd18 100644 --- a/src/Grpc.AspNetCore.Server/Internal/ServerCallHandlerFactory.cs +++ b/src/Grpc.AspNetCore.Server/Internal/ServerCallHandlerFactory.cs @@ -118,8 +118,10 @@ public RequestDelegate CreateUnimplementedMethod() var unimplementedMethod = httpContext.Request.RouteValues["unimplementedMethod"]?.ToString() ?? ""; Log.MethodUnimplemented(logger, unimplementedMethod); - GrpcEventSource.Log.CallUnimplemented(httpContext.Request.Path.Value!); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallUnimplemented(httpContext.Request.Path.Value!); + } GrpcProtocolHelpers.SetStatus(GrpcProtocolHelpers.GetTrailersDestination(httpContext.Response), new Status(StatusCode.Unimplemented, "Method is unimplemented.")); return Task.CompletedTask; }; @@ -146,8 +148,10 @@ public RequestDelegate CreateUnimplementedService() var unimplementedService = httpContext.Request.RouteValues["unimplementedService"]?.ToString() ?? ""; Log.ServiceUnimplemented(logger, unimplementedService); - GrpcEventSource.Log.CallUnimplemented(httpContext.Request.Path.Value!); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallUnimplemented(httpContext.Request.Path.Value!); + } GrpcProtocolHelpers.SetStatus(GrpcProtocolHelpers.GetTrailersDestination(httpContext.Response), new Status(StatusCode.Unimplemented, "Service is unimplemented.")); return Task.CompletedTask; }; diff --git a/src/Grpc.Net.Client/Internal/GrpcCall.cs b/src/Grpc.Net.Client/Internal/GrpcCall.cs index 834f26939..2a795a001 100644 --- a/src/Grpc.Net.Client/Internal/GrpcCall.cs +++ b/src/Grpc.Net.Client/Internal/GrpcCall.cs @@ -585,8 +585,10 @@ private async Task RunCall(HttpRequestMessage request, TimeSpan? timeout) } else { - GrpcEventSource.Log.MessageReceived(); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageReceived(); + } FinishResponseAndCleanUp(status.Value); finished = FinishCall(request, diagnosticSourceEnabled, activity, status.Value); @@ -809,7 +811,10 @@ public Exception CreateFailureStatusException(Status status) private (bool diagnosticSourceEnabled, Activity? activity) InitializeCall(HttpRequestMessage request, TimeSpan? timeout) { GrpcCallLog.StartingCall(Logger, Method.Type, request.RequestUri!); - GrpcEventSource.Log.CallStart(Method.FullName); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallStart(Method.FullName); + } // Deadline will cancel the call CTS. // Only exceed deadline/start timer after reader/writer have been created, otherwise deadline will cancel @@ -882,19 +887,26 @@ private bool FinishCall(HttpRequestMessage request, bool diagnosticSourceEnabled if (IsDeadlineExceededUnsynchronized()) { GrpcCallLog.DeadlineExceeded(Logger); - GrpcEventSource.Log.CallDeadlineExceeded(); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallDeadlineExceeded(); + } _deadline = DateTime.MaxValue; } } } GrpcCallLog.GrpcStatusError(Logger, status.StatusCode, status.Detail); - GrpcEventSource.Log.CallFailed(status.StatusCode); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallFailed(status.StatusCode); + } } GrpcCallLog.FinishedCall(Logger); - GrpcEventSource.Log.CallStop(); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallStop(); + } // Activity needs to be stopped in the same execution context it was started if (activity != null) { @@ -1096,8 +1108,10 @@ private void DeadlineExceeded() Debug.Assert(Monitor.IsEntered(this)); GrpcCallLog.DeadlineExceeded(Logger); - GrpcEventSource.Log.CallDeadlineExceeded(); - + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.CallDeadlineExceeded(); + } // Set _deadline to DateTime.MaxValue to signal that deadline has been exceeded. // This prevents duplicate logging and cancellation. _deadline = DateTime.MaxValue; diff --git a/src/Grpc.Net.Client/Internal/GrpcEventSource.cs b/src/Grpc.Net.Client/Internal/GrpcEventSource.cs index 19b7d1871..b5f7bf67c 100644 --- a/src/Grpc.Net.Client/Internal/GrpcEventSource.cs +++ b/src/Grpc.Net.Client/Internal/GrpcEventSource.cs @@ -16,13 +16,14 @@ #endregion +using System.Diagnostics; using System.Diagnostics.Tracing; using System.Runtime.CompilerServices; using Grpc.Core; namespace Grpc.Net.Client.Internal; -internal class GrpcEventSource : EventSource +internal sealed class GrpcEventSource : EventSource { public static readonly GrpcEventSource Log = new GrpcEventSource(); @@ -68,6 +69,8 @@ internal void ResetCounters() [Event(eventId: 1, Level = EventLevel.Verbose)] public void CallStart(string method) { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _totalCalls); Interlocked.Increment(ref _currentCalls); @@ -78,6 +81,8 @@ public void CallStart(string method) [Event(eventId: 2, Level = EventLevel.Verbose)] public void CallStop() { + AssertEventSourceEnabled(); + Interlocked.Decrement(ref _currentCalls); WriteEvent(2); @@ -87,6 +92,8 @@ public void CallStop() [Event(eventId: 3, Level = EventLevel.Error)] public void CallFailed(StatusCode statusCode) { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _callsFailed); WriteEvent(3, (int)statusCode); @@ -96,6 +103,8 @@ public void CallFailed(StatusCode statusCode) [Event(eventId: 4, Level = EventLevel.Error)] public void CallDeadlineExceeded() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _callsDeadlineExceeded); WriteEvent(4); @@ -105,6 +114,8 @@ public void CallDeadlineExceeded() [Event(eventId: 5, Level = EventLevel.Verbose)] public void MessageSent() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _messageSent); WriteEvent(5); @@ -114,11 +125,20 @@ public void MessageSent() [Event(eventId: 6, Level = EventLevel.Verbose)] public void MessageReceived() { + AssertEventSourceEnabled(); + Interlocked.Increment(ref _messageReceived); WriteEvent(6); } + [Conditional("DEBUG")] + [NonEvent] + private void AssertEventSourceEnabled() + { + Debug.Assert(IsEnabled(), "Event source should be enabled."); + } + protected override void OnEventCommand(EventCommandEventArgs command) { if (command.Command == EventCommand.Enable) diff --git a/src/Grpc.Net.Client/Internal/Http/PushUnaryContent.cs b/src/Grpc.Net.Client/Internal/Http/PushUnaryContent.cs index bb3e9eba8..d9215638b 100644 --- a/src/Grpc.Net.Client/Internal/Http/PushUnaryContent.cs +++ b/src/Grpc.Net.Client/Internal/Http/PushUnaryContent.cs @@ -47,7 +47,10 @@ protected override Task SerializeToStreamAsync(Stream stream, TransportContext? #pragma warning restore CA2012 // Use ValueTasks correctly if (writeMessageTask.IsCompletedSuccessfully()) { - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } return Task.CompletedTask; } @@ -57,7 +60,10 @@ protected override Task SerializeToStreamAsync(Stream stream, TransportContext? private static async Task WriteMessageCore(ValueTask writeMessageTask) { await writeMessageTask.ConfigureAwait(false); - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } } protected override bool TryComputeLength(out long length) diff --git a/src/Grpc.Net.Client/Internal/Http/WinHttpUnaryContent.cs b/src/Grpc.Net.Client/Internal/Http/WinHttpUnaryContent.cs index 0d10a5a0b..56517ab6c 100644 --- a/src/Grpc.Net.Client/Internal/Http/WinHttpUnaryContent.cs +++ b/src/Grpc.Net.Client/Internal/Http/WinHttpUnaryContent.cs @@ -54,7 +54,10 @@ protected override Task SerializeToStreamAsync(Stream stream, TransportContext? #pragma warning restore CA2012 // Use ValueTasks correctly if (writeMessageTask.IsCompletedSuccessfully()) { - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } return Task.CompletedTask; } @@ -64,7 +67,10 @@ protected override Task SerializeToStreamAsync(Stream stream, TransportContext? private static async Task WriteMessageCore(ValueTask writeMessageTask) { await writeMessageTask.ConfigureAwait(false); - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } } protected override bool TryComputeLength(out long length) diff --git a/src/Grpc.Net.Client/Internal/HttpContentClientStreamReader.cs b/src/Grpc.Net.Client/Internal/HttpContentClientStreamReader.cs index 8871c3249..ab7e5655e 100644 --- a/src/Grpc.Net.Client/Internal/HttpContentClientStreamReader.cs +++ b/src/Grpc.Net.Client/Internal/HttpContentClientStreamReader.cs @@ -173,8 +173,10 @@ private async Task MoveNextCore(CancellationToken cancellationToken) Current = null!; return false; } - - GrpcEventSource.Log.MessageReceived(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageReceived(); + } Current = readMessage!; return true; } diff --git a/src/Grpc.Net.Client/Internal/HttpContentClientStreamWriter.cs b/src/Grpc.Net.Client/Internal/HttpContentClientStreamWriter.cs index 48dd1b89c..c7cdf0845 100644 --- a/src/Grpc.Net.Client/Internal/HttpContentClientStreamWriter.cs +++ b/src/Grpc.Net.Client/Internal/HttpContentClientStreamWriter.cs @@ -174,8 +174,10 @@ public async Task WriteAsyncCore(Func, Str // Flush stream to ensure messages are sent immediately. await writeStream.FlushAsync(_call.CancellationToken).ConfigureAwait(false); - - GrpcEventSource.Log.MessageSent(); + if (GrpcEventSource.Log.IsEnabled()) + { + GrpcEventSource.Log.MessageSent(); + } } catch (OperationCanceledException ex) {