• Home
  • Line#
  • Scopes#
  • Navigate#
  • Raw
  • Download
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(__APPLE__) && !defined(__BIONIC__)
getprogname()66 static const char* getprogname() {
67 #ifdef _WIN32
68   static bool first = true;
69   static char progname[MAX_PATH] = {};
70 
71   if (first) {
72     snprintf(progname, sizeof(progname), "%s",
73              android::base::Basename(android::base::GetExecutablePath()).c_str());
74     first = false;
75   }
76 
77   return progname;
78 #else
79   return program_invocation_short_name;
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 /dev/kmsg w` environment from a daemon's init .rc file.
104   // If you're wondering why you're not seeing kernel logs from your daemon,
105   // it's probably because you're missing that line in your .rc file!
106   // You'll also need to `allow <your_domain> kmsg_device:chr_file w_file_perms;`
107   // in `system/sepolocy/private/<your_domain>.te`.
108   const auto val = getenv("ANDROID_FILE__dev_kmsg");
109   if (val != nullptr) {
110     int fd;
111     if (android::base::ParseInt(val, &fd, 0)) {
112       auto flags = fcntl(fd, F_GETFL);
113       if ((flags != -1) && ((flags & O_ACCMODE) == O_WRONLY)) return fd;
114     }
115   }
116 #endif
117   // Note that this is _not_ the normal case: this is primarily for init itself.
118   // Most other code will need to inherit an fd from init, as described above.
119   return TEMP_FAILURE_RETRY(open("/dev/kmsg", O_WRONLY | O_CLOEXEC));
120 }
121 #endif
122 
log_id_tToLogId(int32_t buffer_id)123 static LogId log_id_tToLogId(int32_t buffer_id) {
124   switch (buffer_id) {
125     case LOG_ID_MAIN:
126       return MAIN;
127     case LOG_ID_SYSTEM:
128       return SYSTEM;
129     case LOG_ID_RADIO:
130       return RADIO;
131     case LOG_ID_CRASH:
132       return CRASH;
133     case LOG_ID_DEFAULT:
134     default:
135       return DEFAULT;
136   }
137 }
138 
LogIdTolog_id_t(LogId log_id)139 static int32_t LogIdTolog_id_t(LogId log_id) {
140   switch (log_id) {
141     case MAIN:
142       return LOG_ID_MAIN;
143     case SYSTEM:
144       return LOG_ID_SYSTEM;
145     case RADIO:
146       return LOG_ID_RADIO;
147     case CRASH:
148       return LOG_ID_CRASH;
149     case DEFAULT:
150     default:
151       return LOG_ID_DEFAULT;
152   }
153 }
154 
PriorityToLogSeverity(int priority)155 static LogSeverity PriorityToLogSeverity(int priority) {
156   switch (priority) {
157     case ANDROID_LOG_DEFAULT:
158       return INFO;
159     case ANDROID_LOG_VERBOSE:
160       return VERBOSE;
161     case ANDROID_LOG_DEBUG:
162       return DEBUG;
163     case ANDROID_LOG_INFO:
164       return INFO;
165     case ANDROID_LOG_WARN:
166       return WARNING;
167     case ANDROID_LOG_ERROR:
168       return ERROR;
169     case ANDROID_LOG_FATAL:
170       return FATAL;
171     default:
172       return FATAL;
173   }
174 }
175 
LogSeverityToPriority(LogSeverity severity)176 static int32_t LogSeverityToPriority(LogSeverity severity) {
177   switch (severity) {
178     case VERBOSE:
179       return ANDROID_LOG_VERBOSE;
180     case DEBUG:
181       return ANDROID_LOG_DEBUG;
182     case INFO:
183       return ANDROID_LOG_INFO;
184     case WARNING:
185       return ANDROID_LOG_WARN;
186     case ERROR:
187       return ANDROID_LOG_ERROR;
188     case FATAL_WITHOUT_ABORT:
189     case FATAL:
190     default:
191       return ANDROID_LOG_FATAL;
192   }
193 }
194 
Logger()195 static LogFunction& Logger() {
196 #ifdef __ANDROID__
197   static auto& logger = *new LogFunction(LogdLogger());
198 #else
199   static auto& logger = *new LogFunction(StderrLogger);
200 #endif
201   return logger;
202 }
203 
Aborter()204 static AbortFunction& Aborter() {
205   static auto& aborter = *new AbortFunction(DefaultAborter);
206   return aborter;
207 }
208 
209 // Only used for Q fallback.
TagLock()210 static std::recursive_mutex& TagLock() {
211   static auto& tag_lock = *new std::recursive_mutex();
212   return tag_lock;
213 }
214 // Only used for Q fallback.
215 static std::string* gDefaultTag;
216 
SetDefaultTag(const std::string & tag)217 void SetDefaultTag(const std::string& tag) {
218   if (__builtin_available(android 30, *)) {
219     __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 - PREFIX_MAX| bytes, where
261   // PREFIX_MAX could be 48 or 32.
262   // Reference: kernel/printk/printk.c
263   static constexpr int LOG_LINE_MAX = 1024 - 48;
264   char buf[LOG_LINE_MAX] __attribute__((__uninitialized__));
265   size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %.*s\n", level, tag, length, msg);
266   TEMP_FAILURE_RETRY(write(klog_fd, buf, std::min(size, sizeof(buf))));
267 
268   if (size > sizeof(buf)) {
269     size_t truncated = size - sizeof(buf);
270     size = snprintf(
271         buf, sizeof(buf),
272         "<%d>%s: **previous message missing %zu bytes** %zu-byte message too long for printk\n",
273         level, tag, truncated, size);
274     TEMP_FAILURE_RETRY(write(klog_fd, buf, std::min(size, sizeof(buf))));
275   }
276 }
277 
KernelLogger(android::base::LogId,android::base::LogSeverity severity,const char * tag,const char *,unsigned int,const char * full_message)278 void KernelLogger(android::base::LogId, android::base::LogSeverity severity, const char* tag,
279                   const char*, unsigned int, const char* full_message) {
280   SplitByLines(full_message, KernelLogLine, severity, tag);
281 }
282 #endif
283 
StderrLogger(LogId,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)284 void StderrLogger(LogId, LogSeverity severity, const char* tag, const char* file, unsigned int line,
285                   const char* message) {
286   struct timespec ts;
287   clock_gettime(CLOCK_REALTIME, &ts);
288   auto output_string =
289       StderrOutputGenerator(ts, 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 
TeeLogger(LogFunction && l1,LogFunction && l2)304 LogFunction TeeLogger(LogFunction&& l1, LogFunction&& l2) {
305   return [l1 = std::move(l1), l2 = std::move(l2)](LogId id, LogSeverity severity, const char* tag,
306                                                   const char* file, unsigned int line,
307                                                   const char* message) {
308     l1(id, severity, tag, file, line, message);
309     l2(id, severity, tag, file, line, message);
310   };
311 }
312 
DefaultAborter(const char * abort_message)313 void DefaultAborter(const char* abort_message) {
314 #ifdef __ANDROID__
315   android_set_abort_message(abort_message);
316 #else
317   UNUSED(abort_message);
318 #endif
319   abort();
320 }
321 
LogdLogChunk(LogId id,LogSeverity severity,const char * tag,const char * message)322 static void LogdLogChunk(LogId id, LogSeverity severity, const char* tag, const char* message) {
323   int32_t lg_id = LogIdTolog_id_t(id);
324   int32_t priority = LogSeverityToPriority(severity);
325 
326   if (__builtin_available(android 30, *)) {
327     __android_log_message log_message = {sizeof(__android_log_message),     lg_id, priority, tag,
328                                          static_cast<const char*>(nullptr), 0,     message};
329     __android_log_logd_logger(&log_message);
330   } else {
331     __android_log_buf_print(lg_id, priority, tag, "%s", message);
332   }
333 }
334 
LogdLogger(LogId default_log_id)335 LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) {}
336 
operator ()(LogId id,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)337 void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag, const char* file,
338                             unsigned int line, const char* message) {
339   if (id == DEFAULT) {
340     id = default_log_id_;
341   }
342 
343   SplitByLogdChunks(id, severity, tag, file, line, message, LogdLogChunk);
344 }
345 
InitLogging(char * argv[],LogFunction && logger,AbortFunction && aborter)346 void InitLogging(char* argv[], LogFunction&& logger, AbortFunction&& aborter) {
347   SetLogger(std::forward<LogFunction>(logger));
348   SetAborter(std::forward<AbortFunction>(aborter));
349 
350   if (gInitialized) {
351     return;
352   }
353 
354   gInitialized = true;
355 
356   // Stash the command line for later use. We can use /proc/self/cmdline on
357   // Linux to recover this, but we don't have that luxury on the Mac/Windows,
358   // and there are a couple of argv[0] variants that are commonly used.
359   if (argv != nullptr) {
360     SetDefaultTag(basename(argv[0]));
361   }
362 
363   const char* tags = getenv("ANDROID_LOG_TAGS");
364   if (tags == nullptr) {
365     return;
366   }
367 
368   std::vector<std::string> specs = Split(tags, " ");
369   for (size_t i = 0; i < specs.size(); ++i) {
370     // "tag-pattern:[vdiwefs]"
371     std::string spec(specs[i]);
372     if (spec.size() == 3 && StartsWith(spec, "*:")) {
373       switch (spec[2]) {
374         case 'v':
375           SetMinimumLogSeverity(VERBOSE);
376           continue;
377         case 'd':
378           SetMinimumLogSeverity(DEBUG);
379           continue;
380         case 'i':
381           SetMinimumLogSeverity(INFO);
382           continue;
383         case 'w':
384           SetMinimumLogSeverity(WARNING);
385           continue;
386         case 'e':
387           SetMinimumLogSeverity(ERROR);
388           continue;
389         case 'f':
390           SetMinimumLogSeverity(FATAL_WITHOUT_ABORT);
391           continue;
392         // liblog will even suppress FATAL if you say 's' for silent, but fatal should
393         // never be suppressed.
394         case 's':
395           SetMinimumLogSeverity(FATAL_WITHOUT_ABORT);
396           continue;
397       }
398     }
399     LOG(FATAL) << "unsupported '" << spec << "' in ANDROID_LOG_TAGS (" << tags
400                << ")";
401   }
402 }
403 
SetLogger(LogFunction && logger)404 LogFunction SetLogger(LogFunction&& logger) {
405   LogFunction old_logger = std::move(Logger());
406   Logger() = std::move(logger);
407 
408   if (__builtin_available(android 30, *)) {
409     __android_log_set_logger([](const struct __android_log_message* log_message) {
410       auto log_id = log_id_tToLogId(log_message->buffer_id);
411       auto severity = PriorityToLogSeverity(log_message->priority);
412 
413       Logger()(log_id, severity, log_message->tag, log_message->file, log_message->line,
414                log_message->message);
415     });
416   }
417   return old_logger;
418 }
419 
SetAborter(AbortFunction && aborter)420 AbortFunction SetAborter(AbortFunction&& aborter) {
421   AbortFunction old_aborter = std::move(Aborter());
422   Aborter() = std::move(aborter);
423 
424   if (__builtin_available(android 30, *)) {
425     __android_log_set_aborter([](const char* abort_message) { Aborter()(abort_message); });
426   }
427   return old_aborter;
428 }
429 
430 // This indirection greatly reduces the stack impact of having lots of
431 // checks/logging in a function.
432 class LogMessageData {
433  public:
LogMessageData(const char * file,unsigned int line,LogSeverity severity,const char * tag,int error)434   LogMessageData(const char* file, unsigned int line, LogSeverity severity, const char* tag,
435                  int error)
436       : file_(GetFileBasename(file)),
437         line_number_(line),
438         severity_(severity),
439         tag_(tag),
440         error_(error) {}
441 
GetFile() const442   const char* GetFile() const {
443     return file_;
444   }
445 
GetLineNumber() const446   unsigned int GetLineNumber() const {
447     return line_number_;
448   }
449 
GetSeverity() const450   LogSeverity GetSeverity() const {
451     return severity_;
452   }
453 
GetTag() const454   const char* GetTag() const { return tag_; }
455 
GetError() const456   int GetError() const {
457     return error_;
458   }
459 
GetBuffer()460   std::ostream& GetBuffer() {
461     return buffer_;
462   }
463 
ToString() const464   std::string ToString() const {
465     return buffer_.str();
466   }
467 
468  private:
469   std::ostringstream buffer_;
470   const char* const file_;
471   const unsigned int line_number_;
472   const LogSeverity severity_;
473   const char* const tag_;
474   const int error_;
475 
476   DISALLOW_COPY_AND_ASSIGN(LogMessageData);
477 };
478 
LogMessage(const char * file,unsigned int line,LogId,LogSeverity severity,const char * tag,int error)479 LogMessage::LogMessage(const char* file, unsigned int line, LogId, LogSeverity severity,
480                        const char* tag, int error)
481     : LogMessage(file, line, severity, tag, error) {}
482 
LogMessage(const char * file,unsigned int line,LogSeverity severity,const char * tag,int error)483 LogMessage::LogMessage(const char* file, unsigned int line, LogSeverity severity, const char* tag,
484                        int error)
485     : data_(new LogMessageData(file, line, severity, tag, error)) {}
486 
~LogMessage()487 LogMessage::~LogMessage() {
488   // Check severity again. This is duplicate work wrt/ LOG macros, but not LOG_STREAM.
489   if (!WOULD_LOG(data_->GetSeverity())) {
490     return;
491   }
492 
493   // Finish constructing the message.
494   if (data_->GetError() != -1) {
495     data_->GetBuffer() << ": " << strerror(data_->GetError());
496   }
497   std::string msg(data_->ToString());
498 
499   if (data_->GetSeverity() == FATAL) {
500 #ifdef __ANDROID__
501     // Set the bionic abort message early to avoid liblog doing it
502     // with the individual lines, so that we get the whole message.
503     android_set_abort_message(msg.c_str());
504 #endif
505   }
506 
507   LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetSeverity(), data_->GetTag(),
508           msg.c_str());
509 
510   // Abort if necessary.
511   if (data_->GetSeverity() == FATAL) {
512     if (__builtin_available(android 30, *)) {
513       __android_log_call_aborter(msg.c_str());
514     } else {
515       Aborter()(msg.c_str());
516     }
517   }
518 }
519 
stream()520 std::ostream& LogMessage::stream() {
521   return data_->GetBuffer();
522 }
523 
LogLine(const char * file,unsigned int line,LogSeverity severity,const char * tag,const char * message)524 void LogMessage::LogLine(const char* file, unsigned int line, LogSeverity severity, const char* tag,
525                          const char* message) {
526   int32_t priority = LogSeverityToPriority(severity);
527   if (__builtin_available(android 30, *)) {
528     __android_log_message log_message = {
529         sizeof(__android_log_message), LOG_ID_DEFAULT, priority, tag, file, line, message};
530     __android_log_write_log_message(&log_message);
531   } else {
532     if (tag == nullptr) {
533       std::lock_guard<std::recursive_mutex> lock(TagLock());
534       if (gDefaultTag == nullptr) {
535         gDefaultTag = new std::string(getprogname());
536       }
537 
538       Logger()(DEFAULT, severity, gDefaultTag->c_str(), file, line, message);
539     } else {
540       Logger()(DEFAULT, severity, tag, file, line, message);
541     }
542   }
543 }
544 
GetMinimumLogSeverity()545 LogSeverity GetMinimumLogSeverity() {
546   if (__builtin_available(android 30, *)) {
547     return PriorityToLogSeverity(__android_log_get_minimum_priority());
548   } else {
549     return gMinimumLogSeverity;
550   }
551 }
552 
ShouldLog(LogSeverity severity,const char * tag)553 bool ShouldLog(LogSeverity severity, const char* tag) {
554   // Even though we're not using the R liblog functions in this function, if we're running on Q,
555   // we need to fall back to using gMinimumLogSeverity, since __android_log_is_loggable() will not
556   // take into consideration the value from SetMinimumLogSeverity().
557   if (__builtin_available(android 30, *)) {
558     int32_t priority = LogSeverityToPriority(severity);
559     return __android_log_is_loggable(priority, tag, ANDROID_LOG_INFO);
560   } else {
561     return severity >= gMinimumLogSeverity;
562   }
563 }
564 
SetMinimumLogSeverity(LogSeverity new_severity)565 LogSeverity SetMinimumLogSeverity(LogSeverity new_severity) {
566   if (__builtin_available(android 30, *)) {
567     int32_t priority = LogSeverityToPriority(new_severity);
568     return PriorityToLogSeverity(__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