Merge pull request #4025 from jtattermusch/csharp_perf_instrumentation

Add simple profiling instrumentation for C#

17 files changed, 587 insertions, 86 deletions

diff --git a/src/csharp/Grpc.Core.Tests/ClientServerTest.cs b/src/csharp/Grpc.Core.Tests/ClientServerTest.cs
index e58528ff50..25a5a27c8e 100644
--- a/src/csharp/Grpc.Core.Tests/ClientServerTest.cs
+++ b/src/csharp/Grpc.Core.Tests/ClientServerTest.cs
@@ -38,6 +38,7 @@ using System.Threading;
 using System.Threading.Tasks;
 using Grpc.Core;
 using Grpc.Core.Internal;
+using Grpc.Core.Profiling;
 using Grpc.Core.Utils;
 using NUnit.Framework;
 
@@ -200,19 +201,6 @@ namespace Grpc.Core.Tests
             Assert.AreEqual(headers[1].Key, trailers[1].Key);
             CollectionAssert.AreEqual(headers[1].ValueBytes, trailers[1].ValueBytes);
         }
-
-        [Test]
-        public void UnaryCallPerformance()
-        {
-            helper.UnaryHandler = new UnaryServerMethod<string, string>(async (request, context) =>
-            {
-                return request;
-            });
-
-            var callDetails = helper.CreateUnaryCall();
-            BenchmarkUtil.RunBenchmark(1, 10,
-                                       () => { Calls.BlockingUnaryCall(callDetails, "ABC"); });
-        }
             
         [Test]
         public void UnknownMethodHandler()
diff --git a/src/csharp/Grpc.Core.Tests/Grpc.Core.Tests.csproj b/src/csharp/Grpc.Core.Tests/Grpc.Core.Tests.csproj
index 91d072abab..e5ffa31989 100644
--- a/src/csharp/Grpc.Core.Tests/Grpc.Core.Tests.csproj
+++ b/src/csharp/Grpc.Core.Tests/Grpc.Core.Tests.csproj
@@ -88,6 +88,7 @@
     <Compile Include="CompressionTest.cs" />
     <Compile Include="ContextPropagationTest.cs" />
     <Compile Include="MetadataTest.cs" />
+    <Compile Include="PerformanceTest.cs" />
   </ItemGroup>
   <Import Project="$(MSBuildBinPath)\Microsoft.CSharp.targets" />
   <ItemGroup>
diff --git a/src/csharp/Grpc.Core.Tests/Internal/TimespecTest.cs b/src/csharp/Grpc.Core.Tests/Internal/TimespecTest.cs
index 874df02baa..9be5450d81 100644
--- a/src/csharp/Grpc.Core.Tests/Internal/TimespecTest.cs
+++ b/src/csharp/Grpc.Core.Tests/Internal/TimespecTest.cs
@@ -34,6 +34,7 @@
 using System;
 using System.Runtime.InteropServices;
 using Grpc.Core.Internal;
+using Grpc.Core.Utils;
 using NUnit.Framework;
 
 namespace Grpc.Core.Internal.Tests
@@ -198,5 +199,23 @@ namespace Grpc.Core.Internal.Tests
                 Console.WriteLine("Test cannot be run on this platform, skipping the test.");
             }
         }
+            
+        // Test attribute commented out to prevent running as part of the default test suite.
+        // [Test]
+        // [Category("Performance")]
+        public void NowBenchmark() 
+        {
+            // approx Timespec.Now latency <33ns
+            BenchmarkUtil.RunBenchmark(10000000, 1000000000, () => { var now = Timespec.Now; });
+        }
+
+        // Test attribute commented out to prevent running as part of the default test suite.
+        // [Test]
+        // [Category("Performance")]
+        public void PreciseNowBenchmark()
+        {
+            // approx Timespec.PreciseNow latency <18ns (when compiled with GRPC_TIMERS_RDTSC)
+            BenchmarkUtil.RunBenchmark(10000000, 1000000000, () => { var now = Timespec.PreciseNow; });
+        }
     }
 }
