[msg] Add unit tests for PacketHeader spec compliance. #1

turon · 2021-10-08T03:21:15Z

This adds some unit tests to help verify and debug spec compliance of the PacketHeader class.

It's not safe to access line editing state from the IO thread while inside readline() on the main thread. Remove the code that attempts to redraw readline after printing logs. This avoids segfaults during logging at the cost of those logs overwriting the prompt (this is not trivial to fix as readline is a blocking API). ================== WARNING: ThreadSanitizer: data race (pid=63005) Write of size 1 at 0x55f81c7745ff by main thread: #0 InteractiveStartCommand::ParseCommand(char*) ../../examples/chip-tool/commands/interactive/InteractiveCommands.cpp:127 (chip-tool+0x874911) #1 InteractiveStartCommand::RunCommand() ../../examples/chip-tool/commands/interactive/InteractiveCommands.cpp:85 (chip-tool+0x874594) project-chip#2 CHIPCommand::StartWaiting(std::chrono::duration<unsigned int, std::ratio<1l, 1000l> >) ../../examples/chip-tool/commands/common/CHIPCommand.cpp:408 (chip-tool+0x83e478) project-chip#3 CHIPCommand::Run() ../../examples/chip-tool/commands/common/CHIPCommand.cpp:187 (chip-tool+0x83c839) project-chip#4 Commands::RunCommand(int, char**, bool) ../../examples/chip-tool/commands/common/Commands.cpp:147 (chip-tool+0x85d4f7) project-chip#5 Commands::Run(int, char**) ../../examples/chip-tool/commands/common/Commands.cpp:51 (chip-tool+0x85c288) project-chip#6 main <null> (chip-tool+0x569c0a) Previous read of size 1 at 0x55f81c7745ff by thread T5 (mutexes: write M185): #0 LoggingCallback ../../examples/chip-tool/commands/interactive/InteractiveCommands.cpp:46 (chip-tool+0x874479) #1 chip::Logging::LogV(unsigned char, unsigned char, char const*, __va_list_tag*) ../../src/lib/support/logging/CHIPLogging.cpp:221 (chip-tool+0x8ee4dc) project-chip#2 chip::Logging::Log(unsigned char, unsigned char, char const*, ...) ../../src/lib/support/logging/CHIPLogging.cpp:172 (chip-tool+0x8ee30a) project-chip#3 chip::app::ReadClient::RefreshLivenessCheckTimer() <null> (chip-tool+0x8b1746) project-chip#4 chip::app::ReadClient::ProcessSubscribeResponse(chip::System::PacketBufferHandle&&) ../../src/app/ReadClient.cpp:845 (chip-tool+0x8b20ec) project-chip#5 chip::app::ReadClient::OnMessageReceived(chip::Messaging::ExchangeContext*, chip::PayloadHeader const&, chip::System::PacketBufferHandle&&) ../../src/app/ReadClient.cpp:409 (chip-tool+0x8ae2a4) project-chip#6 chip::Messaging::ExchangeContext::HandleMessage(unsigned int, chip::PayloadHeader const&, chip::BitFlags<chip::Messaging::MessageFlagValues, unsigned int>, chip::System::PacketBufferHandle&&) <null> (chip-tool+0xa0517a) project-chip#7 operator()<chip::Messaging::ExchangeContext> ../../src/messaging/ExchangeMgr.cpp:219 (chip-tool+0xa08c73) project-chip#8 Call ../../src/lib/support/Pool.h:126 (chip-tool+0xa0912d) project-chip#9 chip::internal::HeapObjectList::ForEachNode(void*, chip::Loop (*)(void*, void*)) ../../src/lib/support/Pool.cpp:127 (chip-tool+0x8ee05a) project-chip#10 ForEachActiveObject<chip::Messaging::ExchangeManager::OnMessageReceived(const chip::PacketHeader&, const chip::PayloadHeader&, const chip::SessionHandle&, chip::SessionMessageDelegate::DuplicateMessage, chip::System::PacketBufferHandle&&)::<lambda(auto:2*)> > ../../src/lib/support/Pool.h:396 (chip-tool+0xa08d10) project-chip#11 chip::Messaging::ExchangeManager::OnMessageReceived(chip::PacketHeader const&, chip::PayloadHeader const&, chip::SessionHandle const&, chip::SessionMessageDelegate::DuplicateMessage, chip::System::PacketBufferHandle&&) ../../src/messaging/ExchangeMgr.cpp:212 (chip-tool+0xa07e91) project-chip#12 chip::SessionManager::SecureUnicastMessageDispatch(chip::PacketHeader const&, chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&) ../../src/transport/SessionManager.cpp:616 (chip-tool+0xa1548b) project-chip#13 chip::SessionManager::OnMessageReceived(chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&) ../../src/transport/SessionManager.cpp:443 (chip-tool+0xa14426) project-chip#14 chip::TransportMgrBase::HandleMessageReceived(chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&) ../../src/transport/TransportMgrBase.cpp:76 (chip-tool+0xa17dfa) project-chip#15 chip::Transport::Base::HandleMessageReceived(chip::Transport::PeerAddress const&, chip::System::PacketBufferHandle&&) ../../src/transport/raw/Base.h:102 (chip-tool+0xb19728) project-chip#16 chip::Transport::UDP::OnUdpReceive(chip::Inet::UDPEndPoint*, chip::System::PacketBufferHandle&&, chip::Inet::IPPacketInfo const*) ../../src/transport/raw/UDP.cpp:122 (chip-tool+0xb1a48b) project-chip#17 chip::Inet::UDPEndPointImplSockets::HandlePendingIO(chip::BitFlags<chip::System::SocketEventFlags, unsigned char>) ../../src/inet/UDPEndPointImplSockets.cpp:688 (chip-tool+0xb00aa0) project-chip#18 chip::Inet::UDPEndPointImplSockets::HandlePendingIO(chip::BitFlags<chip::System::SocketEventFlags, unsigned char>, long) ../../src/inet/UDPEndPointImplSockets.cpp:569 (chip-tool+0xafff89) project-chip#19 chip::System::LayerImplSelect::HandleEvents() ../../src/system/SystemLayerImplSelect.cpp:406 (chip-tool+0xb07563) project-chip#20 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::_RunEventLoop() ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:181 (chip-tool+0x98a227) project-chip#21 chip::DeviceLayer::PlatformManager::RunEventLoop() ../../src/include/platform/PlatformManager.h:362 (chip-tool+0x988f75) project-chip#22 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::EventLoopTaskMain(void*) ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:205 (chip-tool+0x98a87c) Location is global '(anonymous namespace)::gIsCommandRunning' of size 1 at 0x55f81c7745ff (chip-tool+0x000000c485ff) Mutex M185 (0x55f81c776180) created at: #0 pthread_mutex_lock ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:4240 (libtsan.so.0+0x4f30a) #1 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::_LockChipStack() ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:78 (chip-tool+0x989e90) project-chip#2 chip::DeviceLayer::PlatformManager::LockChipStack() ../../src/include/platform/PlatformManager.h:410 (chip-tool+0x988fa5) project-chip#3 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::_RunEventLoop() ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:170 (chip-tool+0x98a147) project-chip#4 chip::DeviceLayer::PlatformManager::RunEventLoop() ../../src/include/platform/PlatformManager.h:362 (chip-tool+0x988f75) project-chip#5 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::EventLoopTaskMain(void*) ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:205 (chip-tool+0x98a87c) Thread T5 (tid=63013, running) created by main thread at: #0 pthread_create ../../../../src/libsanitizer/tsan/tsan_interceptors_posix.cpp:969 (libtsan.so.0+0x5ad75) #1 chip::DeviceLayer::Internal::GenericPlatformManagerImpl_POSIX<chip::DeviceLayer::PlatformManagerImpl>::_StartEventLoopTask() ../../src/include/platform/internal/GenericPlatformManagerImpl_POSIX.ipp:231 (chip-tool+0x98a40a) project-chip#2 chip::DeviceLayer::PlatformManager::StartEventLoopTask() ../../src/include/platform/PlatformManager.h:375 (chip-tool+0xaacca2) project-chip#3 chip::Controller::DeviceControllerFactory::ServiceEvents() ../../src/controller/CHIPDeviceControllerFactory.cpp:331 (chip-tool+0xab0417) project-chip#4 CHIPCommand::StartWaiting(std::chrono::duration<unsigned int, std::ratio<1l, 1000l> >) ../../examples/chip-tool/commands/common/CHIPCommand.cpp:403 (chip-tool+0x83e353) project-chip#5 CHIPCommand::Run() ../../examples/chip-tool/commands/common/CHIPCommand.cpp:187 (chip-tool+0x83c839) project-chip#6 Commands::RunCommand(int, char**, bool) ../../examples/chip-tool/commands/common/Commands.cpp:147 (chip-tool+0x85d4f7) project-chip#7 Commands::Run(int, char**) ../../examples/chip-tool/commands/common/Commands.cpp:51 (chip-tool+0x85c288) project-chip#8 main <null> (chip-tool+0x569c0a) SUMMARY: ThreadSanitizer: data race ../../examples/chip-tool/commands/interactive/InteractiveCommands.cpp:127 in InteractiveStartCommand::ParseCommand(char*) ==================

