1 /*
2 * Copyright (C) 2019 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 #include "perfetto/base/logging.h"
18
19 #include <stdarg.h>
20 #include <stdio.h>
21
22 #if !PERFETTO_BUILDFLAG(PERFETTO_OS_WIN)
23 #include <unistd.h> // For isatty()
24 #endif
25
26 #include <atomic>
27 #include <memory>
28
29 #include "perfetto/base/time.h"
30
31 namespace perfetto {
32 namespace base {
33
34 namespace {
35 const char kReset[] = "\x1b[0m";
36 const char kDefault[] = "\x1b[39m";
37 const char kDim[] = "\x1b[2m";
38 const char kRed[] = "\x1b[31m";
39 const char kBoldGreen[] = "\x1b[1m\x1b[32m";
40 const char kLightGray[] = "\x1b[90m";
41
42 std::atomic<LogMessageCallback> g_log_callback{};
43
44 } // namespace
45
SetLogMessageCallback(LogMessageCallback callback)46 void SetLogMessageCallback(LogMessageCallback callback) {
47 g_log_callback.store(callback, std::memory_order_relaxed);
48 }
49
LogMessage(LogLev level,const char * fname,int line,const char * fmt,...)50 void LogMessage(LogLev level,
51 const char* fname,
52 int line,
53 const char* fmt,
54 ...) {
55 char stack_buf[512];
56 std::unique_ptr<char[]> large_buf;
57 char* log_msg = &stack_buf[0];
58
59 // By default use a stack allocated buffer because most log messages are quite
60 // short. In rare cases they can be larger (e.g. --help). In those cases we
61 // pay the cost of allocating the buffer on the heap.
62 for (size_t max_len = sizeof(stack_buf);;) {
63 va_list args;
64 va_start(args, fmt);
65 int res = vsnprintf(log_msg, max_len, fmt, args);
66 va_end(args);
67
68 // If for any reason the print fails, overwrite the message but still print
69 // it. The code below will attach the filename and line, which is still
70 // useful.
71 if (res < 0) {
72 strncpy(log_msg, "[printf format error]", max_len);
73 break;
74 }
75
76 // if res == max_len, vsnprintf saturated the input buffer. Retry with a
77 // larger buffer in that case (within reasonable limits).
78 if (res < static_cast<int>(max_len) || max_len >= 128 * 1024)
79 break;
80 max_len *= 4;
81 large_buf.reset(new char[max_len]);
82 log_msg = &large_buf[0];
83 }
84
85 LogMessageCallback cb = g_log_callback.load(std::memory_order_relaxed);
86 if (cb) {
87 cb({level, line, fname, log_msg});
88 return;
89 }
90
91 const char* color = kDefault;
92 switch (level) {
93 case kLogDebug:
94 color = kDim;
95 break;
96 case kLogInfo:
97 color = kDefault;
98 break;
99 case kLogImportant:
100 color = kBoldGreen;
101 break;
102 case kLogError:
103 color = kRed;
104 break;
105 }
106
107 #if !PERFETTO_BUILDFLAG(PERFETTO_OS_WIN) && \
108 !PERFETTO_BUILDFLAG(PERFETTO_OS_WASM)
109 static const bool use_colors = isatty(STDERR_FILENO);
110 #else
111 static const bool use_colors = false;
112 #endif
113
114 // Formats file.cc:line as a space-padded fixed width string. If the file name
115 // |fname| is too long, truncate it on the left-hand side.
116 char line_str[10];
117 size_t line_len =
118 static_cast<size_t>(snprintf(line_str, sizeof(line_str), "%d", line));
119
120 // 24 will be the width of the file.cc:line column in the log event.
121 char file_and_line[24];
122 size_t fname_len = strlen(fname);
123 size_t fname_max = sizeof(file_and_line) - line_len - 2; // 2 = ':' + '\0'.
124 size_t fname_offset = fname_len <= fname_max ? 0 : fname_len - fname_max;
125 int len = snprintf(file_and_line, sizeof(file_and_line), "%s:%s",
126 fname + fname_offset, line_str);
127 memset(&file_and_line[len], ' ', sizeof(file_and_line) - size_t(len));
128 file_and_line[sizeof(file_and_line) - 1] = '\0';
129
130 #if PERFETTO_BUILDFLAG(PERFETTO_OS_ANDROID)
131 // Logcat has already timestamping, don't re-emit it.
132 __android_log_print(ANDROID_LOG_DEBUG + level, "perfetto", "%s %s",
133 file_and_line, log_msg);
134 #endif
135
136 // When printing on stderr, print also the timestamp. We don't really care
137 // about the actual time. We just need some reference clock that can be used
138 // to correlated events across differrent processses (e.g. traced and
139 // traced_probes). The wall time % 1000 is good enough.
140 char timestamp[32];
141 uint32_t t_ms = static_cast<uint32_t>(GetWallTimeMs().count());
142 uint32_t t_sec = t_ms / 1000;
143 t_ms -= t_sec * 1000;
144 t_sec = t_sec % 1000;
145 snprintf(timestamp, sizeof(timestamp), "[%03u.%03u] ", t_sec, t_ms);
146
147 if (use_colors) {
148 fprintf(stderr, "%s%s%s%s %s%s%s\n", kLightGray, timestamp, file_and_line,
149 kReset, color, log_msg, kReset);
150 } else {
151 fprintf(stderr, "%s%s %s\n", timestamp, file_and_line, log_msg);
152 }
153 }
154
155 } // namespace base
156 } // namespace perfetto
157