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