From a45898859b4f4c2323b3a00fc30b5a8b3ebcbe40 Mon Sep 17 00:00:00 2001 From: hai007 Date: Tue, 27 Apr 2021 06:16:24 -0700 Subject: [PATCH] Internal change PiperOrigin-RevId: 370664271 --- cpp/core/internal/encryption_runner.cc | 36 +++++++------ cpp/core/internal/internal_payload_factory.cc | 9 +++- cpp/core/internal/payload_manager.cc | 52 +++++++++---------- 3 files changed, 54 insertions(+), 43 deletions(-) diff --git a/cpp/core/internal/encryption_runner.cc b/cpp/core/internal/encryption_runner.cc index 24833d75..2d606ed7 100644 --- a/cpp/core/internal/encryption_runner.cc +++ b/cpp/core/internal/encryption_runner.cc @@ -70,8 +70,8 @@ void CancelableAlarmRunnable(ClientProxy* client, const std::string& endpoint_id, EndpointChannel* endpoint_channel) { NEARBY_LOG(INFO, - "Timing out encryption for client %" PRId64 - " to endpoint %s after %" PRId64 " ms", + "Timing out encryption for client %x" PRIx64 + " to endpoint_id=%s after %" PRId64 " ms", client->GetClientId(), endpoint_id.c_str(), static_cast(absl::ToInt64Milliseconds(kTimeout))); endpoint_channel->Close(); @@ -123,7 +123,8 @@ class ServerRunnable final { return; } - NEARBY_LOG(INFO, "In StartServer(), read UKEY2 Message 1 from endpoint %s", + NEARBY_LOG(INFO, + "In StartServer(), read UKEY2 Message 1 from endpoint(id=%s).", endpoint_id_.c_str()); // Message 2 (Server Init) @@ -145,7 +146,8 @@ class ServerRunnable final { return; } - NEARBY_LOG(INFO, "In StartServer(), wrote UKEY2 Message 2 to endpoint %s", + NEARBY_LOG(INFO, + "In StartServer(), wrote UKEY2 Message 2 to endpoint(id=%s).", endpoint_id_.c_str()); // Message 3 (Client Finish) @@ -170,7 +172,8 @@ class ServerRunnable final { return; } - NEARBY_LOG(INFO, "In StartServer(), read UKEY2 Message 3 from endpoint %s", + NEARBY_LOG(INFO, + "In StartServer(), read UKEY2 Message 3 from endpoint(id=%s).", endpoint_id_.c_str()); timeout_alarm.Cancel(); @@ -184,7 +187,7 @@ class ServerRunnable final { private: void LogException() const { - NEARBY_LOG(ERROR, "In StartServer(), UKEY2 failed with endpoint %s", + NEARBY_LOG(ERROR, "In StartServer(), UKEY2 failed with endpoint(id=%s).", endpoint_id_.c_str()); } @@ -199,8 +202,8 @@ class ServerRunnable final { channel_->Write(ByteArray(*parse_result.alert_to_send)); if (!write_exception.Ok()) { NEARBY_LOG(WARNING, - "In StartServer(), client %" PRId64 - " failed to pass the alert error message to endpoint %s", + "In StartServer(), client %x" PRIx64 + " failed to pass the alert error message to endpoint(id=%s).", client_->GetClientId(), endpoint_id_.c_str()); } } @@ -225,7 +228,7 @@ class ClientRunnable final { void operator()() const { CancelableAlarm timeout_alarm( - "EncryptionRunner.startClient() timeout", + "EncryptionRunner.StartClient() timeout", [this]() { CancelableAlarmRunnable(client_, endpoint_id_, channel_); }, kTimeout, alarm_executor_); @@ -257,7 +260,8 @@ class ClientRunnable final { return; } - NEARBY_LOG(INFO, "In startClient(), wrote UKEY2 Message 1 to endpoint %s", + NEARBY_LOG(INFO, + "In StartClient(), wrote UKEY2 Message 1 to endpoint(id=%s).", endpoint_id_.c_str()); // Message 2 (Server Init) @@ -282,7 +286,8 @@ class ClientRunnable final { return; } - NEARBY_LOG(INFO, "In startClient(), read UKEY2 Message 2 from endpoint %s", + NEARBY_LOG(INFO, + "In StartClient(), read UKEY2 Message 2 from endpoint(id=%s).", endpoint_id_.c_str()); // Message 3 (Client Finish) @@ -304,7 +309,8 @@ class ClientRunnable final { return; } - NEARBY_LOG(INFO, "In startClient(), wrote UKEY2 Message 3 to endpoint %s", + NEARBY_LOG(INFO, + "In StartClient(), wrote UKEY2 Message 3 to endpoint(id=%s).", endpoint_id_.c_str()); timeout_alarm.Cancel(); @@ -318,7 +324,7 @@ class ClientRunnable final { private: void LogException() const { - NEARBY_LOG(ERROR, "In startClient(), UKEY2 failed with endpoint %s", + NEARBY_LOG(ERROR, "In StartClient(), UKEY2 failed with endpoint(id=%s).", endpoint_id_.c_str()); } @@ -333,8 +339,8 @@ class ClientRunnable final { channel_->Write(ByteArray(*parse_result.alert_to_send)); if (!write_exception.Ok()) { NEARBY_LOG(WARNING, - "In startClient(), client %" PRId64 - " failed to pass the alert error message to endpoint %s", + "In StartClient(), client %x" PRIx64 + " failed to pass the alert error message to endpoint(id=%s).", client_->GetClientId(), endpoint_id_.c_str()); } } diff --git a/cpp/core/internal/internal_payload_factory.cc b/cpp/core/internal/internal_payload_factory.cc index 070bd513..9ef67f67 100644 --- a/cpp/core/internal/internal_payload_factory.cc +++ b/cpp/core/internal/internal_payload_factory.cc @@ -94,8 +94,9 @@ class OutgoingStreamInternalPayload : public InternalPayload { ByteArray scoped_bytes_read = std::move(bytes_read.result()); if (scoped_bytes_read.Empty()) { - NEARBY_LOGS(INFO) << "No more data for outgoing payload " << this - << ", closing InputStream."; + NEARBY_LOG(INFO, + "No more data for outgoing payload %p, closing InputStream.", + this); input_stream->Close(); return {}; @@ -131,6 +132,10 @@ class IncomingStreamInternalPayload : public InternalPayload { Exception AttachNextChunk(const ByteArray& chunk) override { if (chunk.Empty()) { + NEARBY_LOG(INFO, + "Received null last chunk for incoming payload %p, closing " + "OutputStream.", + this); output_stream_->Close(); return {Exception::kSuccess}; } diff --git a/cpp/core/internal/payload_manager.cc b/cpp/core/internal/payload_manager.cc index 9f286978..a66f490e 100644 --- a/cpp/core/internal/payload_manager.cc +++ b/cpp/core/internal/payload_manager.cc @@ -70,7 +70,7 @@ bool PayloadManager::SendPayloadLoop( // notify the remaining recipients. if (pending_payload.IsLocallyCanceled()) { NEARBY_LOG(INFO, - "Aborting send of payload_id=%x" PRIx64 " at offset %x" PRIx64 + "Aborting send of payload_id=%" PRIx64 " at offset %" PRIx64 " since it is marked canceled.", static_cast( pending_payload.GetInternalPayload()->GetId()), @@ -101,7 +101,7 @@ bool PayloadManager::SendPayloadLoop( pending_payload.GetInternalPayload()->GetTotalSize() > 0 && pending_payload.GetInternalPayload()->GetTotalSize() < next_chunk_offset) { - NEARBY_LOG(INFO, "Payload xfer failed: payload_id=%x" PRIx64, + NEARBY_LOG(INFO, "Payload xfer failed: payload_id=%" PRIx64, static_cast( pending_payload.GetInternalPayload()->GetId())); HandleFinishedOutgoingPayload( @@ -117,7 +117,7 @@ bool PayloadManager::SendPayloadLoop( // Check whether at least one endpoint failed. if (!failed_endpoint_ids.empty()) { NEARBY_LOG(INFO, - "Payload xfer: endpoints failed: payload_id=%x" PRIx64 + "Payload xfer: endpoints failed: payload_id=%" PRIx64 "; endpoint_ids={%s}", static_cast(payload_header.id()), ToString(failed_endpoint_ids).c_str()); @@ -139,8 +139,8 @@ bool PayloadManager::SendPayloadLoop( } } NEARBY_LOG(VERBOSE, - "PayloadManager done sending chunk at offset %x" PRIx64 - " of payload_id=%x" PRIx64, + "PayloadManager done sending chunk at offset %" PRIx64 + " of payload_id=%" PRIx64, next_chunk_offset, static_cast( pending_payload.GetInternalPayload()->GetId())); @@ -149,7 +149,7 @@ bool PayloadManager::SendPayloadLoop( if (!next_chunk_size) { // That was the last chunk, we're outta here. NEARBY_LOG(INFO, - "Payload xfer done: payload_id=%x" PRIx64 "; size=%" PRId64, + "Payload xfer done: payload_id=%" PRIx64 "; size=%" PRId64, static_cast( pending_payload.GetInternalPayload()->GetId()), next_chunk_offset); @@ -221,7 +221,7 @@ Payload::Id PayloadManager::CreateOutgoingPayload( Payload payload, const EndpointIds& endpoint_ids) { auto internal_payload{CreateOutgoingInternalPayload(std::move(payload))}; Payload::Id payload_id = internal_payload->GetId(); - NEARBY_LOG(INFO, "CreateOutgoingPayload: payload_id=%x" PRIx64, + NEARBY_LOG(INFO, "CreateOutgoingPayload: payload_id=%" PRIx64, static_cast(payload_id)); MutexLock lock(&mutex_); pending_payloads_.StartTrackingPayload( @@ -342,7 +342,7 @@ void PayloadManager::SendPayload(ClientProxy* client, if (!pending_payload) { NEARBY_LOG(INFO, "PayloadManager failed to create InternalPayload for outgoing " - "payload_id=%x" PRIx64 + "payload_id=%" PRIx64 ", payload_type=%d, aborting sendPayload().", static_cast(payload_id), payload_type); return; @@ -364,7 +364,7 @@ void PayloadManager::SendPayload(ClientProxy* client, }); }); NEARBY_LOG(INFO, - "PayloadManager: xfer scheduled: self=%p; payload_id=%x" PRIx64 + "PayloadManager: xfer scheduled: self=%p; payload_id=%" PRIx64 ", payload_type=%d", this, static_cast(payload_id), payload_type); } @@ -380,7 +380,7 @@ Status PayloadManager::CancelPayload(ClientProxy* client, PendingPayload* canceled_payload = GetPayload(payload_id); if (!canceled_payload) { NEARBY_LOG(INFO, - "Client requested cancel for unknown payload_id=%x" PRIx64 + "Client requested cancel for unknown payload_id=%" PRIx64 ", ignoring.", static_cast(payload_id)); return {Status::kPayloadUnknown}; @@ -389,7 +389,7 @@ Status PayloadManager::CancelPayload(ClientProxy* client, // Mark the payload as canceled. canceled_payload->MarkLocallyCanceled(); NEARBY_LOG(INFO, - "Cancelling %s payload_id=%x" PRIx64 " at request of client.", + "Cancelling %s payload_id=%" PRIx64 " at request of client.", (canceled_payload->IsIncoming() ? "incoming" : "outgoing"), static_cast(payload_id)); @@ -574,7 +574,7 @@ PayloadManager::PendingPayload* PayloadManager::CreateIncomingPayload( } Payload::Id payload_id = internal_payload->GetId(); - NEARBY_LOG(INFO, "CreateIncomingPayload: payload_id=%x" PRIx64, + NEARBY_LOG(INFO, "CreateIncomingPayload: payload_id=%" PRIx64, static_cast(payload_id)); MutexLock lock(&mutex_); pending_payloads_.StartTrackingPayload( @@ -682,7 +682,7 @@ void PayloadManager::HandleFinishedOutgoingPayload( break; case proto::connections::PayloadStatus::LOCAL_CANCELLATION: NEARBY_LOG( - INFO, "Sending PAYLOAD_CANCEL to receiver side; payload_id=%x" PRIx64, + INFO, "Sending PAYLOAD_CANCEL to receiver side; payload_id=%" PRIx64, static_cast(payload_header.id())); SendControlMessage( finished_endpoint_ids, payload_header, @@ -728,7 +728,7 @@ void PayloadManager::HandleFinishedIncomingPayload( break; default: NEARBY_LOG(INFO, - "Unhandled finished incoming payload_id=%x" PRIx64 + "Unhandled finished incoming payload_id=%" PRIx64 " with payload_status=%d!", static_cast(payload_header.id()), status); break; @@ -793,7 +793,7 @@ void PayloadManager::DestroyPendingPayload(Payload::Id payload_id) { const char* direction = is_incoming ? "incoming" : "outgoing"; NEARBY_LOG(INFO, "PayloadManager: destroying %s pending payload: " - "self=%p; payload_id=%x" PRIx64, + "self=%p; payload_id=%" PRIx64, direction, this, static_cast(payload_id)); pending->Close(); pending.reset(); @@ -842,8 +842,8 @@ void PayloadManager::ProcessDataPacket( PayloadTransferFrame::PayloadChunk& payload_chunk = *payload_transfer_frame.mutable_payload_chunk(); NEARBY_LOG(VERBOSE, - "PayloadManager got data OfflineFrame for payload_id=%x" PRIx64 - " from endpoint_id=%s at offset %x" PRIx64, + "PayloadManager got data OfflineFrame for payload_id=%" PRIx64 + " from endpoint_id=%s at offset %" PRIx64, static_cast(payload_header.id()), from_endpoint_id.c_str(), payload_chunk.offset()); @@ -854,7 +854,7 @@ void PayloadManager::ProcessDataPacket( if (!pending_payload) { NEARBY_LOG(WARNING, "PayloadManager failed to create InternalPayload from " - "PayloadTransferFrame with ID %x" PRIx64 + "PayloadTransferFrame with ID %" PRIx64 " and type %d, aborting receipt.", static_cast(payload_header.id()), payload_header.type()); @@ -871,7 +871,7 @@ void PayloadManager::ProcessDataPacket( [to_client, from_endpoint_id, pending_payload]() RUN_ON_PAYLOAD_STATUS_UPDATE_THREAD() { NEARBY_LOG(INFO, - "PayloadManager received new payload_id=%x" PRIx64 + "PayloadManager received new payload_id=%" PRIx64 " from endpoint_id=%s", static_cast( pending_payload->GetInternalPayload()->GetId()), @@ -885,7 +885,7 @@ void PayloadManager::ProcessDataPacket( if (!pending_payload) { NEARBY_LOG( WARNING, - "ProcessDataPacket: [missing] endpoint_id=%s; payload_id=%x" PRIx64, + "ProcessDataPacket: [missing] endpoint_id=%s; payload_id=%" PRIx64, from_endpoint_id.c_str(), static_cast(payload_header.id())); return; @@ -897,7 +897,7 @@ void PayloadManager::ProcessDataPacket( // all the cleanup. See go/nc-cancel-payload NEARBY_LOG( INFO, - "ProcessDataPacket: [cancel] endpoint_id=%s; payload_id=%x" PRIx64, + "ProcessDataPacket: [cancel] endpoint_id=%s; payload_id=%" PRIx64, from_endpoint_id.c_str(), static_cast(pending_payload->GetId())); HandleFinishedIncomingPayload( @@ -921,7 +921,7 @@ void PayloadManager::ProcessDataPacket( .Raised()) { NEARBY_LOG( ERROR, - "ProcessDataPacket: [data: error] endpoint_id=%s; payload_id=%x" PRIx64, + "ProcessDataPacket: [data: error] endpoint_id=%s; payload_id=%" PRIx64, from_endpoint_id.c_str(), static_cast(pending_payload->GetId())); HandleFinishedIncomingPayload( @@ -946,7 +946,7 @@ void PayloadManager::ProcessControlPacket( PendingPayload* pending_payload = GetPayload(payload_header.id()); if (!pending_payload) { NEARBY_LOG(INFO, - "Got ControlMessage for unknown payload_id=%x" PRIx64 + "Got ControlMessage for unknown payload_id=%" PRIx64 ", ignoring: %d", static_cast(payload_header.id()), control_message.event()); @@ -975,7 +975,7 @@ void PayloadManager::ProcessControlPacket( control_message); } NEARBY_LOG(VERBOSE, - "Marked %s payload_id=" PRIx64 + "Marked %s payload_id=%" PRIx64 " as canceled at request of endpoint_id=%s.", (pending_payload->IsIncoming() ? "incoming" : "outgoing"), static_cast( @@ -994,7 +994,7 @@ void PayloadManager::ProcessControlPacket( } break; default: - NEARBY_LOG(INFO, "Unhandled control message %d for payload_id= %x" PRIx64, + NEARBY_LOG(INFO, "Unhandled control message %d for payload_id=%" PRIx64, control_message.event(), static_cast( pending_payload->GetInternalPayload()->GetId())); @@ -1155,7 +1155,7 @@ void PayloadManager::PendingPayloads::StartTrackingPayload( pending_payloads_.erase(payload_id); } auto pair = pending_payloads_.emplace(payload_id, std::move(pending_payload)); - NEARBY_LOG(INFO, "StartTrackingPayload: payload_id=%x" PRIx64 "; inserted=%d", + NEARBY_LOG(INFO, "StartTrackingPayload: payload_id=%" PRIx64 "; inserted=%d", static_cast(payload_id), pair.second); }