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 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__) 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 121 static std::mutex& LoggingLock() { 122 static auto& logging_lock = *new std::mutex(); 123 return logging_lock; 124 } 125 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 135 static AbortFunction& Aborter() { 136 static auto& aborter = *new AbortFunction(DefaultAborter); 137 return aborter; 138 } 139 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__) 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 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 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__ 221 LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) { 222 } 223 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 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 315 void SetLogger(LogFunction&& logger) { 316 std::lock_guard<std::mutex> lock(LoggingLock()); 317 Logger() = std::move(logger); 318 } 319 320 void SetAborter(AbortFunction&& aborter) { 321 std::lock_guard<std::mutex> lock(LoggingLock()); 322 Aborter() = std::move(aborter); 323 } 324 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: 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 354 const char* GetFile() const { 355 return file_; 356 } 357 358 unsigned int GetLineNumber() const { 359 return line_number_; 360 } 361 362 LogSeverity GetSeverity() const { 363 return severity_; 364 } 365 366 LogId GetId() const { 367 return id_; 368 } 369 370 int GetError() const { 371 return error_; 372 } 373 374 std::ostream& GetBuffer() { 375 return buffer_; 376 } 377 378 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 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 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 437 std::ostream& LogMessage::stream() { 438 return data_->GetBuffer(); 439 } 440 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 447 LogSeverity GetMinimumLogSeverity() { 448 return gMinimumLogSeverity; 449 } 450 451 LogSeverity SetMinimumLogSeverity(LogSeverity new_severity) { 452 LogSeverity old_severity = gMinimumLogSeverity; 453 gMinimumLogSeverity = new_severity; 454 return old_severity; 455 } 456 457 ScopedLogSeverity::ScopedLogSeverity(LogSeverity new_severity) { 458 old_ = SetMinimumLogSeverity(new_severity); 459 } 460 461 ScopedLogSeverity::~ScopedLogSeverity() { 462 SetMinimumLogSeverity(old_); 463 } 464 465 } // namespace base 466 } // namespace android 467