Crash in OnRefreshSubscribeTimerSyncCallback when a new request cannot get attribute paths in handler

[yunhanw-google]

Problem

https://github.com/project-chip/connectedhomeip/runs/6183140367?check_suite_focus=true looks like a ReadHandler use-after-free
it seems it fail in new test introduced from resource minimas PR, https://github.com/project-chip/connectedhomeip/commit/077e44eadf46f349916b3f4f358da6126be2ed48#diff-77150bc5eb6a8acd1ca[…]002fa2dc773dc8e4df8721e9b, where it would kill the read handlers that uses more paths than the limit per fabric, at the same time, readhandler try to send the report for previous sub.

[1651008934853] [33203:330540] CHIP: [EM] Found matching exchange: 62317i, Delegate: 0x611000012600
[1651008934853] [33203:330540] CHIP: [EM] Rxd Ack; Removing MessageCounter:5771483 from Retrans Table on exchange 62317i
[1651008934853] [33203:330540] CHIP: [EM] Removed CHIP MessageCounter:5771483 from RetransTable on exchange 62317i
[1651008934853] [33203:330540] CHIP: [DMG] StatusResponseMessage =
[1651008934853] [33203:330540] CHIP: [DMG] {
[1651008934853] [33203:330540] CHIP: [DMG] Status = 0xc8 (PATHS_EXHAUSTED),
[1651008934853] [33203:330540] CHIP: [DMG] InteractionModelRevision = 1
[1651008934853] [33203:330540] CHIP: [DMG] }
[1651008934853] [33203:330540] CHIP: [IM] Received status response, status is 0xc8 (PATHS_EXHAUSTED)
[1651008934853] [33203:330540] CHIP: [DMG] mResubscribePolicy is null
[1651008934853] [33203:330540] CHIP: [EM] Sending Standalone Ack for MessageCounter:9523671 on exchange 62317i
[1651008934853] [33203:330540] CHIP: [IN] Prepared secure message 0x7ffee13833e0 to 0xDEDEDEDE00010001 (2) of type 0x10 and protocolId (0, 0) on exchange 62317i with MessageCounter:5771484.
[1651008934853] [33203:330540] CHIP: [IN] Sending encrypted msg 0x7ffee13833e0 with MessageCounter:5771484 to 0xDEDEDEDE00010001 (2) at monotonic time: 000000000033ABE4 msec
[1651008934853] [33203:330540] CHIP: [EM] Flushed pending ack for MessageCounter:9523671 on exchange 62317i
[1651008934854] [33203:330540] CHIP: [EM] Received message of type 0x10 with protocolId (0, 0) and MessageCounter:5771484 on exchange 62317r
[1651008934854] [33203:330540] CHIP: [EM] Found matching exchange: 62317r, Delegate: 0x0
[1651008934854] [33203:330540] CHIP: [EM] Rxd Ack; Removing MessageCounter:9523671 from Retrans Table on exchange 62317r
[1651008934854] [33203:330540] CHIP: [EM] Removed CHIP MessageCounter:9523671 from RetransTable on exchange 62317r
[1651008934854] [33203:330540] CHIP: [IN] Prepared secure message 0x7ffee1388388 to 0xDEDEDEDE00010001 (2) of type 0x3 and protocolId (0, 1) on exchange 62318i with MessageCounter:5771485.
[1651008934854] [33203:330540] CHIP: [IN] Sending encrypted msg=================================================================
==33203==ERROR: AddressSanitizer: heap-use-after-free on address 0x612000021409 at pc 0x00010eb3a0df bp 0x7ffee1385a90 sp 0x7ffee1385a88
WRITE of size 1 at 0x612000021409 thread T0
#0 0x10eb3a0de in chip::app::ReadHandler::OnRefreshSubscribeTimerSyncCallback(chip::System::Layer*, void*) ReadHandler.cpp:783
#1 0x10ebd41ad in chip::System::TimerData::Callback::Invoke() const SystemTimer.h:61
#2 0x10ebd1033 in chip::System::TimerPoolchip::System::TimerList::Node::Invoke(chip::System::TimerList::Node*) SystemTimer.h:224
#3 0x10ebd0838 in chip::System::LayerImplSelect::HandleEvents() SystemLayerImplSelect.cpp:397
#4 0x10ecb40b9 in ServiceEvents(unsigned int) TestInetCommonPosix.cpp:450
#5 0x10ecb252c in chip::Test::IOContext::DriveIO() NetworkTestHelpers.cpp:62
#6 0x10e92995e in chip::Test::LoopbackTransportManager::DrainAndServiceIO(std::__1::chrono::duration<unsigned int, std::__1::ratio<1l, 1000l> >) LoopbackTransportManager.h:79
#7 0x10e926482 in (anonymous namespace)::TestReadInteraction::TestReadHandler_KillOverQuotaSubscriptions(_nlTestSuite*, void*) TestRead.cpp:1605
#8 0x10ecb7f50 in nlTestRunner nlunit-test.c:213
#9 0x10e8e22ad in TestReadInteractionTest() TestRead.cpp:1768
#10 0x10e8708ca in main TestRead.driver.cpp:32
#11 0x7fff2059ef3c in start+0x0 (libdyld.dylib:x86_64+0x15f3c)

0x612000021409 is located 201 bytes inside of 296-byte region [0x612000021340,0x612000021468)
freed by thread T0 here:

[erjiaqing]

Given the fact that

connectedhomeip/src/app/ReadHandler.cpp

Lines 84 to 110 in 13ef4a3

	ReadHandler::~ReadHandler()
	{
	auto * appCallback = mManagementCallback.GetAppCallback();
	if (mActiveSubscription && appCallback)
	{
	appCallback->OnSubscriptionTerminated(*this);
	}
	Abort(true);
	if (IsType(InteractionType::Subscribe))
	{
	InteractionModelEngine::GetInstance()->GetExchangeManager()->GetSessionManager()->SystemLayer()->CancelTimer(
	OnUnblockHoldReportCallback, this);
	InteractionModelEngine::GetInstance()->GetExchangeManager()->GetSessionManager()->SystemLayer()->CancelTimer(
	OnRefreshSubscribeTimerSyncCallback, this);
	}
	if (IsAwaitingReportResponse())
	{
	InteractionModelEngine::GetInstance()->GetReportingEngine().OnReportConfirm();
	}
	InteractionModelEngine::GetInstance()->ReleaseAttributePathList(mpAttributePathList);
	InteractionModelEngine::GetInstance()->ReleaseEventPathList(mpEventPathList);
	InteractionModelEngine::GetInstance()->ReleaseDataVersionFilterList(mpDataVersionFilterList);
	}

We have

         InteractionModelEngine::GetInstance()->GetExchangeManager()->GetSessionManager()->SystemLayer()->CancelTimer( 
             OnUnblockHoldReportCallback, this); 
  
         InteractionModelEngine::GetInstance()->GetExchangeManager()->GetSessionManager()->SystemLayer()->CancelTimer( 
             OnRefreshSubscribeTimerSyncCallback, this); 

In the destructor of the ReadHandler, it is quite strange that this timer is not cancelled actually.

--> If destructor is called, then this function should not be called.
--> If destructor is not called, then this function should not crash.

[bzbarsky-apple]

We can't defer a known use-after-free...

[andy31415]

Maybe fixed by #22375 since that one had a use-after-free in readhandler

[andy31415]

Based on the signature, I believe this is a duplicate of #22160 which was fixed.