GAL profiling output is enabled with WXTRACE env variable.

common/draw_panel_gal.cpp

@@ -45,9 +45,10 @@
 
 #include <boost/foreach.hpp>
 
-#ifdef __WXDEBUG__
+#ifdef PROFILE
 #include <profile.h>
-#endif /* __WXDEBUG__ */
+#endif /* PROFILE */
+
 
 EDA_DRAW_PANEL_GAL::EDA_DRAW_PANEL_GAL( wxWindow* aParentWindow, wxWindowID aWindowId,
                                         const wxPoint& aPosition, const wxSize& aSize,
@@ -142,6 +143,11 @@ void EDA_DRAW_PANEL_GAL::onPaint( wxPaintEvent& WXUNUSED( aEvent ) )
     if( m_drawing )
         return;
 
+#ifdef PROFILE
+    prof_counter totalRealTime;
+    prof_start( &totalRealTime );
+#endif /* PROFILE */
+
     m_drawing = true;
     KIGFX::PCB_RENDER_SETTINGS* settings = static_cast<KIGFX::PCB_RENDER_SETTINGS*>( m_painter->GetSettings() );
 
@@ -167,6 +173,11 @@ void EDA_DRAW_PANEL_GAL::onPaint( wxPaintEvent& WXUNUSED( aEvent ) )
     m_gal->DrawCursor( m_viewControls->GetCursorPosition() );
     m_gal->EndDrawing();
 
+#ifdef PROFILE
+    prof_end( &totalRealTime );
+    wxLogDebug( wxT( "EDA_DRAW_PANEL_GAL::onPaint(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* PROFILE */
+
     m_lastRefresh = wxGetLocalTimeMillis();
     m_drawing = false;
 }

common/gal/opengl/gpu_manager.cpp

@@ -35,11 +35,11 @@
 
 #include <typeinfo>
 #include <confirm.h>
-#ifdef PROFILE
+
+#ifdef __WXDEBUG__
 #include <profile.h>
-#include <wx/debug.h>
 #include <wx/log.h>
-#endif /* PROFILE */
+#endif /* __WXDEBUG__ */
 
 using namespace KIGFX;
 
@@ -153,6 +153,11 @@ void GPU_CACHED_MANAGER::DrawAll()
 
 void GPU_CACHED_MANAGER::EndDrawing()
 {
+#ifdef __WXDEBUG__
+    prof_counter totalRealTime;
+    prof_start( &totalRealTime );
+#endif /* __WXDEBUG__ */
+
     wxASSERT( m_isDrawing );
 
     // Prepare buffers
@@ -177,6 +182,10 @@ void GPU_CACHED_MANAGER::EndDrawing()
 
     glDrawElements( GL_TRIANGLES, m_indicesSize, GL_UNSIGNED_INT, 0 );
 
+#ifdef __WXDEBUG__
+    wxLogTrace( "GAL_PROFILE", wxT( "Cached manager size: %d" ), m_indicesSize );
+#endif /* __WXDEBUG__ */
+
     glBindBuffer( GL_ARRAY_BUFFER, 0 );
     glBindBuffer( GL_ELEMENT_ARRAY_BUFFER, 0 );
 
@@ -191,15 +200,21 @@ void GPU_CACHED_MANAGER::EndDrawing()
     }
 
     m_isDrawing = false;
+
+#ifdef __WXDEBUG__
+    prof_end( &totalRealTime );
+    wxLogTrace( "GAL_PROFILE",
+                wxT( "GPU_CACHED_MANAGER::EndDrawing(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* __WXDEBUG__ */
 }
 
 
 void GPU_CACHED_MANAGER::uploadToGpu()
 {
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_counter totalTime;
     prof_start( &totalTime );
-#endif /* PROFILE  */
+#endif /* __WXDEBUG__  */
 
     if( !m_buffersInitialized )
         Initialize();
@@ -218,11 +233,11 @@ void GPU_CACHED_MANAGER::uploadToGpu()
     // Allocate the biggest possible buffer for indices
     resizeIndices( bufferSize );
 
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_end( &totalTime );
-
-    wxLogDebug( wxT( "Uploading %d vertices to GPU / %.1f ms" ), bufferSize, totalTime.msecs() );
-#endif /* PROFILE */
+    wxLogTrace( "GAL_PROFILE",
+                wxT( "Uploading %d vertices to GPU / %.1f ms" ), bufferSize, totalTime.msecs() );
+#endif /* __WXDEBUG__ */
 }
 
 
@@ -270,6 +285,11 @@ void GPU_NONCACHED_MANAGER::DrawAll()
 
 void GPU_NONCACHED_MANAGER::EndDrawing()
 {
+#ifdef __WXDEBUG__
+    prof_counter totalRealTime;
+    prof_start( &totalRealTime );
+#endif /* __WXDEBUG__ */
+
     VERTEX*  vertices       = m_container->GetAllVertices();
     GLfloat* coordinates    = (GLfloat*) ( vertices );
     GLubyte* colors         = (GLubyte*) ( vertices ) + ColorOffset;
@@ -293,6 +313,10 @@ void GPU_NONCACHED_MANAGER::EndDrawing()
 
     glDrawArrays( GL_TRIANGLES, 0, m_container->GetSize() );
 
+#ifdef __WXDEBUG__
+    wxLogTrace( "GAL_PROFILE", wxT( "Noncached manager size: %d" ), m_container->GetSize() );
+#endif /* __WXDEBUG__ */
+
     // Deactivate vertex array
     glDisableClientState( GL_COLOR_ARRAY );
     glDisableClientState( GL_VERTEX_ARRAY );
@@ -302,4 +326,10 @@ void GPU_NONCACHED_MANAGER::EndDrawing()
         glDisableVertexAttribArray( m_shaderAttrib );
         m_shader->Deactivate();
     }
+
+#ifdef __WXDEBUG__
+    prof_end( &totalRealTime );
+    wxLogTrace( "GAL_PROFILE",
+                wxT( "GPU_NONCACHED_MANAGER::EndDrawing(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* __WXDEBUG__ */
 }

common/gal/opengl/opengl_gal.cpp

@@ -29,10 +29,11 @@
 #include <gal/opengl/opengl_gal.h>
 #include <gal/definitions.h>
 
-#include <wx/log.h>
 #include <macros.h>
+
 #ifdef __WXDEBUG__
 #include <profile.h>
+#include <wx/log.h>
 #endif /* __WXDEBUG__ */
 
 #include <limits>
@@ -137,6 +138,11 @@ void OPENGL_GAL::BeginDrawing()
     if( !IsShownOnScreen() )
         return;
 
+#ifdef __WXDEBUG__
+    prof_counter totalRealTime;
+    prof_start( &totalRealTime );
+#endif /* __WXDEBUG__ */
+
     SetCurrent( *glContext );
     clientDC = new wxClientDC( this );
 
@@ -205,11 +211,22 @@ void OPENGL_GAL::BeginDrawing()
     cachedManager.BeginDrawing();
     nonCachedManager.BeginDrawing();
     overlayManager.BeginDrawing();
+
+#ifdef __WXDEBUG__
+    prof_end( &totalRealTime );
+    wxLogTrace( "GAL_PROFILE",
+                wxT( "OPENGL_GAL::BeginDrawing(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* __WXDEBUG__ */
 }
 
 
 void OPENGL_GAL::EndDrawing()
 {
+#ifdef __WXDEBUG__
+    prof_counter totalRealTime;
+    prof_start( &totalRealTime );
+#endif /* __WXDEBUG__ */
+
     // Cached & non-cached containers are rendered to the same buffer
     compositor.SetBuffer( mainBuffer );
     nonCachedManager.EndDrawing();
@@ -231,6 +248,11 @@ void OPENGL_GAL::EndDrawing()
     SwapBuffers();
 
     delete clientDC;
+
+#ifdef __WXDEBUG__
+    prof_end( &totalRealTime );
+    wxLogTrace( "GAL_PROFILE", wxT( "OPENGL_GAL::EndDrawing(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* __WXDEBUG__ */
 }
 
 

common/view/view.cpp

@@ -34,9 +34,9 @@
 #include <gal/graphics_abstraction_layer.h>
 #include <painter.h>
 
-#ifdef PROFILE
+#ifdef __WXDEBUG__
 #include <profile.h>
-#endif /* PROFILE  */
+#endif /* __WXDEBUG__  */
 
 using namespace KIGFX;
 
@@ -774,10 +774,10 @@ void VIEW::ClearTargets()
 
 void VIEW::Redraw()
 {
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_counter totalRealTime;
     prof_start( &totalRealTime );
-#endif /* PROFILE */
+#endif /* __WXDEBUG__ */
 
     VECTOR2D screenSize = m_gal->GetScreenPixelSize();
     BOX2I    rect( ToWorld( VECTOR2D( 0, 0 ) ),
@@ -791,11 +791,10 @@ void VIEW::Redraw()
     markTargetClean( TARGET_NONCACHED );
     markTargetClean( TARGET_OVERLAY );
 
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_end( &totalRealTime );
-
-    wxLogDebug( wxT( "Redraw: %.1f ms" ), totalRealTime.msecs() );
-#endif /* PROFILE */
+    wxLogTrace( "GAL_PROFILE", wxT( "VIEW::Redraw(): %.1f ms" ), totalRealTime.msecs() );
+#endif /* __WXDEBUG__ */
 }
 
 
@@ -1005,10 +1004,10 @@ void VIEW::RecacheAllItems( bool aImmediately )
 
     r.SetMaximum();
 
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_counter totalRealTime;
     prof_start( &totalRealTime );
-#endif /* PROFILE */
+#endif /* __WXDEBUG__ */
 
     for( LAYER_MAP_ITER i = m_layers.begin(); i != m_layers.end(); ++i )
     {
@@ -1024,12 +1023,11 @@ void VIEW::RecacheAllItems( bool aImmediately )
         }
     }
 
-#ifdef PROFILE
+#ifdef __WXDEBUG__
     prof_end( &totalRealTime );
-
-    wxLogDebug( wxT( "RecacheAllItems::immediately: %u %.1f ms" ),
+    wxLogTrace( "GAL_PROFILE", wxT( "RecacheAllItems::immediately: %u %.1f ms" ),
                 aImmediately, totalRealTime.msecs() );
-#endif /* PROFILE */
+#endif /* __WXDEBUG__ */
 }