First use of Diags.

Refined the Diags Macros, and used to actually monitor timings.

src/AudacityHeaders.h

@@ -49,6 +49,7 @@
 #include "AudacityApp.h"
 #include "AudioIO.h"
 #include "BlockFile.h"
+#include "Diags.h"
 #include "DirManager.h"
 #include "Envelope.h"
 #include "FFT.h"

src/Diags.cpp

@@ -42,10 +42,14 @@ static wxStopWatch MasterWatch;
 static bool bStopWatchStarted = false;
 
 void diagnostics_do_diag( t_diag_struct * pDiag ){
+   wxLog * pLog = wxLog::SetActiveTarget(NULL);
    wxLogDebug( wxT("%s"), pDiag->pMessage );
+   wxLog::SetActiveTarget(pLog);
 }
 void diagnostics_do_diag_mem( t_diag_struct * pDiag, long amount ){
+   wxLog * pLog = wxLog::SetActiveTarget(NULL);
    wxLogDebug( wxT("%s %l"), pDiag->pMessage, amount );
+   wxLog::SetActiveTarget(pLog);
    pDiag->total += amount;
    pDiag->most_recent = amount;
    if( pDiag->countdown == (pDiag->initial_count -1 )){
@@ -69,7 +73,7 @@ void diagnostics_do_perfmon_start( t_diag_struct * pDiag, t_diag_struct ** pReme
    pDiag->most_recent = MasterWatch.Time();
 }
 
-void diagnostics_do_perfmon_stop( const char * pMessage, t_diag_struct ** ppDiag ){
+void diagnostics_do_perfmon_stop( t_diag_struct ** ppDiag ){
    t_diag_struct * pDiag = *ppDiag;
    *ppDiag = NULL;
    long amount = MasterWatch.Time() - pDiag->most_recent;
@@ -83,6 +87,9 @@ void diagnostics_do_perfmon_stop( const char * pMessage, t_diag_struct ** ppDiag
       pDiag->most = amount;
    else if( amount < pDiag->least )
       pDiag->least = amount;
+   wxLog * pLog = wxLog::SetActiveTarget(NULL);
+   wxLogDebug( wxT("%s %f seconds"), pDiag->pMessage, ((float)amount)/1000.0f );
+   wxLog::SetActiveTarget(pLog);
 }
 
 

src/Diags.h

@@ -24,14 +24,14 @@ struct t_diag_struct {
    long most_recent;
    long least;
    long most;
-   const char * pMessage;
+   const wchar_t * pMessage;
 };
 
 
 extern void diagnostics_do_diag( t_diag_struct * pDiag );
 extern void diagnostics_do_diag_mem( t_diag_struct * pDiag, long amount );
 extern void diagnostics_do_perfmon_start( t_diag_struct * pDiag, t_diag_struct ** ppRememberMe );
-extern void diagnostics_do_perfmon_stop( const char * pMessage, t_diag_struct ** ppDiag);
+extern void diagnostics_do_perfmon_stop( t_diag_struct ** ppDiag);
 
 // A constant that sets the maximum number of times we log the message.
 #define DEFAULT_LOG_COUNT (10)
@@ -42,39 +42,40 @@ extern void diagnostics_do_perfmon_stop( const char * pMessage, t_diag_struct **
 //
 // Use DIAG for a simple message. Usually for something bad like an overrun.
 // Use TRACK_MEM to track hungry memory usage, RAM or disk.
-// Use PERFMON_START and STOP to time an interval.
+// Use TIMER_START and STOP to time an interval.
 // For the above two, you will need a MAKE_TIMER( timername ) first.
 
 // The 'timername' created here is almost free.
 // It's a pointer that allows both START and STOP to use the same struct.
 #define MAKE_TIMER( timername ) \
-   static t_diagstruct * timername = NULL;
+   static t_diag_struct * timername = NULL;
 
 // Note that in all three macros:
 // The {} ensure diag name is not visible outside
 // static ensures struct is initialised just once.
 // No function is called after the countdown is counted out.
 #define DIAG( message ) { \
-   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,message};\
+   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,wxT(message)};\
    if( --diag.countdown >=0 )\
       diagnostics_do_diag( &diag );\
 }
 
 #define TRACK_MEM( message, amount ) { \
-   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,message};\
+   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,wxT(message)};\
    if( --diag.countdown >=0 )\
       diagnostics_do_diag_mem( &diag, amount );\
 }
 
-#define PERFMON_START( message, timername ){ \
-   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,message};\
+#define TIMER_START( message, timername )\
+   MAKE_TIMER( timername ); { \
+   static t_diag_struct diag{ DEFAULT_LOG_COUNT, DEFAULT_LOG_COUNT, 0,0,0,0,wxT(message)};\
    if( --diag.countdown >=0 )\
-      diagnostics_do_perfmon_start( &diag, &pRememberMe );\
+      diagnostics_do_perfmon_start( &diag, &timername );\
 }
 
-#define PERFMON_STOP( message, timername ){ \
+#define TIMER_STOP( timername ){ \
    if( timername != NULL )\
-      diagnostics_do_perfmon_stop( message, &timername );\
+      diagnostics_do_perfmon_stop( &timername );\
 }
 
 

src/Project.cpp

@@ -3106,6 +3106,7 @@ void AudacityProject::WriteXMLHeader(XMLWriter &xmlFile)
 
 void AudacityProject::WriteXML(XMLWriter &xmlFile)
 {
+   TIMER_START( "AudacityProject::WriteXML", xml_writer_timer );
    // Warning: This block of code is duplicated in Save, for now...
    wxString project = mFileName;
    if (project.Len() > 4 && project.Mid(project.Len() - 4) == wxT(".aup"))
@@ -3198,6 +3199,8 @@ void AudacityProject::WriteXML(XMLWriter &xmlFile)
       // recording log data to the end of the file later
       xmlFile.EndTag(wxT("project"));
    }
+   TIMER_STOP( xml_writer_timer );
+
 }
 
 // Lock all blocks in all tracks of the last saved version

src/UndoManager.cpp

@@ -50,6 +50,7 @@ UndoManager::~UndoManager()
 
 void UndoManager::CalculateSpaceUsage()
 {
+   TIMER_START( "CalculateSpaceUsage", space_calc );
    TrackListOfKindIterator iter(Track::Wave);
 
    space.Clear();
@@ -102,6 +103,7 @@ void UndoManager::CalculateSpaceUsage()
 
    delete cur;
    delete prev;
+   TIMER_STOP( space_calc );
 }
 
 void UndoManager::GetLongDescription(unsigned int n, wxString *desc,

win/Projects/Audacity/Audacity.vcxproj

@@ -509,6 +509,7 @@
     <ClInclude Include="..\..\..\src\AllThemeResources.h" />
     <ClInclude Include="..\..\..\src\Audacity.h" />
     <ClInclude Include="..\..\..\src\AudacityApp.h" />
+    <ClInclude Include="..\..\..\src\AudacityHeaders.h" />
     <ClInclude Include="..\..\..\src\AudacityLogger.h" />
     <ClInclude Include="..\..\..\src\AudioIO.h" />
     <ClInclude Include="..\..\..\src\AudioIOListener.h" />

win/Projects/Audacity/Audacity.vcxproj.filters

@@ -1673,6 +1673,9 @@
     <ClInclude Include="..\..\..\src\Diags.h">
       <Filter>src</Filter>
     </ClInclude>
+    <ClInclude Include="..\..\..\src\AudacityHeaders.h">
+      <Filter>src</Filter>
+    </ClInclude>
   </ItemGroup>
   <ItemGroup>
     <Image Include="..\..\audacity.ico">