• 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 #if defined(__linux__)
36 #include <sys/uio.h>
37 #endif
38 
39 #include <iostream>
40 #include <limits>
41 #include <mutex>
42 #include <sstream>
43 #include <string>
44 #include <utility>
45 #include <vector>
46 
47 // Headers for LogMessage::LogLine.
48 #ifdef __ANDROID__
49 #include <android/log.h>
50 #include <android/set_abort_message.h>
51 #else
52 #include <sys/types.h>
53 #include <unistd.h>
54 #endif
55 
56 #include <android-base/file.h>
57 #include <android-base/macros.h>
58 #include <android-base/parseint.h>
59 #include <android-base/strings.h>
60 #include <android-base/threads.h>
61 
62 namespace android {
63 namespace base {
64 
65 // BSD-based systems like Android/macOS have getprogname(). Others need us to provide one.
66 #if defined(__GLIBC__) || defined(_WIN32)
getprogname()67 static const char* getprogname() {
68 #if defined(__GLIBC__)
69   return program_invocation_short_name;
70 #elif defined(_WIN32)
71   static bool first = true;
72   static char progname[MAX_PATH] = {};
73 
74   if (first) {
75     snprintf(progname, sizeof(progname), "%s",
76              android::base::Basename(android::base::GetExecutablePath()).c_str());
77     first = false;
78   }
79 
80   return progname;
81 #endif
82 }
83 #endif
84 
GetFileBasename(const char * file)85 static const char* GetFileBasename(const char* file) {
86   // We can't use basename(3) even on Unix because the Mac doesn't
87   // have a non-modifying basename.
88   const char* last_slash = strrchr(file, '/');
89   if (last_slash != nullptr) {
90     return last_slash + 1;
91   }
92 #if defined(_WIN32)
93   const char* last_backslash = strrchr(file, '\\');
94   if (last_backslash != nullptr) {
95     return last_backslash + 1;
96   }
97 #endif
98   return file;
99 }
100 
101 #if defined(__linux__)
OpenKmsg()102 static int OpenKmsg() {
103 #if defined(__ANDROID__)
104   // pick up 'file w /dev/kmsg' environment from daemon's init rc file
105   const auto val = getenv("ANDROID_FILE__dev_kmsg");
106   if (val != nullptr) {
107     int fd;
108     if (android::base::ParseInt(val, &fd, 0)) {
109       auto flags = fcntl(fd, F_GETFL);
110       if ((flags != -1) && ((flags & O_ACCMODE) == O_WRONLY)) return fd;
111     }
112   }
113 #endif
114   return TEMP_FAILURE_RETRY(open("/dev/kmsg", O_WRONLY | O_CLOEXEC));
115 }
116 #endif
117 
LoggingLock()118 static std::mutex& LoggingLock() {
119   static auto& logging_lock = *new std::mutex();
120   return logging_lock;
121 }
122 
Logger()123 static LogFunction& Logger() {
124 #ifdef __ANDROID__
125   static auto& logger = *new LogFunction(LogdLogger());
126 #else
127   static auto& logger = *new LogFunction(StderrLogger);
128 #endif
129   return logger;
130 }
131 
Aborter()132 static AbortFunction& Aborter() {
133   static auto& aborter = *new AbortFunction(DefaultAborter);
134   return aborter;
135 }
136 
TagLock()137 static std::recursive_mutex& TagLock() {
138   static auto& tag_lock = *new std::recursive_mutex();
139   return tag_lock;
140 }
141 static std::string* gDefaultTag;
GetDefaultTag()142 std::string GetDefaultTag() {
143   std::lock_guard<std::recursive_mutex> lock(TagLock());
144   if (gDefaultTag == nullptr) {
145     return "";
146   }
147   return *gDefaultTag;
148 }
SetDefaultTag(const std::string & tag)149 void SetDefaultTag(const std::string& tag) {
150   std::lock_guard<std::recursive_mutex> lock(TagLock());
151   if (gDefaultTag != nullptr) {
152     delete gDefaultTag;
153     gDefaultTag = nullptr;
154   }
155   if (!tag.empty()) {
156     gDefaultTag = new std::string(tag);
157   }
158 }
159 
160 static bool gInitialized = false;
161 static LogSeverity gMinimumLogSeverity = INFO;
162 
163 #if defined(__linux__)
KernelLogger(android::base::LogId,android::base::LogSeverity severity,const char * tag,const char *,unsigned int,const char * msg)164 void KernelLogger(android::base::LogId, android::base::LogSeverity severity,
165                   const char* tag, const char*, unsigned int, const char* msg) {
166   // clang-format off
167   static constexpr int kLogSeverityToKernelLogLevel[] = {
168       [android::base::VERBOSE] = 7,              // KERN_DEBUG (there is no verbose kernel log
169                                                  //             level)
170       [android::base::DEBUG] = 7,                // KERN_DEBUG
171       [android::base::INFO] = 6,                 // KERN_INFO
172       [android::base::WARNING] = 4,              // KERN_WARNING
173       [android::base::ERROR] = 3,                // KERN_ERROR
174       [android::base::FATAL_WITHOUT_ABORT] = 2,  // KERN_CRIT
175       [android::base::FATAL] = 2,                // KERN_CRIT
176   };
177   // clang-format on
178   static_assert(arraysize(kLogSeverityToKernelLogLevel) == android::base::FATAL + 1,
179                 "Mismatch in size of kLogSeverityToKernelLogLevel and values in LogSeverity");
180 
181   static int klog_fd = OpenKmsg();
182   if (klog_fd == -1) return;
183 
184   int level = kLogSeverityToKernelLogLevel[severity];
185 
186   // The kernel's printk buffer is only 1024 bytes.
187   // TODO: should we automatically break up long lines into multiple lines?
188   // Or we could log but with something like "..." at the end?
189   char buf[1024];
190   size_t size = snprintf(buf, sizeof(buf), "<%d>%s: %s\n", level, tag, msg);
191   if (size > sizeof(buf)) {
192     size = snprintf(buf, sizeof(buf), "<%d>%s: %zu-byte message too long for printk\n",
193                     level, tag, size);
194   }
195 
196   iovec iov[1];
197   iov[0].iov_base = buf;
198   iov[0].iov_len = size;
199   TEMP_FAILURE_RETRY(writev(klog_fd, iov, 1));
200 }
201 #endif
202 
StderrLogger(LogId,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)203 void StderrLogger(LogId, LogSeverity severity, const char* tag, const char* file, unsigned int line,
204                   const char* message) {
205   struct tm now;
206   time_t t = time(nullptr);
207 
208 #if defined(_WIN32)
209   localtime_s(&now, &t);
210 #else
211   localtime_r(&t, &now);
212 #endif
213 
214   char timestamp[32];
215   strftime(timestamp, sizeof(timestamp), "%m-%d %H:%M:%S", &now);
216 
217   static const char log_characters[] = "VDIWEFF";
218   static_assert(arraysize(log_characters) - 1 == FATAL + 1,
219                 "Mismatch in size of log_characters and values in LogSeverity");
220   char severity_char = log_characters[severity];
221   fprintf(stderr, "%s %c %s %5d %5" PRIu64 " %s:%u] %s\n", tag ? tag : "nullptr", severity_char,
222           timestamp, getpid(), GetThreadId(), file, line, message);
223 }
224 
StdioLogger(LogId,LogSeverity severity,const char *,const char *,unsigned int,const char * message)225 void StdioLogger(LogId, LogSeverity severity, const char* /*tag*/, const char* /*file*/,
226                  unsigned int /*line*/, const char* message) {
227   if (severity >= WARNING) {
228     fflush(stdout);
229     fprintf(stderr, "%s: %s\n", GetFileBasename(getprogname()), message);
230   } else {
231     fprintf(stdout, "%s\n", message);
232   }
233 }
234 
DefaultAborter(const char * abort_message)235 void DefaultAborter(const char* abort_message) {
236 #ifdef __ANDROID__
237   android_set_abort_message(abort_message);
238 #else
239   UNUSED(abort_message);
240 #endif
241   abort();
242 }
243 
244 
245 #ifdef __ANDROID__
LogdLogger(LogId default_log_id)246 LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) {
247 }
248 
operator ()(LogId id,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)249 void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag,
250                             const char* file, unsigned int line,
251                             const char* message) {
252   static constexpr android_LogPriority kLogSeverityToAndroidLogPriority[] = {
253       ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO,
254       ANDROID_LOG_WARN,    ANDROID_LOG_ERROR, ANDROID_LOG_FATAL,
255       ANDROID_LOG_FATAL,
256   };
257   static_assert(arraysize(kLogSeverityToAndroidLogPriority) == FATAL + 1,
258                 "Mismatch in size of kLogSeverityToAndroidLogPriority and values in LogSeverity");
259 
260   int priority = kLogSeverityToAndroidLogPriority[severity];
261   if (id == DEFAULT) {
262     id = default_log_id_;
263   }
264 
265   static constexpr log_id kLogIdToAndroidLogId[] = {
266     LOG_ID_MAX, LOG_ID_MAIN, LOG_ID_SYSTEM,
267   };
268   static_assert(arraysize(kLogIdToAndroidLogId) == SYSTEM + 1,
269                 "Mismatch in size of kLogIdToAndroidLogId and values in LogId");
270   log_id lg_id = kLogIdToAndroidLogId[id];
271 
272   if (priority == ANDROID_LOG_FATAL) {
273     __android_log_buf_print(lg_id, priority, tag, "%s:%u] %s", file, line,
274                             message);
275   } else {
276     __android_log_buf_print(lg_id, priority, tag, "%s", message);
277   }
278 }
279 #endif
280 
InitLogging(char * argv[],LogFunction && logger,AbortFunction && aborter)281 void InitLogging(char* argv[], LogFunction&& logger, AbortFunction&& aborter) {
282   SetLogger(std::forward<LogFunction>(logger));
283   SetAborter(std::forward<AbortFunction>(aborter));
284 
285   if (gInitialized) {
286     return;
287   }
288 
289   gInitialized = true;
290 
291   // Stash the command line for later use. We can use /proc/self/cmdline on
292   // Linux to recover this, but we don't have that luxury on the Mac/Windows,
293   // and there are a couple of argv[0] variants that are commonly used.
294   if (argv != nullptr) {
295     SetDefaultTag(basename(argv[0]));
296   }
297 
298   const char* tags = getenv("ANDROID_LOG_TAGS");
299   if (tags == nullptr) {
300     return;
301   }
302 
303   std::vector<std::string> specs = Split(tags, " ");
304   for (size_t i = 0; i < specs.size(); ++i) {
305     // "tag-pattern:[vdiwefs]"
306     std::string spec(specs[i]);
307     if (spec.size() == 3 && StartsWith(spec, "*:")) {
308       switch (spec[2]) {
309         case 'v':
310           gMinimumLogSeverity = VERBOSE;
311           continue;
312         case 'd':
313           gMinimumLogSeverity = DEBUG;
314           continue;
315         case 'i':
316           gMinimumLogSeverity = INFO;
317           continue;
318         case 'w':
319           gMinimumLogSeverity = WARNING;
320           continue;
321         case 'e':
322           gMinimumLogSeverity = ERROR;
323           continue;
324         case 'f':
325           gMinimumLogSeverity = FATAL_WITHOUT_ABORT;
326           continue;
327         // liblog will even suppress FATAL if you say 's' for silent, but that's
328         // crazy!
329         case 's':
330           gMinimumLogSeverity = FATAL_WITHOUT_ABORT;
331           continue;
332       }
333     }
334     LOG(FATAL) << "unsupported '" << spec << "' in ANDROID_LOG_TAGS (" << tags
335                << ")";
336   }
337 }
338 
SetLogger(LogFunction && logger)339 void SetLogger(LogFunction&& logger) {
340   std::lock_guard<std::mutex> lock(LoggingLock());
341   Logger() = std::move(logger);
342 }
343 
SetAborter(AbortFunction && aborter)344 void SetAborter(AbortFunction&& aborter) {
345   std::lock_guard<std::mutex> lock(LoggingLock());
346   Aborter() = std::move(aborter);
347 }
348 
349 // This indirection greatly reduces the stack impact of having lots of
350 // checks/logging in a function.
351 class LogMessageData {
352  public:
LogMessageData(const char * file,unsigned int line,LogId id,LogSeverity severity,const char * tag,int error)353   LogMessageData(const char* file, unsigned int line, LogId id, LogSeverity severity,
354                  const char* tag, int error)
355       : file_(GetFileBasename(file)),
356         line_number_(line),
357         id_(id),
358         severity_(severity),
359         tag_(tag),
360         error_(error) {}
361 
GetFile() const362   const char* GetFile() const {
363     return file_;
364   }
365 
GetLineNumber() const366   unsigned int GetLineNumber() const {
367     return line_number_;
368   }
369 
GetSeverity() const370   LogSeverity GetSeverity() const {
371     return severity_;
372   }
373 
GetTag() const374   const char* GetTag() const { return tag_; }
375 
GetId() const376   LogId GetId() const {
377     return id_;
378   }
379 
GetError() const380   int GetError() const {
381     return error_;
382   }
383 
GetBuffer()384   std::ostream& GetBuffer() {
385     return buffer_;
386   }
387 
ToString() const388   std::string ToString() const {
389     return buffer_.str();
390   }
391 
392  private:
393   std::ostringstream buffer_;
394   const char* const file_;
395   const unsigned int line_number_;
396   const LogId id_;
397   const LogSeverity severity_;
398   const char* const tag_;
399   const int error_;
400 
401   DISALLOW_COPY_AND_ASSIGN(LogMessageData);
402 };
403 
LogMessage(const char * file,unsigned int line,LogId id,LogSeverity severity,const char * tag,int error)404 LogMessage::LogMessage(const char* file, unsigned int line, LogId id, LogSeverity severity,
405                        const char* tag, int error)
406     : data_(new LogMessageData(file, line, id, severity, tag, error)) {}
407 
~LogMessage()408 LogMessage::~LogMessage() {
409   // Check severity again. This is duplicate work wrt/ LOG macros, but not LOG_STREAM.
410   if (!WOULD_LOG(data_->GetSeverity())) {
411     return;
412   }
413 
414   // Finish constructing the message.
415   if (data_->GetError() != -1) {
416     data_->GetBuffer() << ": " << strerror(data_->GetError());
417   }
418   std::string msg(data_->ToString());
419 
420   if (data_->GetSeverity() == FATAL) {
421 #ifdef __ANDROID__
422     // Set the bionic abort message early to avoid liblog doing it
423     // with the individual lines, so that we get the whole message.
424     android_set_abort_message(msg.c_str());
425 #endif
426   }
427 
428   {
429     // Do the actual logging with the lock held.
430     std::lock_guard<std::mutex> lock(LoggingLock());
431     if (msg.find('\n') == std::string::npos) {
432       LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetId(), data_->GetSeverity(),
433               data_->GetTag(), msg.c_str());
434     } else {
435       msg += '\n';
436       size_t i = 0;
437       while (i < msg.size()) {
438         size_t nl = msg.find('\n', i);
439         msg[nl] = '\0';
440         LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetId(), data_->GetSeverity(),
441                 data_->GetTag(), &msg[i]);
442         // Undo the zero-termination so we can give the complete message to the aborter.
443         msg[nl] = '\n';
444         i = nl + 1;
445       }
446     }
447   }
448 
449   // Abort if necessary.
450   if (data_->GetSeverity() == FATAL) {
451     Aborter()(msg.c_str());
452   }
453 }
454 
stream()455 std::ostream& LogMessage::stream() {
456   return data_->GetBuffer();
457 }
458 
LogLine(const char * file,unsigned int line,LogId id,LogSeverity severity,const char * tag,const char * message)459 void LogMessage::LogLine(const char* file, unsigned int line, LogId id, LogSeverity severity,
460                          const char* tag, const char* message) {
461   if (tag == nullptr) {
462     std::lock_guard<std::recursive_mutex> lock(TagLock());
463     if (gDefaultTag == nullptr) {
464       gDefaultTag = new std::string(getprogname());
465     }
466     Logger()(id, severity, gDefaultTag->c_str(), file, line, message);
467   } else {
468     Logger()(id, severity, tag, file, line, message);
469   }
470 }
471 
GetMinimumLogSeverity()472 LogSeverity GetMinimumLogSeverity() {
473     return gMinimumLogSeverity;
474 }
475 
SetMinimumLogSeverity(LogSeverity new_severity)476 LogSeverity SetMinimumLogSeverity(LogSeverity new_severity) {
477   LogSeverity old_severity = gMinimumLogSeverity;
478   gMinimumLogSeverity = new_severity;
479   return old_severity;
480 }
481 
ScopedLogSeverity(LogSeverity new_severity)482 ScopedLogSeverity::ScopedLogSeverity(LogSeverity new_severity) {
483   old_ = SetMinimumLogSeverity(new_severity);
484 }
485 
~ScopedLogSeverity()486 ScopedLogSeverity::~ScopedLogSeverity() {
487   SetMinimumLogSeverity(old_);
488 }
489 
490 }  // namespace base
491 }  // namespace android
492