1 //
2 // Copyright (C) 2020 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 #include "tee_logging.h"
17
18 #include <fcntl.h>
19 #include <string.h>
20 #include <unistd.h>
21
22 #include <cinttypes>
23 #include <cstring>
24 #include <ctime>
25 #include <memory>
26 #include <ostream>
27 #include <sstream>
28 #include <string>
29 #include <utility>
30 #include <vector>
31
32 #include <android-base/logging.h>
33 #include <android-base/macros.h>
34 #include <android-base/stringprintf.h>
35 #include <android-base/strings.h>
36 #include <android-base/threads.h>
37
38 #include "common/libs/fs/shared_buf.h"
39 #include "common/libs/utils/environment.h"
40
41 using android::base::GetThreadId;
42 using android::base::FATAL;
43 using android::base::LogSeverity;
44 using android::base::StringPrintf;
45
46 namespace cuttlefish {
47
GuessSeverity(const std::string & env_var,LogSeverity default_value)48 static LogSeverity GuessSeverity(
49 const std::string& env_var, LogSeverity default_value) {
50 using android::base::VERBOSE;
51 using android::base::DEBUG;
52 using android::base::INFO;
53 using android::base::WARNING;
54 using android::base::ERROR;
55 using android::base::FATAL_WITHOUT_ABORT;
56 using android::base::FATAL;
57 std::string env_value = StringFromEnv(env_var, "");
58 using android::base::EqualsIgnoreCase;
59 if (EqualsIgnoreCase(env_value, "VERBOSE")
60 || env_value == std::to_string((int) VERBOSE)) {
61 return VERBOSE;
62 } else if (EqualsIgnoreCase(env_value, "DEBUG")
63 || env_value == std::to_string((int) DEBUG)) {
64 return DEBUG;
65 } else if (EqualsIgnoreCase(env_value, "INFO")
66 || env_value == std::to_string((int) INFO)) {
67 return INFO;
68 } else if (EqualsIgnoreCase(env_value, "WARNING")
69 || env_value == std::to_string((int) WARNING)) {
70 return WARNING;
71 } else if (EqualsIgnoreCase(env_value, "ERROR")
72 || env_value == std::to_string((int) ERROR)) {
73 return ERROR;
74 } else if (EqualsIgnoreCase(env_value, "FATAL_WITHOUT_ABORT")
75 || env_value == std::to_string((int) FATAL_WITHOUT_ABORT)) {
76 return FATAL_WITHOUT_ABORT;
77 } else if (EqualsIgnoreCase(env_value, "FATAL")
78 || env_value == std::to_string((int) FATAL)) {
79 return FATAL;
80 } else {
81 return default_value;
82 }
83 }
84
ConsoleSeverity()85 LogSeverity ConsoleSeverity() {
86 return GuessSeverity("CF_CONSOLE_SEVERITY", android::base::INFO);
87 }
88
LogFileSeverity()89 LogSeverity LogFileSeverity() {
90 return GuessSeverity("CF_FILE_SEVERITY", android::base::DEBUG);
91 }
92
TeeLogger(const std::vector<SeverityTarget> & destinations,const std::string & prefix)93 TeeLogger::TeeLogger(const std::vector<SeverityTarget>& destinations,
94 const std::string& prefix)
95 : destinations_(destinations), prefix_(prefix) {}
96
97 // Copied from system/libbase/logging_splitters.h
CountSizeAndNewLines(const char * message)98 static std::pair<int, int> CountSizeAndNewLines(const char* message) {
99 int size = 0;
100 int new_lines = 0;
101 while (*message != '\0') {
102 size++;
103 if (*message == '\n') {
104 ++new_lines;
105 }
106 ++message;
107 }
108 return {size, new_lines};
109 }
110
111 // Copied from system/libbase/logging_splitters.h
112 // This splits the message up line by line, by calling log_function with a pointer to the start of
113 // each line and the size up to the newline character. It sends size = -1 for the final line.
114 template <typename F, typename... Args>
SplitByLines(const char * msg,const F & log_function,Args &&...args)115 static void SplitByLines(const char* msg, const F& log_function, Args&&... args) {
116 const char* newline = strchr(msg, '\n');
117 while (newline != nullptr) {
118 log_function(msg, newline - msg, args...);
119 msg = newline + 1;
120 newline = strchr(msg, '\n');
121 }
122
123 log_function(msg, -1, args...);
124 }
125
126 // Copied from system/libbase/logging_splitters.h
127 // This adds the log header to each line of message and returns it as a string intended to be
128 // written to stderr.
StderrOutputGenerator(const struct tm & now,int pid,uint64_t tid,LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)129 std::string StderrOutputGenerator(const struct tm& now, int pid, uint64_t tid,
130 LogSeverity severity, const char* tag,
131 const char* file, unsigned int line,
132 const char* message) {
133 char timestamp[32];
134 strftime(timestamp, sizeof(timestamp), "%m-%d %H:%M:%S", &now);
135
136 static const char log_characters[] = "VDIWEFF";
137 static_assert(arraysize(log_characters) - 1 == FATAL + 1,
138 "Mismatch in size of log_characters and values in LogSeverity");
139 char severity_char = log_characters[severity];
140 std::string line_prefix;
141 if (file != nullptr) {
142 line_prefix = StringPrintf("%s %c %s %5d %5" PRIu64 " %s:%u] ", tag ? tag : "nullptr",
143 severity_char, timestamp, pid, tid, file, line);
144 } else {
145 line_prefix = StringPrintf("%s %c %s %5d %5" PRIu64 " ", tag ? tag : "nullptr", severity_char,
146 timestamp, pid, tid);
147 }
148
149 auto [size, new_lines] = CountSizeAndNewLines(message);
150 std::string output_string;
151 output_string.reserve(size + new_lines * line_prefix.size() + 1);
152
153 auto concat_lines = [&](const char* message, int size) {
154 output_string.append(line_prefix);
155 if (size == -1) {
156 output_string.append(message);
157 } else {
158 output_string.append(message, size);
159 }
160 output_string.append("\n");
161 };
162 SplitByLines(message, concat_lines);
163 return output_string;
164 }
165
166 // TODO(schuffelen): Do something less primitive.
StripColorCodes(const std::string & str)167 static std::string StripColorCodes(const std::string& str) {
168 std::stringstream sstream;
169 bool in_color_code = false;
170 for (char c : str) {
171 if (c == '\033') {
172 in_color_code = true;
173 }
174 if (!in_color_code) {
175 sstream << c;
176 }
177 if (c == 'm') {
178 in_color_code = false;
179 }
180 }
181 return sstream.str();
182 }
183
operator ()(android::base::LogId,android::base::LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)184 void TeeLogger::operator()(
185 android::base::LogId,
186 android::base::LogSeverity severity,
187 const char* tag,
188 const char* file,
189 unsigned int line,
190 const char* message) {
191 for (const auto& destination : destinations_) {
192 std::string msg_with_prefix = prefix_ + message;
193 std::string output_string;
194 switch (destination.metadata_level) {
195 case MetadataLevel::ONLY_MESSAGE:
196 output_string = msg_with_prefix + std::string("\n");
197 break;
198 case MetadataLevel::TAG_AND_MESSAGE:
199 output_string = fmt::format("{}] {}{}", tag, msg_with_prefix, "\n");
200 break;
201 default:
202 struct tm now;
203 time_t t = time(nullptr);
204 localtime_r(&t, &now);
205 output_string =
206 StderrOutputGenerator(now, getpid(), GetThreadId(), severity, tag,
207 file, line, msg_with_prefix.c_str());
208 break;
209 }
210 if (severity >= destination.severity) {
211 if (destination.target->IsATTY()) {
212 WriteAll(destination.target, output_string);
213 } else {
214 WriteAll(destination.target, StripColorCodes(output_string));
215 }
216 }
217 }
218 }
219
SeverityTargetsForFiles(const std::vector<std::string> & files)220 static std::vector<SeverityTarget> SeverityTargetsForFiles(
221 const std::vector<std::string>& files) {
222 std::vector<SeverityTarget> log_severities;
223 for (const auto& file : files) {
224 auto log_file_fd =
225 SharedFD::Open(
226 file,
227 O_CREAT | O_WRONLY | O_APPEND,
228 S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP);
229 if (!log_file_fd->IsOpen()) {
230 LOG(FATAL) << "Failed to create log file: " << log_file_fd->StrError();
231 }
232 log_severities.push_back(
233 SeverityTarget{LogFileSeverity(), log_file_fd, MetadataLevel::FULL});
234 }
235 return log_severities;
236 }
237
LogToFiles(const std::vector<std::string> & files,const std::string & prefix)238 TeeLogger LogToFiles(const std::vector<std::string>& files,
239 const std::string& prefix) {
240 return TeeLogger(SeverityTargetsForFiles(files), prefix);
241 }
242
LogToStderrAndFiles(const std::vector<std::string> & files,const std::string & prefix,MetadataLevel stderr_level)243 TeeLogger LogToStderrAndFiles(const std::vector<std::string>& files,
244 const std::string& prefix,
245 MetadataLevel stderr_level) {
246 std::vector<SeverityTarget> log_severities = SeverityTargetsForFiles(files);
247 log_severities.push_back(SeverityTarget{ConsoleSeverity(),
248 SharedFD::Dup(/* stderr */ 2),
249 stderr_level});
250 return TeeLogger(log_severities, prefix);
251 }
252
253 } // namespace cuttlefish
254