* Fix ThreadSanitizer failure in controller factory. The failure looks like this: WARNING: ThreadSanitizer: race on NSMutableArray (pid=11619) Read-only access of NSMutableArray at 0x7b0c0005f5b0 by thread T3: #0 -[__NSArrayM countByEnumeratingWithState:objects:count:] <null>:2 (CoreFoundation:x86_64+0x4a338) #1 -[MTRDeviceControllerFactory(InternalMethods) operationalInstanceAdded:] MTRDeviceControllerFactory.mm:855 (Matter:x86_64+0x1fd2a) project-chip#2 MTROperationalBrowser::OnBrowse(_DNSServiceRef_t*, unsigned int, unsigned int, int, char const*, char const*, char const*, void*) MTROperationalBrowser.mm:100 (Matter:x86_64+0x20ee63c) project-chip#3 handle_browse_response <null>:2 (libsystem_dnssd.dylib:x86_64+0x3733) project-chip#4 _dispatch_client_callout <null>:2 (libdispatch.dylib:x86_64+0x3316) Previous modifying access of NSMutableArray at 0x7b0c0005f5b0 by main thread: #0 -[__NSArrayM addObject:] <null>:2 (CoreFoundation:x86_64+0x2457a) #1 -[MTRDeviceControllerFactory createController] MTRDeviceControllerFactory.mm:719 (Matter:x86_64+0x1cee3) project-chip#2 -[MTRDeviceControllerFactory createControllerOnExistingFabric:error:] MTRDeviceControllerFactory.mm:534 (Matter:x86_64+0x19792) The basic problem is that we are in the middle of adding an object to _controllers on the API consumer thread when on the Matter thread we get our browse notification. The changes here don't aim to lock around all access to _controllers, but just to make sure that our mutations of it can't race with the access on the Matter thread. More coarse locking would need to be done very carefully, given the amount of dispath_sync to the Matter thread we have going on. * Address review comments.

