Skip to content

Commit

Permalink
Remove racy access to readline (project-chip#20466)
Browse files Browse the repository at this point in the history 
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*)
==================
  • Loading branch information
@mspang
mspang authored Jul 9, 2022
1 parent 92971a1 commit 5745a46
Showing 1 changed file with 0 additions and 11 deletions.
11 changes: 0 additions & 11 deletions examples/chip-tool/commands/interactive/InteractiveCommands.cpp
View file
Original file line number Diff line number Diff line change
Expand Up @@ -30,8 +30,6 @@ constexpr const char * kInteractiveModeStopCommand = "quit()";

namespace {

bool gIsCommandRunning = false;

void ClearLine()
{
printf("\r\x1B[0J"); // Move cursor to the beginning of the line and clear from cursor to end of the screen
Expand All @@ -42,11 +40,6 @@ void ENFORCE_FORMAT(3, 0) LoggingCallback(const char * module, uint8_t category,
ClearLine();
chip::Logging::Platform::LogV(module, category, msg, args);
ClearLine();

if (gIsCommandRunning == false)
{
rl_forced_update_display();
}
}
} // namespace

Expand Down Expand Up @@ -110,9 +103,7 @@ bool InteractiveStartCommand::ParseCommand(char * command)
{
if (argsCount == kInteractiveModeArgumentsMaxLength)
{
gIsCommandRunning = true;
ChipLogError(chipTool, "Too many arguments. Ignoring.");
gIsCommandRunning = false;
return true;
}

Expand All @@ -122,9 +113,7 @@ bool InteractiveStartCommand::ParseCommand(char * command)
}

ClearLine();
gIsCommandRunning = true;
mHandler->RunInteractive(argsCount, args);
gIsCommandRunning = false;

// Do not delete arg[0]
while (--argsCount)
Expand Down

0 comments on commit 5745a46

Please sign in to comment.