changeset 35:2880242f987a diagnostics

initial log capabilities
author cin
date Mon, 14 Apr 2014 18:25:26 +0400
parents dabf79fde388
children 313f708a50e9
files Implab.v11.suo Implab/Diagnostics/IEventListener.cs Implab/Diagnostics/Log.cs Implab/Diagnostics/LogContext.cs Implab/Diagnostics/LogicalOperation.cs Implab/Diagnostics/TraceEventType.cs Implab/Implab.csproj Implab/Parallels/AsyncPool.cs Implab/Parallels/WorkerPool.cs Implab/PromiseState.cs
diffstat 10 files changed, 247 insertions(+), 17 deletions(-) [+]
line wrap: on
line diff
Binary file Implab.v11.suo has changed
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/IEventListener.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -0,0 +1,11 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace Implab.Diagnostics {
+    public interface IEventListener {
+        void TraceEvent(LogContext context, TraceEventType type, string format, params object[] args);
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/Log.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -0,0 +1,50 @@
+using System;
+using System.Collections.Generic;
+using System.Diagnostics;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace Implab.Diagnostics {
+    public static class Log {
+        [Conditional("TRACE")]
+        public static void Transfer(LogContext from) {
+            LogContext.Transfer(from);
+        }
+
+        [Conditional("TRACE")]
+        public static void StartLogicalOperation() {
+            LogContext.Current.StartLogicalOperation();
+        }
+
+        [Conditional("TRACE")]
+        public static void StartLogicalOperation(string name) {
+            LogContext.Current.StartLogicalOperation(name);
+        }
+
+        [Conditional("TRACE")]
+        public static void EndLogicalOperation() {
+            LogContext.Current.EndLogicalOperation();
+        }
+
+        [Conditional("TRACE")]
+        public static void TraceInformation(string format, params object[] arguments) {
+            LogContext.Current.TraceEvent(TraceEventType.Information, format, arguments);
+        }
+
+        [Conditional("TRACE")]
+        public static void TraceWarning(string format, params object[] arguments) {
+            LogContext.Current.TraceEvent(TraceEventType.Warning, format, arguments);
+        }
+
+        [Conditional("TRACE")]
+        public static void TraceError(string format, params object[] arguments) {
+            LogContext.Current.TraceEvent(TraceEventType.Error, format, arguments);
+        }
+
+        [Conditional("TRACE")]
+        public static void TraceError(Exception err) {
+            TraceError("{0}", err);
+        }
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/LogContext.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -0,0 +1,107 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading;
+using System.Threading.Tasks;
+
+namespace Implab.Diagnostics {
+    public class LogContext {
+        LogicalOperation m_currentOperation;
+        readonly LogicalOperation m_traceBound;
+        readonly int m_threadId;
+        readonly LogContext m_parent;
+
+        readonly static object _consoleLock = new object();
+
+        [ThreadStatic]
+        static LogContext _current;
+
+        public static LogContext Current {
+            get {
+                if (_current == null)
+                    _current = new LogContext();
+                return _current;
+            }
+        }
+
+        LogContext(LogContext context) {
+            if (context == null)
+                throw new ArgumentNullException("context");
+
+            m_parent = context;
+            m_currentOperation = context.CurrentOperation;
+            m_traceBound = context.CurrentOperation;
+            m_threadId = Thread.CurrentThread.ManagedThreadId;
+
+            TraceEvent(TraceEventType.Transfer, String.Empty);
+        }
+
+        LogContext() {
+            m_currentOperation = new LogicalOperation();
+            m_traceBound = m_currentOperation;
+            m_threadId = Thread.CurrentThread.ManagedThreadId;
+        }
+
+        public static void Transfer(LogContext from) {
+            _current = from == null ? new LogContext() : new LogContext(from);
+        }
+
+        public LogContext ParentContext {
+            get {
+                return m_parent;
+            }
+        }
+
+        public LogicalOperation CurrentOperation {
+            get {
+                return m_currentOperation;
+            }
+        }
+
+        public LogicalOperation TraceBound {
+            get {
+                return m_traceBound;
+            }
+        }
+
+        public int ThreadId {
+            get {
+                return m_threadId;
+            }
+        }
+
+        public void StartLogicalOperation() {
+            StartLogicalOperation(null);
+        }
+
+        public void StartLogicalOperation(string name) {
+            TraceEvent(TraceEventType.OperationStarted, "{0}", name);
+            m_currentOperation = new LogicalOperation(name, m_currentOperation);
+        }
+
+        public void EndLogicalOperation() {
+            if (m_traceBound == m_currentOperation) {
+                TraceEvent(TraceEventType.Error, "Trying to end the operation which isn't belongs to current trace");
+            } else {
+                var op = m_currentOperation;
+                m_currentOperation = m_currentOperation.Parent;
+                TraceEvent(TraceEventType.OperationCompleted, "{0} {1} ms", op.Name, op.Duration);
+            }
+        }
+
+        public void TraceEvent(TraceEventType type, string format, params object[] args) {
+            /*var msg = new StringBuilder();
+            for (int i = 0; i < CurrentOperation.Level; i++)
+                msg.Append("  ");
+            msg.Append(type);
+            msg.AppendFormat("[{0}]: ",m_threadId);
+            msg.AppendFormat(format, args);
+
+            lock (_consoleLock) {
+                Console.ForegroundColor = (ConsoleColor)(m_threadId % 15 + 1);
+                Console.WriteLine(msg.ToString());
+            }*/
+        }
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/LogicalOperation.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -0,0 +1,47 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace Implab.Diagnostics {
+    public class LogicalOperation {
+        readonly LogicalOperation m_parent;
+        readonly string m_name;
+        readonly int m_level;
+        readonly int m_timestamp;
+
+        public LogicalOperation()
+            : this(null, null) {
+        }
+
+        public LogicalOperation(string name, LogicalOperation parent) {
+            m_name = name ?? String.Empty;
+            m_parent = parent;
+
+            m_level = parent == null ? 0 : parent.Level + 1;
+            m_timestamp = Environment.TickCount;
+        }
+
+        public int Duration {
+            get {
+                var dt = Environment.TickCount - m_timestamp;
+                return dt < 0 ? int.MaxValue + dt : dt; // handle overflow
+            }
+        }
+
+        public LogicalOperation Parent {
+            get {
+                return m_parent;
+            }
+        }
+
+        public int Level {
+            get { return m_level; }
+        }
+
+        public string Name {
+            get { return m_name; }
+        }
+    }
+}
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/TraceEventType.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -0,0 +1,16 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+using System.Threading.Tasks;
+
+namespace Implab.Diagnostics {
+    public enum TraceEventType {
+        Information = 1,
+        Warning,
+        Error,
+        OperationStarted,
+        OperationCompleted,
+        Transfer
+    }
+}
--- a/Implab/Implab.csproj	Thu Apr 10 04:20:25 2014 +0400
+++ b/Implab/Implab.csproj	Mon Apr 14 18:25:26 2014 +0400
@@ -15,7 +15,7 @@
     <DebugType>full</DebugType>
     <Optimize>false</Optimize>
     <OutputPath>bin\Debug</OutputPath>
-    <DefineConstants>DEBUG;</DefineConstants>
+    <DefineConstants>TRACE;DEBUG;</DefineConstants>
     <ErrorReport>prompt</ErrorReport>
     <WarningLevel>4</WarningLevel>
     <ConsolePause>false</ConsolePause>
@@ -32,6 +32,11 @@
     <Reference Include="System" />
   </ItemGroup>
   <ItemGroup>
+    <Compile Include="Diagnostics\IEventListener.cs" />
+    <Compile Include="Diagnostics\LogicalOperation.cs" />
+    <Compile Include="Diagnostics\Log.cs" />
+    <Compile Include="Diagnostics\LogContext.cs" />
+    <Compile Include="Diagnostics\TraceEventType.cs" />
     <Compile Include="ICancellable.cs" />
     <Compile Include="IProgressHandler.cs" />
     <Compile Include="IProgressNotifier.cs" />
@@ -43,7 +48,6 @@
     <Compile Include="Parallels\ArrayTraits.cs" />
     <Compile Include="Parallels\MTQueue.cs" />
     <Compile Include="Parallels\WorkerPool.cs" />
-    <Compile Include="PromiseState.cs" />
     <Compile Include="TaskController.cs" />
     <Compile Include="ProgressInitEventArgs.cs" />
     <Compile Include="Properties\AssemblyInfo.cs" />
--- a/Implab/Parallels/AsyncPool.cs	Thu Apr 10 04:20:25 2014 +0400
+++ b/Implab/Parallels/AsyncPool.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -1,3 +1,4 @@
+using Implab.Diagnostics;
 using System;
 using System.Threading;
 
@@ -13,8 +14,10 @@
 
 		public static Promise<T> Invoke<T>(Func<T> func) {
 			var p = new Promise<T>();
+            var caller = LogContext.Current;
 
 			ThreadPool.QueueUserWorkItem(param => {
+                Log.Transfer(caller);
 				try {
 					p.Resolve(func());
 				} catch(Exception e) {
@@ -28,7 +31,10 @@
         public static Promise<T> InvokeNewThread<T>(Func<T> func) {
             var p = new Promise<T>();
 
+            var caller = LogContext.Current;
+
             var worker = new Thread(() => {
+                Log.Transfer(caller);
                 try {
                     p.Resolve(func());
                 } catch (Exception e) {
--- a/Implab/Parallels/WorkerPool.cs	Thu Apr 10 04:20:25 2014 +0400
+++ b/Implab/Parallels/WorkerPool.cs	Mon Apr 14 18:25:26 2014 +0400
@@ -4,6 +4,7 @@
 using System.Text;
 using System.Threading;
 using System.Diagnostics;
+using Implab.Diagnostics;
 
 namespace Implab.Parallels {
     public class WorkerPool : DispatchPool<Action> {
@@ -41,7 +42,10 @@
 
             var promise = new Promise<T>();
 
+            var caller = LogContext.Current;
+
             EnqueueTask(delegate() {
+                Log.Transfer(caller);
                 try {
                     promise.Resolve(task());
                 } catch (Exception e) {
--- a/Implab/PromiseState.cs	Thu Apr 10 04:20:25 2014 +0400
+++ /dev/null	Thu Jan 01 00:00:00 1970 +0000
@@ -1,15 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Linq;
-using System.Text;
-
-namespace Implab
-{
-    public enum PromiseState
-    {
-        Unresolved,
-        Resolved,
-        Cancelled,
-        Rejected
-    }
-}