Merge changes Ib97acc6d,I8f14004a,Id5bbfd6d,I4dfc3f52 into rvc-dev

* changes:
  adbd: add runtime-configurable logging.
  adb: don't hardcode ports in test_adb.
  adbd: add usb thread spawn logging.
  base: add CachedProperty.

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

adb/adb.cpp

@@ -34,6 +34,7 @@
 #include <condition_variable>
 #include <mutex>
 #include <string>
+#include <string_view>
 #include <thread>
 #include <vector>
 
@@ -61,6 +62,8 @@
 #include <sys/mount.h>
 #include <android-base/properties.h>
 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

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 <mutex>
+#include <optional>
+#include <string_view>
+
+#include <android-base/no_destructor.h>
+#include <android-base/properties.h>
+#include <android-base/strings.h>
+#include <android-base/thread_annotations.h>
+
+#if defined(__ANDROID__)
+struct LogStatus {
+    bool enabled[static_cast<size_t>(adb::LogType::COUNT)];
+
+    bool& operator[](adb::LogType type) { return enabled[static_cast<size_t>(type)]; }
+};
+
+using android::base::CachedProperty;
+using android::base::NoDestructor;
+
+static NoDestructor<std::mutex> log_mutex;
+static NoDestructor<CachedProperty> log_property GUARDED_BY(log_mutex)("debug.adbd.logging");
+static std::optional<LogStatus> cached_log_status GUARDED_BY(log_mutex);
+
+static NoDestructor<CachedProperty> persist_log_property
+        GUARDED_BY(log_mutex)("persist.debug.adbd.logging");
+static std::optional<LogStatus> 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<LogStatus>* 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<std::mutex> 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

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 <android-base/logging.h>
+
+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

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

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;
             }
         }

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])) {

adb/test_adb.py

@@ -33,6 +33,11 @@ import time
 import unittest
 import warnings
 
+def find_open_port():
+    # Find an open port.
+    with socket.socket() as s:
+        s.bind(("localhost", 0))
+        return s.getsockname()[1]
 
 @contextlib.contextmanager
 def fake_adbd(protocol=socket.AF_INET, port=0):
@@ -126,10 +131,7 @@ def adb_server():
     This creates an ADB server and returns the port it's listening on.
     """
 
-    port = 5038
-    # Kill any existing server on this non-default port.
-    subprocess.check_output(["adb", "-P", str(port), "kill-server"],
-                            stderr=subprocess.STDOUT)
+    port = find_open_port()
     read_pipe, write_pipe = os.pipe()
 
     if sys.platform == "win32":
@@ -224,10 +226,7 @@ class ServerTest(unittest.TestCase):
         # adb server, this also tests whether multiple instances of the adb
         # server conflict on adb.log.
 
-        port = 5038
-        # Kill any existing server on this non-default port.
-        subprocess.check_output(["adb", "-P", str(port), "kill-server"],
-                                stderr=subprocess.STDOUT)
+        port = find_open_port()
 
         try:
             # We get warnings for unclosed files for the subprocess's pipes,
@@ -289,12 +288,8 @@ class ServerTest(unittest.TestCase):
         """
         Tests that the server can start up on ::1 and that it's accessible
         """
-        server_port = 5037
-        # Kill any existing server on this non-default port.
-        subprocess.check_output(
-            ["adb", "-P", str(server_port), "kill-server"],
-            stderr=subprocess.STDOUT,
-        )
+
+        server_port = find_open_port()
         try:
             subprocess.check_output(
                 ["adb", "-L", "tcp:[::1]:{}".format(server_port), "server"],

base/include/android-base/properties.h

@@ -20,8 +20,11 @@
 
 #include <chrono>
 #include <limits>
+#include <optional>
 #include <string>
 
+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<uint32_t> cached_area_serial_;
+  std::optional<uint32_t> cached_property_serial_;
+  char cached_value_[92];
+  bool is_read_only_;
+  const char* read_only_property_;
+};
+#endif
+
 } // namespace base
 } // namespace android

base/properties.cpp

@@ -30,6 +30,7 @@
 
 #include <android-base/parsebool.h>
 #include <android-base/parseint.h>
+#include <android-base/strings.h>
 
 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<uint32_t> 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<CachedProperty*>(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

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
+}