summaryrefslogtreecommitdiff
path: root/base/logging.cc
diff options
context:
space:
mode:
Diffstat (limited to 'base/logging.cc')
-rw-r--r--base/logging.cc284
1 files changed, 194 insertions, 90 deletions
diff --git a/base/logging.cc b/base/logging.cc
index 74401f7922..3450b9a1b2 100644
--- a/base/logging.cc
+++ b/base/logging.cc
@@ -4,9 +4,17 @@
#include "base/logging.h"
+#include <limits.h>
+#include <stdint.h>
+
+#include "base/macros.h"
+#include "build/build_config.h"
+
#if defined(OS_WIN)
#include <io.h>
#include <windows.h>
+#include "base/files/file_path.h"
+#include "base/files/file_util.h"
typedef HANDLE FileHandle;
typedef HANDLE MutexHandle;
// Windows warns on using write(). It prefers _write().
@@ -14,6 +22,8 @@ typedef HANDLE MutexHandle;
// Windows doesn't define STDERR_FILENO. Define it here.
#define STDERR_FILENO 2
#elif defined(OS_MACOSX)
+#include <asl.h>
+#include <CoreFoundation/CoreFoundation.h>
#include <mach/mach.h>
#include <mach/mach_time.h>
#include <mach-o/dyld.h>
@@ -28,10 +38,12 @@ typedef HANDLE MutexHandle;
#if defined(OS_POSIX)
#include <errno.h>
+#include <paths.h>
#include <pthread.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
+#include <sys/stat.h>
#include <unistd.h>
#define MAX_PATH PATH_MAX
typedef FILE* FileHandle;
@@ -56,6 +68,7 @@ typedef pthread_mutex_t* MutexHandle;
#include "base/strings/string_piece.h"
#include "base/strings/string_util.h"
#include "base/strings/stringprintf.h"
+#include "base/strings/sys_string_conversions.h"
#include "base/strings/utf_string_conversions.h"
#include "base/synchronization/lock_impl.h"
#include "base/threading/platform_thread.h"
@@ -121,7 +134,7 @@ LogMessageHandlerFunction log_message_handler = nullptr;
// Helper functions to wrap platform differences.
-int32 CurrentProcessId() {
+int32_t CurrentProcessId() {
#if defined(OS_WIN)
return GetCurrentProcessId();
#elif defined(OS_POSIX)
@@ -129,7 +142,7 @@ int32 CurrentProcessId() {
#endif
}
-uint64 TickCount() {
+uint64_t TickCount() {
#if defined(OS_WIN)
return GetTickCount();
#elif defined(OS_MACOSX)
@@ -142,9 +155,8 @@ uint64 TickCount() {
struct timespec ts;
clock_gettime(CLOCK_MONOTONIC, &ts);
- uint64 absolute_micro =
- static_cast<int64>(ts.tv_sec) * 1000000 +
- static_cast<int64>(ts.tv_nsec) / 1000;
+ uint64_t absolute_micro = static_cast<int64_t>(ts.tv_sec) * 1000000 +
+ static_cast<int64_t>(ts.tv_nsec) / 1000;
return absolute_micro;
#endif
@@ -178,6 +190,9 @@ PathString GetDefaultLogFile() {
#endif
}
+// We don't need locks on Windows for atomically appending to files. The OS
+// provides this functionality.
+#if !defined(OS_WIN)
// This class acts as a wrapper for locking the logging files.
// LoggingLock::Init() should be called from the main thread before any logging
// is done. Then whenever logging, be sure to have a local LoggingLock
@@ -199,48 +214,17 @@ class LoggingLock {
if (initialized)
return;
lock_log_file = lock_log;
- if (lock_log_file == LOCK_LOG_FILE) {
-#if defined(OS_WIN)
- if (!log_mutex) {
- std::wstring safe_name;
- if (new_log_file)
- safe_name = new_log_file;
- else
- safe_name = GetDefaultLogFile();
- // \ is not a legal character in mutex names so we replace \ with /
- std::replace(safe_name.begin(), safe_name.end(), '\\', '/');
- std::wstring t(L"Global\\");
- t.append(safe_name);
- log_mutex = ::CreateMutex(nullptr, FALSE, t.c_str());
-
- if (log_mutex == nullptr) {
-#if DEBUG
- // Keep the error code for debugging
- int error = GetLastError(); // NOLINT
- base::debug::BreakDebugger();
-#endif
- // Return nicely without putting initialized to true.
- return;
- }
- }
-#endif
- } else {
+
+ if (lock_log_file != LOCK_LOG_FILE)
log_lock = new base::internal::LockImpl();
- }
+
initialized = true;
}
private:
static void LockLogging() {
if (lock_log_file == LOCK_LOG_FILE) {
-#if defined(OS_WIN)
- ::WaitForSingleObject(log_mutex, INFINITE);
- // WaitForSingleObject could have returned WAIT_ABANDONED. We don't
- // abort the process here. UI tests might be crashy sometimes,
- // and aborting the test binary only makes the problem worse.
- // We also don't use LOG macros because that might lead to an infinite
- // loop. For more info see http://crbug.com/18028.
-#elif defined(OS_POSIX)
+#if defined(OS_POSIX)
pthread_mutex_lock(&log_mutex);
#endif
} else {
@@ -251,9 +235,7 @@ class LoggingLock {
static void UnlockLogging() {
if (lock_log_file == LOCK_LOG_FILE) {
-#if defined(OS_WIN)
- ReleaseMutex(log_mutex);
-#elif defined(OS_POSIX)
+#if defined(OS_POSIX)
pthread_mutex_unlock(&log_mutex);
#endif
} else {
@@ -268,9 +250,7 @@ class LoggingLock {
// When we don't use a lock, we are using a global mutex. We need to do this
// because LockFileEx is not thread safe.
-#if defined(OS_WIN)
- static MutexHandle log_mutex;
-#elif defined(OS_POSIX)
+#if defined(OS_POSIX)
static pthread_mutex_t log_mutex;
#endif
@@ -285,13 +265,12 @@ base::internal::LockImpl* LoggingLock::log_lock = nullptr;
// static
LogLockingState LoggingLock::lock_log_file = LOCK_LOG_FILE;
-#if defined(OS_WIN)
-// static
-MutexHandle LoggingLock::log_mutex = nullptr;
-#elif defined(OS_POSIX)
+#if defined(OS_POSIX)
pthread_mutex_t LoggingLock::log_mutex = PTHREAD_MUTEX_INITIALIZER;
#endif
+#endif // OS_WIN
+
// Called by logging functions to ensure that |g_log_file| is initialized
// and can be used for writing. Returns false if the file could not be
// initialized. |g_log_file| will be nullptr in this case.
@@ -307,12 +286,23 @@ bool InitializeLogFileHandle() {
if ((g_logging_destination & LOG_TO_FILE) != 0) {
#if defined(OS_WIN)
- g_log_file = CreateFile(g_log_file_name->c_str(), GENERIC_WRITE,
+ // The FILE_APPEND_DATA access mask ensures that the file is atomically
+ // appended to across accesses from multiple threads.
+ // https://msdn.microsoft.com/en-us/library/windows/desktop/aa364399(v=vs.85).aspx
+ // https://msdn.microsoft.com/en-us/library/windows/desktop/aa363858(v=vs.85).aspx
+ g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
// try the current directory
- g_log_file = CreateFile(L".\\debug.log", GENERIC_WRITE,
+ base::FilePath file_path;
+ if (!base::GetCurrentDirectory(&file_path))
+ return false;
+
+ *g_log_file_name = file_path.Append(
+ FILE_PATH_LITERAL("debug.log")).value();
+
+ g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
@@ -320,7 +310,6 @@ bool InitializeLogFileHandle() {
return false;
}
}
- SetFilePointer(g_log_file, 0, 0, FILE_END);
#elif defined(OS_POSIX)
g_log_file = fopen(g_log_file_name->c_str(), "a");
if (g_log_file == nullptr)
@@ -385,8 +374,10 @@ bool BaseInitLoggingImpl(const LoggingSettings& settings) {
if ((g_logging_destination & LOG_TO_FILE) == 0)
return true;
+#if !defined(OS_WIN)
LoggingLock::Init(settings.lock_log, settings.log_file);
LoggingLock logging_lock;
+#endif
// Calling InitLogging twice or after some log call has already opened the
// default log file will re-initialize to the new options.
@@ -409,6 +400,17 @@ int GetMinLogLevel() {
return g_min_log_level;
}
+bool ShouldCreateLogMessage(int severity) {
+ if (severity < g_min_log_level)
+ return false;
+
+ // Return true here unless we know ~LogMessage won't do anything. Note that
+ // ~LogMessage writes to stderr if severity_ >= kAlwaysPrintErrorLevel, even
+ // when g_logging_destination is LOG_NONE.
+ return g_logging_destination != LOG_NONE || log_message_handler ||
+ severity >= kAlwaysPrintErrorLevel;
+}
+
int GetVlogVerbosity() {
return std::max(-1, LOG_INFO - GetMinLogLevel());
}
@@ -473,38 +475,8 @@ void DisplayDebugMessageInDialog(const std::string& str) {
return;
#if defined(OS_WIN)
- // For Windows programs, it's possible that the message loop is
- // messed up on a fatal error, and creating a MessageBox will cause
- // that message loop to be run. Instead, we try to spawn another
- // process that displays its command line. We look for "Debug
- // Message.exe" in the same directory as the application. If it
- // exists, we use it, otherwise, we use a regular message box.
- wchar_t prog_name[MAX_PATH];
- GetModuleFileNameW(nullptr, prog_name, MAX_PATH);
- wchar_t* backslash = wcsrchr(prog_name, '\\');
- if (backslash)
- backslash[1] = 0;
- wcscat_s(prog_name, MAX_PATH, L"debug_message.exe");
-
- std::wstring cmdline = base::UTF8ToWide(str);
- if (cmdline.empty())
- return;
-
- STARTUPINFO startup_info;
- memset(&startup_info, 0, sizeof(startup_info));
- startup_info.cb = sizeof(startup_info);
-
- PROCESS_INFORMATION process_info;
- if (CreateProcessW(prog_name, &cmdline[0], nullptr, nullptr, false, 0,
- nullptr, nullptr, &startup_info, &process_info)) {
- WaitForSingleObject(process_info.hProcess, INFINITE);
- CloseHandle(process_info.hThread);
- CloseHandle(process_info.hProcess);
- } else {
- // debug process broken, let's just do a message box
- MessageBoxW(nullptr, &cmdline[0], L"Fatal error",
- MB_OK | MB_ICONHAND | MB_TOPMOST);
- }
+ MessageBoxW(nullptr, base::UTF8ToUTF16(str).c_str(), L"Fatal error",
+ MB_OK | MB_ICONHAND | MB_TOPMOST);
#else
// We intentionally don't implement a dialog on other platforms.
// You can just look at stderr.
@@ -526,6 +498,12 @@ LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
Init(file, line);
}
+LogMessage::LogMessage(const char* file, int line, const char* condition)
+ : severity_(LOG_FATAL), file_(file), line_(line) {
+ Init(file, line);
+ stream_ << "Check failed: " << condition << ". ";
+}
+
LogMessage::LogMessage(const char* file, int line, std::string* result)
: severity_(LOG_FATAL), file_(file), line_(line) {
Init(file, line);
@@ -542,9 +520,9 @@ LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
}
LogMessage::~LogMessage() {
-#if !defined(NDEBUG) && !defined(OS_NACL) && !defined(__UCLIBC__)
- if (severity_ == LOG_FATAL) {
- // Include a stack trace on a fatal.
+#if !defined(OFFICIAL_BUILD) && !defined(OS_NACL) && !defined(__UCLIBC__)
+ if (severity_ == LOG_FATAL && !base::debug::BeingDebugged()) {
+ // Include a stack trace on a fatal, unless a debugger is attached.
base::debug::StackTrace trace;
stream_ << std::endl; // Newline to separate from log message.
trace.OutputToStream(&stream_);
@@ -564,6 +542,121 @@ LogMessage::~LogMessage() {
if ((g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
#if defined(OS_WIN)
OutputDebugStringA(str_newline.c_str());
+#elif defined(OS_MACOSX)
+ // In LOG_TO_SYSTEM_DEBUG_LOG mode, log messages are always written to
+ // stderr. If stderr is /dev/null, also log via ASL (Apple System Log). If
+ // there's something weird about stderr, assume that log messages are going
+ // nowhere and log via ASL too. Messages logged via ASL show up in
+ // Console.app.
+ //
+ // Programs started by launchd, as UI applications normally are, have had
+ // stderr connected to /dev/null since OS X 10.8. Prior to that, stderr was
+ // a pipe to launchd, which logged what it received (see log_redirect_fd in
+ // 10.7.5 launchd-392.39/launchd/src/launchd_core_logic.c).
+ //
+ // Another alternative would be to determine whether stderr is a pipe to
+ // launchd and avoid logging via ASL only in that case. See 10.7.5
+ // CF-635.21/CFUtilities.c also_do_stderr(). This would result in logging to
+ // both stderr and ASL even in tests, where it's undesirable to log to the
+ // system log at all.
+ //
+ // Note that the ASL client by default discards messages whose levels are
+ // below ASL_LEVEL_NOTICE. It's possible to change that with
+ // asl_set_filter(), but this is pointless because syslogd normally applies
+ // the same filter.
+ const bool log_via_asl = []() {
+ struct stat stderr_stat;
+ if (fstat(fileno(stderr), &stderr_stat) == -1) {
+ return true;
+ }
+ if (!S_ISCHR(stderr_stat.st_mode)) {
+ return false;
+ }
+
+ struct stat dev_null_stat;
+ if (stat(_PATH_DEVNULL, &dev_null_stat) == -1) {
+ return true;
+ }
+
+ return !S_ISCHR(dev_null_stat.st_mode) ||
+ stderr_stat.st_rdev == dev_null_stat.st_rdev;
+ }();
+
+ if (log_via_asl) {
+ // Log roughly the same way that CFLog() and NSLog() would. See 10.10.5
+ // CF-1153.18/CFUtilities.c __CFLogCString().
+ //
+ // The ASL facility is set to the main bundle ID if available. Otherwise,
+ // "com.apple.console" is used.
+ CFBundleRef main_bundle = CFBundleGetMainBundle();
+ CFStringRef main_bundle_id_cf =
+ main_bundle ? CFBundleGetIdentifier(main_bundle) : nullptr;
+ std::string asl_facility =
+ main_bundle_id_cf ? base::SysCFStringRefToUTF8(main_bundle_id_cf)
+ : std::string("com.apple.console");
+
+ class ASLClient {
+ public:
+ explicit ASLClient(const std::string& asl_facility)
+ : client_(asl_open(nullptr,
+ asl_facility.c_str(),
+ ASL_OPT_NO_DELAY)) {}
+ ~ASLClient() { asl_close(client_); }
+
+ aslclient get() const { return client_; }
+
+ private:
+ aslclient client_;
+ DISALLOW_COPY_AND_ASSIGN(ASLClient);
+ } asl_client(asl_facility);
+
+ class ASLMessage {
+ public:
+ ASLMessage() : message_(asl_new(ASL_TYPE_MSG)) {}
+ ~ASLMessage() { asl_free(message_); }
+
+ aslmsg get() const { return message_; }
+
+ private:
+ aslmsg message_;
+ DISALLOW_COPY_AND_ASSIGN(ASLMessage);
+ } asl_message;
+
+ // By default, messages are only readable by the admin group. Explicitly
+ // make them readable by the user generating the messages.
+ char euid_string[12];
+ snprintf(euid_string, arraysize(euid_string), "%d", geteuid());
+ asl_set(asl_message.get(), ASL_KEY_READ_UID, euid_string);
+
+ // Map Chrome log severities to ASL log levels.
+ const char* const asl_level_string = [](LogSeverity severity) {
+ // ASL_LEVEL_* are ints, but ASL needs equivalent strings. This
+ // non-obvious two-step macro trick achieves what's needed.
+ // https://gcc.gnu.org/onlinedocs/cpp/Stringification.html
+#define ASL_LEVEL_STR(level) ASL_LEVEL_STR_X(level)
+#define ASL_LEVEL_STR_X(level) #level
+ switch (severity) {
+ case LOG_INFO:
+ return ASL_LEVEL_STR(ASL_LEVEL_INFO);
+ case LOG_WARNING:
+ return ASL_LEVEL_STR(ASL_LEVEL_WARNING);
+ case LOG_ERROR:
+ return ASL_LEVEL_STR(ASL_LEVEL_ERR);
+ case LOG_FATAL:
+ return ASL_LEVEL_STR(ASL_LEVEL_CRIT);
+ default:
+ return severity < 0 ? ASL_LEVEL_STR(ASL_LEVEL_DEBUG)
+ : ASL_LEVEL_STR(ASL_LEVEL_NOTICE);
+ }
+#undef ASL_LEVEL_STR
+#undef ASL_LEVEL_STR_X
+ }(severity_);
+ asl_set(asl_message.get(), ASL_KEY_LEVEL, asl_level_string);
+
+ asl_set(asl_message.get(), ASL_KEY_MSG, str_newline.c_str());
+
+ asl_send(asl_client.get(), asl_message.get());
+ }
#elif defined(OS_ANDROID) || defined(__ANDROID__)
android_LogPriority priority =
(severity_ < 0) ? ANDROID_LOG_VERBOSE : ANDROID_LOG_UNKNOWN;
@@ -611,11 +704,12 @@ LogMessage::~LogMessage() {
// to do this at the same time, there will be a race condition to create
// the lock. This is why InitLogging should be called from the main
// thread at the beginning of execution.
+#if !defined(OS_WIN)
LoggingLock::Init(LOCK_LOG_FILE, nullptr);
LoggingLock logging_lock;
+#endif
if (InitializeLogFileHandle()) {
#if defined(OS_WIN)
- SetFilePointer(g_log_file, 0, 0, SEEK_END);
DWORD num_written;
WriteFile(g_log_file,
static_cast<const void*>(str_newline.c_str()),
@@ -647,7 +741,11 @@ LogMessage::~LogMessage() {
// information, and displaying message boxes when the application is
// hosed can cause additional problems.
#ifndef NDEBUG
- DisplayDebugMessageInDialog(stream_.str());
+ if (!base::debug::BeingDebugged()) {
+ // Displaying a dialog is unnecessary when debugging and can complicate
+ // debugging.
+ DisplayDebugMessageInDialog(stream_.str());
+ }
#endif
// Crash the process to generate a dump.
base::debug::BreakDebugger();
@@ -772,7 +870,9 @@ ErrnoLogMessage::~ErrnoLogMessage() {
#endif // defined(OS_WIN)
void CloseLogFile() {
+#if !defined(OS_WIN)
LoggingLock logging_lock;
+#endif
CloseLogFileUnlocked();
}
@@ -811,6 +911,10 @@ void RawLog(int level, const char* message) {
#undef write
#if defined(OS_WIN)
+bool IsLoggingToFileEnabled() {
+ return g_logging_destination & LOG_TO_FILE;
+}
+
std::wstring GetLogFileFullPath() {
if (g_log_file_name)
return *g_log_file_name;