changeset 253:34df34841225 v3 v3.0.1-beta

Implab.Diagnostics drafts
author cin
date Mon, 12 Feb 2018 17:03:37 +0300
parents 6f4630d0bcd9
children 12c00235b105
files Implab.Test/UnitTest1.cs Implab/AbstractEvent.cs Implab/Diagnostics/ActivityScope.cs Implab/Diagnostics/LogicalOperation.cs Implab/Diagnostics/LogicalOperationScope.cs Implab/Diagnostics/SimpleTraceListener.cs Implab/Diagnostics/Trace.cs Implab/Diagnostics/TraceEventCodes.cs Implab/Implab.csproj Implab/ValueEventArgs.cs
diffstat 10 files changed, 274 insertions(+), 48 deletions(-) [+]
line wrap: on
line diff
--- a/Implab.Test/UnitTest1.cs	Mon Feb 12 07:24:31 2018 +0300
+++ b/Implab.Test/UnitTest1.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -4,34 +4,26 @@
 using Implab.Diagnostics;
 using Xunit;
 
-namespace Implab.Test
-{
+namespace Implab.Test {
+    using System.Threading.Tasks;
     using static Trace<UnitTest1>;
-    public class UnitTest1
-    {
+    public class UnitTest1 {
         [Fact]
-        public void Test1()
-        {
-            var listener = new TextWriterTraceListener(Console.Out);
+        public async Task Test1() {
+            var listener = new SimpleTraceListener(Console.Out);
+
             var source = TraceSource;
             source.Switch.Level = SourceLevels.All;
 
             source.Listeners.Add(listener);
-            Trace.Listeners.Add(listener);
 
-            Trace.WriteLine("Hello!");
-            StartLogicalOperation();
-
-            Trace.WriteLine("Inner");
-            foreach(var x in Trace.CorrelationManager.LogicalOperationStack)
-                Trace.WriteLine($"-{x}");
-            Log("source event");
-
-            listener.IndentLevel = 1;
-
-            source.TraceData(TraceEventType.Start, 1, DateTime.Now);
-            
-            StopLogicalOperation();
+            using (var op = LogicalOperation(nameof(Test1)))
+            using (LogicalOperation("InnerOperation")){
+                await Task.Yield();
+                Log("Inner");
+                await Task.Yield();
+                Log("source event");
+            }
         }
     }
 }
--- a/Implab/AbstractEvent.cs	Mon Feb 12 07:24:31 2018 +0300
+++ b/Implab/AbstractEvent.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -62,7 +62,7 @@
             if (TransitionalState != Interlocked.CompareExchange(ref m_state, ResolvedState, TransitionalState))
                 throw new InvalidOperationException("Can't complete transition when the object isn't in the transitional state");
 #else
-            m_state = state;
+            m_state = ResolvedState;
 #endif
             Signal();
         }
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/ActivityScope.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -0,0 +1,29 @@
+using System;
+using System.Diagnostics;
+
+namespace Implab.Diagnostics {
+    public class ActivityScope : IDisposable {
+        readonly TraceSource m_source;
+
+        readonly Guid m_prevId;
+
+        readonly string m_activity;
+
+        readonly int m_code;
+
+        internal ActivityScope(TraceSource source, Guid prevId, int code, string activity) {
+            m_source = source;
+            m_prevId = prevId;
+            m_code = code;
+            m_activity = activity;
+        }
+
+
+        public void Dispose() {
+            if (Trace.CorrelationManager.ActivityId != m_prevId)
+                m_source.TraceTransfer(m_code, "Transfer", m_prevId);
+            m_source.TraceEvent(TraceEventType.Stop, 0, m_activity);
+            Trace.CorrelationManager.ActivityId = m_prevId;
+        }
+    }
+}
\ No newline at end of file
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/LogicalOperation.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -0,0 +1,17 @@
+using System;
+using System.Diagnostics;
+
+namespace Implab.Diagnostics {
+    public class LogicalOperation {
+        public Stopwatch OperationStopwatch { get; private set; }
+
+        public string Name { get; private set; }
+
+        internal LogicalOperation(string name) {
+            Name = string.IsNullOrEmpty(name) ? "<unnamed>" : name;
+            OperationStopwatch = Stopwatch.StartNew();
+        }
+
+        public override string ToString() => Name;
+    }
+}
\ No newline at end of file
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/LogicalOperationScope.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -0,0 +1,21 @@
+using System;
+using System.Diagnostics;
+
+namespace Implab.Diagnostics {
+    public class LogicalOperationScope : IDisposable {
+        readonly TraceSource m_source;
+
+        readonly LogicalOperation m_operation;
+
+        internal LogicalOperationScope(TraceSource source, LogicalOperation operation) {
+            m_source = source;
+            m_operation = operation;
+        }
+
+        public void Dispose() {
+            m_operation.OperationStopwatch.Stop();
+            Trace.CorrelationManager.StopLogicalOperation();
+            m_source.TraceData(TraceEventType.Information, TraceEventCodes.StopLogicalOperation, m_operation);
+        }
+    }
+}
\ No newline at end of file
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/SimpleTraceListener.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -0,0 +1,114 @@
+using System;
+using System.Diagnostics;
+using System.IO;
+
+namespace Implab.Diagnostics {
+    public class SimpleTraceListener : TextWriterTraceListener {
+        public SimpleTraceListener() {
+        }
+
+        public SimpleTraceListener(Stream stream) : base(stream) {
+        }
+
+        public SimpleTraceListener(TextWriter writer) : base(writer) {
+        }
+
+        public SimpleTraceListener(string fileName) : base(fileName) {
+        }
+
+        public SimpleTraceListener(Stream stream, string name) : base(stream, name) {
+        }
+
+        public SimpleTraceListener(TextWriter writer, string name) : base(writer, name) {
+        }
+
+        public SimpleTraceListener(string fileName, string name) : base(fileName, name) {
+        }
+
+        public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, object data) {
+            switch (id) {
+                case TraceEventCodes.StartLogicalOperation:
+                    TraceEvent(eventCache, source, eventType, id, "+{0}", data);
+                    break;
+                case TraceEventCodes.StopLogicalOperation:
+                    TraceEvent(eventCache, source, eventType, id, FormatStopLogicalOperation(data));
+                    break;
+                default:
+                    TraceEvent(eventCache, source, eventType, id, data?.ToString());
+                    break;
+            }
+        }
+
+        string FormatStopLogicalOperation(object data) {
+            if (data is LogicalOperation op) {
+                return string.Format("-{0} ({1})", op, FormatTimespan(op.OperationStopwatch.Elapsed));
+            } else {
+                return data?.ToString();
+            }
+        }
+
+        string FormatTimespan(TimeSpan value) {
+            if (value.TotalSeconds < 10) {
+                return value.Milliseconds.ToString() + "ms";
+            } else if (value.TotalSeconds < 30) {
+                return string.Format("{0:0.###}s", value.TotalSeconds);
+            } else {
+                return value.ToString();
+            }
+        }
+
+        public override void TraceData(TraceEventCache eventCache, string source, TraceEventType eventType, int id, params object[] data) {
+            var prev = IndentLevel;
+            IndentLevel += eventCache.LogicalOperationStack.Count;
+            try {
+                base.TraceData(eventCache, source, eventType, id, data);
+            } finally {
+                IndentLevel = prev;
+            }
+        }
+
+        public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id) {
+            var prev = IndentLevel;
+            IndentLevel += eventCache.LogicalOperationStack.Count;
+            try {
+                base.TraceEvent(eventCache, source, eventType, id);
+            } finally {
+                IndentLevel = prev;
+            }
+        }
+
+        public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string format, params object[] args) {
+            TraceEvent(eventCache, source, eventType, id, String.Format(format, args));
+        }
+
+        public override void TraceEvent(TraceEventCache eventCache, string source, TraceEventType eventType, int id, string message) {
+            var prev = IndentLevel;
+            IndentLevel += eventCache.LogicalOperationStack.Count;
+            try {
+                LogicalOperation operation = null;
+                if (eventCache.LogicalOperationStack.Count > 0)
+                    operation = eventCache.LogicalOperationStack.Peek() as LogicalOperation;
+
+                if (operation != null) {
+                    base.TraceData(eventCache, source, eventType, id, FormatTimespan(operation.OperationStopwatch.Elapsed) + ": " + message);
+                } else {
+                    base.TraceData(eventCache, source, eventType, id, message);
+                }
+            } finally {
+                IndentLevel = prev;
+            }
+        }
+
+        public override void TraceTransfer(TraceEventCache eventCache, string source, int id, string message, Guid relatedActivityId) {
+            var prev = IndentLevel;
+            IndentLevel += eventCache.LogicalOperationStack.Count;
+            try {
+                base.TraceTransfer(eventCache, source, id, message, relatedActivityId);
+            } finally {
+                IndentLevel = prev;
+            }
+        }
+
+
+    }
+}
\ No newline at end of file
--- a/Implab/Diagnostics/Trace.cs	Mon Feb 12 07:24:31 2018 +0300
+++ b/Implab/Diagnostics/Trace.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -29,7 +29,7 @@
         /// <param name="name">Name.</param>
         [Conditional("TRACE")]
         public static void StartLogicalOperation(string name) {
-            Trace.CorrelationManager.StartLogicalOperation();
+            Trace.CorrelationManager.StartLogicalOperation(name);
         }
 
         /// <summary>
