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