From 452ca9b912cf1173d901dc7ef0fcc4098d0ea551 Mon Sep 17 00:00:00 2001 From: Jan Tattermusch Date: Thu, 29 Oct 2015 10:38:03 -0700 Subject: add profiling support --- src/csharp/Grpc.Core/Internal/AsyncCall.cs | 106 ++++++++++++--------- src/csharp/Grpc.Core/Internal/AsyncCallBase.cs | 42 +++++--- src/csharp/Grpc.Core/Internal/CallSafeHandle.cs | 8 +- src/csharp/Grpc.Core/Internal/ChannelSafeHandle.cs | 14 ++- .../Internal/CompletionQueueSafeHandle.cs | 6 +- src/csharp/Grpc.Core/Internal/Enums.cs | 3 + .../Grpc.Core/Internal/MetadataArraySafeHandle.cs | 16 ++-- src/csharp/Grpc.Core/Internal/Timespec.cs | 13 +++ 8 files changed, 135 insertions(+), 73 deletions(-) (limited to 'src/csharp/Grpc.Core/Internal') diff --git a/src/csharp/Grpc.Core/Internal/AsyncCall.cs b/src/csharp/Grpc.Core/Internal/AsyncCall.cs index 800462c854..e3ecc47282 100644 --- a/src/csharp/Grpc.Core/Internal/AsyncCall.cs +++ b/src/csharp/Grpc.Core/Internal/AsyncCall.cs @@ -39,6 +39,7 @@ using System.Threading; using System.Threading.Tasks; using Grpc.Core.Internal; using Grpc.Core.Logging; +using Grpc.Core.Profiling; using Grpc.Core.Utils; namespace Grpc.Core.Internal @@ -87,6 +88,9 @@ namespace Grpc.Core.Internal /// public TResponse UnaryCall(TRequest msg) { + var profiler = Profilers.ForCurrentThread(); + + using (profiler.NewScope("AsyncCall.UnaryCall")) using (CompletionQueueSafeHandle cq = CompletionQueueSafeHandle.Create()) { byte[] payload = UnsafeSerialize(msg); @@ -104,24 +108,26 @@ namespace Grpc.Core.Internal } using (var metadataArray = MetadataArraySafeHandle.Create(details.Options.Headers)) + using (var ctx = BatchContextSafeHandle.Create()) { - using (var ctx = BatchContextSafeHandle.Create()) - { - call.StartUnary(ctx, payload, metadataArray, GetWriteFlagsForCall()); - var ev = cq.Pluck(ctx.Handle); + call.StartUnary(ctx, payload, metadataArray, GetWriteFlagsForCall()); + + var ev = cq.Pluck(ctx.Handle); - bool success = (ev.success != 0); - try + bool success = (ev.success != 0); + try + { + using (profiler.NewScope("AsyncCall.UnaryCall.HandleBatch")) { HandleUnaryResponse(success, ctx.GetReceivedStatusOnClient(), ctx.GetReceivedMessage(), ctx.GetReceivedInitialMetadata()); } - catch (Exception e) - { - Logger.Error(e, "Exception occured while invoking completion delegate."); - } + } + catch (Exception e) + { + Logger.Error(e, "Exception occured while invoking completion delegate."); } } - + // Once the blocking call returns, the result should be available synchronously. // Note that GetAwaiter().GetResult() doesn't wrap exceptions in AggregateException. return unaryResponseTcs.Task.GetAwaiter().GetResult(); @@ -329,27 +335,35 @@ namespace Grpc.Core.Internal private void Initialize(CompletionQueueSafeHandle cq) { - var call = CreateNativeCall(cq); - details.Channel.AddCallReference(this); - InitializeInternal(call); - RegisterCancellationCallback(); + using (Profilers.ForCurrentThread().NewScope("AsyncCall.Initialize")) + { + var call = CreateNativeCall(cq); + + details.Channel.AddCallReference(this); + InitializeInternal(call); + RegisterCancellationCallback(); + } } private INativeCall CreateNativeCall(CompletionQueueSafeHandle cq) { - if (injectedNativeCall != null) - { - return injectedNativeCall; // allows injecting a mock INativeCall in tests. - } + using (Profilers.ForCurrentThread().NewScope("AsyncCall.CreateNativeCall")) + { + if (injectedNativeCall != null) + { + return injectedNativeCall; // allows injecting a mock INativeCall in tests. + } - var parentCall = details.Options.PropagationToken != null ? details.Options.PropagationToken.ParentCall : CallSafeHandle.NullInstance; + var parentCall = details.Options.PropagationToken != null ? details.Options.PropagationToken.ParentCall : CallSafeHandle.NullInstance; - var credentials = details.Options.Credentials; - using (var nativeCredentials = credentials != null ? credentials.ToNativeCredentials() : null) - { - return details.Channel.Handle.CreateCall(environment.CompletionRegistry, - parentCall, ContextPropagationToken.DefaultMask, cq, - details.Method, details.Host, Timespec.FromDateTime(details.Options.Deadline.Value), nativeCredentials); + var credentials = details.Options.Credentials; + using (var nativeCredentials = credentials != null ? credentials.ToNativeCredentials() : null) + { + var result = details.Channel.Handle.CreateCall(environment.CompletionRegistry, + parentCall, ContextPropagationToken.DefaultMask, cq, + details.Method, details.Host, Timespec.FromDateTime(details.Options.Deadline.Value), nativeCredentials); + return result; + } } } @@ -385,33 +399,37 @@ namespace Grpc.Core.Internal /// private void HandleUnaryResponse(bool success, ClientSideStatus receivedStatus, byte[] receivedMessage, Metadata responseHeaders) { - TResponse msg = default(TResponse); - var deserializeException = success ? TryDeserialize(receivedMessage, out msg) : null; - - lock (myLock) + using (Profilers.ForCurrentThread().NewScope("AsyncCall.HandleUnaryResponse")) { - finished = true; + TResponse msg = default(TResponse); + var deserializeException = success ? TryDeserialize(receivedMessage, out msg) : null; - if (deserializeException != null && receivedStatus.Status.StatusCode == StatusCode.OK) + lock (myLock) { - receivedStatus = new ClientSideStatus(DeserializeResponseFailureStatus, receivedStatus.Trailers); + finished = true; + + if (deserializeException != null && receivedStatus.Status.StatusCode == StatusCode.OK) + { + receivedStatus = new ClientSideStatus(DeserializeResponseFailureStatus, receivedStatus.Trailers); + } + finishedStatus = receivedStatus; + + ReleaseResourcesIfPossible(); + } - finishedStatus = receivedStatus; - ReleaseResourcesIfPossible(); - } + responseHeadersTcs.SetResult(responseHeaders); - responseHeadersTcs.SetResult(responseHeaders); + var status = receivedStatus.Status; - var status = receivedStatus.Status; + if (!success || status.StatusCode != StatusCode.OK) + { + unaryResponseTcs.SetException(new RpcException(status)); + return; + } - if (!success || status.StatusCode != StatusCode.OK) - { - unaryResponseTcs.SetException(new RpcException(status)); - return; + unaryResponseTcs.SetResult(msg); } - - unaryResponseTcs.SetResult(msg); } /// diff --git a/src/csharp/Grpc.Core/Internal/AsyncCallBase.cs b/src/csharp/Grpc.Core/Internal/AsyncCallBase.cs index 3e2c57c9b5..953f61aa1e 100644 --- a/src/csharp/Grpc.Core/Internal/AsyncCallBase.cs +++ b/src/csharp/Grpc.Core/Internal/AsyncCallBase.cs @@ -41,6 +41,7 @@ using System.Threading.Tasks; using Grpc.Core.Internal; using Grpc.Core.Logging; +using Grpc.Core.Profiling; using Grpc.Core.Utils; namespace Grpc.Core.Internal @@ -167,16 +168,19 @@ namespace Grpc.Core.Internal /// protected bool ReleaseResourcesIfPossible() { - if (!disposed && call != null) + using (Profilers.ForCurrentThread().NewScope("AsyncCallBase.ReleaseResourcesIfPossible")) { - bool noMoreSendCompletions = sendCompletionDelegate == null && (halfcloseRequested || cancelRequested || finished); - if (noMoreSendCompletions && readingDone && finished) + if (!disposed && call != null) { - ReleaseResources(); - return true; + bool noMoreSendCompletions = sendCompletionDelegate == null && (halfcloseRequested || cancelRequested || finished); + if (noMoreSendCompletions && readingDone && finished) + { + ReleaseResources(); + return true; + } } + return false; } - return false; } protected abstract bool IsClient @@ -228,7 +232,10 @@ namespace Grpc.Core.Internal protected byte[] UnsafeSerialize(TWrite msg) { - return serializer(msg); + using (Profilers.ForCurrentThread().NewScope("AsyncCallBase.UnsafeSerialize")) + { + return serializer(msg); + } } protected Exception TrySerialize(TWrite msg, out byte[] payload) @@ -247,15 +254,20 @@ namespace Grpc.Core.Internal protected Exception TryDeserialize(byte[] payload, out TRead msg) { - try - { - msg = deserializer(payload); - return null; - } - catch (Exception e) + using (Profilers.ForCurrentThread().NewScope("AsyncCallBase.TryDeserialize")) { - msg = default(TRead); - return e; + try + { + + msg = deserializer(payload); + return null; + + } + catch (Exception e) + { + msg = default(TRead); + return e; + } } } diff --git a/src/csharp/Grpc.Core/Internal/CallSafeHandle.cs b/src/csharp/Grpc.Core/Internal/CallSafeHandle.cs index 0be7a4dd3a..ddeedebd11 100644 --- a/src/csharp/Grpc.Core/Internal/CallSafeHandle.cs +++ b/src/csharp/Grpc.Core/Internal/CallSafeHandle.cs @@ -34,6 +34,7 @@ using System.Diagnostics; using System.Runtime.InteropServices; using Grpc.Core; using Grpc.Core.Utils; +using Grpc.Core.Profiling; namespace Grpc.Core.Internal { @@ -131,8 +132,11 @@ namespace Grpc.Core.Internal public void StartUnary(BatchContextSafeHandle ctx, byte[] payload, MetadataArraySafeHandle metadataArray, WriteFlags writeFlags) { - grpcsharp_call_start_unary(this, ctx, payload, new UIntPtr((ulong)payload.Length), metadataArray, writeFlags) - .CheckOk(); + using (Profilers.ForCurrentThread().NewScope("CallSafeHandle.StartUnary")) + { + grpcsharp_call_start_unary(this, ctx, payload, new UIntPtr((ulong)payload.Length), metadataArray, writeFlags) + .CheckOk(); + } } public void StartClientStreaming(UnaryResponseClientHandler callback, MetadataArraySafeHandle metadataArray) diff --git a/src/csharp/Grpc.Core/Internal/ChannelSafeHandle.cs b/src/csharp/Grpc.Core/Internal/ChannelSafeHandle.cs index d270d77526..5f9169bcb2 100644 --- a/src/csharp/Grpc.Core/Internal/ChannelSafeHandle.cs +++ b/src/csharp/Grpc.Core/Internal/ChannelSafeHandle.cs @@ -32,6 +32,7 @@ using System; using System.Runtime.InteropServices; using System.Threading; using System.Threading.Tasks; +using Grpc.Core.Profiling; namespace Grpc.Core.Internal { @@ -84,13 +85,16 @@ namespace Grpc.Core.Internal public CallSafeHandle CreateCall(CompletionRegistry registry, CallSafeHandle parentCall, ContextPropagationFlags propagationMask, CompletionQueueSafeHandle cq, string method, string host, Timespec deadline, CredentialsSafeHandle credentials) { - var result = grpcsharp_channel_create_call(this, parentCall, propagationMask, cq, method, host, deadline); - if (credentials != null) + using (Profilers.ForCurrentThread().NewScope("ChannelSafeHandle.CreateCall")) { - result.SetCredentials(credentials); + var result = grpcsharp_channel_create_call(this, parentCall, propagationMask, cq, method, host, deadline); + if (credentials != null) + { + result.SetCredentials(credentials); + } + result.SetCompletionRegistry(registry); + return result; } - result.SetCompletionRegistry(registry); - return result; } public ChannelState CheckConnectivityState(bool tryToConnect) diff --git a/src/csharp/Grpc.Core/Internal/CompletionQueueSafeHandle.cs b/src/csharp/Grpc.Core/Internal/CompletionQueueSafeHandle.cs index f7a3471bb4..9de2bc7950 100644 --- a/src/csharp/Grpc.Core/Internal/CompletionQueueSafeHandle.cs +++ b/src/csharp/Grpc.Core/Internal/CompletionQueueSafeHandle.cs @@ -31,6 +31,7 @@ using System; using System.Runtime.InteropServices; using System.Threading.Tasks; +using Grpc.Core.Profiling; namespace Grpc.Core.Internal { @@ -70,7 +71,10 @@ namespace Grpc.Core.Internal public CompletionQueueEvent Pluck(IntPtr tag) { - return grpcsharp_completion_queue_pluck(this, tag); + using (Profilers.ForCurrentThread().NewScope("CompletionQueueSafeHandle.Pluck")) + { + return grpcsharp_completion_queue_pluck(this, tag); + } } public void Shutdown() diff --git a/src/csharp/Grpc.Core/Internal/Enums.cs b/src/csharp/Grpc.Core/Internal/Enums.cs index 185098160b..b0eab2001b 100644 --- a/src/csharp/Grpc.Core/Internal/Enums.cs +++ b/src/csharp/Grpc.Core/Internal/Enums.cs @@ -102,6 +102,9 @@ namespace Grpc.Core.Internal /* Realtime clock */ Realtime, + /* Precise clock good for performance profiling. */ + Precise, + /* Timespan - the distance between two time points */ Timespan } diff --git a/src/csharp/Grpc.Core/Internal/MetadataArraySafeHandle.cs b/src/csharp/Grpc.Core/Internal/MetadataArraySafeHandle.cs index 31b834c979..ed1bd24498 100644 --- a/src/csharp/Grpc.Core/Internal/MetadataArraySafeHandle.cs +++ b/src/csharp/Grpc.Core/Internal/MetadataArraySafeHandle.cs @@ -31,6 +31,7 @@ using System; using System.Runtime.InteropServices; using System.Threading.Tasks; +using Grpc.Core.Profiling; namespace Grpc.Core.Internal { @@ -66,14 +67,17 @@ namespace Grpc.Core.Internal public static MetadataArraySafeHandle Create(Metadata metadata) { - // TODO(jtattermusch): we might wanna check that the metadata is readonly - var metadataArray = grpcsharp_metadata_array_create(new UIntPtr((ulong)metadata.Count)); - for (int i = 0; i < metadata.Count; i++) + using (Profilers.ForCurrentThread().NewScope("MetadataArraySafeHandle.Create")) { - var valueBytes = metadata[i].GetSerializedValueUnsafe(); - grpcsharp_metadata_array_add(metadataArray, metadata[i].Key, valueBytes, new UIntPtr((ulong)valueBytes.Length)); + // TODO(jtattermusch): we might wanna check that the metadata is readonly + var metadataArray = grpcsharp_metadata_array_create(new UIntPtr((ulong)metadata.Count)); + for (int i = 0; i < metadata.Count; i++) + { + var valueBytes = metadata[i].GetSerializedValueUnsafe(); + grpcsharp_metadata_array_add(metadataArray, metadata[i].Key, valueBytes, new UIntPtr((ulong)valueBytes.Length)); + } + return metadataArray; } - return metadataArray; } /// diff --git a/src/csharp/Grpc.Core/Internal/Timespec.cs b/src/csharp/Grpc.Core/Internal/Timespec.cs index daf85d5f61..38fc067d9f 100644 --- a/src/csharp/Grpc.Core/Internal/Timespec.cs +++ b/src/csharp/Grpc.Core/Internal/Timespec.cs @@ -239,6 +239,19 @@ namespace Grpc.Core.Internal } } + /// + /// Gets current timestamp using GPRClockType.Precise. + /// Only available internally because core needs to be compiled with + /// GRPC_TIMERS_RDTSC support for this to use RDTSC. + /// + internal static Timespec PreciseNow + { + get + { + return gprsharp_now(GPRClockType.Precise); + } + } + internal static int NativeSize { get -- cgit v1.2.3