Add tracking for stream lifetime (#268)

* Add tracking for stream lifetime * Fix test * Obsolete old StreamDisposedEventArgs constructor instead of changing it. * Mark creationTimestamp readonly * Update src/RecyclableMemoryStream.cs Co-authored-by: Gregory Bell <[email protected]> * Make unit tests more reliable, remove unnecessary cast. * Give more time in unit tests * Add test error message * Fix timestamp casting * Update src/EventArgs.cs Co-authored-by: Ivan Maximov <[email protected]> * Fix time calculation --------- Co-authored-by: Ben Watson <[email protected]> Co-authored-by: Gregory Bell <[email protected]> Co-authored-by: Ivan Maximov <[email protected]>
microsoft · Feb 7, 2023 · 0b445bd · 0b445bd
1 parent 362550d
commit 0b445bd
Show file tree

Hide file tree

Showing 5 changed files with 43 additions and 7 deletions.
diff --git a/UnitTests/Tests.cs b/UnitTests/Tests.cs
@@ -25,6 +25,7 @@ namespace Microsoft.IO.UnitTests
     using System;
     using System.Buffers;
     using System.Collections.Generic;
+    using System.Diagnostics;
     using System.IO;
     using System.Runtime.InteropServices;
     using System.Threading;
@@ -2658,7 +2659,13 @@ public void FinalizedStreamTriggersEvent()
                 handlerTriggered = true;
             };
 
+            mgr.StreamDisposed += (obj, args) =>
+            {
+                Assert.That(args.Lifetime, Is.GreaterThanOrEqualTo(TimeSpan.Zero));
+            };
+
             CreateDeadStream(mgr, expectedGuid, "Tag");
+            Thread.Sleep(100);
 
             GC.Collect(2, GCCollectionMode.Forced, true);
             GC.WaitForPendingFinalizers();
@@ -3441,11 +3448,14 @@ public void EventStreamDisposed()
             {
                 Assert.That(args.Id, Is.Not.EqualTo(Guid.Empty));
                 Assert.That(args.Tag, Is.EqualTo("UnitTest"));
+                Assert.That(args.Lifetime, Is.GreaterThan(TimeSpan.Zero), $"TicksPerSecond: {TimeSpan.TicksPerSecond}, Freq: {Stopwatch.Frequency} Div:{TimeSpan.TicksPerSecond / Stopwatch.Frequency}");
+                Assert.That(args.Lifetime, Is.LessThan(TimeSpan.FromSeconds(2)));
                 Assert.That(args.AllocationStack, Contains.Substring("Microsoft.IO.RecyclableMemoryStream..ctor"));
                 Assert.That(args.DisposeStack, Contains.Substring("Microsoft.IO.RecyclableMemoryStream.Dispose"));
                 raised = true;
             };
             var stream = mgr.GetStream("UnitTest", 13);
+            Thread.Sleep(100);
             stream.Dispose();
             Assert.That(raised, Is.True);
         }

diff --git a/src/EventArgs.cs b/src/EventArgs.cs
@@ -70,17 +70,38 @@ public sealed class StreamDisposedEventArgs : EventArgs
             /// </summary>
             public string DisposeStack { get; }
 
+            /// <summary>
+            /// Lifetime of the stream.
+            /// </summary>
+            public TimeSpan Lifetime { get; }
+
             /// <summary>
             /// Initializes a new instance of the <see cref="StreamDisposedEventArgs"/> class.
             /// </summary>
             /// <param name="guid">Unique ID of the stream.</param>
             /// <param name="tag">Tag of the stream.</param>
             /// <param name="allocationStack">Stack of original allocation.</param>
             /// <param name="disposeStack">Dispose stack.</param>
+            [Obsolete("Use another constructor override")]
             public StreamDisposedEventArgs(Guid guid, string tag, string allocationStack, string disposeStack)
+                :this(guid, tag, TimeSpan.Zero, allocationStack, disposeStack)
+            {
+
+            }
+
+            /// <summary>
+            /// Initializes a new instance of the <see cref="StreamDisposedEventArgs"/> class.
+            /// </summary>
+            /// <param name="guid">Unique ID of the stream.</param>
+            /// <param name="tag">Tag of the stream.</param>
+            /// <param name="lifetime">Lifetime of the stream</param>
+            /// <param name="allocationStack">Stack of original allocation.</param>
+            /// <param name="disposeStack">Dispose stack.</param>
+            public StreamDisposedEventArgs(Guid guid, string tag, TimeSpan lifetime, string allocationStack, string disposeStack)
             {
                 this.Id = guid;
                 this.Tag = tag;
+                this.Lifetime = lifetime;
                 this.AllocationStack = allocationStack;
                 this.DisposeStack = disposeStack;
             }

