[M94 Dev][Tizen] Fix for errors for generating ninja files
[platform/framework/web/chromium-efl.git] / base / logging.cc
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 // logging.h is a widely included header and its size has significant impact on
8 // build time. Try not to raise this limit unless absolutely necessary. See
9 // https://chromium.googlesource.com/chromium/src/+/HEAD/docs/wmax_tokens.md
10 #ifndef NACL_TC_REV
11 #pragma clang max_tokens_here 350000
12 #endif  // NACL_TC_REV
13
14 #ifdef BASE_CHECK_H_
15 #error "logging.h should not include check.h"
16 #endif
17
18 #include <limits.h>
19 #include <stdint.h>
20
21 #include <vector>
22
23 #include "base/cxx17_backports.h"
24 #include "base/pending_task.h"
25 #include "base/strings/string_piece.h"
26 #include "base/task/common/task_annotator.h"
27 #include "base/trace_event/base_tracing.h"
28 #include "build/build_config.h"
29
30 #if defined(OS_WIN)
31 #include <io.h>
32 #include <windows.h>
33 typedef HANDLE FileHandle;
34 // Windows warns on using write().  It prefers _write().
35 #define write(fd, buf, count) _write(fd, buf, static_cast<unsigned int>(count))
36 // Windows doesn't define STDERR_FILENO.  Define it here.
37 #define STDERR_FILENO 2
38
39 #elif defined(OS_APPLE)
40 // In MacOS 10.12 and iOS 10.0 and later ASL (Apple System Log) was deprecated
41 // in favor of OS_LOG (Unified Logging).
42 #include <AvailabilityMacros.h>
43 #if defined(OS_IOS)
44 #if !defined(__IPHONE_10_0) || __IPHONE_OS_VERSION_MIN_REQUIRED < __IPHONE_10_0
45 #define USE_ASL
46 #endif
47 #else  // !defined(OS_IOS)
48 #if !defined(MAC_OS_X_VERSION_10_12) || \
49     MAC_OS_X_VERSION_MIN_REQUIRED < MAC_OS_X_VERSION_10_12
50 #define USE_ASL
51 #endif
52 #endif  // defined(OS_IOS)
53
54 #if defined(USE_ASL)
55 #include <asl.h>
56 #else
57 #include <os/log.h>
58 #endif
59
60 #include <CoreFoundation/CoreFoundation.h>
61 #include <mach/mach.h>
62 #include <mach/mach_time.h>
63 #include <mach-o/dyld.h>
64
65 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
66 #if defined(OS_NACL)
67 #include <sys/time.h>  // timespec doesn't seem to be in <time.h>
68 #endif
69 #include <time.h>
70 #endif
71
72 #if defined(OS_FUCHSIA)
73 #include <lib/syslog/global.h>
74 #include <lib/syslog/logger.h>
75 #include <zircon/process.h>
76 #include <zircon/syscalls.h>
77 #endif
78
79 #if defined(OS_ANDROID)
80 #include <android/log.h>
81 #endif
82
83 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
84 #include <errno.h>
85 #include <paths.h>
86 #include <stdio.h>
87 #include <stdlib.h>
88 #include <string.h>
89 #include <sys/stat.h>
90 #include "base/process/process_handle.h"
91 #define MAX_PATH PATH_MAX
92 typedef FILE* FileHandle;
93 #endif
94
95 #include <algorithm>
96 #include <cstring>
97 #include <ctime>
98 #include <iomanip>
99 #include <ostream>
100 #include <string>
101 #include <utility>
102
103 #include "base/base_switches.h"
104 #include "base/callback.h"
105 #include "base/command_line.h"
106 #include "base/containers/stack.h"
107 #include "base/debug/activity_tracker.h"
108 #include "base/debug/alias.h"
109 #include "base/debug/debugger.h"
110 #include "base/debug/stack_trace.h"
111 #include "base/debug/task_trace.h"
112 #include "base/no_destructor.h"
113 #include "base/path_service.h"
114 #include "base/posix/eintr_wrapper.h"
115 #include "base/strings/string_piece.h"
116 #include "base/strings/string_split.h"
117 #include "base/strings/string_util.h"
118 #include "base/strings/stringprintf.h"
119 #include "base/strings/sys_string_conversions.h"
120 #include "base/strings/utf_string_conversions.h"
121 #include "base/synchronization/lock.h"
122 #include "base/test/scoped_logging_settings.h"
123 #include "base/threading/platform_thread.h"
124 #include "base/vlog.h"
125 #include "build/chromeos_buildflags.h"
126
127 #if defined(OS_WIN)
128 #include "base/win/win_util.h"
129 #endif
130
131 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
132 #include "base/posix/safe_strerror.h"
133 #endif
134
135 #if BUILDFLAG(IS_CHROMEOS_ASH)
136 #include "base/files/scoped_file.h"
137 #endif
138
139 #if defined(OS_TIZEN)
140 #define LOG_TAG "CHROMIUM"
141 #include <dlog/dlog.h>
142 #endif
143
144 namespace logging {
145
146 namespace {
147
148 VlogInfo* g_vlog_info = nullptr;
149 VlogInfo* g_vlog_info_prev = nullptr;
150
151 const char* const log_severity_names[] = {"INFO", "WARNING", "ERROR", "FATAL"};
152 static_assert(LOGGING_NUM_SEVERITIES == base::size(log_severity_names),
153               "Incorrect number of log_severity_names");
154
155 const char* log_severity_name(int severity) {
156   if (severity >= 0 && severity < LOGGING_NUM_SEVERITIES)
157     return log_severity_names[severity];
158   return "UNKNOWN";
159 }
160
161 int g_min_log_level = 0;
162
163 // Specifies the process' logging sink(s), represented as a combination of
164 // LoggingDestination values joined by bitwise OR.
165 uint32_t g_logging_destination = LOG_DEFAULT;
166
167 #if BUILDFLAG(IS_CHROMEOS_ASH)
168 // Specifies the format of log header for chrome os.
169 LogFormat g_log_format = LogFormat::LOG_FORMAT_SYSLOG;
170 #endif
171
172 // For LOGGING_ERROR and above, always print to stderr.
173 const int kAlwaysPrintErrorLevel = LOGGING_ERROR;
174
175 // Which log file to use? This is initialized by InitLogging or
176 // will be lazily initialized to the default value when it is
177 // first needed.
178 using PathString = base::FilePath::StringType;
179 PathString* g_log_file_name = nullptr;
180
181 // This file is lazily opened and the handle may be nullptr
182 FileHandle g_log_file = nullptr;
183
184 // What should be prepended to each message?
185 bool g_log_process_id = false;
186 bool g_log_thread_id = false;
187 bool g_log_timestamp = true;
188 bool g_log_tickcount = false;
189 const char* g_log_prefix = nullptr;
190
191 // Should we pop up fatal debug messages in a dialog?
192 bool show_error_dialogs = false;
193
194 // An assert handler override specified by the client to be called instead of
195 // the debug message dialog and process termination. Assert handlers are stored
196 // in stack to allow overriding and restoring.
197 base::stack<LogAssertHandlerFunction>& GetLogAssertHandlerStack() {
198   static base::NoDestructor<base::stack<LogAssertHandlerFunction>> instance;
199   return *instance;
200 }
201
202 // A log message handler that gets notified of every log message we process.
203 LogMessageHandlerFunction g_log_message_handler = nullptr;
204
205 #if !defined(OS_TIZEN)
206 // Helper functions to wrap platform differences.
207
208 int32_t CurrentProcessId() {
209 #if defined(OS_WIN)
210   return GetCurrentProcessId();
211 #elif defined(OS_FUCHSIA)
212   zx_info_handle_basic_t basic = {};
213   zx_object_get_info(zx_process_self(), ZX_INFO_HANDLE_BASIC, &basic,
214                      sizeof(basic), nullptr, nullptr);
215   return basic.koid;
216 #elif defined(OS_POSIX)
217   return getpid();
218 #endif
219 }
220
221 uint64_t TickCount() {
222 #if defined(OS_WIN)
223   return GetTickCount();
224 #elif defined(OS_FUCHSIA)
225   return zx_clock_get_monotonic() /
226          static_cast<zx_time_t>(base::Time::kNanosecondsPerMicrosecond);
227 #elif defined(OS_APPLE)
228   return mach_absolute_time();
229 #elif defined(OS_NACL)
230   // NaCl sadly does not have _POSIX_TIMERS enabled in sys/features.h
231   // So we have to use clock() for now.
232   return clock();
233 #elif defined(OS_POSIX)
234   struct timespec ts;
235   clock_gettime(CLOCK_MONOTONIC, &ts);
236
237   uint64_t absolute_micro = static_cast<int64_t>(ts.tv_sec) * 1000000 +
238                             static_cast<int64_t>(ts.tv_nsec) / 1000;
239
240   return absolute_micro;
241 #endif
242 }
243 #endif  // !OS_TIZEN
244
245 void DeleteFilePath(const PathString& log_name) {
246 #if defined(OS_WIN)
247   DeleteFile(log_name.c_str());
248 #elif defined(OS_NACL)
249   // Do nothing; unlink() isn't supported on NaCl.
250 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
251   unlink(log_name.c_str());
252 #else
253 #error Unsupported platform
254 #endif
255 }
256
257 PathString GetDefaultLogFile() {
258 #if defined(OS_WIN)
259   // On Windows we use the same path as the exe.
260   wchar_t module_name[MAX_PATH];
261   GetModuleFileName(nullptr, module_name, MAX_PATH);
262
263   PathString log_name = module_name;
264   PathString::size_type last_backslash = log_name.rfind('\\', log_name.size());
265   if (last_backslash != PathString::npos)
266     log_name.erase(last_backslash + 1);
267   log_name += FILE_PATH_LITERAL("debug.log");
268   return log_name;
269 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
270   // On other platforms we just use the current directory.
271   return PathString("debug.log");
272 #endif
273 }
274
275 // We don't need locks on Windows for atomically appending to files. The OS
276 // provides this functionality.
277 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
278
279 base::Lock& GetLoggingLock() {
280   static base::NoDestructor<base::Lock> lock;
281   return *lock;
282 }
283
284 #endif  // OS_POSIX || OS_FUCHSIA
285
286 // Called by logging functions to ensure that |g_log_file| is initialized
287 // and can be used for writing. Returns false if the file could not be
288 // initialized. |g_log_file| will be nullptr in this case.
289 bool InitializeLogFileHandle() {
290   if (g_log_file)
291     return true;
292
293   if (!g_log_file_name) {
294     // Nobody has called InitLogging to specify a debug log file, so here we
295     // initialize the log file name to a default.
296     g_log_file_name = new PathString(GetDefaultLogFile());
297   }
298
299   if ((g_logging_destination & LOG_TO_FILE) == 0)
300     return true;
301
302 #if defined(OS_WIN)
303   // The FILE_APPEND_DATA access mask ensures that the file is atomically
304   // appended to across accesses from multiple threads.
305   // https://msdn.microsoft.com/en-us/library/windows/desktop/aa364399(v=vs.85).aspx
306   // https://msdn.microsoft.com/en-us/library/windows/desktop/aa363858(v=vs.85).aspx
307   g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
308                           FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
309                           OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
310   if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
311     // We are intentionally not using FilePath or FileUtil here to reduce the
312     // dependencies of the logging implementation. For e.g. FilePath and
313     // FileUtil depend on shell32 and user32.dll. This is not acceptable for
314     // some consumers of base logging like chrome_elf, etc.
315     // Please don't change the code below to use FilePath.
316     // try the current directory
317     wchar_t system_buffer[MAX_PATH];
318     system_buffer[0] = 0;
319     DWORD len = ::GetCurrentDirectory(base::size(system_buffer), system_buffer);
320     if (len == 0 || len > base::size(system_buffer))
321       return false;
322
323     *g_log_file_name = system_buffer;
324     // Append a trailing backslash if needed.
325     if (g_log_file_name->back() != L'\\')
326       *g_log_file_name += FILE_PATH_LITERAL("\\");
327     *g_log_file_name += FILE_PATH_LITERAL("debug.log");
328
329     g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
330                             FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
331                             OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
332     if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
333       g_log_file = nullptr;
334       return false;
335     }
336   }
337 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
338   g_log_file = fopen(g_log_file_name->c_str(), "a");
339   if (g_log_file == nullptr)
340     return false;
341 #else
342 #error Unsupported platform
343 #endif
344
345   return true;
346 }
347
348 void CloseFile(FileHandle log) {
349 #if defined(OS_WIN)
350   CloseHandle(log);
351 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
352   fclose(log);
353 #else
354 #error Unsupported platform
355 #endif
356 }
357
358 void CloseLogFileUnlocked() {
359   if (!g_log_file)
360     return;
361
362   CloseFile(g_log_file);
363   g_log_file = nullptr;
364
365   // If we initialized logging via an externally-provided file descriptor, we
366   // won't have a log path set and shouldn't try to reopen the log file.
367   if (!g_log_file_name)
368     g_logging_destination &= ~LOG_TO_FILE;
369 }
370
371 #if defined(OS_FUCHSIA)
372
373 inline fx_log_severity_t LogSeverityToFuchsiaLogSeverity(LogSeverity severity) {
374   switch (severity) {
375     case LOGGING_INFO:
376       return FX_LOG_INFO;
377     case LOGGING_WARNING:
378       return FX_LOG_WARNING;
379     case LOGGING_ERROR:
380       return FX_LOG_ERROR;
381     case LOGGING_FATAL:
382       // Don't use FX_LOG_FATAL, otherwise fx_logger_log() will abort().
383       return FX_LOG_ERROR;
384   }
385   if (severity > -3) {
386     // LOGGING_VERBOSE levels 1 and 2.
387     return FX_LOG_DEBUG;
388   }
389   // LOGGING_VERBOSE levels 3 and higher, or incorrect levels.
390   return FX_LOG_TRACE;
391 }
392
393 #endif  // defined (OS_FUCHSIA)
394
395 }  // namespace
396
397 #if defined(DCHECK_IS_CONFIGURABLE)
398 // In DCHECK-enabled Chrome builds, allow the meaning of LOGGING_DCHECK to be
399 // determined at run-time. We default it to INFO, to avoid it triggering
400 // crashes before the run-time has explicitly chosen the behaviour.
401 BASE_EXPORT logging::LogSeverity LOGGING_DCHECK = LOGGING_INFO;
402 #endif  // defined(DCHECK_IS_CONFIGURABLE)
403
404 // This is never instantiated, it's just used for EAT_STREAM_PARAMETERS to have
405 // an object of the correct type on the LHS of the unused part of the ternary
406 // operator.
407 std::ostream* g_swallow_stream;
408
409 bool BaseInitLoggingImpl(const LoggingSettings& settings) {
410 #if defined(OS_NACL)
411   // Can log only to the system debug log and stderr.
412   CHECK_EQ(settings.logging_dest & ~(LOG_TO_SYSTEM_DEBUG_LOG | LOG_TO_STDERR),
413            0u);
414 #endif
415
416 #if BUILDFLAG(IS_CHROMEOS_ASH)
417   g_log_format = settings.log_format;
418 #endif
419
420   if (base::CommandLine::InitializedForCurrentProcess()) {
421     base::CommandLine* command_line = base::CommandLine::ForCurrentProcess();
422     // Don't bother initializing |g_vlog_info| unless we use one of the
423     // vlog switches.
424     if (command_line->HasSwitch(switches::kV) ||
425         command_line->HasSwitch(switches::kVModule)) {
426       // NOTE: If |g_vlog_info| has already been initialized, it might be in use
427       // by another thread. Don't delete the old VLogInfo, just create a second
428       // one. We keep track of both to avoid memory leak warnings.
429       CHECK(!g_vlog_info_prev);
430       g_vlog_info_prev = g_vlog_info;
431
432       g_vlog_info =
433           new VlogInfo(command_line->GetSwitchValueASCII(switches::kV),
434                        command_line->GetSwitchValueASCII(switches::kVModule),
435                        &g_min_log_level);
436     }
437   }
438
439   g_logging_destination = settings.logging_dest;
440
441 #if defined(OS_FUCHSIA)
442   if (g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) {
443     std::string log_tag = base::CommandLine::ForCurrentProcess()
444                               ->GetProgram()
445                               .BaseName()
446                               .AsUTF8Unsafe();
447     const char* log_tag_data = log_tag.data();
448
449     fx_logger_config_t config = {
450         .min_severity = g_vlog_info ? FX_LOG_TRACE : FX_LOG_INFO,
451         .console_fd = -1,
452         .tags = &log_tag_data,
453         .num_tags = 1,
454     };
455     fx_log_reconfigure(&config);
456   }
457 #endif
458
459   // ignore file options unless logging to file is set.
460   if ((g_logging_destination & LOG_TO_FILE) == 0)
461     return true;
462
463 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
464   base::AutoLock guard(GetLoggingLock());
465 #endif
466
467   // Calling InitLogging twice or after some log call has already opened the
468   // default log file will re-initialize to the new options.
469   CloseLogFileUnlocked();
470
471 #if BUILDFLAG(IS_CHROMEOS_ASH)
472   if (settings.log_file) {
473     DCHECK(!settings.log_file_path);
474     g_log_file = settings.log_file;
475     return true;
476   }
477 #endif
478
479   DCHECK(settings.log_file_path) << "LOG_TO_FILE set but no log_file_path!";
480
481   if (!g_log_file_name)
482     g_log_file_name = new PathString();
483   *g_log_file_name = settings.log_file_path;
484   if (settings.delete_old == DELETE_OLD_LOG_FILE)
485     DeleteFilePath(*g_log_file_name);
486
487   return InitializeLogFileHandle();
488 }
489
490 void SetMinLogLevel(int level) {
491   g_min_log_level = std::min(LOGGING_FATAL, level);
492 }
493
494 int GetMinLogLevel() {
495   return g_min_log_level;
496 }
497
498 bool ShouldCreateLogMessage(int severity) {
499   if (severity < g_min_log_level)
500     return false;
501
502   // Return true here unless we know ~LogMessage won't do anything.
503   return g_logging_destination != LOG_NONE || g_log_message_handler ||
504          severity >= kAlwaysPrintErrorLevel;
505 }
506
507 // Returns true when LOG_TO_STDERR flag is set, or |severity| is high.
508 // If |severity| is high then true will be returned when no log destinations are
509 // set, or only LOG_TO_FILE is set, since that is useful for local development
510 // and debugging.
511 bool ShouldLogToStderr(int severity) {
512   if (g_logging_destination & LOG_TO_STDERR)
513     return true;
514   if (severity >= kAlwaysPrintErrorLevel)
515     return (g_logging_destination & ~LOG_TO_FILE) == LOG_NONE;
516   return false;
517 }
518
519 int GetVlogVerbosity() {
520   return std::max(-1, LOG_INFO - GetMinLogLevel());
521 }
522
523 int GetVlogLevelHelper(const char* file, size_t N) {
524   DCHECK_GT(N, 0U);
525   // Note: |g_vlog_info| may change on a different thread during startup
526   // (but will always be valid or nullptr).
527   VlogInfo* vlog_info = g_vlog_info;
528   return vlog_info ?
529       vlog_info->GetVlogLevel(base::StringPiece(file, N - 1)) :
530       GetVlogVerbosity();
531 }
532
533 void SetLogItems(bool enable_process_id, bool enable_thread_id,
534                  bool enable_timestamp, bool enable_tickcount) {
535   g_log_process_id = enable_process_id;
536   g_log_thread_id = enable_thread_id;
537   g_log_timestamp = enable_timestamp;
538   g_log_tickcount = enable_tickcount;
539 }
540
541 void SetLogPrefix(const char* prefix) {
542   DCHECK(!prefix ||
543          base::ContainsOnlyChars(prefix, "abcdefghijklmnopqrstuvwxyz"));
544   g_log_prefix = prefix;
545 }
546
547 void SetShowErrorDialogs(bool enable_dialogs) {
548   show_error_dialogs = enable_dialogs;
549 }
550
551 ScopedLogAssertHandler::ScopedLogAssertHandler(
552     LogAssertHandlerFunction handler) {
553   GetLogAssertHandlerStack().push(std::move(handler));
554 }
555
556 ScopedLogAssertHandler::~ScopedLogAssertHandler() {
557   GetLogAssertHandlerStack().pop();
558 }
559
560 void SetLogMessageHandler(LogMessageHandlerFunction handler) {
561   g_log_message_handler = handler;
562 }
563
564 LogMessageHandlerFunction GetLogMessageHandler() {
565   return g_log_message_handler;
566 }
567
568 #if !defined(NDEBUG)
569 // Displays a message box to the user with the error message in it.
570 // Used for fatal messages, where we close the app simultaneously.
571 // This is for developers only; we don't use this in circumstances
572 // (like release builds) where users could see it, since users don't
573 // understand these messages anyway.
574 void DisplayDebugMessageInDialog(const std::string& str) {
575   if (str.empty())
576     return;
577
578   if (!show_error_dialogs)
579     return;
580
581 #if defined(OS_WIN)
582   // We intentionally don't implement a dialog on other platforms.
583   // You can just look at stderr.
584   if (base::win::IsUser32AndGdi32Available()) {
585     MessageBoxW(nullptr, base::as_wcstr(base::UTF8ToUTF16(str)), L"Fatal error",
586                 MB_OK | MB_ICONHAND | MB_TOPMOST);
587   } else {
588     OutputDebugStringW(base::as_wcstr(base::UTF8ToUTF16(str)));
589   }
590 #endif  // defined(OS_WIN)
591 }
592 #endif  // !defined(NDEBUG)
593
594 LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
595     : severity_(severity), file_(file), line_(line) {
596   Init(file, line);
597 }
598
599 LogMessage::LogMessage(const char* file, int line, const char* condition)
600     : severity_(LOGGING_FATAL), file_(file), line_(line) {
601   Init(file, line);
602   stream_ << "Check failed: " << condition << ". ";
603 }
604
605 LogMessage::~LogMessage() {
606   size_t stack_start = stream_.tellp();
607 #if !defined(OFFICIAL_BUILD) && !defined(OS_NACL) && !defined(__UCLIBC__) && \
608     !defined(OS_AIX)
609   if (severity_ == LOGGING_FATAL && !base::debug::BeingDebugged()) {
610     // Include a stack trace on a fatal, unless a debugger is attached.
611     base::debug::StackTrace stack_trace;
612     stream_ << std::endl;  // Newline to separate from log message.
613     stack_trace.OutputToStream(&stream_);
614     base::debug::TaskTrace task_trace;
615     if (!task_trace.empty())
616       task_trace.OutputToStream(&stream_);
617
618     // Include the IPC context, if any.
619     // TODO(chrisha): Integrate with symbolization once those tools exist!
620     const auto* task = base::TaskAnnotator::CurrentTaskForThread();
621     if (task && task->ipc_hash) {
622       stream_ << "IPC message handler context: "
623               << base::StringPrintf("0x%08X", task->ipc_hash) << std::endl;
624     }
625   }
626 #endif
627   stream_ << std::endl;
628   std::string str_newline(stream_.str());
629   TRACE_LOG_MESSAGE(
630       file_, base::StringPiece(str_newline).substr(message_start_), line_);
631
632   // Give any log message handler first dibs on the message.
633   if (g_log_message_handler &&
634       g_log_message_handler(severity_, file_, line_, message_start_,
635                             str_newline)) {
636     // The handler took care of it, no further processing.
637     return;
638   }
639
640   if ((g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
641 #if defined(OS_WIN)
642     OutputDebugStringA(str_newline.c_str());
643 #elif defined(OS_APPLE)
644     // In LOG_TO_SYSTEM_DEBUG_LOG mode, log messages are always written to
645     // stderr. If stderr is /dev/null, also log via ASL (Apple System Log) or
646     // its successor OS_LOG. If there's something weird about stderr, assume
647     // that log messages are going nowhere and log via ASL/OS_LOG too.
648     // Messages logged via ASL/OS_LOG show up in Console.app.
649     //
650     // Programs started by launchd, as UI applications normally are, have had
651     // stderr connected to /dev/null since OS X 10.8. Prior to that, stderr was
652     // a pipe to launchd, which logged what it received (see log_redirect_fd in
653     // 10.7.5 launchd-392.39/launchd/src/launchd_core_logic.c).
654     //
655     // Another alternative would be to determine whether stderr is a pipe to
656     // launchd and avoid logging via ASL only in that case. See 10.7.5
657     // CF-635.21/CFUtilities.c also_do_stderr(). This would result in logging to
658     // both stderr and ASL/OS_LOG even in tests, where it's undesirable to log
659     // to the system log at all.
660     //
661     // Note that the ASL client by default discards messages whose levels are
662     // below ASL_LEVEL_NOTICE. It's possible to change that with
663     // asl_set_filter(), but this is pointless because syslogd normally applies
664     // the same filter.
665     const bool log_to_system = []() {
666       struct stat stderr_stat;
667       if (fstat(fileno(stderr), &stderr_stat) == -1) {
668         return true;
669       }
670       if (!S_ISCHR(stderr_stat.st_mode)) {
671         return false;
672       }
673
674       struct stat dev_null_stat;
675       if (stat(_PATH_DEVNULL, &dev_null_stat) == -1) {
676         return true;
677       }
678
679       return !S_ISCHR(dev_null_stat.st_mode) ||
680              stderr_stat.st_rdev == dev_null_stat.st_rdev;
681     }();
682
683     if (log_to_system) {
684       // Log roughly the same way that CFLog() and NSLog() would. See 10.10.5
685       // CF-1153.18/CFUtilities.c __CFLogCString().
686       CFBundleRef main_bundle = CFBundleGetMainBundle();
687       CFStringRef main_bundle_id_cf =
688           main_bundle ? CFBundleGetIdentifier(main_bundle) : nullptr;
689       std::string main_bundle_id =
690           main_bundle_id_cf ? base::SysCFStringRefToUTF8(main_bundle_id_cf)
691                             : std::string("");
692 #if defined(USE_ASL)
693       // The facility is set to the main bundle ID if available. Otherwise,
694       // "com.apple.console" is used.
695       const class ASLClient {
696        public:
697         explicit ASLClient(const std::string& facility)
698             : client_(asl_open(nullptr, facility.c_str(), ASL_OPT_NO_DELAY)) {}
699         ASLClient(const ASLClient&) = delete;
700         ASLClient& operator=(const ASLClient&) = delete;
701         ~ASLClient() { asl_close(client_); }
702
703         aslclient get() const { return client_; }
704
705        private:
706         aslclient client_;
707       } asl_client(main_bundle_id.empty() ? main_bundle_id
708                                           : "com.apple.console");
709
710       const class ASLMessage {
711        public:
712         ASLMessage() : message_(asl_new(ASL_TYPE_MSG)) {}
713         ASLMessage(const ASLMessage&) = delete;
714         ASLMessage& operator=(const ASLMessage&) = delete;
715         ~ASLMessage() { asl_free(message_); }
716
717         aslmsg get() const { return message_; }
718
719        private:
720         aslmsg message_;
721       } asl_message;
722
723       // By default, messages are only readable by the admin group. Explicitly
724       // make them readable by the user generating the messages.
725       char euid_string[12];
726       snprintf(euid_string, base::size(euid_string), "%d", geteuid());
727       asl_set(asl_message.get(), ASL_KEY_READ_UID, euid_string);
728
729       // Map Chrome log severities to ASL log levels.
730       const char* const asl_level_string = [](LogSeverity severity) {
731         // ASL_LEVEL_* are ints, but ASL needs equivalent strings. This
732         // non-obvious two-step macro trick achieves what's needed.
733         // https://gcc.gnu.org/onlinedocs/cpp/Stringification.html
734 #define ASL_LEVEL_STR(level) ASL_LEVEL_STR_X(level)
735 #define ASL_LEVEL_STR_X(level) #level
736         switch (severity) {
737           case LOGGING_INFO:
738             return ASL_LEVEL_STR(ASL_LEVEL_INFO);
739           case LOGGING_WARNING:
740             return ASL_LEVEL_STR(ASL_LEVEL_WARNING);
741           case LOGGING_ERROR:
742             return ASL_LEVEL_STR(ASL_LEVEL_ERR);
743           case LOGGING_FATAL:
744             return ASL_LEVEL_STR(ASL_LEVEL_CRIT);
745           default:
746             return severity < 0 ? ASL_LEVEL_STR(ASL_LEVEL_DEBUG)
747                                 : ASL_LEVEL_STR(ASL_LEVEL_NOTICE);
748         }
749 #undef ASL_LEVEL_STR
750 #undef ASL_LEVEL_STR_X
751       }(severity_);
752       asl_set(asl_message.get(), ASL_KEY_LEVEL, asl_level_string);
753
754       asl_set(asl_message.get(), ASL_KEY_MSG, str_newline.c_str());
755
756       asl_send(asl_client.get(), asl_message.get());
757 #else   // !defined(USE_ASL)
758       const class OSLog {
759        public:
760         explicit OSLog(const char* subsystem)
761             : os_log_(subsystem ? os_log_create(subsystem, "chromium_logging")
762                                 : OS_LOG_DEFAULT) {}
763         OSLog(const OSLog&) = delete;
764         OSLog& operator=(const OSLog&) = delete;
765         ~OSLog() {
766           if (os_log_ != OS_LOG_DEFAULT) {
767             os_release(os_log_);
768           }
769         }
770         os_log_t get() const { return os_log_; }
771
772        private:
773         os_log_t os_log_;
774       } log(main_bundle_id.empty() ? nullptr : main_bundle_id.c_str());
775       const os_log_type_t os_log_type = [](LogSeverity severity) {
776         switch (severity) {
777           case LOGGING_INFO:
778             return OS_LOG_TYPE_INFO;
779           case LOGGING_WARNING:
780             return OS_LOG_TYPE_DEFAULT;
781           case LOGGING_ERROR:
782             return OS_LOG_TYPE_ERROR;
783           case LOGGING_FATAL:
784             return OS_LOG_TYPE_FAULT;
785           default:
786             return severity < 0 ? OS_LOG_TYPE_DEBUG : OS_LOG_TYPE_DEFAULT;
787         }
788       }(severity_);
789       os_log_with_type(log.get(), os_log_type, "%{public}s",
790                        str_newline.c_str());
791 #endif  // defined(USE_ASL)
792     }
793 #elif defined(OS_ANDROID)
794     android_LogPriority priority =
795         (severity_ < 0) ? ANDROID_LOG_VERBOSE : ANDROID_LOG_UNKNOWN;
796     switch (severity_) {
797       case LOGGING_INFO:
798         priority = ANDROID_LOG_INFO;
799         break;
800       case LOGGING_WARNING:
801         priority = ANDROID_LOG_WARN;
802         break;
803       case LOGGING_ERROR:
804         priority = ANDROID_LOG_ERROR;
805         break;
806       case LOGGING_FATAL:
807         priority = ANDROID_LOG_FATAL;
808         break;
809     }
810     const char kAndroidLogTag[] = "chromium";
811 #if DCHECK_IS_ON()
812     // Split the output by new lines to prevent the Android system from
813     // truncating the log.
814     std::vector<std::string> lines = base::SplitString(
815         str_newline, "\n", base::KEEP_WHITESPACE, base::SPLIT_WANT_ALL);
816     // str_newline has an extra newline appended to it (at the top of this
817     // function), so skip the last split element to avoid needlessly
818     // logging an empty string.
819     lines.pop_back();
820     for (const auto& line : lines)
821       __android_log_write(priority, kAndroidLogTag, line.c_str());
822 #else
823     // The Android system may truncate the string if it's too long.
824     __android_log_write(priority, kAndroidLogTag, str_newline.c_str());
825 #endif
826 #elif defined(OS_TIZEN)
827     log_priority priority = DLOG_UNKNOWN;
828     switch (severity_) {
829       case LOG_INFO:
830         priority = DLOG_INFO;
831         break;
832       case LOG_WARNING:
833         priority = DLOG_WARN;
834         break;
835       case LOG_ERROR:
836         priority = DLOG_ERROR;
837         break;
838       case LOG_FATAL:
839         priority = DLOG_FATAL;
840         break;
841     }
842     dlog_print(priority, LOG_TAG, "%s", str_newline.c_str());
843 #elif defined(OS_FUCHSIA)
844     fx_logger_t* logger = fx_log_get_logger();
845     if (logger) {
846       // Temporarily remove the trailing newline from |str_newline|'s C-string
847       // representation, since fx_logger will add a newline of its own.
848       str_newline.pop_back();
849       fx_logger_log_with_source(
850           logger, LogSeverityToFuchsiaLogSeverity(severity_), nullptr, file_,
851           line_, str_newline.c_str() + message_start_);
852       str_newline.push_back('\n');
853     }
854 #endif  // OS_FUCHSIA
855   }
856
857   if (ShouldLogToStderr(severity_)) {
858 #if defined(OS_TIZEN)
859     log_priority priority = DLOG_UNKNOWN;
860     switch (severity_) {
861       case LOG_INFO:
862         priority = DLOG_INFO;
863         break;
864       case LOG_WARNING:
865         priority = DLOG_WARN;
866         break;
867       case LOG_ERROR:
868         priority = DLOG_ERROR;
869         break;
870       case LOG_FATAL:
871         priority = DLOG_FATAL;
872         break;
873     }
874     dlog_print(priority, LOG_TAG, "%s", str_newline.c_str());
875 #else
876     ignore_result(fwrite(str_newline.data(), str_newline.size(), 1, stderr));
877     fflush(stderr);
878 #endif
879   }
880
881   if ((g_logging_destination & LOG_TO_FILE) != 0) {
882     // We can have multiple threads and/or processes, so try to prevent them
883     // from clobbering each other's writes.
884     // If the client app did not call InitLogging, and the lock has not
885     // been created do it now. We do this on demand, but if two threads try
886     // to do this at the same time, there will be a race condition to create
887     // the lock. This is why InitLogging should be called from the main
888     // thread at the beginning of execution.
889 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
890     base::AutoLock guard(GetLoggingLock());
891 #endif
892     if (InitializeLogFileHandle()) {
893 #if defined(OS_WIN)
894       DWORD num_written;
895       WriteFile(g_log_file,
896                 static_cast<const void*>(str_newline.c_str()),
897                 static_cast<DWORD>(str_newline.length()),
898                 &num_written,
899                 nullptr);
900 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
901       ignore_result(fwrite(
902           str_newline.data(), str_newline.size(), 1, g_log_file));
903       fflush(g_log_file);
904 #else
905 #error Unsupported platform
906 #endif
907     }
908   }
909
910   if (severity_ == LOGGING_FATAL) {
911     // Write the log message to the global activity tracker, if running.
912     base::debug::GlobalActivityTracker* tracker =
913         base::debug::GlobalActivityTracker::Get();
914     if (tracker)
915       tracker->RecordLogMessage(str_newline);
916
917     char str_stack[1024];
918     base::strlcpy(str_stack, str_newline.data(), base::size(str_stack));
919     base::debug::Alias(&str_stack);
920
921     if (!GetLogAssertHandlerStack().empty()) {
922       LogAssertHandlerFunction log_assert_handler =
923           GetLogAssertHandlerStack().top();
924
925       if (log_assert_handler) {
926         log_assert_handler.Run(
927             file_, line_,
928             base::StringPiece(str_newline.c_str() + message_start_,
929                               stack_start - message_start_),
930             base::StringPiece(str_newline.c_str() + stack_start));
931       }
932     } else {
933       // Don't use the string with the newline, get a fresh version to send to
934       // the debug message process. We also don't display assertions to the
935       // user in release mode. The enduser can't do anything with this
936       // information, and displaying message boxes when the application is
937       // hosed can cause additional problems.
938 #ifndef NDEBUG
939       if (!base::debug::BeingDebugged()) {
940         // Displaying a dialog is unnecessary when debugging and can complicate
941         // debugging.
942         DisplayDebugMessageInDialog(stream_.str());
943       }
944 #endif
945       // Crash the process to generate a dump.
946 #if defined(OFFICIAL_BUILD) && defined(NDEBUG)
947       IMMEDIATE_CRASH();
948 #else
949       base::debug::BreakDebugger();
950 #endif
951     }
952   }
953 }
954
955 // writes the common header info to the stream
956 void LogMessage::Init(const char* file, int line) {
957   base::StringPiece filename(file);
958   size_t last_slash_pos = filename.find_last_of("\\/");
959   if (last_slash_pos != base::StringPiece::npos)
960     filename.remove_prefix(last_slash_pos + 1);
961
962 #if BUILDFLAG(IS_CHROMEOS_ASH)
963   if (g_log_format == LogFormat::LOG_FORMAT_SYSLOG) {
964     InitWithSyslogPrefix(
965         filename, line, TickCount(), log_severity_name(severity_), g_log_prefix,
966         g_log_process_id, g_log_thread_id, g_log_timestamp, g_log_tickcount);
967   } else
968 #endif  // BUILDFLAG(IS_CHROMEOS_ASH)
969   {
970     // TODO(darin): It might be nice if the columns were fixed width.
971     stream_ << '[';
972 #if !defined(OS_TIZEN)
973     if (g_log_prefix)
974       stream_ << g_log_prefix << ':';
975     if (g_log_process_id)
976       stream_ << base::GetUniqueIdForProcess() << ':';
977     if (g_log_thread_id)
978       stream_ << base::PlatformThread::CurrentId() << ':';
979     if (g_log_timestamp) {
980 #if defined(OS_WIN)
981       SYSTEMTIME local_time;
982       GetLocalTime(&local_time);
983       stream_ << std::setfill('0')
984               << std::setw(2) << local_time.wMonth
985               << std::setw(2) << local_time.wDay
986               << '/'
987               << std::setw(2) << local_time.wHour
988               << std::setw(2) << local_time.wMinute
989               << std::setw(2) << local_time.wSecond
990               << '.'
991               << std::setw(3) << local_time.wMilliseconds
992               << ':';
993 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
994       timeval tv;
995       gettimeofday(&tv, nullptr);
996       time_t t = tv.tv_sec;
997       struct tm local_time;
998       localtime_r(&t, &local_time);
999       struct tm* tm_time = &local_time;
1000       stream_ << std::setfill('0')
1001               << std::setw(2) << 1 + tm_time->tm_mon
1002               << std::setw(2) << tm_time->tm_mday
1003               << '/'
1004               << std::setw(2) << tm_time->tm_hour
1005               << std::setw(2) << tm_time->tm_min
1006               << std::setw(2) << tm_time->tm_sec
1007               << '.'
1008               << std::setw(6) << tv.tv_usec
1009               << ':';
1010 #else
1011 #error Unsupported platform
1012 #endif
1013     }
1014     if (g_log_tickcount)
1015       stream_ << TickCount() << ':';
1016 #endif  // defined(OS_TIZEN)
1017     if (severity_ >= 0) {
1018       stream_ << log_severity_name(severity_);
1019     } else {
1020       stream_ << "VERBOSE" << -severity_;
1021     }
1022     stream_ << ":" << filename << "(" << line << ")] ";
1023   }
1024   message_start_ = stream_.str().length();
1025 }
1026
1027 #if defined(OS_WIN)
1028 // This has already been defined in the header, but defining it again as DWORD
1029 // ensures that the type used in the header is equivalent to DWORD. If not,
1030 // the redefinition is a compile error.
1031 typedef DWORD SystemErrorCode;
1032 #endif
1033
1034 SystemErrorCode GetLastSystemErrorCode() {
1035 #if defined(OS_WIN)
1036   return ::GetLastError();
1037 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
1038   return errno;
1039 #endif
1040 }
1041
1042 BASE_EXPORT std::string SystemErrorCodeToString(SystemErrorCode error_code) {
1043 #if defined(OS_WIN)
1044   const int kErrorMessageBufferSize = 256;
1045   char msgbuf[kErrorMessageBufferSize];
1046   DWORD flags = FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_IGNORE_INSERTS;
1047   DWORD len = FormatMessageA(flags, nullptr, error_code, 0, msgbuf,
1048                              base::size(msgbuf), nullptr);
1049   if (len) {
1050     // Messages returned by system end with line breaks.
1051     return base::CollapseWhitespaceASCII(msgbuf, true) +
1052            base::StringPrintf(" (0x%lX)", error_code);
1053   }
1054   return base::StringPrintf("Error (0x%lX) while retrieving error. (0x%lX)",
1055                             GetLastError(), error_code);
1056 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
1057   return base::safe_strerror(error_code) +
1058          base::StringPrintf(" (%d)", error_code);
1059 #endif  // defined(OS_WIN)
1060 }
1061
1062
1063 #if defined(OS_WIN)
1064 Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
1065                                            int line,
1066                                            LogSeverity severity,
1067                                            SystemErrorCode err)
1068     : LogMessage(file, line, severity), err_(err) {}
1069
1070 Win32ErrorLogMessage::~Win32ErrorLogMessage() {
1071   stream() << ": " << SystemErrorCodeToString(err_);
1072   // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
1073   // field) and use Alias in hopes that it makes it into crash dumps.
1074   DWORD last_error = err_;
1075   base::debug::Alias(&last_error);
1076 }
1077 #elif defined(OS_POSIX) || defined(OS_FUCHSIA)
1078 ErrnoLogMessage::ErrnoLogMessage(const char* file,
1079                                  int line,
1080                                  LogSeverity severity,
1081                                  SystemErrorCode err)
1082     : LogMessage(file, line, severity), err_(err) {}
1083
1084 ErrnoLogMessage::~ErrnoLogMessage() {
1085   stream() << ": " << SystemErrorCodeToString(err_);
1086   // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
1087   // field) and use Alias in hopes that it makes it into crash dumps.
1088   int last_error = err_;
1089   base::debug::Alias(&last_error);
1090 }
1091 #endif  // defined(OS_WIN)
1092
1093 void CloseLogFile() {
1094 #if defined(OS_POSIX) || defined(OS_FUCHSIA)
1095   base::AutoLock guard(GetLoggingLock());
1096 #endif
1097   CloseLogFileUnlocked();
1098 }
1099
1100 #if BUILDFLAG(IS_CHROMEOS_ASH)
1101 FILE* DuplicateLogFILE() {
1102   if ((g_logging_destination & LOG_TO_FILE) == 0 || !InitializeLogFileHandle())
1103     return nullptr;
1104
1105   int log_fd = fileno(g_log_file);
1106   if (log_fd == -1)
1107     return nullptr;
1108   base::ScopedFD dup_fd(dup(log_fd));
1109   if (dup_fd == -1)
1110     return nullptr;
1111   FILE* duplicate = fdopen(dup_fd.get(), "a");
1112   if (!duplicate)
1113     return nullptr;
1114   ignore_result(dup_fd.release());
1115   return duplicate;
1116 }
1117 #endif
1118
1119 // Used for testing. Declared in test/scoped_logging_settings.h.
1120 ScopedLoggingSettings::ScopedLoggingSettings()
1121     : min_log_level_(g_min_log_level),
1122       logging_destination_(g_logging_destination),
1123 #if BUILDFLAG(IS_CHROMEOS_ASH)
1124       log_format_(g_log_format),
1125 #endif  // BUILDFLAG(IS_CHROMEOS_ASH)
1126       enable_process_id_(g_log_process_id),
1127       enable_thread_id_(g_log_thread_id),
1128       enable_timestamp_(g_log_timestamp),
1129       enable_tickcount_(g_log_tickcount),
1130       log_prefix_(g_log_prefix),
1131       message_handler_(g_log_message_handler) {
1132   if (g_log_file_name)
1133     log_file_name_ = std::make_unique<PathString>(*g_log_file_name);
1134   // Duplicating |g_log_file| is complex & unnecessary for this test helpers'
1135   // use-cases, and so long as |g_log_file_name| is set, it will be re-opened
1136   // automatically anyway, when required, so just close the existing one.
1137   if (g_log_file) {
1138     CHECK(g_log_file_name) << "Un-named |log_file| is not supported.";
1139     CloseLogFileUnlocked();
1140   }
1141 }
1142
1143 ScopedLoggingSettings::~ScopedLoggingSettings() {
1144   // Re-initialize logging via the normal path. This will clean up old file
1145   // name and handle state, including re-initializing the VLOG internal state.
1146   CHECK(InitLogging({
1147     .logging_dest = logging_destination_,
1148     .log_file_path = log_file_name_ ? log_file_name_->data() : nullptr,
1149 #if BUILDFLAG(IS_CHROMEOS_ASH)
1150     .log_format = log_format_
1151 #endif
1152   })) << "~ScopedLoggingSettings() failed to restore settings.";
1153
1154   // Restore plain data settings.
1155   SetMinLogLevel(min_log_level_);
1156   SetLogItems(enable_process_id_, enable_thread_id_, enable_timestamp_,
1157               enable_tickcount_);
1158   SetLogPrefix(log_prefix_);
1159   SetLogMessageHandler(message_handler_);
1160 }
1161
1162 #if BUILDFLAG(IS_CHROMEOS_ASH)
1163 void ScopedLoggingSettings::SetLogFormat(LogFormat log_format) const {
1164   g_log_format = log_format;
1165 }
1166 #endif  // BUILDFLAG(IS_CHROMEOS_ASH)
1167
1168 void RawLog(int level, const char* message) {
1169   if (level >= g_min_log_level && message) {
1170     size_t bytes_written = 0;
1171     const size_t message_len = strlen(message);
1172     int rv;
1173     while (bytes_written < message_len) {
1174       rv = HANDLE_EINTR(
1175           write(STDERR_FILENO, message + bytes_written,
1176                 message_len - bytes_written));
1177       if (rv < 0) {
1178         // Give up, nothing we can do now.
1179         break;
1180       }
1181       bytes_written += rv;
1182     }
1183
1184     if (message_len > 0 && message[message_len - 1] != '\n') {
1185       do {
1186         rv = HANDLE_EINTR(write(STDERR_FILENO, "\n", 1));
1187         if (rv < 0) {
1188           // Give up, nothing we can do now.
1189           break;
1190         }
1191       } while (rv != 1);
1192     }
1193   }
1194
1195   if (level == LOGGING_FATAL)
1196     base::debug::BreakDebugger();
1197 }
1198
1199 // This was defined at the beginning of this file.
1200 #undef write
1201
1202 #if defined(OS_WIN)
1203 bool IsLoggingToFileEnabled() {
1204   return g_logging_destination & LOG_TO_FILE;
1205 }
1206
1207 std::wstring GetLogFileFullPath() {
1208   if (g_log_file_name)
1209     return *g_log_file_name;
1210   return std::wstring();
1211 }
1212 #endif
1213
1214 }  // namespace logging
1215
1216 std::ostream& std::operator<<(std::ostream& out, const wchar_t* wstr) {
1217   return out << (wstr ? base::WStringPiece(wstr) : base::WStringPiece());
1218 }
1219
1220 std::ostream& std::operator<<(std::ostream& out, const std::wstring& wstr) {
1221   return out << base::WStringPiece(wstr);
1222 }
1223
1224 std::ostream& std::operator<<(std::ostream& out, const char16_t* str16) {
1225   return out << (str16 ? base::StringPiece16(str16) : base::StringPiece16());
1226 }
1227
1228 std::ostream& std::operator<<(std::ostream& out, const std::u16string& str16) {
1229   return out << base::StringPiece16(str16);
1230 }