From 3c3f211d1e5698da6eea9e83584acb2dee4ca46e Mon Sep 17 00:00:00 2001 From: Jerry Zhang Date: Wed, 2 May 2018 16:56:00 -0700 Subject: recovery: Refactor logging code into logging.cpp Move common logging related functions to rotate_logs.cpp, and rename that to logging.cpp. Test: Recovery works Bug: 78793464 Change-Id: I00f20a79a296680122b8437d54a87897c5cb2fc7 --- Android.bp | 12 ++- Android.mk | 2 +- common.h | 9 +- logging.cpp | 243 +++++++++++++++++++++++++++++++++++++++++++++++++++ logging.h | 50 +++++++++++ recovery-persist.cpp | 2 +- recovery-refresh.cpp | 2 +- recovery.cpp | 134 ++-------------------------- recovery_main.cpp | 2 +- rotate_logs.cpp | 107 ----------------------- rotate_logs.h | 38 -------- 11 files changed, 315 insertions(+), 286 deletions(-) create mode 100644 logging.cpp create mode 100644 logging.h delete mode 100644 rotate_logs.cpp delete mode 100644 rotate_logs.h diff --git a/Android.bp b/Android.bp index 9ad961d5b..22c90bd3e 100644 --- a/Android.bp +++ b/Android.bp @@ -89,8 +89,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-persist.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -98,6 +98,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-persist.rc", ], @@ -112,8 +116,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-refresh.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -121,6 +125,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-refresh.rc", ], diff --git a/Android.mk b/Android.mk index eff4b015d..dbd2eb788 100644 --- a/Android.mk +++ b/Android.mk @@ -126,10 +126,10 @@ LOCAL_SRC_FILES := \ adb_install.cpp \ device.cpp \ fuse_sdcard_provider.cpp \ + logging.cpp \ recovery.cpp \ recovery_main.cpp \ roots.cpp \ - rotate_logs.cpp \ LOCAL_MODULE := recovery diff --git a/common.h b/common.h index de536fdb4..3dc36a960 100644 --- a/common.h +++ b/common.h @@ -27,7 +27,9 @@ static constexpr int kRecoveryApiVersion = 3; class RecoveryUI; +struct selabel_handle; +extern struct selabel_handle* sehandle; extern RecoveryUI* ui; extern bool modified_flash; @@ -37,13 +39,6 @@ extern std::string stage; // The reason argument provided in "--reason=". extern const char* reason; -// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the -// file pointer, or nullptr on error. -FILE* fopen_path(const std::string& path, const char* mode); - -// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. -void check_and_fclose(FILE* fp, const std::string& name); - void ui_print(const char* format, ...) __printflike(1, 2); bool is_ro_debuggable(); diff --git a/logging.cpp b/logging.cpp new file mode 100644 index 000000000..d5af72aad --- /dev/null +++ b/logging.cpp @@ -0,0 +1,243 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "logging.h" + +#include +#include +#include +#include + +#include + +#include +#include +#include +#include +#include /* for AID_SYSTEM */ +#include /* private pmsg functions */ + +#include "common.h" +#include "otautil/dirutil.h" +#include "otautil/paths.h" +#include "roots.h" + +static constexpr const char* LOG_FILE = "/cache/recovery/log"; +static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; +static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; +static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; + +static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; +static const std::string LAST_LOG_FILTER = "recovery/last_log"; + +// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the +// file pointer, or nullptr on error. +static FILE* fopen_path(const std::string& path, const char* mode) { + if (ensure_path_mounted(path.c_str()) != 0) { + LOG(ERROR) << "Can't mount " << path; + return nullptr; + } + + // When writing, try to create the containing directory, if necessary. Use generous permissions, + // the system (init.rc) will reset them. + if (strchr("wa", mode[0])) { + mkdir_recursively(path, 0777, true, sehandle); + } + return fopen(path.c_str(), mode); +} + +void check_and_fclose(FILE* fp, const std::string& name) { + fflush(fp); + if (fsync(fileno(fp)) == -1) { + PLOG(ERROR) << "Failed to fsync " << name; + } + if (ferror(fp)) { + PLOG(ERROR) << "Error in " << name; + } + fclose(fp); +} + +// close a file, log an error if the error indicator is set +ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, + size_t len, void* arg) { + bool* do_rotate = static_cast(arg); + if (LAST_KMSG_FILTER.find(filename) != std::string::npos || + LAST_LOG_FILTER.find(filename) != std::string::npos) { + *do_rotate = true; + } + return len; +} + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg) { + bool* do_rotate = static_cast(arg); + if (!*do_rotate) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + std::string name(filename); + size_t dot = name.find_last_of('.'); + std::string sub = name.substr(0, dot); + + if (LAST_KMSG_FILTER.find(sub) == std::string::npos && + LAST_LOG_FILTER.find(sub) == std::string::npos) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + // filename rotation + if (dot == std::string::npos) { + name += ".1"; + } else { + std::string number = name.substr(dot + 1); + if (!isdigit(number[0])) { + name += ".1"; + } else { + size_t i; + if (!android::base::ParseUint(number, &i)) { + LOG(ERROR) << "failed to parse uint in " << number; + return -1; + } + name = sub + "." + std::to_string(i + 1); + } + } + + return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); +} + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { + // Logs should only be rotated once. + static bool rotated = false; + if (rotated) { + return; + } + rotated = true; + + for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { + std::string old_log = android::base::StringPrintf("%s", last_log_file); + if (i > 0) { + old_log += "." + std::to_string(i); + } + std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); + // Ignore errors if old_log doesn't exist. + rename(old_log.c_str(), new_log.c_str()); + + std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); + if (i > 0) { + old_kmsg += "." + std::to_string(i); + } + std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); + rename(old_kmsg.c_str(), new_kmsg.c_str()); + } +} + +// Writes content to the current pmsg session. +static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { + return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), + buf.data(), buf.size()); +} + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { + std::string content; + android::base::ReadFileToString(source, &content); + __pmsg_write(destination, content); +} + +// How much of the temp log we have copied to the copy in cache. +static off_t tmplog_offset = 0; + +void reset_tmplog_offset() { + tmplog_offset = 0; +} + +void copy_log_file(const std::string& source, const std::string& destination, bool append) { + FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); + if (dest_fp == nullptr) { + PLOG(ERROR) << "Can't open " << destination; + } else { + FILE* source_fp = fopen(source.c_str(), "re"); + if (source_fp != nullptr) { + if (append) { + fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write + } + char buf[4096]; + size_t bytes; + while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { + fwrite(buf, 1, bytes, dest_fp); + } + if (append) { + tmplog_offset = ftello(source_fp); + } + check_and_fclose(source_fp, source); + } + check_and_fclose(dest_fp, destination); + } +} + +void copy_logs(bool modified_flash, bool has_cache) { + // We only rotate and record the log of the current session if there are actual attempts to modify + // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary + // rotation (and possible deletion) of log files, if it does not do anything loggable. + if (!modified_flash) { + return; + } + + // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. + copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); + copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); + + // We can do nothing for now if there's no /cache partition. + if (!has_cache) { + return; + } + + ensure_path_mounted(LAST_LOG_FILE); + ensure_path_mounted(LAST_KMSG_FILE); + rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); + + // Copy logs to cache so the system can find out what happened. + copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); + copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); + copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); + save_kernel_log(LAST_KMSG_FILE); + chmod(LOG_FILE, 0600); + chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_KMSG_FILE, 0600); + chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_LOG_FILE, 0640); + chmod(LAST_INSTALL_FILE, 0644); + sync(); +} + +// Read from kernel log into buffer and write out to file. +void save_kernel_log(const char* destination) { + int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); + if (klog_buf_len <= 0) { + PLOG(ERROR) << "Error getting klog size"; + return; + } + + std::string buffer(klog_buf_len, 0); + int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); + if (n == -1) { + PLOG(ERROR) << "Error in reading klog"; + return; + } + buffer.resize(n); + android::base::WriteStringToFile(buffer, destination); +} diff --git a/logging.h b/logging.h new file mode 100644 index 000000000..3cfbc7af6 --- /dev/null +++ b/logging.h @@ -0,0 +1,50 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef _LOGGING_H +#define _LOGGING_H + +#include +#include + +#include + +#include + +static constexpr int KEEP_LOG_COUNT = 10; + +ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file); + +// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. +void check_and_fclose(FILE* fp, const std::string& name); + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination); +void copy_log_file(const std::string& source, const std::string& destination, bool append); +void copy_logs(bool modified_flash, bool has_cache); +void reset_tmplog_offset(); + +void save_kernel_log(const char* destination); + +#endif //_LOGGING_H diff --git a/recovery-persist.cpp b/recovery-persist.cpp index dbce7ff74..d3ade6260 100644 --- a/recovery-persist.cpp +++ b/recovery-persist.cpp @@ -41,7 +41,7 @@ #include #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" static const char *LAST_LOG_FILE = "/data/misc/recovery/last_log"; static const char *LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0"; diff --git a/recovery-refresh.cpp b/recovery-refresh.cpp index 14565d3f4..aee1ca592 100644 --- a/recovery-refresh.cpp +++ b/recovery-refresh.cpp @@ -42,7 +42,7 @@ #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" int main(int argc, char **argv) { static const char filter[] = "recovery/"; diff --git a/recovery.cpp b/recovery.cpp index 00f38596c..0ab34197f 100644 --- a/recovery.cpp +++ b/recovery.cpp @@ -29,7 +29,6 @@ #include #include #include -#include #include #include #include @@ -53,8 +52,6 @@ #include #include /* for property_list */ #include -#include /* for AID_SYSTEM */ -#include /* private pmsg functions */ #include #include #include @@ -66,21 +63,19 @@ #include "fuse_sdcard_provider.h" #include "fuse_sideload.h" #include "install.h" +#include "logging.h" #include "minui/minui.h" #include "otautil/dirutil.h" #include "otautil/error_code.h" #include "otautil/paths.h" #include "otautil/sysutil.h" #include "roots.h" -#include "rotate_logs.h" #include "screen_ui.h" #include "stub_ui.h" #include "ui.h" static constexpr const char* CACHE_LOG_DIR = "/cache/recovery"; static constexpr const char* COMMAND_FILE = "/cache/recovery/command"; -static constexpr const char* LOG_FILE = "/cache/recovery/log"; -static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; static constexpr const char* LOCALE_FILE = "/cache/recovery/last_locale"; @@ -149,31 +144,6 @@ struct selabel_handle* sehandle; * 7b. the user reboots (pulling the battery, etc) into the main system */ -FILE* fopen_path(const std::string& path, const char* mode) { - if (ensure_path_mounted(path.c_str()) != 0) { - LOG(ERROR) << "Can't mount " << path; - return nullptr; - } - - // When writing, try to create the containing directory, if necessary. Use generous permissions, - // the system (init.rc) will reset them. - if (strchr("wa", mode[0])) { - mkdir_recursively(path, 0777, true, sehandle); - } - return fopen(path.c_str(), mode); -} - -void check_and_fclose(FILE* fp, const std::string& name) { - fflush(fp); - if (fsync(fileno(fp)) == -1) { - PLOG(ERROR) << "Failed to fsync " << name; - } - if (ferror(fp)) { - PLOG(ERROR) << "Error in " << name; - } - fclose(fp); -} - bool is_ro_debuggable() { return android::base::GetBoolProperty("ro.debuggable", false); } @@ -259,98 +229,6 @@ static void set_sdcard_update_bootloader_message() { } } -// Read from kernel log into buffer and write out to file. -static void save_kernel_log(const char* destination) { - int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); - if (klog_buf_len <= 0) { - PLOG(ERROR) << "Error getting klog size"; - return; - } - - std::string buffer(klog_buf_len, 0); - int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); - if (n == -1) { - PLOG(ERROR) << "Error in reading klog"; - return; - } - buffer.resize(n); - android::base::WriteStringToFile(buffer, destination); -} - -// Writes content to the current pmsg session. -static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { - return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), - buf.data(), buf.size()); -} - -static void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { - std::string content; - android::base::ReadFileToString(source, &content); - __pmsg_write(destination, content); -} - -// How much of the temp log we have copied to the copy in cache. -static off_t tmplog_offset = 0; - -static void copy_log_file(const std::string& source, const std::string& destination, bool append) { - FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); - if (dest_fp == nullptr) { - PLOG(ERROR) << "Can't open " << destination; - } else { - FILE* source_fp = fopen(source.c_str(), "re"); - if (source_fp != nullptr) { - if (append) { - fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write - } - char buf[4096]; - size_t bytes; - while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { - fwrite(buf, 1, bytes, dest_fp); - } - if (append) { - tmplog_offset = ftello(source_fp); - } - check_and_fclose(source_fp, source); - } - check_and_fclose(dest_fp, destination); - } -} - -static void copy_logs() { - // We only rotate and record the log of the current session if there are actual attempts to modify - // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary - // rotation (and possible deletion) of log files, if it does not do anything loggable. - if (!modified_flash) { - return; - } - - // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. - copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); - copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); - - // We can do nothing for now if there's no /cache partition. - if (!has_cache) { - return; - } - - ensure_path_mounted(LAST_LOG_FILE); - ensure_path_mounted(LAST_KMSG_FILE); - rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); - - // Copy logs to cache so the system can find out what happened. - copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); - copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); - copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); - save_kernel_log(LAST_KMSG_FILE); - chmod(LOG_FILE, 0600); - chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_KMSG_FILE, 0600); - chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_LOG_FILE, 0640); - chmod(LAST_INSTALL_FILE, 0644); - sync(); -} - // Clear the recovery command and prepare to boot a (hopefully working) system, // copy our log file to cache as well (for the system to read). This function is // idempotent: call it as many times as you like. @@ -366,7 +244,7 @@ static void finish_recovery() { } } - copy_logs(); + copy_logs(modified_flash, has_cache); // Reset to normal system boot so recovery won't cycle indefinitely. std::string err; @@ -482,8 +360,8 @@ static bool erase_volume(const char* volume) { // Any part of the log we'd copied to cache is now gone. // Reset the pointer so we copy from the beginning of the temp // log. - tmplog_offset = 0; - copy_logs(); + reset_tmplog_offset(); + copy_logs(modified_flash, has_cache); } return (result == 0); @@ -1000,7 +878,7 @@ static Device::BuiltinAction prompt_and_wait(Device* device, int status) { if (status != INSTALL_SUCCESS) { ui->SetBackground(RecoveryUI::ERROR); ui->Print("Installation aborted.\n"); - copy_logs(); + copy_logs(modified_flash, has_cache); } else if (!ui->IsTextVisible()) { return Device::NO_ACTION; // reboot if logs aren't visible } else { @@ -1394,7 +1272,7 @@ int start_recovery(int argc, char** argv) { // RETRY_LIMIT times before we abandon this OTA update. static constexpr int RETRY_LIMIT = 4; if (status == INSTALL_RETRY && retry_count < RETRY_LIMIT) { - copy_logs(); + copy_logs(modified_flash, has_cache); retry_count += 1; set_retry_bootloader_message(retry_count, args); // Print retry count on screen. diff --git a/recovery_main.cpp b/recovery_main.cpp index 9f579f7cd..3147511ee 100644 --- a/recovery_main.cpp +++ b/recovery_main.cpp @@ -24,10 +24,10 @@ #include /* private pmsg functions */ #include "common.h" +#include "logging.h" #include "minadbd/minadbd.h" #include "otautil/paths.h" #include "private/recovery.h" -#include "rotate_logs.h" #include "ui.h" static void UiLogger(android::base::LogId /* id */, android::base::LogSeverity severity, diff --git a/rotate_logs.cpp b/rotate_logs.cpp deleted file mode 100644 index da008792c..000000000 --- a/rotate_logs.cpp +++ /dev/null @@ -1,107 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#include "rotate_logs.h" - -#include -#include -#include - -#include - -#include -#include -#include -#include -#include /* private pmsg functions */ - -static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; -static const std::string LAST_LOG_FILTER = "recovery/last_log"; - -ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, - size_t len, void* arg) { - bool* do_rotate = static_cast(arg); - if (LAST_KMSG_FILTER.find(filename) != std::string::npos || - LAST_LOG_FILTER.find(filename) != std::string::npos) { - *do_rotate = true; - } - return len; -} - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg) { - bool* do_rotate = static_cast(arg); - if (!*do_rotate) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - std::string name(filename); - size_t dot = name.find_last_of('.'); - std::string sub = name.substr(0, dot); - - if (LAST_KMSG_FILTER.find(sub) == std::string::npos && - LAST_LOG_FILTER.find(sub) == std::string::npos) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - // filename rotation - if (dot == std::string::npos) { - name += ".1"; - } else { - std::string number = name.substr(dot + 1); - if (!isdigit(number[0])) { - name += ".1"; - } else { - size_t i; - if (!android::base::ParseUint(number, &i)) { - LOG(ERROR) << "failed to parse uint in " << number; - return -1; - } - name = sub + "." + std::to_string(i + 1); - } - } - - return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); -} - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { - // Logs should only be rotated once. - static bool rotated = false; - if (rotated) { - return; - } - rotated = true; - - for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { - std::string old_log = android::base::StringPrintf("%s", last_log_file); - if (i > 0) { - old_log += "." + std::to_string(i); - } - std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); - // Ignore errors if old_log doesn't exist. - rename(old_log.c_str(), new_log.c_str()); - - std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); - if (i > 0) { - old_kmsg += "." + std::to_string(i); - } - std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); - rename(old_kmsg.c_str(), new_kmsg.c_str()); - } -} diff --git a/rotate_logs.h b/rotate_logs.h deleted file mode 100644 index 007c33d44..000000000 --- a/rotate_logs.h +++ /dev/null @@ -1,38 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#ifndef _ROTATE_LOGS_H -#define _ROTATE_LOGS_H - -#include -#include - -#include - -static constexpr int KEEP_LOG_COUNT = 10; - -ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file); - -#endif //_ROTATE_LOG_H -- cgit v1.2.3 From cadf4ed45137fbb776584b4427694eb783183d7e Mon Sep 17 00:00:00 2001 From: Jerry Zhang Date: Wed, 2 May 2018 16:56:00 -0700 Subject: recovery: Refactor logging code into logging.cpp Move common logging related functions to rotate_logs.cpp, and rename that to logging.cpp. Test: Recovery works Bug: 78793464 Change-Id: I00f20a79a296680122b8437d54a87897c5cb2fc7 (cherry picked from commit 3c3f211d1e5698da6eea9e83584acb2dee4ca46e) --- Android.bp | 12 ++- Android.mk | 2 +- common.h | 9 +- logging.cpp | 243 +++++++++++++++++++++++++++++++++++++++++++++++++++ logging.h | 50 +++++++++++ recovery-persist.cpp | 2 +- recovery-refresh.cpp | 2 +- recovery.cpp | 134 ++-------------------------- recovery_main.cpp | 2 +- rotate_logs.cpp | 107 ----------------------- rotate_logs.h | 38 -------- 11 files changed, 315 insertions(+), 286 deletions(-) create mode 100644 logging.cpp create mode 100644 logging.h delete mode 100644 rotate_logs.cpp delete mode 100644 rotate_logs.h diff --git a/Android.bp b/Android.bp index 9ad961d5b..22c90bd3e 100644 --- a/Android.bp +++ b/Android.bp @@ -89,8 +89,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-persist.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -98,6 +98,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-persist.rc", ], @@ -112,8 +116,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-refresh.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -121,6 +125,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-refresh.rc", ], diff --git a/Android.mk b/Android.mk index eff4b015d..dbd2eb788 100644 --- a/Android.mk +++ b/Android.mk @@ -126,10 +126,10 @@ LOCAL_SRC_FILES := \ adb_install.cpp \ device.cpp \ fuse_sdcard_provider.cpp \ + logging.cpp \ recovery.cpp \ recovery_main.cpp \ roots.cpp \ - rotate_logs.cpp \ LOCAL_MODULE := recovery diff --git a/common.h b/common.h index de536fdb4..3dc36a960 100644 --- a/common.h +++ b/common.h @@ -27,7 +27,9 @@ static constexpr int kRecoveryApiVersion = 3; class RecoveryUI; +struct selabel_handle; +extern struct selabel_handle* sehandle; extern RecoveryUI* ui; extern bool modified_flash; @@ -37,13 +39,6 @@ extern std::string stage; // The reason argument provided in "--reason=". extern const char* reason; -// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the -// file pointer, or nullptr on error. -FILE* fopen_path(const std::string& path, const char* mode); - -// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. -void check_and_fclose(FILE* fp, const std::string& name); - void ui_print(const char* format, ...) __printflike(1, 2); bool is_ro_debuggable(); diff --git a/logging.cpp b/logging.cpp new file mode 100644 index 000000000..d5af72aad --- /dev/null +++ b/logging.cpp @@ -0,0 +1,243 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "logging.h" + +#include +#include +#include +#include + +#include + +#include +#include +#include +#include +#include /* for AID_SYSTEM */ +#include /* private pmsg functions */ + +#include "common.h" +#include "otautil/dirutil.h" +#include "otautil/paths.h" +#include "roots.h" + +static constexpr const char* LOG_FILE = "/cache/recovery/log"; +static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; +static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; +static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; + +static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; +static const std::string LAST_LOG_FILTER = "recovery/last_log"; + +// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the +// file pointer, or nullptr on error. +static FILE* fopen_path(const std::string& path, const char* mode) { + if (ensure_path_mounted(path.c_str()) != 0) { + LOG(ERROR) << "Can't mount " << path; + return nullptr; + } + + // When writing, try to create the containing directory, if necessary. Use generous permissions, + // the system (init.rc) will reset them. + if (strchr("wa", mode[0])) { + mkdir_recursively(path, 0777, true, sehandle); + } + return fopen(path.c_str(), mode); +} + +void check_and_fclose(FILE* fp, const std::string& name) { + fflush(fp); + if (fsync(fileno(fp)) == -1) { + PLOG(ERROR) << "Failed to fsync " << name; + } + if (ferror(fp)) { + PLOG(ERROR) << "Error in " << name; + } + fclose(fp); +} + +// close a file, log an error if the error indicator is set +ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, + size_t len, void* arg) { + bool* do_rotate = static_cast(arg); + if (LAST_KMSG_FILTER.find(filename) != std::string::npos || + LAST_LOG_FILTER.find(filename) != std::string::npos) { + *do_rotate = true; + } + return len; +} + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg) { + bool* do_rotate = static_cast(arg); + if (!*do_rotate) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + std::string name(filename); + size_t dot = name.find_last_of('.'); + std::string sub = name.substr(0, dot); + + if (LAST_KMSG_FILTER.find(sub) == std::string::npos && + LAST_LOG_FILTER.find(sub) == std::string::npos) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + // filename rotation + if (dot == std::string::npos) { + name += ".1"; + } else { + std::string number = name.substr(dot + 1); + if (!isdigit(number[0])) { + name += ".1"; + } else { + size_t i; + if (!android::base::ParseUint(number, &i)) { + LOG(ERROR) << "failed to parse uint in " << number; + return -1; + } + name = sub + "." + std::to_string(i + 1); + } + } + + return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); +} + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { + // Logs should only be rotated once. + static bool rotated = false; + if (rotated) { + return; + } + rotated = true; + + for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { + std::string old_log = android::base::StringPrintf("%s", last_log_file); + if (i > 0) { + old_log += "." + std::to_string(i); + } + std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); + // Ignore errors if old_log doesn't exist. + rename(old_log.c_str(), new_log.c_str()); + + std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); + if (i > 0) { + old_kmsg += "." + std::to_string(i); + } + std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); + rename(old_kmsg.c_str(), new_kmsg.c_str()); + } +} + +// Writes content to the current pmsg session. +static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { + return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), + buf.data(), buf.size()); +} + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { + std::string content; + android::base::ReadFileToString(source, &content); + __pmsg_write(destination, content); +} + +// How much of the temp log we have copied to the copy in cache. +static off_t tmplog_offset = 0; + +void reset_tmplog_offset() { + tmplog_offset = 0; +} + +void copy_log_file(const std::string& source, const std::string& destination, bool append) { + FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); + if (dest_fp == nullptr) { + PLOG(ERROR) << "Can't open " << destination; + } else { + FILE* source_fp = fopen(source.c_str(), "re"); + if (source_fp != nullptr) { + if (append) { + fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write + } + char buf[4096]; + size_t bytes; + while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { + fwrite(buf, 1, bytes, dest_fp); + } + if (append) { + tmplog_offset = ftello(source_fp); + } + check_and_fclose(source_fp, source); + } + check_and_fclose(dest_fp, destination); + } +} + +void copy_logs(bool modified_flash, bool has_cache) { + // We only rotate and record the log of the current session if there are actual attempts to modify + // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary + // rotation (and possible deletion) of log files, if it does not do anything loggable. + if (!modified_flash) { + return; + } + + // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. + copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); + copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); + + // We can do nothing for now if there's no /cache partition. + if (!has_cache) { + return; + } + + ensure_path_mounted(LAST_LOG_FILE); + ensure_path_mounted(LAST_KMSG_FILE); + rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); + + // Copy logs to cache so the system can find out what happened. + copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); + copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); + copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); + save_kernel_log(LAST_KMSG_FILE); + chmod(LOG_FILE, 0600); + chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_KMSG_FILE, 0600); + chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_LOG_FILE, 0640); + chmod(LAST_INSTALL_FILE, 0644); + sync(); +} + +// Read from kernel log into buffer and write out to file. +void save_kernel_log(const char* destination) { + int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); + if (klog_buf_len <= 0) { + PLOG(ERROR) << "Error getting klog size"; + return; + } + + std::string buffer(klog_buf_len, 0); + int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); + if (n == -1) { + PLOG(ERROR) << "Error in reading klog"; + return; + } + buffer.resize(n); + android::base::WriteStringToFile(buffer, destination); +} diff --git a/logging.h b/logging.h new file mode 100644 index 000000000..3cfbc7af6 --- /dev/null +++ b/logging.h @@ -0,0 +1,50 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef _LOGGING_H +#define _LOGGING_H + +#include +#include + +#include + +#include + +static constexpr int KEEP_LOG_COUNT = 10; + +ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file); + +// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. +void check_and_fclose(FILE* fp, const std::string& name); + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination); +void copy_log_file(const std::string& source, const std::string& destination, bool append); +void copy_logs(bool modified_flash, bool has_cache); +void reset_tmplog_offset(); + +void save_kernel_log(const char* destination); + +#endif //_LOGGING_H diff --git a/recovery-persist.cpp b/recovery-persist.cpp index dbce7ff74..d3ade6260 100644 --- a/recovery-persist.cpp +++ b/recovery-persist.cpp @@ -41,7 +41,7 @@ #include #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" static const char *LAST_LOG_FILE = "/data/misc/recovery/last_log"; static const char *LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0"; diff --git a/recovery-refresh.cpp b/recovery-refresh.cpp index 14565d3f4..aee1ca592 100644 --- a/recovery-refresh.cpp +++ b/recovery-refresh.cpp @@ -42,7 +42,7 @@ #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" int main(int argc, char **argv) { static const char filter[] = "recovery/"; diff --git a/recovery.cpp b/recovery.cpp index 00f38596c..0ab34197f 100644 --- a/recovery.cpp +++ b/recovery.cpp @@ -29,7 +29,6 @@ #include #include #include -#include #include #include #include @@ -53,8 +52,6 @@ #include #include /* for property_list */ #include -#include /* for AID_SYSTEM */ -#include /* private pmsg functions */ #include #include #include @@ -66,21 +63,19 @@ #include "fuse_sdcard_provider.h" #include "fuse_sideload.h" #include "install.h" +#include "logging.h" #include "minui/minui.h" #include "otautil/dirutil.h" #include "otautil/error_code.h" #include "otautil/paths.h" #include "otautil/sysutil.h" #include "roots.h" -#include "rotate_logs.h" #include "screen_ui.h" #include "stub_ui.h" #include "ui.h" static constexpr const char* CACHE_LOG_DIR = "/cache/recovery"; static constexpr const char* COMMAND_FILE = "/cache/recovery/command"; -static constexpr const char* LOG_FILE = "/cache/recovery/log"; -static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; static constexpr const char* LOCALE_FILE = "/cache/recovery/last_locale"; @@ -149,31 +144,6 @@ struct selabel_handle* sehandle; * 7b. the user reboots (pulling the battery, etc) into the main system */ -FILE* fopen_path(const std::string& path, const char* mode) { - if (ensure_path_mounted(path.c_str()) != 0) { - LOG(ERROR) << "Can't mount " << path; - return nullptr; - } - - // When writing, try to create the containing directory, if necessary. Use generous permissions, - // the system (init.rc) will reset them. - if (strchr("wa", mode[0])) { - mkdir_recursively(path, 0777, true, sehandle); - } - return fopen(path.c_str(), mode); -} - -void check_and_fclose(FILE* fp, const std::string& name) { - fflush(fp); - if (fsync(fileno(fp)) == -1) { - PLOG(ERROR) << "Failed to fsync " << name; - } - if (ferror(fp)) { - PLOG(ERROR) << "Error in " << name; - } - fclose(fp); -} - bool is_ro_debuggable() { return android::base::GetBoolProperty("ro.debuggable", false); } @@ -259,98 +229,6 @@ static void set_sdcard_update_bootloader_message() { } } -// Read from kernel log into buffer and write out to file. -static void save_kernel_log(const char* destination) { - int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); - if (klog_buf_len <= 0) { - PLOG(ERROR) << "Error getting klog size"; - return; - } - - std::string buffer(klog_buf_len, 0); - int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); - if (n == -1) { - PLOG(ERROR) << "Error in reading klog"; - return; - } - buffer.resize(n); - android::base::WriteStringToFile(buffer, destination); -} - -// Writes content to the current pmsg session. -static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { - return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), - buf.data(), buf.size()); -} - -static void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { - std::string content; - android::base::ReadFileToString(source, &content); - __pmsg_write(destination, content); -} - -// How much of the temp log we have copied to the copy in cache. -static off_t tmplog_offset = 0; - -static void copy_log_file(const std::string& source, const std::string& destination, bool append) { - FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); - if (dest_fp == nullptr) { - PLOG(ERROR) << "Can't open " << destination; - } else { - FILE* source_fp = fopen(source.c_str(), "re"); - if (source_fp != nullptr) { - if (append) { - fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write - } - char buf[4096]; - size_t bytes; - while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { - fwrite(buf, 1, bytes, dest_fp); - } - if (append) { - tmplog_offset = ftello(source_fp); - } - check_and_fclose(source_fp, source); - } - check_and_fclose(dest_fp, destination); - } -} - -static void copy_logs() { - // We only rotate and record the log of the current session if there are actual attempts to modify - // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary - // rotation (and possible deletion) of log files, if it does not do anything loggable. - if (!modified_flash) { - return; - } - - // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. - copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); - copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); - - // We can do nothing for now if there's no /cache partition. - if (!has_cache) { - return; - } - - ensure_path_mounted(LAST_LOG_FILE); - ensure_path_mounted(LAST_KMSG_FILE); - rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); - - // Copy logs to cache so the system can find out what happened. - copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); - copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); - copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); - save_kernel_log(LAST_KMSG_FILE); - chmod(LOG_FILE, 0600); - chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_KMSG_FILE, 0600); - chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_LOG_FILE, 0640); - chmod(LAST_INSTALL_FILE, 0644); - sync(); -} - // Clear the recovery command and prepare to boot a (hopefully working) system, // copy our log file to cache as well (for the system to read). This function is // idempotent: call it as many times as you like. @@ -366,7 +244,7 @@ static void finish_recovery() { } } - copy_logs(); + copy_logs(modified_flash, has_cache); // Reset to normal system boot so recovery won't cycle indefinitely. std::string err; @@ -482,8 +360,8 @@ static bool erase_volume(const char* volume) { // Any part of the log we'd copied to cache is now gone. // Reset the pointer so we copy from the beginning of the temp // log. - tmplog_offset = 0; - copy_logs(); + reset_tmplog_offset(); + copy_logs(modified_flash, has_cache); } return (result == 0); @@ -1000,7 +878,7 @@ static Device::BuiltinAction prompt_and_wait(Device* device, int status) { if (status != INSTALL_SUCCESS) { ui->SetBackground(RecoveryUI::ERROR); ui->Print("Installation aborted.\n"); - copy_logs(); + copy_logs(modified_flash, has_cache); } else if (!ui->IsTextVisible()) { return Device::NO_ACTION; // reboot if logs aren't visible } else { @@ -1394,7 +1272,7 @@ int start_recovery(int argc, char** argv) { // RETRY_LIMIT times before we abandon this OTA update. static constexpr int RETRY_LIMIT = 4; if (status == INSTALL_RETRY && retry_count < RETRY_LIMIT) { - copy_logs(); + copy_logs(modified_flash, has_cache); retry_count += 1; set_retry_bootloader_message(retry_count, args); // Print retry count on screen. diff --git a/recovery_main.cpp b/recovery_main.cpp index 9f579f7cd..3147511ee 100644 --- a/recovery_main.cpp +++ b/recovery_main.cpp @@ -24,10 +24,10 @@ #include /* private pmsg functions */ #include "common.h" +#include "logging.h" #include "minadbd/minadbd.h" #include "otautil/paths.h" #include "private/recovery.h" -#include "rotate_logs.h" #include "ui.h" static void UiLogger(android::base::LogId /* id */, android::base::LogSeverity severity, diff --git a/rotate_logs.cpp b/rotate_logs.cpp deleted file mode 100644 index da008792c..000000000 --- a/rotate_logs.cpp +++ /dev/null @@ -1,107 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#include "rotate_logs.h" - -#include -#include -#include - -#include - -#include -#include -#include -#include -#include /* private pmsg functions */ - -static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; -static const std::string LAST_LOG_FILTER = "recovery/last_log"; - -ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, - size_t len, void* arg) { - bool* do_rotate = static_cast(arg); - if (LAST_KMSG_FILTER.find(filename) != std::string::npos || - LAST_LOG_FILTER.find(filename) != std::string::npos) { - *do_rotate = true; - } - return len; -} - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg) { - bool* do_rotate = static_cast(arg); - if (!*do_rotate) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - std::string name(filename); - size_t dot = name.find_last_of('.'); - std::string sub = name.substr(0, dot); - - if (LAST_KMSG_FILTER.find(sub) == std::string::npos && - LAST_LOG_FILTER.find(sub) == std::string::npos) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - // filename rotation - if (dot == std::string::npos) { - name += ".1"; - } else { - std::string number = name.substr(dot + 1); - if (!isdigit(number[0])) { - name += ".1"; - } else { - size_t i; - if (!android::base::ParseUint(number, &i)) { - LOG(ERROR) << "failed to parse uint in " << number; - return -1; - } - name = sub + "." + std::to_string(i + 1); - } - } - - return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); -} - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { - // Logs should only be rotated once. - static bool rotated = false; - if (rotated) { - return; - } - rotated = true; - - for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { - std::string old_log = android::base::StringPrintf("%s", last_log_file); - if (i > 0) { - old_log += "." + std::to_string(i); - } - std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); - // Ignore errors if old_log doesn't exist. - rename(old_log.c_str(), new_log.c_str()); - - std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); - if (i > 0) { - old_kmsg += "." + std::to_string(i); - } - std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); - rename(old_kmsg.c_str(), new_kmsg.c_str()); - } -} diff --git a/rotate_logs.h b/rotate_logs.h deleted file mode 100644 index 007c33d44..000000000 --- a/rotate_logs.h +++ /dev/null @@ -1,38 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#ifndef _ROTATE_LOGS_H -#define _ROTATE_LOGS_H - -#include -#include - -#include - -static constexpr int KEEP_LOG_COUNT = 10; - -ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file); - -#endif //_ROTATE_LOG_H -- cgit v1.2.3 From 152933a28e9afd9d696f5b0284e638894e6492ee Mon Sep 17 00:00:00 2001 From: Jerry Zhang Date: Wed, 2 May 2018 16:56:00 -0700 Subject: recovery: Refactor logging code into logging.cpp Move common logging related functions to rotate_logs.cpp, and rename that to logging.cpp. Test: Recovery works Bug: 78793464 Merged-In: I00f20a79a296680122b8437d54a87897c5cb2fc7 Change-Id: I00f20a79a296680122b8437d54a87897c5cb2fc7 --- Android.bp | 12 ++- Android.mk | 2 +- common.h | 9 +- logging.cpp | 243 +++++++++++++++++++++++++++++++++++++++++++++++++++ logging.h | 50 +++++++++++ recovery-persist.cpp | 2 +- recovery-refresh.cpp | 2 +- recovery.cpp | 134 ++-------------------------- recovery_main.cpp | 2 +- rotate_logs.cpp | 107 ----------------------- rotate_logs.h | 38 -------- 11 files changed, 315 insertions(+), 286 deletions(-) create mode 100644 logging.cpp create mode 100644 logging.h delete mode 100644 rotate_logs.cpp delete mode 100644 rotate_logs.h diff --git a/Android.bp b/Android.bp index 9ad961d5b..22c90bd3e 100644 --- a/Android.bp +++ b/Android.bp @@ -89,8 +89,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-persist.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -98,6 +98,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-persist.rc", ], @@ -112,8 +116,8 @@ cc_binary { ], srcs: [ + "logging.cpp", "recovery-refresh.cpp", - "rotate_logs.cpp", ], shared_libs: [ @@ -121,6 +125,10 @@ cc_binary { "liblog", ], + static_libs: [ + "libotautil", + ], + init_rc: [ "recovery-refresh.rc", ], diff --git a/Android.mk b/Android.mk index abe1b838f..afbc950fe 100644 --- a/Android.mk +++ b/Android.mk @@ -126,10 +126,10 @@ LOCAL_SRC_FILES := \ adb_install.cpp \ device.cpp \ fuse_sdcard_provider.cpp \ + logging.cpp \ recovery.cpp \ recovery_main.cpp \ roots.cpp \ - rotate_logs.cpp \ LOCAL_MODULE := recovery diff --git a/common.h b/common.h index de536fdb4..3dc36a960 100644 --- a/common.h +++ b/common.h @@ -27,7 +27,9 @@ static constexpr int kRecoveryApiVersion = 3; class RecoveryUI; +struct selabel_handle; +extern struct selabel_handle* sehandle; extern RecoveryUI* ui; extern bool modified_flash; @@ -37,13 +39,6 @@ extern std::string stage; // The reason argument provided in "--reason=". extern const char* reason; -// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the -// file pointer, or nullptr on error. -FILE* fopen_path(const std::string& path, const char* mode); - -// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. -void check_and_fclose(FILE* fp, const std::string& name); - void ui_print(const char* format, ...) __printflike(1, 2); bool is_ro_debuggable(); diff --git a/logging.cpp b/logging.cpp new file mode 100644 index 000000000..d5af72aad --- /dev/null +++ b/logging.cpp @@ -0,0 +1,243 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#include "logging.h" + +#include +#include +#include +#include + +#include + +#include +#include +#include +#include +#include /* for AID_SYSTEM */ +#include /* private pmsg functions */ + +#include "common.h" +#include "otautil/dirutil.h" +#include "otautil/paths.h" +#include "roots.h" + +static constexpr const char* LOG_FILE = "/cache/recovery/log"; +static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; +static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; +static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; + +static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; +static const std::string LAST_LOG_FILTER = "recovery/last_log"; + +// fopen(3)'s the given file, by mounting volumes and making parent dirs as necessary. Returns the +// file pointer, or nullptr on error. +static FILE* fopen_path(const std::string& path, const char* mode) { + if (ensure_path_mounted(path.c_str()) != 0) { + LOG(ERROR) << "Can't mount " << path; + return nullptr; + } + + // When writing, try to create the containing directory, if necessary. Use generous permissions, + // the system (init.rc) will reset them. + if (strchr("wa", mode[0])) { + mkdir_recursively(path, 0777, true, sehandle); + } + return fopen(path.c_str(), mode); +} + +void check_and_fclose(FILE* fp, const std::string& name) { + fflush(fp); + if (fsync(fileno(fp)) == -1) { + PLOG(ERROR) << "Failed to fsync " << name; + } + if (ferror(fp)) { + PLOG(ERROR) << "Error in " << name; + } + fclose(fp); +} + +// close a file, log an error if the error indicator is set +ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, + size_t len, void* arg) { + bool* do_rotate = static_cast(arg); + if (LAST_KMSG_FILTER.find(filename) != std::string::npos || + LAST_LOG_FILTER.find(filename) != std::string::npos) { + *do_rotate = true; + } + return len; +} + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg) { + bool* do_rotate = static_cast(arg); + if (!*do_rotate) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + std::string name(filename); + size_t dot = name.find_last_of('.'); + std::string sub = name.substr(0, dot); + + if (LAST_KMSG_FILTER.find(sub) == std::string::npos && + LAST_LOG_FILTER.find(sub) == std::string::npos) { + return __android_log_pmsg_file_write(id, prio, filename, buf, len); + } + + // filename rotation + if (dot == std::string::npos) { + name += ".1"; + } else { + std::string number = name.substr(dot + 1); + if (!isdigit(number[0])) { + name += ".1"; + } else { + size_t i; + if (!android::base::ParseUint(number, &i)) { + LOG(ERROR) << "failed to parse uint in " << number; + return -1; + } + name = sub + "." + std::to_string(i + 1); + } + } + + return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); +} + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { + // Logs should only be rotated once. + static bool rotated = false; + if (rotated) { + return; + } + rotated = true; + + for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { + std::string old_log = android::base::StringPrintf("%s", last_log_file); + if (i > 0) { + old_log += "." + std::to_string(i); + } + std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); + // Ignore errors if old_log doesn't exist. + rename(old_log.c_str(), new_log.c_str()); + + std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); + if (i > 0) { + old_kmsg += "." + std::to_string(i); + } + std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); + rename(old_kmsg.c_str(), new_kmsg.c_str()); + } +} + +// Writes content to the current pmsg session. +static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { + return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), + buf.data(), buf.size()); +} + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { + std::string content; + android::base::ReadFileToString(source, &content); + __pmsg_write(destination, content); +} + +// How much of the temp log we have copied to the copy in cache. +static off_t tmplog_offset = 0; + +void reset_tmplog_offset() { + tmplog_offset = 0; +} + +void copy_log_file(const std::string& source, const std::string& destination, bool append) { + FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); + if (dest_fp == nullptr) { + PLOG(ERROR) << "Can't open " << destination; + } else { + FILE* source_fp = fopen(source.c_str(), "re"); + if (source_fp != nullptr) { + if (append) { + fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write + } + char buf[4096]; + size_t bytes; + while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { + fwrite(buf, 1, bytes, dest_fp); + } + if (append) { + tmplog_offset = ftello(source_fp); + } + check_and_fclose(source_fp, source); + } + check_and_fclose(dest_fp, destination); + } +} + +void copy_logs(bool modified_flash, bool has_cache) { + // We only rotate and record the log of the current session if there are actual attempts to modify + // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary + // rotation (and possible deletion) of log files, if it does not do anything loggable. + if (!modified_flash) { + return; + } + + // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. + copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); + copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); + + // We can do nothing for now if there's no /cache partition. + if (!has_cache) { + return; + } + + ensure_path_mounted(LAST_LOG_FILE); + ensure_path_mounted(LAST_KMSG_FILE); + rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); + + // Copy logs to cache so the system can find out what happened. + copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); + copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); + copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); + save_kernel_log(LAST_KMSG_FILE); + chmod(LOG_FILE, 0600); + chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_KMSG_FILE, 0600); + chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); + chmod(LAST_LOG_FILE, 0640); + chmod(LAST_INSTALL_FILE, 0644); + sync(); +} + +// Read from kernel log into buffer and write out to file. +void save_kernel_log(const char* destination) { + int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); + if (klog_buf_len <= 0) { + PLOG(ERROR) << "Error getting klog size"; + return; + } + + std::string buffer(klog_buf_len, 0); + int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); + if (n == -1) { + PLOG(ERROR) << "Error in reading klog"; + return; + } + buffer.resize(n); + android::base::WriteStringToFile(buffer, destination); +} diff --git a/logging.h b/logging.h new file mode 100644 index 000000000..3cfbc7af6 --- /dev/null +++ b/logging.h @@ -0,0 +1,50 @@ +/* + * Copyright (C) 2016 The Android Open Source Project + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +#ifndef _LOGGING_H +#define _LOGGING_H + +#include +#include + +#include + +#include + +static constexpr int KEEP_LOG_COUNT = 10; + +ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, + void* arg); + +// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. +// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. +// Overwrite any existing last_log.$max and last_kmsg.$max. +void rotate_logs(const char* last_log_file, const char* last_kmsg_file); + +// In turn fflush(3)'s, fsync(3)'s and fclose(3)'s the given stream. +void check_and_fclose(FILE* fp, const std::string& name); + +void copy_log_file_to_pmsg(const std::string& source, const std::string& destination); +void copy_log_file(const std::string& source, const std::string& destination, bool append); +void copy_logs(bool modified_flash, bool has_cache); +void reset_tmplog_offset(); + +void save_kernel_log(const char* destination); + +#endif //_LOGGING_H diff --git a/recovery-persist.cpp b/recovery-persist.cpp index dbce7ff74..d3ade6260 100644 --- a/recovery-persist.cpp +++ b/recovery-persist.cpp @@ -41,7 +41,7 @@ #include #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" static const char *LAST_LOG_FILE = "/data/misc/recovery/last_log"; static const char *LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0"; diff --git a/recovery-refresh.cpp b/recovery-refresh.cpp index 14565d3f4..aee1ca592 100644 --- a/recovery-refresh.cpp +++ b/recovery-refresh.cpp @@ -42,7 +42,7 @@ #include /* private pmsg functions */ -#include "rotate_logs.h" +#include "logging.h" int main(int argc, char **argv) { static const char filter[] = "recovery/"; diff --git a/recovery.cpp b/recovery.cpp index 7219771cb..2ff7f1d9e 100644 --- a/recovery.cpp +++ b/recovery.cpp @@ -29,7 +29,6 @@ #include #include #include -#include #include #include #include @@ -53,8 +52,6 @@ #include #include /* for property_list */ #include -#include /* for AID_SYSTEM */ -#include /* private pmsg functions */ #include #include #include @@ -66,21 +63,19 @@ #include "fuse_sdcard_provider.h" #include "fuse_sideload.h" #include "install.h" +#include "logging.h" #include "minui/minui.h" #include "otautil/dirutil.h" #include "otautil/error_code.h" #include "otautil/paths.h" #include "otautil/sysutil.h" #include "roots.h" -#include "rotate_logs.h" #include "screen_ui.h" #include "stub_ui.h" #include "ui.h" static constexpr const char* CACHE_LOG_DIR = "/cache/recovery"; static constexpr const char* COMMAND_FILE = "/cache/recovery/command"; -static constexpr const char* LOG_FILE = "/cache/recovery/log"; -static constexpr const char* LAST_INSTALL_FILE = "/cache/recovery/last_install"; static constexpr const char* LAST_KMSG_FILE = "/cache/recovery/last_kmsg"; static constexpr const char* LAST_LOG_FILE = "/cache/recovery/last_log"; static constexpr const char* LOCALE_FILE = "/cache/recovery/last_locale"; @@ -149,31 +144,6 @@ struct selabel_handle* sehandle; * 7b. the user reboots (pulling the battery, etc) into the main system */ -FILE* fopen_path(const std::string& path, const char* mode) { - if (ensure_path_mounted(path.c_str()) != 0) { - LOG(ERROR) << "Can't mount " << path; - return nullptr; - } - - // When writing, try to create the containing directory, if necessary. Use generous permissions, - // the system (init.rc) will reset them. - if (strchr("wa", mode[0])) { - mkdir_recursively(path, 0777, true, sehandle); - } - return fopen(path.c_str(), mode); -} - -void check_and_fclose(FILE* fp, const std::string& name) { - fflush(fp); - if (fsync(fileno(fp)) == -1) { - PLOG(ERROR) << "Failed to fsync " << name; - } - if (ferror(fp)) { - PLOG(ERROR) << "Error in " << name; - } - fclose(fp); -} - bool is_ro_debuggable() { return android::base::GetBoolProperty("ro.debuggable", false); } @@ -259,98 +229,6 @@ static void set_sdcard_update_bootloader_message() { } } -// Read from kernel log into buffer and write out to file. -static void save_kernel_log(const char* destination) { - int klog_buf_len = klogctl(KLOG_SIZE_BUFFER, 0, 0); - if (klog_buf_len <= 0) { - PLOG(ERROR) << "Error getting klog size"; - return; - } - - std::string buffer(klog_buf_len, 0); - int n = klogctl(KLOG_READ_ALL, &buffer[0], klog_buf_len); - if (n == -1) { - PLOG(ERROR) << "Error in reading klog"; - return; - } - buffer.resize(n); - android::base::WriteStringToFile(buffer, destination); -} - -// Writes content to the current pmsg session. -static ssize_t __pmsg_write(const std::string& filename, const std::string& buf) { - return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, filename.c_str(), - buf.data(), buf.size()); -} - -static void copy_log_file_to_pmsg(const std::string& source, const std::string& destination) { - std::string content; - android::base::ReadFileToString(source, &content); - __pmsg_write(destination, content); -} - -// How much of the temp log we have copied to the copy in cache. -static off_t tmplog_offset = 0; - -static void copy_log_file(const std::string& source, const std::string& destination, bool append) { - FILE* dest_fp = fopen_path(destination, append ? "ae" : "we"); - if (dest_fp == nullptr) { - PLOG(ERROR) << "Can't open " << destination; - } else { - FILE* source_fp = fopen(source.c_str(), "re"); - if (source_fp != nullptr) { - if (append) { - fseeko(source_fp, tmplog_offset, SEEK_SET); // Since last write - } - char buf[4096]; - size_t bytes; - while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { - fwrite(buf, 1, bytes, dest_fp); - } - if (append) { - tmplog_offset = ftello(source_fp); - } - check_and_fclose(source_fp, source); - } - check_and_fclose(dest_fp, destination); - } -} - -static void copy_logs() { - // We only rotate and record the log of the current session if there are actual attempts to modify - // the flash, such as wipes, installs from BCB or menu selections. This is to avoid unnecessary - // rotation (and possible deletion) of log files, if it does not do anything loggable. - if (!modified_flash) { - return; - } - - // Always write to pmsg, this allows the OTA logs to be caught in `logcat -L`. - copy_log_file_to_pmsg(Paths::Get().temporary_log_file(), LAST_LOG_FILE); - copy_log_file_to_pmsg(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE); - - // We can do nothing for now if there's no /cache partition. - if (!has_cache) { - return; - } - - ensure_path_mounted(LAST_LOG_FILE); - ensure_path_mounted(LAST_KMSG_FILE); - rotate_logs(LAST_LOG_FILE, LAST_KMSG_FILE); - - // Copy logs to cache so the system can find out what happened. - copy_log_file(Paths::Get().temporary_log_file(), LOG_FILE, true); - copy_log_file(Paths::Get().temporary_log_file(), LAST_LOG_FILE, false); - copy_log_file(Paths::Get().temporary_install_file(), LAST_INSTALL_FILE, false); - save_kernel_log(LAST_KMSG_FILE); - chmod(LOG_FILE, 0600); - chown(LOG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_KMSG_FILE, 0600); - chown(LAST_KMSG_FILE, AID_SYSTEM, AID_SYSTEM); - chmod(LAST_LOG_FILE, 0640); - chmod(LAST_INSTALL_FILE, 0644); - sync(); -} - // Clear the recovery command and prepare to boot a (hopefully working) system, // copy our log file to cache as well (for the system to read). This function is // idempotent: call it as many times as you like. @@ -366,7 +244,7 @@ static void finish_recovery() { } } - copy_logs(); + copy_logs(modified_flash, has_cache); // Reset to normal system boot so recovery won't cycle indefinitely. std::string err; @@ -482,8 +360,8 @@ static bool erase_volume(const char* volume) { // Any part of the log we'd copied to cache is now gone. // Reset the pointer so we copy from the beginning of the temp // log. - tmplog_offset = 0; - copy_logs(); + reset_tmplog_offset(); + copy_logs(modified_flash, has_cache); } return (result == 0); @@ -1000,7 +878,7 @@ static Device::BuiltinAction prompt_and_wait(Device* device, int status) { if (status != INSTALL_SUCCESS) { ui->SetBackground(RecoveryUI::ERROR); ui->Print("Installation aborted.\n"); - copy_logs(); + copy_logs(modified_flash, has_cache); } else if (!ui->IsTextVisible()) { return Device::NO_ACTION; // reboot if logs aren't visible } else { @@ -1374,7 +1252,7 @@ int start_recovery(int argc, char** argv) { // RETRY_LIMIT times before we abandon this OTA update. static constexpr int RETRY_LIMIT = 4; if (status == INSTALL_RETRY && retry_count < RETRY_LIMIT) { - copy_logs(); + copy_logs(modified_flash, has_cache); retry_count += 1; set_retry_bootloader_message(retry_count, args); // Print retry count on screen. diff --git a/recovery_main.cpp b/recovery_main.cpp index 9f579f7cd..3147511ee 100644 --- a/recovery_main.cpp +++ b/recovery_main.cpp @@ -24,10 +24,10 @@ #include /* private pmsg functions */ #include "common.h" +#include "logging.h" #include "minadbd/minadbd.h" #include "otautil/paths.h" #include "private/recovery.h" -#include "rotate_logs.h" #include "ui.h" static void UiLogger(android::base::LogId /* id */, android::base::LogSeverity severity, diff --git a/rotate_logs.cpp b/rotate_logs.cpp deleted file mode 100644 index da008792c..000000000 --- a/rotate_logs.cpp +++ /dev/null @@ -1,107 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#include "rotate_logs.h" - -#include -#include -#include - -#include - -#include -#include -#include -#include -#include /* private pmsg functions */ - -static const std::string LAST_KMSG_FILTER = "recovery/last_kmsg"; -static const std::string LAST_LOG_FILTER = "recovery/last_log"; - -ssize_t logbasename(log_id_t /* id */, char /* prio */, const char* filename, const char* /* buf */, - size_t len, void* arg) { - bool* do_rotate = static_cast(arg); - if (LAST_KMSG_FILTER.find(filename) != std::string::npos || - LAST_LOG_FILTER.find(filename) != std::string::npos) { - *do_rotate = true; - } - return len; -} - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg) { - bool* do_rotate = static_cast(arg); - if (!*do_rotate) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - std::string name(filename); - size_t dot = name.find_last_of('.'); - std::string sub = name.substr(0, dot); - - if (LAST_KMSG_FILTER.find(sub) == std::string::npos && - LAST_LOG_FILTER.find(sub) == std::string::npos) { - return __android_log_pmsg_file_write(id, prio, filename, buf, len); - } - - // filename rotation - if (dot == std::string::npos) { - name += ".1"; - } else { - std::string number = name.substr(dot + 1); - if (!isdigit(number[0])) { - name += ".1"; - } else { - size_t i; - if (!android::base::ParseUint(number, &i)) { - LOG(ERROR) << "failed to parse uint in " << number; - return -1; - } - name = sub + "." + std::to_string(i + 1); - } - } - - return __android_log_pmsg_file_write(id, prio, name.c_str(), buf, len); -} - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file) { - // Logs should only be rotated once. - static bool rotated = false; - if (rotated) { - return; - } - rotated = true; - - for (int i = KEEP_LOG_COUNT - 1; i >= 0; --i) { - std::string old_log = android::base::StringPrintf("%s", last_log_file); - if (i > 0) { - old_log += "." + std::to_string(i); - } - std::string new_log = android::base::StringPrintf("%s.%d", last_log_file, i + 1); - // Ignore errors if old_log doesn't exist. - rename(old_log.c_str(), new_log.c_str()); - - std::string old_kmsg = android::base::StringPrintf("%s", last_kmsg_file); - if (i > 0) { - old_kmsg += "." + std::to_string(i); - } - std::string new_kmsg = android::base::StringPrintf("%s.%d", last_kmsg_file, i + 1); - rename(old_kmsg.c_str(), new_kmsg.c_str()); - } -} diff --git a/rotate_logs.h b/rotate_logs.h deleted file mode 100644 index 007c33d44..000000000 --- a/rotate_logs.h +++ /dev/null @@ -1,38 +0,0 @@ -/* - * Copyright (C) 2016 The Android Open Source Project - * - * Licensed under the Apache License, Version 2.0 (the "License"); - * you may not use this file except in compliance with the License. - * You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, software - * distributed under the License is distributed on an "AS IS" BASIS, - * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. - * See the License for the specific language governing permissions and - * limitations under the License. - */ - -#ifndef _ROTATE_LOGS_H -#define _ROTATE_LOGS_H - -#include -#include - -#include - -static constexpr int KEEP_LOG_COUNT = 10; - -ssize_t logbasename(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf, size_t len, - void* arg); - -// Rename last_log -> last_log.1 -> last_log.2 -> ... -> last_log.$max. -// Similarly rename last_kmsg -> last_kmsg.1 -> ... -> last_kmsg.$max. -// Overwrite any existing last_log.$max and last_kmsg.$max. -void rotate_logs(const char* last_log_file, const char* last_kmsg_file); - -#endif //_ROTATE_LOG_H -- cgit v1.2.3 From 864c668dd204e3cc7cdaa5d1c3d5b2da3d6f7f5e Mon Sep 17 00:00:00 2001 From: Tao Bao Date: Mon, 7 May 2018 11:38:25 -0700 Subject: updater: Skip an updated partition on retry. Prior to the change, the BBOTA updater would try to re-run all the commands for a given partition on retry, including creating stashes according to the list of commands. This could fail a retry when the previous update had moved on to next stage, with leftovers in /cache. This CL creates a marker on /cache upon successfully updating a partition. The update commands will be skipped when trying to apply updates on an updated partition. Note that the marker is expected to be removed while doing a normal boot (in particular, handled by RecoverySystem#handleAftermath). If that didn't happen, the updater would also remove the marker before starting next fresh update. Alternatively, we can achieve the same goal by changing the OTA script, which needs to additionally compare the checksum against the target build. For example, range_sha1("/system", "ranges") == SHA1_of_updated_system || block_image_update("/system"); The downside is that we need to pay that cost on each install, as the edify script doesn't support caching the result in a variable. Bug: 79165963 Test: Simulate the process on device (by triggering a reboot while updating /vendor). Check the update log and result. Change-Id: I731031fa336133e1221b33edfc469969706e8091 --- updater/blockimg.cpp | 116 ++++++++++++++++++++++++++++++++++----------------- 1 file changed, 77 insertions(+), 39 deletions(-) diff --git a/updater/blockimg.cpp b/updater/blockimg.cpp index d767d4467..b0ce2c3aa 100644 --- a/updater/blockimg.cpp +++ b/updater/blockimg.cpp @@ -116,6 +116,22 @@ static bool ParseLastCommandFile(int* last_command_index) { return true; } +static bool FsyncDir(const std::string& dirname) { + android::base::unique_fd dfd( + TEMP_FAILURE_RETRY(ota_open(dirname.c_str(), O_RDONLY | O_DIRECTORY))); + if (dfd == -1) { + failure_type = kFileOpenFailure; + PLOG(ERROR) << "Failed to open " << dirname; + return false; + } + if (fsync(dfd) == -1) { + failure_type = kFsyncFailure; + PLOG(ERROR) << "Failed to fsync " << dirname; + return false; + } + return true; +} + // Update the last command index in the last_command_file if the current command writes to the // stash either explicitly or implicitly. static bool UpdateLastCommandIndex(int command_index, const std::string& command_string) { @@ -144,19 +160,22 @@ static bool UpdateLastCommandIndex(int command_index, const std::string& command return false; } - std::string last_command_dir = android::base::Dirname(last_command_file); - android::base::unique_fd dfd( - TEMP_FAILURE_RETRY(ota_open(last_command_dir.c_str(), O_RDONLY | O_DIRECTORY))); - if (dfd == -1) { - PLOG(ERROR) << "Failed to open " << last_command_dir; + if (!FsyncDir(android::base::Dirname(last_command_file))) { return false; } - if (fsync(dfd) == -1) { - PLOG(ERROR) << "Failed to fsync " << last_command_dir; + return true; +} + +static bool SetPartitionUpdatedMarker(const std::string& marker) { + if (!android::base::WriteStringToFile("", marker)) { + PLOG(ERROR) << "Failed to write to marker file " << marker; return false; } - + if (!FsyncDir(android::base::Dirname(marker))) { + return false; + } + LOG(INFO) << "Wrote partition updated marker to " << marker; return true; } @@ -676,7 +695,11 @@ static std::string GetStashFileName(const std::string& base, const std::string& if (base.empty()) { return ""; } - return Paths::Get().stash_directory_base() + "/" + base + "/" + id + postfix; + std::string filename = Paths::Get().stash_directory_base() + "/" + base; + if (id.empty() && postfix.empty()) { + return filename; + } + return filename + "/" + id + postfix; } // Does a best effort enumeration of stash files. Ignores possible non-file items in the stash @@ -864,18 +887,9 @@ static int WriteStash(const std::string& base, const std::string& id, int blocks } std::string dname = GetStashFileName(base, "", ""); - android::base::unique_fd dfd(TEMP_FAILURE_RETRY(ota_open(dname.c_str(), - O_RDONLY | O_DIRECTORY))); - if (dfd == -1) { - failure_type = kFileOpenFailure; - PLOG(ERROR) << "failed to open \"" << dname << "\" failed"; - return -1; - } - - if (ota_fsync(dfd) == -1) { - failure_type = kFsyncFailure; - PLOG(ERROR) << "fsync \"" << dname << "\" failed"; - return -1; + if (!FsyncDir(dname)) { + failure_type = kFsyncFailure; + return -1; } return 0; @@ -884,30 +898,18 @@ static int WriteStash(const std::string& base, const std::string& id, int blocks // Creates a directory for storing stash files and checks if the /cache partition // hash enough space for the expected amount of blocks we need to store. Returns // >0 if we created the directory, zero if it existed already, and <0 of failure. - -static int CreateStash(State* state, size_t maxblocks, const std::string& blockdev, - std::string& base) { - if (blockdev.empty()) { - return -1; - } - - // Stash directory should be different for each partition to avoid conflicts - // when updating multiple partitions at the same time, so we use the hash of - // the block device name as the base directory - uint8_t digest[SHA_DIGEST_LENGTH]; - SHA1(reinterpret_cast(blockdev.data()), blockdev.size(), digest); - base = print_sha1(digest); - +static int CreateStash(State* state, size_t maxblocks, const std::string& base) { std::string dirname = GetStashFileName(base, "", ""); struct stat sb; int res = stat(dirname.c_str(), &sb); - size_t max_stash_size = maxblocks * BLOCKSIZE; - if (res == -1 && errno != ENOENT) { ErrorAbort(state, kStashCreationFailure, "stat \"%s\" failed: %s", dirname.c_str(), strerror(errno)); return -1; - } else if (res != 0) { + } + + size_t max_stash_size = maxblocks * BLOCKSIZE; + if (res == -1) { LOG(INFO) << "creating stash " << dirname; res = mkdir(dirname.c_str(), STASH_DIRECTORY_MODE); @@ -1595,6 +1597,35 @@ static Value* PerformBlockImageUpdate(const char* name, State* state, return StringValue(""); } + // Stash directory should be different for each partition to avoid conflicts when updating + // multiple partitions at the same time, so we use the hash of the block device name as the base + // directory. + uint8_t digest[SHA_DIGEST_LENGTH]; + SHA1(reinterpret_cast(blockdev_filename->data.data()), + blockdev_filename->data.size(), digest); + params.stashbase = print_sha1(digest); + + // Possibly do return early on retry, by checking the marker. If the update on this partition has + // been finished (but interrupted at a later point), there could be leftover on /cache that would + // fail the no-op retry. + std::string updated_marker = GetStashFileName(params.stashbase + ".UPDATED", "", ""); + if (is_retry) { + struct stat sb; + int result = stat(updated_marker.c_str(), &sb); + if (result == 0) { + LOG(INFO) << "Skipping already updated partition " << blockdev_filename->data + << " based on marker"; + return StringValue("t"); + } + } else { + // Delete the obsolete marker if any. + std::string err; + if (!android::base::RemoveFileIfExists(updated_marker, &err)) { + LOG(ERROR) << "Failed to remove partition updated marker " << updated_marker << ": " << err; + return StringValue(""); + } + } + if (params.canwrite) { params.nti.za = za; params.nti.entry = new_entry; @@ -1662,7 +1693,7 @@ static Value* PerformBlockImageUpdate(const char* name, State* state, return StringValue(""); } - int res = CreateStash(state, stash_max_blocks, blockdev_filename->data, params.stashbase); + int res = CreateStash(state, stash_max_blocks, params.stashbase); if (res == -1) { return StringValue(""); } @@ -1799,6 +1830,13 @@ pbiudone: // to complete the update later. DeleteStash(params.stashbase); DeleteLastCommandFile(); + + // Create a marker on /cache partition, which allows skipping the update on this partition on + // retry. The marker will be removed once booting into normal boot, or before starting next + // fresh install. + if (!SetPartitionUpdatedMarker(updated_marker)) { + LOG(WARNING) << "Failed to set updated marker; continuing"; + } } pthread_mutex_destroy(¶ms.nti.mu); -- cgit v1.2.3 From 98f875eee713096b03728c5d7424be503d4dc4c1 Mon Sep 17 00:00:00 2001 From: Tao Bao Date: Mon, 7 May 2018 15:03:30 -0700 Subject: updater: Fix an issue when resuming an update. We cannot skip "new" commands while resuming an update with last_command_file, because they read in the data sequentially from the package. Bug: 69858743 Test: Interrupt an update that has new commands. Check the update log. Change-Id: I05fb67246f5ea3ba2a0f78f10255c0d9b0bc2f5a --- updater/blockimg.cpp | 9 ++++++--- 1 file changed, 6 insertions(+), 3 deletions(-) diff --git a/updater/blockimg.cpp b/updater/blockimg.cpp index d767d4467..7b98f7f9a 100644 --- a/updater/blockimg.cpp +++ b/updater/blockimg.cpp @@ -1730,8 +1730,12 @@ static Value* PerformBlockImageUpdate(const char* name, State* state, continue; } - // Skip all commands before the saved last command index when resuming an update. - if (params.canwrite && params.cmdindex != -1 && params.cmdindex <= saved_last_command_index) { + std::string cmdname = std::string(params.cmdname); + + // Skip all commands before the saved last command index when resuming an update, except for + // "new" command. Because new commands read in the data sequentially. + if (params.canwrite && params.cmdindex != -1 && params.cmdindex <= saved_last_command_index && + cmdname != "new") { LOG(INFO) << "Skipping already executed command: " << params.cmdindex << ", last executed command for previous update: " << saved_last_command_index; continue; @@ -1748,7 +1752,6 @@ static Value* PerformBlockImageUpdate(const char* name, State* state, if (!params.canwrite && saved_last_command_index != -1 && params.cmdindex != -1 && params.cmdindex <= saved_last_command_index) { // TODO(xunchang) check that the cmdline of the saved index is correct. - std::string cmdname = std::string(params.cmdname); if ((cmdname == "move" || cmdname == "bsdiff" || cmdname == "imgdiff") && !params.target_verified) { LOG(WARNING) << "Previously executed command " << saved_last_command_index << ": " -- cgit v1.2.3