diff --git a/src/Events.cs b/src/Events.cs
@@ -89,14 +89,15 @@ public void MemoryStreamCreated(Guid guid, string tag, long requestedSize, long
             /// </summary>
             /// <param name="guid">A unique ID for this stream.</param>
             /// <param name="tag">A temporary ID for this stream, usually indicates current usage.</param>
+            /// <param name="lifetime">Lifetime of the stream</param>
             /// <param name="allocationStack">Call stack of initial allocation.</param>
             /// <param name="disposeStack">Call stack of the dispose.</param>
-            [Event(2, Level = EventLevel.Verbose, Version = 2)]
-            public void MemoryStreamDisposed(Guid guid, string tag, string allocationStack, string disposeStack)
+            [Event(2, Level = EventLevel.Verbose, Version = 3)]
+            public void MemoryStreamDisposed(Guid guid, string tag, TimeSpan lifetime, string allocationStack, string disposeStack)
             {
                 if (this.IsEnabled(EventLevel.Verbose, EventKeywords.None))
                 {
-                    WriteEvent(2, guid, tag ?? string.Empty, allocationStack ?? string.Empty, disposeStack ?? string.Empty);
+                    WriteEvent(2, guid, tag ?? string.Empty, lifetime, allocationStack ?? string.Empty, disposeStack ?? string.Empty);
                 }
             }
 

diff --git a/src/RecyclableMemoryStream.cs b/src/RecyclableMemoryStream.cs
@@ -102,6 +102,8 @@ public sealed class RecyclableMemoryStream : MemoryStream, IBufferWriter<byte>
 
         private readonly string tag;
 
+        private readonly long creationTimestamp;
+
         /// <summary>
         /// This list is used to store buffers once they're replaced by something larger.
         /// This is for the cases where you have users of this class that may hold onto the buffers longer
@@ -257,6 +259,7 @@ internal RecyclableMemoryStream(RecyclableMemoryStreamManager memoryManager, Gui
             this.id = id;
             this.tag = tag;
             this.blocks = new List<byte[]>();
+            this.creationTimestamp = Stopwatch.GetTimestamp();
 
             var actualRequestedSize = Math.Max(requestedSize, this.memoryManager.BlockSize);
 
@@ -308,13 +311,14 @@ protected override void Dispose(bool disposing)
             }
 
             this.disposed = true;
+            var lifetime = TimeSpan.FromTicks((Stopwatch.GetTimestamp() - this.creationTimestamp) * TimeSpan.TicksPerSecond / Stopwatch.Frequency);
 
             if (this.memoryManager.GenerateCallStacks)
             {
                 this.DisposeStack = Environment.StackTrace;
             }
 
-            this.memoryManager.ReportStreamDisposed(this.id, this.tag, this.AllocationStack, this.DisposeStack);
+            this.memoryManager.ReportStreamDisposed(this.id, this.tag, lifetime, this.AllocationStack, this.DisposeStack);
 
             if (disposing)
             {

diff --git a/src/RecyclableMemoryStreamManager.cs b/src/RecyclableMemoryStreamManager.cs
@@ -665,10 +665,10 @@ internal void ReportStreamCreated(Guid id, string tag, long requestedSize, long
             this.StreamCreated?.Invoke(this, new StreamCreatedEventArgs(id, tag, requestedSize, actualSize));
         }
 
-        internal void ReportStreamDisposed(Guid id, string tag, string allocationStack, string disposeStack)
+        internal void ReportStreamDisposed(Guid id, string tag, TimeSpan lifetime, string allocationStack, string disposeStack)
         {
-            Events.Writer.MemoryStreamDisposed(id, tag, allocationStack, disposeStack);
-            this.StreamDisposed?.Invoke(this, new StreamDisposedEventArgs(id, tag, allocationStack, disposeStack));
+            Events.Writer.MemoryStreamDisposed(id, tag, lifetime, allocationStack, disposeStack);
+            this.StreamDisposed?.Invoke(this, new StreamDisposedEventArgs(id, tag, lifetime, allocationStack, disposeStack));
         }
 
         internal void ReportStreamDoubleDisposed(Guid id, string tag, string allocationStack, string disposeStack1, string disposeStack2)