Debugging

- Added timers to measure performance.

src/Context.cpp

@@ -31,6 +31,7 @@
 #include <stdlib.h>
 #include <string.h>
 #include "Context.h"
+#include "Timer.h"
 #include "text.h"
 #include "util.h"
 #include "main.h"
@@ -80,6 +81,8 @@ void Context::initialize (int argc, char** argv)
 ////////////////////////////////////////////////////////////////////////////////
 void Context::initialize ()
 {
+  Timer t ("Context::initialize");
+
   // Set up randomness.
 #ifdef HAVE_SRANDOM
   srandom (time (NULL));
@@ -129,6 +132,8 @@ void Context::initialize ()
 ////////////////////////////////////////////////////////////////////////////////
 int Context::run ()
 {
+  Timer t ("Context::run");
+
   std::string output;
   try
   {
@@ -176,6 +181,8 @@ int Context::run ()
 ////////////////////////////////////////////////////////////////////////////////
 std::string Context::dispatch ()
 {
+  Timer t ("Context::dispatch");
+
   int gcMod = 0; // Change occurred by way of gc.
   std::string out;
 
@@ -360,6 +367,8 @@ void Context::parse (
   Subst& parseSubst,
   Filter& parseFilter)
 {
+  Timer t ("Context::parse");
+
   Att attribute;
   tagAdditions.clear ();
   tagRemovals.clear ();

src/TDB.cpp

@@ -35,6 +35,7 @@
 #include "text.h"
 #include "util.h"
 #include "TDB.h"
+#include "Timer.h"
 #include "main.h"
 
 extern Context context;
@@ -198,6 +199,8 @@ int TDB::load (std::vector <Task>& tasks, Filter& filter)
 //       multiple files.
 int TDB::loadPending (std::vector <Task>& tasks, Filter& filter)
 {
+  Timer t ("TDB::loadPending");
+
   std::string file;
   int line_number;
 
@@ -262,6 +265,8 @@ int TDB::loadPending (std::vector <Task>& tasks, Filter& filter)
 //       multiple files.
 int TDB::loadCompleted (std::vector <Task>& tasks, Filter& filter)
 {
+  Timer t ("TDB::loadCompleted");
+
   std::string file;
   int line_number;
 
@@ -331,6 +336,8 @@ void TDB::update (const Task& task)
 // only modified by TDB::gc.
 int TDB::commit ()
 {
+  Timer t ("TDB::commit");
+
   int quantity = mNew.size () + mModified.size ();
 
   // This is an optimization.  If there are only new tasks, and none were
@@ -393,6 +400,8 @@ void TDB::upgrade ()
 // moves them to the completed.data file.  Returns a count of tasks moved.
 int TDB::gc ()
 {
+  Timer t ("TDB::gc");
+
   int count = 0;
   Date now;
 

src/Table.cpp

@@ -46,9 +46,10 @@
 #include <iostream>
 #include <string.h>
 #include <assert.h>
-#include <Table.h>
-#include <Date.h>
-#include <Duration.h>
+#include "Table.h"
+#include "Date.h"
+#include "Duration.h"
+#include "Timer.h"
 #include "text.h"
 #include "util.h"
 
@@ -1040,6 +1041,8 @@ void Table::clean (std::string& value)
 ////////////////////////////////////////////////////////////////////////////////
 const std::string Table::render (int maximum /* = 0 */)
 {
+  Timer t ("Table::render");
+
   calculateColumnWidths ();
 
   // Print column headers in column order.

src/Timer.cpp

@@ -26,7 +26,11 @@
 ////////////////////////////////////////////////////////////////////////////////
 #include <iostream>
 #include <iomanip>
-#include <Timer.h>
+#include <sstream>
+#include "Timer.h"
+#include "Context.h"
+
+extern Context context;
 
 ////////////////////////////////////////////////////////////////////////////////
 // Timer starts when the object is constructed.
@@ -43,13 +47,15 @@ Timer::~Timer ()
   struct timeval end;
   ::gettimeofday (&end, NULL);
 
-  std::cout << "Timer " // No i18n
-            << mDescription
-            << " "
-            << std::setprecision (6)
-            << ((end.tv_sec - mStart.tv_sec) +
-               ((end.tv_usec - mStart.tv_usec ) / 1000000.0))
-            << std::endl;
+  std::stringstream s;
+  s << "Timer " // No i18n
+    << mDescription
+    << " "
+    << std::setprecision (6)
+    << ((end.tv_sec - mStart.tv_sec) + ((end.tv_usec - mStart.tv_usec )
+       / 1000000.0));
+
+  context.debug (s.str ());
 }
 
 ////////////////////////////////////////////////////////////////////////////////