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/".
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 
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 
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:
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.
144   FileLogger(const FileLogger& other) { fd_.reset(dup(other.fd_)); }
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_;
160   void WriteToFd(std::string_view message) {
161     ignore_result(
162         android::base::WriteFully(fd_, message.data(), message.size()));
163   }
164 
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:
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   }
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.
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   // This will eventually be redirected to CombinedLogger.
244   // Use nullptr as tag so that liblog infers log tag from getprogname().
245   __android_log_write(priority, nullptr /* tag */, str.c_str());
246   return true;
247 }
248 
249 }  // namespace
250 
251 void SetupLogging(bool log_to_system, bool log_to_file) {
252   // Note that libchrome logging uses liblog.
253   // By calling liblog's __android_log_set_logger function, all of libchrome
254   // (used by update_engine) / libbase / liblog (used by depended modules)
255   // logging eventually redirects to CombinedLogger.
256   static auto g_logger =
257       std::make_unique<CombinedLogger>(log_to_system, log_to_file);
258   __android_log_set_logger([](const struct __android_log_message* log_message) {
259     (*g_logger)(log_message);
260   });
261 
262   // libchrome logging should not log to file.
263   logging::LoggingSettings log_settings;
264   log_settings.lock_log = logging::DONT_LOCK_LOG_FILE;
265   log_settings.logging_dest =
266       static_cast<logging::LoggingDestination>(logging::LOG_NONE);
267   log_settings.log_file = nullptr;
268   logging::InitLogging(log_settings);
269   logging::SetLogItems(false /* enable_process_id */,
270                        false /* enable_thread_id */,
271                        false /* enable_timestamp */,
272                        false /* enable_tickcount */);
273   logging::SetLogMessageHandler(&RedirectToLiblog);
274 }
275 
276 }  // namespace chromeos_update_engine
277