diff options
author | Charles Kerr <charles.kerr@canonical.com> | 2016-09-22 09:10:48 -0500 |
---|---|---|
committer | Charles Kerr <charles.kerr@canonical.com> | 2016-09-22 09:10:48 -0500 |
commit | c58d22061d944dc8b9b0b072082665c9f10877ac (patch) | |
tree | d8e3670f005ef9067a09a60f36e937981aa854a9 /src | |
parent | b74f5f6a37edaab28156e551462407096cfbfcbd (diff) | |
download | ayatana-indicator-display-c58d22061d944dc8b9b0b072082665c9f10877ac.tar.gz ayatana-indicator-display-c58d22061d944dc8b9b0b072082665c9f10877ac.tar.bz2 ayatana-indicator-display-c58d22061d944dc8b9b0b072082665c9f10877ac.zip |
add a plethora of log statements to help figure out what's causing the silo test failures
Diffstat (limited to 'src')
-rw-r--r-- | src/adbd-client.cpp | 93 | ||||
-rw-r--r-- | src/usb-manager.cpp | 42 |
2 files changed, 135 insertions, 0 deletions
diff --git a/src/adbd-client.cpp b/src/adbd-client.cpp index 83b15ac..1539982 100644 --- a/src/adbd-client.cpp +++ b/src/adbd-client.cpp @@ -39,22 +39,31 @@ public: m_cancellable{g_cancellable_new()}, m_worker_thread{&Impl::worker_func, this} { +g_debug("%s %s", G_STRLOC, G_STRFUNC); } ~Impl() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); // tell the worker thread to stop whatever it's doing and exit. g_debug("%s Client::Impl dtor, cancelling m_cancellable", G_STRLOC); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_cancellable_cancel(m_cancellable); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.notify_one(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_sleep_cv.notify_one(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (m_worker_thread.joinable()) m_worker_thread.join(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&m_cancellable); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } core::Signal<const PKRequest&>& on_pk_request() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); return m_on_pk_request; } @@ -78,6 +87,7 @@ private: void pass_public_key_to_main_thread(const std::string& public_key) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_idle_add_full(G_PRIORITY_DEFAULT_IDLE, on_public_key_request_static, new PKIdleData{this, m_cancellable, public_key}, @@ -88,30 +98,47 @@ private: { /* NB: It's possible (though unlikely) that data.self was destroyed while this callback was pending, so we must check is-cancelled FIRST */ +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto data = static_cast<PKIdleData*>(gdata); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!g_cancellable_is_cancelled(data->cancellable)) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); // notify our listeners of the request +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto self = data->self; +g_debug("%s %s", G_STRLOC, G_STRFUNC); struct PKRequest req; +g_debug("%s %s", G_STRLOC, G_STRFUNC); req.public_key = data->public_key; +g_debug("%s %s", G_STRLOC, G_STRFUNC); req.fingerprint = get_fingerprint(req.public_key); +g_debug("%s %s", G_STRLOC, G_STRFUNC); req.respond = [self](PKResponse response){self->on_public_key_response(response);}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); self->m_on_pk_request(req); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } +g_debug("%s %s", G_STRLOC, G_STRFUNC); return G_SOURCE_REMOVE; } void on_public_key_response(PKResponse response) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s got response %d", G_STRLOC, int(response)); +g_debug("%s %s", G_STRLOC, G_STRFUNC); // set m_pkresponse and wake up the waiting worker thread std::unique_lock<std::mutex> lk(m_pkresponse_mutex); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse = response; +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_ready = true; +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.notify_one(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } /*** @@ -120,59 +147,89 @@ private: void worker_func() // runs in worker thread { +g_debug("%s %s", G_STRLOC, G_STRFUNC); const std::string socket_path {m_socket_path}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); while (!g_cancellable_is_cancelled(m_cancellable)) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s thread %p creating a client socket to '%s'", G_STRLOC, g_thread_self(), socket_path.c_str()); auto socket = create_client_socket(socket_path); +g_debug("%s %s", G_STRLOC, G_STRFUNC); bool got_valid_req = false; g_debug("%s thread %p calling read_request", g_thread_self(), G_STRLOC); std::string reqstr; +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (socket != nullptr) reqstr = read_request(socket); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!reqstr.empty()) g_debug("%s got request [%s]", G_STRLOC, reqstr.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (reqstr.substr(0,2) == "PK") { +g_debug("%s %s", G_STRLOC, G_STRFUNC); PKResponse response = PKResponse::DENY; +g_debug("%s %s", G_STRLOC, G_STRFUNC); const auto public_key = reqstr.substr(2); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s thread %p got pk [%s]", G_STRLOC, g_thread_self(), public_key.c_str()); if (!public_key.empty()) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); got_valid_req = true; +g_debug("%s %s", G_STRLOC, G_STRFUNC); std::unique_lock<std::mutex> lk(m_pkresponse_mutex); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_ready = false; +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse = AdbdClient::PKResponse::DENY; +g_debug("%s %s", G_STRLOC, G_STRFUNC); pass_public_key_to_main_thread(public_key); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s thread %p waiting", G_STRLOC, g_thread_self()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); try { +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.wait(lk, [this](){ +g_debug("%s %s", G_STRLOC, G_STRFUNC); return m_pkresponse_ready || g_cancellable_is_cancelled(m_cancellable); }); } catch (std::system_error& e) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_critical("%s thread %p unable to wait for response because of unexpected error '%s'", G_STRLOC, g_thread_self(), e.what()); } +g_debug("%s %s", G_STRLOC, G_STRFUNC); response = m_pkresponse; g_debug("%s thread %p got response '%d', is-cancelled %d", G_STRLOC, g_thread_self(), int(response), int(g_cancellable_is_cancelled(m_cancellable))); } +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!g_cancellable_is_cancelled(m_cancellable)) send_pk_response(socket, response); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } else if (!reqstr.empty()) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_warning("Invalid ADB request: [%s]", reqstr.c_str()); } +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&socket); // If nothing interesting's happening, sleep a bit. // (Interval copied from UsbDebuggingManager.java) +g_debug("%s %s", G_STRLOC, G_STRFUNC); static constexpr std::chrono::seconds sleep_interval {std::chrono::seconds(1)}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!got_valid_req && !g_cancellable_is_cancelled(m_cancellable)) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); std::unique_lock<std::mutex> lk(m_sleep_mutex); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_sleep_cv.wait_for(lk, sleep_interval); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } } } @@ -181,10 +238,12 @@ private: GSocket* create_client_socket(const std::string& socket_path) { GError* error {}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto socket = g_socket_new(G_SOCKET_FAMILY_UNIX, G_SOCKET_TYPE_STREAM, G_SOCKET_PROTOCOL_DEFAULT, &error); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (error != nullptr) { g_warning("Error creating adbd client socket: %s", error->message); g_clear_error(&error); @@ -192,55 +251,80 @@ private: return nullptr; } +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto address = g_unix_socket_address_new(socket_path.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); const auto connected = g_socket_connect(socket, address, m_cancellable, &error); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&address); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!connected) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("unable to connect to '%s': %s", socket_path.c_str(), error->message); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_error(&error); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&socket); +g_debug("%s %s", G_STRLOC, G_STRFUNC); return nullptr; } +g_debug("%s %s", G_STRLOC, G_STRFUNC); return socket; } std::string read_request(GSocket* socket) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); char buf[4096] = {}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s calling g_socket_receive()", G_STRLOC); +g_debug("%s %s", G_STRLOC, G_STRFUNC); const auto n_bytes = g_socket_receive (socket, buf, sizeof(buf), m_cancellable, nullptr); +g_debug("%s %s", G_STRLOC, G_STRFUNC); std::string ret; +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (n_bytes > 0) ret.append(buf, std::string::size_type(n_bytes)); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s g_socket_receive got %d bytes: [%s]", G_STRLOC, int(n_bytes), ret.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); return ret; } void send_pk_response(GSocket* socket, PKResponse response) { std::string response_str; +g_debug("%s %s", G_STRLOC, G_STRFUNC); switch(response) { case PKResponse::ALLOW: response_str = "OK"; break; case PKResponse::DENY: response_str = "NO"; break; } g_debug("%s sending reply: [%s]", G_STRLOC, response_str.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); GError* error {}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_socket_send(socket, response_str.c_str(), response_str.size(), m_cancellable, &error); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (error != nullptr) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!g_error_matches(error, G_IO_ERROR, G_IO_ERROR_CANCELLED)) +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_warning("GAdbdServer: Error accepting socket connection: %s", error->message); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_error(&error); } +g_debug("%s %s", G_STRLOC, G_STRFUNC); } static std::string get_fingerprint(const std::string& public_key) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); // The first token is base64-encoded data, so cut on the first whitespace const std::string base64 ( public_key.begin(), @@ -250,14 +334,20 @@ private: ) ); +g_debug("%s %s", G_STRLOC, G_STRFUNC); gsize digest_len {}; +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto digest = g_base64_decode(base64.c_str(), &digest_len); +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto checksum = g_compute_checksum_for_data(G_CHECKSUM_MD5, digest, digest_len); +g_debug("%s %s", G_STRLOC, G_STRFUNC); const gsize checksum_len = checksum ? strlen(checksum) : 0; +g_debug("%s %s", G_STRLOC, G_STRFUNC); // insert ':' between character pairs; eg "ff27b5f3" --> "ff:27:b5:f3" std::string fingerprint; +g_debug("%s %s", G_STRLOC, G_STRFUNC); for (gsize i=0; i<checksum_len; ) { fingerprint.append(checksum+i, checksum+i+2); if (i < checksum_len-2) @@ -265,8 +355,11 @@ private: i += 2; } +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_pointer(&digest, g_free); +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_clear_pointer(&checksum, g_free); +g_debug("%s %s", G_STRLOC, G_STRFUNC); return fingerprint; } diff --git a/src/usb-manager.cpp b/src/usb-manager.cpp index aac289a..8d6a0c9 100644 --- a/src/usb-manager.cpp +++ b/src/usb-manager.cpp @@ -45,89 +45,127 @@ public: m_usb_monitor{usb_monitor}, m_greeter{greeter} { +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_usb_monitor->on_usb_disconnected().connect([this](const std::string& /*usb_name*/) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); restart(); }); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_greeter->is_active().changed().connect([this](bool /*is_active*/) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); maybe_snap(); }); +g_debug("%s %s", G_STRLOC, G_STRFUNC); restart(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } ~Impl() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (m_restart_idle_tag) g_source_remove(m_restart_idle_tag); +g_debug("%s %s", G_STRLOC, G_STRFUNC); clear(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } private: void clear() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); // clear out old state m_snap_connections.clear(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_snap.reset(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_req = decltype(m_req)(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_adbd_client.reset(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } void restart() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); clear(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); // set a new client m_adbd_client.reset(new GAdbdClient{m_socket_path}); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_adbd_client->on_pk_request().connect( [this](const AdbdClient::PKRequest& req) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s got pk request: %s", G_STRLOC, req.fingerprint.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_req = req; +g_debug("%s %s", G_STRLOC, G_STRFUNC); maybe_snap(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } ); } void maybe_snap() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); // don't prompt in the greeter! if (!m_req.public_key.empty() && !m_greeter->is_active().get()) snap(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } void snap() { +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_snap = std::make_shared<UsbSnap>(m_req.fingerprint); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_snap_connections.insert((*m_snap).on_user_response().connect( [this](AdbdClient::PKResponse response, bool remember_choice){ +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s thread %p user responded! response %d, remember %d", G_STRLOC, g_thread_self(), int(response), int(remember_choice)); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_req.respond(response); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (remember_choice && (response == AdbdClient::PKResponse::ALLOW)) write_public_key(m_req.public_key); +g_debug("%s %s", G_STRLOC, G_STRFUNC); m_restart_idle_tag = g_idle_add([](gpointer gself){ +g_debug("%s %s", G_STRLOC, G_STRFUNC); auto self = static_cast<Impl*>(gself); +g_debug("%s %s", G_STRLOC, G_STRFUNC); self->m_restart_idle_tag = 0; +g_debug("%s %s", G_STRLOC, G_STRFUNC); self->restart(); +g_debug("%s %s", G_STRLOC, G_STRFUNC); return G_SOURCE_REMOVE; }, this); } )); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } void write_public_key(const std::string& public_key) { +g_debug("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s writing public key '%s' to '%s'", G_STRLOC, public_key.c_str(), m_public_keys_filename.c_str()); // confirm the directory exists auto dirname = g_path_get_dirname(m_public_keys_filename.c_str()); +g_debug("%s %s", G_STRLOC, G_STRFUNC); const auto dir_exists = g_file_test(dirname, G_FILE_TEST_IS_DIR); if (!dir_exists) g_warning("ADB data directory '%s' does not exist", dirname); g_clear_pointer(&dirname, g_free); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (!dir_exists) return; +g_debug("%s %s", G_STRLOC, G_STRFUNC); // open the file in append mode, with user rw and group r permissions const auto fd = open( @@ -135,16 +173,20 @@ private: O_APPEND|O_CREAT|O_WRONLY, S_IRUSR|S_IWUSR|S_IRGRP ); +g_debug("%s %s", G_STRLOC, G_STRFUNC); if (fd == -1) { g_warning("Error opening ADB datafile: %s", g_strerror(errno)); +g_debug("%s %s", G_STRLOC, G_STRFUNC); return; } +g_debug("%s %s", G_STRLOC, G_STRFUNC); // write the new public key on its own line std::string buf {public_key + '\n'}; if (write(fd, buf.c_str(), buf.size()) == -1) g_warning("Error writing ADB datafile: %d %s", errno, g_strerror(errno)); close(fd); +g_debug("%s %s", G_STRLOC, G_STRFUNC); } const std::string m_socket_path; |