1 /*
2 * Copyright (C) 2015 The Android Open Source Project
3 *
4 * Licensed under the Apache License, Version 2.0 (the "License");
5 * you may not use this file except in compliance with the License.
6 * You may obtain a copy of the License at
7 *
8 * http://www.apache.org/licenses/LICENSE-2.0
9 *
10 * Unless required by applicable law or agreed to in writing, software
11 * distributed under the License is distributed on an "AS IS" BASIS,
12 * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied.
13 * See the License for the specific language governing permissions and
14 * limitations under the License.
15 */
16
17 #if defined(_WIN32)
18 #include <windows.h>
19 #endif
20
21 #include "android-base/logging.h"
22
23 #include <fcntl.h>
24 #include <inttypes.h>
25 #include <libgen.h>
26 #include <time.h>
27
28 // For getprogname(3) or program_invocation_short_name.
29 #if defined(__ANDROID__) || defined(__APPLE__)
30 #include <stdlib.h>
31 #elif defined(__GLIBC__)
32 #include <errno.h>
33 #endif
34
35 #if defined(__linux__)
36 #include <sys/uio.h>
37 #endif
38
39 #include <atomic>
40 #include <iostream>
41 #include <limits>
42 #include <mutex>
43 #include <optional>
44 #include <sstream>
45 #include <string>
46 #include <utility>
47 #include <vector>
48
49 #include <android/log.h>
50 #ifdef __ANDROID__
51 #include <android/set_abort_message.h>
52 #else
53 #include <sys/types.h>
54 #include <unistd.h>
55 #endif
56
57 #include <android-base/file.h>
58 #include <android-base/macros.h>
59 #include <android-base/parseint.h>
60 #include <android-base/strings.h>
61 #include <android-base/threads.h>
62
63 #include "liblog_symbols.h"
64 #include "logging_splitters.h"
65
66 namespace android {
67 namespace base {
68
69 // BSD-based systems like Android/macOS have getprogname(). Others need us to provide one.
70 #if defined(__GLIBC__) || defined(_WIN32)
getprogname()71 static const char* getprogname() {
72 #if defined(__GLIBC__)
73 return program_invocation_short_name;
74 #elif defined(_WIN32)
75 static bool first = true;
76 static char progname[MAX_PATH] = {};
77
78 if (first) {
79 snprintf(progname, sizeof(progname), "%s",
80 android::base::Basename(android::base::GetExecutablePath()).c_str());
81 first = false;
82 }
83
84 return progname;
85 #endif
86 }
87 #endif
88
GetFileBasename(const char * file)89 static const char* GetFileBasename(const char* file) {
90 // We can't use basename(3) even on Unix because the Mac doesn't
91 // have a non-modifying basename.
92 const char* last_slash = strrchr(file, '/');
93 if (last_slash != nullptr) {
94 return last_slash + 1;
95 }
96 #if defined(_WIN32)
97 const char* last_backslash = strrchr(file, '\\');
98 if (last_backslash != nullptr) {
99 return last_backslash + 1;
100 }
101 #endif
102 return file;
103 }
104
105 #if defined(__linux__)
OpenKmsg()106 static int OpenKmsg() {
107 #if defined(__ANDROID__)
108 // pick up 'file w /dev/kmsg' environment from daemon's init rc file
109 const auto val = getenv("ANDROID_FILE__dev_kmsg");
110 if (val != nullptr) {
111 int fd;
112 if (android::base::ParseInt(val, &fd, 0)) {
113 auto flags = fcntl(fd, F_GETFL);
114 if ((flags != -1) && ((flags & O_ACCMODE) == O_WRONLY)) return fd;
115 }
116 }
117 #endif
118 return TEMP_FAILURE_RETRY(open("/dev/kmsg", O_WRONLY | O_CLOEXEC));
119 }
120 #endif
121
log_id_tToLogId(int32_t buffer_id)122 static LogId log_id_tToLogId(int32_t buffer_id) {
123 switch (buffer_id) {
124 case LOG_ID_MAIN:
125 return MAIN;
126 case LOG_ID_SYSTEM:
127 return SYSTEM;
128 case LOG_ID_RADIO:
129 return RADIO;
130 case LOG_ID_CRASH:
131 return CRASH;
132 case LOG_ID_DEFAULT:
133 default:
134 return DEFAULT;
135 }
136 }
137
LogIdTolog_id_t(LogId log_id)138 static int32_t LogIdTolog_id_t(LogId log_id) {
139 switch (log_id) {
140 case MAIN:
141 return LOG_ID_MAIN;
142 case SYSTEM:
143 return LOG_ID_SYSTEM;
144 case RADIO:
145 return LOG_ID_RADIO;
146 case CRASH:
147 return LOG_ID_CRASH;
148 case DEFAULT:
149 default:
150 return LOG_ID_DEFAULT;
151 }
152 }
153
PriorityToLogSeverity(int priority)154 static LogSeverity PriorityToLogSeverity(int priority) {
155 switch (priority) {
156 case ANDROID_LOG_DEFAULT:
157 return INFO;
158 case ANDROID_LOG_VERBOSE:
159 return VERBOSE;
160 case ANDROID_LOG_DEBUG:
161 return DEBUG;
162 case ANDROID_LOG_INFO:
163 return INFO;
164 case ANDROID_LOG_WARN:
165 return WARNING;
166 case ANDROID_LOG_ERROR:
167 return ERROR;
168 case ANDROID_LOG_FATAL:
169 return FATAL;
170 default:
171 return FATAL;
172 }
173 }
174
LogSeverityToPriority(LogSeverity severity)175 static int32_t LogSeverityToPriority(LogSeverity severity) {
176 switch (severity) {
177 case VERBOSE:
178 return ANDROID_LOG_VERBOSE;
179 case DEBUG:
180 return ANDROID_LOG_DEBUG;
181 case INFO:
182 return ANDROID_LOG_INFO;
183 case WARNING:
184 return ANDROID_LOG_WARN;
185 case ERROR:
186 return ANDROID_LOG_ERROR;
187 case FATAL_WITHOUT_ABORT:
188 case FATAL:
189 default:
190 return ANDROID_LOG_FATAL;
191 }
192 }
193
Logger()194 static LogFunction& Logger() {
195 #ifdef __ANDROID__
196 static auto& logger = *new LogFunction(LogdLogger());
197 #else
198 static auto& logger = *new LogFunction(StderrLogger);
199 #endif
200 return logger;
201 }
202
Aborter()203 static AbortFunction& Aborter() {
204 static auto& aborter = *new AbortFunction(DefaultAborter);
205 return aborter;
206 }
207
208 // Only used for Q fallback.
TagLock()209 static std::recursive_mutex& TagLock() {
210 static auto& tag_lock = *new std::recursive_mutex();
211 return tag_lock;
212 }
213 // Only used for Q fallback.
214 static std::string* gDefaultTag;
215
SetDefaultTag(const std::string & tag)216 void SetDefaultTag(const std::string& tag) {
217 static auto& liblog_functions = GetLibLogFunctions();
218 if (liblog_functions) {
219 liblog_functions->__android_log_set_default_tag(tag.c_str());
220 } else {
221 std::lock_guard<std::recursive_mutex> lock(TagLock());
222 if (gDefaultTag != nullptr) {
223 delete gDefaultTag;
224 gDefaultTag = nullptr;
225 }
226 if (!tag.empty()) {
227 gDefaultTag = new std::string(tag);
228 }
229 }
230 }
231
232 static bool gInitialized = false;
233
234 // Only used for Q fallback.
235 static LogSeverity gMinimumLogSeverity = INFO;
236
237 #if defined(__linux__)
KernelLogLine(const char * msg,int length,android::base::LogSeverity severity,const char * tag)238 static void KernelLogLine(const char* msg, int length, android::base::LogSeverity severity,
239 const char* tag) {
240 // clang-format off
241 static constexpr int kLogSeverityToKernelLogLevel[] = {
242 [android::base::VERBOSE] = 7, // KERN_DEBUG (there is no verbose kernel log
243 // level)
244 [android::base::DEBUG] = 7, // KERN_DEBUG
245 [android::base::INFO] = 6, // KERN_INFO
246 [android::base::WARNING] = 4, // KERN_WARNING
247 [android::base::ERROR] = 3, // KERN_ERROR
248 [android::base::FATAL_WITHOUT_ABORT] = 2, // KERN_CRIT
249 [android::base::FATAL] = 2, // KERN_CRIT
250 };
251 // clang-format on
252 static_assert(arraysize(kLogSeverityToKernelLogLevel) == android::base::FATAL + 1,
253 "Mismatch in size of kLogSeverityToKernelLogLevel and values in LogSeverity");
254
255 static int klog_fd = OpenKmsg();
256 if (klog_fd == -1) return;
257
258 int level = kLogSeverityToKernelLogLevel[severity];
259
260 // The kernel's printk buffer is only 1024 bytes.
261 // TODO: should we automatically break up long lines into multiple lines?
262 // Or we could log but with something like "..." at the end?
263 char buf[1024] __attribute__((__uninitialized__));
264 size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %.*s\n", level, tag, length, msg);
265 if (size > sizeof(buf)) {
266 size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
267 level, tag, size);
268 }
269
270 iovec iov[1];
271 iov[0].iov_base = buf;
272 iov[0].iov_len = size;
273 TEMP_FAILURE_RETRY(writev(klog_fd, iov, 1));
274 }
275
KernelLogger(android::base::LogId,android::base::LogSeverity severity,const char * tag,const char *,unsigned int,const char * full_message)276 void KernelLogger(android::base::LogId, android::base::LogSeverity severity, const char* tag,
277 const char*, unsigned int, const char* full_message) {
278 SplitByLines(full_message, KernelLogLine, severity, tag);
279 }
280 #endif
281
StderrLogger(LogId,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)282 void StderrLogger(LogId, LogSeverity severity, const char* tag, const char* file, unsigned int line,
283 const char* message) {
284 struct tm now;
285 time_t t = time(nullptr);
286
287 #if defined(_WIN32)
288 localtime_s(&now, &t);
289 #else
290 localtime_r(&t, &now);
291 #endif
292 auto output_string =
293 StderrOutputGenerator(now, getpid(), GetThreadId(), severity, tag, file, line, message);
294
295 fputs(output_string.c_str(), stderr);
296 }
297
StdioLogger(LogId,LogSeverity severity,const char *,const char *,unsigned int,const char * message)298 void StdioLogger(LogId, LogSeverity severity, const char* /*tag*/, const char* /*file*/,
299 unsigned int /*line*/, const char* message) {
300 if (severity >= WARNING) {
301 fflush(stdout);
302 fprintf(stderr, "%s: %s\n", GetFileBasename(getprogname()), message);
303 } else {
304 fprintf(stdout, "%s\n", message);
305 }
306 }
307
DefaultAborter(const char * abort_message)308 void DefaultAborter(const char* abort_message) {
309 #ifdef __ANDROID__
310 android_set_abort_message(abort_message);
311 #else
312 UNUSED(abort_message);
313 #endif
314 abort();
315 }
316
LogdLogChunk(LogId id,LogSeverity severity,const char * tag,const char * message)317 static void LogdLogChunk(LogId id, LogSeverity severity, const char* tag, const char* message) {
318 int32_t lg_id = LogIdTolog_id_t(id);
319 int32_t priority = LogSeverityToPriority(severity);
320
321 static auto& liblog_functions = GetLibLogFunctions();
322 if (liblog_functions) {
323 __android_log_message log_message = {sizeof(__android_log_message), lg_id, priority, tag,
324 static_cast<const char*>(nullptr), 0, message};
325 liblog_functions->__android_log_logd_logger(&log_message);
326 } else {
327 __android_log_buf_print(lg_id, priority, tag, "%s", message);
328 }
329 }
330
LogdLogger(LogId default_log_id)331 LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) {}
332
operator ()(LogId id,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)333 void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag, const char* file,
334 unsigned int line, const char* message) {
335 if (id == DEFAULT) {
336 id = default_log_id_;
337 }
338
339 SplitByLogdChunks(id, severity, tag, file, line, message, LogdLogChunk);
340 }
341
InitLogging(char * argv[],LogFunction && logger,AbortFunction && aborter)342 void InitLogging(char* argv[], LogFunction&& logger, AbortFunction&& aborter) {
343 SetLogger(std::forward<LogFunction>(logger));
344 SetAborter(std::forward<AbortFunction>(aborter));
345
346 if (gInitialized) {
347 return;
348 }
349
350 gInitialized = true;
351
352 // Stash the command line for later use. We can use /proc/self/cmdline on
353 // Linux to recover this, but we don't have that luxury on the Mac/Windows,
354 // and there are a couple of argv[0] variants that are commonly used.
355 if (argv != nullptr) {
356 SetDefaultTag(basename(argv[0]));
357 }
358
359 const char* tags = getenv("ANDROID_LOG_TAGS");
360 if (tags == nullptr) {
361 return;
362 }
363
364 std::vector<std::string> specs = Split(tags, " ");
365 for (size_t i = 0; i < specs.size(); ++i) {
366 // "tag-pattern:[vdiwefs]"
367 std::string spec(specs[i]);
368 if (spec.size() == 3 && StartsWith(spec, "*:")) {
369 switch (spec[2]) {
370 case 'v':
371 SetMinimumLogSeverity(VERBOSE);
372 continue;
373 case 'd':
374 SetMinimumLogSeverity(DEBUG);
375 continue;
376 case 'i':
377 SetMinimumLogSeverity(INFO);
378 continue;
379 case 'w':
380 SetMinimumLogSeverity(WARNING);
381 continue;
382 case 'e':
383 SetMinimumLogSeverity(ERROR);
384 continue;
385 case 'f':
386 SetMinimumLogSeverity(FATAL_WITHOUT_ABORT);
387 continue;
388 // liblog will even suppress FATAL if you say 's' for silent, but fatal should
389 // never be suppressed.
390 case 's':
391 SetMinimumLogSeverity(FATAL_WITHOUT_ABORT);
392 continue;
393 }
394 }
395 LOG(FATAL) << "unsupported '" << spec << "' in ANDROID_LOG_TAGS (" << tags
396 << ")";
397 }
398 }
399
SetLogger(LogFunction && logger)400 void SetLogger(LogFunction&& logger) {
401 Logger() = std::move(logger);
402
403 static auto& liblog_functions = GetLibLogFunctions();
404 if (liblog_functions) {
405 liblog_functions->__android_log_set_logger([](const struct __android_log_message* log_message) {
406 auto log_id = log_id_tToLogId(log_message->buffer_id);
407 auto severity = PriorityToLogSeverity(log_message->priority);
408
409 Logger()(log_id, severity, log_message->tag, log_message->file, log_message->line,
410 log_message->message);
411 });
412 }
413 }
414
SetAborter(AbortFunction && aborter)415 void SetAborter(AbortFunction&& aborter) {
416 Aborter() = std::move(aborter);
417
418 static auto& liblog_functions = GetLibLogFunctions();
419 if (liblog_functions) {
420 liblog_functions->__android_log_set_aborter(
421 [](const char* abort_message) { Aborter()(abort_message); });
422 }
423 }
424
425 // This indirection greatly reduces the stack impact of having lots of
426 // checks/logging in a function.
427 class LogMessageData {
428 public:
LogMessageData(const char * file,unsigned int line,LogSeverity severity,const char * tag,int error)429 LogMessageData(const char* file, unsigned int line, LogSeverity severity, const char* tag,
430 int error)
431 : file_(GetFileBasename(file)),
432 line_number_(line),
433 severity_(severity),
434 tag_(tag),
435 error_(error) {}
436
GetFile() const437 const char* GetFile() const {
438 return file_;
439 }
440
GetLineNumber() const441 unsigned int GetLineNumber() const {
442 return line_number_;
443 }
444
GetSeverity() const445 LogSeverity GetSeverity() const {
446 return severity_;
447 }
448
GetTag() const449 const char* GetTag() const { return tag_; }
450
GetError() const451 int GetError() const {
452 return error_;
453 }
454
GetBuffer()455 std::ostream& GetBuffer() {
456 return buffer_;
457 }
458
ToString() const459 std::string ToString() const {
460 return buffer_.str();
461 }
462
463 private:
464 std::ostringstream buffer_;
465 const char* const file_;
466 const unsigned int line_number_;
467 const LogSeverity severity_;
468 const char* const tag_;
469 const int error_;
470
471 DISALLOW_COPY_AND_ASSIGN(LogMessageData);
472 };
473
LogMessage(const char * file,unsigned int line,LogId,LogSeverity severity,const char * tag,int error)474 LogMessage::LogMessage(const char* file, unsigned int line, LogId, LogSeverity severity,
475 const char* tag, int error)
476 : LogMessage(file, line, severity, tag, error) {}
477
LogMessage(const char * file,unsigned int line,LogSeverity severity,const char * tag,int error)478 LogMessage::LogMessage(const char* file, unsigned int line, LogSeverity severity, const char* tag,
479 int error)
480 : data_(new LogMessageData(file, line, severity, tag, error)) {}
481
~LogMessage()482 LogMessage::~LogMessage() {
483 // Check severity again. This is duplicate work wrt/ LOG macros, but not LOG_STREAM.
484 if (!WOULD_LOG(data_->GetSeverity())) {
485 return;
486 }
487
488 // Finish constructing the message.
489 if (data_->GetError() != -1) {
490 data_->GetBuffer() << ": " << strerror(data_->GetError());
491 }
492 std::string msg(data_->ToString());
493
494 if (data_->GetSeverity() == FATAL) {
495 #ifdef __ANDROID__
496 // Set the bionic abort message early to avoid liblog doing it
497 // with the individual lines, so that we get the whole message.
498 android_set_abort_message(msg.c_str());
499 #endif
500 }
501
502 LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetSeverity(), data_->GetTag(),
503 msg.c_str());
504
505 // Abort if necessary.
506 if (data_->GetSeverity() == FATAL) {
507 static auto& liblog_functions = GetLibLogFunctions();
508 if (liblog_functions) {
509 liblog_functions->__android_log_call_aborter(msg.c_str());
510 } else {
511 Aborter()(msg.c_str());
512 }
513 }
514 }
515
stream()516 std::ostream& LogMessage::stream() {
517 return data_->GetBuffer();
518 }
519
LogLine(const char * file,unsigned int line,LogSeverity severity,const char * tag,const char * message)520 void LogMessage::LogLine(const char* file, unsigned int line, LogSeverity severity, const char* tag,
521 const char* message) {
522 static auto& liblog_functions = GetLibLogFunctions();
523 int32_t priority = LogSeverityToPriority(severity);
524 if (liblog_functions) {
525 __android_log_message log_message = {
526 sizeof(__android_log_message), LOG_ID_DEFAULT, priority, tag, file, line, message};
527 liblog_functions->__android_log_write_log_message(&log_message);
528 } else {
529 if (tag == nullptr) {
530 std::lock_guard<std::recursive_mutex> lock(TagLock());
531 if (gDefaultTag == nullptr) {
532 gDefaultTag = new std::string(getprogname());
533 }
534
535 Logger()(DEFAULT, severity, gDefaultTag->c_str(), file, line, message);
536 } else {
537 Logger()(DEFAULT, severity, tag, file, line, message);
538 }
539 }
540 }
541
GetMinimumLogSeverity()542 LogSeverity GetMinimumLogSeverity() {
543 static auto& liblog_functions = GetLibLogFunctions();
544 if (liblog_functions) {
545 return PriorityToLogSeverity(liblog_functions->__android_log_get_minimum_priority());
546 } else {
547 return gMinimumLogSeverity;
548 }
549 }
550
ShouldLog(LogSeverity severity,const char * tag)551 bool ShouldLog(LogSeverity severity, const char* tag) {
552 static auto& liblog_functions = GetLibLogFunctions();
553 // Even though we're not using the R liblog functions in this function, if we're running on Q,
554 // we need to fall back to using gMinimumLogSeverity, since __android_log_is_loggable() will not
555 // take into consideration the value from SetMinimumLogSeverity().
556 if (liblog_functions) {
557 int32_t priority = LogSeverityToPriority(severity);
558 return __android_log_is_loggable(priority, tag, ANDROID_LOG_INFO);
559 } else {
560 return severity >= gMinimumLogSeverity;
561 }
562 }
563
SetMinimumLogSeverity(LogSeverity new_severity)564 LogSeverity SetMinimumLogSeverity(LogSeverity new_severity) {
565 static auto& liblog_functions = GetLibLogFunctions();
566 if (liblog_functions) {
567 int32_t priority = LogSeverityToPriority(new_severity);
568 return PriorityToLogSeverity(liblog_functions->__android_log_set_minimum_priority(priority));
569 } else {
570 LogSeverity old_severity = gMinimumLogSeverity;
571 gMinimumLogSeverity = new_severity;
572 return old_severity;
573 }
574 }
575
ScopedLogSeverity(LogSeverity new_severity)576 ScopedLogSeverity::ScopedLogSeverity(LogSeverity new_severity) {
577 old_ = SetMinimumLogSeverity(new_severity);
578 }
579
~ScopedLogSeverity()580 ScopedLogSeverity::~ScopedLogSeverity() {
581 SetMinimumLogSeverity(old_);
582 }
583
584 } // namespace base
585 } // namespace android
586