diff --git a/examples/tv-casting-app/linux/simple-app-helper.cpp b/examples/tv-casting-app/linux/simple-app-helper.cpp index 115fe9f7869fc9..4bdf660bd5bda9 100644 --- a/examples/tv-casting-app/linux/simple-app-helper.cpp +++ b/examples/tv-casting-app/linux/simple-app-helper.cpp @@ -450,6 +450,9 @@ CHIP_ERROR CommandHandler(int argc, char ** argv) targetCastingPlayer->VerifyOrEstablishConnection(connectionCallbacks, matter::casting::core::kCommissioningWindowTimeoutSec, idOptions); + ChipLogProgress(AppServer, "CommandHandler() request, VerifyOrEstablishConnection() called, calling StopDiscovery()"); + // Stop discovery since we have discovered, and are now connecting to the desired CastingPlayer. + matter::casting::core::CastingPlayerDiscovery::GetInstance()->StopDiscovery(); return CHIP_NO_ERROR; } if (strcmp(argv[0], "setcommissionerpasscode") == 0) diff --git a/examples/tv-casting-app/tv-casting-common/core/CastingPlayer.cpp b/examples/tv-casting-app/tv-casting-common/core/CastingPlayer.cpp index 83fc6b4b563a9e..37d442f7142aa2 100644 --- a/examples/tv-casting-app/tv-casting-common/core/CastingPlayer.cpp +++ b/examples/tv-casting-app/tv-casting-common/core/CastingPlayer.cpp @@ -380,10 +380,10 @@ chip::Inet::IPAddress * CastingPlayer::GetIpAddressForUDCRequest() void CastingPlayer::FindOrEstablishSession(void * clientContext, chip::OnDeviceConnected onDeviceConnected, chip::OnDeviceConnectionFailure onDeviceConnectionFailure) { - ChipLogProgress(AppServer, "CastingPlayer.FindOrEstablishSession called on nodeId=0x" ChipLogFormatX64 " fabricIndex=%d", + ChipLogProgress(AppServer, "CastingPlayer::FindOrEstablishSession() called on nodeId=0x" ChipLogFormatX64 " fabricIndex=%d", ChipLogValueX64(mAttributes.nodeId), mAttributes.fabricIndex); VerifyOrReturn(mAttributes.nodeId != 0 && mAttributes.fabricIndex != 0, - ChipLogError(AppServer, "CastingPlayer.FindOrEstablishSession called on invalid nodeId/fabricIndex")); + ChipLogError(AppServer, "CastingPlayer::FindOrEstablishSession() called on invalid nodeId/fabricIndex")); ConnectionContext * connectionContext = new ConnectionContext(clientContext, this, onDeviceConnected, onDeviceConnectionFailure); diff --git a/examples/tv-casting-app/tv-casting-common/core/Endpoint.h b/examples/tv-casting-app/tv-casting-common/core/Endpoint.h index 734f1e3d5ae140..85e67dbfe95ade 100644 --- a/examples/tv-casting-app/tv-casting-common/core/Endpoint.h +++ b/examples/tv-casting-app/tv-casting-common/core/Endpoint.h @@ -105,7 +105,6 @@ class Endpoint : public std::enable_shared_from_this */ std::vector GetServerList() { - ChipLogProgress(AppServer, "Endpoint::GetServerList() mClusters.size(): %d", static_cast(mClusters.size())); std::vector serverList; for (auto const & cluster : mClusters) { @@ -123,7 +122,6 @@ class Endpoint : public std::enable_shared_from_this template void RegisterCluster(const chip::ClusterId clusterId) { - ChipLogProgress(AppServer, "Endpoint::RegisterCluster() Registering clusterId %d for endpointId %d", clusterId, GetId()); static_assert(std::is_base_of::value, "T must be derived from BaseCluster"); auto cluster = std::make_shared(shared_from_this()); cluster->SetUp(); @@ -137,7 +135,6 @@ class Endpoint : public std::enable_shared_from_this memory::Strong GetCluster() { static_assert(std::is_base_of::value, "T must be derived from BaseCluster"); - ChipLogProgress(AppServer, "Endpoint::GetCluster() mClusters.size(): %d", static_cast(mClusters.size())); for (const auto & pair : mClusters) { auto cluster = std::dynamic_pointer_cast(pair.second); @@ -151,8 +148,8 @@ class Endpoint : public std::enable_shared_from_this void LogDetail() const { - ChipLogProgress(AppServer, "Endpoint::LogDetail() Endpoint ID: %d, Vendor ID: %d, Product ID: %d", mAttributes.mId, - mAttributes.mVendorId, mAttributes.mProductId); + ChipLogProgress(AppServer, "Endpoint::LogDetail() Endpoint ID: %d, Vendor ID: %d, Product ID: %d, Clusters: %d", + mAttributes.mId, mAttributes.mVendorId, mAttributes.mProductId, static_cast(mClusters.size())); } }; diff --git a/examples/tv-casting-app/tv-casting-common/support/CastingStore.cpp b/examples/tv-casting-app/tv-casting-common/support/CastingStore.cpp index 93bd00616dac6c..1ddf40a9b27abc 100644 --- a/examples/tv-casting-app/tv-casting-common/support/CastingStore.cpp +++ b/examples/tv-casting-app/tv-casting-common/support/CastingStore.cpp @@ -78,8 +78,9 @@ std::vector CastingStore::ReadAll() size_t castingStoreDataSize = 0; err = chip::DeviceLayer::PersistedStorage::KeyValueStoreMgr().Get(kCastingStoreDataKey, castingStoreData, kCastingStoreDataMaxBytes, &castingStoreDataSize); - VerifyOrReturnValue(err == CHIP_NO_ERROR, std::vector(), - ChipLogError(AppServer, "KeyValueStoreMgr.Get failed %" CHIP_ERROR_FORMAT, err.Format())); + VerifyOrReturnValue( + err == CHIP_NO_ERROR, std::vector(), + ChipLogError(AppServer, "CastingStore::ReadAll() KeyValueStoreMgr.Get failed %" CHIP_ERROR_FORMAT, err.Format())); ChipLogProgress(AppServer, "CastingStore::ReadAll() Read TLV(CastingStoreData) from KVS store with size: %lu bytes", static_cast(castingStoreDataSize)); @@ -252,6 +253,9 @@ std::vector CastingStore::ReadAll() if (endpointContainerTagNum == kCastingPlayerEndpointIdTag) { err = reader.Get(endpointAttributes.mId); + // Log which endpoints we cached. + ChipLogProgress(AppServer, "CastingStore::ReadAll() Endpoints container endpointAttributes.mId: %d", + endpointAttributes.mId); VerifyOrReturnValue(err == CHIP_NO_ERROR, std::vector(), ChipLogError(AppServer, "TLVReader.Get failed %" CHIP_ERROR_FORMAT, err.Format())); continue; @@ -475,7 +479,7 @@ CHIP_ERROR CastingStore::WriteAll(std::vector castingPlayer for (auto & castingPlayer : castingPlayers) { - ChipLogProgress(AppServer, "CastingStore::WriteAll() writing castingPlayer:"); + ChipLogProgress(AppServer, "CastingStore::WriteAll() writing CastingPlayer:"); chip::TLV::TLVType castingPlayerContainerType; // CastingPlayer container starts ReturnErrorOnFailure( @@ -547,7 +551,8 @@ CHIP_ERROR CastingStore::WriteAll(std::vector castingPlayer ReturnErrorOnFailure(tlvWriter.StartContainer(chip::TLV::ContextTag(kCastingPlayerEndpointServerListContainerTag), chip::TLV::kTLVType_Structure, serverListContainerType)); std::vector serverList = endpoint->GetServerList(); - ChipLogProgress(AppServer, "CastingStore::WriteAll() writing CastingPlayer Endpoint ServerList:"); + ChipLogProgress(AppServer, "CastingStore::WriteAll() writing CastingPlayer Endpoint ID: %d ServerList.size(): %d", + endpoint->GetId(), static_cast(serverList.size())); for (chip::ClusterId clusterId : serverList) { ChipLogProgress(AppServer, "CastingStore::WriteAll() clusterId: %d", clusterId); @@ -586,7 +591,7 @@ CHIP_ERROR CastingStore::DeleteAll() CHIP_ERROR err = chip::DeviceLayer::PersistedStorage::KeyValueStoreMgr().Delete(kCastingStoreDataKey); if (err == CHIP_ERROR_PERSISTED_STORAGE_VALUE_NOT_FOUND) // no error, if the key-value pair was not stored { - ChipLogProgress(AppServer, "CastingStore::DeleteAll ignoring error %" CHIP_ERROR_FORMAT, err.Format()); + ChipLogProgress(AppServer, "CastingStore::DeleteAll() ignoring error %" CHIP_ERROR_FORMAT, err.Format()); return CHIP_NO_ERROR; } return err; @@ -594,7 +599,7 @@ CHIP_ERROR CastingStore::DeleteAll() CHIP_ERROR CastingStore::Delete(core::CastingPlayer castingPlayer) { - ChipLogProgress(AppServer, "CastingStore::Delete"); + ChipLogProgress(AppServer, "CastingStore::Delete()"); // Read cache of CastingPlayers std::vector castingPlayers = ReadAll(); @@ -608,7 +613,7 @@ CHIP_ERROR CastingStore::Delete(core::CastingPlayer castingPlayer) if (it != castingPlayers.end()) { - ChipLogProgress(AppServer, "CastingStore::Delete deleting CastingPlayer %s from CastingStore cache", it->GetId()); + ChipLogProgress(AppServer, "CastingStore::Delete() deleting CastingPlayer %s from CastingStore cache", it->GetId()); castingPlayers.erase(it); return WriteAll(castingPlayers); } @@ -618,7 +623,7 @@ CHIP_ERROR CastingStore::Delete(core::CastingPlayer castingPlayer) void CastingStore::OnFabricRemoved(const chip::FabricTable & fabricTable, chip::FabricIndex fabricIndex) { - ChipLogProgress(AppServer, "CastingStore::OnFabricRemoved"); + ChipLogProgress(AppServer, "CastingStore::OnFabricRemoved()"); // Read cache of CastingPlayers std::vector castingPlayers = ReadAll(); @@ -633,12 +638,15 @@ void CastingStore::OnFabricRemoved(const chip::FabricTable & fabricTable, chip:: if (it != castingPlayers.end()) { - ChipLogProgress(AppServer, "CastingStore::OnFabricRemoved deleting CastingPlayer %s from CastingStore cache", + ChipLogProgress(AppServer, "CastingStore::OnFabricRemoved() deleting CastingPlayer %s from CastingStore cache", it->GetId()); castingPlayers.erase(it); WriteAll(castingPlayers); } } + CHIP_ERROR err = chip::Server::GetInstance().GetSessionResumptionStorage()->DeleteAll(fabricIndex); + ChipLogProgress(AppServer, "CastingStore::OnFabricRemoved() SessionResumptionStorage.DeleteAll(%d) status %" CHIP_ERROR_FORMAT, + fabricIndex, err.Format()); } }; // namespace support diff --git a/examples/tv-casting-app/tv-casting-common/support/ChipDeviceEventHandler.cpp b/examples/tv-casting-app/tv-casting-common/support/ChipDeviceEventHandler.cpp index cf8ca82366a7bb..f027c8d1c477df 100644 --- a/examples/tv-casting-app/tv-casting-common/support/ChipDeviceEventHandler.cpp +++ b/examples/tv-casting-app/tv-casting-common/support/ChipDeviceEventHandler.cpp @@ -62,6 +62,7 @@ void ChipDeviceEventHandler::Handle(const chip::DeviceLayer::ChipDeviceEvent * e CastingPlayer::GetTargetCastingPlayer()->SetNodeId(targetNodeId); CastingPlayer::GetTargetCastingPlayer()->SetFabricIndex(targetFabricIndex); + ChipLogProgress(AppServer, "ChipDeviceEventHandler::Handle() calling FindOrEstablishSession()"); CastingPlayer::GetTargetCastingPlayer()->FindOrEstablishSession( nullptr, [](void * context, chip::Messaging::ExchangeManager & exchangeMgr, const chip::SessionHandle & sessionHandle) { @@ -144,12 +145,12 @@ void ChipDeviceEventHandler::HandleBindingsChangedViaCluster(const chip::DeviceL bool & runPostCommissioning, chip::NodeId & targetNodeId, chip::FabricIndex & targetFabricIndex) { - ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleBindingsChangedViaCluster called"); + ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() called"); if (CastingPlayer::GetTargetCastingPlayer()->IsConnected()) { // re-use existing nodeId and fabricIndex - ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleBindingsChangedViaCluster already connected to video player"); + ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() already connected to video player"); runPostCommissioning = true; targetNodeId = CastingPlayer::GetTargetCastingPlayer()->GetNodeId(); targetFabricIndex = CastingPlayer::GetTargetCastingPlayer()->GetFabricIndex(); @@ -159,7 +160,7 @@ void ChipDeviceEventHandler::HandleBindingsChangedViaCluster(const chip::DeviceL else if (sUdcInProgress) { ChipLogProgress(AppServer, - "ChipDeviceEventHandler::HandleBindingsChangedViaCluster UDC is in progress while handling " + "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() UDC is in progress while handling " "kBindingsChangedViaCluster with " "fabricIndex: %d", event->BindingsChanged.fabricIndex); @@ -170,7 +171,7 @@ void ChipDeviceEventHandler::HandleBindingsChangedViaCluster(const chip::DeviceL for (const auto & binding : chip::BindingTable::GetInstance()) { ChipLogProgress(AppServer, - "ChipDeviceEventHandler::HandleBindingsChangedViaCluster Read cached binding type=%d fabrixIndex=%d " + "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() Read cached binding type=%d fabrixIndex=%d " "nodeId=0x" ChipLogFormatX64 " groupId=%d local endpoint=%d remote endpoint=%d cluster=" ChipLogFormatMEI, binding.type, binding.fabricIndex, ChipLogValueX64(binding.nodeId), binding.groupId, binding.local, @@ -178,7 +179,7 @@ void ChipDeviceEventHandler::HandleBindingsChangedViaCluster(const chip::DeviceL if (binding.type == MATTER_UNICAST_BINDING && event->BindingsChanged.fabricIndex == binding.fabricIndex) { ChipLogProgress(AppServer, - "ChipDeviceEventHandler::HandleBindingsChangedViaCluster Matched accessingFabricIndex with " + "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() Matched accessingFabricIndex with " "nodeId=0x" ChipLogFormatX64, ChipLogValueX64(binding.nodeId)); targetNodeId = binding.nodeId; @@ -190,9 +191,10 @@ void ChipDeviceEventHandler::HandleBindingsChangedViaCluster(const chip::DeviceL if (targetNodeId == 0 && runPostCommissioning == false) { - ChipLogError(AppServer, - "ChipDeviceEventHandler::HandleBindingsChangedViaCluster accessingFabricIndex: %d did not match bindings", - event->BindingsChanged.fabricIndex); + ChipLogError( + AppServer, + "ChipDeviceEventHandler::HandleBindingsChangedViaCluster() accessingFabricIndex: %d did not match bindings", + event->BindingsChanged.fabricIndex); CastingPlayer::GetTargetCastingPlayer()->mOnCompleted(CHIP_ERROR_INCORRECT_STATE, CastingPlayer::GetTargetCastingPlayer()); return; @@ -204,7 +206,7 @@ void ChipDeviceEventHandler::HandleCommissioningComplete(const chip::DeviceLayer bool & runPostCommissioning, chip::NodeId & targetNodeId, chip::FabricIndex & targetFabricIndex) { - ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleCommissioningComplete called"); + ChipLogProgress(AppServer, "ChipDeviceEventHandler::HandleCommissioningComplete() called"); sUdcInProgress = false; targetNodeId = event->CommissioningComplete.nodeId; targetFabricIndex = event->CommissioningComplete.fabricIndex; diff --git a/examples/tv-casting-app/tv-casting-common/support/EndpointListLoader.cpp b/examples/tv-casting-app/tv-casting-common/support/EndpointListLoader.cpp index 44e76f628b5a18..a54c4ddc59debf 100644 --- a/examples/tv-casting-app/tv-casting-common/support/EndpointListLoader.cpp +++ b/examples/tv-casting-app/tv-casting-common/support/EndpointListLoader.cpp @@ -51,9 +51,17 @@ void EndpointListLoader::Initialize(chip::Messaging::ExchangeManager * exchangeM mExchangeMgr = exchangeMgr; mSessionHandle = sessionHandle; + chip::NodeId targetCastingPlayerNodeId = CastingPlayer::GetTargetCastingPlayer()->GetNodeId(); + chip::FabricIndex targetCastingPlayerFabricIndex = CastingPlayer::GetTargetCastingPlayer()->GetFabricIndex(); + ChipLogProgress(AppServer, + "EndpointListLoader::Initialize() targetCastingPlayerNodeId: 0x" ChipLogFormatX64 + ", targetCastingPlayerFabricIndex: %d", + ChipLogValueX64(targetCastingPlayerNodeId), targetCastingPlayerFabricIndex); + for (const auto & binding : chip::BindingTable::GetInstance()) { - if (binding.type == MATTER_UNICAST_BINDING && CastingPlayer::GetTargetCastingPlayer()->GetNodeId() == binding.nodeId) + if (binding.type == MATTER_UNICAST_BINDING && targetCastingPlayerNodeId == binding.nodeId && + targetCastingPlayerFabricIndex == binding.fabricIndex) { // check to see if we discovered a new endpoint in the bindings chip::EndpointId endpointId = binding.remote; @@ -66,6 +74,8 @@ void EndpointListLoader::Initialize(chip::Messaging::ExchangeManager * exchangeM } } } + ChipLogProgress(AppServer, "EndpointListLoader::Initialize() mNewEndpointsToLoad++, mNewEndpointsToLoad: %lu", + mNewEndpointsToLoad); mPendingAttributeReads = mNewEndpointsToLoad * kTotalDesiredAttributes; mEndpointAttributesList = new EndpointAttributes[mNewEndpointsToLoad]; @@ -78,16 +88,24 @@ CHIP_ERROR EndpointListLoader::Load() VerifyOrReturnError(CastingPlayer::GetTargetCastingPlayer() != nullptr, CHIP_ERROR_INCORRECT_STATE); + chip::NodeId targetCastingPlayerNodeId = CastingPlayer::GetTargetCastingPlayer()->GetNodeId(); + chip::FabricIndex targetCastingPlayerFabricIndex = CastingPlayer::GetTargetCastingPlayer()->GetFabricIndex(); + ChipLogProgress(AppServer, + "EndpointListLoader::Load() targetCastingPlayerNodeId: 0x" ChipLogFormatX64 + ", targetCastingPlayerFabricIndex: %d", + ChipLogValueX64(targetCastingPlayerNodeId), targetCastingPlayerFabricIndex); + int endpointIndex = -1; bool isLoadingRequired = false; for (const auto & binding : chip::BindingTable::GetInstance()) { ChipLogProgress(AppServer, - "Binding type=%d fab=%d nodeId=0x" ChipLogFormatX64 + "EndpointListLoader::Load() Binding type=%d fab=%d nodeId=0x" ChipLogFormatX64 " groupId=%d local endpoint=%d remote endpoint=%d cluster=" ChipLogFormatMEI, binding.type, binding.fabricIndex, ChipLogValueX64(binding.nodeId), binding.groupId, binding.local, binding.remote, ChipLogValueMEI(binding.clusterId.value_or(0))); - if (binding.type == MATTER_UNICAST_BINDING && CastingPlayer::GetTargetCastingPlayer()->GetNodeId() == binding.nodeId) + if (binding.type == MATTER_UNICAST_BINDING && targetCastingPlayerNodeId == binding.nodeId && + targetCastingPlayerFabricIndex == binding.fabricIndex) { // if we discovered a new Endpoint from the bindings, read its EndpointAttributes chip::EndpointId endpointId = binding.remote; @@ -98,7 +116,8 @@ CHIP_ERROR EndpointListLoader::Load() }) == endpoints.end()) { // Read attributes and mEndpointAttributesList for (endpointIndex + 1) - ChipLogProgress(AppServer, "EndpointListLoader::Load Reading attributes for endpointId %d", endpointId); + ChipLogProgress(AppServer, "EndpointListLoader::Load() Reading attributes for endpointId: %d, on fabricIndex: %d", + endpointId, binding.fabricIndex); isLoadingRequired = true; mEndpointAttributesList[++endpointIndex].mId = endpointId; ReadVendorId(&mEndpointAttributesList[endpointIndex]); @@ -121,7 +140,7 @@ CHIP_ERROR EndpointListLoader::Load() void EndpointListLoader::Complete() { - ChipLogProgress(AppServer, "EndpointListLoader::Complete called with mPendingAttributeReads %lu", mPendingAttributeReads); + ChipLogProgress(AppServer, "EndpointListLoader::Complete() called with mPendingAttributeReads: %lu", mPendingAttributeReads); if (mPendingAttributeReads > 0) { mPendingAttributeReads--; @@ -161,7 +180,7 @@ void EndpointListLoader::Complete() // callback client OnCompleted VerifyOrReturn(CastingPlayer::GetTargetCastingPlayer()->mOnCompleted, - ChipLogError(AppServer, "EndpointListLoader::Complete mOnCompleted() not found")); + ChipLogError(AppServer, "EndpointListLoader::Complete() mOnCompleted() not found")); CastingPlayer::GetTargetCastingPlayer()->mOnCompleted(CHIP_NO_ERROR, CastingPlayer::GetTargetCastingPlayer()); } } @@ -180,7 +199,8 @@ CHIP_ERROR EndpointListLoader::ReadVendorId(EndpointAttributes * endpointAttribu }, [](void * context, CHIP_ERROR err) { EndpointAttributes * _endpointAttributes = static_cast(context); - ChipLogError(AppServer, "EndpointListLoader ReadAttribute(VendorID) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, + ChipLogError(AppServer, + "EndpointListLoader::ReadAttribute(VendorID) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, _endpointAttributes->mId, err.Format()); EndpointListLoader::GetInstance()->Complete(); }); @@ -201,7 +221,7 @@ CHIP_ERROR EndpointListLoader::ReadProductId(EndpointAttributes * endpointAttrib [](void * context, CHIP_ERROR err) { EndpointAttributes * _endpointAttributes = static_cast(context); ChipLogError(AppServer, - "EndpointListLoader ReadAttribute(ProductID) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, + "EndpointListLoader::ReadAttribute(ProductID) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, _endpointAttributes->mId, err.Format()); EndpointListLoader::GetInstance()->Complete(); }); @@ -227,7 +247,7 @@ CHIP_ERROR EndpointListLoader::ReadDeviceTypeList(EndpointAttributes * endpointA [](void * context, CHIP_ERROR err) { EndpointAttributes * _endpointAttributes = static_cast(context); ChipLogError(AppServer, - "EndpointListLoader ReadAttribute(DeviceTypeList) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, + "EndpointListLoader::ReadAttribute(DeviceTypeList) failed for endpointID %d. Err: %" CHIP_ERROR_FORMAT, _endpointAttributes->mId, err.Format()); EndpointListLoader::GetInstance()->Complete(); }); @@ -251,7 +271,9 @@ CHIP_ERROR EndpointListLoader::ReadServerList(std::vector * end EndpointListLoader::GetInstance()->Complete(); }, [](void * context, CHIP_ERROR err) { - ChipLogError(AppServer, "EndpointListLoader ReadAttribute(ServerList) failed. Err: %" CHIP_ERROR_FORMAT, err.Format()); + ChipLogError(AppServer, + "EndpointListLoader::ReadServerList() ReadAttribute(ServerList) failed. Err: %" CHIP_ERROR_FORMAT, + err.Format()); EndpointListLoader::GetInstance()->Complete(); }); }