crash in exchange context when sending multiple messages

[yunhanw-google]

Problem

See the consistent crash when running all cirque integration test, after reverting #5938, issue goes away
for example, in echo test,
/out/debug/linux_x64_clang/chip-echo-requester 100.96.158.129
./out/debug/linux_x64_clang/chip-echo-responder
we see
Echo Response: 1/1(100.00%) len=15 time=0.001ms
CHIP:IN: ExchangeContext::Free is called, 0x55555563c548
CHIP:EM: Sending Standalone Ack for MsgId:00000000

CHIP:IN: Secure msg send status No Error
CHIP:EM: Rxd Ack; Removing MsgId:00000000 from Retrans Table
CHIP:EM: Removed CHIP MsgId:00000000 from RetransTable
CHIP:EM: Sending Standalone Ack for MsgId:00000000
CHIP:EM: Failed to send Solitary ack for MsgId:00000000:4003
Echo Response: 1/1(100.00%) len=15 time=0.000ms
CHIP:EM: Sending Standalone Ack for MsgId:00000000

Thread 8 "chip-echo-reque" received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffe77fe700 (LWP 1467642)]
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007ffff7522537 in __GI_abort () at abort.c:79
#2 0x00005555555e2b64 in chip::Messaging::ExchangeContext::SendMessageImpl(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&, chip::Transport::PeerConnectionState*)
(this=0x55555563c368 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=..., state=0x55555563d310 <(anonymous namespace)::gSessionManager+32>)
at ../../src/messaging/ExchangeContext.cpp:119
#3 0x00005555555e2a53 in chip::Messaging::ExchangeContext::SendMessage(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&) (this=0x55555563c368 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=...) at ../../src/messaging/ExchangeContext.cpp:107
#4 0x00005555555e937f in chip::Messaging::ExchangeContext::SendMessage<chip::Protocols::SecureChannel::MsgType, void>(chip::Protocols::SecureChannel::MsgType, chip::System::PacketBufferHandle&&, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&)
(this=0x55555563c368 <gExchangeManager+520>, msgType=chip::Protocols::SecureChannel::MsgType::StandaloneAck, msgPayload=..., sendFlags=...) at ../../src/messaging/ExchangeContext.h:122
#5 0x00005555555e8f5b in chip::Messaging::ReliableMessageContext::SendStandaloneAckMessage() (this=0x55555563c370 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:271
#6 0x00005555555e8e39 in chip::Messaging::ReliableMessageContext::FlushAcks() (this=0x55555563c370 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:125
#7 0x00005555555e3015 in chip::Messaging::ExchangeContext::DoClose(bool) (this=0x55555563c368 <gExchangeManager+520>, clearRetransTable=false) at ../../src/messaging/ExchangeContext.cpp:179
#8 0x00005555555e33fe in chip::Messaging::ExchangeContext::Free() (this=0x55555563c368 <gExchangeManager+520>) at ../../src/messaging/ExchangeContext.cpp:277
#9 0x00005555555e3b35 in chip::Messaging::ExchangeContextDeletor::Release(chip::Messaging::ExchangeContext*) (obj=0x55555563c368 <gExchangeManager+520>)
at ../../src/messaging/ExchangeContext.h:246
#10 0x00005555555e2fb2 in chip::ReferenceCounted<chip::Messaging::ExchangeContext, chip::Messaging::ExchangeContextDeletor, 0>::Release() (this=0x55555563c368 <gExchangeManager+520>)
at ../../src/lib/core/ReferenceCounted.h:72
#11 0x00005555555e38bf in chip::Messaging::ExchangeContext::HandleMessage(chip::PacketHeader const&, chip::PayloadHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle) (this=0x55555563c368 <gExchangeManager+520>, packetHeader=..., payloadHeader=..., peerAddress=..., msgBuf=...) at ../../src/messaging/ExchangeContext.cpp:397
#12 0x00005555555e528b in chip::Messaging::ExchangeManager::OnMessageReceived(chip::PacketHeader const&, chip::PayloadHeader const&, chip::SecureSessionHandle, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle, chip::SecureSessionMgr*) (this=
0x55555563c160 , packetHeader=..., payloadHeader=..., session=..., source=..., msgBuf=..., msgLayer=0x55555563d2f0 <(anonymous namespace)::gSessionManager>)
at ../../src/messaging/ExchangeMgr.cpp:234

In IM test,
./out/debug/linux_x64_clang/chip-im-responder
./out/debug/linux_x64_clang/chip-im-initiator 100.96.158.129

