Src/DasherCore/FileLogger.cpp

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