Src/DasherCore/FileLogger.cpp

   1
   2 #include "../Common/Common.h"
   3
   4 #include <cstring>
   5 #include "FileLogger.h"
   6
   7 // Track memory leaks on Windows to the line that new'd the memory
   8 #ifdef _WIN32
   9 #ifdef _DEBUG
  10 #define DEBUG_NEW new( _NORMAL_BLOCK, THIS_FILE, __LINE__ )
  11 #define new DEBUG_NEW
  12 #undef THIS_FILE
  13 static char THIS_FILE[] = __FILE__;
  14 #endif
  15 #endif
  16
  17
  18 #ifdef _WIN32
  19 #include <sys/timeb.h>
  20 #else
  21 #include <sys/time.h>
  22 #endif
  23
  24 CFileLogger::CFileLogger(const std::string& strFilenamePath, eLogLevel iLogLevel, int iOptionsMask)
  25 {
  26   m_strFilenamePath       = "";
  27   m_iLogLevel             = iLogLevel;
  28   m_iFunctionIndentLevel  = 0;
  29
  30   m_bFunctionLogging      = false;
  31   m_bTimeStamp            = false;
  32   m_bDateStamp            = false;
  33   m_bDeleteOldFile        = false;
  34   m_bFunctionTiming       = false;
  35   m_bOutputScreen         = false;
  36
  37   // See what options are set in our bit mask options parameter
  38   if (iOptionsMask & logFunctionEntryExit)
  39     m_bFunctionLogging = true;
  40   if (iOptionsMask & logTimeStamp)
  41     m_bTimeStamp = true;
  42   if (iOptionsMask & logDateStamp)
  43     m_bDateStamp = true;
  44   if (iOptionsMask & logDeleteOldFile)
  45     m_bDeleteOldFile = true;
  46   if (iOptionsMask & logFunctionTiming)
  47     m_bFunctionTiming = true;
  48   if (iOptionsMask & logOutputScreen)
  49     m_bOutputScreen = true;
  50
  51   // On windows anyway if somebody can open up a file with CreateFile() in a different
  52   // directory and cause the working directory to change.  We don't want our log file
  53   // moving around, so we'll find a absolute path when we are created and stick to
  54   // that for the remainder of our life.
  55   m_strFilenamePath = GetFullFilenamePath(strFilenamePath);
  56
  57   // See if we should get rid of any existing filename with our given name.  This prevents having
  58   // to remember to delete the file before every new debugging run.
  59   if (m_bDeleteOldFile)
  60   {
  61     FILE* fp = NULL;
  62
  63     fp = fopen(m_strFilenamePath.c_str(), "w");
  64     if (fp != NULL)
  65     {
  66       fclose(fp);
  67       fp = NULL;
  68     }
  69   }
  70
  71 }
  72
  73 CFileLogger::~CFileLogger()
  74 {
  75 #ifdef _WIN32
  76   if (m_bFunctionTiming)
  77   {
  78     // Dump the results of our function timing logging
  79
  80     MAP_STRING_INT64::iterator map_iter;
  81
  82     Log("%-60s%20s%10s", logNORMAL, "Function","Ticks", "Percent");
  83     Log("%-60s%20s%10s", logNORMAL, "--------","-----", "-------");
  84
  85     __int64 iMaxTicks = 0;
  86
  87     // First pass to count the max ticks
  88     // We assume that there was a function logger on the outer most (main) program.
  89     // This allows the percent reflect the relative time spent inside emedded calls.
  90
  91     for (map_iter = m_mapFunctionTicks.begin(); map_iter != m_mapFunctionTicks.end(); map_iter++)
  92     {
  93       if (map_iter->second > iMaxTicks)
  94         iMaxTicks = map_iter->second;
  95     }
  96
  97     for (map_iter = m_mapFunctionTicks.begin(); map_iter != m_mapFunctionTicks.end(); map_iter++)
  98     {
  99       std::string name = map_iter->first;
 100       __int64 iTicks = map_iter->second;
 101       Log("%-60s%20I64Ld%10.2f", logNORMAL, name.c_str(), iTicks, (double) iTicks / (double) iMaxTicks  * (double) 100.0);
 102     }
 103   }
 104 #endif
 105 }
 106
 107 // Changes the filename of this logging object
 108 void CFileLogger::SetFilename(const std::string& strFilename)
 109 {
 110   m_strFilenamePath = strFilename;
 111
 112   // See if we should get rid of any existing filename with our given name.  This prevents having
 113   // to remember to delete the file before every new debugging run.
 114   if (m_bDeleteOldFile)
 115   {
 116     FILE* fp = NULL;
 117
 118     fp = fopen(m_strFilenamePath.c_str(), "w");
 119     if (fp != NULL)
 120     {
 121       fclose(fp);
 122       fp = NULL;
 123     }
 124   }
 125 }
 126
 127 // Logs a string to our file.  eLogLevel specifies the importance of this message, we
 128 // only write to the log file if it is at least as important as the level set in the
 129 // constructor.  Accepts printf style formatting in the first string which must be
 130 // filled with the variable parameter list at the end.
 131 // NOTE: Currently not thread safe!
 132 void CFileLogger::Log(const char* szText, eLogLevel iLogLevel, ...)
 133 {
 134   va_list       args;
 135
 136   if ((m_strFilenamePath.length() > 0) &&
 137       (m_iLogLevel <= iLogLevel) &&
 138       (szText != NULL))
 139   {
 140     FILE* fp = NULL;
 141     fp = fopen(m_strFilenamePath.c_str(), "a");
 142
 143     std::string strTimeStamp = GetTimeDateStamp();
 144
 145     if (fp != NULL)
 146     {
 147       std::string strIndented = strTimeStamp + GetIndentedString(szText) + "\n";
 148
 149       va_start(args, iLogLevel);
 150       vfprintf(fp, strIndented.c_str(), args);
 151       va_end(args);
 152
 153       // Optionally we can output message to stdout
 154       if (m_bOutputScreen)
 155       {
 156         va_start(args, iLogLevel);
 157         vprintf(strIndented.c_str(), args);
 158         va_end(args);
 159       }
 160
 161       fclose(fp);
 162       fp = NULL;
 163     }
 164   }
 165 }
 166
 167 // Overloaded version that takes a STL::string
 168 void CFileLogger::Log(const std::string strText, eLogLevel iLogLevel, ...)
 169 {
 170   va_list       args;
 171
 172   if ((m_strFilenamePath.length() > 0) &&
 173       (m_iLogLevel <= iLogLevel))
 174   {
 175     FILE* fp = NULL;
 176     fp = fopen(m_strFilenamePath.c_str(), "a");
 177
 178     std::string strTimeStamp = GetTimeDateStamp();
 179
 180     if (fp != NULL)
 181     {
 182       std::string strIndented = strTimeStamp + GetIndentedString(strText) + "\n";
 183
 184       va_start(args, iLogLevel);
 185       vfprintf(fp, strIndented.c_str(), args);
 186       va_end(args);
 187
 188       // Optionally we can output message to stdout
 189       if (m_bOutputScreen)
 190       {
 191         va_start(args, iLogLevel);
 192         vprintf(strIndented.c_str(), args);
 193         va_end(args);
 194       }
 195
 196       fclose(fp);
 197       fp = NULL;
 198     }
 199   }
 200 }
 201
 202 // Version that assume log level is logDEBUG
 203 void CFileLogger::LogDebug(const char* szText, ...)
 204 {
 205   // Note: it would be nice not to duplicate code, but the variable
 206   // parameter list makes this problematic.
 207   va_list       args;
 208
 209   if ((m_strFilenamePath.length() > 0) &&
 210       (m_iLogLevel == logDEBUG) &&
 211       (szText != NULL))
 212   {
 213     FILE* fp = NULL;
 214     fp = fopen(m_strFilenamePath.c_str(), "a");
 215
 216     std::string strTimeStamp = GetTimeDateStamp();
 217
 218     if (fp != NULL)
 219     {
 220       std::string strIndented = strTimeStamp + GetIndentedString(szText) + "\n";
 221
 222       va_start(args, szText);
 223       vfprintf(fp, strIndented.c_str(), args);
 224       va_end(args);
 225
 226       // Optionally we can output message to stdout
 227       if (m_bOutputScreen)
 228       {
 229         va_start(args, szText);
 230         vprintf(strIndented.c_str(), args);
 231         va_end(args);
 232       }
 233
 234       fclose(fp);
 235       fp = NULL;
 236     }
 237   }
 238 }
 239
 240 // Version that assume log level is logNormal
 241 void CFileLogger::LogNormal(const char* szText, ...)
 242 {
 243   // Note: it would be nice not to duplicate code, but the variable
 244   // parameter list makes this problematic.
 245   va_list       args;
 246
 247   if ((m_strFilenamePath.length() > 0) &&
 248       (m_iLogLevel <= logNORMAL) &&
 249       (szText != NULL))
 250   {
 251     FILE* fp = NULL;
 252     fp = fopen(m_strFilenamePath.c_str(), "a");
 253
 254     std::string strTimeStamp = GetTimeDateStamp();
 255
 256     if (fp != NULL)
 257     {
 258       std::string strIndented = strTimeStamp + GetIndentedString(szText) + "\n";
 259
 260       va_start(args, szText);
 261       vfprintf(fp, strIndented.c_str(), args);
 262       va_end(args);
 263
 264       // Optionally we can output message to stdout
 265       if (m_bOutputScreen)
 266       {
 267         va_start(args, szText);
 268         vprintf(strIndented.c_str(), args);
 269         va_end(args);
 270       }
 271
 272       fclose(fp);
 273       fp = NULL;
 274     }
 275   }
 276 }
 277
 278 // Version that assume log level is logCRITICAL
 279 void CFileLogger::LogCritical(const char* szText, ...)
 280 {
 281   // Note: it would be nice not to duplicate code, but the variable
 282   // parameter list makes this problematic.
 283   va_list       args;
 284
 285   // Always log critical messages
 286   if ((m_strFilenamePath.length() > 0) &&
 287       (szText != NULL))
 288   {
 289     FILE* fp = NULL;
 290     fp = fopen(m_strFilenamePath.c_str(), "a");
 291
 292     std::string strTimeStamp = GetTimeDateStamp();
 293
 294     if (fp != NULL)
 295     {
 296       std::string strIndented = strTimeStamp + GetIndentedString(szText) + "\n";
 297
 298       va_start(args, szText);
 299       vfprintf(fp, strIndented.c_str(), args);
 300       va_end(args);
 301
 302       // Optionally we can output message to stdout
 303       if (m_bOutputScreen)
 304       {
 305         va_start(args, szText);
 306         vprintf(strIndented.c_str(), args);
 307         va_end(args);
 308       }
 309
 310       fclose(fp);
 311       fp = NULL;
 312     }
 313   }
 314 }
 315
 316 // Logs entry into a particular function
 317 void CFileLogger::LogFunctionEntry(const std::string& strFunctionName)
 318 {
 319   if (m_bFunctionLogging)
 320   {
 321     std::string strStart = "start: ";
 322     strStart += strFunctionName;
 323     Log(strStart.c_str());
 324     m_iFunctionIndentLevel++;
 325   }
 326 }
 327
 328 // Logs exit into a particular function
 329 void CFileLogger::LogFunctionExit(const std::string& strFunctionName)
 330 {
 331   if (m_bFunctionLogging)
 332   {
 333     m_iFunctionIndentLevel--;
 334     std::string strEnd = "end: ";
 335     strEnd += strFunctionName;
 336     Log(strEnd.c_str());
 337   }
 338 }
 339
 340 #ifdef _WIN32
 341 void CFileLogger::LogFunctionTicks(const std::string& strFunctionName, __int64 iTicks)
 342 {
 343   __int64 iCurrent;
 344
 345   iCurrent = m_mapFunctionTicks[strFunctionName];
 346   iCurrent = iCurrent + iTicks;
 347
 348   m_mapFunctionTicks[strFunctionName] = iCurrent;
 349 }
 350 #endif
 351
 352 // Gets an indented version of the function name
 353 std::string CFileLogger::GetIndentedString(const std::string& strText)
 354 {
 355   std::string strIndented = "";
 356   for (int i = 0; i < m_iFunctionIndentLevel; i++)
 357     strIndented += " ";
 358   strIndented += strText;
 359
 360   return strIndented;
 361 }
 362
 363 bool CFileLogger::GetFunctionTiming()
 364 {
 365   return m_bFunctionTiming;
 366 }
 367
 368 // Utility method that converts a filename into a fully qualified
 369 // path and filename on Windows.  This can be used to make sure
 370 // a relative filename stays pointed at the same location despite
 371 // changes in the working directory.
 372 std::string CFileLogger::GetFullFilenamePath(std::string strFilename)
 373 {
 374 #ifdef _WIN32
 375
 376   // Windows code
 377   const int   MAX_PATH_LENGTH = 1024;
 378
 379 #ifdef _UNICODE
 380
 381   // In Unicode, we need the parameters to GetFullPathName() in wide characters
 382   wchar_t     szPath[MAX_PATH_LENGTH];
 383   wchar_t*    pszFilePart = NULL;
 384   wchar_t     wstrFilenamePath[MAX_PATH_LENGTH];
 385   char        szResult[MAX_PATH_LENGTH];
 386
 387   unsigned int i = 0;
 388   for (i = 0; i < strFilename.length(); i++)
 389     wstrFilenamePath[i] = (wchar_t) strFilename[i];
 390   wstrFilenamePath[i] = '\0';
 391
 392   ::GetFullPathName(wstrFilenamePath, MAX_PATH_LENGTH, szPath, &pszFilePart);
 393   i = 0;
 394   while (szPath[i] != '\0')
 395   {
 396     szResult[i] = (char) szPath[i];
 397     i++;
 398   }
 399   szResult[i] = '\0';
 400
 401   return szResult;
 402
 403 #else
 404   // Using normal non-unicode strings
 405   char        szPath[MAX_PATH_LENGTH];
 406   char*       pszFilePart = NULL;
 407
 408   ::GetFullPathName(strFilename.c_str(), MAX_PATH_LENGTH, szPath, &pszFilePart);
 409
 410   return szPath;
 411
 412 #endif
 413
 414 #else
 415   // Non-windows code
 416   return strFilename;
 417
 418 #endif
 419 }
 420
 421 /////////////////////////////////////// CFunctionLogger /////////////////////////////////////////////////////////////
 422
 423 CFunctionLogger::CFunctionLogger(const std::string& strFunctionName, CFileLogger* pLogger)
 424 {
 425   m_pLogger = pLogger;
 426
 427   if ((m_pLogger != NULL) && (strFunctionName.length() > 0))
 428   {
 429     m_strFunctionName = strFunctionName;
 430
 431     if (!m_pLogger->GetFunctionTiming())
 432       m_pLogger->LogFunctionEntry(m_strFunctionName);
 433     else {
 434 #ifdef _WIN32
 435       QueryPerformanceCounter(&m_iStartTicks);
 436 #endif
 437     }
 438   }
 439
 440 }
 441
 442 CFunctionLogger::~CFunctionLogger()
 443 {
 444   if ((m_pLogger != NULL) && (m_strFunctionName.length() > 0))
 445   {
 446     if (!m_pLogger->GetFunctionTiming())
 447       m_pLogger->LogFunctionExit(m_strFunctionName);
 448     else
 449     {
 450 #ifdef _WIN32
 451       LARGE_INTEGER iEndTicks;
 452       QueryPerformanceCounter(&iEndTicks);
 453       // Add our total ticks to the tracking map object in the logger object
 454           m_pLogger->LogFunctionTicks(m_strFunctionName,
 455                   iEndTicks.QuadPart - m_iStartTicks.QuadPart);
 456 #endif
 457     }
 458   }
 459 }
 460
 461 // Update what log level this object is using
 462 void CFileLogger::SetLogLevel(const eLogLevel iNewLevel)
 463 {
 464   m_iLogLevel = iNewLevel;
 465 }
 466
 467 // Update whether function entry/exit is logged
 468 void CFileLogger::SetFunctionLogging(bool bFunctionLogging)
 469 {
 470   m_bFunctionLogging = bFunctionLogging;
 471 }
 472
 473
 474 // Gets the time and/or date stamp as specified
 475 // by our construction options.
 476 std::string CFileLogger::GetTimeDateStamp()
 477 {
 478   std::string strTimeStamp = "";
 479
 480   if ((m_bTimeStamp) || (m_bDateStamp))
 481   {
 482 #ifdef _WIN32
 483     struct timeb sTimeBuffer;
 484 #else
 485     struct timeval sTimeBuffer;
 486     struct timezone sTimezoneBuffer;
 487     time_t t;
 488 #endif
 489     char* szTimeLine = NULL;
 490
 491 #ifdef _WIN32
 492     ftime(&sTimeBuffer);
 493     szTimeLine = ctime(&(sTimeBuffer.time));
 494 #else
 495     gettimeofday(&sTimeBuffer, &sTimezoneBuffer);
 496     t = sTimeBuffer.tv_sec;
 497     szTimeLine = ctime(&t);
 498 #endif
 499
 500     // Format is:
 501     // Wed Jun 22 10:22:00 2005
 502     // 0123456789012345678901234
 503     if ((szTimeLine != NULL) && (strlen(szTimeLine) > 23))
 504     {
 505       if (m_bDateStamp)
 506       {
 507         for (int i = 4; i < 10; i++)
 508           strTimeStamp += szTimeLine[i];
 509         for (int i = 19; i < 24; i++)
 510           strTimeStamp += szTimeLine[i];
 511         if (m_bTimeStamp)
 512           strTimeStamp += " ";
 513       }
 514
 515       if (m_bTimeStamp)
 516       {
 517         for (int i = 11; i < 19; i++)
 518           strTimeStamp += szTimeLine[i];
 519         strTimeStamp += ".";
 520         char strMs[16];
 521 #ifdef _WIN32
 522         sprintf(strMs, "%d", sTimeBuffer.millitm);
 523 #else
 524         sprintf(strMs, "%d", static_cast<int>(sTimeBuffer.tv_usec / 1000));
 525 #endif
 526         if (strlen(strMs) == 1)
 527           strTimeStamp += "00";
 528         else if (strlen(strMs) == 2)
 529           strTimeStamp += "0";
 530         strTimeStamp += strMs;
 531       }
 532
 533       strTimeStamp += "\t";
 534     }
 535   }
 536
 537   return strTimeStamp;
 538 }