1 // Copyright 2012 The Chromium Authors
2 // Use of this source code is governed by a BSD-style license that can be
3 // found in the LICENSE file.
4
5 #ifdef UNSAFE_BUFFERS_BUILD
6 // TODO(crbug.com/40284755): Remove this and spanify to fix the errors.
7 #pragma allow_unsafe_buffers
8 #endif
9
10 #include "base/logging.h"
11
12 #ifdef BASE_CHECK_H_
13 #error "logging.h should not include check.h"
14 #endif
15
16 #include <limits.h>
17 #include <stdint.h>
18
19 #include <algorithm>
20 #include <atomic>
21 #include <cstring>
22 #include <ctime>
23 #include <iomanip>
24 #include <memory>
25 #include <ostream>
26 #include <string>
27 #include <string_view>
28 #include <tuple>
29 #include <utility>
30 #include <vector>
31
32 #include "base/base_export.h"
33 #include "base/base_switches.h"
34 #include "base/command_line.h"
35 #include "base/containers/stack.h"
36 #include "base/debug/alias.h"
37 #include "base/debug/crash_logging.h"
38 #include "base/debug/debugger.h"
39 #include "base/debug/stack_trace.h"
40 #include "base/debug/task_trace.h"
41 #include "base/functional/callback.h"
42 #include "base/immediate_crash.h"
43 #include "base/no_destructor.h"
44 #include "base/not_fatal_until.h"
45 #include "base/path_service.h"
46 #include "base/pending_task.h"
47 #include "base/posix/eintr_wrapper.h"
48 #include "base/process/process_handle.h"
49 #include "base/scoped_clear_last_error.h"
50 #include "base/strings/string_split.h"
51 #include "base/strings/string_util.h"
52 #include "base/strings/stringprintf.h"
53 #include "base/strings/sys_string_conversions.h"
54 #include "base/strings/utf_string_conversions.h"
55 #include "base/synchronization/lock.h"
56 #include "base/task/common/task_annotator.h"
57 #include "base/test/scoped_logging_settings.h"
58 #include "base/threading/platform_thread.h"
59 #include "base/trace_event/base_tracing.h"
60 #include "base/vlog.h"
61 #include "build/build_config.h"
62 #include "build/chromeos_buildflags.h"
63 #include "third_party/abseil-cpp/absl/base/internal/raw_logging.h"
64 #include "third_party/abseil-cpp/absl/cleanup/cleanup.h"
65
66 #if !BUILDFLAG(IS_NACL)
67 #include "base/auto_reset.h"
68 #include "base/debug/crash_logging.h"
69 #endif // !BUILDFLAG(IS_NACL)
70
71 #if defined(LEAK_SANITIZER) && !BUILDFLAG(IS_NACL)
72 #include "base/debug/leak_annotations.h"
73 #endif // defined(LEAK_SANITIZER) && !BUILDFLAG(IS_NACL)
74
75 #if BUILDFLAG(IS_WIN)
76 #include <windows.h>
77
78 #include <io.h>
79
80 #include "base/win/win_util.h"
81
82 typedef HANDLE FileHandle;
83 // Windows warns on using write(). It prefers _write().
84 #define write(fd, buf, count) _write(fd, buf, static_cast<unsigned int>(count))
85 // Windows doesn't define STDERR_FILENO. Define it here.
86 #define STDERR_FILENO 2
87 #endif // BUILDFLAG(IS_WIN)
88
89 #if BUILDFLAG(IS_APPLE)
90 #include <CoreFoundation/CoreFoundation.h>
91 #include <mach-o/dyld.h>
92 #include <mach/mach.h>
93 #include <mach/mach_time.h>
94 #include <os/log.h>
95 #endif // BUILDFLAG(IS_APPLE)
96
97 #if BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
98 #include <errno.h>
99 #include <paths.h>
100 #include <stdio.h>
101 #include <stdlib.h>
102 #include <string.h>
103 #include <sys/stat.h>
104 #include <time.h>
105
106 #include "base/posix/safe_strerror.h"
107
108 #if BUILDFLAG(IS_NACL)
109 #include <sys/time.h> // timespec doesn't seem to be in <time.h>
110 #endif
111
112 #define MAX_PATH PATH_MAX
113 typedef FILE* FileHandle;
114 #endif // BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
115
116 #if BUILDFLAG(IS_ANDROID)
117 #include <android/log.h>
118 #include "base/android/jni_android.h"
119 #endif
120
121 #if BUILDFLAG(IS_CHROMEOS_ASH)
122 #include "base/files/scoped_file.h"
123 #endif
124
125 #if BUILDFLAG(IS_FUCHSIA)
126 #include "base/fuchsia/scoped_fx_logger.h"
127 #endif
128
129 #if !BUILDFLAG(IS_NACL)
130 #include "base/logging/rust_logger.rs.h"
131 #endif
132
133 namespace logging {
134
135 namespace {
136
137 int g_min_log_level = 0;
138
139 // NOTE: Once |g_vlog_info| has been initialized, it might be in use
140 // by another thread. Never delete the old VLogInfo, just create a second
141 // one and overwrite. We need to use leak-san annotations on this intentional
142 // leak.
143 //
144 // This can be read/written on multiple threads. In tests we don't see that
145 // causing a problem as updates tend to happen early. Atomic ensures there are
146 // no problems. To avoid some of the overhead of Atomic, we use
147 // |load(std::memory_order_acquire)| and |store(...,
148 // std::memory_order_release)| when reading or writing. This guarantees that the
149 // referenced object is available at the time the |g_vlog_info| is read and that
150 // |g_vlog_info| is updated atomically.
151 //
152 // Do not access this directly. You must use |GetVlogInfo|, |InitializeVlogInfo|
153 // and/or |ExchangeVlogInfo|.
154 std::atomic<VlogInfo*> g_vlog_info = nullptr;
155
GetVlogInfo()156 VlogInfo* GetVlogInfo() {
157 return g_vlog_info.load(std::memory_order_acquire);
158 }
159
160 // Sets g_vlog_info if it is not already set. Checking that it's not already set
161 // prevents logging initialization (which can come late in test setup) from
162 // overwriting values set via ScopedVmoduleSwitches.
InitializeVlogInfo(VlogInfo * vlog_info)163 bool InitializeVlogInfo(VlogInfo* vlog_info) {
164 VlogInfo* previous_vlog_info = nullptr;
165 return g_vlog_info.compare_exchange_strong(previous_vlog_info, vlog_info);
166 }
167
ExchangeVlogInfo(VlogInfo * vlog_info)168 VlogInfo* ExchangeVlogInfo(VlogInfo* vlog_info) {
169 return g_vlog_info.exchange(vlog_info);
170 }
171
172 // Creates a VlogInfo from the commandline if it has been initialized and if it
173 // contains relevant switches, otherwise this returns |nullptr|.
VlogInfoFromCommandLine()174 std::unique_ptr<VlogInfo> VlogInfoFromCommandLine() {
175 if (!base::CommandLine::InitializedForCurrentProcess())
176 return nullptr;
177 base::CommandLine* command_line = base::CommandLine::ForCurrentProcess();
178 if (!command_line->HasSwitch(switches::kV) &&
179 !command_line->HasSwitch(switches::kVModule)) {
180 return nullptr;
181 }
182 #if defined(LEAK_SANITIZER) && !BUILDFLAG(IS_NACL)
183 // See comments on |g_vlog_info|.
184 ScopedLeakSanitizerDisabler lsan_disabler;
185 #endif // defined(LEAK_SANITIZER)
186 return std::make_unique<VlogInfo>(
187 command_line->GetSwitchValueASCII(switches::kV),
188 command_line->GetSwitchValueASCII(switches::kVModule), &g_min_log_level);
189 }
190
191 // If the commandline is initialized for the current process this will
192 // initialize g_vlog_info. If there are no VLOG switches, it will initialize it
193 // to |nullptr|.
MaybeInitializeVlogInfo()194 void MaybeInitializeVlogInfo() {
195 if (base::CommandLine::InitializedForCurrentProcess()) {
196 std::unique_ptr<VlogInfo> vlog_info = VlogInfoFromCommandLine();
197 if (vlog_info) {
198 // VlogInfoFromCommandLine is annotated with ScopedLeakSanitizerDisabler
199 // so it's allowed to leak. If the object was installed, we release it.
200 if (InitializeVlogInfo(vlog_info.get())) {
201 vlog_info.release();
202 }
203 }
204 }
205 }
206
207 const char* const log_severity_names[] = {"INFO", "WARNING", "ERROR", "FATAL"};
208 static_assert(LOGGING_NUM_SEVERITIES == std::size(log_severity_names),
209 "Incorrect number of log_severity_names");
210
log_severity_name(int severity)211 const char* log_severity_name(int severity) {
212 if (severity >= 0 && severity < LOGGING_NUM_SEVERITIES)
213 return log_severity_names[severity];
214 return "UNKNOWN";
215 }
216
217 // Specifies the process' logging sink(s), represented as a combination of
218 // LoggingDestination values joined by bitwise OR.
219 uint32_t g_logging_destination = LOG_DEFAULT;
220
221 #if BUILDFLAG(IS_CHROMEOS)
222 // Specifies the format of log header for chrome os.
223 LogFormat g_log_format = LogFormat::LOG_FORMAT_SYSLOG;
224 #endif
225
226 #if BUILDFLAG(IS_FUCHSIA)
227 // Retains system logging structures.
GetScopedFxLogger()228 base::ScopedFxLogger& GetScopedFxLogger() {
229 static base::NoDestructor<base::ScopedFxLogger> logger;
230 return *logger;
231 }
232 #endif
233
234 // For LOGGING_ERROR and above, always print to stderr.
235 const int kAlwaysPrintErrorLevel = LOGGING_ERROR;
236
237 // Which log file to use? This is initialized by InitLogging or
238 // will be lazily initialized to the default value when it is
239 // first needed.
240 using PathString = base::FilePath::StringType;
241 PathString* g_log_file_name = nullptr;
242
243 // This file is lazily opened and the handle may be nullptr
244 FileHandle g_log_file = nullptr;
245
246 // What should be prepended to each message?
247 bool g_log_process_id = false;
248 bool g_log_thread_id = false;
249 bool g_log_timestamp = true;
250 bool g_log_tickcount = false;
251 const char* g_log_prefix = nullptr;
252
253 // Should we pop up fatal debug messages in a dialog?
254 bool show_error_dialogs = false;
255
256 // An assert handler override specified by the client to be called instead of
257 // the debug message dialog and process termination. Assert handlers are stored
258 // in stack to allow overriding and restoring.
GetLogAssertHandlerStack()259 base::stack<LogAssertHandlerFunction>& GetLogAssertHandlerStack() {
260 static base::NoDestructor<base::stack<LogAssertHandlerFunction>> instance;
261 return *instance;
262 }
263
264 // A log message handler that gets notified of every log message we process.
265 LogMessageHandlerFunction g_log_message_handler = nullptr;
266
TickCount()267 uint64_t TickCount() {
268 #if BUILDFLAG(IS_WIN)
269 return GetTickCount();
270 #elif BUILDFLAG(IS_FUCHSIA)
271 return static_cast<uint64_t>(
272 zx_clock_get_monotonic() /
273 static_cast<zx_time_t>(base::Time::kNanosecondsPerMicrosecond));
274 #elif BUILDFLAG(IS_APPLE)
275 return mach_absolute_time();
276 #elif BUILDFLAG(IS_NACL)
277 // NaCl sadly does not have _POSIX_TIMERS enabled in sys/features.h
278 // So we have to use clock() for now.
279 return clock();
280 #elif BUILDFLAG(IS_POSIX)
281 struct timespec ts;
282 clock_gettime(CLOCK_MONOTONIC, &ts);
283
284 uint64_t absolute_micro = static_cast<uint64_t>(ts.tv_sec) * 1000000 +
285 static_cast<uint64_t>(ts.tv_nsec) / 1000;
286
287 return absolute_micro;
288 #endif
289 }
290
DeleteFilePath(const PathString & log_name)291 void DeleteFilePath(const PathString& log_name) {
292 #if BUILDFLAG(IS_WIN)
293 DeleteFile(log_name.c_str());
294 #elif BUILDFLAG(IS_NACL)
295 // Do nothing; unlink() isn't supported on NaCl.
296 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
297 unlink(log_name.c_str());
298 #else
299 #error Unsupported platform
300 #endif
301 }
302
GetDefaultLogFile()303 PathString GetDefaultLogFile() {
304 #if BUILDFLAG(IS_WIN)
305 // On Windows we use the same path as the exe.
306 wchar_t module_name[MAX_PATH];
307 GetModuleFileName(nullptr, module_name, MAX_PATH);
308
309 PathString log_name = module_name;
310 PathString::size_type last_backslash = log_name.rfind('\\', log_name.size());
311 if (last_backslash != PathString::npos)
312 log_name.erase(last_backslash + 1);
313 log_name += FILE_PATH_LITERAL("debug.log");
314 return log_name;
315 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
316 // On other platforms we just use the current directory.
317 return PathString("debug.log");
318 #endif
319 }
320
321 // We don't need locks on Windows for atomically appending to files. The OS
322 // provides this functionality.
323 #if BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
324
325 // Provides a lock to synchronize appending to the log file across
326 // threads. This can be required to support NFS file systems even on OSes that
327 // provide atomic append operations in most cases. It should be noted that this
328 // lock is not not shared across processes. When using NFS filesystems
329 // protection against clobbering between different processes will be best-effort
330 // and provided by the OS. See
331 // https://man7.org/linux/man-pages/man2/open.2.html.
332 //
333 // The lock also protects initializing and closing the log file which can
334 // happen concurrently with logging on some platforms like ChromeOS that need to
335 // redirect logging by calling BaseInitLoggingImpl() twice.
GetLoggingLock()336 base::Lock& GetLoggingLock() {
337 static base::NoDestructor<base::Lock> lock;
338 return *lock;
339 }
340
341 #endif // BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
342
343 // Called by logging functions to ensure that |g_log_file| is initialized
344 // and can be used for writing. Returns false if the file could not be
345 // initialized. |g_log_file| will be nullptr in this case.
InitializeLogFileHandle()346 bool InitializeLogFileHandle() {
347 if (g_log_file)
348 return true;
349
350 if (!g_log_file_name) {
351 // Nobody has called InitLogging to specify a debug log file, so here we
352 // initialize the log file name to a default.
353 g_log_file_name = new PathString(GetDefaultLogFile());
354 }
355
356 if ((g_logging_destination & LOG_TO_FILE) == 0)
357 return true;
358
359 #if BUILDFLAG(IS_WIN)
360 // The FILE_APPEND_DATA access mask ensures that the file is atomically
361 // appended to across accesses from multiple threads.
362 // https://msdn.microsoft.com/en-us/library/windows/desktop/aa364399(v=vs.85).aspx
363 // https://msdn.microsoft.com/en-us/library/windows/desktop/aa363858(v=vs.85).aspx
364 g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
365 FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
366 OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
367 if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
368 // We are intentionally not using FilePath or FileUtil here to reduce the
369 // dependencies of the logging implementation. For e.g. FilePath and
370 // FileUtil depend on shell32 and user32.dll. This is not acceptable for
371 // some consumers of base logging like chrome_elf, etc.
372 // Please don't change the code below to use FilePath.
373 // try the current directory
374 wchar_t system_buffer[MAX_PATH];
375 system_buffer[0] = 0;
376 DWORD len = ::GetCurrentDirectory(std::size(system_buffer), system_buffer);
377 if (len == 0 || len > std::size(system_buffer))
378 return false;
379
380 *g_log_file_name = system_buffer;
381 // Append a trailing backslash if needed.
382 if (g_log_file_name->back() != L'\\')
383 *g_log_file_name += FILE_PATH_LITERAL("\\");
384 *g_log_file_name += FILE_PATH_LITERAL("debug.log");
385
386 g_log_file = CreateFile(g_log_file_name->c_str(), FILE_APPEND_DATA,
387 FILE_SHARE_READ | FILE_SHARE_WRITE, nullptr,
388 OPEN_ALWAYS, FILE_ATTRIBUTE_NORMAL, nullptr);
389 if (g_log_file == INVALID_HANDLE_VALUE || g_log_file == nullptr) {
390 g_log_file = nullptr;
391 return false;
392 }
393 }
394 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
395 g_log_file = fopen(g_log_file_name->c_str(), "a");
396 if (g_log_file == nullptr)
397 return false;
398 #else
399 #error Unsupported platform
400 #endif
401
402 return true;
403 }
404
CloseFile(FileHandle log)405 void CloseFile(FileHandle log) {
406 #if BUILDFLAG(IS_WIN)
407 CloseHandle(log);
408 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
409 fclose(log);
410 #else
411 #error Unsupported platform
412 #endif
413 }
414
CloseLogFileUnlocked()415 void CloseLogFileUnlocked() {
416 if (!g_log_file)
417 return;
418
419 CloseFile(g_log_file);
420 g_log_file = nullptr;
421
422 // If we initialized logging via an externally-provided file descriptor, we
423 // won't have a log path set and shouldn't try to reopen the log file.
424 if (!g_log_file_name)
425 g_logging_destination &= ~LOG_TO_FILE;
426 }
427
WriteToFd(int fd,const char * data,size_t length)428 void WriteToFd(int fd, const char* data, size_t length) {
429 size_t bytes_written = 0;
430 long rv;
431 while (bytes_written < length) {
432 rv = HANDLE_EINTR(write(fd, data + bytes_written, length - bytes_written));
433 if (rv < 0) {
434 // Give up, nothing we can do now.
435 break;
436 }
437 bytes_written += static_cast<size_t>(rv);
438 }
439 }
440
SetLogFatalCrashKey(LogMessage * log_message)441 void SetLogFatalCrashKey(LogMessage* log_message) {
442 #if !BUILDFLAG(IS_NACL)
443 // In case of an out-of-memory condition, this code could be reentered when
444 // constructing and storing the key. Using a static is not thread-safe, but if
445 // multiple threads are in the process of a fatal crash at the same time, this
446 // should work.
447 static bool guarded = false;
448 if (guarded)
449 return;
450
451 base::AutoReset<bool> guard(&guarded, true);
452
453 // Note that we intentionally use LOG_FATAL here (old name for LOGGING_FATAL)
454 // as that's understood and used by the crash backend.
455 static auto* const crash_key = base::debug::AllocateCrashKeyString(
456 "LOG_FATAL", base::debug::CrashKeySize::Size1024);
457 base::debug::SetCrashKeyString(crash_key, log_message->BuildCrashString());
458
459 #endif // !BUILDFLAG(IS_NACL)
460 }
461
BuildCrashString(const char * file,int line,const char * message_without_prefix)462 std::string BuildCrashString(const char* file,
463 int line,
464 const char* message_without_prefix) {
465 // Only log last path component.
466 if (file) {
467 const char* slash = strrchr(file,
468 #if BUILDFLAG(IS_WIN)
469 '\\'
470 #else
471 '/'
472 #endif // BUILDFLAG(IS_WIN)
473 );
474 if (slash) {
475 file = slash + 1;
476 }
477 }
478
479 return base::StringPrintf("%s:%d: %s", file, line, message_without_prefix);
480 }
481
482 // Invokes macro to record trace event when a log message is emitted.
TraceLogMessage(const char * file,int line,const std::string & message)483 void TraceLogMessage(const char* file, int line, const std::string& message) {
484 TRACE_EVENT_INSTANT("log", "LogMessage", [&](perfetto::EventContext ctx) {
485 perfetto::protos::pbzero::LogMessage* log = ctx.event()->set_log_message();
486 log->set_source_location_iid(base::trace_event::InternedSourceLocation::Get(
487 &ctx, base::trace_event::TraceSourceLocation(/*function_name=*/nullptr,
488 file, line)));
489 log->set_body_iid(
490 base::trace_event::InternedLogMessage::Get(&ctx, message));
491 });
492 }
493
494 } // namespace
495
496 #if BUILDFLAG(DCHECK_IS_CONFIGURABLE)
497 // In DCHECK-enabled Chrome builds, allow the meaning of LOGGING_DCHECK to be
498 // determined at run-time. We default it to ERROR, to avoid it triggering
499 // crashes before the run-time has explicitly chosen the behaviour.
500 BASE_EXPORT logging::LogSeverity LOGGING_DCHECK = LOGGING_ERROR;
501 #endif // BUILDFLAG(DCHECK_IS_CONFIGURABLE)
502
503 // This is never instantiated, it's just used for EAT_STREAM_PARAMETERS to have
504 // an object of the correct type on the LHS of the unused part of the ternary
505 // operator.
506 std::ostream* g_swallow_stream;
507
BaseInitLoggingImpl(const LoggingSettings & settings)508 bool BaseInitLoggingImpl(const LoggingSettings& settings) {
509 #if BUILDFLAG(IS_NACL)
510 // Can log only to the system debug log and stderr.
511 CHECK_EQ(settings.logging_dest & ~(LOG_TO_SYSTEM_DEBUG_LOG | LOG_TO_STDERR),
512 0u);
513 #endif
514
515 #if BUILDFLAG(IS_CHROMEOS)
516 g_log_format = settings.log_format;
517 #endif
518
519 MaybeInitializeVlogInfo();
520
521 g_logging_destination = settings.logging_dest;
522
523 #if BUILDFLAG(IS_FUCHSIA)
524 if (g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) {
525 GetScopedFxLogger() = base::ScopedFxLogger::CreateForProcess();
526 }
527 #endif
528
529 #if !BUILDFLAG(IS_NACL)
530 // Connects Rust logging with the //base logging functionality.
531 internal::init_rust_log_crate();
532 #endif
533
534 // Ignore file options unless logging to file is set.
535 if ((g_logging_destination & LOG_TO_FILE) == 0)
536 return true;
537
538 #if BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
539 base::AutoLock guard(GetLoggingLock());
540 #endif
541
542 // Calling InitLogging twice or after some log call has already opened the
543 // default log file will re-initialize to the new options.
544 CloseLogFileUnlocked();
545
546 #if BUILDFLAG(IS_CHROMEOS_ASH) || BUILDFLAG(IS_WIN)
547 if (settings.log_file) {
548 CHECK(settings.log_file_path.empty(), base::NotFatalUntil::M127);
549 g_log_file = settings.log_file;
550 return true;
551 }
552 #endif // BUILDFLAG(IS_CHROMEOS_ASH) || BUILDFLAG(IS_WIN)
553
554 CHECK(!settings.log_file_path.empty(), base::NotFatalUntil::M127)
555 << "LOG_TO_FILE set but no log_file_path!";
556
557 if (!g_log_file_name)
558 g_log_file_name = new PathString();
559 *g_log_file_name = settings.log_file_path;
560 if (settings.delete_old == DELETE_OLD_LOG_FILE)
561 DeleteFilePath(*g_log_file_name);
562
563 return InitializeLogFileHandle();
564 }
565
SetMinLogLevel(int level)566 void SetMinLogLevel(int level) {
567 g_min_log_level = std::min(LOGGING_FATAL, level);
568 }
569
GetMinLogLevel()570 int GetMinLogLevel() {
571 return g_min_log_level;
572 }
573
ShouldCreateLogMessage(int severity)574 bool ShouldCreateLogMessage(int severity) {
575 if (severity < g_min_log_level)
576 return false;
577
578 // Return true here unless we know ~LogMessage won't do anything.
579 return g_logging_destination != LOG_NONE || g_log_message_handler ||
580 severity >= kAlwaysPrintErrorLevel;
581 }
582
583 // Returns true when LOG_TO_STDERR flag is set, or |severity| is high.
584 // If |severity| is high then true will be returned when no log destinations are
585 // set, or only LOG_TO_FILE is set, since that is useful for local development
586 // and debugging.
ShouldLogToStderr(int severity)587 bool ShouldLogToStderr(int severity) {
588 if (g_logging_destination & LOG_TO_STDERR)
589 return true;
590
591 #if BUILDFLAG(IS_FUCHSIA)
592 // Fuchsia will persist data logged to stdio by a component, so do not emit
593 // logs to stderr unless explicitly configured to do so.
594 return false;
595 #else
596 if (severity >= kAlwaysPrintErrorLevel)
597 return (g_logging_destination & ~LOG_TO_FILE) == LOG_NONE;
598 return false;
599 #endif
600 }
601
GetVlogVerbosity()602 int GetVlogVerbosity() {
603 return std::max(-1, LOGGING_INFO - GetMinLogLevel());
604 }
605
GetVlogLevelHelper(const char * file,size_t N)606 int GetVlogLevelHelper(const char* file, size_t N) {
607 DCHECK_GT(N, 0U);
608
609 // Note: |g_vlog_info| may change on a different thread during startup
610 // (but will always be valid or nullptr).
611 VlogInfo* vlog_info = GetVlogInfo();
612 return vlog_info ? vlog_info->GetVlogLevel(std::string_view(file, N - 1))
613 : GetVlogVerbosity();
614 }
615
SetLogItems(bool enable_process_id,bool enable_thread_id,bool enable_timestamp,bool enable_tickcount)616 void SetLogItems(bool enable_process_id, bool enable_thread_id,
617 bool enable_timestamp, bool enable_tickcount) {
618 g_log_process_id = enable_process_id;
619 g_log_thread_id = enable_thread_id;
620 g_log_timestamp = enable_timestamp;
621 g_log_tickcount = enable_tickcount;
622 }
623
SetLogPrefix(const char * prefix)624 void SetLogPrefix(const char* prefix) {
625 DCHECK(!prefix ||
626 base::ContainsOnlyChars(prefix, "abcdefghijklmnopqrstuvwxyz"));
627 g_log_prefix = prefix;
628 }
629
SetShowErrorDialogs(bool enable_dialogs)630 void SetShowErrorDialogs(bool enable_dialogs) {
631 show_error_dialogs = enable_dialogs;
632 }
633
634 namespace {
635
AbslAbortHook(const char * file,int line,const char * buf_start,const char * prefix_end,const char * buf_end)636 [[noreturn]] void AbslAbortHook(const char* file,
637 int line,
638 const char* buf_start,
639 const char* prefix_end,
640 const char* buf_end) {
641 // This simulates a NOTREACHED() at file:line instead of here. This is used
642 // instead of base::ImmediateCrash() to give better error messages locally
643 // (printed stack for one).
644 LogMessageFatal(file, line, LOGGING_FATAL).stream()
645 << "NOTREACHED hit. " << prefix_end;
646 }
647
648 } // namespace
649
RegisterAbslAbortHook()650 void RegisterAbslAbortHook() {
651 // TODO(pbos): Update this to not rely on a _internal namespace once there's
652 // a public API in absl::.
653 // Note: If this fails to compile because of an absl roll, this is fair to
654 // remove if you file a crbug.com/new and assign it to pbos@.
655 ::absl::raw_log_internal::RegisterAbortHook(&AbslAbortHook);
656 }
657
ScopedLogAssertHandler(LogAssertHandlerFunction handler)658 ScopedLogAssertHandler::ScopedLogAssertHandler(
659 LogAssertHandlerFunction handler) {
660 GetLogAssertHandlerStack().push(std::move(handler));
661 }
662
~ScopedLogAssertHandler()663 ScopedLogAssertHandler::~ScopedLogAssertHandler() {
664 GetLogAssertHandlerStack().pop();
665 }
666
SetLogMessageHandler(LogMessageHandlerFunction handler)667 void SetLogMessageHandler(LogMessageHandlerFunction handler) {
668 g_log_message_handler = handler;
669 }
670
GetLogMessageHandler()671 LogMessageHandlerFunction GetLogMessageHandler() {
672 return g_log_message_handler;
673 }
674
675 #if !defined(NDEBUG)
676 // Displays a message box to the user with the error message in it.
677 // Used for fatal messages, where we close the app simultaneously.
678 // This is for developers only; we don't use this in circumstances
679 // (like release builds) where users could see it, since users don't
680 // understand these messages anyway.
DisplayDebugMessageInDialog(const std::string & str)681 void DisplayDebugMessageInDialog(const std::string& str) {
682 if (str.empty())
683 return;
684
685 if (!show_error_dialogs)
686 return;
687
688 #if BUILDFLAG(IS_WIN)
689 // We intentionally don't implement a dialog on other platforms.
690 // You can just look at stderr.
691 if (base::win::IsUser32AndGdi32Available()) {
692 MessageBoxW(nullptr, base::as_wcstr(base::UTF8ToUTF16(str)), L"Fatal error",
693 MB_OK | MB_ICONHAND | MB_TOPMOST);
694 } else {
695 OutputDebugStringW(base::as_wcstr(base::UTF8ToUTF16(str)));
696 }
697 #endif // BUILDFLAG(IS_WIN)
698 }
699 #endif // !defined(NDEBUG)
700
LogMessage(const char * file,int line,LogSeverity severity)701 LogMessage::LogMessage(const char* file, int line, LogSeverity severity)
702 : severity_(severity), file_(file), line_(line) {
703 Init(file, line);
704 }
705
LogMessage(const char * file,int line,const char * condition)706 LogMessage::LogMessage(const char* file, int line, const char* condition)
707 : severity_(LOGGING_FATAL), file_(file), line_(line) {
708 Init(file, line);
709 stream_ << "Check failed: " << condition << ". ";
710 }
711
~LogMessage()712 LogMessage::~LogMessage() {
713 Flush();
714 }
715
Flush()716 void LogMessage::Flush() {
717 // Don't let actions from this method affect the system error after returning.
718 base::ScopedClearLastError scoped_clear_last_error;
719
720 size_t stack_start = stream_.str().length();
721 #if !defined(OFFICIAL_BUILD) && !BUILDFLAG(IS_NACL) && !defined(__UCLIBC__) && \
722 !BUILDFLAG(IS_AIX)
723 // Include a stack trace on a fatal, unless a debugger is attached.
724 if (severity_ == LOGGING_FATAL && !base::debug::BeingDebugged()) {
725 base::debug::StackTrace stack_trace;
726 stream_ << std::endl; // Newline to separate from log message.
727 stack_trace.OutputToStream(&stream_);
728 #if BUILDFLAG(IS_ANDROID)
729 std::string java_stack = base::android::GetJavaStackTraceIfPresent();
730 if (!java_stack.empty()) {
731 stream_ << "Java stack (may interleave with native stack):\n";
732 stream_ << java_stack << '\n';
733 }
734 #endif
735 base::debug::TaskTrace task_trace;
736 if (!task_trace.empty())
737 task_trace.OutputToStream(&stream_);
738
739 // Include the IPC context, if any.
740 // TODO(chrisha): Integrate with symbolization once those tools exist!
741 const auto* task = base::TaskAnnotator::CurrentTaskForThread();
742 if (task && task->ipc_hash) {
743 stream_ << "IPC message handler context: "
744 << base::StringPrintf("0x%08X", task->ipc_hash) << std::endl;
745 }
746
747 // Include the crash keys, if any.
748 base::debug::OutputCrashKeysToStream(stream_);
749 }
750 #endif
751 stream_ << std::endl;
752 std::string str_newline(stream_.str());
753 TraceLogMessage(file_, line_, str_newline.substr(message_start_));
754
755 // FATAL messages should always run the assert handler and crash, even if a
756 // message handler marks them as otherwise handled.
757 absl::Cleanup handle_fatal_message = [&] {
758 if (severity_ == LOGGING_FATAL) {
759 HandleFatal(stack_start, str_newline);
760 }
761 };
762
763 if (severity_ == LOGGING_FATAL)
764 SetLogFatalCrashKey(this);
765
766 // Give any log message handler first dibs on the message.
767 if (g_log_message_handler &&
768 g_log_message_handler(severity_, file_, line_, message_start_,
769 str_newline)) {
770 // The handler took care of it, no further processing.
771 return;
772 }
773
774 if ((g_logging_destination & LOG_TO_SYSTEM_DEBUG_LOG) != 0) {
775 #if BUILDFLAG(IS_WIN)
776 OutputDebugStringA(str_newline.c_str());
777 #elif BUILDFLAG(IS_APPLE)
778 // In LOG_TO_SYSTEM_DEBUG_LOG mode, log messages are always written to
779 // stderr. If stderr is /dev/null, also log via os_log. If there's something
780 // weird about stderr, assume that log messages are going nowhere and log
781 // via os_log too. Messages logged via os_log show up in Console.app.
782 //
783 // Programs started by launchd, as UI applications normally are, have had
784 // stderr connected to /dev/null since OS X 10.8. Prior to that, stderr was
785 // a pipe to launchd, which logged what it received (see log_redirect_fd in
786 // 10.7.5 launchd-392.39/launchd/src/launchd_core_logic.c).
787 //
788 // Another alternative would be to determine whether stderr is a pipe to
789 // launchd and avoid logging via os_log only in that case. See 10.7.5
790 // CF-635.21/CFUtilities.c also_do_stderr(). This would result in logging to
791 // both stderr and os_log even in tests, where it's undesirable to log to
792 // the system log at all.
793 const bool log_to_system = [] {
794 struct stat stderr_stat;
795 if (fstat(fileno(stderr), &stderr_stat) == -1) {
796 return true;
797 }
798 if (!S_ISCHR(stderr_stat.st_mode)) {
799 return false;
800 }
801
802 struct stat dev_null_stat;
803 if (stat(_PATH_DEVNULL, &dev_null_stat) == -1) {
804 return true;
805 }
806
807 return !S_ISCHR(dev_null_stat.st_mode) ||
808 stderr_stat.st_rdev == dev_null_stat.st_rdev;
809 }();
810
811 if (log_to_system) {
812 // Log roughly the same way that CFLog() and NSLog() would. See 10.10.5
813 // CF-1153.18/CFUtilities.c __CFLogCString().
814 CFBundleRef main_bundle = CFBundleGetMainBundle();
815 CFStringRef main_bundle_id_cf =
816 main_bundle ? CFBundleGetIdentifier(main_bundle) : nullptr;
817 std::string main_bundle_id =
818 main_bundle_id_cf ? base::SysCFStringRefToUTF8(main_bundle_id_cf)
819 : std::string("");
820
821 const class OSLog {
822 public:
823 explicit OSLog(const char* subsystem)
824 : os_log_(subsystem ? os_log_create(subsystem, "chromium_logging")
825 : OS_LOG_DEFAULT) {}
826 OSLog(const OSLog&) = delete;
827 OSLog& operator=(const OSLog&) = delete;
828 ~OSLog() {
829 if (os_log_ != OS_LOG_DEFAULT) {
830 os_release(os_log_);
831 }
832 }
833 os_log_t get() const { return os_log_; }
834
835 private:
836 os_log_t os_log_;
837 } log(main_bundle_id.empty() ? nullptr : main_bundle_id.c_str());
838 const os_log_type_t os_log_type = [](LogSeverity severity) {
839 switch (severity) {
840 case LOGGING_INFO:
841 return OS_LOG_TYPE_INFO;
842 case LOGGING_WARNING:
843 return OS_LOG_TYPE_DEFAULT;
844 case LOGGING_ERROR:
845 return OS_LOG_TYPE_ERROR;
846 case LOGGING_FATAL:
847 return OS_LOG_TYPE_FAULT;
848 case LOGGING_VERBOSE:
849 return OS_LOG_TYPE_DEBUG;
850 default:
851 return OS_LOG_TYPE_DEFAULT;
852 }
853 }(severity_);
854 os_log_with_type(log.get(), os_log_type, "%{public}s",
855 str_newline.c_str());
856 }
857 #elif BUILDFLAG(IS_ANDROID)
858 android_LogPriority priority =
859 (severity_ < 0) ? ANDROID_LOG_VERBOSE : ANDROID_LOG_UNKNOWN;
860 switch (severity_) {
861 case LOGGING_INFO:
862 priority = ANDROID_LOG_INFO;
863 break;
864 case LOGGING_WARNING:
865 priority = ANDROID_LOG_WARN;
866 break;
867 case LOGGING_ERROR:
868 priority = ANDROID_LOG_ERROR;
869 break;
870 case LOGGING_FATAL:
871 priority = ANDROID_LOG_FATAL;
872 break;
873 }
874 const char kAndroidLogTag[] = "chromium";
875 #if DCHECK_IS_ON()
876 // Split the output by new lines to prevent the Android system from
877 // truncating the log.
878 std::vector<std::string> lines = base::SplitString(
879 str_newline, "\n", base::KEEP_WHITESPACE, base::SPLIT_WANT_ALL);
880 // str_newline has an extra newline appended to it (at the top of this
881 // function), so skip the last split element to avoid needlessly
882 // logging an empty string.
883 lines.pop_back();
884 for (const auto& line : lines)
885 __android_log_write(priority, kAndroidLogTag, line.c_str());
886 #else
887 // The Android system may truncate the string if it's too long.
888 __android_log_write(priority, kAndroidLogTag, str_newline.c_str());
889 #endif
890 #elif BUILDFLAG(IS_FUCHSIA)
891 // LogMessage() will silently drop the message if the logger is not valid.
892 // Skip the final character of |str_newline|, since LogMessage() will add
893 // a newline.
894 const auto message = std::string_view(str_newline).substr(message_start_);
895 GetScopedFxLogger().LogMessage(file_, static_cast<uint32_t>(line_),
896 message.substr(0, message.size() - 1),
897 severity_);
898 #endif // BUILDFLAG(IS_FUCHSIA)
899 }
900
901 if (ShouldLogToStderr(severity_)) {
902 // Not using fwrite() here, as there are crashes on Windows when CRT calls
903 // malloc() internally, triggering an OOM crash. This likely means that the
904 // process is close to OOM, but at least get the proper error message out,
905 // and give the caller a chance to free() up some resources. For instance if
906 // the calling code is:
907 //
908 // allocate_something();
909 // if (!TryToDoSomething()) {
910 // LOG(ERROR) << "Something went wrong";
911 // free_something();
912 // }
913 WriteToFd(STDERR_FILENO, str_newline.data(), str_newline.size());
914 }
915
916 if ((g_logging_destination & LOG_TO_FILE) != 0) {
917 #if BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
918 // If the client app did not call InitLogging() and the lock has not
919 // been created it will be done now on calling GetLoggingLock(). We do this
920 // on demand, but if two threads try to do this at the same time, there will
921 // be a race condition to create the lock. This is why InitLogging should be
922 // called from the main thread at the beginning of execution.
923 base::AutoLock guard(GetLoggingLock());
924 #endif
925 if (InitializeLogFileHandle()) {
926 #if BUILDFLAG(IS_WIN)
927 DWORD num_written;
928 WriteFile(g_log_file,
929 static_cast<const void*>(str_newline.c_str()),
930 static_cast<DWORD>(str_newline.length()),
931 &num_written,
932 nullptr);
933 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
934 std::ignore =
935 fwrite(str_newline.data(), str_newline.size(), 1, g_log_file);
936 fflush(g_log_file);
937 #else
938 #error Unsupported platform
939 #endif
940 }
941 }
942 }
943
BuildCrashString() const944 std::string LogMessage::BuildCrashString() const {
945 return logging::BuildCrashString(file(), line(),
946 str().c_str() + message_start_);
947 }
948
949 // writes the common header info to the stream
Init(const char * file,int line)950 void LogMessage::Init(const char* file, int line) {
951 // Don't let actions from this method affect the system error after returning.
952 base::ScopedClearLastError scoped_clear_last_error;
953
954 std::string_view filename(file);
955 size_t last_slash_pos = filename.find_last_of("\\/");
956 if (last_slash_pos != std::string_view::npos) {
957 filename.remove_prefix(last_slash_pos + 1);
958 }
959
960 #if BUILDFLAG(IS_CHROMEOS)
961 if (g_log_format == LogFormat::LOG_FORMAT_SYSLOG) {
962 InitWithSyslogPrefix(
963 filename, line, TickCount(), log_severity_name(severity_), g_log_prefix,
964 g_log_process_id, g_log_thread_id, g_log_timestamp, g_log_tickcount);
965 } else
966 #endif // BUILDFLAG(IS_CHROMEOS)
967 {
968 // TODO(darin): It might be nice if the columns were fixed width.
969 stream_ << '[';
970 if (g_log_prefix)
971 stream_ << g_log_prefix << ':';
972 if (g_log_process_id)
973 stream_ << base::GetUniqueIdForProcess() << ':';
974 if (g_log_thread_id)
975 stream_ << base::PlatformThread::CurrentId() << ':';
976 if (g_log_timestamp) {
977 #if BUILDFLAG(IS_WIN)
978 SYSTEMTIME local_time;
979 GetLocalTime(&local_time);
980 stream_ << std::setfill('0')
981 << std::setw(2) << local_time.wMonth
982 << std::setw(2) << local_time.wDay
983 << '/'
984 << std::setw(2) << local_time.wHour
985 << std::setw(2) << local_time.wMinute
986 << std::setw(2) << local_time.wSecond
987 << '.'
988 << std::setw(3) << local_time.wMilliseconds
989 << ':';
990 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
991 timeval tv;
992 gettimeofday(&tv, nullptr);
993 time_t t = tv.tv_sec;
994 struct tm local_time;
995 localtime_r(&t, &local_time);
996 struct tm* tm_time = &local_time;
997 stream_ << std::setfill('0')
998 << std::setw(2) << 1 + tm_time->tm_mon
999 << std::setw(2) << tm_time->tm_mday
1000 << '/'
1001 << std::setw(2) << tm_time->tm_hour
1002 << std::setw(2) << tm_time->tm_min
1003 << std::setw(2) << tm_time->tm_sec
1004 << '.'
1005 << std::setw(6) << tv.tv_usec
1006 << ':';
1007 #else
1008 #error Unsupported platform
1009 #endif
1010 }
1011 if (g_log_tickcount)
1012 stream_ << TickCount() << ':';
1013 if (severity_ >= 0) {
1014 stream_ << log_severity_name(severity_);
1015 } else {
1016 stream_ << "VERBOSE" << -severity_;
1017 }
1018 stream_ << ":" << filename << "(" << line << ")] ";
1019 }
1020 message_start_ = stream_.str().length();
1021 }
1022
HandleFatal(size_t stack_start,const std::string & str_newline) const1023 void LogMessage::HandleFatal(size_t stack_start,
1024 const std::string& str_newline) const {
1025 char str_stack[1024];
1026 base::strlcpy(str_stack, str_newline.data(), std::size(str_stack));
1027 base::debug::Alias(&str_stack);
1028
1029 if (!GetLogAssertHandlerStack().empty()) {
1030 LogAssertHandlerFunction log_assert_handler =
1031 GetLogAssertHandlerStack().top();
1032
1033 if (log_assert_handler) {
1034 auto newline_view = std::string_view(str_newline);
1035 log_assert_handler.Run(
1036 file_, line_,
1037 newline_view.substr(message_start_, stack_start - message_start_),
1038 newline_view.substr(stack_start));
1039 }
1040 } else {
1041 // Don't use the string with the newline, get a fresh version to send to
1042 // the debug message process. We also don't display assertions to the
1043 // user in release mode. The enduser can't do anything with this
1044 // information, and displaying message boxes when the application is
1045 // hosed can cause additional problems.
1046 #ifndef NDEBUG
1047 if (!base::debug::BeingDebugged()) {
1048 // Displaying a dialog is unnecessary when debugging and can complicate
1049 // debugging.
1050 DisplayDebugMessageInDialog(stream_.str());
1051 }
1052 #endif
1053
1054 // Crash the process to generate a dump.
1055 // TODO(crbug.com/40254046): Move ImmediateCrash() to an absl::Cleanup to
1056 // make sure it runs unconditionally. Currently LogAssertHandlers can abort
1057 // a FATAL message and tests rely on this. HandleFatal() should be
1058 // [[noreturn]].
1059 base::ImmediateCrash();
1060 }
1061 }
1062
~LogMessageFatal()1063 LogMessageFatal::~LogMessageFatal() {
1064 Flush();
1065 base::ImmediateCrash();
1066 }
1067
1068 #if BUILDFLAG(IS_WIN)
1069 // This has already been defined in the header, but defining it again as DWORD
1070 // ensures that the type used in the header is equivalent to DWORD. If not,
1071 // the redefinition is a compile error.
1072 typedef DWORD SystemErrorCode;
1073 #endif
1074
GetLastSystemErrorCode()1075 SystemErrorCode GetLastSystemErrorCode() {
1076 #if BUILDFLAG(IS_WIN)
1077 return ::GetLastError();
1078 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
1079 return errno;
1080 #endif
1081 }
1082
SystemErrorCodeToString(SystemErrorCode error_code)1083 BASE_EXPORT std::string SystemErrorCodeToString(SystemErrorCode error_code) {
1084 #if BUILDFLAG(IS_WIN)
1085 LPWSTR msgbuf = nullptr;
1086 DWORD len = ::FormatMessageW(
1087 FORMAT_MESSAGE_ALLOCATE_BUFFER | FORMAT_MESSAGE_FROM_SYSTEM |
1088 FORMAT_MESSAGE_IGNORE_INSERTS,
1089 nullptr, error_code, 0, reinterpret_cast<LPWSTR>(&msgbuf), 0, nullptr);
1090 if (len) {
1091 std::u16string message = base::WideToUTF16(msgbuf);
1092 ::LocalFree(msgbuf);
1093 msgbuf = nullptr;
1094 // Messages returned by system end with line breaks.
1095 return base::UTF16ToUTF8(base::CollapseWhitespace(message, true)) +
1096 base::StringPrintf(" (0x%lX)", error_code);
1097 }
1098 return base::StringPrintf("Error (0x%lX) while retrieving error. (0x%lX)",
1099 GetLastError(), error_code);
1100 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
1101 return base::safe_strerror(error_code) +
1102 base::StringPrintf(" (%d)", error_code);
1103 #endif // BUILDFLAG(IS_WIN)
1104 }
1105
1106 #if BUILDFLAG(IS_WIN)
Win32ErrorLogMessage(const char * file,int line,LogSeverity severity,SystemErrorCode err)1107 Win32ErrorLogMessage::Win32ErrorLogMessage(const char* file,
1108 int line,
1109 LogSeverity severity,
1110 SystemErrorCode err)
1111 : LogMessage(file, line, severity), err_(err) {}
1112
~Win32ErrorLogMessage()1113 Win32ErrorLogMessage::~Win32ErrorLogMessage() {
1114 AppendError();
1115 }
1116
AppendError()1117 void Win32ErrorLogMessage::AppendError() {
1118 // Don't let actions from this method affect the system error after returning.
1119 base::ScopedClearLastError scoped_clear_last_error;
1120
1121 stream() << ": " << SystemErrorCodeToString(err_);
1122 // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
1123 // field) and use Alias in hopes that it makes it into crash dumps.
1124 DWORD last_error = err_;
1125 base::debug::Alias(&last_error);
1126 }
1127
~Win32ErrorLogMessageFatal()1128 Win32ErrorLogMessageFatal::~Win32ErrorLogMessageFatal() {
1129 AppendError();
1130 Flush();
1131 base::ImmediateCrash();
1132 }
1133
1134 #elif BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
ErrnoLogMessage(const char * file,int line,LogSeverity severity,SystemErrorCode err)1135 ErrnoLogMessage::ErrnoLogMessage(const char* file,
1136 int line,
1137 LogSeverity severity,
1138 SystemErrorCode err)
1139 : LogMessage(file, line, severity), err_(err) {}
1140
~ErrnoLogMessage()1141 ErrnoLogMessage::~ErrnoLogMessage() {
1142 AppendError();
1143 }
1144
AppendError()1145 void ErrnoLogMessage::AppendError() {
1146 // Don't let actions from this method affect the system error after returning.
1147 base::ScopedClearLastError scoped_clear_last_error;
1148
1149 stream() << ": " << SystemErrorCodeToString(err_);
1150 // We're about to crash (CHECK). Put |err_| on the stack (by placing it in a
1151 // field) and use Alias in hopes that it makes it into crash dumps.
1152 int last_error = err_;
1153 base::debug::Alias(&last_error);
1154 }
1155
~ErrnoLogMessageFatal()1156 ErrnoLogMessageFatal::~ErrnoLogMessageFatal() {
1157 AppendError();
1158 Flush();
1159 base::ImmediateCrash();
1160 }
1161
1162 #endif // BUILDFLAG(IS_WIN)
1163
CloseLogFile()1164 void CloseLogFile() {
1165 #if BUILDFLAG(IS_POSIX) || BUILDFLAG(IS_FUCHSIA)
1166 base::AutoLock guard(GetLoggingLock());
1167 #endif
1168 CloseLogFileUnlocked();
1169 }
1170
1171 #if BUILDFLAG(IS_CHROMEOS_ASH)
DuplicateLogFILE()1172 FILE* DuplicateLogFILE() {
1173 if ((g_logging_destination & LOG_TO_FILE) == 0 || !InitializeLogFileHandle())
1174 return nullptr;
1175
1176 int log_fd = fileno(g_log_file);
1177 if (log_fd == -1)
1178 return nullptr;
1179 base::ScopedFD dup_fd(dup(log_fd));
1180 if (dup_fd == -1)
1181 return nullptr;
1182 FILE* duplicate = fdopen(dup_fd.get(), "a");
1183 if (!duplicate)
1184 return nullptr;
1185 std::ignore = dup_fd.release();
1186 return duplicate;
1187 }
1188 #endif
1189
1190 #if BUILDFLAG(IS_WIN)
DuplicateLogFileHandle()1191 HANDLE DuplicateLogFileHandle() {
1192 // `g_log_file` should only be valid, or nullptr, but be very careful that we
1193 // do not duplicate INVALID_HANDLE_VALUE as it aliases the process handle.
1194 if (!(g_logging_destination & LOG_TO_FILE) || !g_log_file ||
1195 g_log_file == INVALID_HANDLE_VALUE) {
1196 return nullptr;
1197 }
1198 HANDLE duplicate = nullptr;
1199 if (!::DuplicateHandle(::GetCurrentProcess(), g_log_file,
1200 ::GetCurrentProcess(), &duplicate, 0,
1201 /*bInheritHandle=*/TRUE, DUPLICATE_SAME_ACCESS)) {
1202 return nullptr;
1203 }
1204 return duplicate;
1205 }
1206 #endif
1207
1208 // Used for testing. Declared in test/scoped_logging_settings.h.
ScopedLoggingSettings()1209 ScopedLoggingSettings::ScopedLoggingSettings()
1210 : min_log_level_(g_min_log_level),
1211 logging_destination_(g_logging_destination),
1212 #if BUILDFLAG(IS_CHROMEOS)
1213 log_format_(g_log_format),
1214 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
1215 enable_process_id_(g_log_process_id),
1216 enable_thread_id_(g_log_thread_id),
1217 enable_timestamp_(g_log_timestamp),
1218 enable_tickcount_(g_log_tickcount),
1219 log_prefix_(g_log_prefix),
1220 message_handler_(g_log_message_handler) {
1221 if (g_log_file_name) {
1222 log_file_name_ = *g_log_file_name;
1223 }
1224
1225 // Duplicating |g_log_file| is complex & unnecessary for this test helpers'
1226 // use-cases, and so long as |g_log_file_name| is set, it will be re-opened
1227 // automatically anyway, when required, so just close the existing one.
1228 if (g_log_file) {
1229 CHECK(g_log_file_name) << "Un-named |log_file| is not supported.";
1230 CloseLogFileUnlocked();
1231 }
1232 }
1233
~ScopedLoggingSettings()1234 ScopedLoggingSettings::~ScopedLoggingSettings() {
1235 // Re-initialize logging via the normal path. This will clean up old file
1236 // name and handle state, including re-initializing the VLOG internal state.
1237 CHECK(InitLogging({.logging_dest = logging_destination_,
1238 .log_file_path = log_file_name_,
1239 #if BUILDFLAG(IS_CHROMEOS)
1240 .log_format = log_format_
1241 #endif
1242 })) << "~ScopedLoggingSettings() failed to restore settings.";
1243
1244 // Restore plain data settings.
1245 SetMinLogLevel(min_log_level_);
1246 SetLogItems(enable_process_id_, enable_thread_id_, enable_timestamp_,
1247 enable_tickcount_);
1248 SetLogPrefix(log_prefix_);
1249 SetLogMessageHandler(message_handler_);
1250 }
1251
1252 #if BUILDFLAG(IS_CHROMEOS)
SetLogFormat(LogFormat log_format) const1253 void ScopedLoggingSettings::SetLogFormat(LogFormat log_format) const {
1254 g_log_format = log_format;
1255 }
1256 #endif // BUILDFLAG(IS_CHROMEOS_ASH)
1257
RawLog(int level,const char * message)1258 void RawLog(int level, const char* message) {
1259 if (level >= g_min_log_level && message) {
1260 const size_t message_len = strlen(message);
1261 WriteToFd(STDERR_FILENO, message, message_len);
1262
1263 if (message_len > 0 && message[message_len - 1] != '\n') {
1264 long rv;
1265 do {
1266 rv = HANDLE_EINTR(write(STDERR_FILENO, "\n", 1));
1267 if (rv < 0) {
1268 // Give up, nothing we can do now.
1269 break;
1270 }
1271 } while (rv != 1);
1272 }
1273 }
1274
1275 if (level == LOGGING_FATAL)
1276 base::ImmediateCrash();
1277 }
1278
1279 // This was defined at the beginning of this file.
1280 #undef write
1281
1282 #if BUILDFLAG(IS_WIN)
IsLoggingToFileEnabled()1283 bool IsLoggingToFileEnabled() {
1284 return g_logging_destination & LOG_TO_FILE;
1285 }
1286
GetLogFileFullPath()1287 std::wstring GetLogFileFullPath() {
1288 if (g_log_file_name)
1289 return *g_log_file_name;
1290 return std::wstring();
1291 }
1292 #endif
1293
1294 // Used for testing. Declared in test/scoped_logging_settings.h.
1295 ScopedVmoduleSwitches::ScopedVmoduleSwitches() = default;
1296
CreateVlogInfoWithSwitches(const std::string & vmodule_switch)1297 VlogInfo* ScopedVmoduleSwitches::CreateVlogInfoWithSwitches(
1298 const std::string& vmodule_switch) {
1299 // Try get a VlogInfo on which to base this.
1300 // First ensure that VLOG has been initialized.
1301 MaybeInitializeVlogInfo();
1302
1303 // Getting this now and setting it later is racy, however if a
1304 // ScopedVmoduleSwitches is being used on multiple threads that requires
1305 // further coordination and avoids this race.
1306 VlogInfo* base_vlog_info = GetVlogInfo();
1307 if (!base_vlog_info) {
1308 // Base is |nullptr|, so just create it from scratch.
1309 return new VlogInfo(/*v_switch_=*/"", vmodule_switch, &g_min_log_level);
1310 }
1311 return base_vlog_info->WithSwitches(vmodule_switch);
1312 }
1313
InitWithSwitches(const std::string & vmodule_switch)1314 void ScopedVmoduleSwitches::InitWithSwitches(
1315 const std::string& vmodule_switch) {
1316 // Make sure we are only initialized once.
1317 CHECK(!scoped_vlog_info_);
1318 {
1319 #if defined(LEAK_SANITIZER) && !BUILDFLAG(IS_NACL)
1320 // See comments on |g_vlog_info|.
1321 ScopedLeakSanitizerDisabler lsan_disabler;
1322 #endif // defined(LEAK_SANITIZER)
1323 scoped_vlog_info_ = CreateVlogInfoWithSwitches(vmodule_switch);
1324 }
1325 previous_vlog_info_ = ExchangeVlogInfo(scoped_vlog_info_);
1326 }
1327
~ScopedVmoduleSwitches()1328 ScopedVmoduleSwitches::~ScopedVmoduleSwitches() {
1329 VlogInfo* replaced_vlog_info = ExchangeVlogInfo(previous_vlog_info_);
1330 // Make sure something didn't replace our scoped VlogInfo while we weren't
1331 // looking.
1332 CHECK_EQ(replaced_vlog_info, scoped_vlog_info_);
1333 }
1334
1335 } // namespace logging
1336