From 891e6dad73699d7b67861705843f95ba19ca5c4d Mon Sep 17 00:00:00 2001 From: Josh Gao Date: Wed, 26 Feb 2020 14:57:20 -0800 Subject: [PATCH 1/3] base: add CachedProperty. Copy bionic's CachedProperty with some minor API tweaks, to allow for efficient querying of properties that rarely change. Bug: http://b/141959374 Test: treehugger Change-Id: I4dfc3f527d30262b35e871d256cec69e69f2e1d7 --- base/include/android-base/properties.h | 30 ++++++++++++++ base/properties.cpp | 57 ++++++++++++++++++++++++++ base/properties_test.cpp | 25 +++++++++++ 3 files changed, 112 insertions(+) diff --git a/base/include/android-base/properties.h b/base/include/android-base/properties.h index 31823df0a..49f1f3184 100644 --- a/base/include/android-base/properties.h +++ b/base/include/android-base/properties.h @@ -20,8 +20,11 @@ #include #include +#include #include +struct prop_info; + namespace android { namespace base { @@ -67,5 +70,32 @@ bool WaitForPropertyCreation(const std::string& key, std::chrono::milliseconds r std::chrono::milliseconds::max()); #endif +#if defined(__BIONIC__) && __cplusplus >= 201703L +// Cached system property lookup. For code that needs to read the same property multiple times, +// this class helps optimize those lookups. +class CachedProperty { + public: + explicit CachedProperty(const char* property_name); + + // Returns the current value of the underlying system property as cheaply as possible. + // The returned pointer is valid until the next call to Get. Because most callers are going + // to want to parse the string returned here and cached that as well, this function performs + // no locking, and is completely thread unsafe. It is the caller's responsibility to provide a + // lock for thread-safety. + // + // Note: *changed can be set to true even if the contents of the property remain the same. + const char* Get(bool* changed = nullptr); + + private: + std::string property_name_; + const prop_info* prop_info_; + std::optional cached_area_serial_; + std::optional cached_property_serial_; + char cached_value_[92]; + bool is_read_only_; + const char* read_only_property_; +}; +#endif + } // namespace base } // namespace android diff --git a/base/properties.cpp b/base/properties.cpp index 4731bf249..35e41a86e 100644 --- a/base/properties.cpp +++ b/base/properties.cpp @@ -30,6 +30,7 @@ #include #include +#include namespace android { namespace base { @@ -195,6 +196,62 @@ bool WaitForPropertyCreation(const std::string& key, return (WaitForPropertyCreation(key, relative_timeout, start_time) != nullptr); } +CachedProperty::CachedProperty(const char* property_name) + : property_name_(property_name), + prop_info_(nullptr), + cached_area_serial_(0), + cached_property_serial_(0), + is_read_only_(android::base::StartsWith(property_name, "ro.")), + read_only_property_(nullptr) { + static_assert(sizeof(cached_value_) == PROP_VALUE_MAX); +} + +const char* CachedProperty::Get(bool* changed) { + std::optional initial_property_serial_ = cached_property_serial_; + + // Do we have a `struct prop_info` yet? + if (prop_info_ == nullptr) { + // `__system_property_find` is expensive, so only retry if a property + // has been created since last time we checked. + uint32_t property_area_serial = __system_property_area_serial(); + if (property_area_serial != cached_area_serial_) { + prop_info_ = __system_property_find(property_name_.c_str()); + cached_area_serial_ = property_area_serial; + } + } + + if (prop_info_ != nullptr) { + // Only bother re-reading the property if it's actually changed since last time. + uint32_t property_serial = __system_property_serial(prop_info_); + if (property_serial != cached_property_serial_) { + __system_property_read_callback( + prop_info_, + [](void* data, const char*, const char* value, uint32_t serial) { + CachedProperty* instance = reinterpret_cast(data); + instance->cached_property_serial_ = serial; + // Read only properties can be larger than PROP_VALUE_MAX, but also never change value + // or location, thus we return the pointer from the shared memory directly. + if (instance->is_read_only_) { + instance->read_only_property_ = value; + } else { + strlcpy(instance->cached_value_, value, PROP_VALUE_MAX); + } + }, + this); + } + } + + if (changed) { + *changed = cached_property_serial_ != initial_property_serial_; + } + + if (is_read_only_) { + return read_only_property_; + } else { + return cached_value_; + } +} + #endif } // namespace base diff --git a/base/properties_test.cpp b/base/properties_test.cpp index e7d4880c2..c30c41e8a 100644 --- a/base/properties_test.cpp +++ b/base/properties_test.cpp @@ -230,3 +230,28 @@ TEST(properties, WaitForPropertyCreation_timeout) { GTEST_LOG_(INFO) << "This test does nothing on the host.\n"; #endif } + +TEST(properties, CachedProperty) { +#if defined(__BIONIC__) + android::base::CachedProperty cached_property("debug.libbase.CachedProperty_test"); + bool changed; + cached_property.Get(&changed); + + android::base::SetProperty("debug.libbase.CachedProperty_test", "foo"); + ASSERT_STREQ("foo", cached_property.Get(&changed)); + ASSERT_TRUE(changed); + + ASSERT_STREQ("foo", cached_property.Get(&changed)); + ASSERT_FALSE(changed); + + android::base::SetProperty("debug.libbase.CachedProperty_test", "bar"); + ASSERT_STREQ("bar", cached_property.Get(&changed)); + ASSERT_TRUE(changed); + + ASSERT_STREQ("bar", cached_property.Get(&changed)); + ASSERT_FALSE(changed); + +#else + GTEST_LOG_(INFO) << "This test does nothing on the host.\n"; +#endif +} From e3d34e1f8bd6c7df8a252f5ce734acf872383f56 Mon Sep 17 00:00:00 2001 From: Josh Gao Date: Wed, 26 Feb 2020 15:44:30 -0800 Subject: [PATCH 2/3] adbd: add usb thread spawn logging. Bug: http://b/141959374 Test: adbd shell killall adbd; adb wait-for-device logcat | grep UsbFfs Change-Id: Id5bbfd6d2198005bf10b94c691499059e130afe7 --- adb/daemon/usb.cpp | 3 +++ 1 file changed, 3 insertions(+) diff --git a/adb/daemon/usb.cpp b/adb/daemon/usb.cpp index 092819807..ff97a6f05 100644 --- a/adb/daemon/usb.cpp +++ b/adb/daemon/usb.cpp @@ -282,6 +282,7 @@ struct UsbFfsConnection : public Connection { monitor_thread_ = std::thread([this]() { adb_thread_setname("UsbFfs-monitor"); + LOG(INFO) << "UsbFfs-monitor thread spawned"; bool bound = false; bool enabled = false; @@ -427,6 +428,8 @@ struct UsbFfsConnection : public Connection { worker_started_ = true; worker_thread_ = std::thread([this]() { adb_thread_setname("UsbFfs-worker"); + LOG(INFO) << "UsbFfs-worker thread spawned"; + for (size_t i = 0; i < kUsbReadQueueDepth; ++i) { read_requests_[i] = CreateReadBlock(next_read_id_++); if (!SubmitRead(&read_requests_[i])) { From 52d0b67f191319e20272d404659ec2f967d2769c Mon Sep 17 00:00:00 2001 From: Josh Gao Date: Wed, 26 Feb 2020 16:39:20 -0800 Subject: [PATCH 3/3] adbd: add runtime-configurable logging. Add some requested logging options that can be turned on at runtime without having to restart adbd. Bug: http://b/141959374 Test: manual Change-Id: Ib97acc6d199e0b91238a6758e18b7cb75f8688d9 --- adb/Android.bp | 1 + adb/adb.cpp | 6 +++ adb/daemon/logging.cpp | 89 ++++++++++++++++++++++++++++++++++++ adb/daemon/logging.h | 33 +++++++++++++ adb/daemon/services.cpp | 4 +- adb/daemon/shell_service.cpp | 5 +- 6 files changed, 135 insertions(+), 3 deletions(-) create mode 100644 adb/daemon/logging.cpp create mode 100644 adb/daemon/logging.h diff --git a/adb/Android.bp b/adb/Android.bp index fea8c7807..50e372793 100644 --- a/adb/Android.bp +++ b/adb/Android.bp @@ -375,6 +375,7 @@ cc_library_static { srcs: libadb_srcs + libadb_linux_srcs + libadb_posix_srcs + [ "daemon/auth.cpp", "daemon/jdwp_service.cpp", + "daemon/logging.cpp", "daemon/adb_wifi.cpp", ], diff --git a/adb/adb.cpp b/adb/adb.cpp index 554a754fd..98db19123 100644 --- a/adb/adb.cpp +++ b/adb/adb.cpp @@ -34,6 +34,7 @@ #include #include #include +#include #include #include @@ -61,6 +62,8 @@ #include #include using namespace std::chrono_literals; + +#include "daemon/logging.h" #endif std::string adb_version() { @@ -312,6 +315,9 @@ static void handle_new_connection(atransport* t, apacket* p) { #if ADB_HOST handle_online(t); #else + ADB_LOG(Connection) << "received CNXN: version=" << p->msg.arg0 << ", maxdata = " << p->msg.arg1 + << ", banner = '" << banner << "'"; + if (t->use_tls) { // We still handshake in TLS mode. If auth_required is disabled, // we'll just not verify the client's certificate. This should be the diff --git a/adb/daemon/logging.cpp b/adb/daemon/logging.cpp new file mode 100644 index 000000000..203c6c73d --- /dev/null +++ b/adb/daemon/logging.cpp @@ -0,0 +1,89 @@ +/* + * Copyright (C) 2020 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 "daemon/logging.h" + +#include +#include +#include + +#include +#include +#include +#include + +#if defined(__ANDROID__) +struct LogStatus { + bool enabled[static_cast(adb::LogType::COUNT)]; + + bool& operator[](adb::LogType type) { return enabled[static_cast(type)]; } +}; + +using android::base::CachedProperty; +using android::base::NoDestructor; + +static NoDestructor log_mutex; +static NoDestructor log_property GUARDED_BY(log_mutex)("debug.adbd.logging"); +static std::optional cached_log_status GUARDED_BY(log_mutex); + +static NoDestructor persist_log_property + GUARDED_BY(log_mutex)("persist.debug.adbd.logging"); +static std::optional cached_persist_log_status GUARDED_BY(log_mutex); + +static LogStatus ParseLogStatus(std::string_view str) { + LogStatus result = {}; + for (const auto& part : android::base::Split(std::string(str), ",")) { + if (part == "cnxn") { + result[adb::LogType::Connection] = true; + } else if (part == "service") { + result[adb::LogType::Service] = true; + } else if (part == "shell") { + result[adb::LogType::Shell] = true; + } else if (part == "all") { + result[adb::LogType::Connection] = true; + result[adb::LogType::Service] = true; + result[adb::LogType::Shell] = true; + } + } + return result; +} + +static LogStatus GetLogStatus(android::base::CachedProperty* property, + std::optional* cached_status) REQUIRES(log_mutex) { + bool changed; + const char* value = property->Get(&changed); + if (changed || !*cached_status) { + **cached_status = ParseLogStatus(value); + } + return **cached_status; +} + +namespace adb { +bool is_logging_enabled(LogType type) { + std::lock_guard lock(*log_mutex); + return GetLogStatus(log_property.get(), &cached_log_status)[type] || + GetLogStatus(persist_log_property.get(), &cached_persist_log_status)[type]; +} +} // namespace adb + +#else + +namespace adb { +bool is_logging_enabled(LogType type) { + return false; +} +} // namespace adb +#endif diff --git a/adb/daemon/logging.h b/adb/daemon/logging.h new file mode 100644 index 000000000..3e28bef31 --- /dev/null +++ b/adb/daemon/logging.h @@ -0,0 +1,33 @@ +/* + * Copyright (C) 2007 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. + */ + +#pragma once + +#include + +namespace adb { +enum class LogType { + Connection, + Service, + Shell, + COUNT, +}; + +bool is_logging_enabled(LogType type); + +#define ADB_LOG(type) ::adb::is_logging_enabled(::adb::LogType::type) && LOG(INFO) + +} // namespace adb diff --git a/adb/daemon/services.cpp b/adb/daemon/services.cpp index 4ec90d27c..6bbf66e8e 100644 --- a/adb/daemon/services.cpp +++ b/adb/daemon/services.cpp @@ -54,10 +54,10 @@ #include "daemon/file_sync_service.h" #include "daemon/framebuffer_service.h" +#include "daemon/logging.h" #include "daemon/restart_service.h" #include "daemon/shell_service.h" - void reconnect_service(unique_fd fd, atransport* t) { WriteFdExactly(fd.get(), "done"); kick_transport(t); @@ -259,6 +259,8 @@ asocket* daemon_service_to_socket(std::string_view name) { } unique_fd daemon_service_to_fd(std::string_view name, atransport* transport) { + ADB_LOG(Service) << "transport " << transport->serial_name() << " opening service " << name; + #if defined(__ANDROID__) && !defined(__ANDROID_RECOVERY__) if (name.starts_with("abb:") || name.starts_with("abb_exec:")) { return execute_abb_command(name); diff --git a/adb/daemon/shell_service.cpp b/adb/daemon/shell_service.cpp index f62032d06..fbfae1e44 100644 --- a/adb/daemon/shell_service.cpp +++ b/adb/daemon/shell_service.cpp @@ -107,6 +107,7 @@ #include "adb_trace.h" #include "adb_unique_fd.h" #include "adb_utils.h" +#include "daemon/logging.h" #include "security_log_tags.h" #include "shell_protocol.h" @@ -760,14 +761,14 @@ void Subprocess::WaitForExit() { D("post waitpid (pid=%d) status=%04x", pid_, status); if (WIFSIGNALED(status)) { exit_code = 0x80 | WTERMSIG(status); - D("subprocess killed by signal %d", WTERMSIG(status)); + ADB_LOG(Shell) << "subprocess " << pid_ << " killed by signal " << WTERMSIG(status); break; } else if (!WIFEXITED(status)) { D("subprocess didn't exit"); break; } else if (WEXITSTATUS(status) >= 0) { exit_code = WEXITSTATUS(status); - D("subprocess exit code = %d", WEXITSTATUS(status)); + ADB_LOG(Shell) << "subprocess " << pid_ << " exited with status " << exit_code; break; } }