logging.cpp revision 26f2e1fd4ff02cb8a3927c86a90656269ebcb412 
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#ifdef _WIN32
18#include <windows.h>
19#endif
20
21#include "base/logging.h"
22
23#include <libgen.h>
24
25// For getprogname(3) or program_invocation_short_name.
26#if defined(__ANDROID__) || defined(__APPLE__)
27#include <stdlib.h>
28#elif defined(__GLIBC__)
29#include <errno.h>
30#endif
31
32#include <iostream>
33#include <limits>
34#include <sstream>
35#include <string>
36#include <utility>
37#include <vector>
38
39#ifndef _WIN32
40#include <mutex>
41#endif
42
43#include "base/macros.h"
44#include "base/strings.h"
45#include "cutils/threads.h"
46
47// Headers for LogMessage::LogLine.
48#ifdef __ANDROID__
49#include <android/set_abort_message.h>
50#include "cutils/log.h"
51#else
52#include <sys/types.h>
53#include <unistd.h>
54#endif
55
56// For gettid.
57#if defined(__APPLE__)
58#include "AvailabilityMacros.h"  // For MAC_OS_X_VERSION_MAX_ALLOWED
59#include <stdint.h>
60#include <stdlib.h>
61#include <sys/syscall.h>
62#include <sys/time.h>
63#include <unistd.h>
64#elif defined(__linux__) && !defined(__ANDROID__)
65#include <syscall.h>
66#include <unistd.h>
67#elif defined(_WIN32)
68#include <windows.h>
69#endif
70
71static pid_t GetThreadId() {
72#if defined(__BIONIC__)
73  return gettid();
74#elif defined(__APPLE__)
75  return syscall(SYS_thread_selfid);
76#elif defined(__linux__)
77  return syscall(__NR_gettid);
78#elif defined(_WIN32)
79  return GetCurrentThreadId();
80#endif
81}
82
83namespace {
84#ifndef _WIN32
85using std::mutex;
86using std::lock_guard;
87
88#if defined(__GLIBC__)
89const char* getprogname() {
90  return program_invocation_short_name;
91}
92#endif
93
94#else
95const char* getprogname() {
96  static bool first = true;
97  static char progname[MAX_PATH] = {};
98
99  if (first) {
100    CHAR longname[MAX_PATH];
101    DWORD nchars = GetModuleFileNameA(nullptr, longname, arraysize(longname));
102    if ((nchars >= arraysize(longname)) || (nchars == 0)) {
103      // String truncation or some other error.
104      strcpy(progname, "<unknown>");
105    } else {
106      strcpy(progname, basename(longname));
107    }
108    first = false;
109  }
110
111  return progname;
112}
113
114class mutex {
115 public:
116  mutex() {
117    InitializeCriticalSection(&critical_section_);
118  }
119  ~mutex() {
120    DeleteCriticalSection(&critical_section_);
121  }
122
123  void lock() {
124    EnterCriticalSection(&critical_section_);
125  }
126
127  void unlock() {
128    LeaveCriticalSection(&critical_section_);
129  }
130
131 private:
132  CRITICAL_SECTION critical_section_;
133};
134
135template <typename LockT>
136class lock_guard {
137 public:
138  explicit lock_guard(LockT& lock) : lock_(lock) {
139    lock_.lock();
140  }
141
142  ~lock_guard() {
143    lock_.unlock();
144  }
145
146 private:
147  LockT& lock_;
148
149  DISALLOW_COPY_AND_ASSIGN(lock_guard);
150};
151#endif
152} // namespace
153
154namespace android {
155namespace base {
156
157static auto& logging_lock = *new mutex();
158
159#ifdef __ANDROID__
160static auto& gLogger = *new LogFunction(LogdLogger());
161#else
162static auto& gLogger = *new LogFunction(StderrLogger);
163#endif
164
165static bool gInitialized = false;
166static LogSeverity gMinimumLogSeverity = INFO;
167static auto& gProgramInvocationName = *new std::unique_ptr<std::string>();
168
169LogSeverity GetMinimumLogSeverity() {
170  return gMinimumLogSeverity;
171}
172
173static const char* ProgramInvocationName() {
174  if (gProgramInvocationName == nullptr) {
175    gProgramInvocationName.reset(new std::string(getprogname()));
176  }
177
178  return gProgramInvocationName->c_str();
179}
180
181void StderrLogger(LogId, LogSeverity severity, const char*, const char* file,
182                  unsigned int line, const char* message) {
183  static const char log_characters[] = "VDIWEF";
184  static_assert(arraysize(log_characters) - 1 == FATAL + 1,
185                "Mismatch in size of log_characters and values in LogSeverity");
186  char severity_char = log_characters[severity];
187  fprintf(stderr, "%s %c %5d %5d %s:%u] %s\n", ProgramInvocationName(),
188          severity_char, getpid(), GetThreadId(), file, line, message);
189}
190
191
192#ifdef __ANDROID__
193LogdLogger::LogdLogger(LogId default_log_id) : default_log_id_(default_log_id) {
194}
195
196static const android_LogPriority kLogSeverityToAndroidLogPriority[] = {
197    ANDROID_LOG_VERBOSE, ANDROID_LOG_DEBUG, ANDROID_LOG_INFO,
198    ANDROID_LOG_WARN,    ANDROID_LOG_ERROR, ANDROID_LOG_FATAL,
199};
200static_assert(arraysize(kLogSeverityToAndroidLogPriority) == FATAL + 1,
201              "Mismatch in size of kLogSeverityToAndroidLogPriority and values "
202              "in LogSeverity");
203
204static const log_id kLogIdToAndroidLogId[] = {
205    LOG_ID_MAX, LOG_ID_MAIN, LOG_ID_SYSTEM,
206};
207static_assert(arraysize(kLogIdToAndroidLogId) == SYSTEM + 1,
208              "Mismatch in size of kLogIdToAndroidLogId and values in LogId");
209
210void LogdLogger::operator()(LogId id, LogSeverity severity, const char* tag,
211                            const char* file, unsigned int line,
212                            const char* message) {
213  int priority = kLogSeverityToAndroidLogPriority[severity];
214  if (id == DEFAULT) {
215    id = default_log_id_;
216  }
217
218  log_id lg_id = kLogIdToAndroidLogId[id];
219
220  if (priority == ANDROID_LOG_FATAL) {
221    __android_log_buf_print(lg_id, priority, tag, "%s:%u] %s", file, line,
222                            message);
223  } else {
224    __android_log_buf_print(lg_id, priority, tag, "%s", message);
225  }
226}
227#endif
228
229void InitLogging(char* argv[], LogFunction&& logger) {
230  SetLogger(std::forward<LogFunction>(logger));
231  InitLogging(argv);
232}
233
234void InitLogging(char* argv[]) {
235  if (gInitialized) {
236    return;
237  }
238
239  gInitialized = true;
240
241  // Stash the command line for later use. We can use /proc/self/cmdline on
242  // Linux to recover this, but we don't have that luxury on the Mac/Windows,
243  // and there are a couple of argv[0] variants that are commonly used.
244  if (argv != nullptr) {
245    gProgramInvocationName.reset(new std::string(basename(argv[0])));
246  }
247
248  const char* tags = getenv("ANDROID_LOG_TAGS");
249  if (tags == nullptr) {
250    return;
251  }
252
253  std::vector<std::string> specs = Split(tags, " ");
254  for (size_t i = 0; i < specs.size(); ++i) {
255    // "tag-pattern:[vdiwefs]"
256    std::string spec(specs[i]);
257    if (spec.size() == 3 && StartsWith(spec, "*:")) {
258      switch (spec[2]) {
259        case 'v':
260          gMinimumLogSeverity = VERBOSE;
261          continue;
262        case 'd':
263          gMinimumLogSeverity = DEBUG;
264          continue;
265        case 'i':
266          gMinimumLogSeverity = INFO;
267          continue;
268        case 'w':
269          gMinimumLogSeverity = WARNING;
270          continue;
271        case 'e':
272          gMinimumLogSeverity = ERROR;
273          continue;
274        case 'f':
275          gMinimumLogSeverity = FATAL;
276          continue;
277        // liblog will even suppress FATAL if you say 's' for silent, but that's
278        // crazy!
279        case 's':
280          gMinimumLogSeverity = FATAL;
281          continue;
282      }
283    }
284    LOG(FATAL) << "unsupported '" << spec << "' in ANDROID_LOG_TAGS (" << tags
285               << ")";
286  }
287}
288
289void SetLogger(LogFunction&& logger) {
290  lock_guard<mutex> lock(logging_lock);
291  gLogger = std::move(logger);
292}
293
294static const char* GetFileBasename(const char* file) {
295  // We can't use basename(3) even on Unix because the Mac doesn't
296  // have a non-modifying basename.
297  const char* last_slash = strrchr(file, '/');
298  if (last_slash != nullptr) {
299    return last_slash + 1;
300  }
301#if defined(_WIN32)
302  const char* last_backslash = strrchr(file, '\\');
303  if (last_backslash != nullptr) {
304    return last_backslash + 1;
305  }
306#endif
307  return file;
308}
309
310// This indirection greatly reduces the stack impact of having lots of
311// checks/logging in a function.
312class LogMessageData {
313 public:
314  LogMessageData(const char* file, unsigned int line, LogId id,
315                 LogSeverity severity, int error)
316      : file_(GetFileBasename(file)),
317        line_number_(line),
318        id_(id),
319        severity_(severity),
320        error_(error) {
321  }
322
323  const char* GetFile() const {
324    return file_;
325  }
326
327  unsigned int GetLineNumber() const {
328    return line_number_;
329  }
330
331  LogSeverity GetSeverity() const {
332    return severity_;
333  }
334
335  LogId GetId() const {
336    return id_;
337  }
338
339  int GetError() const {
340    return error_;
341  }
342
343  std::ostream& GetBuffer() {
344    return buffer_;
345  }
346
347  std::string ToString() const {
348    return buffer_.str();
349  }
350
351 private:
352  std::ostringstream buffer_;
353  const char* const file_;
354  const unsigned int line_number_;
355  const LogId id_;
356  const LogSeverity severity_;
357  const int error_;
358
359  DISALLOW_COPY_AND_ASSIGN(LogMessageData);
360};
361
362LogMessage::LogMessage(const char* file, unsigned int line, LogId id,
363                       LogSeverity severity, int error)
364    : data_(new LogMessageData(file, line, id, severity, error)) {
365}
366
367LogMessage::~LogMessage() {
368  // Finish constructing the message.
369  if (data_->GetError() != -1) {
370    data_->GetBuffer() << ": " << strerror(data_->GetError());
371  }
372  std::string msg(data_->ToString());
373
374  {
375    // Do the actual logging with the lock held.
376    lock_guard<mutex> lock(logging_lock);
377    if (msg.find('\n') == std::string::npos) {
378      LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetId(),
379              data_->GetSeverity(), msg.c_str());
380    } else {
381      msg += '\n';
382      size_t i = 0;
383      while (i < msg.size()) {
384        size_t nl = msg.find('\n', i);
385        msg[nl] = '\0';
386        LogLine(data_->GetFile(), data_->GetLineNumber(), data_->GetId(),
387                data_->GetSeverity(), &msg[i]);
388        i = nl + 1;
389      }
390    }
391  }
392
393  // Abort if necessary.
394  if (data_->GetSeverity() == FATAL) {
395#ifdef __ANDROID__
396    android_set_abort_message(msg.c_str());
397#endif
398    abort();
399  }
400}
401
402std::ostream& LogMessage::stream() {
403  return data_->GetBuffer();
404}
405
406void LogMessage::LogLine(const char* file, unsigned int line, LogId id,
407                         LogSeverity severity, const char* message) {
408  const char* tag = ProgramInvocationName();
409  gLogger(id, severity, tag, file, line, message);
410}
411
412ScopedLogSeverity::ScopedLogSeverity(LogSeverity level) {
413  old_ = gMinimumLogSeverity;
414  gMinimumLogSeverity = level;
415}
416
417ScopedLogSeverity::~ScopedLogSeverity() {
418  gMinimumLogSeverity = old_;
419}
420
421}  // namespace base
422}  // namespace android
423