kicad-developers team mailing list archive

[Ian McInerney <Ian.S.McInerney@xxxxxxxx>]

Whoops, ignore the patch in the last email since it appears a log statement
slipped out of an if null check. Here is an updated patch.

-Ian

On Sat, Jul 27, 2019 at 5:30 PM Ian McInerney <Ian.S.McInerney@xxxxxxxx>
wrote:

> As I was working on the cvpcb actions, I needed to trace the tool dispatch
> routes through the stack, so I went ahead and added a new debug trace for
> monitoring the dispatch events. It is contained in the attached patch. I
> don't guarantee that I found every location they pass through, but I got
> the major ones.
>
> Hopefully this is useful enough to merge into master.
>
> -Ian
>

From 2b95f423e8b0bc8de24d3ea142ea98a129f75865 Mon Sep 17 00:00:00 2001
From: Ian McInerney <Ian.S.McInerney@xxxxxxxx>
Date: Sat, 27 Jul 2019 16:11:41 +0200
Subject: [PATCH] Add log trace for tool handling

---
 common/eda_base_frame.cpp       |  8 ++++----
 common/tool/action_manager.cpp  | 19 +++++++++++++++++--
 common/tool/action_menu.cpp     | 14 +++++++++-----
 common/tool/tool_dispatcher.cpp |  6 ++++++
 common/tool/tool_manager.cpp    | 32 ++++++++++++++++++++++++++++++--
 common/trace_helpers.cpp        |  1 +
 include/trace_helpers.h         |  7 +++++++
 7 files changed, 74 insertions(+), 13 deletions(-)

diff --git a/common/eda_base_frame.cpp b/common/eda_base_frame.cpp
index b059a6955..ad98123ac 100644
--- a/common/eda_base_frame.cpp
+++ b/common/eda_base_frame.cpp
@@ -70,7 +70,7 @@ static const wxString entryMaximized = "Maximized";  ///< Nonzero iff frame is m
 BEGIN_EVENT_TABLE( EDA_BASE_FRAME, wxFrame )
     EVT_MENU( wxID_ABOUT, EDA_BASE_FRAME::OnKicadAbout )
     EVT_MENU( wxID_PREFERENCES, EDA_BASE_FRAME::OnPreferences )
-    
+
     EVT_CHAR_HOOK( EDA_BASE_FRAME::OnCharHook )
     EVT_MENU_OPEN( EDA_BASE_FRAME::OnMenuOpen )
     EVT_MENU_CLOSE( EDA_BASE_FRAME::OnMenuOpen )
@@ -307,7 +307,7 @@ bool EDA_BASE_FRAME::doAutoSave()
 
 void EDA_BASE_FRAME::OnCharHook( wxKeyEvent& event )
 {
-    wxLogTrace( kicadTraceKeyEvent, "EDA_DRAW_FRAME::OnCharHook %s", dump( event ) );
+    wxLogTrace( kicadTraceKeyEvent, "EDA_BASE_FRAME::OnCharHook %s", dump( event ) );
     // Key events can be filtered here.
     // Currently no filtering is made.
     event.Skip();
@@ -372,7 +372,7 @@ void EDA_BASE_FRAME::AddStandardHelpMenu( wxMenuBar* aMenuBar )
     helpMenu->Add( ACTIONS::gettingStarted );
     helpMenu->Add( ACTIONS::listHotKeys );
     helpMenu->Add( ACTIONS::getInvolved );
-    
+
     helpMenu->AppendSeparator();
     helpMenu->Add( _( "&About KiCad" ), "", wxID_ABOUT, about_xpm );
 
@@ -608,7 +608,7 @@ void EDA_BASE_FRAME::OnPreferences( wxCommandEvent& event )
     wxTreebook* book = dlg.GetTreebook();
 
     book->AddPage( new PANEL_COMMON_SETTINGS( &dlg, book ), _( "Common" ) );
-    
+
     PANEL_HOTKEYS_EDITOR* hotkeysPanel = new PANEL_HOTKEYS_EDITOR( this, book, false );
     book->AddPage( hotkeysPanel, _( "Hotkeys" ) );
 
diff --git a/common/tool/action_manager.cpp b/common/tool/action_manager.cpp
index 1b681032d..cd14118ee 100644
--- a/common/tool/action_manager.cpp
+++ b/common/tool/action_manager.cpp
@@ -23,10 +23,11 @@
  * 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA
  */
 
+#include <eda_draw_frame.h>
 #include <tool/action_manager.h>
-#include <tool/tool_manager.h>
 #include <tool/tool_action.h>
-#include <eda_draw_frame.h>
+#include <tool/tool_manager.h>
+#include <trace_helpers.h>
 
 #include <hotkeys_basic.h>
 #include <cctype>
@@ -92,6 +93,9 @@ bool ACTION_MANAGER::RunHotKey( int aHotKey ) const
     if( key >= 'a' && key <= 'z' )
         key = std::toupper( key );
 
+    wxLogTrace( kicadTraceToolStack, "ACTION_MANAGER::RunHotKey Key: %s",
+            KeyNameFromKeyCode( aHotKey ) );
+
     HOTKEY_LIST::const_iterator it = m_actionHotKeys.find( key | mod );
 
     // If no luck, try without Shift, to handle keys that require it
@@ -141,15 +145,26 @@ bool ACTION_MANAGER::RunHotKey( int aHotKey ) const
 
     if( context )
     {
+        wxLogTrace( kicadTraceToolStack,
+                "ACTION_MANAGER::RunHotKey Running action %s for hotkey %s", context->GetName(),
+                KeyNameFromKeyCode( aHotKey ) );
+
         m_toolMgr->RunAction( *context, true );
         return true;
     }
     else if( global )
     {
+        wxLogTrace( kicadTraceToolStack,
+                "ACTION_MANAGER::RunHotKey Running action: %s for hotkey %s", global->GetName(),
+                KeyNameFromKeyCode( aHotKey ) );
+
         m_toolMgr->RunAction( *global, true );
         return true;
     }
 
+    wxLogTrace( kicadTraceToolStack, "ACTION_MANAGER::RunHotKey No action found for key %s",
+            KeyNameFromKeyCode( aHotKey ) );
+
     return false;
 }
 
