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