changeset 48:d9d794b61bb9 interactive logger

Interactive tracing Improved working with tracing contexts
author cin
date Fri, 18 Apr 2014 12:34:45 +0400
parents b181f7bcb259
children 6f335e65b75f
files Implab.Diagnostics.Interactive/InteractiveListener.cs Implab.Diagnostics.Interactive/TraceForm.Designer.cs Implab.Diagnostics.Interactive/TraceForm.cs Implab.Diagnostics.Interactive/TraceForm.resx Implab.Diagnostics.Interactive/TraceViewItem.cs Implab/Diagnostics/ConsoleTraceListener.cs Implab/Diagnostics/LogChannel.cs Implab/Diagnostics/TextFileListener.cs Implab/Diagnostics/TextListenerBase.cs Implab/Diagnostics/TraceContext.cs Implab/Diagnostics/TraceEventType.cs Implab/Disposable.cs Implab/Parallels/ArrayTraits.cs Implab/Parallels/AsyncPool.cs
diffstat 14 files changed, 205 insertions(+), 47 deletions(-) [+]
line wrap: on
line diff
--- a/Implab.Diagnostics.Interactive/InteractiveListener.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab.Diagnostics.Interactive/InteractiveListener.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -9,15 +9,14 @@
 
 namespace Implab.Diagnostics.Interactive
 {
-    public class InteractiveListener: Disposable
+    public class InteractiveListener: TextListenerBase
     {
         TraceForm m_form;
         
         SynchronizationContext m_syncGuiThread;
+        readonly Promise<object> m_guiStarted = new Promise<object>();
         
         readonly IPromiseBase m_guiFinished;
-        readonly Promise<object> m_guiStarted = new Promise<object>();
-
         readonly IPromiseBase m_workerFinished = new Promise<object>();
         
         readonly MTQueue<TraceViewItem> m_queue = new MTQueue<TraceViewItem>();
@@ -30,17 +29,19 @@
         bool m_paused;
         readonly ManualResetEvent m_pauseEvent = new ManualResetEvent(true);
 
-        public InteractiveListener() {
-            m_guiFinished = AsyncPool.InvokeNewThread(() => {
-                GuiThread();
-                return 0;
-            });
+        public InteractiveListener(bool global) : base(global) {
+            m_guiFinished = AsyncPool.InvokeNewThread(GuiThread);
+            m_workerFinished = AsyncPool.InvokeNewThread(QueueThread);
 
             m_guiStarted.Join();
         }
 
         void GuiThread() {
             m_form = new TraceForm(); // will create SynchronizationContext
+
+            m_form.PauseEvents += (s,a) => Pause();
+            m_form.ResumeEvents += (s, a) => Resume();
+
             m_syncGuiThread = SynchronizationContext.Current;
             m_guiStarted.Resolve();
             Application.Run();
@@ -93,6 +94,8 @@
         }
 
         void Terminate() {
+            m_exitPending = true;
+            Resume();            
             m_syncGuiThread.Post(x => Application.ExitThread(), null);
         }
 
@@ -103,5 +106,17 @@
             }
             base.Dispose(disposing);
         }
+
+        protected override void WriteEntry(TraceContext context, EventText text, string channel) {
+            var item = new TraceViewItem {
+                Indent = text.indent,
+                Message = text.content,
+                Thread = context.ThreadId,
+                Channel = channel,
+                Timestamp = Environment.TickCount
+            };
+
+            Enqueue(item);
+        }
     }
 }
--- a/Implab.Diagnostics.Interactive/TraceForm.Designer.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab.Diagnostics.Interactive/TraceForm.Designer.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -30,6 +30,7 @@
             this.eventsDataGrid = new System.Windows.Forms.DataGridView();
             this.traceViewItemBindingSource = new System.Windows.Forms.BindingSource(this.components);
             this.threadDataGridViewTextBoxColumn = new System.Windows.Forms.DataGridViewTextBoxColumn();
+            this.Channel = new System.Windows.Forms.DataGridViewTextBoxColumn();
             this.messageDataGridViewTextBoxColumn = new System.Windows.Forms.DataGridViewTextBoxColumn();
             ((System.ComponentModel.ISupportInitialize)(this.eventsDataGrid)).BeginInit();
             ((System.ComponentModel.ISupportInitialize)(this.traceViewItemBindingSource)).BeginInit();