diff --git a/common/tool/action_menu.cpp b/common/tool/action_menu.cpp
index c707fb176..6293898ea 100644
--- a/common/tool/action_menu.cpp
+++ b/common/tool/action_menu.cpp
@@ -24,16 +24,17 @@
  * 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA
  */
 
+#include <eda_base_frame.h>
 #include <functional>
+#include <id.h>
+#include <menus_helpers.h>
+#include <tool/action_menu.h>
 #include <tool/actions.h>
 #include <tool/tool_event.h>
-#include <tool/tool_manager.h>
 #include <tool/tool_interactive.h>
-#include <tool/action_menu.h>
+#include <tool/tool_manager.h>
+#include <trace_helpers.h>
 #include <wx/log.h>
-#include <menus_helpers.h>
-#include <eda_base_frame.h>
-#include <id.h>
 
 
 using namespace std::placeholders;
@@ -436,6 +437,9 @@ void ACTION_MENU::OnMenuEvent( wxMenuEvent& aEvent )
     // clients that don't supply a tool will have to check GetSelected() themselves
     if( evt && m_tool )
     {
+
+        wxLogTrace( kicadTraceToolStack, "ACTION_MENU::OnMenuEvent %s", evt->Format() );
+
         TOOL_MANAGER* toolMgr = m_tool->GetManager();
 
         if( g_last_menu_highlighted_id == aEvent.GetId() && !m_isContextMenu )
diff --git a/common/tool/tool_dispatcher.cpp b/common/tool/tool_dispatcher.cpp
index 5e9711ff9..8b4259944 100644
--- a/common/tool/tool_dispatcher.cpp
+++ b/common/tool/tool_dispatcher.cpp
@@ -463,6 +463,8 @@ void TOOL_DISPATCHER::DispatchWxEvent( wxEvent& aEvent )
 
     if( evt )
     {
+        wxLogTrace( kicadTraceToolStack, "TOOL_DISPATCHER::DispatchWxEvent %s", evt->Format() );
+
         handled = m_toolMgr->ProcessEvent( *evt );
 
         // ESC is the special key for canceling tools, and is therefore seen as handled
@@ -499,7 +501,11 @@ void TOOL_DISPATCHER::DispatchWxCommand( wxCommandEvent& aEvent )
     OPT<TOOL_EVENT> evt = m_actions->TranslateLegacyId( aEvent.GetId() );
 
     if( evt )
+    {
+        wxLogTrace( kicadTraceToolStack, "TOOL_DISPATCHER::DispatchWxCommand %s", evt->Format() );
+
         m_toolMgr->ProcessEvent( *evt );
+    }
     else
         aEvent.Skip();
 }
diff --git a/common/tool/tool_manager.cpp b/common/tool/tool_manager.cpp
index 250985c75..71870b267 100644
--- a/common/tool/tool_manager.cpp
+++ b/common/tool/tool_manager.cpp
@@ -24,10 +24,11 @@
  * 51 Franklin Street, Fifth Floor, Boston, MA  02110-1301, USA
  */
 
-#include <map>
-#include <stack>
 #include <algorithm>
 #include <core/optional.h>
+#include <map>
+#include <stack>
+#include <trace_helpers.h>
 
 #include <wx/event.h>
 #include <wx/clipbrd.h>
@@ -528,6 +529,8 @@ bool TOOL_MANAGER::dispatchInternal( const TOOL_EVENT& aEvent )
 {
     bool handled = false;
 
+    wxLogTrace( kicadTraceToolStack, "TOOL_MANAGER::dispatchInternal %s", aEvent.Format() );
+
     // iterate over active tool stack
     for( auto it = m_activeTools.begin(); it != m_activeTools.end(); ++it )
     {
@@ -555,6 +558,10 @@ bool TOOL_MANAGER::dispatchInternal( const TOOL_EVENT& aEvent )
 
                 if( st->cofunc )
                 {
+                    wxLogTrace( kicadTraceToolStack,
+                            "TOOL_MANAGER::dispatchInternal Waking tool %s for event: %s",
+                            st->theTool->GetName(), aEvent.Format() );
+
                     setActiveState( st );
                     bool end = !st->cofunc->Resume();
 
@@ -565,6 +572,10 @@ bool TOOL_MANAGER::dispatchInternal( const TOOL_EVENT& aEvent )
                 // If the tool did not request the event be passed to other tools, we're done
                 if( !st->wakeupEvent.PassEvent() )
                 {
+                    wxLogTrace( kicadTraceToolStack,
+                            "TOOL_MANAGER::dispatchInternal %s stopped passing event: %s",
+                            st->theTool->GetName(), aEvent.Format() );
+
                     handled = true;
                     break;
                 }
@@ -604,6 +615,10 @@ bool TOOL_MANAGER::dispatchInternal( const TOOL_EVENT& aEvent )
                     // as the state changes, the transition table has to be set up again
                     st->transitions.clear();
 
+                    wxLogTrace( kicadTraceToolStack,
+                            "TOOL_MANAGER::dispatchInternal Running tool %s for event: %s",
+                            st->theTool->GetName(), aEvent.Format() );
+
                     // got match? Run the handler.
                     setActiveState( st );
                     st->idle = false;
@@ -626,6 +641,9 @@ bool TOOL_MANAGER::dispatchInternal( const TOOL_EVENT& aEvent )
             break;      // only the first tool gets the event
     }
 
+    wxLogTrace( kicadTraceToolStack, "TOOL_MANAGER::dispatchInternal handled: %s  %s",
+            ( handled ? "true" : "false" ), aEvent.Format() );
+
     return handled;
 }
 
@@ -641,6 +659,7 @@ bool TOOL_MANAGER::dispatchHotKey( const TOOL_EVENT& aEvent )
 
 bool TOOL_MANAGER::dispatchActivation( const TOOL_EVENT& aEvent )
 {
+    wxLogTrace( kicadTraceToolStack, "TOOL_MANAGER::dispatchActivation %s", aEvent.Format() );
     if( aEvent.IsActivate() )
     {
         wxString cmdStr( *aEvent.GetCommandStr() );
@@ -649,6 +668,10 @@ bool TOOL_MANAGER::dispatchActivation( const TOOL_EVENT& aEvent )
 
         if( tool != m_toolNameIndex.end() )
         {
+            wxLogTrace( kicadTraceToolStack,
+                    "TOOL_MANAGER::dispatchActivation Running tool %s for event: %s",
+                    tool->second->theTool->GetName(), aEvent.Format() );
+
             runTool( tool->second->theTool );
             return true;
         }
@@ -931,6 +954,8 @@ void TOOL_MANAGER::applyViewControls( TOOL_STATE* aState )
 
 bool TOOL_MANAGER::processEvent( const TOOL_EVENT& aEvent )
 {
+    wxLogTrace( kicadTraceToolStack, "TOOL_MANAGER::processEvent %s", aEvent.Format() );
+
     if( dispatchHotKey( aEvent ) )
         return true;
 
@@ -949,6 +974,9 @@ bool TOOL_MANAGER::processEvent( const TOOL_EVENT& aEvent )
         processEvent( event );
     }
 
+    wxLogTrace( kicadTraceToolStack, "TOOL_MANAGER::processEvent handled: %s  %s",
+            ( handled ? "true" : "false" ), aEvent.Format() );
+
     return handled;
 }
 
diff --git a/common/trace_helpers.cpp b/common/trace_helpers.cpp
index c7b4c662c..b4cda831b 100644
--- a/common/trace_helpers.cpp
+++ b/common/trace_helpers.cpp
@@ -33,6 +33,7 @@
 const wxChar* const traceFindReplace = wxT( "KICAD_FIND_REPLACE" );
 const wxChar* const kicadTraceCoords = wxT( "KICAD_COORDS" );
 const wxChar* const kicadTraceKeyEvent = wxT( "KICAD_KEY_EVENTS" );
+const wxChar* const kicadTraceToolStack = wxT( "KICAD_TOOL_STACK" );
 const wxChar* const traceSchLibMem = wxT( "KICAD_SCH_LIB_MEM" );
 const wxChar* const traceFindItem = wxT( "KICAD_FIND_ITEM" );
 const wxChar* const traceSchLegacyPlugin = wxT( "KICAD_SCH_LEGACY_PLUGIN" );
diff --git a/include/trace_helpers.h b/include/trace_helpers.h
index d310bf5ee..55caa48a1 100644
--- a/include/trace_helpers.h
+++ b/include/trace_helpers.h
@@ -75,6 +75,13 @@ extern const wxChar* const kicadTraceCoords;
  */
 extern const wxChar* const kicadTraceKeyEvent;
 
+/**
+ * Flag to enable tracing of the tool handling stack.
+ *
+ * Use "KICAD_TOOL_STACK" to enable.
+ */
+extern const wxChar* const kicadTraceToolStack;
+
 /**
  * Flag to enable auto save feature debug tracing.
  *
-- 
2.21.0