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