Fix logging to allow real-time log monitoring am: bef3d190db Original change: https://android-review.googlesource.com/c/platform/packages/modules/adb/+/3411297 Change-Id: I0c7b24be8ce188ed4530f2dd3186238534d4ba58 Signed-off-by: Automerger Merge Worker <android-build-automerger-merge-worker@system.gserviceaccount.com>
diff --git a/adb.cpp b/adb.cpp index 66d5785..c7aea30 100644 --- a/adb.cpp +++ b/adb.cpp
@@ -199,11 +199,11 @@ void handle_offline(atransport *t) { if (t->GetConnectionState() == kCsOffline) { - LOG(INFO) << t->serial_name() << ": already offline"; + VLOG(ADB) << t->serial_name() << ": already offline"; return; } - LOG(INFO) << t->serial_name() << ": offline"; + VLOG(ADB) << t->serial_name() << ": offline"; #if !ADB_HOST && defined(__ANDROID__) DecrementActiveConnections(); @@ -535,13 +535,13 @@ s->peer->peer = s; if (t->SupportsDelayedAck()) { - LOG(DEBUG) << "delayed ack available: send buffer = " << send_bytes; + VLOG(PACKETS) << "delayed ack available: send buffer = " << send_bytes; s->available_send_bytes = send_bytes; // TODO: Make this adjustable at connection time? send_ready(s->id, s->peer->id, t, INITIAL_DELAYED_ACK_BYTES); } else { - LOG(DEBUG) << "delayed ack unavailable"; + VLOG(PACKETS) << "delayed ack unavailable"; send_ready(s->id, s->peer->id, t, 0); }
diff --git a/daemon/auth.cpp b/daemon/auth.cpp index b65f474..495df66 100644 --- a/daemon/auth.cpp +++ b/daemon/auth.cpp
@@ -255,7 +255,7 @@ } void send_auth_request(atransport* t) { - LOG(INFO) << "Calling send_auth_request..."; + VLOG(AUTH) << "Calling send_auth_request..."; if (!adbd_auth_generate_token(t->token, sizeof(t->token))) { PLOG(ERROR) << "Error generating token"; @@ -271,19 +271,19 @@ } void adbd_auth_verified(atransport* t) { - LOG(INFO) << "adb client authorized"; + VLOG(AUTH) << "adb client authorized"; handle_online(t); send_connect(t); } static void adb_disconnected(void* unused, atransport* t) { - LOG(INFO) << "ADB disconnect"; + VLOG(AUTH) << "ADB disconnect"; CHECK(t->auth_id.has_value()); adbd_auth_notify_disconnect(auth_ctx, t->auth_id.value()); } void adbd_auth_confirm_key(atransport* t) { - LOG(INFO) << "prompting user to authorize key"; + VLOG(AUTH) << "prompting user to authorize key"; t->AddDisconnect(&adb_disconnect); if (adbd_auth_prompt_user_with_id) { t->auth_id = adbd_auth_prompt_user_with_id(auth_ctx, t->auth_key.data(), t->auth_key.size(), @@ -301,19 +301,19 @@ int adbd_tls_verify_cert(X509_STORE_CTX* ctx, std::string* auth_key) { if (!auth_required) { // Any key will do. - LOG(INFO) << __func__ << ": auth not required"; + VLOG(AUTH) << __func__ << ": auth not required"; return 1; } bool authorized = false; X509* cert = X509_STORE_CTX_get0_cert(ctx); if (cert == nullptr) { - LOG(INFO) << "got null x509 certificate"; + VLOG(AUTH) << "got null x509 certificate"; return 0; } bssl::UniquePtr<EVP_PKEY> evp_pkey(X509_get_pubkey(cert)); if (evp_pkey == nullptr) { - LOG(INFO) << "got null evp_pkey from x509 certificate"; + VLOG(AUTH) << "got null evp_pkey from x509 certificate"; return 0; } @@ -337,10 +337,10 @@ bssl::UniquePtr<EVP_PKEY> known_evp(EVP_PKEY_new()); EVP_PKEY_set1_RSA(known_evp.get(), key); if (EVP_PKEY_cmp(known_evp.get(), evp_pkey.get())) { - LOG(INFO) << "Matched auth_key=" << public_key; + VLOG(AUTH) << "Matched auth_key=" << public_key; verified = true; } else { - LOG(INFO) << "auth_key doesn't match [" << public_key << "]"; + VLOG(AUTH) << "auth_key doesn't match [" << public_key << "]"; } RSA_free(key); if (verified) { @@ -367,7 +367,7 @@ std::thread([t]() { std::string auth_key; if (t->connection()->DoTlsHandshake(rsa_pkey, &auth_key)) { - LOG(INFO) << "auth_key=" << auth_key; + VLOG(AUTH) << "auth_key=" << auth_key; if (t->IsTcpDevice()) { t->auth_key = auth_key; adbd_wifi_secure_connect(t);
diff --git a/daemon/jdwp_service.cpp b/daemon/jdwp_service.cpp index 6e0c89e..a54cd31 100644 --- a/daemon/jdwp_service.cpp +++ b/daemon/jdwp_service.cpp
@@ -268,6 +268,7 @@ goto CloseProcess; } + VLOG(JDWP) << "Received JDWP Process info for pid=" << process_info->pid; proc->process = std::move(*process_info); jdwp_process_list_updated(); app_process_list_updated(); @@ -288,6 +289,7 @@ proc->out_fds.pop_back(); if (proc->out_fds.empty()) { + VLOG(JDWP) << "Removing FDE_WRITE"; fdevent_del(proc->fde, FDE_WRITE); } } @@ -295,6 +297,7 @@ return; CloseProcess: + VLOG(JDWP) << "Process " << proc->process.pid << " has disconnected"; bool debuggable = proc->process.debuggable; bool profileable = proc->process.profileable; proc->RemoveFromList(); @@ -318,8 +321,12 @@ D("socketpair: (%d,%d)", fds[0], fds[1]); proc->out_fds.emplace_back(fds[1]); + VLOG(JDWP) << "create_jdwp_connection_fd out_fds=" << proc->out_fds.size(); if (proc->out_fds.size() == 1) { + VLOG(JDWP) << "Requesting FDE_WRITE"; fdevent_add(proc->fde, FDE_WRITE); + } else { + VLOG(JDWP) << "Skipping request for FDE_WRITE"; } return unique_fd{fds[0]};
diff --git a/daemon/jdwp_service.h b/daemon/jdwp_service.h index 71a8e64..efc4ccb 100644 --- a/daemon/jdwp_service.h +++ b/daemon/jdwp_service.h
@@ -21,4 +21,7 @@ asocket* create_jdwp_service_socket(); asocket* create_jdwp_tracker_service_socket(); asocket* create_app_tracker_service_socket(); + +// Create a socket pair. Send one end to the debuggable process `jdwp_pid` and +// return the other one. unique_fd create_jdwp_connection_fd(int jdwp_pid); \ No newline at end of file
diff --git a/daemon/usb.cpp b/daemon/usb.cpp index bd881c7..f442961 100644 --- a/daemon/usb.cpp +++ b/daemon/usb.cpp
@@ -150,7 +150,7 @@ control_fd_(std::move(control)), read_fd_(std::move(read)), write_fd_(std::move(write)) { - LOG(INFO) << "UsbFfsConnection constructed"; + VLOG(USB) << "UsbFfsConnection constructed"; worker_event_fd_.reset(eventfd(0, EFD_CLOEXEC)); if (worker_event_fd_ == -1) { PLOG(FATAL) << "failed to create eventfd"; @@ -165,7 +165,7 @@ } ~UsbFfsConnection() { - LOG(INFO) << "UsbFfsConnection being destroyed"; + VLOG(USB) << "UsbFfsConnection being destroyed"; Stop(); monitor_thread_.join(); @@ -180,7 +180,7 @@ } virtual bool Write(std::unique_ptr<apacket> packet) override final { - LOG(DEBUG) << "USB write: " << dump_header(&packet->msg); + VLOG(USB) << "USB write: " << dump_header(&packet->msg); auto header = std::make_shared<Block>(sizeof(packet->msg)); memcpy(header->data(), &packet->msg, sizeof(packet->msg)); @@ -260,7 +260,7 @@ monitor_thread_ = std::thread([this]() { adb_thread_setname("UsbFfs-monitor"); - LOG(INFO) << "UsbFfs-monitor thread spawned"; + VLOG(USB) << "UsbFfs-monitor thread spawned"; bool bound = false; bool enabled = false; @@ -299,7 +299,7 @@ << sizeof(event) << ", got " << rc; } - LOG(INFO) << "USB event: " + VLOG(USB) << "USB event: " << to_string(static_cast<usb_functionfs_event_type>(event.type)); switch (event.type) { @@ -363,7 +363,7 @@ break; case FUNCTIONFS_SETUP: { - LOG(INFO) << "received FUNCTIONFS_SETUP control transfer: bRequestType = " + VLOG(USB) << "received FUNCTIONFS_SETUP control transfer: bRequestType = " << static_cast<int>(event.u.setup.bRequestType) << ", bRequest = " << static_cast<int>(event.u.setup.bRequest) << ", wValue = " << static_cast<int>(event.u.setup.wValue) @@ -371,7 +371,7 @@ << ", wLength = " << static_cast<int>(event.u.setup.wLength); if ((event.u.setup.bRequestType & USB_DIR_IN)) { - LOG(INFO) << "acking device-to-host control transfer"; + VLOG(USB) << "acking device-to-host control transfer"; ssize_t rc = adb_write(control_fd_.get(), "", 0); if (rc != 0) { PLOG(ERROR) << "failed to write empty packet to host"; @@ -389,7 +389,7 @@ << event.u.setup.wLength; } - LOG(INFO) << "control request contents: " << buf; + VLOG(USB) << "control request contents: " << buf; break; } } @@ -406,7 +406,7 @@ worker_started_ = true; worker_thread_ = std::thread([this]() { adb_thread_setname("UsbFfs-worker"); - LOG(INFO) << "UsbFfs-worker thread spawned"; + VLOG(USB) << "UsbFfs-worker thread spawned"; for (size_t i = 0; i < kUsbReadQueueDepth; ++i) { read_requests_[i] = CreateReadBlock(next_read_id_++); @@ -541,8 +541,8 @@ // Notification for completed reads can be received out of order. if (block->id().id != needed_read_id_) { - LOG(VERBOSE) << "read " << block->id().id << " completed while waiting for " - << needed_read_id_; + VLOG(USB) << "read " << block->id().id << " completed while waiting for " + << needed_read_id_; return true; } @@ -605,7 +605,7 @@ write_requests_.erase(it); size_t outstanding_writes = --writes_submitted_; - LOG(DEBUG) << "USB write: reaped, down to " << outstanding_writes; + VLOG(USB) << "USB write: reaped, down to " << outstanding_writes; } IoWriteBlock CreateWriteBlock(std::shared_ptr<Block> payload, size_t offset, size_t len, @@ -647,7 +647,7 @@ CHECK(!write_requests_[writes_submitted_ + i].pending); write_requests_[writes_submitted_ + i].pending = true; iocbs[i] = &write_requests_[writes_submitted_ + i].control; - LOG(VERBOSE) << "submitting write_request " << static_cast<void*>(iocbs[i]); + VLOG(USB) << "submitting write_request " << static_cast<void*>(iocbs[i]); } writes_submitted_ += writes_to_submit; @@ -667,7 +667,7 @@ for (size_t i = 0; i < writes_submitted_; ++i) { struct io_event res; if (write_requests_[i].pending == true) { - LOG(INFO) << "cancelling pending write# " << i; + VLOG(USB) << "cancelling pending write# " << i; io_cancel(aio_context_.get(), &write_requests_[i].control, &res); } } @@ -749,9 +749,9 @@ } if (android::base::GetBoolProperty(kPropertyUsbDisabled, false)) { - LOG(INFO) << "pausing USB due to " << kPropertyUsbDisabled; + VLOG(USB) << "pausing USB due to " << kPropertyUsbDisabled; prop_mon.Run(); - LOG(INFO) << "resuming USB"; + VLOG(USB) << "resuming USB"; } atransport* transport = new atransport(kTransportUsb);
diff --git a/sockets.cpp b/sockets.cpp index 4411fe3..9a24ff0 100644 --- a/sockets.cpp +++ b/sockets.cpp
@@ -470,7 +470,7 @@ int fd_value = fd.get(); asocket* s = create_local_socket(std::move(fd)); s->transport = transport; - LOG(VERBOSE) << "LS(" << s->id << "): bound to '" << name << "' via " << fd_value; + VLOG(SERVICES) << "LS(" << s->id << "): bound to '" << name << "' via " << fd_value; #if !ADB_HOST if ((name.starts_with("root:") && getuid() != 0 && __android_log_is_debuggable()) ||