Remove allocations and improve performance

AssemblyWithInterceptorAndFormatting/ClassWithMethod.cs

@@ -1,4 +1,5 @@
-using System.Diagnostics;
+using System;
+using System.Diagnostics;
 using System.Threading;
 using MethodTimer;
 
@@ -18,16 +19,18 @@ public void Method(string fileName, int id)
 
     public void Method_Expected(string fileName, int id)
     {
-        var stopwatch = Stopwatch.StartNew();
+        var start = Stopwatch.GetTimestamp();
         try
         {
             Thread.Sleep(10);
         }
         finally
         {
-            stopwatch.Stop();
+            var end = Stopwatch.GetTimestamp();
+            var duration = end - start;
+            var elapsedTimeSpan = new TimeSpan((long)(MethodTimerHelper.TimestampToTicks * duration));
             var methodTimerMessage = $"File name '{fileName}' with id '{id}'";
-            MethodTimeLogger.Log(null, stopwatch.ElapsedMilliseconds, methodTimerMessage);
+            MethodTimeLogger.Log(null, (long)elapsedTimeSpan.TotalMilliseconds, methodTimerMessage);
         }
     }
 

AssemblyWithInterceptorAndFormatting/MethodTimeLogger.cs

@@ -1,5 +1,6 @@
 using System;
 using System.Collections.Generic;
+using System.Diagnostics;
 using System.Reflection;
 
 public static class MethodTimeLogger
@@ -18,4 +19,9 @@ public static void Log(MethodBase methodBase, long milliseconds, string message)
             Messages.Add(message);
         }
     }
+}
+
+internal static class MethodTimerHelper
+{
+    internal static readonly double TimestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
 }

ExampleAssembly/Benchmarks.cs

@@ -0,0 +1,27 @@
+namespace ExampleAssembly
+{
+    using BenchmarkDotNet.Attributes;
+
+    [MemoryDiagnoser]
+    public class StopwatchVsTimestamp
+    {
+        private TestClassWithStopwatch _testClassWithStopwatch = new TestClassWithStopwatch();
+        private TestClassWithTimestamp _testClassWithTimestamp = new TestClassWithTimestamp();
+
+        public StopwatchVsTimestamp()
+        {
+        }
+
+        [Benchmark]
+        public void Timestamp_Sync() => _testClassWithTimestamp.SyncMethod();
+
+        [Benchmark]
+        public void Timestamp_Async() => _testClassWithTimestamp.SyncMethod();
+
+        [Benchmark]
+        public void Stopwatch_Sync() => _testClassWithStopwatch.SyncMethod();
+
+        [Benchmark]
+        public void Stopwatch_Async() => _testClassWithStopwatch.SyncMethod();
+    }
+}

ExampleAssembly/ExampleAssembly.csproj

@@ -0,0 +1,10 @@
+<?xml version="1.0" encoding="utf-8"?>
+<Project Sdk="Microsoft.NET.Sdk">
+  <PropertyGroup>
+    <TargetFramework>net6.0</TargetFramework>
+    <OutputType>Exe</OutputType>
+  </PropertyGroup>
+  <ItemGroup>
+    <PackageReference Include="BenchmarkDotNet" Version="0.14.0" />
+  </ItemGroup>
+</Project>

ExampleAssembly/MethodTimeLogger.cs

@@ -0,0 +1,21 @@
+using System;
+using System.Collections.Generic;
+using System.Reflection;
+
+public static class MethodTimeLogger
+{
+    public static List<MethodBase> MethodBase = new();
+    public static List<string> Messages = new();
+
+    public static void Log(MethodBase methodBase, long milliseconds, string message)
+    {
+        Console.WriteLine($"{methodBase.Name} {milliseconds}: {message}");
+
+        MethodBase.Add(methodBase);
+
+        if (message != null)
+        {
+            Messages.Add(message);
+        }
+    }
+}

ExampleAssembly/MethodTimerHelper.cs

@@ -0,0 +1,7 @@
+using System;
+using System.Diagnostics;
+
+internal static class MethodTimerHelper
+{
+    internal static readonly double TimestampToTicks = TimeSpan.TicksPerSecond / (double)Stopwatch.Frequency;
+}

ExampleAssembly/MethodsWithStopwatch.cs

