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
This commit is contained in:
Jerry Zhang 2018-05-02 16:56:00 -07:00
parent 420f7f8df4
commit 152933a28e
10 changed files with 280 additions and 251 deletions

View file

@ -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",
],

View file

@ -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

View file

@ -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();

243
logging.cpp Normal file
View file

@ -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 <stdio.h>
#include <string.h>
#include <sys/klog.h>
#include <sys/types.h>
#include <string>
#include <android-base/file.h>
#include <android-base/logging.h>
#include <android-base/parseint.h>
#include <android-base/stringprintf.h>
#include <private/android_filesystem_config.h> /* for AID_SYSTEM */
#include <private/android_logger.h> /* 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<bool*>(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<bool*>(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);
}

View file

@ -14,12 +14,14 @@
* limitations under the License.
*/
#ifndef _ROTATE_LOGS_H
#define _ROTATE_LOGS_H
#ifndef _LOGGING_H
#define _LOGGING_H
#include <stddef.h>
#include <sys/types.h>
#include <string>
#include <log/log_id.h>
static constexpr int KEEP_LOG_COUNT = 10;
@ -35,4 +37,14 @@ ssize_t logrotate(log_id_t id, char prio, const char* filename, const char* buf,
// 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
// 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

View file

@ -41,7 +41,7 @@
#include <android-base/logging.h>
#include <private/android_logger.h> /* 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";

View file

@ -42,7 +42,7 @@
#include <private/android_logger.h> /* private pmsg functions */
#include "rotate_logs.h"
#include "logging.h"
int main(int argc, char **argv) {
static const char filter[] = "recovery/";

View file

@ -29,7 +29,6 @@
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
#include <sys/klog.h>
#include <sys/stat.h>
#include <sys/types.h>
#include <sys/wait.h>
@ -53,8 +52,6 @@
#include <cutils/android_reboot.h>
#include <cutils/properties.h> /* for property_list */
#include <healthd/BatteryMonitor.h>
#include <private/android_filesystem_config.h> /* for AID_SYSTEM */
#include <private/android_logger.h> /* private pmsg functions */
#include <selinux/android.h>
#include <selinux/label.h>
#include <selinux/selinux.h>
@ -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.

View file

@ -24,10 +24,10 @@
#include <private/android_logger.h> /* 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,

View file

@ -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 <stdio.h>
#include <string.h>
#include <sys/types.h>
#include <string>
#include <android-base/file.h>
#include <android-base/logging.h>
#include <android-base/parseint.h>
#include <android-base/stringprintf.h>
#include <private/android_logger.h> /* 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<bool*>(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<bool*>(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());
}
}