• 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 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