Revert "Revert "adb: detect some spin loops and abort.""

This reverts commit 04b9ca8c31.

The original incarnation of this patch was falsely triggering when our
poll would block with no activity happening for an extended amount of
time. When the poll returned, we would immediately flag that as a spin
loop. Solve this by tracking the last time we looped, to detect this.

While we're at it, switch from CLOCK_MONOTONIC to CLOCK_BOOTTIME, for
the same reason.

Change-Id: Ibcdf69d93f7b6012142cafd72066f39494c1f84b
Test: ./test_device.py

adb/daemon/services.cpp

@@ -202,6 +202,27 @@ unique_fd ShellService(const std::string& args, const atransport* transport) {
     return StartSubprocess(command.c_str(), terminal_type.c_str(), type, protocol);
 }
 
+static void spin_service(unique_fd fd) {
+    if (!__android_log_is_debuggable()) {
+        WriteFdExactly(fd.get(), "refusing to spin on non-debuggable build\n");
+        return;
+    }
+
+    // A service that creates an fdevent that's always pending, and then ignores it.
+    unique_fd pipe_read, pipe_write;
+    if (!Pipe(&pipe_read, &pipe_write)) {
+        WriteFdExactly(fd.get(), "failed to create pipe\n");
+        return;
+    }
+
+    fdevent_run_on_main_thread([fd = pipe_read.release()]() {
+        fdevent* fde = fdevent_create(fd, [](int, unsigned, void*) {}, nullptr);
+        fdevent_add(fde, FDE_READ);
+    });
+
+    WriteFdExactly(fd.get(), "spinning\n");
+}
+
 unique_fd daemon_service_to_fd(const char* name, atransport* transport) {
     if (!strncmp("dev:", name, 4)) {
         return unique_fd{unix_open(name + 4, O_RDWR | O_CLOEXEC)};
@@ -254,6 +275,9 @@ unique_fd daemon_service_to_fd(const char* name, atransport* transport) {
     } else if (!strcmp(name, "reconnect")) {
         return create_service_thread(
                 "reconnect", std::bind(reconnect_service, std::placeholders::_1, transport));
+    } else if (!strcmp(name, "spin")) {
+        return create_service_thread("spin", spin_service);
     }
+
     return unique_fd{};
 }

adb/fdevent.cpp

@@ -35,6 +35,8 @@
 #include <unordered_map>
 #include <vector>
 
+#include <android-base/chrono_utils.h>
+#include <android-base/file.h>
 #include <android-base/logging.h>
 #include <android-base/stringprintf.h>
 #include <android-base/thread_annotations.h>
@@ -44,6 +46,7 @@
 #include "adb_trace.h"
 #include "adb_unique_fd.h"
 #include "adb_utils.h"
+#include "sysdeps/chrono.h"
 
 #define FDE_EVENTMASK  0x00ff
 #define FDE_STATEMASK  0xff00
@@ -247,6 +250,7 @@ static void fdevent_process() {
     }
     CHECK_GT(pollfds.size(), 0u);
     D("poll(), pollfds = %s", dump_pollfds(pollfds).c_str());
+
     int ret = adb_poll(&pollfds[0], pollfds.size(), -1);
     if (ret == -1) {
         PLOG(ERROR) << "poll(), ret = " << ret;
@@ -367,10 +371,66 @@ void fdevent_run_on_main_thread(std::function<void()> fn) {
     }
 }
 
+static void fdevent_check_spin(uint64_t cycle) {
+    // Check to see if we're spinning because we forgot about an fdevent
+    // by keeping track of how long fdevents have been continuously pending.
+    struct SpinCheck {
+        fdevent* fde;
+        android::base::boot_clock::time_point timestamp;
+        uint64_t cycle;
+    };
+    static auto& g_continuously_pending = *new std::unordered_map<uint64_t, SpinCheck>();
+    static auto last_cycle = android::base::boot_clock::now();
+
+    auto now = android::base::boot_clock::now();
+    if (now - last_cycle > 10ms) {
+        // We're not spinning.
+        g_continuously_pending.clear();
+        last_cycle = now;
+        return;
+    }
+    last_cycle = now;
+
+    for (auto* fde : g_pending_list) {
+        auto it = g_continuously_pending.find(fde->id);
+        if (it == g_continuously_pending.end()) {
+            g_continuously_pending[fde->id] =
+                    SpinCheck{.fde = fde, .timestamp = now, .cycle = cycle};
+        } else {
+            it->second.cycle = cycle;
+        }
+    }
+
+    for (auto it = g_continuously_pending.begin(); it != g_continuously_pending.end();) {
+        if (it->second.cycle != cycle) {
+            it = g_continuously_pending.erase(it);
+        } else {
+            // Use an absurdly long window, since all we really care about is
+            // getting a bugreport eventually.
+            if (now - it->second.timestamp > 300s) {
+                LOG(FATAL_WITHOUT_ABORT)
+                        << "detected spin in fdevent: " << dump_fde(it->second.fde);
+#if defined(__linux__)
+                int fd = it->second.fde->fd.get();
+                std::string fd_path = android::base::StringPrintf("/proc/self/fd/%d", fd);
+                std::string path;
+                if (!android::base::Readlink(fd_path, &path)) {
+                    PLOG(FATAL_WITHOUT_ABORT) << "readlink of fd " << fd << " failed";
+                }
+                LOG(FATAL_WITHOUT_ABORT) << "fd " << fd << " = " << path;
+#endif
+                abort();
+            }
+            ++it;
+        }
+    }
+}
+
 void fdevent_loop() {
     set_main_thread();
     fdevent_run_setup();
 
+    uint64_t cycle = 0;
     while (true) {
         if (terminate_loop) {
             return;
@@ -380,6 +440,8 @@ void fdevent_loop() {
 
         fdevent_process();
 
+        fdevent_check_spin(cycle++);
+
         while (!g_pending_list.empty()) {
             fdevent* fde = g_pending_list.front();
             g_pending_list.pop_front();