WARNING: ThreadSanitizer: race on NSMutableDictionary (pid=72050) Modifying access of NSMutableDictionary at 0x7b0800149020 by thread T7: #0 -[__NSDictionaryM setObject:forKey:] <null>:2 (CoreFoundation:x86_64+0x40d4e) #1 -[MTRXPCListenerSample listener:shouldAcceptNewConnection:] MTRXPCListenerSampleTests.m:116 (MatterTests:x86_64+0x48437b) project-chip#2 service_connection_handler_make_connection <null>:2 (Foundation:x86_64+0xdea93) Previous modifying access of NSMutableDictionary at 0x7b0800149020 by thread T4: #0 -[__NSDictionaryM removeObjectForKey:] <null>:2 (CoreFoundation:x86_64+0x6cd6d) #1 __59-[MTRXPCListenerSample listener:shouldAcceptNewConnection:]_block_invoke MTRXPCListenerSampleTests.m:119 (MatterTests:x86_64+0x484630)

…ist". (project-chip#29666) The typical failure there looks like this: ==29620==ERROR: LeakSanitizer: detected memory leaks Direct leak of 88 byte(s) in 1 object(s) allocated from: #0 0x106396e12 in calloc+0xa2 (libclang_rt.asan_osx_dynamic.dylib:x86_64+0x51e12) #1 0x7ff800dc9789 in map_images_nolock+0x24b (libobjc.A.dylib:x86_64h+0x1789) project-chip#2 0x7ff800dc94db in map_images+0x42 (libobjc.A.dylib:x86_64h+0x14db) project-chip#3 0x113d721fa in invocation function for block in dyld4::RuntimeState::setObjCNotifiers(void (*)(unsigned int, char const* const*, mach_header const* const*), void (*)(char const*, mach_header const*), void (*)(char const*, mach_header const*))+0x112 (dyld:x86_64+0xf1fa) project-chip#4 0x113d6d6c8 in dyld4::RuntimeState::withLoadersReadLock(void () block_pointer)+0x28 (dyld:x86_64+0xa6c8) project-chip#5 0x113d720e1 in dyld4::RuntimeState::setObjCNotifiers(void (*)(unsigned int, char const* const*, mach_header const* const*), void (*)(char const*, mach_header const*), void (*)(char const*, mach_header const*))+0x51 (dyld:x86_64+0xf0e1) project-chip#6 0x113d85d44 in dyld4::APIs::_dyld_objc_notify_register(void (*)(unsigned int, char const* const*, mach_header const* const*), void (*)(char const*, mach_header const*), void (*)(char const*, mach_header const*))+0x4e (dyld:x86_64+0x22d44) project-chip#7 0x7ff800dc9343 in _objc_init+0x4fe (libobjc.A.dylib:x86_64h+0x1343) project-chip#8 0x7ff800d83992 in _os_object_init+0xc (libdispatch.dylib:x86_64+0x2992) project-chip#9 0x7ff800d911b7 in libdispatch_init+0x136 (libdispatch.dylib:x86_64+0x101b7) project-chip#10 0x7ff80bd34894 in libSystem_initializer+0xed (libSystem.B.dylib:x86_64+0x1894) project-chip#11 0x113d77e4e in invocation function for block in dyld4::Loader::findAndRunAllInitializers(dyld4::RuntimeState&) const+0xb5 (dyld:x86_64+0x14e4e) project-chip#12 0x113d9eaac in invocation function for block in dyld3::MachOAnalyzer::forEachInitializer(Diagnostics&, dyld3::MachOAnalyzer::VMAddrConverter const&, void (unsigned int) block_pointer, void const*) const+0xf1 (dyld:x86_64+0x3baac) project-chip#13 0x113d95e25 in invocation function for block in dyld3::MachOFile::forEachSection(void (dyld3::MachOFile::SectionInfo const&, bool, bool&) block_pointer) const+0x22c (dyld:x86_64+0x32e25) project-chip#14 0x113d64db2 in dyld3::MachOFile::forEachLoadCommand(Diagnostics&, void (load_command const*, bool&) block_pointer) const+0x80 (dyld:x86_64+0x1db2) project-chip#15 0x113d95bb6 in dyld3::MachOFile::forEachSection(void (dyld3::MachOFile::SectionInfo const&, bool, bool&) block_pointer) const+0xb2 (dyld:x86_64+0x32bb6) project-chip#16 0x113d9e603 in dyld3::MachOAnalyzer::forEachInitializer(Diagnostics&, dyld3::MachOAnalyzer::VMAddrConverter const&, void (unsigned int) block_pointer, void const*) const+0x1d1 (dyld:x86_64+0x3b603) project-chip#17 0x113d77d81 in dyld4::Loader::findAndRunAllInitializers(dyld4::RuntimeState&) const+0x8f (dyld:x86_64+0x14d81) project-chip#18 0x113d7e659 in dyld4::PrebuiltLoader::runInitializers(dyld4::RuntimeState&) const+0x1d (dyld:x86_64+0x1b659) project-chip#19 0x113d8b76d in dyld4::APIs::runAllInitializersForMain()+0x25 (dyld:x86_64+0x2876d) project-chip#20 0x113d6938c in dyld4::prepare(dyld4::APIs&, dyld3::MachOAnalyzer const*)+0xd72 (dyld:x86_64+0x638c) project-chip#21 0x113d684e3 in start+0x183 (dyld:x86_64+0x54e3)

jepenven-silabs and others added 6 commits October 7, 2021 09:54

Update Message Header with spec

1a15085

Fix Unit Tests

32e839c

Fix style

28afa19

[msg] Add unit tests for PacketHeader spec compliance.

12d36ff

[msg] Reorder fields to match spec. Improve unit tests.

b98cc3c

[crypto] Correct NONCE / IV generation according to spec.

19173ba

jepenven-silabs force-pushed the remove_EncryptedFlags branch from c1ca671 to d49af9a Compare October 15, 2021 19:50

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

[msg] Add unit tests for PacketHeader spec compliance. #1

[msg] Add unit tests for PacketHeader spec compliance. #1

turon commented Oct 8, 2021

[msg] Add unit tests for PacketHeader spec compliance. #1

Are you sure you want to change the base?

[msg] Add unit tests for PacketHeader spec compliance. #1

Conversation

turon commented Oct 8, 2021