From: Jean-Philippe Bruyère Date: Thu, 18 Jun 2020 20:22:26 +0000 (+0200) Subject: Debug logger improvments and visualization X-Git-Tag: v0.9.5-beta~113^2~7 X-Git-Url: https://git.osiis.dedyn.io/?a=commitdiff_plain;h=5b48f0fa5b96b3336ac2da2d69bddccab304250a;p=jp%2Fcrow.git Debug logger improvments and visualization --- diff --git a/Crow/src/Interface.cs b/Crow/src/Interface.cs index 8babc221..8d4766ff 100644 --- a/Crow/src/Interface.cs +++ b/Crow/src/Interface.cs @@ -114,13 +114,6 @@ namespace Crow }; t.Start (); } - -#if MEASURE_TIME - PerfMeasures.Add (updateMeasure); - PerfMeasures.Add (drawingMeasure); - PerfMeasures.Add (layoutingMeasure); - PerfMeasures.Add (clippingMeasure); -#endif } #endregion @@ -221,27 +214,29 @@ namespace Crow while (!Glfw3.WindowShouldClose (hWin)) { Update (); Thread.Sleep (UPDATE_INTERVAL); -#if MEASURE_TIME - foreach (PerformanceMeasure m in PerfMeasures) - m.NotifyChanges (); -#endif } } protected virtual void OnInitialized () { - try { + /*try { Load ("#main.crow").DataSource = this; - } catch { } + } catch { }*/ Initialized.Raise (this, null); } /// /// load styling, init default tooltips and context menus, load main.crow resource if exists. /// public void Init () { +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceInit); +#endif loadStyling (); initTooltip (); initContextMenus (); OnInitialized (); +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceInit); +#endif } /// /// call Init() then enter the running loop performing ProcessEvents until running==false. @@ -560,8 +555,14 @@ namespace Crow public Widget Load (string path) { lock (UpdateMutex) { + #if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceLoad); + #endif Widget tmp = CreateInstance (path); AddWidget (tmp); + #if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceLoad); + #endif return tmp; } } @@ -613,21 +614,13 @@ namespace Crow _activeWidget = value; - #if DEBUG_FOCUS +#if DEBUG_LOG NotifyValueChanged("ActiveWidget", _activeWidget); - #endif + DbgLogger.AddEvent (DbgEvtType.ActiveWidget, _activeWidget); +#endif if (_activeWidget != null) - { _activeWidget.IsActive = true; - #if DEBUG_FOCUS - NotifyValueChanged("ActiveWidget", _activeWidget); - Debug.WriteLine("Active => " + _activeWidget.ToString()); - }else - Debug.WriteLine("Active => null"); - #else - } - #endif } } /// Pointer is over the widget @@ -643,9 +636,10 @@ namespace Crow _hoverWidget = value; - #if DEBUG_FOCUS +#if DEBUG_LOG NotifyValueChanged("HoverWidget", _hoverWidget); - #endif + DbgLogger.AddEvent (DbgEvtType.HoverWidget, _hoverWidget); +#endif if (DragAndDropOperation == null && FOCUS_ON_HOVER) { Widget w = _hoverWidget; @@ -659,15 +653,7 @@ namespace Crow } if (_hoverWidget != null) - { _hoverWidget.IsHover = true; -#if DEBUG_FOCUS - Debug.WriteLine("Hover => " + _hoverWidget.ToString()); - }else - Debug.WriteLine("Hover => null"); -#else - } -#endif } } /// Widget has the keyboard or mouse focus @@ -679,19 +665,12 @@ namespace Crow if (_focusedWidget != null) _focusedWidget.HasFocus = false; _focusedWidget = value; - #if DEBUG_FOCUS +#if DEBUG_LOG NotifyValueChanged("FocusedWidget", _focusedWidget); - #endif + DbgLogger.AddEvent (DbgEvtType.FocusedWidget, _focusedWidget); +#endif if (_focusedWidget != null) - { _focusedWidget.HasFocus = true; -#if DEBUG_FOCUS - Debug.WriteLine ("Focus => " + _hoverWidget.ToString ()); - } else - Debug.WriteLine ("Focus => null"); -#else - } -#endif } } #endregion @@ -707,7 +686,7 @@ namespace Crow if (g.IsQueueForClipping) return; #if DEBUG_LOG - DebugLog.AddEvent(DbgEvtType.GOEnqueueForRepaint, g); + DbgLogger.AddEvent(DbgEvtType.GOEnqueueForRepaint, g); #endif ClippingQueue.Enqueue (g); g.IsQueueForClipping = true; @@ -742,14 +721,10 @@ namespace Crow if (!Monitor.TryEnter (UpdateMutex)) return; - - #if MEASURE_TIME - updateMeasure.StartCycle(); - #endif - - /*#if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.IFaceUpdate); - #endif*/ + +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceUpdate); +#endif processLayouting (); @@ -761,8 +736,8 @@ namespace Crow }else processDrawing (ctx); -#if MEASURE_TIME - updateMeasure.StopCycle(); +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceUpdate, true); #endif Monitor.Exit (UpdateMutex); @@ -771,14 +746,10 @@ namespace Crow /// Layouting queue items. Failing LQI's are requeued in this cycle until MaxTry is reached which /// trigger an enqueue for the next Update Cycle protected virtual void processLayouting(){ - #if MEASURE_TIME - layoutingMeasure.StartCycle(); - #endif if (Monitor.TryEnter (LayoutMutex)) { - #if DEBUG_LOG - if (LayoutingQueue.Count > 0) - DebugLog.AddEvent (DbgEvtType.IFaceStartLayouting); - #endif +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceLayouting); +#endif DiscardQueue = new Queue (); //Debug.WriteLine ("======= Layouting queue start ======="); LayoutingQueueItem lqi; @@ -787,27 +758,20 @@ namespace Crow lqi.ProcessLayouting (); } LayoutingQueue = DiscardQueue; +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceLayouting, true); +#endif Monitor.Exit (LayoutMutex); DiscardQueue = null; } - /*#if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.IFaceStartLayouting); - #endif*/ - #if MEASURE_TIME - layoutingMeasure.StopCycle(); - #endif } /// Degueue Widget to clip from DrawingQueue and register the last painted slot and the new one /// Clipping rectangles are added at each level of the tree from leef to root, that's the way for the painting /// operation to known if it should go down in the tree for further graphic updates and repaints void clippingRegistration(){ - #if MEASURE_TIME - clippingMeasure.StartCycle(); - #endif - #if DEBUG_LOG - if (ClippingQueue.Count > 0) - DebugLog.AddEvent (DbgEvtType.IFaceStartClipping); - #endif +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceClipping); +#endif Widget g = null; while (ClippingQueue.Count > 0) { lock (ClippingMutex) { @@ -816,23 +780,16 @@ namespace Crow } g.ClippingRegistration (); } - /*#if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.IFaceEndClipping); - #endif*/ - #if MEASURE_TIME - clippingMeasure.StopCycle(); - #endif +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceClipping, true); +#endif } /// Clipping Rectangles drive the drawing process. For compositing, each object under a clip rectangle should be /// repainted. If it contains also clip rectangles, its cache will be update, or if not cached a full redraw will take place void processDrawing(Context ctx){ - #if MEASURE_TIME - drawingMeasure.StartCycle(); - #endif - #if DEBUG_LOG - if (!clipping.IsEmpty) - DebugLog.AddEvent (DbgEvtType.IFaceStartDrawing); - #endif +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.IFaceDrawing); +#endif if (DragImage != null) clipping.UnionRectangle(new Rectangle (DragImageX, DragImageY, DragImageWidth, DragImageHeight)); if (!clipping.IsEmpty) { @@ -894,12 +851,9 @@ namespace Crow clipping = new Region (); } - /*#if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.IFaceEndDrawing); - #endif*/ - #if MEASURE_TIME - drawingMeasure.StopCycle(); - #endif +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.IFaceDrawing, true); +#endif } #endregion @@ -1483,13 +1437,7 @@ namespace Crow public Rectangle getSlot () { return ClientRectangle; } #endregion -#if MEASURE_TIME - public PerformanceMeasure clippingMeasure = new PerformanceMeasure ("Clipping", 1); - public PerformanceMeasure layoutingMeasure = new PerformanceMeasure ("Layouting", 1); - public PerformanceMeasure updateMeasure = new PerformanceMeasure ("Update", 1); - public PerformanceMeasure drawingMeasure = new PerformanceMeasure ("Drawing", 1); - public List PerfMeasures = new List (); -#endif + #if DEBUG_LAYOUTING public List LQIsTries = new List(); public LQIList curLQIsTries = new LQIList(); diff --git a/Crow/src/LayoutingQueueItem.cs b/Crow/src/LayoutingQueueItem.cs index 23556d2b..f1568db3 100644 --- a/Crow/src/LayoutingQueueItem.cs +++ b/Crow/src/LayoutingQueueItem.cs @@ -75,7 +75,7 @@ namespace Crow Slot = Rectangle.Zero; NewSlot = Rectangle.Zero; result = Result.Register; - DebugLog.AddEvent (DbgEvtType.GORegisterLayouting, this); + DbgLogger.AddEvent (DbgEvtType.GORegisterLayouting, this); #endif } #endregion @@ -95,19 +95,16 @@ namespace Crow //cancel layouting for object without parent, maybe some were in queue when //removed from a listbox #if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.GOProcessLayoutingWithNoParent, this); + DbgLogger.AddEvent (DbgEvtType.GOProcessLayoutingWithNoParent, this); #endif go.parentRWLock.ExitReadLock (); return; } #if DEBUG_LOG - DbgEvent dbgEvt = DebugLog.AddEvent (DbgEvtType.GOProcessLayouting, this); + DbgLogger.DbgEvent dbgEvt = DbgLogger.StartEvent (DbgEvtType.GOProcessLayouting, this); #endif LayoutingTries++; if (!Layoutable.UpdateLayout (LayoutType)) { - #if DEBUG_LOG - dbgEvt.end = DebugLog.chrono.ElapsedTicks; - #endif if (LayoutingTries < Interface.MaxLayoutingTries) { Layoutable.RegisteredLayoutings |= LayoutType; (Layoutable as Widget).IFace.LayoutingQueue.Enqueue (this); @@ -133,7 +130,7 @@ namespace Crow else{ result = Result.Success; } - dbgEvt.data = this; + DbgLogger.EndEvent (DbgEvtType.GOProcessLayouting).data = this; #endif go.parentRWLock.ExitReadLock (); } diff --git a/Crow/src/Widgets/TemplatedGroup.cs b/Crow/src/Widgets/TemplatedGroup.cs index d06ea064..416be311 100644 --- a/Crow/src/Widgets/TemplatedGroup.cs +++ b/Crow/src/Widgets/TemplatedGroup.cs @@ -339,6 +339,9 @@ namespace Crow { /// Items loading thread /// void loading(){ +#if DEBUG_LOG + DbgLogger.StartEvent (DbgEvtType.TGLoadingThread, this); +#endif try { loadPage (data, items, dataTest); } catch (Exception ex) { @@ -346,20 +349,22 @@ namespace Crow { Monitor.Exit (IFace.LayoutMutex); System.Diagnostics.Debug.WriteLine ("loading thread aborted: " + ex.ToString()); } - +#if DEBUG_LOG + DbgLogger.EndEvent (DbgEvtType.TGLoadingThread); +#endif } -// //if (!ItemTemplates.ContainsKey ("default")) -// // ItemTemplates ["default"] = Interface.GetItemTemplate (ItemTemplate); -// -// for (int i = 1; i <= (data.Count / itemPerPage) + 1; i++) { -// if ((bool)loadingThread?.cancelRequested) { -// this.Dispose (); -// return; -// } -// loadPage (i); -// Thread.Sleep (1); -// } -// } + // //if (!ItemTemplates.ContainsKey ("default")) + // // ItemTemplates ["default"] = Interface.GetItemTemplate (ItemTemplate); + // + // for (int i = 1; i <= (data.Count / itemPerPage) + 1; i++) { + // if ((bool)loadingThread?.cancelRequested) { + // this.Dispose (); + // return; + // } + // loadPage (i); + // Thread.Sleep (1); + // } + // } void cancelLoadingThread(){ if (loadingThread == null) return; @@ -367,7 +372,7 @@ namespace Crow { bool layoutMx = Monitor.IsEntered (IFace.LayoutMutex); #if DEBUG_LOG - DebugLog.AddEvent (DbgEvtType.TGCancelLoadingThread, this); + DbgLogger.AddEvent (DbgEvtType.TGCancelLoadingThread, this); #endif if (layoutMx) diff --git a/Crow/src/Widgets/Widget.cs b/Crow/src/Widgets/Widget.cs index c98c84ae..ca693cde 100644 --- a/Crow/src/Widgets/Widget.cs +++ b/Crow/src/Widgets/Widget.cs @@ -228,7 +228,7 @@ namespace Crow Clipping = new Region (); #if DEBUG_LOG GraphicObjects.Add (this); - DebugLog.AddEvent(DbgEvtType.GOClassCreation, this); + DbgLogger.AddEvent(DbgEvtType.GOClassCreation, this); #endif } /// @@ -480,7 +480,7 @@ namespace Crow /// If enabled, resulting bitmap of graphic object is cached /// speeding up rendering of complex object. Default is enabled. /// - [DesignCategory ("Behavior")][DefaultValue(true)] + [DesignCategory ("Behavior")][DefaultValue(false)] public virtual bool CacheEnabled { get { return cacheEnabled; } set { @@ -954,14 +954,14 @@ namespace Crow rootDataLevel = true; #if DEBUG_LOG - DbgEvent dbgEvt = DebugLog.AddEvent(DbgEvtType.GOLockUpdate, this); + DbgLogger.StartEvent(DbgEvtType.GOLockUpdate, this); #endif lock (IFace.UpdateMutex) { OnDataSourceChanged (this, dse); NotifyValueChangedAuto (DataSource); } #if DEBUG_LOG - dbgEvt.end = DebugLog.chrono.ElapsedTicks; + DbgLogger.EndEvent (DbgEvtType.GOLockUpdate); #endif } get { @@ -995,7 +995,7 @@ namespace Crow public virtual void OnDataSourceChanged(object sender, DataSourceChangeEventArgs e){ DataSourceChanged.Raise (this, e); #if DEBUG_LOG - DebugLog.AddEvent(DbgEvtType.GONewDataSource, this); + DbgLogger.AddEvent(DbgEvtType.GONewDataSource, this); #endif #if DEBUG_BINDING @@ -1044,7 +1044,7 @@ namespace Crow public void loadDefaultValues() { #if DEBUG_LOG - DbgEvent dbgEvt = DebugLog.AddEvent(DbgEvtType.GOInitialization, this); + DbgLogger.StartEvent (DbgEvtType.GOInitialization, this); #endif Type thisType = this.GetType (); @@ -1165,11 +1165,6 @@ namespace Crow /*} catch (Exception ex) { throw new Exception ("Error applying style <" + styleKey + ">:", ex); }*/ - - #if DEBUG_LOG - dbgEvt.end = DebugLog.chrono.ElapsedTicks; - #endif - onInitialized (this, null); } void setDefaultValue (ILGenerator il, PropertyInfo pi, ref List