@@ -55,6 +56,7 @@
             this.eventsDataGrid.ColumnHeadersHeightSizeMode = System.Windows.Forms.DataGridViewColumnHeadersHeightSizeMode.AutoSize;
             this.eventsDataGrid.Columns.AddRange(new System.Windows.Forms.DataGridViewColumn[] {
             this.threadDataGridViewTextBoxColumn,
+            this.Channel,
             this.messageDataGridViewTextBoxColumn});
             this.eventsDataGrid.DataSource = this.traceViewItemBindingSource;
             dataGridViewCellStyle3.Alignment = System.Windows.Forms.DataGridViewContentAlignment.MiddleLeft;
@@ -87,6 +89,15 @@
             this.threadDataGridViewTextBoxColumn.ReadOnly = true;
             this.threadDataGridViewTextBoxColumn.Width = 5;
             // 
+            // Channel
+            // 
+            this.Channel.AutoSizeMode = System.Windows.Forms.DataGridViewAutoSizeColumnMode.DisplayedCells;
+            this.Channel.DataPropertyName = "Channel";
+            this.Channel.HeaderText = "Channel";
+            this.Channel.Name = "Channel";
+            this.Channel.ReadOnly = true;
+            this.Channel.Width = 79;
+            // 
             // messageDataGridViewTextBoxColumn
             // 
             this.messageDataGridViewTextBoxColumn.AutoSizeMode = System.Windows.Forms.DataGridViewAutoSizeColumnMode.Fill;
@@ -116,6 +127,7 @@
         private System.Windows.Forms.DataGridView eventsDataGrid;
         private System.Windows.Forms.BindingSource traceViewItemBindingSource;
         private System.Windows.Forms.DataGridViewTextBoxColumn threadDataGridViewTextBoxColumn;
+        private System.Windows.Forms.DataGridViewTextBoxColumn Channel;
         private System.Windows.Forms.DataGridViewTextBoxColumn messageDataGridViewTextBoxColumn;
 
     }
--- a/Implab.Diagnostics.Interactive/TraceForm.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab.Diagnostics.Interactive/TraceForm.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -13,9 +13,12 @@
         readonly Dictionary<int, Color> m_threadColors = new Dictionary<int,Color>();
         readonly Random m_rand = new Random();
 
+        public event EventHandler PauseEvents;
+
+        public event EventHandler ResumeEvents;
+
         public TraceForm() {
             InitializeComponent();
-
         }
 
         protected override void OnFormClosing(FormClosingEventArgs e) {
@@ -26,18 +29,9 @@
             }
         }
 
-        public void AddTraceEvent(int indent, int thread, string message) {
-            traceViewItemBindingSource.Add(new TraceViewItem {
-                Indent = indent,
-                Thread = thread,
-                Message = message,
-                Timestamp = Environment.TickCount
-            });
-
-        }
-
         public void AddTraceEvent(TraceViewItem item) {
             traceViewItemBindingSource.Add(item);
+            eventsDataGrid.FirstDisplayedScrollingRowIndex = eventsDataGrid.RowCount - 1;
         }
 
         Color GetThreadColor(int thread) {
@@ -51,7 +45,8 @@
 
         private void eventsDataGrid_CellFormatting(object sender, DataGridViewCellFormattingEventArgs e) {
             var data = (TraceViewItem)traceViewItemBindingSource[e.RowIndex];
-            e.CellStyle.Padding = new Padding(data.Indent * 10,0,0,0);
+            if (e.ColumnIndex == messageDataGridViewTextBoxColumn.Index)
+                e.CellStyle.Padding = new Padding(data.Indent * 10,0,0,0);
             e.CellStyle.ForeColor = GetThreadColor(data.Thread);
         }
     }
--- a/Implab.Diagnostics.Interactive/TraceForm.resx	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab.Diagnostics.Interactive/TraceForm.resx	Fri Apr 18 12:34:45 2014 +0400
@@ -117,6 +117,9 @@
   <resheader name="writer">
     <value>System.Resources.ResXResourceWriter, System.Windows.Forms, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089</value>
   </resheader>
+  <metadata name="Channel.UserAddedColumn" type="System.Boolean, mscorlib, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b77a5c561934e089">
+    <value>True</value>
+  </metadata>
   <metadata name="traceViewItemBindingSource.TrayLocation" type="System.Drawing.Point, System.Drawing, Version=4.0.0.0, Culture=neutral, PublicKeyToken=b03f5f7f11d50a3a">
     <value>17, 17</value>
   </metadata>
--- a/Implab.Diagnostics.Interactive/TraceViewItem.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab.Diagnostics.Interactive/TraceViewItem.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -12,6 +12,7 @@
         public int Timestamp { get; set; }
         public int Indent { get; set; }
         public int Thread { get; set; }
