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