@@ -47,7 +47,7 @@
         /// <param name="arguments">Arguments.</param>
         [Conditional("TRACE")]
         public static void Log(string format, params object[] arguments) {
-            TraceSource.TraceEvent(TraceEventType.Information, 1, format, arguments);
+            TraceSource.TraceEvent(TraceEventType.Information, 0, format, arguments);
         }
 
         /// <summary>
@@ -57,17 +57,71 @@
         /// <param name="arguments">Arguments.</param>
         [Conditional("TRACE")]
         public static void Warn(string format, params object[] arguments) {
-            TraceSource.TraceEvent(TraceEventType.Warning, 1, format, arguments);
+            TraceSource.TraceEvent(TraceEventType.Warning, 0, format, arguments);
         }
 
         [Conditional("TRACE")]
         public static void Error(string format, params object[] arguments) {
-            TraceSource.TraceEvent(TraceEventType.Error, 1, format, arguments);
+            TraceSource.TraceEvent(TraceEventType.Error, 0, format, arguments);
         }
 
         [Conditional("TRACE")]
         public static void Error(Exception err) {
-            TraceSource.TraceData(TraceEventType.Error, 1, err);
+            TraceSource.TraceData(TraceEventType.Error, 0, err);
+        }
+
+        /// <summary>
+        /// This method save the current activity, and transfers to the specified activity,
+        /// emits <see cref="TraceEventType.Start"/> and returns a scope of the new
+        /// activity.
+        /// </summary>
+        /// <param name="activityName">The name of the new activity/</param>
+        /// <param name="activityId">The identifier of the activity to which 
+        /// the control will be transferred</param>
+        /// <returns>A scope of the new activity, dispose it to transfer
+        /// the control back to the original activity.</returns>
+        public static ActivityScope TransferActivity(string activityName, Guid activityId) {
+            var prev = Trace.CorrelationManager.ActivityId;
+
+            TraceSource.TraceTransfer(0, "Transfer", activityId);
+            Trace.CorrelationManager.ActivityId = activityId;
+            TraceSource.TraceEvent(TraceEventType.Start, 0, activityName);
+
+            return new ActivityScope(TraceSource, prev, 0, activityName);
+        }
+
+        /// <summary>
+        /// Emits <see cref="TraceEventType.Start"/> and returns a scope of the
+        /// activity.
+        /// </summary>
+        /// <param name="activityName">The name of the activity to start</param>
+        /// <returns>A scope of the new activity, dispose it to emit
+        /// <see cref="TraceEventType.Stop"/> for the current activity.</returns>
+        public static ActivityScope StartActivity(string activityName) {
+            if (Trace.CorrelationManager.ActivityId == Guid.Empty)
+                Trace.CorrelationManager.ActivityId = Guid.NewGuid();
+
+            var prev = Trace.CorrelationManager.ActivityId;
+            
+            TraceSource.TraceEvent(TraceEventType.Start, 0, activityName);
+            return new ActivityScope(TraceSource, prev, 0, activityName);
+        }
+
+        /// <summary>
+        /// Creates new <see cref="LogicalOperation(string)"/> and calls
+        /// to <see cref="CorrelationManager.StartLogicalOperation(object)"/>
+        /// passing the created operation as identity. Calls
+        /// <see cref="TraceSource.TraceData(TraceEventType, int, object)"/>
+        /// to notify listeners on operation start.
+        /// </summary>
+        /// <param name="name">The name of the logical operation.</param>
+        /// <returns>Logical operation scope, disposing it will stop
+        /// logical operation and notify trace listeners.</returns>
+        public static LogicalOperationScope LogicalOperation(string name) {
+            var operation = new LogicalOperation(name);
+            TraceSource.TraceData(TraceEventType.Information, TraceEventCodes.StartLogicalOperation, operation);
+            Trace.CorrelationManager.StartLogicalOperation(operation);
+            return new LogicalOperationScope(TraceSource, operation);
         }
     }
 }
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/TraceEventCodes.cs	Mon Feb 12 17:03:37 2018 +0300
@@ -0,0 +1,10 @@
+namespace Implab.Diagnostics {
+    public class TraceEventCodes {
+        public const int EventCodesBase = 1024;
+      
+        public const int StartLogicalOperation = EventCodesBase + 1;
+
+        public const int StopLogicalOperation = EventCodesBase + 2;
+
+    }
+}
\ No newline at end of file
--- a/Implab/Implab.csproj	Mon Feb 12 07:24:31 2018 +0300
+++ b/Implab/Implab.csproj	Mon Feb 12 17:03:37 2018 +0300
@@ -1,6 +1,16 @@
 <Project Sdk="Microsoft.NET.Sdk">
 
   <PropertyGroup>
