Home | History | Annotate | Download | only in base
      1 // Copyright 2006 Google Inc. All Rights Reserved.
      2 // Author: brettw (Brett Wilson)
      3 
      4 #ifndef BASE_LOGGING_H__
      5 #define BASE_LOGGING_H__
      6 
      7 #include <string>
      8 #include <cstring>
      9 #include <strstream>
     10 #include <tchar.h>
     11 
     12 #include "base/basictypes.h"
     13 #include "base/scoped_ptr.h"
     14 
     15 // Optional message capabilities
     16 // -----------------------------
     17 // Assertion failed messages and fatal errors are displayed in a dialog box
     18 // before the application exits. However, running this UI creates a message
     19 // loop, which causes application messages to be processed and potentially
     20 // dispatched to existing application windows. Since the application is in a
     21 // bad state when this assertion dialog is displayed, these messages may not
     22 // get processed and hang the dialog, or the application might go crazy.
     23 //
     24 // Therefore, it can be beneficial to display the error dialog in a separate
     25 // process from the main application. When the logging system needs to display
     26 // a fatal error dialog box, it will look for a program called
     27 // "DebugMessage.exe" in the same directory as the application executable. It
     28 // will run this application with the message as the command line, and will
     29 // not include the name of the application as is traditional for easier
     30 // parsing.
     31 //
     32 // The code for DebugMessage.exe is only one line. In WinMain, do:
     33 //   MessageBox(NULL, GetCommandLineW(), L"Fatal Error", 0);
     34 //
     35 // If DebugMessage.exe is not found, the logging code will use a normal
     36 // MessageBox, potentially causing the problems discussed above.
     37 
     38 
     39 // Instructions
     40 // ------------
     41 //
     42 // Make a bunch of macros for logging.  The way to log things is to stream
     43 // things to LOG(<a particular severity level>).  E.g.,
     44 //
     45 //   LOG(INFO) << "Found " << num_cookies << " cookies";
     46 //
     47 // You can also do conditional logging:
     48 //
     49 //   LOG_IF(INFO, num_cookies > 10) << "Got lots of cookies";
     50 //
     51 // The above will cause log messages to be output on the 1st, 11th, 21st, ...
     52 // times it is executed.  Note that the special COUNTER value is used to
     53 // identify which repetition is happening.
     54 //
     55 // There are also "debug mode" logging macros like the ones above:
     56 //
     57 //   DLOG(INFO) << "Found cookies";
     58 //
     59 //   DLOG_IF(INFO, num_cookies > 10) << "Got lots of cookies";
     60 //
     61 // All "debug mode" logging is compiled away to nothing for non-debug mode
     62 // compiles.  LOG_IF and development flags also work well together
     63 // because the code can be compiled away sometimes.
     64 //
     65 // We also have
     66 //
     67 //   LOG_ASSERT(assertion);
     68 //   DLOG_ASSERT(assertion);
     69 //
     70 // which is syntactic sugar for {,D}LOG_IF(FATAL, assert fails) << assertion;
     71 //
     72 // We also override the standard 'assert' to use 'DLOG_ASSERT'.
     73 //
     74 // The supported severity levels for macros that allow you to specify one
     75 // are (in increasing order of severity) INFO, WARNING, ERROR, and FATAL.
     76 //
     77 // There is also the special severity of DFATAL, which logs FATAL in
     78 // debug mode, ERROR in normal mode.
     79 //
     80 // Very important: logging a message at the FATAL severity level causes
     81 // the program to terminate (after the message is logged).
     82 
     83 namespace logging {
     84 
     85 // Where to record logging output? A flat file and/or system debug log via
     86 // OutputDebugString. Defaults to LOG_ONLY_TO_FILE.
     87 enum LoggingDestination { LOG_ONLY_TO_FILE,
     88                           LOG_ONLY_TO_SYSTEM_DEBUG_LOG,
     89                           LOG_TO_BOTH_FILE_AND_SYSTEM_DEBUG_LOG };
     90 
     91 // Indicates that the log file should be locked when being written to.
     92 // Often, there is no locking, which is fine for a single threaded program.
     93 // If logging is being done from multiple threads or there can be more than
     94 // one process doing the logging, the file should be locked during writes to
     95 // make each log outut atomic. Other writers will block.
     96 //
     97 // All processes writing to the log file must have their locking set for it to
     98 // work properly. Defaults to DONT_LOCK_LOG_FILE.
     99 enum LogLockingState { LOCK_LOG_FILE, DONT_LOCK_LOG_FILE };
    100 
    101 // On startup, should we delete or append to an existing log file (if any)?
    102 // Defaults to APPEND_TO_OLD_LOG_FILE.
    103 enum OldFileDeletionState { DELETE_OLD_LOG_FILE, APPEND_TO_OLD_LOG_FILE };
    104 
    105 // Sets the log file name and other global logging state. Calling this function
    106 // is recommended, and is normally done at the beginning of application init.
    107 // If you don't call it, all the flags will be initialized to their default
    108 // values, and there is a race condition that may leak a critical section
    109 // object if two threads try to do the first log at the same time.
    110 // See the definition of the enums above for descriptions and default values.
    111 //
    112 // The default log file is initialized to "debug.log" in the application
    113 // directory. You probably don't want this, especially since the program
    114 // directory may not be writable on an enduser's system.
    115 void InitLogging(const TCHAR* log_file, LoggingDestination logging_dest,
    116                  LogLockingState lock_log, OldFileDeletionState delete_old);
    117 
    118 // Sets the log level. Anything at or above this level will be written to the
    119 // log file/displayed to the user (if applicable). Anything below this level
    120 // will be silently ignored. The log level defaults to 0 (everything is logged)
    121 // if this function is not called.
    122 void SetMinLogLevel(int level);
    123 
    124 // Sets the log filter prefix.  Any log message below LOG_ERROR severity that
    125 // doesn't start with this prefix with be silently ignored.  The filter defaults
    126 // to NULL (everything is logged) if this function is not called.  Messages
    127 // with severity of LOG_ERROR or higher will not be filtered.
    128 void SetLogFilterPrefix(char* filter);
    129 
    130 // Sets the common items you want to be prepended to each log message.
    131 // process and thread IDs default to off, the timestamp defaults to on.
    132 // If this function is not called, logging defaults to writing the timestamp
    133 // only.
    134 void SetLogItems(bool enable_process_id, bool enable_thread_id,
    135                  bool enable_timestamp, bool enable_tickcount);
    136 
    137 // Sets the Log Assert Handler that will be used to notify of check failures.
    138 // The default handler shows a dialog box, however clients can use this
    139 // function to override with their own handling (e.g. a silent one for Unit
    140 // Tests)
    141 typedef void (*LogAssertHandlerFunction)(const std::string& str);
    142 void SetLogAssertHandler(LogAssertHandlerFunction handler);
    143 
    144 typedef int LogSeverity;
    145 const LogSeverity LOG_INFO = 0;
    146 const LogSeverity LOG_WARNING = 1;
    147 const LogSeverity LOG_ERROR = 2;
    148 const LogSeverity LOG_FATAL = 3;
    149 const LogSeverity LOG_NUM_SEVERITIES = 4;
    150 
    151 // LOG_DFATAL_LEVEL is LOG_FATAL in debug mode, ERROR in normal mode
    152 #ifdef NDEBUG
    153 const LogSeverity LOG_DFATAL_LEVEL = LOG_ERROR;
    154 #else
    155 const LogSeverity LOG_DFATAL_LEVEL = LOG_FATAL;
    156 #endif
    157 
    158 // A few definitions of macros that don't generate much code. These are used
    159 // by LOG() and LOG_IF, etc. Since these are used all over our code, it's
    160 // better to have compact code for these operations.
    161 #define COMPACT_GOOGLE_LOG_INFO \
    162   logging::LogMessage(__FILE__, __LINE__)
    163 #define COMPACT_GOOGLE_LOG_WARNING \
    164   logging::LogMessage(__FILE__, __LINE__, logging::LOG_WARNING)
    165 #define COMPACT_GOOGLE_LOG_ERROR \
    166   logging::LogMessage(__FILE__, __LINE__, logging::LOG_ERROR)
    167 #define COMPACT_GOOGLE_LOG_FATAL \
    168   logging::LogMessage(__FILE__, __LINE__, logging::LOG_FATAL)
    169 #define COMPACT_GOOGLE_LOG_DFATAL \
    170   logging::LogMessage(__FILE__, __LINE__, logging::LOG_DFATAL_LEVEL)
    171 
    172 // wingdi.h defines ERROR to be 0. When we call LOG(ERROR), it gets
    173 // substituted with 0, and it expands to COMPACT_GOOGLE_LOG_0. To allow us
    174 // to keep using this syntax, we define this macro to do the same thing
    175 // as COMPACT_GOOGLE_LOG_ERROR, and also define ERROR the same way that
    176 // the Windows SDK does for consistency.
    177 #define ERROR 0
    178 #define COMPACT_GOOGLE_LOG_0 \
    179   logging::LogMessage(__FILE__, __LINE__, logging::LOG_ERROR)
    180 
    181 // We use the preprocessor's merging operator, "##", so that, e.g.,
    182 // LOG(INFO) becomes the token COMPACT_GOOGLE_LOG_INFO.  There's some funny
    183 // subtle difference between ostream member streaming functions (e.g.,
    184 // ostream::operator<<(int) and ostream non-member streaming functions
    185 // (e.g., ::operator<<(ostream&, string&): it turns out that it's
    186 // impossible to stream something like a string directly to an unnamed
    187 // ostream. We employ a neat hack by calling the stream() member
    188 // function of LogMessage which seems to avoid the problem.
    189 
    190 #define LOG(severity) COMPACT_GOOGLE_LOG_ ## severity.stream()
    191 #define SYSLOG(severity) LOG(severity)
    192 
    193 #define LOG_IF(severity, condition) \
    194   !(condition) ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
    195 #define SYSLOG_IF(severity, condition) LOG_IF(severity, condition)
    196 
    197 #define LOG_ASSERT(condition)  \
    198   LOG_IF(FATAL, !(condition)) << "Assert failed: " #condition ". "
    199 #define SYSLOG_ASSERT(condition) \
    200   SYSLOG_IF(FATAL, !(condition)) << "Assert failed: " #condition ". "
    201 
    202 // A container for a string pointer which can be evaluated to a bool -
    203 // true iff the pointer is NULL.
    204 struct CheckOpString {
    205   CheckOpString(std::string* str) : str_(str) { }
    206   // No destructor: if str_ is non-NULL, we're about to LOG(FATAL),
    207   // so there's no point in cleaning up str_.
    208   operator bool() const { return str_ != NULL; }
    209   std::string* str_;
    210 };
    211 
    212 // Build the error message string.  This is separate from the "Impl"
    213 // function template because it is not performance critical and so can
    214 // be out of line, while the "Impl" code should be inline.
    215 template<class t1, class t2>
    216 std::string* MakeCheckOpString(const t1& v1, const t2& v2, const char* names) {
    217   std::ostrstream ss;
    218   ss << names << " (" << v1 << " vs. " << v2 << ")";
    219   return new std::string(ss.str(), ss.pcount());
    220 }
    221 
    222 extern std::string* MakeCheckOpStringIntInt(int v1, int v2, const char* names);
    223 
    224 template<int, int>
    225 std::string* MakeCheckOpString(const int& v1, const int& v2, const char* names) {
    226   return MakeCheckOpStringIntInt(v1, v2, names);
    227 }
    228 
    229 // Plus some debug-logging macros that get compiled to nothing for production
    230 //
    231 // DEBUG_MODE is for uses like
    232 //   if (DEBUG_MODE) foo.CheckThatFoo();
    233 // instead of
    234 //   #ifndef NDEBUG
    235 //     foo.CheckThatFoo();
    236 //   #endif
    237 
    238 #ifndef NDEBUG
    239 
    240 #define DLOG(severity) LOG(severity)
    241 #define DLOG_IF(severity, condition) LOG_IF(severity, condition)
    242 #define DLOG_ASSERT(condition) LOG_ASSERT(condition)
    243 
    244 // debug-only checking.  not executed in NDEBUG mode.
    245 enum { DEBUG_MODE = 1 };
    246 #define DCHECK(condition) \
    247   LOG_IF(FATAL, !(condition)) << "Check failed: " #condition ". "
    248 
    249 // Helper functions for DCHECK_OP macro.
    250 // The (int, int) specialization works around the issue that the compiler
    251 // will not instantiate the template version of the function on values of
    252 // unnamed enum type - see comment below.
    253 #define DEFINE_DCHECK_OP_IMPL(name, op) \
    254   template <class t1, class t2> \
    255   inline std::string* Check##name##Impl(const t1& v1, const t2& v2, \
    256                                         const char* names) { \
    257     if (v1 op v2) return NULL; \
    258     else return MakeCheckOpString(v1, v2, names); \
    259   } \
    260   inline std::string* Check##name##Impl(int v1, int v2, const char* names) { \
    261     if (v1 op v2) return NULL; \
    262     else return MakeCheckOpString(v1, v2, names); \
    263   }
    264 DEFINE_DCHECK_OP_IMPL(EQ, ==)
    265 DEFINE_DCHECK_OP_IMPL(NE, !=)
    266 DEFINE_DCHECK_OP_IMPL(LE, <=)
    267 DEFINE_DCHECK_OP_IMPL(LT, < )
    268 DEFINE_DCHECK_OP_IMPL(GE, >=)
    269 DEFINE_DCHECK_OP_IMPL(GT, > )
    270 #undef DEFINE_DCHECK_OP_IMPL
    271 
    272 // Helper macro for binary operators.
    273 // Don't use this macro directly in your code, use CHECK_EQ et al below.
    274 #define DCHECK_OP(name, op, val1, val2)  \
    275   while (logging::CheckOpString _result = \
    276          logging::Check##name##Impl((val1), (val2), #val1 " " #op " " #val2)) \
    277     logging::LogMessage(__FILE__, __LINE__, _result).stream()
    278 
    279 // Equality/Inequality checks - compare two values, and log a LOG_FATAL message
    280 // including the two values when the result is not as expected.  The values
    281 // must have operator<<(ostream, ...) defined.
    282 //
    283 // You may append to the error message like so:
    284 //   CHECK_NE(1, 2) << ": The world must be ending!";
    285 //
    286 // We are very careful to ensure that each argument is evaluated exactly
    287 // once, and that anything which is legal to pass as a function argument is
    288 // legal here.  In particular, the arguments may be temporary expressions
    289 // which will end up being destroyed at the end of the apparent statement,
    290 // for example:
    291 //   CHECK_EQ(string("abc")[1], 'b');
    292 //
    293 // WARNING: These don't compile correctly if one of the arguments is a pointer
    294 // and the other is NULL. To work around this, simply static_cast NULL to the
    295 // type of the desired pointer.
    296 
    297 #define DCHECK_EQ(val1, val2) DCHECK_OP(EQ, ==, val1, val2)
    298 #define DCHECK_NE(val1, val2) DCHECK_OP(NE, !=, val1, val2)
    299 #define DCHECK_LE(val1, val2) DCHECK_OP(LE, <=, val1, val2)
    300 #define DCHECK_LT(val1, val2) DCHECK_OP(LT, < , val1, val2)
    301 #define DCHECK_GE(val1, val2) DCHECK_OP(GE, >=, val1, val2)
    302 #define DCHECK_GT(val1, val2) DCHECK_OP(GT, > , val1, val2)
    303 
    304 // Helper functions for string comparisons.
    305 // To avoid bloat, the definitions are in logging.cc.
    306 #define DECLARE_DCHECK_STROP_IMPL(func, expected) \
    307   std::string* Check##func##expected##Impl(const char* s1, \
    308                                            const char* s2, \
    309                                            const char* names);
    310 DECLARE_DCHECK_STROP_IMPL(strcmp, true)
    311 DECLARE_DCHECK_STROP_IMPL(strcmp, false)
    312 DECLARE_DCHECK_STROP_IMPL(_stricmp, true)
    313 DECLARE_DCHECK_STROP_IMPL(_stricmp, false)
    314 #undef DECLARE_DCHECK_STROP_IMPL
    315 
    316 // Helper macro for string comparisons.
    317 // Don't use this macro directly in your code, use CHECK_STREQ et al below.
    318 #define DCHECK_STROP(func, op, expected, s1, s2) \
    319   while (CheckOpString _result = \
    320       logging::Check##func##expected##Impl((s1), (s2), \
    321                                            #s1 " " #op " " #s2)) \
    322     LOG(FATAL) << *_result.str_
    323 
    324 // String (char*) equality/inequality checks.
    325 // CASE versions are case-insensitive.
    326 //
    327 // Note that "s1" and "s2" may be temporary strings which are destroyed
    328 // by the compiler at the end of the current "full expression"
    329 // (e.g. DCHECK_STREQ(Foo().c_str(), Bar().c_str())).
    330 
    331 #define DCHECK_STREQ(s1, s2) DCHECK_STROP(strcmp, ==, true, s1, s2)
    332 #define DCHECK_STRNE(s1, s2) DCHECK_STROP(strcmp, !=, false, s1, s2)
    333 #define DCHECK_STRCASEEQ(s1, s2) DCHECK_STROP(_stricmp, ==, true, s1, s2)
    334 #define DCHECK_STRCASENE(s1, s2) DCHECK_STROP(_stricmp, !=, false, s1, s2)
    335 
    336 #define DCHECK_INDEX(I,A) DCHECK(I < (sizeof(A)/sizeof(A[0])))
    337 #define DCHECK_BOUND(B,A) DCHECK(B <= (sizeof(A)/sizeof(A[0])))
    338 
    339 #else  // NDEBUG
    340 
    341 #define DLOG(severity) \
    342   true ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
    343 
    344 #define DLOG_IF(severity, condition) \
    345   true ? (void) 0 : logging::LogMessageVoidify() & LOG(severity)
    346 
    347 #define DLOG_ASSERT(condition) \
    348   true ? (void) 0 : LOG_ASSERT(condition)
    349 
    350 enum { DEBUG_MODE = 0 };
    351 
    352 // This macro can be followed by a sequence of stream parameters in
    353 // non-debug mode. The DCHECK and friends macros use this so that
    354 // the expanded expression DCHECK(foo) << "asdf" is still syntactically
    355 // valid, even though the expression will get optimized away.
    356 #define NDEBUG_EAT_STREAM_PARAMETERS \
    357   logging::LogMessage(__FILE__, __LINE__).stream()
    358 
    359 #define DCHECK(condition) \
    360   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    361 
    362 #define DCHECK_EQ(val1, val2) \
    363   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    364 
    365 #define DCHECK_NE(val1, val2) \
    366   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    367 
    368 #define DCHECK_LE(val1, val2) \
    369   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    370 
    371 #define DCHECK_LT(val1, val2) \
    372   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    373 
    374 #define DCHECK_GE(val1, val2) \
    375   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    376 
    377 #define DCHECK_GT(val1, val2) \
    378   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    379 
    380 #define DCHECK_STREQ(str1, str2) \
    381   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    382 
    383 #define DCHECK_STRCASEEQ(str1, str2) \
    384   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    385 
    386 #define DCHECK_STRNE(str1, str2) \
    387   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    388 
    389 #define DCHECK_STRCASENE(str1, str2) \
    390   while (false) NDEBUG_EAT_STREAM_PARAMETERS
    391 
    392 #endif  // NDEBUG
    393 
    394 #define NOTREACHED() DCHECK(false)
    395 
    396 // Redefine the standard assert to use our nice log files
    397 #undef assert
    398 #define assert(x) DLOG_ASSERT(x)
    399 
    400 // This class more or less represents a particular log message.  You
    401 // create an instance of LogMessage and then stream stuff to it.
    402 // When you finish streaming to it, ~LogMessage is called and the
    403 // full message gets streamed to the appropriate destination.
    404 //
    405 // You shouldn't actually use LogMessage's constructor to log things,
    406 // though.  You should use the LOG() macro (and variants thereof)
    407 // above.
    408 class LogMessage {
    409  public:
    410   LogMessage(const char* file, int line, LogSeverity severity, int ctr);
    411 
    412   // Two special constructors that generate reduced amounts of code at
    413   // LOG call sites for common cases.
    414   //
    415   // Used for LOG(INFO): Implied are:
    416   // severity = LOG_INFO, ctr = 0
    417   //
    418   // Using this constructor instead of the more complex constructor above
    419   // saves a couple of bytes per call site.
    420   LogMessage(const char* file, int line);
    421 
    422   // Used for LOG(severity) where severity != INFO.  Implied
    423   // are: ctr = 0
    424   //
    425   // Using this constructor instead of the more complex constructor above
    426   // saves a couple of bytes per call site.
    427   LogMessage(const char* file, int line, LogSeverity severity);
    428 
    429   // A special constructor used for check failures.
    430   // Implied severity = LOG_FATAL
    431   LogMessage(const char* file, int line, const CheckOpString& result);
    432 
    433   ~LogMessage();
    434 
    435   std::ostream& stream() { return stream_; }
    436 
    437  private:
    438   void Init(const char* file, int line);
    439 
    440   LogSeverity severity_;
    441   std::ostrstream stream_;
    442   int message_start_;  // offset of the start of the message (past prefix info).
    443 
    444   DISALLOW_EVIL_CONSTRUCTORS(LogMessage);
    445 };
    446 
    447 // A non-macro interface to the log facility; (useful
    448 // when the logging level is not a compile-time constant).
    449 inline void LogAtLevel(int const log_level, std::string const &msg) {
    450   LogMessage(__FILE__, __LINE__, log_level).stream() << msg;
    451 }
    452 
    453 // This class is used to explicitly ignore values in the conditional
    454 // logging macros.  This avoids compiler warnings like "value computed
    455 // is not used" and "statement has no effect".
    456 class LogMessageVoidify {
    457  public:
    458   LogMessageVoidify() { }
    459   // This has to be an operator with a precedence lower than << but
    460   // higher than ?:
    461   void operator&(std::ostream&) { }
    462 };
    463 
    464 // Closes the log file explicitly if open.
    465 // NOTE: Since the log file is opened as necessary by the action of logging
    466 //       statements, there's no guarantee that it will stay closed
    467 //       after this call.
    468 void CloseLogFile();
    469 
    470 } // namespace Logging
    471 
    472 // These functions are provided as a convenience for logging, which is where we
    473 // use streams (it is against Google style to use streams in other places). It
    474 // is designed to allow you to emit non-ASCII Unicode strings to the log file,
    475 // which is normally ASCII. It is relatively slow, so try not to use it for
    476 // common cases. Non-ASCII characters will be converted to UTF-8 by these operators.
    477 std::ostream& operator<<(std::ostream& out, const wchar_t* wstr);
    478 inline std::ostream& operator<<(std::ostream& out, const std::wstring& wstr) {
    479   return out << wstr.c_str();
    480 }
    481 
    482 #endif  // BASE_LOGGING_H__
    483