@@ -0,0 +1,39 @@
+using System;
+using System.Diagnostics;
+using System.Threading.Tasks;
+
+public class TestClassWithStopwatch
+{
+    public void SyncMethod()
+    {
+        var stopwatch = Stopwatch.StartNew();
+
+        try
+        {
+            // Do something
+            //Console.WriteLine("Hello, World!");
+        }
+        finally
+        {
+            stopwatch.Stop();
+
+            var elapsedTimeSpan = stopwatch.Elapsed;
+        }
+    }
+
+    public async Task AsyncMethod()
+    {
+        var stopwatch = Stopwatch.StartNew();
+
+        try
+        {
+            await Task.Delay(5);
+        }
+        finally
+        {
+            stopwatch.Stop();
+
+            var elapsedTimeSpan = stopwatch.Elapsed;
+        }
+    }
+}

ExampleAssembly/MethodsWithTimestamp.cs

@@ -0,0 +1,58 @@
+using System;
+using System.Diagnostics;
+using System.Reflection;
+using System.Threading.Tasks;
+
+public class TestClassWithTimestamp
+{
+    public void SyncMethod()
+    {
+        long startTimestamp;
+        long endTimestamp;
+        long elapsed;
+        TimeSpan elapsedTimeSpan;
+
+        startTimestamp = Stopwatch.GetTimestamp();
+
+        try
+        {
+            // Do something
+            //Console.WriteLine("Hello, World!");
+        }
+        finally
+        {
+            endTimestamp = Stopwatch.GetTimestamp();
+
+            elapsed = endTimestamp - startTimestamp;
+            elapsedTimeSpan = new TimeSpan((long)(MethodTimerHelper.TimestampToTicks * elapsed));
+        }
+    }
+
+    public async Task AsyncMethod()
+    {
+        long startTimestamp = default;
+        long endTimestamp;
+        long elapsed;
+        TimeSpan elapsedTimeSpan;
+
+        if (startTimestamp == 0)
+        {
+            startTimestamp = Stopwatch.GetTimestamp();
+        }
+
+        try
+        {
+            await Task.Delay(5);
+        }
+        finally
+        {
+            if (startTimestamp != 0)
+            {
+                endTimestamp = Stopwatch.GetTimestamp();
+
+                elapsed = endTimestamp - startTimestamp;
+                elapsedTimeSpan = new TimeSpan((long)(MethodTimerHelper.TimestampToTicks * elapsed));
+            }
+        }
+    }
+}

ExampleAssembly/MethodsWithTimestampPreweaved.cs

@@ -0,0 +1,46 @@
+namespace ExampleAssembly
+{
+    using System;
+    using System.Diagnostics;
+    using System.Reflection;
+    using System.Threading.Tasks;
+
+    public class MethodsWithTimestampPreweaved
+    {
+        private long _startTimestamp = default;
+        private long _endTimestamp;
+        private long _elapsed;
+        private TimeSpan _elapsedTimeSpan;
+        private int _state = 0;
+        private string methodTimerMessage;
+
+        public async Task AsyncMethod()
+        {
+            if (_startTimestamp == 0)
+            {
+                _startTimestamp = Stopwatch.GetTimestamp();
+            }
+
+            try
+            {
+                await Task.Delay(5);
+            }
+            finally
+            {
+                StopMethodTimerStopwatch();
+            }
+        }
+
+        private void StopMethodTimerStopwatch()
+        {
+            if (_state == -2 && _startTimestamp != 0)
+            {
+                _endTimestamp = Stopwatch.GetTimestamp();
+                _elapsed = _endTimestamp - _startTimestamp;
+                _elapsedTimeSpan = new TimeSpan((long)(MethodTimerHelper.TimestampToTicks * (double)_elapsed));
+                methodTimerMessage = null;
+                MethodTimeLogger.Log(MethodBase.GetCurrentMethod(), (long)_elapsedTimeSpan.TotalMilliseconds, methodTimerMessage);
+            }
+        }
+    }
+}

ExampleAssembly/Program.cs

@@ -0,0 +1,12 @@
+namespace ExampleAssembly
+{
+    using BenchmarkDotNet.Running;
+
+    public class Program
+    {
+        public static void Main(string[] args)
+        {
+            var summary = BenchmarkRunner.Run<StopwatchVsTimestamp>();
+        }
+    }
+}