CHIP:DMG: ICR moving to [Initialize]
Command Response: 1/1(100.00%) time=0.001ms
CHIP:IN: ExchangeContext::Free is called, 0x55555564e588
CHIP:EM: Sending Standalone Ack for MsgId:00000000

Send invoke command request message to Node: 12344321
CHIP:DMG: ICR moving to [AddCommand]

Thread 8 "chip-im-initiat" received signal SIGABRT, Aborted.
[Switching to Thread 0x7fffe77fe700 (LWP 1373052)]
__GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
50 ../sysdeps/unix/sysv/linux/raise.c: No such file or directory.
(gdb) bt
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007ffff7522537 in __GI_abort () at abort.c:79
#2 0x00005555555ce874 in chip::Messaging::ExchangeContext::SendMessageImpl(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&, chip::Transport::PeerConnectionState*)
(this=0x55555564e588 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=..., state=0x55555564dbe8 <(anonymous namespace)::gSessionManager+32>)
at ../../src/messaging/ExchangeContext.cpp:119
#3 0x00005555555ce783 in chip::Messaging::ExchangeContext::SendMessage(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&) (this=0x55555564e588 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=...) at ../../src/messaging/ExchangeContext.cpp:107
#4 0x00005555555d53bf in chip::Messaging::ExchangeContext::SendMessage<chip::Protocols::SecureChannel::MsgType, void>(chip::Protocols::SecureChannel::MsgType, chip::System::PacketBufferHandle&&, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&)
(this=0x55555564e588 <gExchangeManager+520>, msgType=chip::Protocols::SecureChannel::MsgType::StandaloneAck, msgPayload=..., sendFlags=...) at ../../src/messaging/ExchangeContext.h:122
#5 0x00005555555d4f9b in chip::Messaging::ReliableMessageContext::SendStandaloneAckMessage() (this=0x55555564e590 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:271
#6 0x00005555555d4e79 in chip::Messaging::ReliableMessageContext::FlushAcks() (this=0x55555564e590 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:125
#7 0x00005555555ceda5 in chip::Messaging::ExchangeContext::DoClose(bool) (this=0x55555564e588 <gExchangeManager+520>, clearRetransTable=false) at ../../src/messaging/ExchangeContext.cpp:179
#8 0x00005555555cf1ad in chip::Messaging::ExchangeContext::Free() (this=0x55555564e588 <gExchangeManager+520>) at ../../src/messaging/ExchangeContext.cpp:278
#9 0x00005555555cf8b5 in chip::Messaging::ExchangeContextDeletor::Release(chip::Messaging::ExchangeContext*) (obj=0x55555564e588 <gExchangeManager+520>)
at ../../src/messaging/ExchangeContext.h:246
#10 0x00005555555ced42 in chip::ReferenceCounted<chip::Messaging::ExchangeContext, chip::Messaging::ExchangeContextDeletor, 0>::Release() (this=0x55555564e588 <gExchangeManager+520>)
at ../../src/lib/core/ReferenceCounted.h:72
#11 0x00005555555cf66b in chip::Messaging::ExchangeContext::HandleMessage(chip::PacketHeader const&, chip::PayloadHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle) (this=0x55555564e588 <gExchangeManager+520>, packetHeader=..., payloadHeader=..., peerAddress=..., msgBuf=...) at ../../src/messaging/ExchangeContext.cpp:402
#12 0x00005555555d100b in chip::Messaging::ExchangeManager::OnMessageReceived(chip::PacketHeader const&, chip::PayloadHeader const&, chip::SecureSessionHandle, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle, chip::SecureSessionMgr*) (this=
0x55555564e380 , packetHeader=..., payloadHeader=..., session=..., source=..., msgBuf=..., msgLayer=0x55555564dbc8 <(anonymous namespace)::gSessionManager>)
at ../../src/messaging/ExchangeMgr.cpp:234
#13 0x0000555555600ad9 in chip::SecureSessionMgr::SecureMessageDispatch(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle)
(this=0x55555564dbc8 <(anonymous namespace)::gSessionManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/SecureSessionMgr.cpp:465
#14 0x000055555560045d in chip::SecureSessionMgr::OnMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle)
(this=0x55555564dbc8 <(anonymous namespace)::gSessionManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/SecureSessionMgr.cpp:356
#15 0x0000555555601920 in chip::TransportMgrBase::HandleMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle) (this=
0x55555564db80 <(anonymous namespace)::gTransportManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/TransportMgrBase.cpp:59
#16 0x00005555556031de in chip::Transport::Base::HandleMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&)
(this=0x55555564dba8 <(anonymous namespace)::gTransportManager+40>, header=..., source=..., buffer=...) at ../../src/transport/raw/Base.h:93
#17 0x0000555555602ed3 in chip::Transport::UDP::OnUdpReceive(chip::Inet::IPEndPointBasis*, chip::System::PacketBufferHandle, chip::Inet::IPPacketInfo const*)
(endPoint=0x555555652e58 chip::Inet::UDPEndPoint::sPool, buffer=..., pktInfo=0x7fffe77fdb58) at ../../src/transport/raw/UDP.cpp:118
#18 0x00005555555e4bc0 in chip::Inet::IPEndPointBasis::HandlePendingIO(unsigned short) (this=0x555555652e58 chip::Inet::UDPEndPoint::sPool, aPort=11098)
at ../../src/inet/IPEndPointBasis.cpp:1183
#19 0x00005555555e69c4 in chip::Inet::UDPEndPoint::HandlePendingIO() (this=0x555555652e58 chip::Inet::UDPEndPoint::sPool) at ../../src/inet/UDPEndPoint.cpp:941
#20 0x00005555555e3283 in chip::Inet::InetLayer::HandleSelectResult(int, fd_set*, fd_set*, fd_set*) (this=
0x555555650b80 chip::DeviceLayer::InetLayer, selectRes=11, readfds=0x555555650c30 chip::DeviceLayer::PlatformManagerImpl::sInstance+16, writefds=0x555555650cb0 chip::DeviceLayer::PlatformManagerImpl::sInstance+144, exceptfds=0x555555650d30 chip::DeviceLayer::PlatformManagerImpl::sInstance+272) at ../../src/inet/InetLayer.cpp:1271
#21 0x00005555555a59d5 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::SysProcess()
(this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:185
#22 0x00005555555a55a6 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::_RunEventLoop()
(this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:203
#23 0x00005555555a5dd8 in chip::DeviceLayer::PlatformManager::RunEventLoop() (this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance)
at ../../src/include/platform/PlatformManager.h:204
#24 0x00005555555a5bd8 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::EventLoopTaskMain(void*)
(arg=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:214
#25 0x00007ffff7f82ea7 in start_thread (arg=) at pthread_create.c:477
#26 0x00007ffff75fadef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95
(gdb)
#0 __GI_raise (sig=sig@entry=6) at ../sysdeps/unix/sysv/linux/raise.c:50
#1 0x00007ffff7522537 in __GI_abort () at abort.c:79
#2 0x00005555555ce874 in chip::Messaging::ExchangeContext::SendMessageImpl(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&, chip::Transport::PeerConnectionState*)
(this=0x55555564e588 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=..., state=0x55555564dbe8 <(anonymous namespace)::gSessionManager+32>)
at ../../src/messaging/ExchangeContext.cpp:119
#3 0x00005555555ce783 in chip::Messaging::ExchangeContext::SendMessage(chip::Protocols::Id, unsigned char, chip::System::PacketBufferHandle, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&) (this=0x55555564e588 <gExchangeManager+520>, protocolId=..., msgType=16 '\020', msgBuf=..., sendFlags=...) at ../../src/messaging/ExchangeContext.cpp:107
#4 0x00005555555d53bf in chip::Messaging::ExchangeContext::SendMessage<chip::Protocols::SecureChannel::MsgType, void>(chip::Protocols::SecureChannel::MsgType, chip::System::PacketBufferHandle&&, chip::BitFlags<chip::Messaging::SendMessageFlags, unsigned short> const&)
(this=0x55555564e588 <gExchangeManager+520>, msgType=chip::Protocols::SecureChannel::MsgType::StandaloneAck, msgPayload=..., sendFlags=...) at ../../src/messaging/ExchangeContext.h:122
#5 0x00005555555d4f9b in chip::Messaging::ReliableMessageContext::SendStandaloneAckMessage() (this=0x55555564e590 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:271
#6 0x00005555555d4e79 in chip::Messaging::ReliableMessageContext::FlushAcks() (this=0x55555564e590 <gExchangeManager+528>) at ../../src/messaging/ReliableMessageContext.cpp:125
#7 0x00005555555ceda5 in chip::Messaging::ExchangeContext::DoClose(bool) (this=0x55555564e588 <gExchangeManager+520>, clearRetransTable=false) at ../../src/messaging/ExchangeContext.cpp:179
#8 0x00005555555cf1ad in chip::Messaging::ExchangeContext::Free() (this=0x55555564e588 <gExchangeManager+520>) at ../../src/messaging/ExchangeContext.cpp:278
#9 0x00005555555cf8b5 in chip::Messaging::ExchangeContextDeletor::Release(chip::Messaging::ExchangeContext*) (obj=0x55555564e588 <gExchangeManager+520>)
at ../../src/messaging/ExchangeContext.h:246
#10 0x00005555555ced42 in chip::ReferenceCounted<chip::Messaging::ExchangeContext, chip::Messaging::ExchangeContextDeletor, 0>::Release() (this=0x55555564e588 <gExchangeManager+520>)
at ../../src/lib/core/ReferenceCounted.h:72
#11 0x00005555555cf66b in chip::Messaging::ExchangeContext::HandleMessage(chip::PacketHeader const&, chip::PayloadHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle) (this=0x55555564e588 <gExchangeManager+520>, packetHeader=..., payloadHeader=..., peerAddress=..., msgBuf=...) at ../../src/messaging/ExchangeContext.cpp:402
#12 0x00005555555d100b in chip::Messaging::ExchangeManager::OnMessageReceived(chip::PacketHeader const&, chip::PayloadHeader const&, chip::SecureSessionHandle, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle, chip::SecureSessionMgr*)
(this=0x55555564e380 , packetHeader=..., payloadHeader=..., session=..., source=..., msgBuf=..., msgLayer=0x55555564dbc8 <(anonymous namespace)::gSessionManager>)
at ../../src/messaging/ExchangeMgr.cpp:234
#13 0x0000555555600ad9 in chip::SecureSessionMgr::SecureMessageDispatch(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle)
(this=0x55555564dbc8 <(anonymous namespace)::gSessionManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/SecureSessionMgr.cpp:465
#14 0x000055555560045d in chip::SecureSessionMgr::OnMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle)
(this=0x55555564dbc8 <(anonymous namespace)::gSessionManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/SecureSessionMgr.cpp:356
#15 0x0000555555601920 in chip::TransportMgrBase::HandleMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle)
(this=0x55555564db80 <(anonymous namespace)::gTransportManager>, packetHeader=..., peerAddress=..., msg=...) at ../../src/transport/TransportMgrBase.cpp:59
#16 0x00005555556031de in chip::Transport::Base::HandleMessageReceived(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&)
(this=0x55555564dba8 <(anonymous namespace)::gTransportManager+40>, header=..., source=..., buffer=...) at ../../src/transport/raw/Base.h:93
#17 0x0000555555602ed3 in chip::Transport::UDP::OnUdpReceive(chip::Inet::IPEndPointBasis*, chip::System::PacketBufferHandle, chip::Inet::IPPacketInfo const*)
(endPoint=0x555555652e58 chip::Inet::UDPEndPoint::sPool, buffer=..., pktInfo=0x7fffe77fdb58) at ../../src/transport/raw/UDP.cpp:118
#18 0x00005555555e4bc0 in chip::Inet::IPEndPointBasis::HandlePendingIO(unsigned short) (this=0x555555652e58 chip::Inet::UDPEndPoint::sPool, aPort=11098)
at ../../src/inet/IPEndPointBasis.cpp:1183
#19 0x00005555555e69c4 in chip::Inet::UDPEndPoint::HandlePendingIO() (this=0x555555652e58 chip::Inet::UDPEndPoint::sPool) at ../../src/inet/UDPEndPoint.cpp:941
#20 0x00005555555e3283 in chip::Inet::InetLayer::HandleSelectResult(int, fd_set*, fd_set*, fd_set*) (this=
0x555555650b80 chip::DeviceLayer::InetLayer, selectRes=11, readfds=0x555555650c30 chip::DeviceLayer::PlatformManagerImpl::sInstance+16, writefds=0x555555650cb0 chip::DeviceLayer::PlatformManagerImpl::sInstance+144, exceptfds=0x555555650d30 chip::DeviceLayer::PlatformManagerImpl::sInstance+272) at ../../src/inet/InetLayer.cpp:1271
#21 0x00005555555a59d5 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::SysProcess()
(this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:185
#22 0x00005555555a55a6 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::_RunEventLoop()
(this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:203
#23 0x00005555555a5dd8 in chip::DeviceLayer::PlatformManager::RunEventLoop() (this=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance)
at ../../src/include/platform/PlatformManager.h:204
#24 0x00005555555a5bd8 in chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIXchip::DeviceLayer::PlatformManagerImpl::EventLoopTaskMain(void*)
(arg=0x555555650c20 chip::DeviceLayer::PlatformManagerImpl::sInstance) at ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.cpp:214
#25 0x00007ffff7f82ea7 in start_thread (arg=) at pthread_create.c:477
#26 0x00007ffff75fadef in clone () at ../sysdeps/unix/sysv/linux/x86_64/clone.S:95

note(
Since we disable cirque in master temporarily, we have not yet catched the below crash in time
)