1 /*
2 * Copyright 2004 The WebRTC Project Authors. All rights reserved.
3 *
4 * Use of this source code is governed by a BSD-style license
5 * that can be found in the LICENSE file in the root of the source
6 * tree. An additional intellectual property rights grant can be found
7 * in the file PATENTS. All contributing project authors may
8 * be found in the AUTHORS file in the root of the source tree.
9 */
10
11 #include "rtc_base/logging.h"
12
13 #include <string.h>
14
15 #if RTC_LOG_ENABLED()
16
17 #if defined(WEBRTC_WIN)
18 #include <windows.h>
19 #if _MSC_VER < 1900
20 #define snprintf _snprintf
21 #endif
22 #undef ERROR // wingdi.h
23 #endif
24
25 #if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS)
26 #include <CoreServices/CoreServices.h>
27 #elif defined(WEBRTC_ANDROID)
28 #include <android/log.h>
29
30 // Android has a 1024 limit on log inputs. We use 60 chars as an
31 // approx for the header/tag portion.
32 // See android/system/logging/liblog/logd_write.c
33 static const int kMaxLogLineSize = 1024 - 60;
34 #endif // WEBRTC_MAC && !defined(WEBRTC_IOS) || WEBRTC_ANDROID
35
36 #include <stdio.h>
37 #include <time.h>
38
39 #include <algorithm>
40 #include <cstdarg>
41 #include <vector>
42
43 #include "absl/base/attributes.h"
44 #include "rtc_base/checks.h"
45 #include "rtc_base/platform_thread_types.h"
46 #include "rtc_base/string_encode.h"
47 #include "rtc_base/string_utils.h"
48 #include "rtc_base/strings/string_builder.h"
49 #include "rtc_base/synchronization/mutex.h"
50 #include "rtc_base/thread_annotations.h"
51 #include "rtc_base/time_utils.h"
52
53 namespace rtc {
54 namespace {
55 // By default, release builds don't log, debug builds at info level
56 #if !defined(NDEBUG)
57 static LoggingSeverity g_min_sev = LS_INFO;
58 static LoggingSeverity g_dbg_sev = LS_INFO;
59 #else
60 static LoggingSeverity g_min_sev = LS_NONE;
61 static LoggingSeverity g_dbg_sev = LS_NONE;
62 #endif
63
64 // Return the filename portion of the string (that following the last slash).
FilenameFromPath(const char * file)65 const char* FilenameFromPath(const char* file) {
66 const char* end1 = ::strrchr(file, '/');
67 const char* end2 = ::strrchr(file, '\\');
68 if (!end1 && !end2)
69 return file;
70 else
71 return (end1 > end2) ? end1 + 1 : end2 + 1;
72 }
73
74 // Global lock for log subsystem, only needed to serialize access to streams_.
75 // TODO(bugs.webrtc.org/11665): this is not currently constant initialized and
76 // trivially destructible.
77 webrtc::Mutex g_log_mutex_;
78 } // namespace
79
80 /////////////////////////////////////////////////////////////////////////////
81 // LogMessage
82 /////////////////////////////////////////////////////////////////////////////
83
84 bool LogMessage::log_to_stderr_ = true;
85
86 // The list of logging streams currently configured.
87 // Note: we explicitly do not clean this up, because of the uncertain ordering
88 // of destructors at program exit. Let the person who sets the stream trigger
89 // cleanup by setting to null, or let it leak (safe at program exit).
90 ABSL_CONST_INIT LogSink* LogMessage::streams_ RTC_GUARDED_BY(g_log_mutex_) =
91 nullptr;
92 ABSL_CONST_INIT std::atomic<bool> LogMessage::streams_empty_ = {true};
93
94 // Boolean options default to false (0)
95 bool LogMessage::thread_, LogMessage::timestamp_;
96
LogMessage(const char * file,int line,LoggingSeverity sev)97 LogMessage::LogMessage(const char* file, int line, LoggingSeverity sev)
98 : LogMessage(file, line, sev, ERRCTX_NONE, 0) {}
99
LogMessage(const char * file,int line,LoggingSeverity sev,LogErrorContext err_ctx,int err)100 LogMessage::LogMessage(const char* file,
101 int line,
102 LoggingSeverity sev,
103 LogErrorContext err_ctx,
104 int err)
105 : severity_(sev) {
106 if (timestamp_) {
107 // Use SystemTimeMillis so that even if tests use fake clocks, the timestamp
108 // in log messages represents the real system time.
109 int64_t time = TimeDiff(SystemTimeMillis(), LogStartTime());
110 // Also ensure WallClockStartTime is initialized, so that it matches
111 // LogStartTime.
112 WallClockStartTime();
113 print_stream_ << "[" << rtc::LeftPad('0', 3, rtc::ToString(time / 1000))
114 << ":" << rtc::LeftPad('0', 3, rtc::ToString(time % 1000))
115 << "] ";
116 }
117
118 if (thread_) {
119 PlatformThreadId id = CurrentThreadId();
120 print_stream_ << "[" << id << "] ";
121 }
122
123 if (file != nullptr) {
124 #if defined(WEBRTC_ANDROID)
125 tag_ = FilenameFromPath(file);
126 print_stream_ << "(line " << line << "): ";
127 #else
128 print_stream_ << "(" << FilenameFromPath(file) << ":" << line << "): ";
129 #endif
130 }
131
132 if (err_ctx != ERRCTX_NONE) {
133 char tmp_buf[1024];
134 SimpleStringBuilder tmp(tmp_buf);
135 tmp.AppendFormat("[0x%08X]", err);
136 switch (err_ctx) {
137 case ERRCTX_ERRNO:
138 tmp << " " << strerror(err);
139 break;
140 #ifdef WEBRTC_WIN
141 case ERRCTX_HRESULT: {
142 char msgbuf[256];
143 DWORD flags =
144 FORMAT_MESSAGE_FROM_SYSTEM | FORMAT_MESSAGE_IGNORE_INSERTS;
145 if (DWORD len = FormatMessageA(
146 flags, nullptr, err, MAKELANGID(LANG_NEUTRAL, SUBLANG_DEFAULT),
147 msgbuf, sizeof(msgbuf) / sizeof(msgbuf[0]), nullptr)) {
148 while ((len > 0) &&
149 isspace(static_cast<unsigned char>(msgbuf[len - 1]))) {
150 msgbuf[--len] = 0;
151 }
152 tmp << " " << msgbuf;
153 }
154 break;
155 }
156 #endif // WEBRTC_WIN
157 default:
158 break;
159 }
160 extra_ = tmp.str();
161 }
162 }
163
164 #if defined(WEBRTC_ANDROID)
LogMessage(const char * file,int line,LoggingSeverity sev,const char * tag)165 LogMessage::LogMessage(const char* file,
166 int line,
167 LoggingSeverity sev,
168 const char* tag)
169 : LogMessage(file, line, sev, ERRCTX_NONE, 0 /* err */) {
170 tag_ = tag;
171 print_stream_ << tag << ": ";
172 }
173 #endif
174
175 // DEPRECATED. Currently only used by downstream projects that use
176 // implementation details of logging.h. Work is ongoing to remove those
177 // dependencies.
LogMessage(const char * file,int line,LoggingSeverity sev,const std::string & tag)178 LogMessage::LogMessage(const char* file,
179 int line,
180 LoggingSeverity sev,
181 const std::string& tag)
182 : LogMessage(file, line, sev) {
183 print_stream_ << tag << ": ";
184 }
185
~LogMessage()186 LogMessage::~LogMessage() {
187 FinishPrintStream();
188
189 const std::string str = print_stream_.Release();
190
191 if (severity_ >= g_dbg_sev) {
192 #if defined(WEBRTC_ANDROID)
193 OutputToDebug(str, severity_, tag_);
194 #else
195 OutputToDebug(str, severity_);
196 #endif
197 }
198
199 webrtc::MutexLock lock(&g_log_mutex_);
200 for (LogSink* entry = streams_; entry != nullptr; entry = entry->next_) {
201 if (severity_ >= entry->min_severity_) {
202 #if defined(WEBRTC_ANDROID)
203 entry->OnLogMessage(str, severity_, tag_);
204 #else
205 entry->OnLogMessage(str, severity_);
206 #endif
207 }
208 }
209 }
210
AddTag(const char * tag)211 void LogMessage::AddTag(const char* tag) {
212 #ifdef WEBRTC_ANDROID
213 tag_ = tag;
214 #endif
215 }
216
stream()217 rtc::StringBuilder& LogMessage::stream() {
218 return print_stream_;
219 }
220
GetMinLogSeverity()221 int LogMessage::GetMinLogSeverity() {
222 return g_min_sev;
223 }
224
GetLogToDebug()225 LoggingSeverity LogMessage::GetLogToDebug() {
226 return g_dbg_sev;
227 }
LogStartTime()228 int64_t LogMessage::LogStartTime() {
229 static const int64_t g_start = SystemTimeMillis();
230 return g_start;
231 }
232
WallClockStartTime()233 uint32_t LogMessage::WallClockStartTime() {
234 static const uint32_t g_start_wallclock = time(nullptr);
235 return g_start_wallclock;
236 }
237
LogThreads(bool on)238 void LogMessage::LogThreads(bool on) {
239 thread_ = on;
240 }
241
LogTimestamps(bool on)242 void LogMessage::LogTimestamps(bool on) {
243 timestamp_ = on;
244 }
245
LogToDebug(LoggingSeverity min_sev)246 void LogMessage::LogToDebug(LoggingSeverity min_sev) {
247 g_dbg_sev = min_sev;
248 webrtc::MutexLock lock(&g_log_mutex_);
249 UpdateMinLogSeverity();
250 }
251
SetLogToStderr(bool log_to_stderr)252 void LogMessage::SetLogToStderr(bool log_to_stderr) {
253 log_to_stderr_ = log_to_stderr;
254 }
255
GetLogToStream(LogSink * stream)256 int LogMessage::GetLogToStream(LogSink* stream) {
257 webrtc::MutexLock lock(&g_log_mutex_);
258 LoggingSeverity sev = LS_NONE;
259 for (LogSink* entry = streams_; entry != nullptr; entry = entry->next_) {
260 if (stream == nullptr || stream == entry) {
261 sev = std::min(sev, entry->min_severity_);
262 }
263 }
264 return sev;
265 }
266
AddLogToStream(LogSink * stream,LoggingSeverity min_sev)267 void LogMessage::AddLogToStream(LogSink* stream, LoggingSeverity min_sev) {
268 webrtc::MutexLock lock(&g_log_mutex_);
269 stream->min_severity_ = min_sev;
270 stream->next_ = streams_;
271 streams_ = stream;
272 streams_empty_.store(false, std::memory_order_relaxed);
273 UpdateMinLogSeverity();
274 }
275
RemoveLogToStream(LogSink * stream)276 void LogMessage::RemoveLogToStream(LogSink* stream) {
277 webrtc::MutexLock lock(&g_log_mutex_);
278 for (LogSink** entry = &streams_; *entry != nullptr;
279 entry = &(*entry)->next_) {
280 if (*entry == stream) {
281 *entry = (*entry)->next_;
282 break;
283 }
284 }
285 streams_empty_.store(streams_ == nullptr, std::memory_order_relaxed);
286 UpdateMinLogSeverity();
287 }
288
ConfigureLogging(const char * params)289 void LogMessage::ConfigureLogging(const char* params) {
290 LoggingSeverity current_level = LS_VERBOSE;
291 LoggingSeverity debug_level = GetLogToDebug();
292
293 std::vector<std::string> tokens;
294 tokenize(params, ' ', &tokens);
295
296 for (const std::string& token : tokens) {
297 if (token.empty())
298 continue;
299
300 // Logging features
301 if (token == "tstamp") {
302 LogTimestamps();
303 } else if (token == "thread") {
304 LogThreads();
305
306 // Logging levels
307 } else if (token == "verbose") {
308 current_level = LS_VERBOSE;
309 } else if (token == "info") {
310 current_level = LS_INFO;
311 } else if (token == "warning") {
312 current_level = LS_WARNING;
313 } else if (token == "error") {
314 current_level = LS_ERROR;
315 } else if (token == "none") {
316 current_level = LS_NONE;
317
318 // Logging targets
319 } else if (token == "debug") {
320 debug_level = current_level;
321 }
322 }
323
324 #if defined(WEBRTC_WIN) && !defined(WINUWP)
325 if ((LS_NONE != debug_level) && !::IsDebuggerPresent()) {
326 // First, attempt to attach to our parent's console... so if you invoke
327 // from the command line, we'll see the output there. Otherwise, create
328 // our own console window.
329 // Note: These methods fail if a console already exists, which is fine.
330 if (!AttachConsole(ATTACH_PARENT_PROCESS))
331 ::AllocConsole();
332 }
333 #endif // defined(WEBRTC_WIN) && !defined(WINUWP)
334
335 LogToDebug(debug_level);
336 }
337
UpdateMinLogSeverity()338 void LogMessage::UpdateMinLogSeverity()
339 RTC_EXCLUSIVE_LOCKS_REQUIRED(g_log_mutex_) {
340 LoggingSeverity min_sev = g_dbg_sev;
341 for (LogSink* entry = streams_; entry != nullptr; entry = entry->next_) {
342 min_sev = std::min(min_sev, entry->min_severity_);
343 }
344 g_min_sev = min_sev;
345 }
346
347 #if defined(WEBRTC_ANDROID)
OutputToDebug(const std::string & str,LoggingSeverity severity,const char * tag)348 void LogMessage::OutputToDebug(const std::string& str,
349 LoggingSeverity severity,
350 const char* tag) {
351 #else
352 void LogMessage::OutputToDebug(const std::string& str,
353 LoggingSeverity severity) {
354 #endif
355 bool log_to_stderr = log_to_stderr_;
356 #if defined(WEBRTC_MAC) && !defined(WEBRTC_IOS) && defined(NDEBUG)
357 // On the Mac, all stderr output goes to the Console log and causes clutter.
358 // So in opt builds, don't log to stderr unless the user specifically sets
359 // a preference to do so.
360 CFStringRef key = CFStringCreateWithCString(
361 kCFAllocatorDefault, "logToStdErr", kCFStringEncodingUTF8);
362 CFStringRef domain = CFBundleGetIdentifier(CFBundleGetMainBundle());
363 if (key != nullptr && domain != nullptr) {
364 Boolean exists_and_is_valid;
365 Boolean should_log =
366 CFPreferencesGetAppBooleanValue(key, domain, &exists_and_is_valid);
367 // If the key doesn't exist or is invalid or is false, we will not log to
368 // stderr.
369 log_to_stderr = exists_and_is_valid && should_log;
370 }
371 if (key != nullptr) {
372 CFRelease(key);
373 }
374 #endif // defined(WEBRTC_MAC) && !defined(WEBRTC_IOS) && defined(NDEBUG)
375
376 #if defined(WEBRTC_WIN)
377 // Always log to the debugger.
378 // Perhaps stderr should be controlled by a preference, as on Mac?
379 OutputDebugStringA(str.c_str());
380 if (log_to_stderr) {
381 // This handles dynamically allocated consoles, too.
382 if (HANDLE error_handle = ::GetStdHandle(STD_ERROR_HANDLE)) {
383 log_to_stderr = false;
384 DWORD written = 0;
385 ::WriteFile(error_handle, str.data(), static_cast<DWORD>(str.size()),
386 &written, 0);
387 }
388 }
389 #endif // WEBRTC_WIN
390
391 #if defined(WEBRTC_ANDROID)
392 // Android's logging facility uses severity to log messages but we
393 // need to map libjingle's severity levels to Android ones first.
394 // Also write to stderr which maybe available to executable started
395 // from the shell.
396 int prio;
397 switch (severity) {
398 case LS_VERBOSE:
399 prio = ANDROID_LOG_VERBOSE;
400 break;
401 case LS_INFO:
402 prio = ANDROID_LOG_INFO;
403 break;
404 case LS_WARNING:
405 prio = ANDROID_LOG_WARN;
406 break;
407 case LS_ERROR:
408 prio = ANDROID_LOG_ERROR;
409 break;
410 default:
411 prio = ANDROID_LOG_UNKNOWN;
412 }
413
414 int size = str.size();
415 int line = 0;
416 int idx = 0;
417 const int max_lines = size / kMaxLogLineSize + 1;
418 if (max_lines == 1) {
419 __android_log_print(prio, tag, "%.*s", size, str.c_str());
420 } else {
421 while (size > 0) {
422 const int len = std::min(size, kMaxLogLineSize);
423 // Use the size of the string in the format (str may have \0 in the
424 // middle).
425 __android_log_print(prio, tag, "[%d/%d] %.*s", line + 1, max_lines, len,
426 str.c_str() + idx);
427 idx += len;
428 size -= len;
429 ++line;
430 }
431 }
432 #endif // WEBRTC_ANDROID
433 if (log_to_stderr) {
434 fprintf(stderr, "%s", str.c_str());
435 fflush(stderr);
436 }
437 }
438
439 // static
440 bool LogMessage::IsNoop(LoggingSeverity severity) {
441 if (severity >= g_dbg_sev || severity >= g_min_sev)
442 return false;
443 return streams_empty_.load(std::memory_order_relaxed);
444 }
445
446 void LogMessage::FinishPrintStream() {
447 if (!extra_.empty())
448 print_stream_ << " : " << extra_;
449 print_stream_ << "\n";
450 }
451
452 namespace webrtc_logging_impl {
453
454 void Log(const LogArgType* fmt, ...) {
455 va_list args;
456 va_start(args, fmt);
457
458 LogMetadataErr meta;
459 const char* tag = nullptr;
460 switch (*fmt) {
461 case LogArgType::kLogMetadata: {
462 meta = {va_arg(args, LogMetadata), ERRCTX_NONE, 0};
463 break;
464 }
465 case LogArgType::kLogMetadataErr: {
466 meta = va_arg(args, LogMetadataErr);
467 break;
468 }
469 #ifdef WEBRTC_ANDROID
470 case LogArgType::kLogMetadataTag: {
471 const LogMetadataTag tag_meta = va_arg(args, LogMetadataTag);
472 meta = {{nullptr, 0, tag_meta.severity}, ERRCTX_NONE, 0};
473 tag = tag_meta.tag;
474 break;
475 }
476 #endif
477 default: {
478 RTC_NOTREACHED();
479 va_end(args);
480 return;
481 }
482 }
483
484 if (LogMessage::IsNoop(meta.meta.Severity())) {
485 va_end(args);
486 return;
487 }
488
489 LogMessage log_message(meta.meta.File(), meta.meta.Line(),
490 meta.meta.Severity(), meta.err_ctx, meta.err);
491 if (tag) {
492 log_message.AddTag(tag);
493 }
494
495 for (++fmt; *fmt != LogArgType::kEnd; ++fmt) {
496 switch (*fmt) {
497 case LogArgType::kInt:
498 log_message.stream() << va_arg(args, int);
499 break;
500 case LogArgType::kLong:
501 log_message.stream() << va_arg(args, long);
502 break;
503 case LogArgType::kLongLong:
504 log_message.stream() << va_arg(args, long long);
505 break;
506 case LogArgType::kUInt:
507 log_message.stream() << va_arg(args, unsigned);
508 break;
509 case LogArgType::kULong:
510 log_message.stream() << va_arg(args, unsigned long);
511 break;
512 case LogArgType::kULongLong:
513 log_message.stream() << va_arg(args, unsigned long long);
514 break;
515 case LogArgType::kDouble:
516 log_message.stream() << va_arg(args, double);
517 break;
518 case LogArgType::kLongDouble:
519 log_message.stream() << va_arg(args, long double);
520 break;
521 case LogArgType::kCharP: {
522 const char* s = va_arg(args, const char*);
523 log_message.stream() << (s ? s : "(null)");
524 break;
525 }
526 case LogArgType::kStdString:
527 log_message.stream() << *va_arg(args, const std::string*);
528 break;
529 case LogArgType::kStringView:
530 log_message.stream() << *va_arg(args, const absl::string_view*);
531 break;
532 case LogArgType::kVoidP:
533 log_message.stream() << rtc::ToHex(
534 reinterpret_cast<uintptr_t>(va_arg(args, const void*)));
535 break;
536 default:
537 RTC_NOTREACHED();
538 va_end(args);
539 return;
540 }
541 }
542
543 va_end(args);
544 }
545
546 } // namespace webrtc_logging_impl
547 } // namespace rtc
548 #endif
549
550 namespace rtc {
551 // Inefficient default implementation, override is recommended.
OnLogMessage(const std::string & msg,LoggingSeverity severity,const char * tag)552 void LogSink::OnLogMessage(const std::string& msg,
553 LoggingSeverity severity,
554 const char* tag) {
555 OnLogMessage(tag + (": " + msg), severity);
556 }
557
OnLogMessage(const std::string & msg,LoggingSeverity)558 void LogSink::OnLogMessage(const std::string& msg,
559 LoggingSeverity /* severity */) {
560 OnLogMessage(msg);
561 }
562 } // namespace rtc
563