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