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