diff --git a/src/csharp/Grpc.Core.Tests/PerformanceTest.cs b/src/csharp/Grpc.Core.Tests/PerformanceTest.cs
new file mode 100644
index 0000000000..5516cd3377
--- /dev/null
+++ b/src/csharp/Grpc.Core.Tests/PerformanceTest.cs
@@ -0,0 +1,99 @@
+#region Copyright notice and license
+
+// Copyright 2015, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#endregion
+
+using System;
+using System.Diagnostics;
+using System.Linq;
+using System.Threading;
+using System.Threading.Tasks;
+using Grpc.Core;
+using Grpc.Core.Internal;
+using Grpc.Core.Profiling;
+using Grpc.Core.Utils;
+using NUnit.Framework;
+
+namespace Grpc.Core.Tests
+{
+    public class PerformanceTest
+    {
+        const string Host = "127.0.0.1";
+
+        MockServiceHelper helper;
+        Server server;
+        Channel channel;
+
+        [SetUp]
+        public void Init()
+        {
+            helper = new MockServiceHelper(Host);
+            server = helper.GetServer();
+            server.Start();
+            channel = helper.GetChannel();
+        }
+
+        [TearDown]
+        public void Cleanup()
+        {
+            channel.ShutdownAsync().Wait();
+            server.ShutdownAsync().Wait();
+        }
+
+        // Test attribute commented out to prevent running as part of the default test suite.
+        //[Test]
+        //[Category("Performance")]
+        public void UnaryCallPerformance()
+        {
+            var profiler = new BasicProfiler();
+            Profilers.SetForCurrentThread(profiler);
+
+            helper.UnaryHandler = new UnaryServerMethod<string, string>(async (request, context) =>
+            {
+                return request;
+            });
+
+            var callDetails = helper.CreateUnaryCall();
+            for(int i = 0; i < 3000; i++)
+            {
+                Calls.BlockingUnaryCall(callDetails, "ABC");
+            }
+
+            profiler.Reset();
+
+            for(int i = 0; i < 3000; i++)
+            {
+                Calls.BlockingUnaryCall(callDetails, "ABC");
+            }
+            profiler.Dump("latency_trace_csharp.txt");
+        }
+    }
+}
diff --git a/src/csharp/Grpc.Core/Grpc.Core.csproj b/src/csharp/Grpc.Core/Grpc.Core.csproj
index 92d4e19eac..0aab7bdd8a 100644
--- a/src/csharp/Grpc.Core/Grpc.Core.csproj
+++ b/src/csharp/Grpc.Core/Grpc.Core.csproj
@@ -119,6 +119,10 @@
     <Compile Include="CompressionLevel.cs" />
     <Compile Include="WriteOptions.cs" />
     <Compile Include="ContextPropagationToken.cs" />
+    <Compile Include="Profiling\ProfilerEntry.cs" />
+    <Compile Include="Profiling\ProfilerScope.cs" />
+    <Compile Include="Profiling\IProfiler.cs" />
+    <Compile Include="Profiling\Profilers.cs" />
   </ItemGroup>
   <ItemGroup>
     <None Include="Grpc.Core.nuspec" />
@@ -150,4 +154,7 @@
   <Import Project="..\packages\grpc.dependencies.openssl.redist.1.0.2.2\build\portable-net45\grpc.dependencies.openssl.redist.targets" Condition="Exists('..\packages\grpc.dependencies.openssl.redist.1.0.2.2\build\portable-net45\grpc.dependencies.openssl.redist.targets')" />
   <Import Project="..\packages\grpc.dependencies.zlib.redist.1.2.8.9\build\portable-net45\grpc.dependencies.zlib.redist.targets" Condition="Exists('..\packages\grpc.dependencies.zlib.redist.1.2.8.9\build\portable-net45\grpc.dependencies.zlib.redist.targets')" />
   <ItemGroup />
+  <ItemGroup>
+    <Folder Include="Profiling\" />
+  </ItemGroup>
 </Project>
\ No newline at end of file
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
         /// </summary>
         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
         /// </summary>
         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);
         }
 
         /// <summary>
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
         /// </summary>
         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;
         }
 
         /// <summary>
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
             }
         }
 