+    <Authors>Sergey Smirnov</Authors>
+    <Title>Implab library</Title>
+    <Description>Provides some helper clesses like XML serialization helpers, JSON XML reader,
+    JSON pull-parser, ECMA-style promises, lightweight synchonization routines Signal
+    and SharedLock, Trace helpers on top of System.Diagnostics, ObjectPool etc.
+    </Description>
+    <Copyright>2012-2018 Sergey Smirnov</Copyright>
+    <LicenseUrl>https://opensource.org/licenses/BSD-2-Clause</LicenseUrl>
+    <ProjectUrl>https://implab.org</ProjectUrl>
+    <RepositoryUrl>https://hg.implab.org/pub/ImplabNet/</RepositoryUrl>
     <TargetFrameworks>netstandard2.0;net45</TargetFrameworks>
     <FrameworkPathOverride Condition="'$(TargetFramework)'=='net45' and '$(OSTYPE)'=='linux'">/usr/lib/mono/4.5/</FrameworkPathOverride>
   </PropertyGroup>
--- a/Implab/ValueEventArgs.cs	Mon Feb 12 07:24:31 2018 +0300
+++ /dev/null	Thu Jan 01 00:00:00 1970 +0000
@@ -1,21 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Linq;
-using System.Text;
-
-namespace Implab
-{
-    [Serializable]
-    public class ValueEventArgs<T>: EventArgs
-    {
-        public ValueEventArgs(T value)
-        {
-            this.Value = value;
-        }
-        public T Value
-        {
-            get;
-            private set;
-        }
-    }
-}