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