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
17 #include <inttypes.h>
18 #include <stdio.h>
19 #include <sys/stat.h>
20 #include <unistd.h>
21
22 #include <algorithm>
23 #include <functional>
24 #include <iomanip>
25 #include <sstream>
26 #include <string>
27 #include <string_view>
28 #include <vector>
29
30 #include <android-base/file.h>
31 #include <android-base/strings.h>
32 #include <android-base/unique_fd.h>
33 #include <base/files/dir_reader_posix.h>
34 #include <base/logging.h>
35 #include <base/strings/string_util.h>
36 #include <base/strings/stringprintf.h>
37 #include <log/log.h>
38
39 #include "android/log.h"
40 #include "update_engine/common/utils.h"
41
42 using std::string;
43
44 #ifdef _UE_SIDELOAD
45 constexpr bool kSideload = true;
46 #else
47 constexpr bool kSideload = false;
48 #endif
49
50 namespace chromeos_update_engine {
51 namespace {
52
53 constexpr char kSystemLogsRoot[] = "/data/misc/update_engine_log";
54 constexpr size_t kLogCount = 5;
55
56 // Keep the most recent |kLogCount| logs but remove the old ones in
57 // "/data/misc/update_engine_log/".
DeleteOldLogs(const string & kLogsRoot)58 void DeleteOldLogs(const string& kLogsRoot) {
59 base::DirReaderPosix reader(kLogsRoot.c_str());
60 if (!reader.IsValid()) {
61 LOG(ERROR) << "Failed to read " << kLogsRoot;
62 return;
63 }
64
65 std::vector<string> old_logs;
66 while (reader.Next()) {
67 if (reader.name()[0] == '.')
68 continue;
69
70 // Log files are in format "update_engine.%Y%m%d-%H%M%S",
71 // e.g. update_engine.20090103-231425
72 uint64_t date;
73 uint64_t local_time;
74 if (sscanf(reader.name(),
75 "update_engine.%" PRIu64 "-%" PRIu64 "",
76 &date,
77 &local_time) == 2) {
78 old_logs.push_back(reader.name());
79 } else {
80 LOG(WARNING) << "Unrecognized log file " << reader.name();
81 }
82 }
83
84 std::sort(old_logs.begin(), old_logs.end(), std::greater<string>());
85 for (size_t i = kLogCount; i < old_logs.size(); i++) {
86 string log_path = kLogsRoot + "/" + old_logs[i];
87 if (unlink(log_path.c_str()) == -1) {
88 PLOG(WARNING) << "Failed to unlink " << log_path;
89 }
90 }
91 }
92
SetupLogFile(const string & kLogsRoot)93 string SetupLogFile(const string& kLogsRoot) {
94 DeleteOldLogs(kLogsRoot);
95
96 return base::StringPrintf("%s/update_engine.%s",
97 kLogsRoot.c_str(),
98 utils::GetTimeAsString(::time(nullptr)).c_str());
99 }
100
LogPriorityToCString(int priority)101 const char* LogPriorityToCString(int priority) {
102 switch (priority) {
103 case ANDROID_LOG_VERBOSE:
104 return "VERBOSE";
105 case ANDROID_LOG_DEBUG:
106 return "DEBUG";
107 case ANDROID_LOG_INFO:
108 return "INFO";
109 case ANDROID_LOG_WARN:
110 return "WARN";
111 case ANDROID_LOG_ERROR:
112 return "ERROR";
113 case ANDROID_LOG_FATAL:
114 return "FATAL";
115 default:
116 return "UNKNOWN";
117 }
118 }
119
120 using LoggerFunction = std::function<void(const struct __android_log_message*)>;
121
122 class FileLogger {
123 public:
FileLogger(const string & path)124 explicit FileLogger(const string& path) {
125 fd_.reset(TEMP_FAILURE_RETRY(
126 open(path.c_str(),
127 O_WRONLY | O_CREAT | O_TRUNC | O_CLOEXEC | O_NOFOLLOW | O_SYNC,
128 0644)));
129 if (fd_ == -1) {
130 // Use ALOGE that logs to logd before __android_log_set_logger.
131 ALOGE("Cannot open persistent log %s: %s", path.c_str(), strerror(errno));
132 return;
133 }
134 // The log file will have AID_LOG as group ID; this GID is inherited from
135 // the parent directory "/data/misc/update_engine_log" which sets the SGID
136 // bit.
137 if (fchmod(fd_.get(), 0640) == -1) {
138 // Use ALOGE that logs to logd before __android_log_set_logger.
139 ALOGE("Cannot chmod 0640 persistent log %s: %s",
140 path.c_str(),
141 strerror(errno));
142 return;
143 }
144 }
145 // Copy-constructor needed to be converted to std::function.
FileLogger(const FileLogger & other)146 FileLogger(const FileLogger& other) { fd_.reset(dup(other.fd_)); }
operator ()(const struct __android_log_message * log_message)147 void operator()(const struct __android_log_message* log_message) {
148 if (fd_ == -1) {
149 return;
150 }
151
152 std::string_view message_str =
153 log_message->message != nullptr ? log_message->message : "";
154
155 WriteToFd(GetPrefix(log_message));
156 WriteToFd(message_str);
157 WriteToFd("\n");
158 }
159
160 private:
161 android::base::unique_fd fd_;
WriteToFd(std::string_view message)162 void WriteToFd(std::string_view message) {
163 ignore_result(
164 android::base::WriteFully(fd_, message.data(), message.size()));
165 }
166
GetPrefix(const struct __android_log_message * log_message)167 string GetPrefix(const struct __android_log_message* log_message) {
168 std::stringstream ss;
169 timeval tv;
170 gettimeofday(&tv, nullptr);
171 time_t t = tv.tv_sec;
172 struct tm local_time;
173 localtime_r(&t, &local_time);
174 struct tm* tm_time = &local_time;
175 ss << "[" << std::setfill('0') << std::setw(2) << 1 + tm_time->tm_mon
176 << std::setw(2) << tm_time->tm_mday << '/' << std::setw(2)
177 << tm_time->tm_hour << std::setw(2) << tm_time->tm_min << std::setw(2)
178 << tm_time->tm_sec << '.' << std::setw(6) << tv.tv_usec << "] ";
179 // libchrome logs prepends |message| with severity, file and line, but
180 // leave logger_data->file as nullptr.
181 // libbase / liblog logs doesn't. Hence, add them to match the style.
182 // For liblog logs that doesn't set logger_data->file, not printing the
183 // priority is acceptable.
184 if (log_message->file) {
185 ss << "[" << LogPriorityToCString(log_message->priority) << ':'
186 << log_message->file << '(' << log_message->line << ")] ";
187 }
188 return ss.str();
189 }
190 };
191
192 class CombinedLogger {
193 public:
CombinedLogger(bool log_to_system,bool log_to_file)194 CombinedLogger(bool log_to_system, bool log_to_file) {
195 if (log_to_system) {
196 if (kSideload) {
197 // No logd in sideload. Use stdout.
198 // recovery has already redirected stdio properly.
199 loggers_.push_back(__android_log_stderr_logger);
200 } else {
201 loggers_.push_back(__android_log_logd_logger);
202 }
203 }
204 if (log_to_file) {
205 loggers_.push_back(std::move(FileLogger(SetupLogFile(kSystemLogsRoot))));
206 }
207 }
operator ()(const struct __android_log_message * log_message)208 void operator()(const struct __android_log_message* log_message) {
209 if (log_message->file != nullptr && log_message->line != 0) {
210 __android_log_message formatted = *log_message;
211 std::stringstream ss;
212 ss << "[" << LogPriorityToCString(formatted.priority) << ":"
213 << formatted.file << "(" << formatted.line << ")] "
214 << formatted.message;
215 formatted.file = nullptr;
216 formatted.line = 0;
217 const auto str = ss.str();
218 formatted.message = str.c_str();
219 for (auto&& logger : loggers_) {
220 logger(&formatted);
221 }
222 } else {
223 for (auto&& logger : loggers_) {
224 logger(log_message);
225 }
226 }
227 }
228
229 private:
230 std::vector<LoggerFunction> loggers_;
231 };
232
233 // Redirect all libchrome logs to liblog using our custom handler that does
234 // not call __android_log_write and explicitly write to stderr at the same
235 // time. The preset CombinedLogger already writes to stderr properly.
RedirectToLiblog(int severity,const char * file,int line,size_t message_start,const std::string & str_newline)236 bool RedirectToLiblog(int severity,
237 const char* file,
238 int line,
239 size_t message_start,
240 const std::string& str_newline) {
241 android_LogPriority priority =
242 (severity < 0) ? ANDROID_LOG_VERBOSE : ANDROID_LOG_UNKNOWN;
243 switch (severity) {
244 case logging::LOG_INFO:
245 priority = ANDROID_LOG_INFO;
246 break;
247 case logging::LOG_WARNING:
248 priority = ANDROID_LOG_WARN;
249 break;
250 case logging::LOG_ERROR:
251 priority = ANDROID_LOG_ERROR;
252 break;
253 case logging::LOG_FATAL:
254 priority = ANDROID_LOG_FATAL;
255 break;
256 }
257 std::string_view sv = str_newline;
258 ignore_result(android::base::ConsumeSuffix(&sv, "\n"));
259 std::string str(sv.data(), sv.size());
260
261 if (priority == ANDROID_LOG_FATAL) {
262 // Abort the program for priority FATAL. __android_log_assert will log the
263 // message to stderr and CombinedLogger.
264 __android_log_assert(nullptr, nullptr, "%s", str.c_str());
265 } else {
266 // This will eventually be redirected to CombinedLogger.
267 // Use nullptr as tag so that liblog infers log tag from getprogname().
268 if (file == nullptr || file[0] == 0 || line == 0 || message_start != 0) {
269 __android_log_write(priority, nullptr /* tag */, str.c_str());
270 } else {
271 __android_log_print(priority,
272 nullptr,
273 "[%s:%s(%d)] %s",
274 LogPriorityToCString(priority),
275 file,
276 line,
277 str.c_str());
278 }
279 }
280 return true;
281 }
282
283 } // namespace
284
SetupLogging(bool log_to_system,bool log_to_file)285 void SetupLogging(bool log_to_system, bool log_to_file) {
286 // Note that libchrome logging uses liblog.
287 // By calling liblog's __android_log_set_logger function, all of libchrome
288 // (used by update_engine) / libbase / liblog (used by depended modules)
289 // logging eventually redirects to CombinedLogger.
290 static auto g_logger =
291 std::make_unique<CombinedLogger>(log_to_system, log_to_file);
292 __android_log_set_logger([](const struct __android_log_message* log_message) {
293 (*g_logger)(log_message);
294 });
295
296 // libchrome logging should not log to file.
297 logging::LoggingSettings log_settings;
298 log_settings.lock_log = logging::DONT_LOCK_LOG_FILE;
299 log_settings.logging_dest =
300 static_cast<logging::LoggingDestination>(logging::LOG_NONE);
301 log_settings.log_file = nullptr;
302 logging::InitLogging(log_settings);
303 logging::SetLogItems(false /* enable_process_id */,
304 false /* enable_thread_id */,
305 false /* enable_timestamp */,
306 false /* enable_tickcount */);
307 logging::SetLogMessageHandler(&RedirectToLiblog);
308 }
309
310 } // namespace chromeos_update_engine
311