+        public string Channel { get; set; }
 
         public string FormattedMessage {
             get {
--- a/Implab/Diagnostics/ConsoleTraceListener.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/ConsoleTraceListener.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -13,17 +13,17 @@
 
         }
 
-        public ConsoleTraceListener(bool local)
-            : base(local) {
+        public ConsoleTraceListener(bool global)
+            : base(global) {
 
         }
 
-        protected override void WriteEntry(TraceContext context, EventText text) {
+        protected override void WriteEntry(TraceContext context, EventText text, string channel) {
             var msg = new StringBuilder();
 
             for (int i = 0; i < text.indent; i++)
                 msg.Append("  ");
-            msg.AppendFormat("[{0}]: {1}", context.ThreadId, text.content);
+            msg.AppendFormat("[{0}]:{1}: {2}", context.ThreadId, channel, text.content);
 
             lock (_consoleLock) {
                 Console.ForegroundColor = (ConsoleColor)(context.ThreadId % 15 + 1);
--- a/Implab/Diagnostics/LogChannel.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/LogChannel.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -4,23 +4,74 @@
 using System.Text;
 
 namespace Implab.Diagnostics {
+    /// <summary>
+    /// Канал, через который публикуются события журнала.
+    /// </summary>
+    /// <typeparam name="TEvent">Тип событий в канале</typeparam>
+    /// <remarks>
+    /// Событиями журнала могут быть любые типы, например строки, в которых будет передаваться
+    /// информация, или структуры с набором полей, описывающих  важность, текст и другую информацию.
+    /// </remarks>
     public class LogChannel<TEvent> {
         static LogChannel<TEvent> _default = new LogChannel<TEvent>();
 
+        /// <summary>
+        /// Канал по-умолчанию для событий типа <typeparam name="TEvent"/>.
+        /// </summary>
         public static LogChannel<TEvent> Default {
             get {
                 return _default;
             }
         }
 
+        /// <summary>
+        /// Событие появление новой записи в журнале, на это событие подписываются слушатели.
+        /// </summary>
         public event EventHandler<ValueEventArgs<TEvent>> Events;
+        
+        /// <summary>
+        /// Имя канала, полезно для отображения в журнале
+        /// </summary>
+        public string Name {
+            get;
+            private set;
+        }
 
+        /// <summary>
+        /// Создает журнал, имя типа событий назначается в качетве имени канала.
+        /// </summary>
+        public LogChannel()
+            : this(null) {
+        }
+
+        /// <summary>
+        /// Содает канал с указанным именем.
+        /// </summary>
+        /// <param name="name">Имя канала.</param>
+        public LogChannel(string name) {
+            if (String.IsNullOrEmpty(name))
+                name = typeof(TEvent).Name;
+            Name = name;
+        }
+
+        /// <summary>
+        /// Отправляет запись журнала через канал подписчикам.
+        /// </summary>
+        /// <param name="data">Запись журнала.</param>
+        /// <remarks>
+        /// Контекст трассировки от которого рассылается сообщение определяется автоматически из текущего потока.
+        /// </remarks>
         public void LogEvent(TEvent data) {
             var t = Events;
             if (t!= null)
                 t(TraceContext.Current,new ValueEventArgs<TEvent>(data));
         }
 
+        /// <summary>
+        /// Отправляет запись журнала через канал подписчикам.
+        /// </summary>
+        /// <param name="data">Запись журнала.</param>
+        /// <param name="context">Контекст трассировки от которого рассылается сообщение/</param>
         public void LogEvent(TraceContext context,TEvent data) {
             var t = Events;
             if (t != null)
--- a/Implab/Diagnostics/TextFileListener.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/TextFileListener.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -8,18 +8,19 @@
     public class TextFileListener: TextListenerBase {
         readonly TextWriter m_textWriter;
 
-        public TextFileListener(string fileName, bool local) : base(local) {
+        public TextFileListener(string fileName, bool global)
+            : base(global) {
             m_textWriter = File.CreateText(fileName);
 
             m_textWriter.WriteLine("LOG {0}", DateTime.Now);
             Register(this);
         }
 
-        protected override void WriteEntry(TraceContext context, EventText text) {
+        protected override void WriteEntry(TraceContext context, EventText text, string channel) {
             var msg = new StringBuilder();
             for (int i = 0; i < text.indent; i++)
                 msg.Append("  ");
-            msg.AppendFormat("[{0}]: {1}", context.ThreadId, text.content);
+            msg.AppendFormat("[{0}]:{1}: {2}", context.ThreadId, channel, text.content);
 
             lock (m_textWriter) {
                 if (!IsDisposed) {
--- a/Implab/Diagnostics/TextListenerBase.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/TextListenerBase.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -10,9 +10,9 @@
         readonly LogicalOperation m_boundOperation;
         readonly int m_baseIndent;
 
-        protected TextListenerBase(bool local) {
+        protected TextListenerBase(bool global) {
             Register(this);
-            if (local) {
+            if (!global) {
                 m_boundOperation = TraceContext.Current.CurrentOperation;
                 m_baseIndent = Math.Max(0, m_boundOperation.Level - 1);
             }
@@ -36,6 +36,7 @@
                 AssertNotDisposed();
 
                 var formatter = GetService<IEventTextFormatter<TEvent>>();
+                var channelName = channel.Name;
 
                 EventHandler<ValueEventArgs<TEvent>> handler = (sender, args) => {
                     TraceContext context = (TraceContext)sender;
@@ -43,7 +44,7 @@
                     text.indent -= m_baseIndent;
 
                     if (IsRelated(context.CurrentOperation))
-                        WriteEntry(context, text);
+                        WriteEntry(context, text, channelName);
                 };
 
                 if (m_subscriptions.ContainsKey(channel))
@@ -98,7 +99,7 @@
         /// </remarks>
         /// <param name="context">Контекст трассировки.</param>
         /// <param name="text">Текст сообщения.</param>
-        protected abstract void WriteEntry(TraceContext context, EventText text);
+        protected abstract void WriteEntry(TraceContext context, EventText text, string channel);
         
         public EventText Format(TraceContext context, object data) {
             return new EventText {
--- a/Implab/Diagnostics/TraceContext.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/TraceContext.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -25,18 +25,24 @@
         /// </summary>
         public static TraceContext Current {
             get {
-                if (_current == null)
+                if (_current == null) {
                     _current = new TraceContext();
+                    _current.LogEvent(TraceEventType.Created,"[{0}]", _current.ThreadId);
+                }
                 return _current;
             }
         }
 
-        TraceContext(TraceContext context) {
+        TraceContext(TraceContext context)
+            : this(context, false) {
+        }
+
+        TraceContext(TraceContext context, bool attach) {
             if (context == null)
                 throw new ArgumentNullException("context");
 
             m_currentOperation = context.CurrentOperation;
-            m_bound = context.CurrentOperation;
+            m_bound = attach ? context.BoundOperation : context.CurrentOperation;
             m_threadId = Thread.CurrentThread.ManagedThreadId;
         }
 
@@ -57,15 +63,15 @@
         /// контексте ранее начатые логические операции не могут быть завершены.
         /// </para>
         /// <para>
-        /// Если передача состояния состоялась, то вызывается событие трассировки <see cref="TraceEventType.Transfer"/>.
+        /// Если передача состояния состоялась, то вызывается событие трассировки <see cref="TraceEventType.Fork"/>.
         /// </para>
         /// </remarks>
-        public static void Transfer(TraceContext from) {
+        public static void Fork(TraceContext from) {
             if (_current == from)
                 return;
             if (from != null) {
                 var context = new TraceContext(from);
-                context.LogEvent(TraceEventType.Transfer, "[{0}]-->[{1}]",from.ThreadId, context.ThreadId);
+                context.LogEvent(TraceEventType.Fork, "[{0}]-->[{1}]",from.ThreadId, context.ThreadId);
                 _current = context;
             } else {
                 _current = new TraceContext();
@@ -73,7 +79,40 @@
         }
 
         /// <summary>
-        /// Создает постоянную копию текущего контекста, данную копию можно хранить и использовать для передачи через <see cref="Transfer(TraceContext)"/>
+        /// Задает текущему потоку указанный контекст, текущей поток может заканчивать ранее начатые
+        /// логические операции в указанном контексте.
+        /// </summary>
+        /// <param name="source"></param>
+        public static void Attach(TraceContext source) {
+            if (_current == source)
+                return;
+            if (source != null) {
+                var context = new TraceContext(source, true);
+                context.LogEvent(TraceEventType.Attach, "[{0}]-->[{1}]", source.ThreadId, context.ThreadId);
+                _current = context;
+            } else {
+                _current = new TraceContext();
+            }
+        }
+
+        /// <summary>
+        /// Отсоединяет текущий контекст трассировки от потока, для дальнейшей его передачи другому потоку
+        /// <see cref="Attach(TraceContext)"/>.
+        /// </summary>
+        /// <returns>Контекст трассировки потока</returns>
+        /// <remarks>
+        /// После отсоединения контекста трассировки от потока, при первом обращении к трассировке в этом
+        /// потоке будет создан новый контекст.
+        /// </remarks>
+        public static TraceContext Detach() {
+            var context = Current;
+            context.LogEvent(TraceEventType.Detach, null);
+            _current = null;
+            return context;
+        }
+
+        /// <summary>
+        /// Создает постоянную копию текущего контекста, данную копию можно хранить и использовать для передачи через <see cref="Fork(TraceContext)"/>
         /// </summary>
         /// <returns>Копия текущего контекста трассировки.</returns>
         public static TraceContext Snapshot() {
@@ -88,7 +127,7 @@
             if (action == null)
                 throw new ArgumentNullException("action");
             var old = _current;
-            Transfer(this);
+            Fork(this);
             try {
                 action();
             } finally {
--- a/Implab/Diagnostics/TraceEventType.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Diagnostics/TraceEventType.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -11,6 +11,9 @@
         Error,
         OperationStarted,
         OperationCompleted,
-        Transfer
+        Fork,
+        Attach,
+        Detach,
+        Created
     }
 }
--- a/Implab/Disposable.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Disposable.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -1,10 +1,14 @@
-using System;
+using Implab.Diagnostics;
+using System;
 using System.Collections.Generic;
 using System.Diagnostics;
 using System.Linq;
 using System.Web;
 
 namespace Implab {
+    /// <summary>
+    /// Объект, поддерживающий освобождение ресурсов.
+    /// </summary>
     public class Disposable : IDisposable {
         
         bool m_disposed;
@@ -19,7 +23,16 @@
             if (m_disposed)
                 throw new ObjectDisposedException(this.ToString());
         }
-
+        /// <summary>
+        /// Переводит объект в состояние <c>Disposed</c> и вызывает событие <see cref="Disposed"/>
+        /// </summary>
+        /// <param name="disposing">Признак того, что нужно освободить ресурсы, иначе данный метод
+        /// вызван сборщиком мусора и нужно освобождать ТОЛЬКО неуправляемые ресурсы ТОЛЬКО этого
+        /// объекта.</param>
+        /// <remarks>
+        /// Данный метод осуществляет проверку того, что объект уже был освобожден, чтобы не вызывать
+        /// событие <see cref="Disposed"/>. Не поддерживает многопоточность.
+        /// </remarks>
         protected virtual void Dispose(bool disposing) {
             if (disposing && !m_disposed) {
                 m_disposed = true;
@@ -34,8 +47,11 @@
             GC.SuppressFinalize(this);
         }
 
+        /// <summary>
+        /// Записывает сообщение об утечке объекта.
+        /// </summary>
         protected virtual void ReportObjectLeaks() {
-            Trace.TraceWarning("The object is marked as disposable but isn't disposed properly: {0}", this);
+            TraceLog.TraceWarning("The object is marked as disposable but isn't disposed properly: {0}", this);
         }
 
         ~Disposable() {
--- a/Implab/Parallels/ArrayTraits.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Parallels/ArrayTraits.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -42,7 +42,7 @@
             }
 
             protected override void Worker() {
-                TraceContext.Transfer(m_traceContext);
+                TraceContext.Fork(m_traceContext);
                 base.Worker();
             }
 
@@ -99,7 +99,7 @@
             }
 
             protected override void Worker() {
-                TraceContext.Transfer(m_traceContext);
+                TraceContext.Fork(m_traceContext);
                 base.Worker();
             }
 
--- a/Implab/Parallels/AsyncPool.cs	Thu Apr 17 18:49:36 2014 +0400
+++ b/Implab/Parallels/AsyncPool.cs	Fri Apr 18 12:34:45 2014 +0400
@@ -17,7 +17,7 @@
             var caller = TraceContext.Snapshot();
 
 			ThreadPool.QueueUserWorkItem(param => {
-                TraceContext.Transfer(caller);
+                TraceContext.Fork(caller);
 				try {
 					p.Resolve(func());
 				} catch(Exception e) {
@@ -34,7 +34,7 @@
             var caller = TraceContext.Snapshot();
 
             var worker = new Thread(() => {
-                TraceContext.Transfer(caller);
+                TraceContext.Fork(caller);
                 try {
                     p.Resolve(func());
                 } catch (Exception e) {
@@ -46,5 +46,26 @@
 
             return p;
         }
+
+
+        public static IPromiseBase InvokeNewThread(Action func) {
+            var p = new Promise<object>();
+
+            var caller = TraceContext.Snapshot();
+
+            var worker = new Thread(() => {
+                TraceContext.Fork(caller);
+                try {
+                    func();
+                    p.Resolve();
+                } catch (Exception e) {
+                    p.Reject(e);
+                }
+            });
+            worker.IsBackground = true;
+            worker.Start();
+
+            return p;
+        }
 	}
 }