From e179157dc543cb4b94479fe069c8c7b2228ed71c Mon Sep 17 00:00:00 2001 From: David Anderson Date: Fri, 5 Nov 2021 18:57:49 -0700 Subject: [PATCH 1/2] Improve vold logging. This patch adds more error logging to mountFstab. In a few cases, the were error paths with no existing error logs. In other cases, the log messages are there to help understand error flow in logs (for example when a function with lots of error paths returns false). Bug: 205314634 Test: treehugger builds Change-Id: I464edc6e74ea0d7419ee9d9b75fd238752c13f4f --- KeyStorage.cpp | 20 ++++++++++++++++---- KeyUtil.cpp | 5 ++++- MetadataCrypt.cpp | 26 ++++++++++++++++++++------ 3 files changed, 40 insertions(+), 11 deletions(-) diff --git a/KeyStorage.cpp b/KeyStorage.cpp index 50bba56..4b39aef 100644 --- a/KeyStorage.cpp +++ b/KeyStorage.cpp @@ -601,9 +601,15 @@ static bool storeKey(const std::string& dir, const KeyAuthentication& auth, cons if (!generateKeyStorageKey(keystore, appId, &ksKey)) return false; if (!writeStringToFile(ksKey, dir + "/" + kFn_keymaster_key_blob)) return false; km::AuthorizationSet keyParams = beginParams(appId); - if (!encryptWithKeystoreKey(keystore, dir, keyParams, key, &encryptedKey)) return false; + if (!encryptWithKeystoreKey(keystore, dir, keyParams, key, &encryptedKey)) { + LOG(ERROR) << "encryptWithKeystoreKey failed"; + return false; + } } else { - if (!encryptWithoutKeystore(appId, key, &encryptedKey)) return false; + if (!encryptWithoutKeystore(appId, key, &encryptedKey)) { + LOG(ERROR) << "encryptWithoutKeystore failed"; + return false; + } } if (!writeStringToFile(encryptedKey, dir + "/" + kFn_encrypted_key)) return false; if (!FsyncDirectory(dir)) return false; @@ -648,9 +654,15 @@ bool retrieveKey(const std::string& dir, const KeyAuthentication& auth, KeyBuffe Keystore keystore; if (!keystore) return false; km::AuthorizationSet keyParams = beginParams(appId); - if (!decryptWithKeystoreKey(keystore, dir, keyParams, encryptedMessage, key)) return false; + if (!decryptWithKeystoreKey(keystore, dir, keyParams, encryptedMessage, key)) { + LOG(ERROR) << "decryptWithKeystoreKey failed"; + return false; + } } else { - if (!decryptWithoutKeystore(appId, encryptedMessage, key)) return false; + if (!decryptWithoutKeystore(appId, encryptedMessage, key)) { + LOG(ERROR) << "decryptWithoutKeystore failed"; + return false; + } } return true; } diff --git a/KeyUtil.cpp b/KeyUtil.cpp index 2f9c876..25d5af3 100644 --- a/KeyUtil.cpp +++ b/KeyUtil.cpp @@ -54,7 +54,10 @@ static bool randomKey(size_t size, KeyBuffer* key) { } bool generateStorageKey(const KeyGeneration& gen, KeyBuffer* key) { - if (!gen.allow_gen) return false; + if (!gen.allow_gen) { + LOG(ERROR) << "Generating storage key not allowed"; + return false; + } if (gen.use_hw_wrapped_key) { if (gen.keysize != FSCRYPT_MAX_KEY_SIZE) { LOG(ERROR) << "Cannot generate a wrapped key " << gen.keysize << " bytes long"; diff --git a/MetadataCrypt.cpp b/MetadataCrypt.cpp index 8b2b960..0bd6100 100644 --- a/MetadataCrypt.cpp +++ b/MetadataCrypt.cpp @@ -245,7 +245,8 @@ bool fscrypt_mount_metadata_encrypted(const std::string& blk_device, const std:: << fs_type; auto encrypted_state = android::base::GetProperty("ro.crypto.state", ""); if (encrypted_state != "" && encrypted_state != "encrypted") { - LOG(DEBUG) << "fscrypt_enable_crypto got unexpected starting state: " << encrypted_state; + LOG(ERROR) << "fscrypt_mount_metadata_encrypted got unexpected starting state: " + << encrypted_state; return false; } @@ -282,12 +283,18 @@ bool fscrypt_mount_metadata_encrypted(const std::string& blk_device, const std:: auto gen = needs_encrypt ? makeGen(options) : neverGen(); KeyBuffer key; - if (!read_key(data_rec->metadata_key_dir, gen, &key)) return false; + if (!read_key(data_rec->metadata_key_dir, gen, &key)) { + LOG(ERROR) << "read_key failed in mountFstab"; + return false; + } std::string crypto_blkdev; uint64_t nr_sec; - if (!create_crypto_blk_dev(kDmNameUserdata, blk_device, key, options, &crypto_blkdev, &nr_sec)) + if (!create_crypto_blk_dev(kDmNameUserdata, blk_device, key, options, &crypto_blkdev, + &nr_sec)) { + LOG(ERROR) << "create_crypto_blk_dev failed in mountFstab"; return false; + } if (needs_encrypt) { if (should_format) { @@ -301,10 +308,17 @@ bool fscrypt_mount_metadata_encrypted(const std::string& blk_device, const std:: LOG(ERROR) << "Unknown filesystem type: " << fs_type; return false; } - LOG(DEBUG) << "Format (err=" << error << ") " << crypto_blkdev << " on " << mount_point; - if (error != 0) return false; + if (error != 0) { + LOG(ERROR) << "Format of " << crypto_blkdev << " for " << mount_point + << " failed (err=" << error << ")."; + return false; + } + LOG(DEBUG) << "Format of " << crypto_blkdev << " for " << mount_point << " succeeded."; } else { - if (!encrypt_inplace(crypto_blkdev, blk_device, nr_sec, false)) return false; + if (!encrypt_inplace(crypto_blkdev, blk_device, nr_sec, false)) { + LOG(ERROR) << "encrypt_inplace failed in mountFstab"; + return false; + } } } From 52de78e97b3abeac6397d46263897774f19c9ca8 Mon Sep 17 00:00:00 2001 From: David Anderson Date: Fri, 5 Nov 2021 19:26:56 -0700 Subject: [PATCH 2/2] Route error logs to the kernel during early boot. This is needed to debug vold mounting errors before adb is up. It also helps diagnose failures on devices that store dmesg persistently. Tested by adding an error log with serial attached. Bug: 205314634 Test: manual test Change-Id: Ia095340c562e3f1f94bc44c5d13ad466a7a35345 --- main.cpp | 25 ++++++++++++++++++++++++- 1 file changed, 24 insertions(+), 1 deletion(-) diff --git a/main.cpp b/main.cpp index 641d13a..978db66 100644 --- a/main.cpp +++ b/main.cpp @@ -52,8 +52,11 @@ typedef struct vold_configs { static int process_config(VolumeManager* vm, VoldConfigs* configs); static void coldboot(const char* path); static void parse_args(int argc, char** argv); +static void VoldLogger(android::base::LogId log_buffer_id, android::base::LogSeverity severity, + const char* tag, const char* file, unsigned int line, const char* message); struct selabel_handle* sehandle; +android::base::LogdLogger logd_logger(android::base::SYSTEM); using android::base::StringPrintf; using android::fs_mgr::ReadDefaultFstab; @@ -61,7 +64,7 @@ using android::fs_mgr::ReadDefaultFstab; int main(int argc, char** argv) { atrace_set_tracing_enabled(false); setenv("ANDROID_LOG_TAGS", "*:d", 1); // Do not submit with verbose logs enabled - android::base::InitLogging(argv, android::base::LogdLogger(android::base::SYSTEM)); + android::base::InitLogging(argv, &VoldLogger); LOG(INFO) << "Vold 3.0 (the awakening) firing up"; @@ -278,3 +281,23 @@ static int process_config(VolumeManager* vm, VoldConfigs* configs) { } return 0; } + +static void VoldLogger(android::base::LogId log_buffer_id, android::base::LogSeverity severity, + const char* tag, const char* file, unsigned int line, const char* message) { + logd_logger(log_buffer_id, severity, tag, file, line, message); + + if (severity >= android::base::ERROR) { + static bool is_data_mounted = false; + + // When /data fails to mount, we don't have adb to get logcat. So until /data is + // mounted we log errors to the kernel. This allows us to get failures via serial logs + // and via last dmesg/"fastboot oem dmesg" on devices that support it. + // + // As a very quick-and-dirty test for /data, we check whether /data/misc/vold exists. + if (is_data_mounted || access("/data/misc/vold", F_OK) == 0) { + is_data_mounted = true; + return; + } + android::base::KernelLogger(log_buffer_id, severity, tag, file, line, message); + } +}