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 static std::string StderrOutputGenerator(const struct tm& now, int pid, uint64_t tid,
130 LogSeverity severity, const char* tag, const char* file,
131 unsigned int line, const char* message) {
132 char timestamp[32];
133 strftime(timestamp, sizeof(timestamp), "%m-%d %H:%M:%S", &now);
134
135 static const char log_characters[] = "VDIWEFF";
136 static_assert(arraysize(log_characters) - 1 == FATAL + 1,
137 "Mismatch in size of log_characters and values in LogSeverity");
138 char severity_char = log_characters[severity];
139 std::string line_prefix;
140 if (file != nullptr) {
141 line_prefix = StringPrintf("%s %c %s %5d %5" PRIu64 " %s:%u] ", tag ? tag : "nullptr",
142 severity_char, timestamp, pid, tid, file, line);
143 } else {
144 line_prefix = StringPrintf("%s %c %s %5d %5" PRIu64 " ", tag ? tag : "nullptr", severity_char,
145 timestamp, pid, tid);
146 }
147
148 auto [size, new_lines] = CountSizeAndNewLines(message);
149 std::string output_string;
150 output_string.reserve(size + new_lines * line_prefix.size() + 1);
151
152 auto concat_lines = [&](const char* message, int size) {
153 output_string.append(line_prefix);
154 if (size == -1) {
155 output_string.append(message);
156 } else {
157 output_string.append(message, size);
158 }
159 output_string.append("\n");
160 };
161 SplitByLines(message, concat_lines);
162 return output_string;
163 }
164
165 // TODO(schuffelen): Do something less primitive.
StripColorCodes(const std::string & str)166 static std::string StripColorCodes(const std::string& str) {
167 std::stringstream sstream;
168 bool in_color_code = false;
169 for (char c : str) {
170 if (c == '\033') {
171 in_color_code = true;
172 }
173 if (!in_color_code) {
174 sstream << c;
175 }
176 if (c == 'm') {
177 in_color_code = false;
178 }
179 }
180 return sstream.str();
181 }
182
operator ()(android::base::LogId,android::base::LogSeverity severity,const char * tag,const char * file,unsigned int line,const char * message)183 void TeeLogger::operator()(
184 android::base::LogId,
185 android::base::LogSeverity severity,
186 const char* tag,
187 const char* file,
188 unsigned int line,
189 const char* message) {
190 for (const auto& destination : destinations_) {
191 std::string msg_with_prefix = prefix_ + message;
192 std::string output_string;
193 if (destination.metadata_level == MetadataLevel::ONLY_MESSAGE) {
194 output_string = msg_with_prefix + std::string("\n");
195 } else {
196 struct tm now;
197 time_t t = time(nullptr);
198 localtime_r(&t, &now);
199 output_string =
200 StderrOutputGenerator(now, getpid(), GetThreadId(), severity, tag,
201 file, line, msg_with_prefix.c_str());
202 }
203 if (severity >= destination.severity) {
204 if (destination.target->IsATTY()) {
205 WriteAll(destination.target, output_string);
206 } else {
207 WriteAll(destination.target, StripColorCodes(output_string));
208 }
209 }
210 }
211 }
212
SeverityTargetsForFiles(const std::vector<std::string> & files)213 static std::vector<SeverityTarget> SeverityTargetsForFiles(
214 const std::vector<std::string>& files) {
215 std::vector<SeverityTarget> log_severities;
216 for (const auto& file : files) {
217 auto log_file_fd =
218 SharedFD::Open(
219 file,
220 O_CREAT | O_WRONLY | O_APPEND,
221 S_IRUSR | S_IWUSR | S_IRGRP | S_IWGRP);
222 if (!log_file_fd->IsOpen()) {
223 LOG(FATAL) << "Failed to create log file: " << log_file_fd->StrError();
224 }
225 log_severities.push_back(
226 SeverityTarget{LogFileSeverity(), log_file_fd, MetadataLevel::FULL});
227 }
228 return log_severities;
229 }
230
LogToFiles(const std::vector<std::string> & files,const std::string & prefix)231 TeeLogger LogToFiles(const std::vector<std::string>& files,
232 const std::string& prefix) {
233 return TeeLogger(SeverityTargetsForFiles(files), prefix);
234 }
235
LogToStderrAndFiles(const std::vector<std::string> & files,const std::string & prefix)236 TeeLogger LogToStderrAndFiles(const std::vector<std::string>& files,
237 const std::string& prefix) {
238 std::vector<SeverityTarget> log_severities = SeverityTargetsForFiles(files);
239 log_severities.push_back(SeverityTarget{ConsoleSeverity(),
240 SharedFD::Dup(/* stderr */ 2),
241 MetadataLevel::ONLY_MESSAGE});
242 return TeeLogger(log_severities, prefix);
243 }
244
245 } // namespace cuttlefish
246