blob: 49623bf555abfa0d7f09874f9b821bfa1e3fbd1b [file] [log] [blame]
Torne (Richard Coles)58218062012-11-14 11:43:16 +00001// Copyright (c) 2012 The Chromium Authors. All rights reserved.
2// Use of this source code is governed by a BSD-style license that can be
3// found in the LICENSE file.
4
5#include "base/logging.h"
6
7#if defined(OS_WIN)
8#include <io.h>
9#include <windows.h>
10typedef HANDLE FileHandle;
11typedef HANDLE MutexHandle;
12// Windows warns on using write(). It prefers _write().
13#define write(fd, buf, count) _write(fd, buf, static_cast<unsigned int>(count))
14// Windows doesn't define STDERR_FILENO. Define it here.
15#define STDERR_FILENO 2
16#elif defined(OS_MACOSX)
17#include <mach/mach.h>
18#include <mach/mach_time.h>
19#include <mach-o/dyld.h>
20#elif defined(OS_POSIX)
21#if defined(OS_NACL)
22#include <sys/time.h> // timespec doesn't seem to be in <time.h>
23#else
24#include <sys/syscall.h>
25#endif
26#include <time.h>
27#endif
28
29#if defined(OS_POSIX)
30#include <errno.h>
31#include <pthread.h>
Torne (Richard Coles)58218062012-11-14 11:43:16 +000032#include <stdio.h>
Torne (Richard Coles)c2e0dbd2013-05-09 18:35:53 +010033#include <stdlib.h>
Torne (Richard Coles)58218062012-11-14 11:43:16 +000034#include <string.h>
35#include <unistd.h>
36#define MAX_PATH PATH_MAX
37typedef FILE* FileHandle;
38typedef pthread_mutex_t* MutexHandle;
39#endif
40
41#include <algorithm>
42#include <cstring>
43#include <ctime>
44#include <iomanip>
45#include <ostream>
46
47#include "base/base_switches.h"
48#include "base/command_line.h"
49#include "base/debug/alias.h"
50#include "base/debug/debugger.h"
51#include "base/debug/stack_trace.h"
Torne (Richard Coles)2a99a7e2013-03-28 15:31:22 +000052#include "base/posix/eintr_wrapper.h"
Torne (Richard Coles)c2e0dbd2013-05-09 18:35:53 +010053#include "base/strings/string_piece.h"
Torne (Richard Coles)868fa2f2013-06-11 10:57:03 +010054#include "base/strings/utf_string_conversions.h"
Torne (Richard Coles)58218062012-11-14 11:43:16 +000055#include "base/synchronization/lock_impl.h"
56#include "base/threading/platform_thread.h"
Torne (Richard Coles)58218062012-11-14 11:43:16 +000057#include "base/vlog.h"
58#if defined(OS_POSIX)
59#include "base/safe_strerror_posix.h"
60#endif
61
62#if defined(OS_ANDROID)
63#include <android/log.h>
64#endif
65
66namespace logging {
67
68DcheckState g_dcheck_state = DISABLE_DCHECK_FOR_NON_OFFICIAL_RELEASE_BUILDS;
69
Torne (Richard Coles)90dce4d2013-05-29 14:40:03 +010070DcheckState get_dcheck_state() {
71 return g_dcheck_state;
72}
73
74void set_dcheck_state(DcheckState state) {
75 g_dcheck_state = state;
76}
77
Torne (Richard Coles)58218062012-11-14 11:43:16 +000078namespace {
79
80VlogInfo* g_vlog_info = NULL;
81VlogInfo* g_vlog_info_prev = NULL;
82
83const char* const log_severity_names[LOG_NUM_SEVERITIES] = {
84 "INFO", "WARNING", "ERROR", "ERROR_REPORT", "FATAL" };
85
86int min_log_level = 0;
87
88// The default set here for logging_destination will only be used if
89// InitLogging is not called. On Windows, use a file next to the exe;
90// on POSIX platforms, where it may not even be possible to locate the
91// executable on disk, use stderr.
92#if defined(OS_WIN)
93LoggingDestination logging_destination = LOG_ONLY_TO_FILE;
94#elif defined(OS_POSIX)
95LoggingDestination logging_destination = LOG_ONLY_TO_SYSTEM_DEBUG_LOG;
96#endif
97
98// For LOG_ERROR and above, always print to stderr.
99const int kAlwaysPrintErrorLevel = LOG_ERROR;
100
101// Which log file to use? This is initialized by InitLogging or
102// will be lazily initialized to the default value when it is
103// first needed.
104#if defined(OS_WIN)
105typedef std::wstring PathString;
106#else
107typedef std::string PathString;
108#endif
109PathString* log_file_name = NULL;
110
111// this file is lazily opened and the handle may be NULL
112FileHandle log_file = NULL;
113
114// what should be prepended to each message?
115bool log_process_id = false;
116bool log_thread_id = false;
117bool log_timestamp = true;
118bool log_tickcount = false;
119
120// Should we pop up fatal debug messages in a dialog?
121bool show_error_dialogs = false;
122
123// An assert handler override specified by the client to be called instead of
124// the debug message dialog and process termination.
125LogAssertHandlerFunction log_assert_handler = NULL;
126// An report handler override specified by the client to be called instead of
127// the debug message dialog.
128LogReportHandlerFunction log_report_handler = NULL;
129// A log message handler that gets notified of every log message we process.
130LogMessageHandlerFunction log_message_handler = NULL;
131
132// Helper functions to wrap platform differences.
133
134int32 CurrentProcessId() {
135#if defined(OS_WIN)
136 return GetCurrentProcessId();
137#elif defined(OS_POSIX)
138 return getpid();
139#endif
140}
141
142uint64 TickCount() {
143#if defined(OS_WIN)
144 return GetTickCount();
145#elif defined(OS_MACOSX)
146 return mach_absolute_time();
147#elif defined(OS_NACL)
148 // NaCl sadly does not have _POSIX_TIMERS enabled in sys/features.h
149 // So we have to use clock() for now.
150 return clock();
151#elif defined(OS_POSIX)
152 struct timespec ts;
153 clock_gettime(CLOCK_MONOTONIC, &ts);
154
155 uint64 absolute_micro =
156 static_cast<int64>(ts.tv_sec) * 1000000 +
157 static_cast<int64>(ts.tv_nsec) / 1000;
158
159 return absolute_micro;
160#endif
161}
162
163void CloseFile(FileHandle log) {
164#if defined(OS_WIN)
165 CloseHandle(log);
166#else
167 fclose(log);
168#endif
169}
170
171void DeleteFilePath(const PathString& log_name) {
172#if defined(OS_WIN)
173 DeleteFile(log_name.c_str());
Torne (Richard Coles)c2e0dbd2013-05-09 18:35:53 +0100174#elif defined (OS_NACL)
175 // Do nothing; unlink() isn't supported on NaCl.
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000176#else
177 unlink(log_name.c_str());
178#endif
179}
180
181PathString GetDefaultLogFile() {
182#if defined(OS_WIN)
183 // On Windows we use the same path as the exe.
184 wchar_t module_name[MAX_PATH];
185 GetModuleFileName(NULL, module_name, MAX_PATH);
186
187 PathString log_file = module_name;
188 PathString::size_type last_backslash =
189 log_file.rfind('\\', log_file.size());
190 if (last_backslash != PathString::npos)
191 log_file.erase(last_backslash + 1);
192 log_file += L"debug.log";
193 return log_file;
194#elif defined(OS_POSIX)
195 // On other platforms we just use the current directory.
196 return PathString("debug.log");
197#endif
198}
199
200// This class acts as a wrapper for locking the logging files.
201// LoggingLock::Init() should be called from the main thread before any logging
202// is done. Then whenever logging, be sure to have a local LoggingLock
203// instance on the stack. This will ensure that the lock is unlocked upon
204// exiting the frame.
205// LoggingLocks can not be nested.
206class LoggingLock {
207 public:
208 LoggingLock() {
209 LockLogging();
210 }
211
212 ~LoggingLock() {
213 UnlockLogging();
214 }
215
216 static void Init(LogLockingState lock_log, const PathChar* new_log_file) {
217 if (initialized)
218 return;
219 lock_log_file = lock_log;
220 if (lock_log_file == LOCK_LOG_FILE) {
221#if defined(OS_WIN)
222 if (!log_mutex) {
223 std::wstring safe_name;
224 if (new_log_file)
225 safe_name = new_log_file;
226 else
227 safe_name = GetDefaultLogFile();
228 // \ is not a legal character in mutex names so we replace \ with /
229 std::replace(safe_name.begin(), safe_name.end(), '\\', '/');
230 std::wstring t(L"Global\\");
231 t.append(safe_name);
232 log_mutex = ::CreateMutex(NULL, FALSE, t.c_str());
233
234 if (log_mutex == NULL) {
235#if DEBUG
236 // Keep the error code for debugging
237 int error = GetLastError(); // NOLINT
238 base::debug::BreakDebugger();
239#endif
240 // Return nicely without putting initialized to true.
241 return;
242 }
243 }
244#endif
245 } else {
246 log_lock = new base::internal::LockImpl();
247 }
248 initialized = true;
249 }
250
251 private:
252 static void LockLogging() {
253 if (lock_log_file == LOCK_LOG_FILE) {
254#if defined(OS_WIN)
255 ::WaitForSingleObject(log_mutex, INFINITE);
256 // WaitForSingleObject could have returned WAIT_ABANDONED. We don't
257 // abort the process here. UI tests might be crashy sometimes,
258 // and aborting the test binary only makes the problem worse.
259 // We also don't use LOG macros because that might lead to an infinite
260 // loop. For more info see http://crbug.com/18028.
261#elif defined(OS_POSIX)
262 pthread_mutex_lock(&log_mutex);
263#endif
264 } else {
265 // use the lock
266 log_lock->Lock();
267 }
268 }
269
270 static void UnlockLogging() {
271 if (lock_log_file == LOCK_LOG_FILE) {
272#if defined(OS_WIN)
273 ReleaseMutex(log_mutex);
274#elif defined(OS_POSIX)
275 pthread_mutex_unlock(&log_mutex);
276#endif
277 } else {
278 log_lock->Unlock();
279 }
280 }
281
282 // The lock is used if log file locking is false. It helps us avoid problems
283 // with multiple threads writing to the log file at the same time. Use
284 // LockImpl directly instead of using Lock, because Lock makes logging calls.
285 static base::internal::LockImpl* log_lock;
286
287 // When we don't use a lock, we are using a global mutex. We need to do this
288 // because LockFileEx is not thread safe.
289#if defined(OS_WIN)
290 static MutexHandle log_mutex;
291#elif defined(OS_POSIX)
292 static pthread_mutex_t log_mutex;
293#endif
294
295 static bool initialized;
296 static LogLockingState lock_log_file;
297};
298
299// static
300bool LoggingLock::initialized = false;
301// static
302base::internal::LockImpl* LoggingLock::log_lock = NULL;
303// static
304LogLockingState LoggingLock::lock_log_file = LOCK_LOG_FILE;
305
306#if defined(OS_WIN)
307// static
308MutexHandle LoggingLock::log_mutex = NULL;
309#elif defined(OS_POSIX)
310pthread_mutex_t LoggingLock::log_mutex = PTHREAD_MUTEX_INITIALIZER;
311#endif
312
313// Called by logging functions to ensure that debug_file is initialized
314// and can be used for writing. Returns false if the file could not be
315// initialized. debug_file will be NULL in this case.
316bool InitializeLogFileHandle() {
317 if (log_file)
318 return true;
319
320 if (!log_file_name) {
321 // Nobody has called InitLogging to specify a debug log file, so here we
322 // initialize the log file name to a default.
323 log_file_name = new PathString(GetDefaultLogFile());
324 }
325
326 if (logging_destination == LOG_ONLY_TO_FILE ||
327 logging_destination == LOG_TO_BOTH_FILE_AND_SYSTEM_DEBUG_LOG) {
328#if defined(OS_WIN)
329 log_file = CreateFile(log_file_name->c_str(), GENERIC_WRITE,
330 FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
331 OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
332 if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
333 // try the current directory
334 log_file = CreateFile(L".\\debug.log", GENERIC_WRITE,
335 FILE_SHARE_READ | FILE_SHARE_WRITE, NULL,
336 OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, NULL);
337 if (log_file == INVALID_HANDLE_VALUE || log_file == NULL) {
338 log_file = NULL;
339 return false;
340 }
341 }
342 SetFilePointer(log_file, 0, 0, FILE_END);
343#elif defined(OS_POSIX)
344 log_file = fopen(log_file_name->c_str(), "a");
345 if (log_file == NULL)
346 return false;
347#endif
348 }
349
350 return true;
351}
352
353} // namespace
354
355
356bool BaseInitLoggingImpl(const PathChar* new_log_file,
357 LoggingDestination logging_dest,
358 LogLockingState lock_log,
359 OldFileDeletionState delete_old,
360 DcheckState dcheck_state) {
Torne (Richard Coles)c2e0dbd2013-05-09 18:35:53 +0100361#if defined(OS_NACL)
362 CHECK(logging_dest == LOG_NONE ||
363 logging_dest == LOG_ONLY_TO_SYSTEM_DEBUG_LOG);
364#endif
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000365 g_dcheck_state = dcheck_state;
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000366 CommandLine* command_line = CommandLine::ForCurrentProcess();
367 // Don't bother initializing g_vlog_info unless we use one of the
368 // vlog switches.
369 if (command_line->HasSwitch(switches::kV) ||
370 command_line->HasSwitch(switches::kVModule)) {
371 // NOTE: If g_vlog_info has already been initialized, it might be in use
372 // by another thread. Don't delete the old VLogInfo, just create a second
373 // one. We keep track of both to avoid memory leak warnings.
374 CHECK(!g_vlog_info_prev);
375 g_vlog_info_prev = g_vlog_info;
376
377 g_vlog_info =
378 new VlogInfo(command_line->GetSwitchValueASCII(switches::kV),
379 command_line->GetSwitchValueASCII(switches::kVModule),
380 &min_log_level);
381 }
382
383 LoggingLock::Init(lock_log, new_log_file);
384
385 LoggingLock logging_lock;
386
387 if (log_file) {
388 // calling InitLogging twice or after some log call has already opened the
389 // default log file will re-initialize to the new options
390 CloseFile(log_file);
391 log_file = NULL;
392 }
393
394 logging_destination = logging_dest;
395
396 // ignore file options if logging is disabled or only to system
397 if (logging_destination == LOG_NONE ||
398 logging_destination == LOG_ONLY_TO_SYSTEM_DEBUG_LOG)
399 return true;
400
401 if (!log_file_name)
402 log_file_name = new PathString();
403 *log_file_name = new_log_file;
404 if (delete_old == DELETE_OLD_LOG_FILE)
405 DeleteFilePath(*log_file_name);
406
407 return InitializeLogFileHandle();
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000408}
409
410void SetMinLogLevel(int level) {
411 min_log_level = std::min(LOG_ERROR_REPORT, level);
412}
413
414int GetMinLogLevel() {
415 return min_log_level;
416}
417
418int GetVlogVerbosity() {
419 return std::max(-1, LOG_INFO - GetMinLogLevel());
420}
421
422int GetVlogLevelHelper(const char* file, size_t N) {
423 DCHECK_GT(N, 0U);
424 // Note: g_vlog_info may change on a different thread during startup
425 // (but will always be valid or NULL).
426 VlogInfo* vlog_info = g_vlog_info;
427 return vlog_info ?
428 vlog_info->GetVlogLevel(base::StringPiece(file, N - 1)) :
429 GetVlogVerbosity();
430}
431
432void SetLogItems(bool enable_process_id, bool enable_thread_id,
433 bool enable_timestamp, bool enable_tickcount) {
434 log_process_id = enable_process_id;
435 log_thread_id = enable_thread_id;
436 log_timestamp = enable_timestamp;
437 log_tickcount = enable_tickcount;
438}
439
440void SetShowErrorDialogs(bool enable_dialogs) {
441 show_error_dialogs = enable_dialogs;
442}
443
444void SetLogAssertHandler(LogAssertHandlerFunction handler) {
445 log_assert_handler = handler;
446}
447
448void SetLogReportHandler(LogReportHandlerFunction handler) {
449 log_report_handler = handler;
450}
451
452void SetLogMessageHandler(LogMessageHandlerFunction handler) {
453 log_message_handler = handler;
454}
455
456LogMessageHandlerFunction GetLogMessageHandler() {
457 return log_message_handler;
458}
459
460// MSVC doesn't like complex extern templates and DLLs.
461#if !defined(COMPILER_MSVC)
462// Explicit instantiations for commonly used comparisons.
463template std::string* MakeCheckOpString<int, int>(
464 const int&, const int&, const char* names);
465template std::string* MakeCheckOpString<unsigned long, unsigned long>(
466 const unsigned long&, const unsigned long&, const char* names);
467template std::string* MakeCheckOpString<unsigned long, unsigned int>(
468 const unsigned long&, const unsigned int&, const char* names);
469template std::string* MakeCheckOpString<unsigned int, unsigned long>(
470 const unsigned int&, const unsigned long&, const char* names);
471template std::string* MakeCheckOpString<std::string, std::string>(
472 const std::string&, const std::string&, const char* name);
473#endif
474
475// Displays a message box to the user with the error message in it.
476// Used for fatal messages, where we close the app simultaneously.
477// This is for developers only; we don't use this in circumstances
478// (like release builds) where users could see it, since users don't
479// understand these messages anyway.
480void DisplayDebugMessageInDialog(const std::string& str) {
481 if (str.empty())
482 return;
483
484 if (!show_error_dialogs)
485 return;
486
487#if defined(OS_WIN)
488 // For Windows programs, it's possible that the message loop is
489 // messed up on a fatal error, and creating a MessageBox will cause
490 // that message loop to be run. Instead, we try to spawn another
491 // process that displays its command line. We look for "Debug
492 // Message.exe" in the same directory as the application. If it
493 // exists, we use it, otherwise, we use a regular message box.
494 wchar_t prog_name[MAX_PATH];
495 GetModuleFileNameW(NULL, prog_name, MAX_PATH);
496 wchar_t* backslash = wcsrchr(prog_name, '\\');
497 if (backslash)
498 backslash[1] = 0;
499 wcscat_s(prog_name, MAX_PATH, L"debug_message.exe");
500
501 std::wstring cmdline = UTF8ToWide(str);
502 if (cmdline.empty())
503 return;
504
505 STARTUPINFO startup_info;
506 memset(&startup_info, 0, sizeof(startup_info));
507 startup_info.cb = sizeof(startup_info);
508
509 PROCESS_INFORMATION process_info;
510 if (CreateProcessW(prog_name, &cmdline[0], NULL, NULL, false, 0, NULL,
511 NULL, &startup_info, &process_info)) {
512 WaitForSingleObject(process_info.hProcess, INFINITE);
513 CloseHandle(process_info.hThread);
514 CloseHandle(process_info.hProcess);
515 } else {
516 // debug process broken, let's just do a message box
517 MessageBoxW(NULL, &cmdline[0], L"Fatal error",
518 MB_OK | MB_ICONHAND | MB_TOPMOST);
519 }
520#else
521 // We intentionally don't implement a dialog on other platforms.
522 // You can just look at stderr.
523#endif
524}
525
526#if defined(OS_WIN)
527LogMessage::SaveLastError::SaveLastError() : last_error_(::GetLastError()) {
528}
529
530LogMessage::SaveLastError::~SaveLastError() {
531 ::SetLastError(last_error_);
532}
533#endif // defined(OS_WIN)
534
535LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
536 int ctr)
537 : severity_(severity), file_(file), line_(line) {
538 Init(file, line);
539}
540
541LogMessage::LogMessage(const char* file, int line)
542 : severity_(LOG_INFO), file_(file), line_(line) {
543 Init(file, line);
544}
545
546LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
547 : severity_(severity), file_(file), line_(line) {
548 Init(file, line);
549}
550
551LogMessage::LogMessage(const char* file, int line, std::string* result)
552 : severity_(LOG_FATAL), file_(file), line_(line) {
553 Init(file, line);
554 stream_ << "Check failed: " << *result;
555 delete result;
556}
557
558LogMessage::LogMessage(const char* file, int line, LogSeverity severity,
559 std::string* result)
560 : severity_(severity), file_(file), line_(line) {
561 Init(file, line);
562 stream_ << "Check failed: " << *result;
563 delete result;
564}
565
566LogMessage::~LogMessage() {
567 // TODO(port): enable stacktrace generation on LOG_FATAL once backtrace are
568 // working in Android.
569#if !defined(NDEBUG) && !defined(OS_ANDROID) && !defined(OS_NACL)
570 if (severity_ == LOG_FATAL) {
571 // Include a stack trace on a fatal.
572 base::debug::StackTrace trace;
573 stream_ << std::endl; // Newline to separate from log message.
574 trace.OutputToStream(&stream_);
575 }
576#endif
577 stream_ << std::endl;
578 std::string str_newline(stream_.str());
579
580 // Give any log message handler first dibs on the message.
581 if (log_message_handler && log_message_handler(severity_, file_, line_,
582 message_start_, str_newline)) {
583 // The handler took care of it, no further processing.
584 return;
585 }
586
587 if (logging_destination == LOG_ONLY_TO_SYSTEM_DEBUG_LOG ||
588 logging_destination == LOG_TO_BOTH_FILE_AND_SYSTEM_DEBUG_LOG) {
589#if defined(OS_WIN)
590 OutputDebugStringA(str_newline.c_str());
591#elif defined(OS_ANDROID)
Torne (Richard Coles)90dce4d2013-05-29 14:40:03 +0100592 android_LogPriority priority =
593 (severity_ < 0) ? ANDROID_LOG_VERBOSE : ANDROID_LOG_UNKNOWN;
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000594 switch (severity_) {
595 case LOG_INFO:
596 priority = ANDROID_LOG_INFO;
597 break;
598 case LOG_WARNING:
599 priority = ANDROID_LOG_WARN;
600 break;
601 case LOG_ERROR:
602 case LOG_ERROR_REPORT:
603 priority = ANDROID_LOG_ERROR;
604 break;
605 case LOG_FATAL:
606 priority = ANDROID_LOG_FATAL;
607 break;
608 }
609 __android_log_write(priority, "chromium", str_newline.c_str());
610#endif
611 fprintf(stderr, "%s", str_newline.c_str());
612 fflush(stderr);
613 } else if (severity_ >= kAlwaysPrintErrorLevel) {
614 // When we're only outputting to a log file, above a certain log level, we
615 // should still output to stderr so that we can better detect and diagnose
616 // problems with unit tests, especially on the buildbots.
617 fprintf(stderr, "%s", str_newline.c_str());
618 fflush(stderr);
619 }
620
621 // We can have multiple threads and/or processes, so try to prevent them
622 // from clobbering each other's writes.
623 // If the client app did not call InitLogging, and the lock has not
624 // been created do it now. We do this on demand, but if two threads try
625 // to do this at the same time, there will be a race condition to create
626 // the lock. This is why InitLogging should be called from the main
627 // thread at the beginning of execution.
628 LoggingLock::Init(LOCK_LOG_FILE, NULL);
629 // write to log file
630 if (logging_destination != LOG_NONE &&
631 logging_destination != LOG_ONLY_TO_SYSTEM_DEBUG_LOG) {
632 LoggingLock logging_lock;
633 if (InitializeLogFileHandle()) {
634#if defined(OS_WIN)
635 SetFilePointer(log_file, 0, 0, SEEK_END);
636 DWORD num_written;
637 WriteFile(log_file,
638 static_cast<const void*>(str_newline.c_str()),
639 static_cast<DWORD>(str_newline.length()),
640 &num_written,
641 NULL);
642#else
643 fprintf(log_file, "%s", str_newline.c_str());
644 fflush(log_file);
645#endif
646 }
647 }
648
649 if (severity_ == LOG_FATAL) {
650 // Ensure the first characters of the string are on the stack so they
651 // are contained in minidumps for diagnostic purposes.
652 char str_stack[1024];
653 str_newline.copy(str_stack, arraysize(str_stack));
654 base::debug::Alias(str_stack);
655
656 // display a message or break into the debugger on a fatal error
657 if (base::debug::BeingDebugged()) {
658 base::debug::BreakDebugger();
659 } else {
660 if (log_assert_handler) {
661 // make a copy of the string for the handler out of paranoia
662 log_assert_handler(std::string(stream_.str()));
663 } else {
664 // Don't use the string with the newline, get a fresh version to send to
665 // the debug message process. We also don't display assertions to the
666 // user in release mode. The enduser can't do anything with this
667 // information, and displaying message boxes when the application is
668 // hosed can cause additional problems.
669#ifndef NDEBUG
670 DisplayDebugMessageInDialog(stream_.str());
671#endif
672 // Crash the process to generate a dump.
673 base::debug::BreakDebugger();
674 }
675 }
676 } else if (severity_ == LOG_ERROR_REPORT) {
677 // We are here only if the user runs with --enable-dcheck in release mode.
678 if (log_report_handler) {
679 log_report_handler(std::string(stream_.str()));
680 } else {
681 DisplayDebugMessageInDialog(stream_.str());
682 }
683 }
684}
685
686// writes the common header info to the stream
687void LogMessage::Init(const char* file, int line) {
688 base::StringPiece filename(file);
689 size_t last_slash_pos = filename.find_last_of("\\/");
690 if (last_slash_pos != base::StringPiece::npos)
691 filename.remove_prefix(last_slash_pos + 1);
692
693 // TODO(darin): It might be nice if the columns were fixed width.
694
695 stream_ << '[';
696 if (log_process_id)
697 stream_ << CurrentProcessId() << ':';
698 if (log_thread_id)
699 stream_ << base::PlatformThread::CurrentId() << ':';
700 if (log_timestamp) {
701 time_t t = time(NULL);
702 struct tm local_time = {0};
703#if _MSC_VER >= 1400
704 localtime_s(&local_time, &t);
705#else
706 localtime_r(&t, &local_time);
707#endif
708 struct tm* tm_time = &local_time;
709 stream_ << std::setfill('0')
710 << std::setw(2) << 1 + tm_time->tm_mon
711 << std::setw(2) << tm_time->tm_mday
712 << '/'
713 << std::setw(2) << tm_time->tm_hour
714 << std::setw(2) << tm_time->tm_min
715 << std::setw(2) << tm_time->tm_sec
716 << ':';
717 }
718 if (log_tickcount)
719 stream_ << TickCount() << ':';
720 if (severity_ >= 0)
721 stream_ << log_severity_names[severity_];
722 else
723 stream_ << "VERBOSE" << -severity_;
724
725 stream_ << ":" << filename << "(" << line << ")] ";
726
727 message_start_ = stream_.tellp();
728}
729
730#if defined(OS_WIN)
731// This has already been defined in the header, but defining it again as DWORD
732// ensures that the type used in the header is equivalent to DWORD. If not,
733// the redefinition is a compile error.
734typedef DWORD SystemErrorCode;
735#endif
736
737SystemErrorCode GetLastSystemErrorCode() {
738#if defined(OS_WIN)
739 return ::GetLastError();
740#elif defined(OS_POSIX)
741 return errno;
742#else
743#error Not implemented
744#endif
745}
746
747#if defined(OS_WIN)
748Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
749 int line,
750 LogSeverity severity,
751 SystemErrorCode err,
752 const char* module)
753 : err_(err),
754 module_(module),
755 log_message_(file, line, severity) {
756}
757
758Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
759 int line,
760 LogSeverity severity,
761 SystemErrorCode err)
762 : err_(err),
763 module_(NULL),
764 log_message_(file, line, severity) {
765}
766
767Win32ErrorLogMessage::~Win32ErrorLogMessage() {
768 const int error_message_buffer_size = 256;
769 char msgbuf[error_message_buffer_size];
770 DWORD flags = FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_IGNORE_INSERTS;
771 HMODULE hmod;
772 if (module_) {
773 hmod = GetModuleHandleA(module_);
774 if (hmod) {
775 flags |= FORMAT_MESSAGE_FROM_HMODULE;
776 } else {
777 // This makes a nested Win32ErrorLogMessage. It will have module_ of NULL
778 // so it will not call GetModuleHandle, so recursive errors are
779 // impossible.
780 DPLOG(WARNING) << "Couldn't open module " << module_
781 << " for error message query";
782 }
783 } else {
784 hmod = NULL;
785 }
786 DWORD len = FormatMessageA(flags,
787 hmod,
788 err_,
789 0,
790 msgbuf,
791 sizeof(msgbuf) / sizeof(msgbuf[0]),
792 NULL);
793 if (len) {
794 while ((len > 0) &&
795 isspace(static_cast<unsigned char>(msgbuf[len - 1]))) {
796 msgbuf[--len] = 0;
797 }
798 stream() << ": " << msgbuf;
799 } else {
800 stream() << ": Error " << GetLastError() << " while retrieving error "
801 << err_;
802 }
803 // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
804 // field) and use Alias in hopes that it makes it into crash dumps.
805 DWORD last_error = err_;
806 base::debug::Alias(&last_error);
807}
808#elif defined(OS_POSIX)
809ErrnoLogMessage::ErrnoLogMessage(const char* file,
810 int line,
811 LogSeverity severity,
812 SystemErrorCode err)
813 : err_(err),
814 log_message_(file, line, severity) {
815}
816
817ErrnoLogMessage::~ErrnoLogMessage() {
818 stream() << ": " << safe_strerror(err_);
819}
820#endif // OS_WIN
821
822void CloseLogFile() {
823 LoggingLock logging_lock;
824
825 if (!log_file)
826 return;
827
828 CloseFile(log_file);
829 log_file = NULL;
830}
831
832void RawLog(int level, const char* message) {
833 if (level >= min_log_level) {
834 size_t bytes_written = 0;
835 const size_t message_len = strlen(message);
836 int rv;
837 while (bytes_written < message_len) {
838 rv = HANDLE_EINTR(
839 write(STDERR_FILENO, message + bytes_written,
840 message_len - bytes_written));
841 if (rv < 0) {
842 // Give up, nothing we can do now.
843 break;
844 }
845 bytes_written += rv;
846 }
847
848 if (message_len > 0 && message[message_len - 1] != '\n') {
849 do {
850 rv = HANDLE_EINTR(write(STDERR_FILENO, "\n", 1));
851 if (rv < 0) {
852 // Give up, nothing we can do now.
853 break;
854 }
855 } while (rv != 1);
856 }
857 }
858
859 if (level == LOG_FATAL)
860 base::debug::BreakDebugger();
861}
862
863// This was defined at the beginning of this file.
864#undef write
865
Torne (Richard Coles)2a99a7e2013-03-28 15:31:22 +0000866#if defined(OS_WIN)
867std::wstring GetLogFileFullPath() {
868 if (log_file_name)
869 return *log_file_name;
870 return std::wstring();
871}
872#endif
873
Torne (Richard Coles)58218062012-11-14 11:43:16 +0000874} // namespace logging
875
876std::ostream& operator<<(std::ostream& out, const wchar_t* wstr) {
877 return out << WideToUTF8(std::wstring(wstr));
878}