+        /// <summary>
+        /// Gets current timestamp using <c>GPRClockType.Precise</c>.
+        /// Only available internally because core needs to be compiled with 
+        /// GRPC_TIMERS_RDTSC support for this to use RDTSC.
+        /// </summary>
+        internal static Timespec PreciseNow
+        {
+            get
+            {
+                return gprsharp_now(GPRClockType.Precise);
+            }
+        }
+
         internal static int NativeSize
         {
             get
diff --git a/src/csharp/Grpc.Core/Profiling/IProfiler.cs b/src/csharp/Grpc.Core/Profiling/IProfiler.cs
new file mode 100644
index 0000000000..c426c365d2
--- /dev/null
+++ b/src/csharp/Grpc.Core/Profiling/IProfiler.cs
@@ -0,0 +1,47 @@
+#region Copyright notice and license
+
+// Copyright 2015, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#endregion
+
+using System;
+using System.IO;
+using System.Threading;
+using Grpc.Core.Internal;
+
+namespace Grpc.Core.Profiling
+{
+    internal interface IProfiler 
+    {
+        void Begin(string tag);
+        void End(string tag);
+        void Mark(string tag);
+    }
+}
diff --git a/src/csharp/Grpc.Core/Profiling/ProfilerEntry.cs b/src/csharp/Grpc.Core/Profiling/ProfilerEntry.cs
new file mode 100644
index 0000000000..5cc4c3c054
--- /dev/null
+++ b/src/csharp/Grpc.Core/Profiling/ProfilerEntry.cs
@@ -0,0 +1,87 @@
+#region Copyright notice and license
+
+// Copyright 2015, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#endregion
+
+using System;
+using System.IO;
+using System.Threading;
+using Grpc.Core.Internal;
+
+namespace Grpc.Core.Profiling
+{
+    internal struct ProfilerEntry
+    {
+        public enum Type {
+            BEGIN,
+            END,
+            MARK
+        }
+
+        public ProfilerEntry(Timespec timespec, Type type, string tag)
+        {
+            this.timespec = timespec;
+            this.type = type;
+            this.tag = tag;
+        }
+
+        public Timespec timespec;
+        public Type type;
+        public string tag;
+
+        public override string ToString()
+        {
+            // mimic the output format used by C core.
+            return string.Format(
+                "{{\"t\": {0}.{1}, \"thd\":\"unknown\", \"type\": \"{2}\", \"tag\": \"{3}\", " +
+                "\"file\": \"unknown\", \"line\": 0, \"imp\": 0}}",
+                timespec.TimevalSeconds, timespec.TimevalNanos.ToString("D9"),
+                GetTypeAbbreviation(type), tag);
+        }
+
+        internal static string GetTypeAbbreviation(Type type)
+        {
+            switch (type)
+            {
+                case Type.BEGIN:
+                    return "{";
+
+                case Type.END:
+                    return "}";
+                
+                case Type.MARK:
+                    return ".";
+                default:
+                    throw new ArgumentException("Unknown type");
+            }
+        }
+    }
+}
diff --git a/src/csharp/Grpc.Core/Profiling/ProfilerScope.cs b/src/csharp/Grpc.Core/Profiling/ProfilerScope.cs
new file mode 100644
index 0000000000..413f3a1a35
--- /dev/null
+++ b/src/csharp/Grpc.Core/Profiling/ProfilerScope.cs
@@ -0,0 +1,60 @@
+#region Copyright notice and license
+
+// Copyright 2015, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#endregion
+
+using System;
+using System.IO;
+using System.Threading;
+using Grpc.Core.Internal;
+
+namespace Grpc.Core.Profiling
+{
+    // Allows declaring Begin and End of a profiler scope with a using statement.
+    // declared as struct for better performance.
+    internal struct ProfilerScope : IDisposable
+    {
+        readonly IProfiler profiler;
+        readonly string tag;
+
+        public ProfilerScope(IProfiler profiler, string tag)
+        {
+            this.profiler = profiler;
+            this.tag = tag;
+            this.profiler.Begin(this.tag);
+        }
+            
+        public void Dispose()
+        {
+            profiler.End(tag);
+        }
+    }
+}
diff --git a/src/csharp/Grpc.Core/Profiling/Profilers.cs b/src/csharp/Grpc.Core/Profiling/Profilers.cs
new file mode 100644
index 0000000000..c8123347f2
--- /dev/null
+++ b/src/csharp/Grpc.Core/Profiling/Profilers.cs
@@ -0,0 +1,131 @@
+#region Copyright notice and license
+
+// Copyright 2015, Google Inc.
+// All rights reserved.
+//
+// Redistribution and use in source and binary forms, with or without
+// modification, are permitted provided that the following conditions are
+// met:
+//
+//     * Redistributions of source code must retain the above copyright
+// notice, this list of conditions and the following disclaimer.
+//     * Redistributions in binary form must reproduce the above
+// copyright notice, this list of conditions and the following disclaimer
+// in the documentation and/or other materials provided with the
+// distribution.
+//     * Neither the name of Google Inc. nor the names of its
+// contributors may be used to endorse or promote products derived from
+// this software without specific prior written permission.
+//
+// THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
+// "AS IS" AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
+// LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR
+// A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE COPYRIGHT
+// OWNER OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT, INCIDENTAL,
+// SPECIAL, EXEMPLARY, OR CONSEQUENTIAL DAMAGES (INCLUDING, BUT NOT
+// LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES; LOSS OF USE,
+// DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED AND ON ANY
+// THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY, OR TORT
+// (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT OF THE USE
+// OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF SUCH DAMAGE.
+
+#endregion
+
+using System;
+using System.IO;
+using System.Threading;
+using Grpc.Core.Internal;
+
+namespace Grpc.Core.Profiling
+{
+    internal static class Profilers
+    {
+        static readonly NopProfiler defaultProfiler = new NopProfiler();
+        static readonly ThreadLocal<IProfiler> profilers = new ThreadLocal<IProfiler>();
+
+        public static IProfiler ForCurrentThread()
+        {
+            return profilers.Value ?? defaultProfiler;
+        }
+
+        public static void SetForCurrentThread(IProfiler profiler)
+        {
+            profilers.Value = profiler;
+        }
+
+        public static ProfilerScope NewScope(this IProfiler profiler, string tag)
+        {
+            return new ProfilerScope(profiler, tag);
+        }
+    }
+
+    internal class NopProfiler : IProfiler
+    {
+        public void Begin(string tag)
+        {
+        }
+
+        public void End(string tag)
+        {
+        }
+
+        public void Mark(string tag)
+        {
+        }
+    }
+
+    // Profiler using Timespec.PreciseNow
+    internal class BasicProfiler : IProfiler
+    {
+        ProfilerEntry[] entries;
+        int count;
+
+        public BasicProfiler() : this(1024*1024)
+        {
+        }
+
+        public BasicProfiler(int capacity)
+        {
+            this.entries = new ProfilerEntry[capacity];
+        }
+
+        public void Begin(string tag) {
+            AddEntry(new ProfilerEntry(Timespec.PreciseNow, ProfilerEntry.Type.BEGIN, tag));
+        }
+
+        public void End(string tag) {
+            AddEntry(new ProfilerEntry(Timespec.PreciseNow, ProfilerEntry.Type.END, tag));
+        }
+
+        public void Mark(string tag) {
+            AddEntry(new ProfilerEntry(Timespec.PreciseNow, ProfilerEntry.Type.MARK, tag));
+        }
+
+        public void Reset()
+        {
+            count = 0;
+        }
+
+        public void Dump(string filepath)
+        {
+            using (var stream = new StreamWriter(filepath))
+            {
+                Dump(stream);
+            }
+        }
+
+        public void Dump(TextWriter stream)
+        {
+            for (int i = 0; i < count; i++)
+            {
+                var entry = entries[i];
+                stream.WriteLine(entry.ToString());
+            }
+        }
+
+        // NOT THREADSAFE!
+        void AddEntry(ProfilerEntry entry) {
+            entries[count++] = entry;
+        }
+    }
+}