# HG changeset patch
# User cin
# Date 1423609935 -10800
# Node ID 04d4c92d0f28562655eb67672d696354dc284d3e
# Parent  6c49d02a9a05d095acfc359a957b7efebb3cc8c5
Improved logging

diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab.Diagnostics.Interactive/InteractiveListener.cs
--- a/Implab.Diagnostics.Interactive/InteractiveListener.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab.Diagnostics.Interactive/InteractiveListener.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -9,7 +9,7 @@
 
 namespace Implab.Diagnostics.Interactive
 {
-    public class InteractiveListener: TextListenerBase
+    public class InteractiveListener: ListenerBase
     {
         TraceForm m_form;
         
@@ -29,7 +29,7 @@
         bool m_paused;
         readonly ManualResetEvent m_pauseEvent = new ManualResetEvent(true);
 
-        public InteractiveListener(bool global) : base(global) {
+        public InteractiveListener() {
             m_guiFinished = AsyncPool.RunThread(GuiThread);
             /*m_workerFinished = */AsyncPool.RunThread(QueueThread);
 
@@ -107,12 +107,12 @@
             base.Dispose(disposing);
         }
 
-        protected override void WriteEntry(LogEventArgs args, EventText text, string channel) {
+        public override void Write(LogEventArgs args, object entry) {
             var item = new TraceViewItem {
-                Indent = text.indent,
-                Message = text.content,
+                Indent = args.Operation.Level,
+                Message = entry.ToString(),
                 Thread = args.ThreadId,
-                Channel = channel,
+                Channel = args.ChannelName,
                 Timestamp = Environment.TickCount
             };
 
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/ConsoleTraceListener.cs
--- a/Implab/Diagnostics/ConsoleTraceListener.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/ConsoleTraceListener.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -1,29 +1,17 @@
 using System;
-using System.Collections.Generic;
-using System.Linq;
 using System.Text;
 
 namespace Implab.Diagnostics {
-    public class ConsoleTraceListener: TextListenerBase {
+    public class ConsoleTraceListener: ListenerBase {
 
         static readonly object _consoleLock = new object();
 
-        public ConsoleTraceListener()
-            : base(true) {
-
-        }
-
-        public ConsoleTraceListener(bool global)
-            : base(global) {
-
-        }
-
-        protected override void WriteEntry(LogEventArgs args, EventText text, string channel) {
+        public override void Write(LogEventArgs args, object entry) {
             var msg = new StringBuilder();
 
-            for (int i = 0; i < text.indent; i++)
+            for (int i = 0; i < args.Operation.Level; i++)
                 msg.Append("  ");
-            msg.AppendFormat("[{0}]: {1}", args.ThreadId, text.content);
+            msg.AppendFormat("[{0}]: {1}", args.ThreadId, entry);
 
             lock (_consoleLock) {
                 Console.ForegroundColor = (ConsoleColor)(args.ThreadId % 15 + 1);
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/Extensions.cs
--- a/Implab/Diagnostics/Extensions.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/Extensions.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -1,6 +1,4 @@
-using System;
-
-namespace Implab.Diagnostics {
+namespace Implab.Diagnostics {
     public static class Extensions {
         public static IPromise<T> EndLogicalOperation<T>(this IPromise<T> promise) {
             Safe.ArgumentNotNull(promise, "promise");
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/IEventTextFormatter.cs
--- a/Implab/Diagnostics/IEventTextFormatter.cs	Mon Feb 09 00:28:13 2015 +0300
+++ /dev/null	Thu Jan 01 00:00:00 1970 +0000
@@ -1,5 +0,0 @@
-namespace Implab.Diagnostics {
-    public interface IEventTextFormatter<in TEvent> {
-        EventText Format(LogEventArgs args, TEvent data);
-    }
-}
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/ILogWriter.cs
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/ILogWriter.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -0,0 +1,8 @@
+using System;
+
+namespace Implab.Diagnostics {
+    public interface ILogWriter<in TEvent> {
+        void Write(LogEventArgs args, TEvent entry);
+    }
+}
+
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/ListenerBase.cs
--- /dev/null	Thu Jan 01 00:00:00 1970 +0000
+++ b/Implab/Diagnostics/ListenerBase.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -0,0 +1,87 @@
+using System;
+using System.Collections.Generic;
+using System.Linq;
+using System.Text;
+
+namespace Implab.Diagnostics {
+    public abstract class ListenerBase : ServiceLocator, ILogWriter<object>, ILogWriter<TraceEvent> {
+
+        readonly Dictionary<object, Action> m_subscriptions = new Dictionary<object, Action>();
+
+        protected ListenerBase() {
+            Register(this);
+        }
+
+        public void Subscribe(Type eventType) {
+            if (eventType == null)
+                throw new ArgumentNullException("eventType");
+            GetType().GetMethod("Subscribe", new Type[0]).MakeGenericMethod(eventType).Invoke(this, null);
+        }
+
+        public void Subscribe<TEvent>() {
+            Subscribe<TEvent>(LogChannel<TEvent>.Default);
+        }
+
+        public void Subscribe<TEvent>(LogChannel<TEvent> channel) {
+            if (channel == null)
+                throw new ArgumentNullException("channel");
+
+            lock (m_subscriptions) {
+                AssertNotDisposed();
+                if (m_subscriptions.ContainsKey(channel))
+                    return;
+
+                var writer = GetService<ILogWriter<TEvent>>();
+
+                EventHandler<LogEventArgs<TEvent>> handler = (sender, args) => writer.Write(args,args.Value);
+
+                channel.Events += handler;
+
+                Action unsubscribe = () => {
+                    channel.Events -= handler;
+                };
+
+                m_subscriptions.Add(channel, unsubscribe);
+            }
+        }
+
+        public void Unsubscribe<TEvent>(LogChannel<TEvent> channel) {
+            if (channel == null)
+                throw new ArgumentNullException("channel");
+
+            lock (m_subscriptions) {
+                Action subscription;
+                if (m_subscriptions.TryGetValue(channel, out subscription)) {
+                    subscription();
+                    m_subscriptions.Remove(channel);
+                }
+            }
+        }
+
+        public void UnsubscribeAll() {
+            lock (m_subscriptions) {
+                foreach (var subscription in m_subscriptions.Values)
+                    subscription();
+                m_subscriptions.Clear();
+            }
+        }
+
+        #region ILogWriter implementation
+        public abstract void Write(LogEventArgs args, object entry);
+        #endregion
+
+        #region ILogWriter implementation
+        public virtual void Write(LogEventArgs args, TraceEvent entry) {
+            Write(args, (object)entry);
+        }
+        #endregion
+
+
+        protected override void Dispose(bool disposing) {
+            base.Dispose(disposing);
+            if (disposing) {
+                UnsubscribeAll();
+            }
+        }
+    }
+}
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/LogChannel.cs
--- a/Implab/Diagnostics/LogChannel.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/LogChannel.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -69,6 +69,7 @@
                     this,
                     new LogEventArgs<TEvent>(
                         data,
+                        Name,
                         traceContext.ThreadId,
                         traceContext.CurrentOperation,
                         traceContext.CurrentOperation.Duration
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/LogEventArgs.cs
--- a/Implab/Diagnostics/LogEventArgs.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/LogEventArgs.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -2,6 +2,10 @@
 
 namespace Implab.Diagnostics {
     public class LogEventArgs : EventArgs {
+        public string ChannelName {
+            get;
+            private set;
+        }
         public int ThreadId {
             get;
             private set;
@@ -14,7 +18,8 @@
             get;
             private set;
         }
-        public LogEventArgs(int threadId, LogicalOperation operation, int timeOffset) {
+        public LogEventArgs(string channelName, int threadId, LogicalOperation operation, int timeOffset) {
+            ChannelName = channelName;
             ThreadId = threadId;
             Operation = operation;
             OperationTimeOffset = timeOffset;
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/LogEventArgsT.cs
--- a/Implab/Diagnostics/LogEventArgsT.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/LogEventArgsT.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -5,7 +5,7 @@
             private set;
         }
 
-        public LogEventArgs(TEvent value, int threadId, LogicalOperation operation, int timeOffset) : base(threadId, operation, timeOffset) {
+        public LogEventArgs(TEvent value,string channelName, int threadId, LogicalOperation operation, int timeOffset) : base(channelName, threadId, operation, timeOffset) {
             Value = value;
         }
     }
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/OperationContext.cs
--- a/Implab/Diagnostics/OperationContext.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/OperationContext.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -1,9 +1,10 @@
 namespace Implab.Diagnostics {
     struct OperationContext {
-        readonly LogicalOperation m_initial;
         public readonly static OperationContext EMPTY = new OperationContext(LogicalOperation.EMPTY, false);
+
+        LogicalOperation m_initial;
         LogicalOperation m_current;
-        readonly bool m_ownership;
+        bool m_ownership;
 
         public OperationContext(LogicalOperation operation, bool ownership) {
             Safe.ArgumentNotNull(operation, "operation");
@@ -39,14 +40,19 @@
             return detached;
         }
 
-        public void EndLogicalOperation() {
-            if (m_current != m_initial) {
+        public LogicalOperation EndLogicalOperation() {
+            var current = m_current;
+            if (m_current != LogicalOperation.EMPTY && (m_current != m_initial || m_ownership)) {
                 m_current = m_current.Parent;
-            } else if (m_current != LogicalOperation.EMPTY && m_ownership) {
-                m_current = LogicalOperation.EMPTY;
+                if (current == m_initial) {
+                    // we have complete the owned operation
+                    m_initial = m_current;
+                    m_ownership = false;
+                }
             } else {
                 TraceLog.TraceWarning("EndLogicalOperation can't be applied in the current context");
             }
+            return current;
         }
 
         public void Leave() {
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/TextFileListener.cs
--- a/Implab/Diagnostics/TextFileListener.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/TextFileListener.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -3,22 +3,22 @@
 using System.Text;
 
 namespace Implab.Diagnostics {
-    public class TextFileListener: TextListenerBase {
+    public class TextFileListener: ListenerBase {
         readonly TextWriter m_textWriter;
 
-        public TextFileListener(string fileName, bool global)
-            : base(global) {
+        public TextFileListener(string fileName) {
             m_textWriter = File.CreateText(fileName);
 
             m_textWriter.WriteLine("LOG {0}", DateTime.Now);
-            Register(this);
         }
 
-        protected override void WriteEntry(LogEventArgs args, EventText text, string channel) {
+        #region implemented abstract members of ListenerBase
+
+        public override void Write(LogEventArgs args, object entry) {
             var msg = new StringBuilder();
-            for (int i = 0; i < text.indent; i++)
+            for (int i = 0; i < args.Operation.Level; i++)
                 msg.Append("  ");
-            msg.AppendFormat("[{0}]:{1}: {2}", args.ThreadId, channel, text.content);
+            msg.AppendFormat("[{0}]:{1}: {2}", args.ThreadId, args.ChannelName, entry);
 
             lock (m_textWriter) {
                 if (!IsDisposed) {
@@ -29,7 +29,8 @@
             }
         }
 
-        
+        #endregion
+
         protected override void Dispose(bool disposing) {
             base.Dispose(disposing);
             if (disposing) {
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/TextListenerBase.cs
--- a/Implab/Diagnostics/TextListenerBase.cs	Mon Feb 09 00:28:13 2015 +0300
+++ /dev/null	Thu Jan 01 00:00:00 1970 +0000
@@ -1,128 +0,0 @@
-using System;
-using System.Collections.Generic;
-using System.Linq;
-using System.Text;
-
-namespace Implab.Diagnostics {
-    public abstract class TextListenerBase : ServiceLocator, IEventTextFormatter<object>, IEventTextFormatter<TraceEvent> {
-
-        readonly Dictionary<object, Action> m_subscriptions = new Dictionary<object, Action>();
-        readonly LogicalOperation m_boundOperation;
-        readonly int m_baseIndent;
-
-        protected TextListenerBase(bool global) {
-            Register(this);
-            if (!global) {
-                m_boundOperation = TraceContext.Instance.CurrentOperation;
-                m_baseIndent = Math.Max(0, m_boundOperation.Level - 1);
-            }
-        }
-
-        public void Subscribe(Type eventType) {
-            if (eventType == null)
-                throw new ArgumentNullException("eventType");
-            GetType().GetMethod("Subscribe", new Type[0]).MakeGenericMethod(eventType).Invoke(this, null);
-        }
-
-        public void Subscribe<TEvent>() {
-            Subscribe<TEvent>(LogChannel<TEvent>.Default);
-        }
-
-        public void Subscribe<TEvent>(LogChannel<TEvent> channel) {
-            if (channel == null)
-                throw new ArgumentNullException("channel");
-
-            lock (m_subscriptions) {
-                AssertNotDisposed();
-
-                var formatter = GetService<IEventTextFormatter<TEvent>>();
-                var channelName = channel.Name;
-
-                EventHandler<LogEventArgs<TEvent>> handler = (sender, args) => {
-                    var text = formatter.Format(args, args.Value);
-                    text.indent -= m_baseIndent;
-
-                    if (IsRelated(args.Operation))
-                        WriteEntry(args, text, channelName);
-                };
-
-                if (m_subscriptions.ContainsKey(channel))
-                    return;
-
-                channel.Events += handler;
-
-                Action unsubscribe = () => {
-                    channel.Events -= handler;
-                };
-
-                m_subscriptions.Add(channel, unsubscribe);
-            }
-        }
-
-        public bool IsRelated(LogicalOperation op) {
-            if (m_boundOperation == null)
-                return true;
-
-            while (op != m_boundOperation && op.Level > m_boundOperation.Level)
-                op = op.Parent;
-            return op == m_boundOperation;
-        }
-
-        public void Unsubscribe<TEvent>(LogChannel<TEvent> channel) {
-            if (channel == null)
-                throw new ArgumentNullException("channel");
-
-            lock (m_subscriptions) {
-                Action subscription;
-                if (m_subscriptions.TryGetValue(channel, out subscription)) {
-                    subscription();
-                    m_subscriptions.Remove(channel);
-                }
-            }
-        }
-
-        public void UnsubscribeAll() {
-            lock (m_subscriptions) {
-                foreach (var subscription in m_subscriptions.Values)
-                    subscription();
-                m_subscriptions.Clear();
-            }
-        }
-
-        /// <summary>
-        /// Вызывается для записи текста сообщения, в журнал.
-        /// </summary>
-        /// <remarks>
-        /// Данный метод может вызваться из разных потоков одновременно. Возможна ситуация, когда
-        /// данный метод вызывается уже после освобождения ообъекта методом <see cref="Dispose()"/>.
-        /// </remarks>
-        /// <param name="text">Текст сообщения.</param>
-        /// <param name = "channel"></param>
-        protected abstract void WriteEntry(LogEventArgs args, EventText text, string channel);
-        
-        public EventText Format(LogEventArgs args, object data) {
-            return new EventText {
-                indent = args.Operation.Level,
-                content = data.ToString()
-            };
-        }
-
-        public EventText Format(LogEventArgs args, TraceEvent data) {
-            var level = args.Operation.Level;
-            if (data.EventType == TraceEventType.OperationCompleted || data.EventType == TraceEventType.OperationStarted)
-                level--;
-
-            return new EventText {
-                indent = level,
-                content = data.ToString()
-            };
-        }
-
-        protected override void Dispose(bool disposing) {
-            base.Dispose(disposing);
-            if (disposing) {
-                UnsubscribeAll();
-            }
-        }
-    }
-}
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Diagnostics/TraceContext.cs
--- a/Implab/Diagnostics/TraceContext.cs	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Diagnostics/TraceContext.cs	Wed Feb 11 02:12:15 2015 +0300
@@ -42,14 +42,14 @@
 
         public void EnterLogicalOperation(LogicalOperation operation, bool takeOwnership) {
             //var prev = CurrentOperation;
+            //LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(takeOwnership ? TraceEventType.Attach : TraceEventType.Enter, String.Format("{0} -> {1}",prev.Name, operation.Name)));
             m_stack.Push(m_current);
             m_current = new OperationContext(operation, takeOwnership);
-            //LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(takeOwnership ? TraceEventType.Attach : TraceEventType.Enter, String.Format("{0} -> {1}",prev.Name, operation.Name)));
         }
 
         public void StartLogicalOperation(string name) {
+            LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(TraceEventType.OperationStarted, name));
             m_current.BeginLogicalOperation(name);
-            LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(TraceEventType.OperationStarted, String.Format("+{0}",CurrentOperation.Name)));
         }
 
         public void StartLogicalOperation() {
@@ -57,8 +57,8 @@
         }
 
         public void EndLogicalOperation() {
-            LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(TraceEventType.OperationCompleted, String.Format("-{0} : {1}ms",CurrentOperation.Name, CurrentOperation.Duration)));
-            m_current.EndLogicalOperation();
+            var op = m_current.EndLogicalOperation();
+            LogChannel<TraceEvent>.Default.LogEvent(new TraceEvent(TraceEventType.OperationCompleted, String.Format("-{0} : {1}ms",op.Name, op.Duration)));
         }
 
         public LogicalOperation DetachLogicalOperation() {
diff -r 6c49d02a9a05 -r 04d4c92d0f28 Implab/Implab.csproj
--- a/Implab/Implab.csproj	Mon Feb 09 00:28:13 2015 +0300
+++ b/Implab/Implab.csproj	Wed Feb 11 02:12:15 2015 +0300
@@ -74,11 +74,9 @@
     <Compile Include="CustomEqualityComparer.cs" />
     <Compile Include="Diagnostics\ConsoleTraceListener.cs" />
     <Compile Include="Diagnostics\EventText.cs" />
-    <Compile Include="Diagnostics\IEventTextFormatter.cs" />
     <Compile Include="Diagnostics\LogChannel.cs" />
     <Compile Include="Diagnostics\LogicalOperation.cs" />
     <Compile Include="Diagnostics\TextFileListener.cs" />
-    <Compile Include="Diagnostics\TextListenerBase.cs" />
     <Compile Include="Diagnostics\TraceLog.cs" />
     <Compile Include="Diagnostics\TraceEvent.cs" />
     <Compile Include="Diagnostics\TraceEventType.cs" />
@@ -155,6 +153,8 @@
     <Compile Include="PromiseTransientException.cs" />
     <Compile Include="Parallels\Signal.cs" />
     <Compile Include="Parallels\SharedLock.cs" />
+    <Compile Include="Diagnostics\ILogWriter.cs" />
+    <Compile Include="Diagnostics\ListenerBase.cs" />
   </ItemGroup>
   <Import Project="$(MSBuildBinPath)\Microsoft.CSharp.targets" />
   <ItemGroup />