From 13aca598f8e93548fef36d87136e85ce8c9d18de Mon Sep 17 00:00:00 2001 From: Mark Salyzyn Date: Wed, 9 Mar 2016 14:58:16 -0800 Subject: recovery: use __android_log_pmsg_file_write for log files (cherry-pick from commit a4f701af93a5a739f34823cde0c493dfbc63537a) - Add call to __android_log_pmsg_file_write for recovery logging. - Add call to refresh pmsg if we reboot back into recovery and then allow overwrite of those logs. - Add a new one-time executable recovery-refresh that refreshes pmsg in post-fs phase of init. We rely on pmsg eventually scrolling off to age the content after recovery-persist has done its job. - Add a new one-time executable recovery-persist that transfers from pmsg to /data/misc/recovery/ directory if /cache is not mounted in post-fs-data phase of init. - Build and appropriately trigger the above two as required if BOARD_CACHEIMAGE_PARTITION_SIZE is undefined. - Add some simple unit tests NB: Test failure is expected on systems that do not deliver either the recovery-persist or recovery-refresh executables, e.g. systems with /cache. Tests also require a timely reboot sequence of test to truly verify, tests provide guidance on stderr to direct. Bug: 27176738 Change-Id: I17bb95980234984f6b2087fd5941b0a3126b706b --- Android.mk | 24 ++++++ recovery-persist.cpp | 200 +++++++++++++++++++++++++++++++++++++++++++ recovery-persist.rc | 3 + recovery-refresh.cpp | 128 +++++++++++++++++++++++++++ recovery-refresh.rc | 2 + recovery.cpp | 109 ++++++++++++++++++++--- tests/Android.mk | 2 + tests/unit/recovery_test.cpp | 92 ++++++++++++++++++++ 8 files changed, 548 insertions(+), 12 deletions(-) create mode 100644 recovery-persist.cpp create mode 100644 recovery-persist.rc create mode 100644 recovery-refresh.cpp create mode 100644 recovery-refresh.rc create mode 100644 tests/unit/recovery_test.cpp diff --git a/Android.mk b/Android.mk index 5b488ca6d..6c3ce5642 100644 --- a/Android.mk +++ b/Android.mk @@ -101,6 +101,30 @@ else LOCAL_STATIC_LIBRARIES += $(TARGET_RECOVERY_UI_LIB) endif +ifeq ($(BOARD_CACHEIMAGE_PARTITION_SIZE),) +LOCAL_REQUIRED_MODULES := recovery-persist recovery-refresh +endif + +include $(BUILD_EXECUTABLE) + +# recovery-persist (system partition dynamic executable run after /data mounts) +# =============================== +include $(CLEAR_VARS) +LOCAL_SRC_FILES := recovery-persist.cpp +LOCAL_MODULE := recovery-persist +LOCAL_SHARED_LIBRARIES := liblog libbase +LOCAL_CFLAGS := -Werror +LOCAL_INIT_RC := recovery-persist.rc +include $(BUILD_EXECUTABLE) + +# recovery-refresh (system partition dynamic executable run at init) +# =============================== +include $(CLEAR_VARS) +LOCAL_SRC_FILES := recovery-refresh.cpp +LOCAL_MODULE := recovery-refresh +LOCAL_SHARED_LIBRARIES := liblog +LOCAL_CFLAGS := -Werror +LOCAL_INIT_RC := recovery-refresh.rc include $(BUILD_EXECUTABLE) # All the APIs for testing diff --git a/recovery-persist.cpp b/recovery-persist.cpp new file mode 100644 index 000000000..8587e9a66 --- /dev/null +++ b/recovery-persist.cpp @@ -0,0 +1,200 @@ +/* + * 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. + */ + +#define LOG_TAG "recovery-persist" + +// +// Strictly to deal with reboot into system after OTA after /data +// mounts to pull the last pmsg file data and place it +// into /data/misc/recovery/ directory, rotating it in. +// +// Usage: recovery-persist [--force-persist] +// +// On systems without /cache mount, all file content representing in the +// recovery/ directory stored in /sys/fs/pstore/pmsg-ramoops-0 in logger +// format that reside in the LOG_ID_SYSTEM buffer at ANDROID_LOG_INFO +// priority or higher is transfered to the /data/misc/recovery/ directory. +// The content is matched and rotated in as need be. +// +// --force-persist ignore /cache mount, always rotate in the contents. +// + +#include +#include +#include +#include +#include + +#include + +#include /* Android Log Priority Tags */ +#include +#include +#include /* Android Log packet format */ +#include /* private pmsg functions */ + +static const char *LAST_LOG_FILE = "/data/misc/recovery/last_log"; +static const char *LAST_PMSG_FILE = "/sys/fs/pstore/pmsg-ramoops-0"; +static const char *LAST_KMSG_FILE = "/data/misc/recovery/last_kmsg"; +static const char *LAST_CONSOLE_FILE = "/sys/fs/pstore/console-ramoops-0"; + +static const int KEEP_LOG_COUNT = 10; + +// close a file, log an error if the error indicator is set +static void check_and_fclose(FILE *fp, const char *name) { + fflush(fp); + if (ferror(fp)) SLOGE("%s %s", name, strerror(errno)); + fclose(fp); +} + +static void copy_file(const char* source, const char* destination) { + FILE* dest_fp = fopen(destination, "w"); + if (dest_fp == nullptr) { + SLOGE("%s %s", destination, strerror(errno)); + } else { + FILE* source_fp = fopen(source, "r"); + if (source_fp != nullptr) { + char buf[4096]; + size_t bytes; + while ((bytes = fread(buf, 1, sizeof(buf), source_fp)) != 0) { + fwrite(buf, 1, bytes, dest_fp); + } + check_and_fclose(source_fp, source); + } + check_and_fclose(dest_fp, destination); + } +} + +static bool rotated = false; + +// 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. +static void rotate_logs(int max) { + // Logs should only be rotated once. + + if (rotated) { + return; + } + rotated = true; + + for (int i = max-1; i >= 0; --i) { + std::string old_log(LAST_LOG_FILE); + if (i > 0) { + old_log += "." + std::to_string(i); + } + std::string new_log(LAST_LOG_FILE); + new_log += "." + std::to_string(i+1); + + // Ignore errors if old_log doesn't exist. + rename(old_log.c_str(), new_log.c_str()); + + std::string old_kmsg(LAST_KMSG_FILE); + if (i > 0) { + old_kmsg += "." + std::to_string(i); + } + std::string new_kmsg(LAST_KMSG_FILE); + new_kmsg += "." + std::to_string(i+1); + + rename(old_kmsg.c_str(), new_kmsg.c_str()); + } +} + +ssize_t logsave( + log_id_t /* logId */, + char /* prio */, + const char *filename, + const char *buf, size_t len, + void * /* arg */) { + + std::string destination("/data/misc/"); + destination += filename; + + std::string buffer(buf, len); + + { + std::string content; + android::base::ReadFileToString(destination, &content); + + if (buffer.compare(content) == 0) { + return len; + } + } + + // ToDo: Any others that match? Are we pulling in multiple + // already-rotated files? Algorithm thus far is KISS: one file, + // one rotation allowed. + + rotate_logs(KEEP_LOG_COUNT); + + return android::base::WriteStringToFile(buffer, destination.c_str()); +} + +int main(int argc, char **argv) { + + /* Is /cache a mount?, we have been delivered where we are not wanted */ + /* + * Following code halves the size of the executable as compared to: + * + * load_volume_table(); + * has_cache = volume_for_path(CACHE_ROOT) != nullptr; + */ + bool has_cache = false; + static const char mounts_file[] = "/proc/mounts"; + FILE *fp = fopen(mounts_file, "r"); + if (!fp) { + SLOGV("%s %s", mounts_file, strerror(errno)); + } else { + char *line = NULL; + size_t len = 0; + ssize_t read; + while ((read = getline(&line, &len, fp)) != -1) { + if (strstr(line, " /cache ")) { + has_cache = true; + break; + } + } + free(line); + fclose(fp); + } + + if (has_cache) { + /* + * TBD: Future location to move content from + * /cache/recovery to /data/misc/recovery/ + */ + /* if --force-persist flag, then transfer pmsg data anyways */ + if ((argc <= 1) || !argv[1] || strcmp(argv[1], "--force-persist")) { + return 0; + } + } + + /* Is there something in pmsg? */ + if (access(LAST_PMSG_FILE, R_OK)) { + return 0; + } + + // Take last pmsg file contents and send it off to the logsave + __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, "recovery/", logsave, NULL); + + /* Is there a last console log too? */ + if (rotated && !access(LAST_CONSOLE_FILE, R_OK)) { + copy_file(LAST_CONSOLE_FILE, LAST_KMSG_FILE); + } + + return 0; +} diff --git a/recovery-persist.rc b/recovery-persist.rc new file mode 100644 index 000000000..6761627d5 --- /dev/null +++ b/recovery-persist.rc @@ -0,0 +1,3 @@ +on post-fs-data + mkdir /data/misc/recovery 0770 system log + exec - system log -- /system/bin/recovery-persist diff --git a/recovery-refresh.cpp b/recovery-refresh.cpp new file mode 100644 index 000000000..70adc70ee --- /dev/null +++ b/recovery-refresh.cpp @@ -0,0 +1,128 @@ +/* + * 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. + */ + +#define LOG_TAG "recovery-refresh" + +// +// Strictly to deal with reboot into system after OTA, then +// reboot while in system before boot complete landing us back +// into recovery to continue with any mitigations with retained +// log history. This simply refreshes the pmsg files from +// the last pmsg file contents. +// +// Usage: +// recovery-refresh [--force-rotate|--rotate] +// +// All file content representing in the recovery/ directory stored in +// /sys/fs/pstore/pmsg-ramoops-0 in logger format that reside in the +// LOG_ID_SYSTEM buffer at ANDROID_LOG_INFO priority or higher is +// refreshed into /dev/pmsg0. This ensures that an unexpected reboot +// before recovery-persist is run will still contain the associated +// pmsg Android Logger content. +// +// --force-rotate recovery/last_kmsg and recovery.last_log files are +// rotated with . suffixes upwards. +// --rotate rotated only if rocovery/last_msg or recovery/last_log +// exist, otherwise perform 1:1 refresh. +// + +#include + +#include + +#include /* Android Log Priority Tags */ +#include /* Android Log packet format */ +#include /* private pmsg functions */ + +static const char LAST_KMSG_FILE[] = "recovery/last_kmsg"; +static const char LAST_LOG_FILE[] = "recovery/last_log"; + +static ssize_t logbasename( + log_id_t /* logId */, + char /* prio */, + const char *filename, + const char * /* buf */, size_t len, + void *arg) { + if (strstr(LAST_KMSG_FILE, filename) || + strstr(LAST_LOG_FILE, filename)) { + bool *doRotate = reinterpret_cast(arg); + *doRotate = true; + } + return len; +} + +static ssize_t logrotate( + log_id_t logId, + char prio, + const char *filename, + const char *buf, size_t len, + void *arg) { + bool *doRotate = reinterpret_cast(arg); + if (!*doRotate) { + return __android_log_pmsg_file_write(logId, prio, filename, buf, len); + } + + std::string name(filename); + size_t dot = name.find_last_of("."); + std::string sub = name.substr(0, dot); + + if (!strstr(LAST_KMSG_FILE, sub.c_str()) && + !strstr(LAST_LOG_FILE, sub.c_str())) { + return __android_log_pmsg_file_write(logId, prio, filename, buf, len); + } + + // filename rotation + if (dot == std::string::npos) { + name += ".1"; + } else { + std::string number = name.substr(dot + 1); + if (!isdigit(number.data()[0])) { + name += ".1"; + } else { + unsigned long long i = std::stoull(number); + name = sub + "." + std::to_string(i + 1); + } + } + + return __android_log_pmsg_file_write(logId, prio, name.c_str(), buf, len); +} + +int main(int argc, char **argv) { + static const char filter[] = "recovery/"; + static const char force_rotate_flag[] = "--force-rotate"; + static const char rotate_flag[] = "--rotate"; + ssize_t ret; + bool doRotate = false; + + // Take last pmsg contents and rewrite it to the current pmsg session. + if ((argc <= 1) || !argv[1] || + (((doRotate = strcmp(argv[1], rotate_flag))) && + strcmp(argv[1], force_rotate_flag))) { + doRotate = false; + } else if (!doRotate) { + // Do we need to rotate? + __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, filter, + logbasename, &doRotate); + } + + // Take action to refresh pmsg contents + ret = __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, filter, + logrotate, &doRotate); + + return (ret < 0) ? ret : 0; +} diff --git a/recovery-refresh.rc b/recovery-refresh.rc new file mode 100644 index 000000000..14b05cca4 --- /dev/null +++ b/recovery-refresh.rc @@ -0,0 +1,2 @@ +on post-fs + exec - system log -- /system/bin/recovery-refresh diff --git a/recovery.cpp b/recovery.cpp index 7620f1a00..508cd62ee 100644 --- a/recovery.cpp +++ b/recovery.cpp @@ -35,11 +35,14 @@ #include #include +#include /* Android Log Priority Tags */ #include #include #include #include #include +#include /* Android Log packet format */ +#include /* private pmsg functions */ #include @@ -381,6 +384,18 @@ static void save_kernel_log(const char* destination) { android::base::WriteStringToFile(buffer, destination); } +// write content to the current pmsg session. +static ssize_t __pmsg_write(const char *filename, const char *buf, size_t len) { + return __android_log_pmsg_file_write(LOG_ID_SYSTEM, ANDROID_LOG_INFO, + filename, buf, len); +} + +static void copy_log_file_to_pmsg(const char* source, const char* destination) { + std::string content; + android::base::ReadFileToString(source, &content); + __pmsg_write(destination, content.c_str(), content.length()); +} + // How much of the temp log we have copied to the copy in cache. static long tmplog_offset = 0; @@ -440,11 +455,6 @@ static void rotate_logs(int max) { } static void copy_logs() { - // We can do nothing for now if there's no /cache partition. - if (!has_cache) { - return; - } - // 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 @@ -453,6 +463,15 @@ static void copy_logs() { return; } + // Always write to pmsg, this allows the OTA logs to be caught in logcat -L + copy_log_file_to_pmsg(TEMPORARY_LOG_FILE, LAST_LOG_FILE); + copy_log_file_to_pmsg(TEMPORARY_INSTALL_FILE, LAST_INSTALL_FILE); + + // We can do nothing for now if there's no /cache partition. + if (!has_cache) { + return; + } + rotate_logs(KEEP_LOG_COUNT); // Copy logs to cache so the system can find out what happened. @@ -489,13 +508,17 @@ finish_recovery(const char *send_intent) { // Save the locale to cache, so if recovery is next started up // without a --locale argument (eg, directly from the bootloader) // it will use the last-known locale. - if (locale != NULL && has_cache) { - LOGI("Saving locale \"%s\"\n", locale); - FILE* fp = fopen_path(LOCALE_FILE, "w"); - fwrite(locale, 1, strlen(locale), fp); - fflush(fp); - fsync(fileno(fp)); - check_and_fclose(fp, LOCALE_FILE); + if (locale != NULL) { + size_t len = strlen(locale); + __pmsg_write(LOCALE_FILE, locale, len); + if (has_cache) { + LOGI("Saving locale \"%s\"\n", locale); + FILE* fp = fopen_path(LOCALE_FILE, "w"); + fwrite(locale, 1, len, fp); + fflush(fp); + fsync(fileno(fp)); + check_and_fclose(fp, LOCALE_FILE); + } } copy_logs(); @@ -1188,7 +1211,69 @@ static void set_retry_bootloader_message(int retry_count, int argc, char** argv) set_bootloader_message(&boot); } +static ssize_t logbasename( + log_id_t /* logId */, + char /* prio */, + const char *filename, + const char * /* buf */, size_t len, + void *arg) { + if (strstr(LAST_KMSG_FILE, filename) || + strstr(LAST_LOG_FILE, filename)) { + bool *doRotate = reinterpret_cast(arg); + *doRotate = true; + } + return len; +} + +static ssize_t logrotate( + log_id_t logId, + char prio, + const char *filename, + const char *buf, size_t len, + void *arg) { + bool *doRotate = reinterpret_cast(arg); + if (!*doRotate) { + return __android_log_pmsg_file_write(logId, prio, filename, buf, len); + } + + std::string name(filename); + size_t dot = name.find_last_of("."); + std::string sub = name.substr(0, dot); + + if (!strstr(LAST_KMSG_FILE, sub.c_str()) && + !strstr(LAST_LOG_FILE, sub.c_str())) { + return __android_log_pmsg_file_write(logId, prio, filename, buf, len); + } + + // filename rotation + if (dot == std::string::npos) { + name += ".1"; + } else { + std::string number = name.substr(dot + 1); + if (!isdigit(number.data()[0])) { + name += ".1"; + } else { + unsigned long long i = std::stoull(number); + name = sub + "." + std::to_string(i + 1); + } + } + + return __android_log_pmsg_file_write(logId, prio, name.c_str(), buf, len); +} + int main(int argc, char **argv) { + // Take last pmsg contents and rewrite it to the current pmsg session. + static const char filter[] = "recovery/"; + // Do we need to rotate? + bool doRotate = false; + __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, filter, + logbasename, &doRotate); + // Take action to refresh pmsg contents + __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, filter, + logrotate, &doRotate); + // If this binary is started with the single argument "--adbd", // instead of being the normal recovery binary, it turns into kind // of a stripped-down version of adbd that only supports the diff --git a/tests/Android.mk b/tests/Android.mk index 9d83c9a49..eac3581ae 100644 --- a/tests/Android.mk +++ b/tests/Android.mk @@ -23,7 +23,9 @@ LOCAL_MODULE := recovery_unit_test LOCAL_ADDITIONAL_DEPENDENCIES := $(LOCAL_PATH)/Android.mk LOCAL_STATIC_LIBRARIES := libverifier LOCAL_SRC_FILES := unit/asn1_decoder_test.cpp +LOCAL_SRC_FILES += unit/recovery_test.cpp LOCAL_C_INCLUDES := bootable/recovery +LOCAL_SHARED_LIBRARIES := liblog include $(BUILD_NATIVE_TEST) # Component tests diff --git a/tests/unit/recovery_test.cpp b/tests/unit/recovery_test.cpp new file mode 100644 index 000000000..f397f258e --- /dev/null +++ b/tests/unit/recovery_test.cpp @@ -0,0 +1,92 @@ +/* + * 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 +#include +#include +#include + +#include +#include +#include +#include + +static const char myFilename[] = "/data/misc/recovery/inject.txt"; +static const char myContent[] = "Hello World\nWelcome to my recovery\n"; + +// Failure is expected on systems that do not deliver either the +// recovery-persist or recovery-refresh executables. Tests also require +// a reboot sequence of test to truly verify. + +static ssize_t __pmsg_fn(log_id_t logId, char prio, const char *filename, + const char *buf, size_t len, void *arg) { + EXPECT_EQ(LOG_ID_SYSTEM, logId); + EXPECT_EQ(ANDROID_LOG_INFO, prio); + EXPECT_EQ(0, NULL == strstr(myFilename,filename)); + EXPECT_EQ(0, strcmp(myContent, buf)); + EXPECT_EQ(sizeof(myContent), len); + EXPECT_EQ(0, NULL != arg); + return len; +} + +// recovery.refresh - May fail. Requires recovery.inject, two reboots, +// then expect success after second reboot. +TEST(recovery, refresh) { + EXPECT_EQ(0, access("/system/bin/recovery-refresh", F_OK)); + + ssize_t ret = __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, "recovery/", __pmsg_fn, NULL); + if (ret == -ENOENT) { + EXPECT_LT(0, __android_log_pmsg_file_write( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, + myFilename, myContent, sizeof(myContent))); + fprintf(stderr, "injected test data, " + "requires two intervening reboots " + "to check for replication\n"); + } + EXPECT_EQ((ssize_t)sizeof(myContent), ret); +} + +// recovery.persist - Requires recovery.inject, then a reboot, then +// expect success after for this test on that boot. +TEST(recovery, persist) { + EXPECT_EQ(0, access("/system/bin/recovery-persist", F_OK)); + + ssize_t ret = __android_log_pmsg_file_read( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, "recovery/", __pmsg_fn, NULL); + if (ret == -ENOENT) { + EXPECT_LT(0, __android_log_pmsg_file_write( + LOG_ID_SYSTEM, ANDROID_LOG_INFO, + myFilename, myContent, sizeof(myContent))); + fprintf(stderr, "injected test data, " + "requires intervening reboot " + "to check for storage\n"); + } + + int fd = open(myFilename, O_RDONLY); + EXPECT_LE(0, fd); + + char buf[sizeof(myContent) + 32]; + ret = read(fd, buf, sizeof(buf)); + close(fd); + EXPECT_EQ(ret, (ssize_t)sizeof(myContent)); + EXPECT_EQ(0, strcmp(myContent, buf)); + if (fd >= 0) { + fprintf(stderr, "Removing persistent test data, " + "check if reconstructed on reboot\n"); + } + EXPECT_EQ(0, unlink(myFilename)); +} -- cgit v1.2.3