summaryrefslogtreecommitdiff
diff options
context:
space:
mode:
author <shinichiro.hamaji@gmail.com>2009-01-15 10:34:35 +0000
committer <shinichiro.hamaji@gmail.com>2009-01-15 10:34:35 +0000
commite31a91b6502b3d15ecd7c2d1b518fafbc7234572 (patch)
treeae0e0e0995653622e0d753bbffa664fa7a506200
parenteecffc5aa5501b69e9d493ebe8b4e19699d62fb2 (diff)
downloadglog-e31a91b6502b3d15ecd7c2d1b518fafbc7234572.tar.gz
glog-e31a91b6502b3d15ecd7c2d1b518fafbc7234572.tar.bz2
glog-e31a91b6502b3d15ecd7c2d1b518fafbc7234572.zip
* Add LOG_TO_STRING.
* Add LOG_AT_LEVEL. * Add DVLOG. * Add LOG_TO_SINK_ONLY. * Log microseconds. * Add --log_backtrace_at option. * Introduce CrashReason class. * Fix some bugs. git-svn-id: https://google-glog.googlecode.com/svn/trunk@29 eb4d4688-79bd-11dd-afb4-1d65580434c0
-rw-r--r--src/glog/logging.h.in237
-rw-r--r--src/glog/raw_logging.h.in90
-rw-r--r--src/googletest.h5
-rw-r--r--src/logging.cc426
-rw-r--r--src/logging_unittest.cc202
-rw-r--r--src/logging_unittest.err582
-rw-r--r--src/raw_logging.cc72
-rw-r--r--src/utilities.cc68
-rw-r--r--src/utilities.h32
9 files changed, 1174 insertions, 540 deletions
diff --git a/src/glog/logging.h.in b/src/glog/logging.h.in
index 0949432..8f6389e 100644
--- a/src/glog/logging.h.in
+++ b/src/glog/logging.h.in
@@ -229,6 +229,35 @@ typedef unsigned __int64 uint64;
// --v=# set the verbose level
// --logtostderr log all the messages to stderr instead of to logfiles
+// LOG LINE PREFIX FORMAT
+//
+// Log lines have this form:
+//
+// Lmmdd hh:mm:ss.uuuuuu threadid file:line] msg...
+//
+// where the fields are defined as follows:
+//
+// L A single character, representing the log level
+// (eg 'I' for INFO)
+// mm The month (zero padded; ie May is '05')
+// dd The day (zero padded)
+// hh:mm:ss.uuuuuu Time in hours, minutes and fractional seconds
+// threadid The space-padded thread ID as returned by GetTID()
+// (this matches the PID on Linux)
+// file The file name
+// line The line number
+// msg The user-supplied message
+//
+// Example:
+//
+// I1103 11:57:31.739339 24395 google.cc:2341] Command line: ./some_prog
+// I1103 11:57:31.739403 24395 google.cc:2342] Process id 24395
+//
+// NOTE: although the microseconds are useful for comparing events on
+// a single machine, clocks on different machines may not be well
+// synchronized. Hence, use caution when comparing the low bits of
+// timestamps from different machines.
+
#ifndef DECLARE_VARIABLE
#define MUST_UNDEF_GFLAGS_DECLARE_MACROS
#define DECLARE_VARIABLE(type, name, tn) \
@@ -257,9 +286,23 @@ typedef unsigned __int64 uint64;
// Set whether log messages go to stderr instead of logfiles
DECLARE_bool(logtostderr);
-// Set how important a log message should be to avoid buffering
+// Set whether log messages go to stderr in addition to logfiles.
+DECLARE_bool(alsologtostderr);
+
+// Log messages at a level >= this flag are automatically sent to
+// stderr in addition to log files.
+DECLARE_int32(stderrthreshold);
+
+// Set whether the log prefix should be prepended to each line of output.
+DECLARE_bool(log_prefix);
+
+// Log messages at a level <= this flag are buffered.
+// Log messages at a higher level are flushed immediately.
DECLARE_int32(logbuflevel);
+// Sets the maximum number of seconds which logs may be buffered for.
+DECLARE_int32(logbufsecs);
+
// Log suppression level: messages logged at a lower level than this
// are suppressed.
DECLARE_int32(minloglevel);
@@ -268,10 +311,17 @@ DECLARE_int32(minloglevel);
// default logging directory.
DECLARE_string(log_dir);
+// Sets the path of the directory into which to put additional links
+// to the log files.
+DECLARE_string(log_link);
+
DECLARE_int32(v); // in vlog_is_on.cc
-DECLARE_int32(stderrthreshold);
-DECLARE_bool(alsologtostderr);
+// Sets the maximum log file size (in MB).
+DECLARE_int32(max_log_size);
+
+// Sets whether to avoid logging to the disk if the disk is full.
+DECLARE_bool(stop_logging_if_full_disk);
#ifdef MUST_UNDEF_GFLAGS_DECLARE_MACROS
#undef MUST_UNDEF_GFLAGS_DECLARE_MACROS
@@ -288,36 +338,53 @@ DECLARE_bool(alsologtostderr);
// LOG(INFO) and its ilk are used all over our code, it's
// better to have compact code for these operations.
-#if 0 >= GOOGLE_STRIP_LOG
-#define COMPACT_GOOGLE_LOG_INFO @ac_google_namespace@::LogMessage(__FILE__, __LINE__)
+#if GOOGLE_STRIP_LOG == 0
+#define COMPACT_GOOGLE_LOG_INFO @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__)
+#define LOG_TO_STRING_INFO(message) @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::INFO, message)
#else
#define COMPACT_GOOGLE_LOG_INFO @ac_google_namespace@::NullStream()
+#define LOG_TO_STRING_INFO(message) @ac_google_namespace@::NullStream()
#endif
-#if 1 >= GOOGLE_STRIP_LOG
-#define COMPACT_GOOGLE_LOG_WARNING @ac_google_namespace@::LogMessage(__FILE__, __LINE__, @ac_google_namespace@::WARNING)
+#if GOOGLE_STRIP_LOG <= 1
+#define COMPACT_GOOGLE_LOG_WARNING @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::WARNING)
+#define LOG_TO_STRING_WARNING(message) @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::WARNING, message)
#else
#define COMPACT_GOOGLE_LOG_WARNING @ac_google_namespace@::NullStream()
+#define LOG_TO_STRING_WARNING(message) @ac_google_namespace@::NullStream()
#endif
-#if 2 >= GOOGLE_STRIP_LOG
-#define COMPACT_GOOGLE_LOG_ERROR @ac_google_namespace@::LogMessage(__FILE__, __LINE__, @ac_google_namespace@::ERROR)
+#if GOOGLE_STRIP_LOG <= 2
+#define COMPACT_GOOGLE_LOG_ERROR @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::ERROR)
+#define LOG_TO_STRING_ERROR(message) @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::ERROR, message)
#else
#define COMPACT_GOOGLE_LOG_ERROR @ac_google_namespace@::NullStream()
+#define LOG_TO_STRING_ERROR(message) @ac_google_namespace@::NullStream()
#endif
-#if 3 >= GOOGLE_STRIP_LOG
-#define COMPACT_GOOGLE_LOG_FATAL @ac_google_namespace@::LogMessageFatal(__FILE__, __LINE__)
+#if GOOGLE_STRIP_LOG <= 3
+#define COMPACT_GOOGLE_LOG_FATAL @ac_google_namespace@::LogMessageFatal( \
+ __FILE__, __LINE__)
+#define LOG_TO_STRING_FATAL(message) @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::FATAL, message)
#else
#define COMPACT_GOOGLE_LOG_FATAL @ac_google_namespace@::NullStreamFatal()
+#define LOG_TO_STRING_FATAL(message) @ac_google_namespace@::NullStreamFatal()
#endif
// For DFATAL, we want to use LogMessage (as opposed to
// LogMessageFatal), to be consistent with the original behavior.
#ifdef NDEBUG
#define COMPACT_GOOGLE_LOG_DFATAL COMPACT_GOOGLE_LOG_ERROR
-#elif 3 >= GOOGLE_STRIP_LOG
-#define COMPACT_GOOGLE_LOG_DFATAL @ac_google_namespace@::LogMessage(__FILE__, __LINE__, @ac_google_namespace@::FATAL)
+#elif GOOGLE_STRIP_LOG <= 3
+#define COMPACT_GOOGLE_LOG_DFATAL LogMessage( \
+ __FILE__, __LINE__, @ac_google_namespace@::FATAL)
#else
#define COMPACT_GOOGLE_LOG_DFATAL @ac_google_namespace@::NullStreamFatal()
#endif
@@ -395,7 +462,7 @@ GOOGLE_GLOG_DLL_DECL void InstallFailureFunction(void (*fail_func)());
class LogSink; // defined below
// If a non-NULL sink pointer is given, we push this message to that sink.
-// We then do normal LOG(severity) logging as well.
+// For LOG_TO_SINK we then do normal LOG(severity) logging as well.
// This is useful for capturing messages and passing/storing them
// somewhere more specific than the global log of the process.
// Argument types:
@@ -403,8 +470,28 @@ class LogSink; // defined below
// LogSeverity severity;
// The cast is to disambiguate NULL arguments.
#define LOG_TO_SINK(sink, severity) \
- @ac_google_namespace@::LogMessage(__FILE__, __LINE__, @ac_google_namespace@::severity, \
- static_cast<@ac_google_namespace@::LogSink*>(sink)).stream()
+ @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, \
+ @ac_google_namespace@::severity, \
+ static_cast<@ac_google_namespace@::LogSink*>(sink), true).stream()
+#define LOG_TO_SINK_BUT_NOT_TO_LOGFILE(sink, severity) \
+ @ac_google_namespace@::LogMessage( \
+ __FILE__, __LINE__, \
+ @ac_google_namespace@::severity, \
+ static_cast<@ac_google_namespace@::LogSink*>(sink), false).stream()
+
+// If a non-NULL string pointer is given, we write this message to that string.
+// We then do normal LOG(severity) logging as well.
+// This is useful for capturing messages and storing them somewhere more
+// specific than the global log of the process.
+// Argument types:
+// string* message;
+// LogSeverity severity;
+// The cast is to disambiguate NULL arguments.
+// NOTE: LOG(severity) expands to LogMessage().stream() for the specified
+// severity.
+#define LOG_TO_STRING(severity, message) \
+ LOG_TO_STRING_##severity(static_cast<string*>(message)).stream()
// If a non-NULL pointer is given, we push the message onto the end
// of a vector of strings; otherwise, we report it with LOG(severity).
@@ -415,8 +502,7 @@ class LogSink; // defined below
// vector<string> *outvec;
// The cast is to disambiguate NULL arguments.
#define LOG_STRING(severity, outvec) \
- @ac_google_namespace@::LogMessage(__FILE__, __LINE__, @ac_google_namespace@::severity, \
- static_cast<std::vector<std::string>*>(outvec)).stream()
+ LOG_TO_STRING_##severity(static_cast<vector<string>*>(outvec)).stream()
#define LOG_IF(severity, condition) \
!(condition) ? (void) 0 : @ac_google_namespace@::LogMessageVoidify() & LOG(severity)
@@ -541,9 +627,13 @@ DEFINE_CHECK_OP_IMPL(_GT, > )
// in the macro.
typedef std::string _Check_string;
#define CHECK_OP_LOG(name, op, val1, val2, log) \
- while (@ac_google_namespace@::_Check_string* _result = \
- @ac_google_namespace@::Check##name##Impl((val1), (val2), #val1 " " #op " " #val2)) \
- log(__FILE__, __LINE__, @ac_google_namespace@::CheckOpString(_result)).stream()
+ while (@ac_google_namespace@::_Check_string* _result = \
+ @ac_google_namespace@::Check##name##Impl( \
+ @ac_google_namespace@::GetReferenceableValue(val1), \
+ @ac_google_namespace@::GetReferenceableValue(val2), \
+ #val1 " " #op " " #val2)) \
+ log(__FILE__, __LINE__, \
+ @ac_google_namespace@::CheckOpString(_result)).stream()
#else
// In optimized mode, use CheckOpString to hint to compiler that
// the while condition is unlikely.
@@ -555,8 +645,13 @@ typedef std::string _Check_string;
log(__FILE__, __LINE__, _result).stream()
#endif // STATIC_ANALYSIS, !NDEBUG
+#if GOOGLE_STRIP_LOG <= 3
#define CHECK_OP(name, op, val1, val2) \
CHECK_OP_LOG(name, op, val1, val2, @ac_google_namespace@::LogMessageFatal)
+#else
+#define CHECK_OP(name, op, val1, val2) \
+ CHECK_OP_LOG(name, op, val1, val2, @ac_google_namespace@::NullStreamFatal)
+#endif // STRIP_LOG <= 3
// Equality/Inequality checks - compare two values, and log a FATAL message
// including the two values when the result is not as expected. The values
@@ -715,7 +810,19 @@ PLOG_IF(FATAL, GOOGLE_PREDICT_BRANCH_NOT_TAKEN((invocation) == -1)) \
__FILE__, __LINE__, @ac_google_namespace@::severity, LOG_OCCURRENCES, \
&what_to_do).stream()
-#define LOG_EVERY_N(severity, n) \
+namespace glog_internal_namespace_ {
+template <bool>
+struct CompileAssert {
+};
+} // namespace glog_internal_namespace_
+
+#define GOOGLE_GLOG_COMPILE_ASSERT(expr, msg) \
+ typedef @ac_google_namespace@::glog_internal_namespace_::CompileAssert<(bool(expr))> msg[bool(expr) ? 1 : -1]
+
+#define LOG_EVERY_N(severity, n) \
+ GOOGLE_GLOG_COMPILE_ASSERT(@ac_google_namespace@::severity < \
+ @ac_google_namespace@::NUM_SEVERITIES, \
+ INVALID_REQUESTED_LOG_SEVERITY); \
SOME_KIND_OF_LOG_EVERY_N(severity, (n), @ac_google_namespace@::LogMessage::SendToLog)
#define SYSLOG_EVERY_N(severity, n) \
@@ -739,6 +846,7 @@ enum PRIVATE_Counter {COUNTER};
#ifndef NDEBUG
#define DLOG(severity) LOG(severity)
+#define DVLOG(verboselevel) VLOG(verboselevel)
#define DLOG_IF(severity, condition) LOG_IF(severity, condition)
#define DLOG_EVERY_N(severity, n) LOG_EVERY_N(severity, n)
#define DLOG_IF_EVERY_N(severity, condition, n) \
@@ -763,6 +871,10 @@ enum PRIVATE_Counter {COUNTER};
#define DLOG(severity) \
true ? (void) 0 : @ac_google_namespace@::LogMessageVoidify() & LOG(severity)
+#define DVLOG(verboselevel) \
+ (true || !VLOG_IS_ON(verboselevel)) ?\
+ (void) 0 : @ac_google_namespace@::LogMessageVoidify() & LOG(INFO)
+
#define DLOG_IF(severity, condition) \
(true || !(condition)) ? (void) 0 : @ac_google_namespace@::LogMessageVoidify() & LOG(severity)
@@ -908,9 +1020,11 @@ public:
// saves 17 bytes per call site.
LogMessage(const char* file, int line, LogSeverity severity);
- // Constructor to also log this message to a specified sink (if not NULL).
- // Implied are: ctr = 0, send_method = &LogMessage::SendToSinkAndLog.
- LogMessage(const char* file, int line, LogSeverity severity, LogSink* sink);
+ // Constructor to log this message to a specified sink (if not NULL).
+ // Implied are: ctr = 0, send_method = &LogMessage::SendToSinkAndLog if
+ // also_send_to_log is true, send_method = &LogMessage::SendToSink otherwise.
+ LogMessage(const char* file, int line, LogSeverity severity, LogSink* sink,
+ bool also_send_to_log);
// Constructor where we also give a vector<string> pointer
// for storing the messages (if the pointer is not NULL).
@@ -918,6 +1032,12 @@ public:
LogMessage(const char* file, int line, LogSeverity severity,
std::vector<std::string>* outvec);
+ // Constructor where we also give a string pointer for storing the
+ // message (if the pointer is not NULL). Implied are: ctr = 0,
+ // send_method = &LogMessage::WriteToStringAndLog.
+ LogMessage(const char* file, int line, LogSeverity severity,
+ std::string* message);
+
// A special constructor used for check failures
LogMessage(const char* file, int line, const CheckOpString& result);
@@ -940,7 +1060,7 @@ public:
// Call abort() or similar to perform LOG(FATAL) crash.
static void Fail() @ac_cv___attribute___noreturn@;
- std::ostream& stream() { return data_->stream_; }
+ std::ostream& stream() { return *(data_->stream_); }
int preserved_errno() const { return data_->preserved_errno_; }
@@ -948,58 +1068,57 @@ public:
static int64 num_messages(int severity);
private:
-
// Fully internal SendMethod cases:
void SendToSinkAndLog(); // Send to sink if provided and dispatch to the logs
- void SaveOrSendToLog(); // Save to stringvec if provided, else to logs
+ void SendToSink(); // Send to sink if provided, do nothing otherwise.
- struct LogMessageData;
+ // Write to string if provided and dispatch to the logs.
+ void WriteToStringAndLog();
+
+ void SaveOrSendToLog(); // Save to stringvec if provided, else to logs
void Init(const char* file, int line, LogSeverity severity,
void (LogMessage::*send_method)());
- LogMessageData* GetMessageData(int preserved_errno, LogSeverity, int ctr);
-
// Counts of messages sent at each priority:
static int64 num_messages_[NUM_SEVERITIES]; // under log_mutex
// We keep the data in a separate struct so that each instance of
// LogMessage uses less stack space.
struct GOOGLE_GLOG_DLL_DECL LogMessageData {
- // ORDER DEPENDENCY: preserved_errno_ comes before buf_ comes before
- // message_text_ comes before stream_
+ LogMessageData() {};
+
int preserved_errno_; // preserved errno
char* buf_;
char* message_text_; // Complete message text (points to selected buffer)
- LogStream stream_;
- const char severity_; // What level is this LogMessage logged at?
+ LogStream* stream_alloc_;
+ LogStream* stream_;
+ char severity_; // What level is this LogMessage logged at?
int line_; // line number where logging call is.
void (LogMessage::*send_method_)(); // Call this in destructor to send
union { // At most one of these is used: union to keep the size low.
- LogSink* sink_; // NULL or sink to send message to
- std::vector<std::string>* outvec_; // NULL or vector to push message onto
+ LogSink* sink_; // NULL or sink to send message to
+ std::vector<std::string>* outvec_; // NULL or vector to push message onto
+ std::string* message_; // NULL or string to write message into
};
- time_t timestamp_; // Time of creation of LogMessage
- struct ::tm tm_time_; // Time of creation of LogMessage
- size_t num_prefix_chars_; // How many chars of "prefix" for this message?
- size_t num_chars_to_log_; // How many chars of msg to send to log?
- size_t num_chars_to_syslog_; // How many chars of msg to send to syslog?
-
- const char* basename_; // basename of the file which called LOG.
- const char* fullname_; // full name (including directory)
- // of the file which called LOG.
-
- bool has_been_flushed_; // False if data has not yet been flushed.
+ time_t timestamp_; // Time of creation of LogMessage
+ struct ::tm tm_time_; // Time of creation of LogMessage
+ size_t num_prefix_chars_; // # of chars of prefix in this message
+ size_t num_chars_to_log_; // # of chars of msg to send to log
+ size_t num_chars_to_syslog_; // # of chars of msg to send to syslog
+ const char* basename_; // basename of file that called LOG
+ const char* fullname_; // fullname of file that called LOG
+ bool has_been_flushed_; // false => data has not been flushed
+ bool first_fatal_; // true => this was first fatal msg
- LogMessageData(int preserved_errno, LogSeverity severity, int ctr);
~LogMessageData();
-
private:
LogMessageData(const LogMessageData&);
void operator=(const LogMessageData&);
};
- static LogMessageData fatal_message_data_;
+ static LogMessageData fatal_msg_data_exclusive_;
+ static LogMessageData fatal_msg_data_shared_;
LogMessageData* allocated_;
LogMessageData* data_;
@@ -1022,10 +1141,16 @@ class GOOGLE_GLOG_DLL_DECL LogMessageFatal : public LogMessage {
// A non-macro interface to the log facility; (useful
// when the logging level is not a compile-time constant).
-inline void LogAtLevel(int const log_level, std::string const &msg) {
- LogMessage(__FILE__, __LINE__, log_level).stream() << msg;
+inline void LogAtLevel(int const severity, std::string const &msg) {
+ LogMessage(__FILE__, __LINE__, severity).stream() << msg;
}
+// A macro alternative of LogAtLevel. New code may want to use this
+// version since there are two advantages: 1. this version outputs the
+// file name and the line number where this macro is put like other
+// LOG macros, 2. this macro can be used as C++ stream.
+#define LOG_AT_LEVEL(severity) LogMessage(__FILE__, __LINE__, severity).stream()
+
// A small helper for CHECK_NOTNULL().
template <typename T>
T* CheckNotNull(const char *file, int line, const char *names, T* t) {
@@ -1284,6 +1409,9 @@ class GOOGLE_GLOG_DLL_DECL NullStream : public LogMessage::LogStream {
// NullStream& is implicitly converted to LogStream&, in which case
// the overloaded NullStream::operator<< will not be invoked.
NullStream() : LogMessage::LogStream(message_buffer_, 1, 0) { }
+ NullStream(const char* /*file*/, int /*line*/,
+ const CheckOpString& /*result*/) :
+ LogMessage::LogStream(message_buffer_, 1, 0) { }
NullStream &stream() { return *this; }
private:
// A very short buffer for messages (which we discard anyway). This
@@ -1305,6 +1433,9 @@ inline NullStream& operator<<(NullStream &str, const T &value) { return str; }
// trace), like LogMessageFatal.
class GOOGLE_GLOG_DLL_DECL NullStreamFatal : public NullStream {
public:
+ NullStreamFatal() { }
+ NullStreamFatal(const char* file, int line, const CheckOpString& result) :
+ NullStream(file, line, result) { }
@ac_cv___attribute___noreturn@ ~NullStreamFatal() { _exit(1); }
};
diff --git a/src/glog/raw_logging.h.in b/src/glog/raw_logging.h.in
index c7d92d9..c785c36 100644
--- a/src/glog/raw_logging.h.in
+++ b/src/glog/raw_logging.h.in
@@ -1,12 +1,12 @@
// Copyright 2006 Google Inc. All Rights Reserved.
// Author: Maxim Lifantsev
//
-// Logging routines that do not allocate any memory and acquire any
-// locks, and can therefore be used by low-level memory allocation
-// and synchronization code.
+// Thread-safe logging routines that do not allocate any memory or
+// acquire any locks, and can therefore be used by low-level memory
+// allocation and synchronization code.
-#ifndef BASE_RAW_LOGGING_H__
-#define BASE_RAW_LOGGING_H__
+#ifndef BASE_RAW_LOGGING_H_
+#define BASE_RAW_LOGGING_H_
@ac_google_start_namespace@
@@ -38,26 +38,79 @@
// I0821 211317 file.cc:142] RAW: status is 20
#define RAW_LOG(severity, ...) \
do { \
- @ac_google_namespace@::RawLog__(@ac_google_namespace@::severity, __FILE__, __LINE__, __VA_ARGS__); \
+ switch (@ac_google_namespace@::severity) { \
+ case 0: \
+ RAW_LOG_INFO(__VA_ARGS__); \
+ break; \
+ case 1: \
+ RAW_LOG_WARNING(__VA_ARGS__); \
+ break; \
+ case 2: \
+ RAW_LOG_ERROR(__VA_ARGS__); \
+ break; \
+ case 3: \
+ RAW_LOG_FATAL(__VA_ARGS__); \
+ break; \
+ default: \
+ break; \
+ } \
} while (0)
+// The following STRIP_LOG testing is performed in the header file so that it's
+// possible to completely compile out the logging code and the log messages.
+#if STRIP_LOG == 0
#define RAW_VLOG(verboselevel, ...) \
do { \
if (VLOG_IS_ON(verboselevel)) { \
- @ac_google_namespace@::RawLog__(@ac_google_namespace@::INFO, __FILE__, __LINE__, __VA_ARGS__); \
+ RAW_LOG_INFO(__VA_ARGS__); \
} \
} while (0)
+#else
+#define RAW_VLOG(verboselevel, ...) RawLogStub__(0, __VA_ARGS__)
+#endif // STRIP_LOG == 0
+
+#if STRIP_LOG == 0
+#define RAW_LOG_INFO(...) @ac_google_namespace@::RawLog__(@ac_google_namespace@::INFO, \
+ __FILE__, __LINE__, __VA_ARGS__)
+#else
+#define RAW_LOG_INFO(...) @ac_google_namespace@::RawLogStub__(0, __VA_ARGS__)
+#endif // STRIP_LOG == 0
+
+#if STRIP_LOG <= 1
+#define RAW_LOG_WARNING(...) @ac_google_namespace@::RawLog__(@ac_google_namespace@::WARNING, \
+ __FILE__, __LINE__, __VA_ARGS__)
+#else
+#define RAW_LOG_WARNING(...) @ac_google_namespace@::RawLogStub__(0, __VA_ARGS__)
+#endif // STRIP_LOG <= 1
+
+#if STRIP_LOG <= 2
+#define RAW_LOG_ERROR(...) @ac_google_namespace@::RawLog__(@ac_google_namespace@::ERROR, \
+ __FILE__, __LINE__, __VA_ARGS__)
+#else
+#define RAW_LOG_ERROR(...) @ac_google_namespace@::RawLogStub__(0, __VA_ARGS__)
+#endif // STRIP_LOG <= 2
+
+#if STRIP_LOG <= 3
+#define RAW_LOG_FATAL(...) @ac_google_namespace@::RawLog__(@ac_google_namespace@::FATAL, \
+ __FILE__, __LINE__, __VA_ARGS__)
+#else
+#define RAW_LOG_FATAL(...) \
+ do { \
+ @ac_google_namespace@::RawLogStub__(0, __VA_ARGS__); \
+ exit(1); \
+ } while (0)
+#endif // STRIP_LOG <= 3
// Similar to CHECK(condition) << message,
// but for low-level modules: we use only RAW_LOG that does not allocate memory.
// We do not want to provide args list here to encourage this usage:
// if (!cond) RAW_LOG(FATAL, "foo ...", hard_to_compute_args);
// so that the args are not computed when not needed.
-#define RAW_CHECK(condition, message) \
- do { \
- if (!(condition)) { \
- RAW_LOG(FATAL, "Check %s failed: %s", #condition, message); \
- } \
+#define RAW_CHECK(condition, message) \
+ do { \
+ if (!(condition)) { \
+ RAW_LOG(FATAL, "Check %s failed: %s", #condition, message); \
+ } \
} while (0)
// Debug versions of RAW_LOG and RAW_CHECK
@@ -68,8 +121,8 @@
#else // NDEBUG
-#define RAW_DLOG(severity, ...) \
- while (false) \
+#define RAW_DLOG(severity, ...) \
+ while (false) \
RAW_LOG(severity, __VA_ARGS__)
#define RAW_DCHECK(condition, message) \
while (false) \
@@ -77,6 +130,11 @@
#endif // NDEBUG
+// Stub log function used to work around for unused variable warnings when
+// building with STRIP_LOG > 0.
+static inline void RawLogStub__(int ignored, ...) {
+}
+
// Helper function to implement RAW_LOG and RAW_VLOG
// Logs format... at "severity" level, reporting it
// as called from file:line.
@@ -91,8 +149,8 @@ GOOGLE_GLOG_DLL_DECL void RawLog__(LogSeverity severity,
// this module does not have to directly call localtime_r(),
// which could allocate memory.
extern "C" struct ::tm;
-GOOGLE_GLOG_DLL_DECL void RawLog__SetLastTime(const struct ::tm& t);
+GOOGLE_GLOG_DLL_DECL void RawLog__SetLastTime(const struct ::tm& t, int usecs);
@ac_google_end_namespace@
-#endif // BASE_RAW_LOGGING_H__
+#endif // BASE_RAW_LOGGING_H_
diff --git a/src/googletest.h b/src/googletest.h
index 8b669f2..4a4475b 100644
--- a/src/googletest.h
+++ b/src/googletest.h
@@ -58,7 +58,7 @@ DEFINE_string(test_srcdir, TEST_SRC_DIR,
#ifdef NDEBUG
DEFINE_int32(benchmark_iters, 100000000, "Number of iterations per benchmark");
#else
-DEFINE_int32(benchmark_iters, 1000000, "Number of iterations per benchmark");
+DEFINE_int32(benchmark_iters, 100000, "Number of iterations per benchmark");
#endif
#ifdef HAVE_LIB_GTEST
@@ -153,7 +153,7 @@ static int RUN_ALL_TESTS() {
_END_GOOGLE_NAMESPACE_
-#endif
+#endif // ! HAVE_LIB_GTEST
_START_GOOGLE_NAMESPACE_
@@ -366,7 +366,6 @@ static string MungeLine(const string& line) {
}
if (!before.empty()) before += " ";
iss >> time;
- CHECK_EQ(6, time.size());
iss >> thread_lineinfo;
CHECK(!thread_lineinfo.empty());
if (thread_lineinfo[thread_lineinfo.size() - 1] != ']') {
diff --git a/src/logging.cc b/src/logging.cc
index 2f34c4c..04580e5 100644
--- a/src/logging.cc
+++ b/src/logging.cc
@@ -33,10 +33,15 @@
#include "glog/raw_logging.h"
#include "base/googleinit.h"
+#ifdef HAVE_STACKTRACE
+# include "stacktrace.h"
+#endif
+
using std::string;
using std::vector;
using std::ostrstream;
using std::setw;
+using std::setfill;
using std::hex;
using std::dec;
using std::min;
@@ -44,10 +49,32 @@ using std::ostream;
using std::ostringstream;
using std::strstream;
-DEFINE_bool(logtostderr, false,
+// There is no thread annotation support.
+#define EXCLUSIVE_LOCKS_REQUIRED(mu)
+
+static bool BoolFromEnv(const char *varname, bool defval) {
+ const char* const valstr = getenv(varname);
+ if (!valstr) {
+ return defval;
+ }
+ return memchr("tTyY1\0", valstr[0], 6) != NULL;
+}
+
+DEFINE_bool(logtostderr, BoolFromEnv("GOOGLE_LOGTOSTDERR", false),
"log messages go to stderr instead of logfiles");
-DEFINE_bool(alsologtostderr, false,
+DEFINE_bool(alsologtostderr, BoolFromEnv("GOOGLE_ALSOLOGTOSTDERR", false),
"log messages go to stderr in addition to logfiles");
+#ifdef OS_LINUX
+DEFINE_bool(drop_log_memory, true, "Drop in-memory buffers of log contents. "
+ "Logs can grow very quickly and they are rarely read before they "
+ "need to be evicted from memory. Instead, drop them from memory "
+ "as soon as they are flushed to disk.");
+_START_GOOGLE_NAMESPACE_
+namespace logging {
+static const int64 kPageSize = getpagesize();
+}
+_END_GOOGLE_NAMESPACE_
+#endif
// By default, errors (including fatal errors) get logged to stderr as
// well as the file.
@@ -100,11 +127,15 @@ DEFINE_string(log_link, "", "Put additional links to the log "
"files in this directory");
DEFINE_int32(max_log_size, 1800,
- "approx. maximum log file size (in MB)");
+ "approx. maximum log file size (in MB). A value of 0 will "
+ "be silently overridden to 1.");
DEFINE_bool(stop_logging_if_full_disk, false,
"Stop attempting to log to disk if the disk is full.");
+DEFINE_string(log_backtrace_at, "",
+ "Emit a backtrace when logging at file:linenum.");
+
// TODO(hamaji): consider windows
#define PATH_SEPARATOR '/'
@@ -132,6 +163,11 @@ static void GetHostName(string* hostname) {
_START_GOOGLE_NAMESPACE_
+// Safely get max_log_size, overriding to 1 if it somehow gets defined as 0
+static int32 MaxLogSize() {
+ return (FLAGS_max_log_size > 0 ? FLAGS_max_log_size : 1);
+}
+
// A mutex that allows only one thread to log at a time, to keep things from
// getting jumbled. Some other very uncommon logging operations (like
// changing the destination file for log messages of a given severity) also
@@ -149,6 +185,9 @@ const char*const LogSeverityNames[NUM_SEVERITIES] = {
"INFO", "WARNING", "ERROR", "FATAL"
};
+// Has the user called SetExitOnDFatal(true)?
+static bool exit_on_dfatal = true;
+
const char* GetLogSeverityName(LogSeverity severity) {
return LogSeverityNames[severity];
}
@@ -307,8 +346,8 @@ class LogDestination {
// Errors do not get logged to email by default.
LogSeverity LogDestination::email_logging_severity_ = 99999;
-string LogDestination::addresses_ = "";
-string LogDestination::hostname_ = "";
+string LogDestination::addresses_;
+string LogDestination::hostname_;
vector<LogSink*>* LogDestination::sinks_ = NULL;
Mutex LogDestination::sink_mutex_;
@@ -521,8 +560,10 @@ inline void LogDestination::WaitForSinks(LogMessage::LogMessageData* data) {
(*sinks_)[i]->WaitTillSent();
}
}
- if (data->send_method_ == &LogMessage::SendToSinkAndLog &&
- data->sink_ != NULL) {
+ const bool send_to_sink =
+ (data->send_method_ == &LogMessage::SendToSink) ||
+ (data->send_method_ == &LogMessage::SendToSinkAndLog);
+ if (send_to_sink && data->sink_ != NULL) {
data->sink_->WaitTillSent();
}
}
@@ -675,8 +716,8 @@ void LogFileObject::Write(bool force_flush,
return;
}
- if (static_cast<int>(file_length_ >> 20) >= FLAGS_max_log_size) {
- fclose(file_);
+ if (static_cast<int>(file_length_ >> 20) >= MaxLogSize()) {
+ if (file_ != NULL) fclose(file_);
file_ = NULL;
file_length_ = bytes_since_flush_ = 0;
rollover_attempt_ = kRolloverAttemptFrequency-1;
@@ -778,6 +819,8 @@ void LogFileObject::Write(bool force_flush,
<< setw(2) << tm_time.tm_sec << '\n'
<< "Running on machine: "
<< LogDestination::hostname() << '\n'
+ << "Log line format: [IWEF]mmdd hh:mm:ss.uuuuuu "
+ << "threadid file:line] msg" << '\n'
<< '\0';
int header_len = strlen(file_header_string);
fwrite(file_header_string, 1, header_len, file_);
@@ -814,153 +857,168 @@ void LogFileObject::Write(bool force_flush,
(bytes_since_flush_ >= 1000000) ||
(CycleClock_Now() >= next_flush_time_) ) {
FlushUnlocked();
+#ifdef OS_LINUX
+ if (FLAGS_drop_log_memory) {
+ if (file_length_ >= logging::kPageSize) {
+ // don't evict the most recent page
+ uint32 len = file_length_ & ~(logging::kPageSize - 1);
+ posix_fadvise(fileno(file_), 0, len, POSIX_FADV_DONTNEED);
+ }
+ }
+#endif
}
}
} // namespace
-//
-// LogMessage's constructor starts each message with a string like:
-// I1018 160715 logging.cc:1153]
-// (1st letter of severity level, GMT month, date, & time;
-// thread id (if not 0x400); basename of file and line of the logging command)
-// We ignore thread id 0x400 because it seems to be the default for single-
-// threaded programs.
-
// An arbitrary limit on the length of a single log message. This
// is so that streaming can be done more efficiently.
const size_t LogMessage::kMaxLogMessageLen = 30000;
-// Need to reserve some space for FATAL messages because
-// we usually do LOG(FATAL) when we ran out of heap memory.
-// However, since LogMessage() also calls new[], in this case,
-// it will recusively call LOG(FATAL), which then call new[] ... etc.
-// Eventually, the program will run out of stack memory and no message
-// will get logged. Note that we will not be protecting this buffer
-// with a lock because the chances are very small that there will
-// be a contention during LOG(FATAL) which can only happen at most
-// once per program.
-static char fatal_message_buffer[LogMessage::kMaxLogMessageLen+1];
-
-// Similarly we reserve space for a LogMessageData struct to be used
-// for FATAL messages.
-LogMessage::LogMessageData LogMessage::fatal_message_data_(0, FATAL, 0);
-
-LogMessage::LogMessageData::LogMessageData(int preserved_errno,
- LogSeverity severity,
- int ctr) :
- // ORDER DEPENDENCY: buf_ comes before message_text_ comes before stream_
- preserved_errno_(preserved_errno),
- // Use static buffer for LOG(FATAL)
- buf_((severity != FATAL) ? new char[kMaxLogMessageLen+1] : NULL),
- message_text_((severity != FATAL) ? buf_ : fatal_message_buffer),
- stream_(message_text_, kMaxLogMessageLen, ctr),
- severity_(severity) {
-}
+// Static log data space to avoid alloc failures in a LOG(FATAL)
+//
+// Since multiple threads may call LOG(FATAL), and we want to preserve
+// the data from the first call, we allocate two sets of space. One
+// for exclusive use by the first thread, and one for shared use by
+// all other threads.
+static Mutex fatal_msg_lock;
+static CrashReason crash_reason;
+static bool fatal_msg_exclusive = true;
+static char fatal_msg_buf_exclusive[LogMessage::kMaxLogMessageLen+1];
+static char fatal_msg_buf_shared[LogMessage::kMaxLogMessageLen+1];
+static LogMessage::LogStream fatal_msg_stream_exclusive(
+ fatal_msg_buf_exclusive, LogMessage::kMaxLogMessageLen, 0);
+static LogMessage::LogStream fatal_msg_stream_shared(
+ fatal_msg_buf_shared, LogMessage::kMaxLogMessageLen, 0);
+LogMessage::LogMessageData LogMessage::fatal_msg_data_exclusive_;
+LogMessage::LogMessageData LogMessage::fatal_msg_data_shared_;
LogMessage::LogMessageData::~LogMessageData() {
delete[] buf_;
-}
-
-LogMessage::LogMessageData* LogMessage::GetMessageData(int preserved_errno,
- LogSeverity severity,
- int ctr) {
- if (severity != FATAL) {
- return allocated_;
- } else {
- fatal_message_data_.preserved_errno_ = preserved_errno;
- fatal_message_data_.stream_.set_ctr(ctr);
- return &fatal_message_data_;
- }
+ delete stream_alloc_;
}
LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
- int ctr, void (LogMessage::*send_method)()) :
- allocated_((severity != FATAL) ?
- new LogMessageData(errno, severity, ctr) : NULL),
- data_(GetMessageData(errno, severity, ctr)) {
+ int ctr, void (LogMessage::*send_method)()) {
Init(file, line, severity, send_method);
+ data_->stream_->set_ctr(ctr);
}
-LogMessage::LogMessage(const char* file, int line, const CheckOpString& result)
- : allocated_(NULL),
- data_(GetMessageData(errno, FATAL, 0)) {
+LogMessage::LogMessage(const char* file, int line,
+ const CheckOpString& result) {
Init(file, line, FATAL, &LogMessage::SendToLog);
stream() << "Check failed: " << (*result.str_) << " ";
}
-LogMessage::LogMessage(const char* file, int line) :
- allocated_(new LogMessageData(errno, INFO, 0)),
- data_(GetMessageData(errno, INFO, 0)) {
+LogMessage::LogMessage(const char* file, int line) {
Init(file, line, INFO, &LogMessage::SendToLog);
}
-LogMessage::LogMessage(const char* file, int line, LogSeverity severity) :
- allocated_((severity != FATAL) ?
- new LogMessageData(errno, severity, 0) : NULL),
- data_(GetMessageData(errno, severity, 0)) {
+LogMessage::LogMessage(const char* file, int line, LogSeverity severity) {
Init(file, line, severity, &LogMessage::SendToLog);
}
LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
- LogSink* sink) :
- allocated_((severity != FATAL) ?
- new LogMessageData(errno, severity, 0) : NULL),
- data_(GetMessageData(errno, severity, 0)) {
- Init(file, line, severity, &LogMessage::SendToSinkAndLog);
+ LogSink* sink, bool also_send_to_log) {
+ Init(file, line, severity, also_send_to_log ? &LogMessage::SendToSinkAndLog :
+ &LogMessage::SendToSink);
data_->sink_ = sink; // override Init()'s setting to NULL
}
LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
- vector<string> *outvec) :
- allocated_((severity != FATAL) ?
- new LogMessageData(errno, severity, 0) : NULL),
- data_(GetMessageData(errno, severity, 0)) {
+ vector<string> *outvec) {
Init(file, line, severity, &LogMessage::SaveOrSendToLog);
data_->outvec_ = outvec; // override Init()'s setting to NULL
}
-void LogMessage::Init(const char* file, int line, LogSeverity severity,
+LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
+ string *message) {
+ Init(file, line, severity, &LogMessage::WriteToStringAndLog);
+ data_->message_ = message; // override Init()'s setting to NULL
+}
+
+void LogMessage::Init(const char* file,
+ int line,
+ LogSeverity severity,
void (LogMessage::*send_method)()) {
+ allocated_ = NULL;
+ if (severity != FATAL || !exit_on_dfatal) {
+ allocated_ = new LogMessageData();
+ data_ = allocated_;
+ data_->buf_ = new char[kMaxLogMessageLen+1];
+ data_->message_text_ = data_->buf_;
+ data_->stream_alloc_ =
+ new LogStream(data_->message_text_, kMaxLogMessageLen, 0);
+ data_->stream_ = data_->stream_alloc_;
+ data_->first_fatal_ = false;
+ } else {
+ MutexLock l(&fatal_msg_lock);
+ if (fatal_msg_exclusive) {
+ fatal_msg_exclusive = false;
+ data_ = &fatal_msg_data_exclusive_;
+ data_->message_text_ = fatal_msg_buf_exclusive;
+ data_->stream_ = &fatal_msg_stream_exclusive;
+ data_->first_fatal_ = true;
+ } else {
+ data_ = &fatal_msg_data_shared_;
+ data_->message_text_ = fatal_msg_buf_shared;
+ data_->stream_ = &fatal_msg_stream_shared;
+ data_->first_fatal_ = false;
+ }
+ data_->stream_alloc_ = NULL;
+ }
+
+ stream().fill('0');
+ data_->preserved_errno_ = errno;
+ data_->severity_ = severity;
data_->line_ = line;
data_->send_method_ = send_method;
-
- data_->outvec_ = NULL;
data_->sink_ = NULL;
- data_->timestamp_ = time(NULL);
+ data_->outvec_ = NULL;
+ WallTime now = WallTime_Now();
+ data_->timestamp_ = static_cast<time_t>(now);
localtime_r(&data_->timestamp_, &data_->tm_time_);
- RawLog__SetLastTime(data_->tm_time_);
+ int usecs = static_cast<int>((now - data_->timestamp_) * 1000000);
+ RawLog__SetLastTime(data_->tm_time_, usecs);
+
+ data_->num_chars_to_log_ = 0;
+ data_->num_chars_to_syslog_ = 0;
data_->basename_ = const_basename(file);
data_->fullname_ = file;
- data_->stream_.fill('0');
+ data_->has_been_flushed_ = false;
- // In some cases, we use logging like a print mechanism and
- // the prefixes get in the way
+ // If specified, prepend a prefix to each line. For example:
+ // I1018 160715 f5d4fbb0 logging.cc:1153]
+ // (log level, GMT month, date, time, thread_id, file basename, line)
+ // We exclude the thread_id for the default thread.
if (FLAGS_log_prefix && (line != kNoLogPrefix)) {
- if ( is_default_thread() ) {
- stream() << LogSeverityNames[severity][0]
- << setw(2) << 1+data_->tm_time_.tm_mon
- << setw(2) << data_->tm_time_.tm_mday
- << ' '
- << setw(2) << data_->tm_time_.tm_hour
- << setw(2) << data_->tm_time_.tm_min
- << setw(2) << data_->tm_time_.tm_sec
- << ' ' << data_->basename_ << ':' << data_->line_ << "] ";
- } else {
- stream() << LogSeverityNames[severity][0]
- << setw(2) << 1+data_->tm_time_.tm_mon
- << setw(2) << data_->tm_time_.tm_mday
- << ' '
- << setw(2) << data_->tm_time_.tm_hour
- << setw(2) << data_->tm_time_.tm_min
- << setw(2) << data_->tm_time_.tm_sec
- << ' ' << setw(8) << std::hex << pthread_self() << std::dec
- << ' ' << data_->basename_ << ':' << data_->line_ << "] ";
+ stream() << LogSeverityNames[severity][0]
+ << setw(2) << 1+data_->tm_time_.tm_mon
+ << setw(2) << data_->tm_time_.tm_mday
+ << ' '
+ << setw(2) << data_->tm_time_.tm_hour << ':'
+ << setw(2) << data_->tm_time_.tm_min << ':'
+ << setw(2) << data_->tm_time_.tm_sec << "."
+ << setw(6) << usecs
+ << ' '
+ << setfill(' ') << setw(5)
+ << static_cast<unsigned int>(GetTID()) << setfill('0')
+ << ' '
+ << data_->basename_ << ':' << data_->line_ << "] ";
+ }
+ data_->num_prefix_chars_ = data_->stream_->pcount();
+
+ if (!FLAGS_log_backtrace_at.empty()) {
+ char fileline[128];
+ snprintf(fileline, sizeof(fileline), "%s:%d", data_->basename_, line);
+#ifdef HAVE_STACKTRACE
+ if (!strcmp(FLAGS_log_backtrace_at.c_str(), fileline)) {
+ string stacktrace;
+ DumpStackTraceToString(&stacktrace);
+ stream() << " (stacktrace:\n" << stacktrace << ") ";
}
+#endif
}
-
- data_->num_prefix_chars_ = data_->stream_.pcount();
- data_->has_been_flushed_ = false;
}
LogMessage::~LogMessage() {
@@ -974,13 +1032,13 @@ void LogMessage::Flush() {
if (data_->has_been_flushed_ || data_->severity_ < FLAGS_minloglevel)
return;
- data_->num_chars_to_log_ = data_->stream_.pcount();
+ data_->num_chars_to_log_ = data_->stream_->pcount();
data_->num_chars_to_syslog_ =
data_->num_chars_to_log_ - data_->num_prefix_chars_;
// Do we need to add a \n to the end of this message?
bool append_newline =
- (data_->message_text_[data_->num_chars_to_log_-1] != '\n');
+ (data_->message_text_[data_->num_chars_to_log_-1] != '\n');
char original_final_char = '\0';
// If we do need to add a \n, we'll do it by violating the memory of the
@@ -1022,13 +1080,9 @@ void LogMessage::Flush() {
data_->has_been_flushed_ = true;
}
-// Copy of FATAL log message so that we can print it out again after
-// all the stack traces.
-// We cannot simply use fatal_message_buffer, because two or more FATAL log
-// messages may happen in a row. This is a real possibility given that
-// FATAL log messages are often associated with corrupted process state.
-// In this case, we still want to reprint the first FATAL log message, so
-// we need to save away the first message in a separate buffer.
+// Copy of first FATAL log message so that we can print it out again
+// after all the stack traces. To preserve legacy behavior, we don't
+// use fatal_msg_buf_exclusive.
static time_t fatal_time;
static char fatal_message[256];
@@ -1044,7 +1098,7 @@ void ReprintFatalMessage() {
}
// L >= log_mutex (callers must hold the log_mutex).
-void LogMessage::SendToLog() {
+void LogMessage::SendToLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
static bool already_warned_before_initgoogle = false;
log_mutex.AssertHeld();
@@ -1097,13 +1151,28 @@ void LogMessage::SendToLog() {
// If we log a FATAL message, flush all the log destinations, then toss
// a signal for others to catch. We leave the logs in a state that
// someone else can use them (as long as they flush afterwards)
- if (data_->severity_ == FATAL) {
- // save away the fatal message so we can print it again later
- const int copy = min<int>(data_->num_chars_to_log_,
- sizeof(fatal_message)-1);
- memcpy(fatal_message, data_->message_text_, copy);
- fatal_message[copy] = '\0';
- fatal_time = data_->timestamp_;
+ if (data_->severity_ == FATAL && exit_on_dfatal) {
+ if (data_->first_fatal_) {
+ crash_reason.filename = fatal_msg_data_exclusive_.fullname_;
+ crash_reason.line_number = fatal_msg_data_exclusive_.line_;
+ crash_reason.message = fatal_msg_buf_exclusive +
+ fatal_msg_data_exclusive_.num_prefix_chars_;
+#ifdef HAVE_STACKTRACE
+ crash_reason.depth = GetStackTrace(crash_reason.stack,
+ ARRAYSIZE(crash_reason.stack),
+ 3);
+#else
+ crash_reason.depth = 0;
+#endif
+ SetCrashReason(&crash_reason);
+
+ // Store shortened fatal message for other logs and GWQ status
+ const int copy = min<int>(data_->num_chars_to_log_,
+ sizeof(fatal_message)-1);
+ memcpy(fatal_message, data_->message_text_, copy);
+ fatal_message[copy] = '\0';
+ fatal_time = data_->timestamp_;
+ }
if (!FLAGS_logtostderr) {
for (int i = 0; i < NUM_SEVERITIES; ++i) {
@@ -1111,7 +1180,7 @@ void LogMessage::SendToLog() {
LogDestination::log_destinations_[i]->logger_->Write(true, 0, "", 0);
}
}
-
+
// release the lock that our caller (directly or indirectly)
// LogMessage::~LogMessage() grabbed so that signal handlers
// can use the logging facility. Alternately, we could add
@@ -1120,6 +1189,8 @@ void LogMessage::SendToLog() {
log_mutex.Unlock();
LogDestination::WaitForSinks(data_);
+ const char* message = "*** Check failure stack trace: ***\n";
+ write(STDERR_FILENO, message, strlen(message));
Fail();
}
}
@@ -1150,7 +1221,7 @@ void LogMessage::Fail() {
}
// L >= log_mutex (callers must hold the log_mutex).
-void LogMessage::SendToSinkAndLog() {
+void LogMessage::SendToSink() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
if (data_->sink_ != NULL) {
RAW_DCHECK(data_->num_chars_to_log_ > 0 &&
data_->message_text_[data_->num_chars_to_log_-1] == '\n', "");
@@ -1160,11 +1231,16 @@ void LogMessage::SendToSinkAndLog() {
(data_->num_chars_to_log_ -
data_->num_prefix_chars_ - 1));
}
+}
+
+// L >= log_mutex (callers must hold the log_mutex).
+void LogMessage::SendToSinkAndLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
+ SendToSink();
SendToLog();
}
// L >= log_mutex (callers must hold the log_mutex).
-void LogMessage::SaveOrSendToLog() {
+void LogMessage::SaveOrSendToLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
if (data_->outvec_ != NULL) {
RAW_DCHECK(data_->num_chars_to_log_ > 0 &&
data_->message_text_[data_->num_chars_to_log_-1] == '\n', "");
@@ -1177,6 +1253,18 @@ void LogMessage::SaveOrSendToLog() {
}
}
+void LogMessage::WriteToStringAndLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
+ if (data_->message_ != NULL) {
+ RAW_DCHECK(data_->num_chars_to_log_ > 0 &&
+ data_->message_text_[data_->num_chars_to_log_-1] == '\n', "");
+ // Omit prefix of message and trailing newline when writing to message_.
+ const char *start = data_->message_text_ + data_->num_prefix_chars_;
+ int len = data_->num_chars_to_log_ - data_->num_prefix_chars_ - 1;
+ data_->message_->assign(start, len);
+ }
+ SendToLog();
+}
+
// L >= log_mutex (callers must hold the log_mutex).
void LogMessage::SendToSyslogAndLog() {
#ifdef HAVE_SYSLOG_H
@@ -1267,26 +1355,24 @@ string LogSink::ToString(LogSeverity severity, const char* file, int line,
ostringstream stream(string(message, message_len));
stream.fill('0');
- if ( is_default_thread() ) {
- stream << LogSeverityNames[severity][0]
- << setw(2) << 1+tm_time->tm_mon
- << setw(2) << tm_time->tm_mday
- << ' '
- << setw(2) << tm_time->tm_hour
- << setw(2) << tm_time->tm_min
- << setw(2) << tm_time->tm_sec
- << ' ' << file << ':' << line << "] ";
- } else {
- stream << LogSeverityNames[severity][0]
- << setw(2) << 1+tm_time->tm_mon
- << setw(2) << tm_time->tm_mday
- << ' '
- << setw(2) << tm_time->tm_hour
- << setw(2) << tm_time->tm_min
- << setw(2) << tm_time->tm_sec
- << ' ' << setw(8) << std::hex << pthread_self() << std::dec
- << ' ' << file << ':' << line << "] ";
- }
+ // FIXME(jrvb): Updating this to use the correct value for usecs
+ // requires changing the signature for both this method and
+ // LogSink::send(). This change needs to be done in a separate CL
+ // so subclasses of LogSink can be updated at the same time.
+ int usecs = 0;
+
+ stream << LogSeverityNames[severity][0]
+ << setw(2) << 1+tm_time->tm_mon
+ << setw(2) << tm_time->tm_mday
+ << ' '
+ << setw(2) << tm_time->tm_hour << ':'
+ << setw(2) << tm_time->tm_min << ':'
+ << setw(2) << tm_time->tm_sec << '.'
+ << setw(6) << usecs
+ << ' '
+ << setfill(' ') << setw(5) << GetTID() << setfill('0')
+ << ' '
+ << file << ':' << line << "] ";
stream << string(message, message_len);
return stream.str();
@@ -1316,6 +1402,32 @@ void LogToStderr() {
LogDestination::LogToStderr();
}
+namespace base {
+namespace internal {
+
+bool GetExitOnDFatal() {
+ MutexLock l(&log_mutex);
+ return exit_on_dfatal;
+}
+
+// Determines whether we exit the program for a LOG(DFATAL) message in
+// debug mode. It does this by skipping the call to Fail/FailQuietly.
+// This is intended for testing only.
+//
+// This can have some effects on LOG(FATAL) as well. Failure messages
+// are always allocated (rather than sharing a buffer), the crash
+// reason is not recorded, the "gwq" status message is not updated,
+// and the stack trace is not recorded. The LOG(FATAL) *will* still
+// exit the program. Since this function is used only in testing,
+// these differences are acceptable.
+void SetExitOnDFatal(bool value) {
+ MutexLock l(&log_mutex);
+ exit_on_dfatal = value;
+}
+
+} // namespace internal
+} // namespace base
+
// use_logging controls whether the logging functions LOG/VLOG are used
// to log errors. It should be set to false when the caller holds the
// log_mutex.
@@ -1330,8 +1442,8 @@ static bool SendEmailInternal(const char*dest, const char *subject,
subject, body, dest);
}
- string cmd(FLAGS_logmailer);
- cmd = cmd + " -s\"" + string(subject) + "\" " + string(dest);
+ string cmd =
+ FLAGS_logmailer + " -s\"" + subject + "\" " + dest;
FILE* pipe = popen(cmd.c_str(), "w");
if (pipe != NULL) {
// Add the body if we have one
@@ -1489,10 +1601,10 @@ void TruncateLogFile(const char *path, int64 limit, int64 keep) {
}
return;
}
-
+
if (fstat(fd, &statbuf) == -1) {
- PLOG(ERROR) << "Unable to fstat()";
- goto out_close_fd;
+ PLOG(ERROR) << "Unable to fstat()";
+ goto out_close_fd;
}
// See if the path refers to a regular file bigger than the
@@ -1503,9 +1615,9 @@ void TruncateLogFile(const char *path, int64 limit, int64 keep) {
// This log file is too large - we need to truncate it
LOG(INFO) << "Truncating " << path << " to " << keep << " bytes";
-
+
// Copy the last "keep" bytes of the file to the beginning of the file
- read_offset = statbuf.st_size - keep;
+ read_offset = statbuf.st_size - keep;
write_offset = 0;
int bytesin, bytesout;
while ((bytesin = pread(fd, copybuf, sizeof(copybuf), read_offset)) > 0) {
@@ -1520,7 +1632,7 @@ void TruncateLogFile(const char *path, int64 limit, int64 keep) {
write_offset += bytesout;
}
if (bytesin == -1) PLOG(ERROR) << "Unable to read from " << path;
-
+
// Truncate the remainder of the file. If someone else writes to the
// end of the file after our last read() above, we lose their latest
// data. Too bad ...
@@ -1537,7 +1649,7 @@ void TruncateLogFile(const char *path, int64 limit, int64 keep) {
void TruncateStdoutStderr() {
#ifdef HAVE_UNISTD_H
- int64 limit = FLAGS_max_log_size << 20;
+ int64 limit = MaxLogSize() << 20;
int64 keep = 1 << 20;
TruncateLogFile("/proc/self/fd/1", limit, keep);
TruncateLogFile("/proc/self/fd/2", limit, keep);
diff --git a/src/logging_unittest.cc b/src/logging_unittest.cc
index 2687a72..14c9789 100644
--- a/src/logging_unittest.cc
+++ b/src/logging_unittest.cc
@@ -28,15 +28,42 @@
#include "glog/raw_logging.h"
#include "googletest.h"
+DECLARE_string(log_backtrace_at); // logging.cc
+
+#ifdef HAVE_LIB_GMOCK
+#include <gmock/gmock.h>
+#include "mock-log.h"
+// Introduce several symbols from gmock.
+using testing::_;
+using testing::AnyNumber;
+using testing::HasSubstr;
+using testing::AllOf;
+using testing::StrNe;
+using testing::StrictMock;
+using testing::InitGoogleMock;
+using GOOGLE_NAMESPACE::glog_testing::ScopedMockLog;
+#endif
+
using namespace std;
using namespace GOOGLE_NAMESPACE;
+// Some non-advertised functions that we want to test or use.
+_START_GOOGLE_NAMESPACE_
+namespace base {
+namespace internal {
+bool GetExitOnDFatal();
+void SetExitOnDFatal(bool value);
+} // namespace internal
+} // namespace base
+_END_GOOGLE_NAMESPACE_
+
static void TestLogging(bool check_counts);
static void TestRawLogging();
static void LogWithLevels(int v, int severity, bool err, bool alsoerr);
static void TestLoggingLevels();
static void TestLogString();
static void TestLogSink();
+static void TestLogToString();
static void TestLogSinkWaitTillSent();
static void TestCHECK();
static void TestDCHECK();
@@ -98,6 +125,20 @@ BENCHMARK(BM_Check2);
static void CheckFailure(int a, int b, const char* file, int line, const char* msg) {
}
+static void BM_logspeed(int n) {
+ while (n-- > 0) {
+ LOG(INFO) << "test message";
+ }
+}
+BENCHMARK(BM_logspeed);
+
+static void BM_vlog(int n) {
+ while (n-- > 0) {
+ VLOG(1) << "test message";
+ }
+}
+BENCHMARK(BM_vlog);
+
int main(int argc, char **argv) {
// Test some basics before InitGoogleLogging:
CaptureTestStderr();
@@ -106,13 +147,16 @@ int main(int argc, char **argv) {
LogWithLevels(0, 0, 0, 0); // simulate "before global c-tors"
const string early_stderr = GetCapturedTestStderr();
- FLAGS_logtostderr = true;
-
InitGoogleLogging(argv[0]);
RunSpecifiedBenchmarks();
+ FLAGS_logtostderr = true;
+
InitGoogleTest(&argc, argv);
+#ifdef HAVE_LIB_GTEST
+ InitGoogleMock(&argc, argv);
+#endif
// so that death tests run before we use threads
CHECK_EQ(RUN_ALL_TESTS(), 0);
@@ -127,6 +171,7 @@ int main(int argc, char **argv) {
TestLoggingLevels();
TestLogString();
TestLogSink();
+ TestLogToString();
TestLogSinkWaitTillSent();
TestCHECK();
TestDCHECK();
@@ -145,7 +190,7 @@ int main(int argc, char **argv) {
TestErrno();
TestTruncate();
- LOG(INFO) << "PASS";
+ fprintf(stdout, "PASS\n");
return 0;
}
@@ -368,6 +413,22 @@ void TestLogString() {
}
}
+void TestLogToString() {
+ string error;
+ string* no_error = NULL;
+
+ LOG_TO_STRING(INFO, &error) << "LOG_TO_STRING: " << "collected info";
+ LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
+ LOG_TO_STRING(WARNING, &error) << "LOG_TO_STRING: " << "collected warning";
+ LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
+ LOG_TO_STRING(ERROR, &error) << "LOG_TO_STRING: " << "collected error";
+ LOG(INFO) << "Captured by LOG_TO_STRING: " << error;
+
+ LOG_TO_STRING(INFO, no_error) << "LOG_TO_STRING: " << "reported info";
+ LOG_TO_STRING(WARNING, no_error) << "LOG_TO_STRING: " << "reported warning";
+ LOG_TO_STRING(ERROR, NULL) << "LOG_TO_STRING: " << "reported error";
+}
+
class TestLogSinkImpl : public LogSink {
public:
vector<string> errors;
@@ -392,6 +453,20 @@ void TestLogSink() {
LOG_TO_SINK(no_sink, WARNING) << "LOG_TO_SINK: " << "reported warning";
LOG_TO_SINK(NULL, ERROR) << "LOG_TO_SINK: " << "reported error";
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, INFO)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected info";
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, WARNING)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected warning";
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(&sink, ERROR)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "collected error";
+
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, INFO)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed info";
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(no_sink, WARNING)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed warning";
+ LOG_TO_SINK_BUT_NOT_TO_LOGFILE(NULL, ERROR)
+ << "LOG_TO_SINK_BUT_NOT_TO_LOGFILE: " << "thrashed error";
+
LOG(INFO) << "Captured by LOG_TO_SINK:";
for (size_t i = 0; i < sink.errors.size(); ++i) {
LogMessage("foo", LogMessage::kNoLogPrefix, INFO).stream()
@@ -948,6 +1023,127 @@ void MyCheck(bool a, bool b) {
CHECK_EQ(a, b);
}
+#ifdef HAVE_LIB_GMOCK
+
+TEST(DVLog, Basic) {
+ ScopedMockLog log;
+
+#if NDEBUG
+ // We are expecting that nothing is logged.
+ EXPECT_CALL(log, Log(_, _, _)).Times(0);
+#else
+ EXPECT_CALL(log, Log(INFO, __FILE__, "debug log"));
+#endif
+
+ FLAGS_v = 1;
+ DVLOG(1) << "debug log";
+}
+
+TEST(DVLog, V0) {
+ ScopedMockLog log;
+
+ // We are expecting that nothing is logged.
+ EXPECT_CALL(log, Log(_, _, _)).Times(0);
+
+ FLAGS_v = 0;
+ DVLOG(1) << "debug log";
+}
+
+TEST(LogAtLevel, Basic) {
+ ScopedMockLog log;
+
+ // The function version outputs "logging.h" as a file name.
+ EXPECT_CALL(log, Log(WARNING, StrNe(__FILE__), "function version"));
+ EXPECT_CALL(log, Log(INFO, __FILE__, "macro version"));
+
+ int severity = WARNING;
+ LogAtLevel(severity, "function version");
+
+ severity = INFO;
+ // We can use the macro version as a C++ stream.
+ LOG_AT_LEVEL(severity) << "macro" << ' ' << "version";
+}
+
+TEST(TestExitOnDFatal, ToBeOrNotToBe) {
+ // Check the default setting...
+ EXPECT_TRUE(base::internal::GetExitOnDFatal());
+
+ // Turn off...
+ base::internal::SetExitOnDFatal(false);
+ EXPECT_FALSE(base::internal::GetExitOnDFatal());
+
+ // We don't die.
+ {
+ ScopedMockLog log;
+ //EXPECT_CALL(log, Log(_, _, _)).Times(AnyNumber());
+ // LOG(DFATAL) has severity FATAL if debugging, but is
+ // downgraded to ERROR if not debugging.
+ const LogSeverity severity =
+#ifdef NDEBUG
+ ERROR;
+#else
+ FATAL;
+#endif
+ EXPECT_CALL(log, Log(severity, __FILE__, "This should not be fatal"));
+ LOG(DFATAL) << "This should not be fatal";
+ }
+
+ // Turn back on...
+ base::internal::SetExitOnDFatal(true);
+ EXPECT_TRUE(base::internal::GetExitOnDFatal());
+
+ // Death comes on little cats' feet.
+ EXPECT_DEBUG_DEATH({
+ LOG(DFATAL) << "This should be fatal in debug mode";
+ }, "This should be fatal in debug mode");
+}
+
+#ifdef HAVE_STACKTRACE
+
+static void BacktraceAtHelper() {
+ LOG(INFO) << "Not me";
+
+// The vertical spacing of the next 3 lines is significant.
+ LOG(INFO) << "Backtrace me";
+}
+static int kBacktraceAtLine = __LINE__ - 2; // The line of the LOG(INFO) above
+
+TEST(LogBacktraceAt, DoesNotBacktraceWhenDisabled) {
+ StrictMock<ScopedMockLog> log;
+
+ FLAGS_log_backtrace_at = "";
+
+ EXPECT_CALL(log, Log(_, _, "Backtrace me"));
+ EXPECT_CALL(log, Log(_, _, "Not me"));
+
+ BacktraceAtHelper();
+}
+
+TEST(LogBacktraceAt, DoesBacktraceAtRightLineWhenEnabled) {
+ StrictMock<ScopedMockLog> log;
+
+ char where[100];
+ snprintf(where, 100, "%s:%d", const_basename(__FILE__), kBacktraceAtLine);
+ FLAGS_log_backtrace_at = where;
+
+ // The LOG at the specified line should include a stacktrace which includes
+ // the name of the containing function, followed by the log message.
+ // We use HasSubstr()s instead of ContainsRegex() for environments
+ // which don't have regexp.
+ EXPECT_CALL(log, Log(_, _, AllOf(HasSubstr("stacktrace:"),
+ HasSubstr("BacktraceAtHelper"),
+ HasSubstr("main"),
+ HasSubstr("Backtrace me"))));
+ // Other LOGs should not include a backtrace.
+ EXPECT_CALL(log, Log(_, _, "Not me"));
+
+ BacktraceAtHelper();
+}
+
+#endif // HAVE_STACKTRACE
+
+#endif // HAVE_LIB_GMOCK
+
struct UserDefinedClass {
bool operator==(const UserDefinedClass& rhs) const { return true; }
};
diff --git a/src/logging_unittest.err b/src/logging_unittest.err
index 7bf7066..4f80bf5 100644
--- a/src/logging_unittest.err
+++ b/src/logging_unittest.err
@@ -1,293 +1,305 @@
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=2 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=2 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
WARNING: Logging before InitGoogleLogging() is written to STDERR
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=0 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] foo bar 10 3.4
-EDATE TIME__ logging_unittest.cc:LINE] Plog every 2, iteration 1: __SUCCESS__ [0]
-EDATE TIME__ logging_unittest.cc:LINE] Log every 3, iteration 1
-EDATE TIME__ logging_unittest.cc:LINE] Log every 4, iteration 1
-WDATE TIME__ logging_unittest.cc:LINE] Log if every 5, iteration 1
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 1
-EDATE TIME__ logging_unittest.cc:LINE] Log if less than 3 every 2, iteration 1
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 2
-EDATE TIME__ logging_unittest.cc:LINE] Plog every 2, iteration 3: __ENOENT__ [2]
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 3
-EDATE TIME__ logging_unittest.cc:LINE] Log if less than 3 every 2, iteration 3
-EDATE TIME__ logging_unittest.cc:LINE] Log every 3, iteration 4
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 4
-EDATE TIME__ logging_unittest.cc:LINE] Plog every 2, iteration 5: __EINTR__ [4]
-EDATE TIME__ logging_unittest.cc:LINE] Log every 4, iteration 5
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 5
-WDATE TIME__ logging_unittest.cc:LINE] Log if every 5, iteration 6
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 6
-EDATE TIME__ logging_unittest.cc:LINE] Plog every 2, iteration 7: __ENXIO__ [6]
-EDATE TIME__ logging_unittest.cc:LINE] Log every 3, iteration 7
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 7
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 8
-EDATE TIME__ logging_unittest.cc:LINE] Plog every 2, iteration 9: __ENOEXEC__ [8]
-EDATE TIME__ logging_unittest.cc:LINE] Log every 4, iteration 9
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 9
-EDATE TIME__ logging_unittest.cc:LINE] Log every 3, iteration 10
-IDATE TIME__ logging_unittest.cc:LINE] Log if every 1, iteration 10
-WDATE TIME__ logging_unittest.cc:LINE] log_if this
-IDATE TIME__ logging_unittest.cc:LINE] array
-IDATE TIME__ logging_unittest.cc:LINE] const array
-EDATE TIME__ logging_unittest.cc:LINE] foo 1000 0000001000 3e8
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=0 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] foo bar 10 3.4
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Plog every 2, iteration 1: __SUCCESS__ [0]
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 3, iteration 1
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 4, iteration 1
+WDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 5, iteration 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 1
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log if less than 3 every 2, iteration 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 2
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Plog every 2, iteration 3: __ENOENT__ [2]
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 3
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log if less than 3 every 2, iteration 3
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 3, iteration 4
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 4
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Plog every 2, iteration 5: __EINTR__ [4]
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 4, iteration 5
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 5
+WDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 5, iteration 6
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 6
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Plog every 2, iteration 7: __ENXIO__ [6]
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 3, iteration 7
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 7
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 8
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Plog every 2, iteration 9: __ENOEXEC__ [8]
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 4, iteration 9
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 9
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Log every 3, iteration 10
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Log if every 1, iteration 10
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if this
+IDATE TIME__ THREADID logging_unittest.cc:LINE] array
+IDATE TIME__ THREADID logging_unittest.cc:LINE] const array
+EDATE TIME__ THREADID logging_unittest.cc:LINE] foo 1000 0000001000 3e8
no prefix
-IDATE TIME__ logging_unittest.cc:LINE] RAW: foo bar 10 3.400000
-WDATE TIME__ logging_unittest.cc:LINE] RAW: array
-IDATE TIME__ logging_unittest.cc:LINE] RAW: const array
-IDATE TIME__ logging_unittest.cc:LINE] RAW: ptr 0x12345678
-IDATE TIME__ logging_unittest.cc:LINE] RAW: ptr __NULLP__
-EDATE TIME__ logging_unittest.cc:LINE] RAW: foo 1000 0000001000 3e8
-IDATE TIME__ logging_unittest.cc:LINE] RAW: foo 1000
-IDATE TIME__ logging_unittest.cc:LINE] RAW: foo 1000
-WDATE TIME__ logging_unittest.cc:LINE] RAW: RAW_LOG ERROR: The Message was too long!
-IDATE TIME__ logging_unittest.cc:LINE] RAW: RAW_LOG ERROR: The Message was too long!
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0 on
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 1 on
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 2 on
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=0 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=0 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] vlog 1
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 1
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=-1 stderrthreshold=0 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=1 logtostderr=0 alsologtostderr=0
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=2 logtostderr=0 alsologtostderr=0
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-EDATE TIME__ logging_unittest.cc:LINE] log error
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=0 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=1 alsologtostderr=0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=0 alsologtostderr=1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=1 logtostderr=0 alsologtostderr=0
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=3 logtostderr=0 alsologtostderr=1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] RAW: vlog 1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: log info
-WDATE TIME__ logging_unittest.cc:LINE] RAW: log warning
-EDATE TIME__ logging_unittest.cc:LINE] RAW: log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog 0
-IDATE TIME__ logging_unittest.cc:LINE] vlog 1
-IDATE TIME__ logging_unittest.cc:LINE] log info
-WDATE TIME__ logging_unittest.cc:LINE] log warning
-EDATE TIME__ logging_unittest.cc:LINE] log error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if -1
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 1
-IDATE TIME__ logging_unittest.cc:LINE] log_if info
-WDATE TIME__ logging_unittest.cc:LINE] log_if warning
-EDATE TIME__ logging_unittest.cc:LINE] log_if error
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error expr
-IDATE TIME__ logging_unittest.cc:LINE] log_if info every 1 expr
-EDATE TIME__ logging_unittest.cc:LINE] log_if error every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] vlog_if 0 every 1 expr
-IDATE TIME__ logging_unittest.cc:LINE] LOG_STRING: reported info
-WDATE TIME__ logging_unittest.cc:LINE] LOG_STRING: reported warning
-EDATE TIME__ logging_unittest.cc:LINE] LOG_STRING: reported error
-IDATE TIME__ logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected info
-IDATE TIME__ logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected warning
-IDATE TIME__ logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected error
-IDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected info
-WDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected warning
-EDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected error
-IDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: reported info
-WDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: reported warning
-EDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: reported error
-IDATE TIME__ logging_unittest.cc:LINE] Captured by LOG_TO_SINK:
-IDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected info
-WDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected warning
-EDATE TIME__ logging_unittest.cc:LINE] LOG_TO_SINK: collected error
-IDATE TIME__ logging_unittest.cc:LINE] Message 1
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffering
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffered
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waiting
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: foo bar 10 3.400000
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: array
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: const array
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: ptr 0x12345678
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: ptr __NULLP__
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: foo 1000 0000001000 3e8
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: foo 1000
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: foo 1000
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: RAW_LOG ERROR: The Message was too long!
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: RAW_LOG ERROR: The Message was too long!
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0 on
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 1 on
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 2 on
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=0 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=0 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=-1 stderrthreshold=0 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=1 logtostderr=0 alsologtostderr=0
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=2 logtostderr=0 alsologtostderr=0
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=0 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=1 alsologtostderr=0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=0 stderrthreshold=3 logtostderr=0 alsologtostderr=1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=1 logtostderr=0 alsologtostderr=0
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Test: v=1 stderrthreshold=3 logtostderr=0 alsologtostderr=1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: vlog 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if -1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] log_if warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] log_if info every 1 expr
+EDATE TIME__ THREADID logging_unittest.cc:LINE] log_if error every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] vlog_if 0 every 1 expr
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_STRING: reported info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_STRING: reported warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_STRING: reported error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected info
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected warning
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_STRING: LOG_STRING: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: reported info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: reported warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: reported error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_TO_SINK:
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK_BUT_NOT_TO_LOGFILE: collected info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK_BUT_NOT_TO_LOGFILE: collected warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_SINK_BUT_NOT_TO_LOGFILE: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: collected info
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_TO_STRING: LOG_TO_STRING: collected info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: collected warning
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_TO_STRING: LOG_TO_STRING: collected warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Captured by LOG_TO_STRING: LOG_TO_STRING: collected error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: reported info
+WDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: reported warning
+EDATE TIME__ THREADID logging_unittest.cc:LINE] LOG_TO_STRING: reported error
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Message 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffering
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffered
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waiting
IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Sink got a messages
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waited
-IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: IDATE TIME__ logging_unittest.cc:LINE] Message 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waited
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: IDATE TIME__ THREADID logging_unittest.cc:LINE] Message 1
IDATE TIME__ THREADID logging_unittest.cc:LINE] Have 0 left
-EDATE TIME__ logging_unittest.cc:LINE] Message 2
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffering
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffered
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waiting
+EDATE TIME__ THREADID logging_unittest.cc:LINE] Message 2
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffering
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffered
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waiting
IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Sink got a messages
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waited
-IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: EDATE TIME__ logging_unittest.cc:LINE] Message 2
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waited
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: EDATE TIME__ THREADID logging_unittest.cc:LINE] Message 2
IDATE TIME__ THREADID logging_unittest.cc:LINE] Have 0 left
-WDATE TIME__ logging_unittest.cc:LINE] Message 3
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffering
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Buffered
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waiting
+WDATE TIME__ THREADID logging_unittest.cc:LINE] Message 3
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffering
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Buffered
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waiting
IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Sink got a messages
-IDATE TIME__ logging_unittest.cc:LINE] RAW: Waited
-IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: WDATE TIME__ logging_unittest.cc:LINE] Message 3
+IDATE TIME__ THREADID logging_unittest.cc:LINE] RAW: Waited
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink is sending out a message: WDATE TIME__ THREADID logging_unittest.cc:LINE] Message 3
IDATE TIME__ THREADID logging_unittest.cc:LINE] Have 0 left
-IDATE TIME__ logging_unittest.cc:LINE] Sink capture: IDATE TIME__ logging_unittest.cc:LINE] Message 1
-IDATE TIME__ logging_unittest.cc:LINE] Sink capture: EDATE TIME__ logging_unittest.cc:LINE] Message 2
-IDATE TIME__ logging_unittest.cc:LINE] Sink capture: WDATE TIME__ logging_unittest.cc:LINE] Message 3
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink capture: IDATE TIME__ THREADID logging_unittest.cc:LINE] Message 1
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink capture: EDATE TIME__ THREADID logging_unittest.cc:LINE] Message 2
+IDATE TIME__ THREADID logging_unittest.cc:LINE] Sink capture: WDATE TIME__ THREADID logging_unittest.cc:LINE] Message 3
diff --git a/src/raw_logging.cc b/src/raw_logging.cc
index 70aa807..7678bee 100644
--- a/src/raw_logging.cc
+++ b/src/raw_logging.cc
@@ -7,10 +7,20 @@
#include <stdarg.h>
#include <stdio.h>
+#include <errno.h>
+#ifdef HAVE_UNISTD_H
+# include <unistd.h> // for close() and write()
+#endif
+#include <fcntl.h> // for open()
#include <time.h>
#include "config.h"
#include "glog/logging.h" // To pick up flag settings etc.
#include "glog/raw_logging.h"
+#include "base/commandlineflags.h"
+
+#ifdef HAVE_STACKTRACE
+# include "stacktrace.h"
+#endif
#if defined(HAVE_SYSCALL_H)
#include <syscall.h> // for syscall()
@@ -21,15 +31,24 @@
# include <unistd.h>
#endif
+#if defined(HAVE_SYSCALL_H) || defined(HAVE_SYS_SYSCALL_H)
+# define safe_write(fd, s, len) syscall(SYS_write, fd, s, len)
+#else
+ // Not so safe, but what can you do?
+# define safe_write(fd, s, len) write(fd, s, len)
+#endif
+
_START_GOOGLE_NAMESPACE_
// Data for RawLog__ below. We simply pick up the latest
// time data created by a normal log message to avoid calling
// localtime_r which can allocate memory.
static struct ::tm last_tm_time_for_raw_log;
+static int last_usecs_for_raw_log;
-void RawLog__SetLastTime(const struct ::tm& t) {
+void RawLog__SetLastTime(const struct ::tm& t, int usecs) {
memcpy(&last_tm_time_for_raw_log, &t, sizeof(last_tm_time_for_raw_log));
+ last_usecs_for_raw_log = usecs;
}
// CAVEAT: vsnprintf called from *DoRawLog below has some (exotic) code paths
@@ -61,6 +80,11 @@ inline static bool VADoRawLog(char** buf, int* size,
return true;
}
+static const int kLogBufSize = 3000;
+static bool crashed = false;
+static CrashReason crash_reason;
+static char crash_buf[kLogBufSize + 1] = { 0 }; // Will end in '\0'
+
void RawLog__(LogSeverity severity, const char* file, int line,
const char* format, ...) {
if (!(FLAGS_logtostderr || severity >= FLAGS_stderrthreshold ||
@@ -69,21 +93,22 @@ void RawLog__(LogSeverity severity, const char* file, int line,
}
// can't call localtime_r here: it can allocate
struct ::tm& t = last_tm_time_for_raw_log;
- char buffer[3000]; // 3000 bytes should be enough for everyone... :-)
+ char buffer[kLogBufSize];
char* buf = buffer;
int size = sizeof(buffer);
- if (is_default_thread()) {
- DoRawLog(&buf, &size, "%c%02d%02d %02d%02d%02d %s:%d] RAW: ",
- LogSeverityNames[severity][0],
- 1 + t.tm_mon, t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec,
- const_basename(const_cast<char *>(file)), line);
- } else {
- DoRawLog(&buf, &size, "%c%02d%02d %02d%02d%02d %08x %s:%d] RAW: ",
- LogSeverityNames[severity][0],
- 1 + t.tm_mon, t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec,
- int(pthread_self()),
- const_basename(const_cast<char *>(file)), line);
- }
+
+ // NOTE: this format should match the specification in base/logging.h
+ DoRawLog(&buf, &size, "%c%02d%02d %02d:%02d:%02d.%06d %5u %s:%d] RAW: ",
+ LogSeverityNames[severity][0],
+ 1 + t.tm_mon, t.tm_mday, t.tm_hour, t.tm_min, t.tm_sec,
+ last_usecs_for_raw_log,
+ static_cast<unsigned int>(GetTID()),
+ const_basename(const_cast<char *>(file)), line);
+
+ // Record the position and size of the buffer after the prefix
+ const char* msg_start = buf;
+ const int msg_size = size;
+
va_list ap;
va_start(ap, format);
bool no_chop = VADoRawLog(&buf, &size, format, ap);
@@ -97,12 +122,23 @@ void RawLog__(LogSeverity severity, const char* file, int line,
// avoiding FILE buffering (to avoid invoking malloc()), and bypassing
// libc (to side-step any libc interception).
// We write just once to avoid races with other invocations of RawLog__.
-#if defined(HAVE_SYSCALL_H) || defined(HAVE_SYS_SYSCALL_H)
- syscall(SYS_write, STDERR_FILENO, buffer, strlen(buffer));
+ safe_write(STDERR_FILENO, buffer, strlen(buffer));
+ if (severity == FATAL) {
+ if (!sync_val_compare_and_swap(&crashed, false, true)) {
+ crash_reason.filename = file;
+ crash_reason.line_number = line;
+ memcpy(crash_buf, msg_start, msg_size); // Don't include prefix
+ crash_reason.message = crash_buf;
+#ifdef HAVE_STACKTRACE
+ crash_reason.depth =
+ GetStackTrace(crash_reason.stack, ARRAYSIZE(crash_reason.stack), 1);
#else
- write(STDERR_FILENO, buffer, strlen(buffer));
+ crash_reason.depth = 0;
#endif
- if (severity == FATAL) LogMessage::Fail();
+ SetCrashReason(&crash_reason);
+ }
+ LogMessage::Fail(); // abort()
+ }
}
_END_GOOGLE_NAMESPACE_
diff --git a/src/utilities.cc b/src/utilities.cc
index 711d743..6477065 100644
--- a/src/utilities.cc
+++ b/src/utilities.cc
@@ -8,6 +8,11 @@
# include <sys/time.h>
#endif
#include <time.h>
+#if defined(HAVE_SYSCALL_H)
+#include <syscall.h> // for syscall()
+#elif defined(HAVE_SYS_SYSCALL_H)
+#include <sys/syscall.h> // for syscall()
+#endif
#include "base/googleinit.h"
#include "stacktrace.h"
@@ -41,6 +46,10 @@ static void DebugWriteToStderr(const char* data, void *unused) {
write(STDERR_FILENO, data, strlen(data));
}
+void DebugWriteToString(const char* data, void *arg) {
+ reinterpret_cast<string*>(arg)->append(data);
+}
+
// Print a program counter and its symbol name.
static void DumpPCAndSymbol(DebugWriter *writerfn, void *arg, void *pc,
const char * const prefix) {
@@ -146,7 +155,6 @@ int64 CycleClock_Now() {
return (static_cast<int64>(now.wSecond) * 1000000 +
static_cast<int64>(now.wMilliseconds) * 1000);
#else
- // TODO(hamaji): temporary impementation - it might be too slow.
struct timeval tv;
gettimeofday(&tv, NULL);
return static_cast<int64>(tv.tv_sec) * 1000000 + tv.tv_usec;
@@ -157,11 +165,53 @@ int64 UsecToCycles(int64 usec) {
return usec;
}
+WallTime WallTime_Now() {
+ // Now, cycle clock is retuning microseconds since the epoch.
+ return CycleClock_Now() * 0.000001;
+}
+
static int32 g_main_thread_pid = getpid();
int32 GetMainThreadPid() {
return g_main_thread_pid;
}
+pid_t GetTID() {
+ // On Linux and FreeBSD, we try to use gettid().
+#if defined OS_LINUX || defined OS_FREEBSD || defined OS_MACOSX
+#ifndef __NR_gettid
+#ifdef OS_MACOSX
+#define __NR_gettid SYS_gettid
+#elif ! defined __i386__
+#error "Must define __NR_gettid for non-x86 platforms"
+#else
+#define __NR_gettid 224
+#endif
+#endif
+ static bool lacks_gettid = false;
+ if (!lacks_gettid) {
+ pid_t tid = syscall(__NR_gettid);
+ if (tid != -1) {
+ return tid;
+ }
+ // Technically, this variable has to be volatile, but there is a small
+ // performance penalty in accessing volatile variables and there should
+ // not be any serious adverse effect if a thread does not immediately see
+ // the value change to "true".
+ lacks_gettid = true;
+ }
+#endif // OS_LINUX || OS_FREEBSD
+
+ // If gettid() could not be used, we use one of the following.
+#if defined OS_LINUX
+ return getpid(); // Linux: getpid returns thread ID when gettid is absent
+#elif defined OS_WINDOWS || defined OS_CYGWIN
+ return GetCurrentThreadId();
+#else
+ // If none of the techniques above worked, we use pthread_self().
+ return (pid_t)pthread_self();
+#endif
+}
+
const char* const_basename(const char* filepath) {
const char* base = strrchr(filepath, '/');
#ifdef OS_WINDOWS // Look for either path separator in Windows
@@ -186,6 +236,22 @@ static void MyUserNameInitializer() {
}
REGISTER_MODULE_INITIALIZER(utilities, MyUserNameInitializer());
+#ifdef HAVE_STACKTRACE
+void DumpStackTraceToString(string* stacktrace) {
+ DumpStackTrace(1, DebugWriteToString, stacktrace);
+}
+#endif
+
+// We use an atomic operation to prevent problems with calling CrashReason
+// from inside the Mutex implementation (potentially through RAW_CHECK).
+static const CrashReason* g_reason = 0;
+
+void SetCrashReason(const CrashReason* r) {
+ sync_val_compare_and_swap(&g_reason,
+ reinterpret_cast<const CrashReason*>(0),
+ r);
+}
+
} // namespace glog_internal_namespace_
void InitGoogleLogging(const char* argv0) {
diff --git a/src/utilities.h b/src/utilities.h
index 700a6a9..dc8c208 100644
--- a/src/utilities.h
+++ b/src/utilities.h
@@ -40,7 +40,7 @@
#include <string>
-#ifdef OS_WINDOWS
+#if defined(OS_WINDOWS) && !defined(__CYGWIN__)
# include "port.h"
#endif
@@ -74,7 +74,7 @@
# define STACKTRACE_H "stacktrace_x86-inl.h"
# elif defined(__x86_64__) && __GNUC__ >= 2
# define STACKTRACE_H "stacktrace_x86_64-inl.h"
-# elif ((__ppc__) || defined(__PPC__)) && __GNUC__ >= 2
+# elif (defined(__ppc__) || defined(__PPC__)) && __GNUC__ >= 2
# define STACKTRACE_H "stacktrace_powerpc-inl.h"
# endif
#endif
@@ -95,8 +95,10 @@
# define HAVE_SYMBOLIZE
#endif
-// There is a better way, but this is good enough in this file.
-#define ARRAYSIZE(a) (sizeof(a) / sizeof(*(a)))
+#ifndef ARRAYSIZE
+// There is a better way, but this is good enough for our purpose.
+# define ARRAYSIZE(a) (sizeof(a) / sizeof(*(a)))
+#endif
_START_GOOGLE_NAMESPACE_
@@ -119,8 +121,13 @@ int64 CycleClock_Now();
int64 UsecToCycles(int64 usec);
+typedef double WallTime;
+WallTime WallTime_Now();
+
int32 GetMainThreadPid();
+pid_t GetTID();
+
const std::string& MyUserName();
// Get the part of filepath after the last path separator.
@@ -155,6 +162,23 @@ inline T sync_val_compare_and_swap(T* ptr, T oldval, T newval) {
#endif
}
+void DumpStackTraceToString(std::string* stacktrace);
+
+struct CrashReason {
+ CrashReason() : filename(0), line_number(0), message(0), depth(0) {}
+
+ const char* filename;
+ int line_number;
+ const char* message;
+
+ // We'll also store a bit of context at the time of crash as it may not be
+ // available later on.
+ void* stack[32];
+ int depth;
+};
+
+void SetCrashReason(const CrashReason* r);
+
} // namespace glog_internal_namespace_
_END_GOOGLE_NAMESPACE_