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