From a17e7fc7ed94bf201b37cf7d9744ef272404c0f7 Mon Sep 17 00:00:00 2001 From: Charles Kerr Date: Thu, 22 Sep 2016 16:10:01 -0500 Subject: tweak the debug tracers --- src/adbd-client.cpp | 186 ++++++++++++++++++++++++++-------------------------- 1 file changed, 93 insertions(+), 93 deletions(-) (limited to 'src/adbd-client.cpp') diff --git a/src/adbd-client.cpp b/src/adbd-client.cpp index 597e69f..fbaf377 100644 --- a/src/adbd-client.cpp +++ b/src/adbd-client.cpp @@ -39,31 +39,31 @@ public: m_cancellable{g_cancellable_new()}, m_worker_thread{&Impl::worker_func, this} { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } ~Impl() { -g_debug("%s %s DTOR DTOR dtor", G_STRLOC, G_STRFUNC); +g_message("%s %s DTOR DTOR dtor", 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_message("%s %s", G_STRLOC, G_STRFUNC); g_cancellable_cancel(m_cancellable); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.notify_one(); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_sleep_cv.notify_one(); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (m_worker_thread.joinable()) m_worker_thread.join(); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&m_cancellable); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } core::Signal& on_pk_request() { -g_debug("%s %s thread %p", G_STRLOC, G_STRFUNC, g_thread_self()); +g_message("%s %s thread %p", G_STRLOC, G_STRFUNC, g_thread_self()); return m_on_pk_request; } @@ -87,7 +87,7 @@ private: void pass_public_key_to_main_thread(const std::string& public_key) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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}, @@ -98,48 +98,48 @@ g_debug("%s %s", G_STRLOC, G_STRFUNC); { /* 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 thread is %p", G_STRLOC, G_STRFUNC, g_thread_self()); +g_message("%s %s thread is %p", G_STRLOC, G_STRFUNC, g_thread_self()); auto data = static_cast(gdata); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (!g_cancellable_is_cancelled(data->cancellable)) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); // notify our listeners of the request -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); auto self = data->self; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); struct PKRequest req; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); req.public_key = data->public_key; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); req.fingerprint = get_fingerprint(req.public_key); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); self->m_on_pk_request(req); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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_message("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s thread %p got response %d", G_STRLOC, g_thread_self(), int(response)); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); // set m_pkresponse and wake up the waiting worker thread //std::lock_guard lk(m_pkresponse_mutex); //std::unique_lock lk(m_pkresponse_mutex); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse = response; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_ready = true; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.notify_one(); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } /*** @@ -148,89 +148,89 @@ g_debug("%s %s", G_STRLOC, G_STRFUNC); void worker_func() // runs in worker thread { -g_debug("%s %s worker thread is %p", G_STRLOC, G_STRFUNC, g_thread_self()); +g_message("%s %s worker thread is %p", G_STRLOC, G_STRFUNC, g_thread_self()); const std::string socket_path {m_socket_path}; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); while (!g_cancellable_is_cancelled(m_cancellable)) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (socket != nullptr) reqstr = read_request(socket); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (reqstr.substr(0,2) == "PK") { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); PKResponse response = PKResponse::DENY; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); const auto public_key = reqstr.substr(2); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); got_valid_req = true; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); std::unique_lock lk(m_pkresponse_mutex); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_ready = false; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse = AdbdClient::PKResponse::DENY; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); pass_public_key_to_main_thread(public_key); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); try { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_pkresponse_cv.wait(lk, [this](){ -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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_message("%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); +g_message("%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); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); } else if (!reqstr.empty()) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); g_warning("Invalid ADB request: [%s]", reqstr.c_str()); } -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (!got_valid_req && !g_cancellable_is_cancelled(m_cancellable)) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); std::unique_lock lk(m_sleep_mutex); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); m_sleep_cv.wait_for(lk, sleep_interval); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } } } @@ -239,12 +239,12 @@ g_debug("%s %s", G_STRLOC, G_STRFUNC); GSocket* create_client_socket(const std::string& socket_path) { GError* error {}; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (error != nullptr) { g_warning("Error creating adbd client socket: %s", error->message); g_clear_error(&error); @@ -252,80 +252,80 @@ g_debug("%s %s", G_STRLOC, G_STRFUNC); return nullptr; } -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%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_message("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&address); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (!connected) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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_message("%s %s", G_STRLOC, G_STRFUNC); g_clear_error(&error); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); g_clear_object(&socket); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); return nullptr; } -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); return socket; } std::string read_request(GSocket* socket) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); char buf[4096] = {}; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); g_debug("%s calling g_socket_receive()", G_STRLOC); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); std::string ret; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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_message("%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); +g_message("%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); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); GError* error {}; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); if (error != nullptr) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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_message("%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_message("%s %s", G_STRLOC, G_STRFUNC); g_clear_error(&error); } -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); } static std::string get_fingerprint(const std::string& public_key) { -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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(), @@ -335,20 +335,20 @@ g_debug("%s %s", G_STRLOC, G_STRFUNC); ) ); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); gsize digest_len {}; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%s %s", G_STRLOC, G_STRFUNC); auto digest = g_base64_decode(base64.c_str(), &digest_len); -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); const gsize checksum_len = checksum ? strlen(checksum) : 0; -g_debug("%s %s", G_STRLOC, G_STRFUNC); +g_message("%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); +g_message("%s %s", G_STRLOC, G_STRFUNC); for (gsize i=0; i