Adds color output support for tmux terminals
[platform/upstream/glog.git] / src / logging.cc
index 54d8e34..5543e3a 100644 (file)
@@ -31,6 +31,7 @@
 
 #include "utilities.h"
 
+#include <algorithm>
 #include <assert.h>
 #include <iomanip>
 #include <string>
@@ -102,6 +103,8 @@ GLOG_DEFINE_bool(logtostderr, BoolFromEnv("GOOGLE_LOGTOSTDERR", false),
                  "log messages go to stderr instead of logfiles");
 GLOG_DEFINE_bool(alsologtostderr, BoolFromEnv("GOOGLE_ALSOLOGTOSTDERR", false),
                  "log messages go to stderr in addition to logfiles");
+GLOG_DEFINE_bool(colorlogtostderr, false,
+                 "color messages logged to stderr (if supported by terminal)");
 #ifdef OS_LINUX
 GLOG_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 "
@@ -177,6 +180,42 @@ GLOG_DEFINE_string(log_backtrace_at, "",
 // TODO(hamaji): consider windows
 #define PATH_SEPARATOR '/'
 
+#ifndef HAVE_PREAD
+#if defined(OS_WINDOWS)
+#include <BaseTsd.h>
+#define ssize_t SSIZE_T
+#endif
+static ssize_t pread(int fd, void* buf, size_t count, off_t offset) {
+  off_t orig_offset = lseek(fd, 0, SEEK_CUR);
+  if (orig_offset == (off_t)-1)
+    return -1;
+  if (lseek(fd, offset, SEEK_CUR) == (off_t)-1)
+    return -1;
+  ssize_t len = read(fd, buf, count);
+  if (len < 0)
+    return len;
+  if (lseek(fd, orig_offset, SEEK_SET) == (off_t)-1)
+    return -1;
+  return len;
+}
+#endif  // !HAVE_PREAD
+
+#ifndef HAVE_PWRITE
+static ssize_t pwrite(int fd, void* buf, size_t count, off_t offset) {
+  off_t orig_offset = lseek(fd, 0, SEEK_CUR);
+  if (orig_offset == (off_t)-1)
+    return -1;
+  if (lseek(fd, offset, SEEK_CUR) == (off_t)-1)
+    return -1;
+  ssize_t len = write(fd, buf, count);
+  if (len < 0)
+    return len;
+  if (lseek(fd, orig_offset, SEEK_SET) == (off_t)-1)
+    return -1;
+  return len;
+}
+#endif  // !HAVE_PWRITE
+
 static void GetHostName(string* hostname) {
 #if defined(HAVE_SYS_UTSNAME_H)
   struct utsname buf;
@@ -199,13 +238,126 @@ static void GetHostName(string* hostname) {
 #endif
 }
 
+// Returns true iff terminal supports using colors in output.
+static bool TerminalSupportsColor() {
+  bool term_supports_color = false;
+#ifdef OS_WINDOWS
+  // on Windows TERM variable is usually not set, but the console does
+  // support colors.
+  term_supports_color = true;
+#else
+  // On non-Windows platforms, we rely on the TERM variable.
+  const char* const term = getenv("TERM");
+  if (term != NULL && term[0] != '\0') {
+    term_supports_color =
+      !strcmp(term, "xterm") ||
+      !strcmp(term, "xterm-color") ||
+      !strcmp(term, "xterm-256color") ||
+      !strcmp(term, "screen-256color") ||
+      !strcmp(term, "screen") ||
+      !strcmp(term, "linux") ||
+      !strcmp(term, "cygwin");
+  }
+#endif
+  return term_supports_color;
+}
+
 _START_GOOGLE_NAMESPACE_
 
+enum GLogColor {
+  COLOR_DEFAULT,
+  COLOR_RED,
+  COLOR_GREEN,
+  COLOR_YELLOW
+};
+
+static GLogColor SeverityToColor(LogSeverity severity) {
+  assert(severity >= 0 && severity < NUM_SEVERITIES);
+  GLogColor color = COLOR_DEFAULT;
+  switch (severity) {
+  case GLOG_INFO:
+    color = COLOR_DEFAULT;
+    break;
+  case GLOG_WARNING:
+    color = COLOR_YELLOW;
+    break;
+  case GLOG_ERROR:
+  case GLOG_FATAL:
+    color = COLOR_RED;
+    break;
+  default:
+    // should never get here.
+    assert(false);
+  }
+  return color;
+}
+
+#ifdef OS_WINDOWS
+
+// Returns the character attribute for the given color.
+WORD GetColorAttribute(GLogColor color) {
+  switch (color) {
+    case COLOR_RED:    return FOREGROUND_RED;
+    case COLOR_GREEN:  return FOREGROUND_GREEN;
+    case COLOR_YELLOW: return FOREGROUND_RED | FOREGROUND_GREEN;
+    default:           return 0;
+  }
+}
+
+#else
+
+// Returns the ANSI color code for the given color.
+const char* GetAnsiColorCode(GLogColor color) {
+  switch (color) {
+  case COLOR_RED:     return "1";
+  case COLOR_GREEN:   return "2";
+  case COLOR_YELLOW:  return "3";
+  case COLOR_DEFAULT:  return "";
+  };
+  return NULL; // stop warning about return type.
+}
+
+#endif  // OS_WINDOWS
+
 // 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);
 }
 
+// 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;
+
+struct LogMessage::LogMessageData  {
+  LogMessageData();
+
+  int preserved_errno_;      // preserved errno
+  // Buffer space; contains complete message text.
+  char message_text_[LogMessage::kMaxLogMessageLen+1];
+  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
+    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_;     // # 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
+
+ private:
+  LogMessageData(const LogMessageData&);
+  void operator=(const LogMessageData&);
+};
+
 // 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
@@ -320,6 +472,9 @@ class LogDestination {
   static const int kNetworkBytes = 1400;
 
   static const string& hostname();
+  static const bool& terminal_supports_color() {
+    return terminal_supports_color_;
+  }
 
   static void DeleteLogDestinations();
 
@@ -370,6 +525,7 @@ class LogDestination {
   static LogSeverity email_logging_severity_;
   static string addresses_;
   static string hostname_;
+  static bool terminal_supports_color_;
 
   // arbitrary global logging destinations.
   static vector<LogSink*>* sinks_;
@@ -391,6 +547,7 @@ string LogDestination::hostname_;
 
 vector<LogSink*>* LogDestination::sinks_ = NULL;
 Mutex LogDestination::sink_mutex_;
+bool LogDestination::terminal_supports_color_ = TerminalSupportsColor();
 
 /* static */
 const string& LogDestination::hostname() {
@@ -511,6 +668,43 @@ inline void LogDestination::SetEmailLogging(LogSeverity min_severity,
   LogDestination::addresses_ = addresses;
 }
 
+static void ColoredWriteToStderr(LogSeverity severity,
+                                 const char* message, size_t len) {
+  const GLogColor color =
+      (LogDestination::terminal_supports_color() && FLAGS_colorlogtostderr) ?
+      SeverityToColor(severity) : COLOR_DEFAULT;
+
+  // Avoid using cerr from this module since we may get called during
+  // exit code, and cerr may be partially or fully destroyed by then.
+  if (COLOR_DEFAULT == color) {
+    fwrite(message, len, 1, stderr);
+    return;
+  }
+#ifdef OS_WINDOWS
+  const HANDLE stderr_handle = GetStdHandle(STD_ERROR_HANDLE);
+
+  // Gets the current text color.
+  CONSOLE_SCREEN_BUFFER_INFO buffer_info;
+  GetConsoleScreenBufferInfo(stderr_handle, &buffer_info);
+  const WORD old_color_attrs = buffer_info.wAttributes;
+
+  // We need to flush the stream buffers into the console before each
+  // SetConsoleTextAttribute call lest it affect the text that is already
+  // printed but has not yet reached the console.
+  fflush(stderr);
+  SetConsoleTextAttribute(stderr_handle,
+                          GetColorAttribute(color) | FOREGROUND_INTENSITY);
+  fwrite(message, len, 1, stderr);
+  fflush(stderr);
+  // Restores the text color.
+  SetConsoleTextAttribute(stderr_handle, old_color_attrs);
+#else
+  fprintf(stderr, "\033[0;3%sm", GetAnsiColorCode(color));
+  fwrite(message, len, 1, stderr);
+  fprintf(stderr, "\033[m");  // Resets the terminal to default.
+#endif  // OS_WINDOWS
+}
+
 static void WriteToStderr(const char* message, size_t len) {
   // Avoid using cerr from this module since we may get called during
   // exit code, and cerr may be partially or fully destroyed by then.
@@ -520,7 +714,7 @@ static void WriteToStderr(const char* message, size_t len) {
 inline void LogDestination::MaybeLogToStderr(LogSeverity severity,
                                             const char* message, size_t len) {
   if ((severity >= FLAGS_stderrthreshold) || FLAGS_alsologtostderr) {
-    WriteToStderr(message, len);
+    ColoredWriteToStderr(severity, message, len);
 #ifdef OS_WINDOWS
     // On Windows, also output to the debugger
     ::OutputDebugStringA(string(message,len).c_str());
@@ -569,12 +763,12 @@ inline void LogDestination::LogToAllLogfiles(LogSeverity severity,
                                              const char* message,
                                              size_t len) {
 
-  if ( FLAGS_logtostderr )            // global flag: never log to file
-    WriteToStderr(message, len);
-  else
+  if ( FLAGS_logtostderr ) {           // global flag: never log to file
+    ColoredWriteToStderr(severity, message, len);
+  } else {
     for (int i = severity; i >= 0; --i)
       LogDestination::MaybeLogToLogfile(i, timestamp, message, len);
-
+  }
 }
 
 inline void LogDestination::LogToSinks(LogSeverity severity,
@@ -732,8 +926,10 @@ bool LogFileObject::CreateLogfile(const string& time_pid_string) {
     linkpath += linkname;
     unlink(linkpath.c_str());                    // delete old one if it exists
 
+#if defined(OS_WINDOWS)
+    // TODO(hamaji): Create lnk file on Windows?
+#elif defined(HAVE_UNISTD_H)
     // We must have unistd.h.
-#ifdef HAVE_UNISTD_H
     // Make the symlink be relative (in the same dir) so that if the
     // entire log directory gets relocated the link is still valid.
     const char *linkdest = slash ? (slash + 1) : filename;
@@ -924,9 +1120,6 @@ void LogFileObject::Write(bool force_flush,
 
 }  // namespace
 
-// 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;
 
 // Static log data space to avoid alloc failures in a LOG(FATAL)
 //
@@ -937,55 +1130,55 @@ const size_t LogMessage::kMaxLogMessageLen = 30000;
 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_;
+static LogMessage::LogMessageData fatal_msg_data_exclusive;
+static LogMessage::LogMessageData fatal_msg_data_shared;
 
-LogMessage::LogMessageData::~LogMessageData() {
-  delete[] buf_;
-  delete stream_alloc_;
+LogMessage::LogMessageData::LogMessageData()
+  : stream_(message_text_, LogMessage::kMaxLogMessageLen, 0) {
 }
 
 LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
-                      int ctr, void (LogMessage::*send_method)()) {
+                       int ctr, void (LogMessage::*send_method)())
+    : allocated_(NULL) {
   Init(file, line, severity, send_method);
-  data_->stream_->set_ctr(ctr);
+  data_->stream_.set_ctr(ctr);
 }
 
 LogMessage::LogMessage(const char* file, int line,
-                       const CheckOpString& result) {
+                       const CheckOpString& result)
+    : allocated_(NULL) {
   Init(file, line, GLOG_FATAL, &LogMessage::SendToLog);
   stream() << "Check failed: " << (*result.str_) << " ";
 }
 
-LogMessage::LogMessage(const char* file, int line) {
+LogMessage::LogMessage(const char* file, int line)
+    : allocated_(NULL) {
   Init(file, line, GLOG_INFO, &LogMessage::SendToLog);
 }
 
-LogMessage::LogMessage(const char* file, int line, LogSeverity severity) {
+LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
+    : allocated_(NULL) {
   Init(file, line, severity, &LogMessage::SendToLog);
 }
 
 LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
-                       LogSink* sink, bool also_send_to_log) {
+                       LogSink* sink, bool also_send_to_log)
+    : allocated_(NULL) {
   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) {
+                       vector<string> *outvec)
+    : allocated_(NULL) {
   Init(file, line, severity, &LogMessage::SaveOrSendToLog);
   data_->outvec_ = outvec; // override Init()'s setting to NULL
 }
 
 LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
-                       string *message) {
+                       string *message)
+    : allocated_(NULL) {
   Init(file, line, severity, &LogMessage::WriteToStringAndLog);
   data_->message_ = message;  // override Init()'s setting to NULL
 }
@@ -998,27 +1191,17 @@ void LogMessage::Init(const char* file,
   if (severity != GLOG_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_ = &fatal_msg_data_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_ = &fatal_msg_data_shared;
       data_->first_fatal_ = false;
     }
-    data_->stream_alloc_ = NULL;
   }
 
   stream().fill('0');
@@ -1059,7 +1242,7 @@ void LogMessage::Init(const char* file,
              << ' '
              << data_->basename_ << ':' << data_->line_ << "] ";
   }
-  data_->num_prefix_chars_ = data_->stream_->pcount();
+  data_->num_prefix_chars_ = data_->stream_.pcount();
 
   if (!FLAGS_log_backtrace_at.empty()) {
     char fileline[128];
@@ -1079,13 +1262,21 @@ LogMessage::~LogMessage() {
   delete allocated_;
 }
 
+int LogMessage::preserved_errno() const {
+  return data_->preserved_errno_;
+}
+
+ostream& LogMessage::stream() {
+  return data_->stream_;
+}
+
 // Flush buffered message, called by the destructor, or any other function
 // that needs to synchronize the log.
 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_;
 
@@ -1135,7 +1326,7 @@ void LogMessage::Flush() {
 
 // 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.
+// use fatal_msg_data_exclusive.
 static time_t fatal_time;
 static char fatal_message[256];
 
@@ -1143,7 +1334,7 @@ void ReprintFatalMessage() {
   if (fatal_message[0]) {
     const int n = strlen(fatal_message);
     if (!FLAGS_logtostderr) {
-      // Also write to stderr
+      // Also write to stderr (don't color to avoid terminal checks)
       WriteToStderr(fatal_message, n);
     }
     LogDestination::LogToAllLogfiles(GLOG_ERROR, fatal_time, fatal_message, n);
@@ -1172,7 +1363,8 @@ void LogMessage::SendToLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
   // file if we haven't parsed the command line flags to get the
   // program name.
   if (FLAGS_logtostderr || !IsGoogleLoggingInitialized()) {
-    WriteToStderr(data_->message_text_, data_->num_chars_to_log_);
+    ColoredWriteToStderr(data_->severity_,
+                         data_->message_text_, data_->num_chars_to_log_);
 
     // this could be protected by a flag if necessary.
     LogDestination::LogToSinks(data_->severity_,
@@ -1244,10 +1436,10 @@ void LogMessage::SendToLog() EXCLUSIVE_LOCKS_REQUIRED(log_mutex) {
 
 void LogMessage::RecordCrashReason(
     glog_internal_namespace_::CrashReason* reason) {
-  reason->filename = fatal_msg_data_exclusive_.fullname_;
-  reason->line_number = fatal_msg_data_exclusive_.line_;
-  reason->message = fatal_msg_buf_exclusive +
-                    fatal_msg_data_exclusive_.num_prefix_chars_;
+  reason->filename = fatal_msg_data_exclusive.fullname_;
+  reason->line_number = fatal_msg_data_exclusive.line_;
+  reason->message = fatal_msg_data_exclusive.message_text_ +
+                    fatal_msg_data_exclusive.num_prefix_chars_;
 #ifdef HAVE_STACKTRACE
   // Retrieve the stack trace, omitting the logging frames that got us here.
   reason->depth = GetStackTrace(reason->stack, ARRAYSIZE(reason->stack), 4);
@@ -1268,7 +1460,7 @@ static void logging_fail() {
 #if defined(_DEBUG) && defined(_MSC_VER)
   // When debugging on windows, avoid the obnoxious dialog and make
   // it possible to continue past a LOG(FATAL) in the debugger
-  _asm int 3
+  __debugbreak();
 #else
   abort();
 #endif
@@ -1394,9 +1586,8 @@ ErrnoLogMessage::ErrnoLogMessage(const char* file, int line,
 ErrnoLogMessage::~ErrnoLogMessage() {
   // Don't access errno directly because it may have been altered
   // while streaming the message.
-  char buf[100];
-  posix_strerror_r(preserved_errno(), buf, sizeof(buf));
-  stream() << ": " << buf << " [" << preserved_errno() << "]";
+  stream() << ": " << StrError(preserved_errno()) << " ["
+           << preserved_errno() << "]";
 }
 
 void FlushLogFiles(LogSeverity min_severity) {
@@ -1525,13 +1716,11 @@ static bool SendEmailInternal(const char*dest, const char *subject,
       bool ok = pclose(pipe) != -1;
       if ( !ok ) {
         if ( use_logging ) {
-          char buf[100];
-          posix_strerror_r(errno, buf, sizeof(buf));
-          LOG(ERROR) << "Problems sending mail to " << dest << ": " << buf;
+          LOG(ERROR) << "Problems sending mail to " << dest << ": "
+                     << StrError(errno);
         } else {
-          char buf[100];
-          posix_strerror_r(errno, buf, sizeof(buf));
-          fprintf(stderr, "Problems sending mail to %s: %s\n", dest, buf);
+          fprintf(stderr, "Problems sending mail to %s: %s\n",
+                  dest, StrError(errno).c_str());
         }
       }
       return ok;
@@ -1653,8 +1842,11 @@ void TruncateLogFile(const char *path, int64 limit, int64 keep) {
   int64 read_offset, write_offset;
   // Don't follow symlinks unless they're our own fd symlinks in /proc
   int flags = O_RDWR;
+  // TODO(hamaji): Support other environments.
+#ifdef OS_LINUX
   const char *procfd_prefix = "/proc/self/fd/";
   if (strncmp(procfd_prefix, path, strlen(procfd_prefix))) flags |= O_NOFOLLOW;
+#endif
 
   int fd = open(path, flags);
   if (fd == -1) {
@@ -1802,6 +1994,15 @@ int posix_strerror_r(int err, char *buf, size_t len) {
   }
 }
 
+string StrError(int err) {
+  char buf[100];
+  int rc = posix_strerror_r(err, buf, sizeof(buf));
+  if ((rc < 0) || (buf[0] == '\000')) {
+    snprintf(buf, sizeof(buf), "Error number %d", err);
+  }
+  return buf;
+}
+
 LogMessageFatal::LogMessageFatal(const char* file, int line) :
     LogMessage(file, line, GLOG_FATAL) {}