diff --git a/cpp/core/internal/bwu_manager.cc b/cpp/core/internal/bwu_manager.cc index 47742df4..9c2f33fc 100644 --- a/cpp/core/internal/bwu_manager.cc +++ b/cpp/core/internal/bwu_manager.cc @@ -110,6 +110,8 @@ void BwuManager::Shutdown() { void BwuManager::InitiateBwuForEndpoint(ClientProxy* client, const std::string& endpoint_id, Medium new_medium) { + NEARBY_LOG(INFO, "InitiateBwuForEndpoint for endpoint %s with medium %d", + endpoint_id.c_str(), new_medium); RunOnBwuManagerThread([this, client, endpoint_id, new_medium]() { Medium proposed_medium = ChooseBestUpgradeMedium( client->GetUpgradeMediums(endpoint_id).GetMediums(true)); @@ -184,6 +186,8 @@ void BwuManager::InitiateBwuForEndpoint(ClientProxy* client, void BwuManager::OnIncomingFrame(OfflineFrame& frame, const std::string& endpoint_id, ClientProxy* client, Medium medium) { + NEARBY_LOG(INFO, "OnIncomingFrame for endpoint %s with medium: %d", + endpoint_id.c_str(), medium); if (parser::GetFrameType(frame) != V1Frame::BANDWIDTH_UPGRADE_NEGOTIATION) return; auto bwu_frame = frame.v1().bandwidth_upgrade_negotiation(); @@ -198,6 +202,7 @@ void BwuManager::OnIncomingFrame(OfflineFrame& frame, void BwuManager::OnEndpointDisconnect(ClientProxy* client, const std::string& endpoint_id, CountDownLatch barrier) { + NEARBY_LOG(INFO, "OnEndpointDisconnect for endpoint %s", endpoint_id.c_str()); RunOnBwuManagerThread([this, client, endpoint_id, barrier]() mutable { if (medium_ == Medium::UNKNOWN_MEDIUM) { barrier.CountDown(); @@ -233,6 +238,7 @@ void BwuManager::OnEndpointDisconnect(ClientProxy* client, } BwuHandler* BwuManager::SetCurrentBwuHandler(Medium medium) { + NEARBY_LOG(INFO, "SetCurrentBwuHandler to %d", medium); handler_ = nullptr; medium_ = medium; if (medium != Medium::UNKNOWN_MEDIUM) { @@ -245,6 +251,7 @@ BwuHandler* BwuManager::SetCurrentBwuHandler(Medium medium) { } void BwuManager::Revert() { + NEARBY_LOG(INFO, "Revert reseting medium %d", medium_); if (handler_) { handler_->Revert(); medium_ = Medium::UNKNOWN_MEDIUM; @@ -255,6 +262,8 @@ void BwuManager::Revert() { void BwuManager::OnBwuNegotiationFrame(ClientProxy* client, const BwuNegotiationFrame& frame, const string& endpoint_id) { + NEARBY_LOG(INFO, "OnBwuNegotiationFrame for endpoint %s", + endpoint_id.c_str()); switch (frame.event_type()) { case BwuNegotiationFrame::UPGRADE_PATH_AVAILABLE: ProcessBwuPathAvailableEvent(client, endpoint_id, @@ -278,6 +287,8 @@ void BwuManager::OnBwuNegotiationFrame(ClientProxy* client, void BwuManager::OnIncomingConnection( ClientProxy* client, std::unique_ptr mutable_connection) { + NEARBY_LOG(INFO, "OnIncomingConnection service id: %s", + client->GetServiceId().c_str()); std::shared_ptr connection( mutable_connection.release()); RunOnBwuManagerThread([this, client, connection]() { @@ -315,7 +326,6 @@ void BwuManager::OnIncomingConnection( if (item.empty()) return; mapped_client = item.mapped(); } - CancelRetryUpgradeAlarm(endpoint_id); if (mapped_client == nullptr) { // This was never a fully EstablishedConnection, no need to provide a @@ -340,6 +350,9 @@ void BwuManager::RunOnBwuManagerThread(Runnable runnable) { void BwuManager::RunUpgradeProtocol( ClientProxy* client, const std::string& endpoint_id, std::unique_ptr new_channel) { + NEARBY_LOG(INFO, "RunUpgradeProtocol new channel @%d name: %s, medium: %d", + new_channel.get(), new_channel->GetName().c_str(), + new_channel->GetMedium()); // First, register this new EndpointChannel as *the* EndpointChannel to use // for this endpoint here onwards. NOTE: We pause this new EndpointChannel // until we've completely drained the old EndpointChannel to avoid out of @@ -379,6 +392,9 @@ void BwuManager::RunUpgradeProtocol( void BwuManager::ProcessBwuPathAvailableEvent( ClientProxy* client, const string& endpoint_id, const UpgradePathInfo& upgrade_path_info) { + NEARBY_LOG(INFO, "ProcessBwuPathAvailableEvent for endpoint %s medium %d.", + endpoint_id.c_str(), + parser::UpgradePathInfoMediumToMedium(upgrade_path_info.medium())); if (in_progress_upgrades_.contains(endpoint_id)) { NEARBY_LOG(INFO, "Invoking duplicate ProcessBwuPathAvailableEvent for %s", endpoint_id.c_str()); @@ -394,15 +410,14 @@ void BwuManager::ProcessBwuPathAvailableEvent( return; } } - Medium medium = parser::UpgradePathInfoMediumToMedium(upgrade_path_info.medium()); if (medium_ == Medium::UNKNOWN_MEDIUM) { SetCurrentBwuHandler(medium); } - // Check for the correct medium so we don't process an incorrect OfflineFrame. if (medium != medium_) { + NEARBY_LOG(INFO, "Medium not matching"); RunUpgradeFailedProtocol(client, endpoint_id, upgrade_path_info); return; } @@ -410,6 +425,7 @@ void BwuManager::ProcessBwuPathAvailableEvent( auto channel = ProcessBwuPathAvailableEventInternal(client, endpoint_id, upgrade_path_info); if (channel == nullptr) { + NEARBY_LOG(INFO, "Failed to get new channel."); RunUpgradeFailedProtocol(client, endpoint_id, upgrade_path_info); return; } @@ -426,6 +442,10 @@ std::unique_ptr BwuManager::ProcessBwuPathAvailableEventInternal( ClientProxy* client, const string& endpoint_id, const UpgradePathInfo& upgrade_path_info) { + NEARBY_LOG(INFO, + "ProcessBwuPathAvailableEventInternal for endpoint %s medium %d", + endpoint_id.c_str(), + parser::UpgradePathInfoMediumToMedium(upgrade_path_info.medium())); std::unique_ptr channel = handler_->CreateUpgradedEndpointChannel(client, client->GetServiceId(), endpoint_id, upgrade_path_info); @@ -480,6 +500,9 @@ BwuManager::ProcessBwuPathAvailableEventInternal( void BwuManager::RunUpgradeFailedProtocol( ClientProxy* client, const std::string& endpoint_id, const UpgradePathInfo& upgrade_path_info) { + NEARBY_LOG(INFO, "RunUpgradeFailedProtocol for endpoint %s medium %d", + endpoint_id.c_str(), + parser::UpgradePathInfoMediumToMedium(upgrade_path_info.medium())); // We attempted to connect to the new medium that the remote device has set up // for us but we failed. We need to let the remote device know so that they // can pick another medium for us to try. @@ -515,6 +538,9 @@ void BwuManager::RunUpgradeFailedProtocol( bool BwuManager::ReadClientIntroductionFrame(EndpointChannel* channel, ClientIntroduction& introduction) { + NEARBY_LOG(INFO, + "ReadClientIntroductionFrame with channel name: %s, medium: %d", + channel->GetName().c_str(), channel->GetMedium()); CancelableAlarm timeout_alarm( "BwuManager::ReadClientIntroductionFrame", [channel]() { @@ -545,6 +571,9 @@ bool BwuManager::ReadClientIntroductionFrame(EndpointChannel* channel, } bool BwuManager::ReadClientIntroductionAckFrame(EndpointChannel* channel) { + NEARBY_LOG(INFO, + "ReadClientIntroductionFrame with channel name: %s, medium: %d", + channel->GetName().c_str(), channel->GetMedium()); CancelableAlarm timeout_alarm( "BwuManager::ReadClientIntroductionAckFrame", [channel]() { @@ -572,11 +601,16 @@ bool BwuManager::ReadClientIntroductionAckFrame(EndpointChannel* channel) { } bool BwuManager::WriteClientIntroductionAckFrame(EndpointChannel* channel) { + NEARBY_LOG(INFO, + "WriteClientIntroductionAckFrame channel name: %s, medium: %d", + channel->GetName().c_str(), channel->GetMedium()); return channel->Write(parser::ForBwuIntroductionAck()).Ok(); } void BwuManager::ProcessLastWriteToPriorChannelEvent( ClientProxy* client, const std::string& endpoint_id) { + NEARBY_LOG(INFO, "ProcessLastWriteToPriorChannelEvent for endpoint %s", + endpoint_id.c_str()); // By this point in the upgrade protocol, there is the guarantee that both // involved endpoints have registered a new EndpointChannel with the // EndpointChannelManager as the official channel for communication; given @@ -621,6 +655,8 @@ void BwuManager::ProcessLastWriteToPriorChannelEvent( void BwuManager::ProcessSafeToClosePriorChannelEvent( ClientProxy* client, const std::string& endpoint_id) { + NEARBY_LOG(INFO, "ProcessSafeToClosePriorChannelEvent for endpoint %s", + endpoint_id.c_str()); // By this point in the upgrade protocol, there's no more writes happening // over the prior EndpointChannel, and the remote device has given us the // go-ahead to close this EndpointChannel [1], so we can safely close it @@ -690,6 +726,9 @@ void BwuManager::ProcessSafeToClosePriorChannelEvent( void BwuManager::ProcessUpgradeFailureEvent( ClientProxy* client, const std::string& endpoint_id, const UpgradePathInfo& upgrade_info) { + NEARBY_LOG(INFO, "ProcessUpgradeFailureEvent for endpoint %s from medium: %d", + endpoint_id.c_str(), + parser::UpgradePathInfoMediumToMedium(upgrade_info.medium())); // The remote device failed to upgrade to the new medium we set up for them. // That's alright! We'll just try the next available medium (if there is // one). @@ -738,6 +777,10 @@ void BwuManager::RetryUpgradeMediums(ClientProxy* client, const std::string& endpoint_id, std::vector upgrade_mediums) { Medium next_medium = ChooseBestUpgradeMedium(upgrade_mediums); + NEARBY_LOG( + INFO, + "RetryUpgradeMediums for endpoint %s after ChooseBestUpgradeMedium: %d", + endpoint_id.c_str(), next_medium); // If current medium is not WiFi and we have not succeeded with upgrading // yet, retry upgrade. @@ -875,6 +918,7 @@ absl::Duration BwuManager::CalculateNextRetryDelay( } void BwuManager::CancelRetryUpgradeAlarm(const std::string& endpoint_id) { + NEARBY_LOG(INFO, "CancelRetryUpgradeAlarm for %s", endpoint_id.c_str()); auto item = retry_upgrade_alarms_.extract(endpoint_id); if (item.empty()) return; auto& pair = item.mapped(); @@ -882,6 +926,7 @@ void BwuManager::CancelRetryUpgradeAlarm(const std::string& endpoint_id) { } void BwuManager::CancelAllRetryUpgradeAlarms() { + NEARBY_LOG(INFO, "CancelAllRetryUpgradeAlarms invoked"); for (const auto& item : retry_upgrade_alarms_) { const std::string& endpoint_id = item.first; CancelRetryUpgradeAlarm(endpoint_id);