OCVSMD: Daemon Crashes When Encountering Timeout During Register Access

phihalip · July 18, 2025, 7:00pm

We seem to have found a potential flaw in the OCVSMD daemon cleanup code that causes it to crash when we probe a node’s register and receive a timeout error.

The specific scenario we’ve encountered this is when the we try to probe the node’s status register to get the status of a software update WHILE the node is updating, which prevents it from responding in time and causes the daemon reach timeout while waiting for a response. Some time afterwards, the OCVSMD code tries to access an object that was prematurely cleaned up due to the timeout and causes the daemon to crash.

Here’s the full backtrace we pulled from the crashed daemon using GDB:

#0  0x0000007ff7c09f14 in __libc_send (fd=9, buf=0x7fffffe0e0, len=8, flags=64) at ../sysdeps/unix/sysv/linux/send.c:28
#1  0x0000005555688d74 in operator() (__closure=<optimized out>) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/io/io.hpp:57
#2  ocvsmd::platform::posixSyscallError<ocvsmd::common::ipc::pipe::SocketBase::send(const ocvsmd::common::ipc::pipe::SocketBase::IoState&, ocvsmd::common::io::SocketBuffer&) const::<lambda()> > (call=...) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/include/ocvsmd/platform/posix_utils.hpp:21
#3  ocvsmd::common::ipc::pipe::SocketBase::send (this=0x555578f6c8, io_state=..., sock_buff=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/pipe/socket_base.cpp:69
#4  0x000000555567f000 in ocvsmd::common::ipc::pipe::SocketServer::send (this=<optimized out>, client_id=<optimized out>, sock_buff=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/pipe/socket_server.cpp:122
#5  0x0000005555683fd0 in operator()<cetl::pf20::span<const cetl::pf17::byte, 18446744073709551615> > (payload=..., __closure=<optimized out>)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/server_router.cpp:298
#6  ocvsmd::common::tryPerformOnSerialized<ocvsmd::common::ipc::Route_0_2, ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::onGatewayDisposal(const ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::Endpoint&, ocvsmd::sdk::OptError)::<lambda(auto:23)> > (action=..., message=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/dsdl_helpers.hpp:52
#7  ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::onGatewayDisposal (completion_opt_error=..., completion_opt_error=..., endpoint=..., 
    this=0x5555783e10) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/server_router.cpp:295
#8  operator() (__closure=0x7fffffe2d8) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/server_router.cpp:132
#9  ocvsmd::common::performWithoutThrowing<>(struct {...} &&) (action=...) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/common_helpers.hpp:40
#10 0x00000055556841c0 in ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl::~GatewayImpl (this=0x555578ff10, 
    __in_chrg=<optimized out>) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/common/ipc/server_router.cpp:125
#11 __gnu_cxx::new_allocator<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl>::destroy<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl> (__p=0x555578ff10, this=0x555578ff10)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/ext/new_allocator.h:168
#12 std::allocator_traits<std::allocator<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl> >::destroy<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl> (__p=0x555578ff10, __a=...)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/alloc_traits.h:535
#13 std::_Sp_counted_ptr_inplace<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl, std::allocator<ocvsmd::common::ipc::(anonymous namespace)::ServerRouterImpl::GatewayImpl>, (__gnu_cxx::_Lock_policy)2>::_M_dispose (this=0x555578ff00)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr_base.h:528
#14 0x0000005555588db0 in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release (this=0x555578ff00)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr_base.h:168
#15 0x0000005555588db0 in std::_Sp_counted_base<(__gnu_cxx::_Lock_policy)2>::_M_release (this=0x555578af00)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr_base.h:168
#16 0x0000005555639c34 in std::__shared_count<(__gnu_cxx::_Lock_policy)2>::~__shared_count (this=0x5555788368, __in_chrg=<optimized out>)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr_base.h:705
#17 std::__shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm, (__gnu_cxx::_Lock_policy)2>::~__shared_ptr
    (this=0x5555788360, __in_chrg=<optimized out>)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr_base.h:1154
#18 std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm>::~shared_ptr (this=0x5555788360, 
    __in_chrg=<optimized out>)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/shared_ptr.h:122
#19 std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >::~pair (
    this=0x5555788358, __in_chrg=<optimized out>)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/stl_pair.h:211
#20 __gnu_cxx::new_allocator<std::__detail::_Hash_node<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, false> >::destroy<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > > (__p=0x5555788358, this=<optimized out>)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/ext/new_allocator.h:168
#21 std::allocator_traits<std::allocator<std::__detail::_Hash_node<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, false> > >::destroy<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > > (__p=0x5555788358, __a=...)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/alloc_traits.h:535
#22 std::__detail::_Hashtable_alloc<std::allocator<std::__detail::_Hash_node<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, false> > >::_M_deallocate_node (this=0x55557887d8, __n=0x5555788350)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/hashtable_policy.h:1894
#23 std::_Hashtable<unsigned long, std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, std::allocator<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > >, std::__detail::_Select1st, std::equal_to<unsigned long>, std::hash<unsigned long>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::_M_erase (__n=0x5555788350, 
    __prev_n=<optimized out>, __bkt=<optimized out>, this=0x55557887d8)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/hashtable.h:2183
#24 std::_Hashtable<unsigned long, std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, std::allocator<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > >, std::__detail::_Select1st, std::equal_to<unsigned long>, std::hash<unsigned long>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::_M_erase (
    __k=<synthetic pointer>: <optimized out>, this=0x55557887d8)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/hashtable.h:2209
#25 std::_Hashtable<unsigned long, std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> >, std::allocator<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > >, std::__detail::_Select1st, std::equal_to<unsigned long>, std::hash<unsigned long>, std::__detail::_Mod_range_hashing, std::__detail::_Default_ranged_hash, std::__detail::_Prime_rehash_policy, std::__detail::_Hashtable_traits<false, false, true> >::erase (
    __k=<synthetic pointer>: <optimized out>, this=0x55557887d8)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/hashtable.h:938
#26 std::unordered_map<unsigned long, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm>, std::hash<unsigned long>, std::equal_to<unsigned long>, std::allocator<std::pair<unsigned long const, std::shared_ptr<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm> > > >::erase (__x=<synthetic pointer>: <optimized out>, this=0x55557887d8)
    at /home/phihalip/brazil-pkg-cache/packages/AdnToolchain-S32G-A53-Yocto-Minimal/AdnToolchain-S32G-A53-Yocto-Minimal-39.0.102.0/AL2_x86_64/DEV.STD.PTHREAD/build/include/toolchain/sdkroot/sysroots/cortexa53-crypto-adn-linux/usr/include/c++/11.4.0/bits/unordered_map.h:763
#27 ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::releaseFsmBy (fsm_id=<optimized out>, this=0x55557887b0)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:379
#28 ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::complete (this=this@entry=0x555578af10, 
    completion_opt_error=...) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:365
#29 0x000000555563acfc in ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::releaseNodeContext (
    node_id=<optimized out>, this=0x555578af10) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:351
#30 ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::releaseNodeContext (node_id=<optimized out>, 
    this=0x555578af10) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:346
#31 ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::startCyRegAccessRpcCallFor (this=this@entry=0x555578af10, 
    node_id=<optimized out>, node_id@entry=23, node_cnxt=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:293
#32 0x000000555563a380 in ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::handleNodeResponse (this=0x555578af10, 
    node_id=<optimized out>, result=...) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:327
#33 0x000000555564ac7c in operator()<libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::Callback::Arg> (arg=..., __closure=<optimized out>)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/svc/node/access_registers_service.cpp:274
#34 cetl::pmr::detail::functor_handler<ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::startCyRegAccessRpcCallFor(ocvsmd::sdk::CyphalNodeId, ocvsmd::daemon::engine::svc::node::(anonymous namespace)::AccessRegistersServiceImpl::Fsm::NodeContext&)::<lambda(const auto:35&)>, void, const libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::Callback::Arg&>::operator() (args#0=..., this=<optimized out>)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/cetl/include/cetl/pmr/function.hpp:65
#35 cetl::pmr::function<void (libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::Callback::Arg const&), 64ul, void>::operator()(libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::Callback::Arg const&) const (args#0=..., this=0x7fffffea70)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/cetl/include/cetl/pmr/function.hpp:270
#36 libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::acceptResult (this=0x5555788bd0, result=..., approx_now=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/presentation/response_promise.hpp:207
#37 0x000000555564b244 in libcyphal::presentation::ResponsePromiseBase<uavcan::_register::Access::Response_1_0, cetl::pf17::variant<libcyphal::presentation::ResponsePromiseExpired, libcyphal::MemoryError, nunavut::support::Error> >::onResponseTimeout (this=<optimized out>, deadline=..., approx_now=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/presentation/response_promise.hpp:242
#38 0x000000555563bf58 in libcyphal::presentation::detail::SharedClient::onNearestDeadline (approx_now=..., this=0x5555790850)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/presentation/client_impl.hpp:55
#39 libcyphal::presentation::detail::SharedClient::SharedClient(libcyphal::presentation::detail::IPresentationDelegate&, libcyphal::IExecutor&, std::unique_ptr<libcyphal::transport::IRequestTxSession, cetl::pmr::PmrInterfaceDeleter<libcyphal::transport::IRequestTxSession> >, std::unique_ptr<libcyphal::transport::IResponseRxSession, cetl::pmr::PmrInterfaceDeleter<libcyphal::transport::IResponseRxSession> >)::{lambda(auto:1 const&)#2}::operator()<libcyphal::IExecutor::Callback::Arg>(libcyphal::IExecutor::Callback::Arg const&) const (arg=..., __closure=<optimized out>)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/presentation/client_impl.hpp:166
#40 cetl::pmr::detail::functor_handler<libcyphal::presentation::detail::SharedClient::SharedClient(libcyphal::presentation::detail::IPresentationDelegate&, libcyphal::IExecutor&, std::unique_ptr<libcyphal::transport::IRequestTxSession, cetl::pmr::PmrInterfaceDeleter<libcyphal::transport::IRequestTxSession> >, std::unique_ptr<libcyphal::transport::IResponseRxSession, cetl::pmr::PmrInterfaceDeleter<libcyphal::transport::IResponseRxSession> >)::{lambda(auto:1 const&)#2}, void, libcyphal::IExecutor::Callback::Arg const&>::operator()(libcyphal::IExecutor::Callback::Arg const&) (this=<optimized out>, args#0=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/cetl/include/cetl/pmr/function.hpp:65
#41 0x00000055555f8f10 in cetl::pmr::function<void (libcyphal::IExecutor::Callback::Arg const&), 64ul, void>::operator()(libcyphal::IExecutor::Callback::Arg const&) const (args#0=..., this=0x5555790a30) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/cetl/include/cetl/pmr/function.hpp:270
#42 libcyphal::platform::SingleThreadedExecutor::CallbackNode::operator() (arg=..., this=0x5555790a00)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/platform/single_threaded_executor.hpp:164
#43 libcyphal::platform::SingleThreadedExecutor::spinOnce (this=0x7fffffef40)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/submodules/libcyphal/include/libcyphal/platform/single_threaded_executor.hpp:79
#44 ocvsmd::daemon::engine::Engine::runWhile(std::function<bool ()> const&) (this=this@entry=0x7fffffef20, loop_predicate=...)
    at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/engine/engine.cpp:172
#45 0x00000055555746f0 in main (argc=3, argv=0x7ffffffb08) at /local/home/phihalip/OCVSMD/src/AdnExOcvsmd/src/daemon/main.cpp:383

phihalip · July 18, 2025, 7:04pm

(post deleted by author)

phihalip · July 18, 2025, 7:11pm

Here’s the server logs we found after the daemon had crashed (I removed about 50 entries where we accessed a register so that the logs would fit in the character limit):

[2025-07-15 20:31:16.571] [784] [] [info] --------------------------
[2025-07-15 20:31:16.571] [784] [] [info] OCVSMD started (ver='0.1').
[2025-07-15 20:31:16.573] [784] [engine] [trace] Initializing engine...
[2025-07-15 20:31:16.573] [784] [io] [trace] Attempting to create UDP transport (ifaces=[], mtu=64)…
[2025-07-15 20:31:16.573] [784] [io] [trace] Attempting to create CAN transport (ifaces=[can_stab_a,], mtu=64)…
[2025-07-15 20:31:16.573] [784] [io] [debug] Created CAN transport (ifaces=1).
[2025-07-15 20:31:16.573] [784] [engine] [info] Setting Cyphal node ID to 24.
[2025-07-15 20:31:16.576] [784] [engine] [trace] FileProviderImpl().
[2025-07-15 20:31:16.576] [784] [engine] [debug] There are 1 file server roots.
[2025-07-15 20:31:16.576] [784] [engine] [warning]    0 '/bulk/software-install/tmp/binfiles' → ❌ not found!
[2025-07-15 20:31:16.576] [784] [engine] [debug] Starting with IPC connection 'unix-abstract:org.opencyphal.ocvsmd.ipc.CAN-can_stab_a-24'...
[2025-07-15 20:31:16.576] [784] [ipc] [trace] Registering 'ocvsmd.svc.node.exec_cmd' service (id=0x5FAE48D0F51BC328).
[2025-07-15 20:31:16.576] [784] [ipc] [trace] Registering 'ocvsmd.svc.node.list_registers' service (id=0xAC777427FBA8DF8).
[2025-07-15 20:31:16.576] [784] [ipc] [trace] Registering 'ocvsmd.svc.node.access_registers' service (id=0x80FEF6131F8355B9).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.relay.raw_publisher' service (id=0x105D79E48A235E0C).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.relay.raw_rpc_client' service (id=0xB0714D553D4D8C84).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.relay.raw_subscriber' service (id=0x30609D5A9C3662F).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.file_server.list_roots' service (id=0xC028915FECCB414).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.file_server.pop_root' service (id=0xEB84334F18A99FEF).
[2025-07-15 20:31:16.577] [784] [ipc] [trace] Registering 'ocvsmd.svc.file_server.push_root' service (id=0x6A77091C040493A1).
[2025-07-15 20:31:16.577] [784] [engine] [debug] Engine is initialized.
[2025-07-15 20:31:16.591] [784] [] [debug] New client connection (id=1, addr='unix:').
[2025-07-15 20:31:16.592] [784] [ipc] [trace] ClientContext(fd=9, id=1).
[2025-07-15 20:31:16.592] [784] [ipc] [debug] Pipe is connected (cl=1).
[2025-07-15 20:31:16.592] [784] [ipc] [debug] Route connect request (cl=1, ver='0.1', err_code=0).
[2025-07-15 20:31:16.592] [784] [ipc] [trace] Gateway(cl=1, tag=0).
[2025-07-15 20:31:16.592] [784] [ipc] [debug] Route Ch Msg (cl=1, tag=0, seq=0, srv=0x5FAE48D0F51BC328).
[2025-07-15 20:31:16.592] [784] [engine] [debug] New 'ocvsmd.svc.node.exec_cmd' service channel (fsm=0).
[2025-07-15 20:31:16.592] [784] [engine] [trace] ExecCmdSvc::Fsm (id=0).
[2025-07-15 20:31:16.592] [784] [ipc] [debug] Route Ch End (cl=1, tag=0, keep_alive=true, err=null).
[2025-07-15 20:31:16.592] [784] [engine] [debug] ExecCmdSvc::handleEvent(Completed(alive=true)) (fsm_id=0).
[2025-07-15 20:31:16.597] [784] [engine] [debug] ExecCmdSvc: RPC promise success from node 23 (status=0, fsm_id=0).
[2025-07-15 20:31:16.597] [784] [ipc] [trace] ~Gateway(cl=1, tag=0, err=null).
[2025-07-15 20:31:16.598] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:31:16.598] [784] [ipc] [debug] End of client stream - closing connection (id=1, fd=9).
[2025-07-15 20:31:16.598] [784] [ipc] [debug] Pipe is disconnected (cl=1).
[2025-07-15 20:31:16.616] [784] [] [debug] New client connection (id=2, addr='unix:').
[2025-07-15 20:31:16.617] [784] [ipc] [trace] ClientContext(fd=9, id=2).
[2025-07-15 20:31:16.617] [784] [ipc] [debug] Pipe is connected (cl=2).
[2025-07-15 20:31:16.617] [784] [ipc] [debug] Route connect request (cl=2, ver='0.1', err_code=0).
[2025-07-15 20:31:16.617] [784] [ipc] [trace] Gateway(cl=2, tag=0).
[2025-07-15 20:31:16.617] [784] [ipc] [debug] Route Ch Msg (cl=2, tag=0, seq=0, srv=0x5FAE48D0F51BC328).
[2025-07-15 20:31:16.617] [784] [engine] [debug] New 'ocvsmd.svc.node.exec_cmd' service channel (fsm=1).
[2025-07-15 20:31:16.617] [784] [engine] [trace] ExecCmdSvc::Fsm (id=1).
[2025-07-15 20:31:16.617] [784] [ipc] [debug] Route Ch End (cl=2, tag=0, keep_alive=true, err=null).
[2025-07-15 20:31:16.617] [784] [engine] [debug] ExecCmdSvc::handleEvent(Completed(alive=true)) (fsm_id=1).
[2025-07-15 20:31:16.618] [784] [engine] [debug] ExecCmdSvc: RPC promise success from node 23 (status=0, fsm_id=1).
[2025-07-15 20:31:16.618] [784] [ipc] [trace] ~Gateway(cl=2, tag=0, err=null).
[2025-07-15 20:31:16.619] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:31:16.619] [784] [ipc] [debug] End of client stream - closing connection (id=2, fd=9).
[2025-07-15 20:31:16.619] [784] [ipc] [debug] Pipe is disconnected (cl=2).
[2025-07-15 20:33:44.344] [784] [] [debug] New client connection (id=3, addr='unix:').
[2025-07-15 20:33:44.344] [784] [ipc] [trace] ClientContext(fd=9, id=3).
[2025-07-15 20:33:44.344] [784] [ipc] [debug] Pipe is connected (cl=3).
[2025-07-15 20:33:44.344] [784] [ipc] [debug] Route connect request (cl=3, ver='0.1', err_code=0).
[2025-07-15 20:33:44.345] [784] [ipc] [trace] Gateway(cl=3, tag=0).
[2025-07-15 20:33:44.345] [784] [ipc] [debug] Route Ch Msg (cl=3, tag=0, seq=0, srv=0x105D79E48A235E0C).
[2025-07-15 20:33:44.345] [784] [engine] [debug] New 'ocvsmd.svc.relay.raw_publisher' service channel (fsm=0).
[2025-07-15 20:33:44.345] [784] [engine] [trace] RawPublisherSvc::Fsm (id=0).
[2025-07-15 20:33:44.345] [784] [ipc] [trace] Route Ch Msg (cl=3, tag=0, seq=1).
[2025-07-15 20:33:44.345] [784] [engine] [trace] RawPublisherSvc::handleEvent(Input).
[2025-07-15 20:33:44.345] [784] [engine] [trace] RawPublisherSvc::handleInputEvent config (fsm_id=0).
[2025-07-15 20:33:44.345] [784] [engine] [debug] RawPublisherSvc::handleInputEvent: setPriority=4 (fsm_id=0).
[2025-07-15 20:33:44.345] [784] [ipc] [trace] Route Ch Msg (cl=3, tag=0, seq=2).
[2025-07-15 20:33:44.345] [784] [engine] [trace] RawPublisherSvc::handleEvent(Input).
[2025-07-15 20:33:44.345] [784] [engine] [trace] RawPublisherSvc::handleInputEvent publish (fsm_id=0).
[2025-07-15 20:33:44.345] [784] [ipc] [debug] Route Ch End (cl=3, tag=0, keep_alive=false, err=null).
[2025-07-15 20:33:44.346] [784] [engine] [debug] RawPublisherSvc::handleEvent(Completed(alive=false)) (fsm_id=0).
[2025-07-15 20:33:44.346] [784] [ipc] [trace] ~Gateway(cl=3, tag=0, err=null).
[2025-07-15 20:33:44.346] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=9).
[2025-07-15 20:33:44.346] [784] [ipc] [debug] End of client stream - closing connection (id=3, fd=9).
[2025-07-15 20:33:44.346] [784] [ipc] [debug] Pipe is disconnected (cl=3).
[2025-07-15 20:33:44.349] [784] [] [debug] New client connection (id=4, addr='unix:').
[2025-07-15 20:33:44.350] [784] [ipc] [trace] ClientContext(fd=9, id=4).
[2025-07-15 20:33:44.350] [784] [ipc] [debug] Pipe is connected (cl=4).
[2025-07-15 20:33:44.350] [784] [ipc] [debug] Route connect request (cl=4, ver='0.1', err_code=0).
[2025-07-15 20:33:44.350] [784] [ipc] [trace] Gateway(cl=4, tag=0).
[2025-07-15 20:33:44.350] [784] [ipc] [debug] Route Ch Msg (cl=4, tag=0, seq=0, srv=0x30609D5A9C3662F).
[2025-07-15 20:33:44.350] [784] [engine] [debug] New 'ocvsmd.svc.relay.raw_subscriber' service channel (fsm=0).
[2025-07-15 20:33:44.350] [784] [engine] [trace] RawSubscriberSvc::Fsm (id=0).
[2025-07-15 20:33:46.352] [784] [ipc] [debug] Route Ch End (cl=4, tag=0, keep_alive=false, err=null).
[2025-07-15 20:33:46.352] [784] [engine] [debug] RawSubscriberSvc::handleEvent(Completed(alive=false)) (fsm_id=0).
[2025-07-15 20:33:46.352] [784] [engine] [warning] RawSubscriberSvc: canceling processing (fsm_id=0).
[2025-07-15 20:33:46.352] [784] [ipc] [trace] ~Gateway(cl=4, tag=0, err=null).
[2025-07-15 20:33:46.352] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=9).
[2025-07-15 20:33:46.352] [784] [ipc] [debug] End of client stream - closing connection (id=4, fd=9).
[2025-07-15 20:33:46.352] [784] [ipc] [debug] Pipe is disconnected (cl=4).
[2025-07-15 20:33:46.365] [784] [] [debug] New client connection (id=5, addr='unix:').
[2025-07-15 20:33:46.365] [784] [ipc] [trace] ClientContext(fd=9, id=5).
[2025-07-15 20:33:46.365] [784] [ipc] [debug] Pipe is connected (cl=5).
[2025-07-15 20:33:46.365] [784] [ipc] [debug] Route connect request (cl=5, ver='0.1', err_code=0).
[2025-07-15 20:33:46.366] [784] [ipc] [trace] Gateway(cl=5, tag=0).
[2025-07-15 20:33:46.366] [784] [ipc] [debug] Route Ch Msg (cl=5, tag=0, seq=0, srv=0x30609D5A9C3662F).
[2025-07-15 20:33:46.366] [784] [engine] [debug] New 'ocvsmd.svc.relay.raw_subscriber' service channel (fsm=1).
[2025-07-15 20:33:46.366] [784] [engine] [trace] RawSubscriberSvc::Fsm (id=1).
[2025-07-15 20:33:46.371] [784] [] [debug] New client connection (id=6, addr='unix:').
[2025-07-15 20:33:46.371] [784] [ipc] [trace] ClientContext(fd=11, id=6).
[2025-07-15 20:33:46.371] [784] [ipc] [debug] Pipe is connected (cl=6).
[2025-07-15 20:33:46.371] [784] [ipc] [debug] Route connect request (cl=6, ver='0.1', err_code=0).
[2025-07-15 20:33:46.371] [784] [ipc] [trace] Gateway(cl=6, tag=0).
[2025-07-15 20:33:46.371] [784] [ipc] [debug] Route Ch Msg (cl=6, tag=0, seq=0, srv=0x105D79E48A235E0C).
[2025-07-15 20:33:46.372] [784] [engine] [debug] New 'ocvsmd.svc.relay.raw_publisher' service channel (fsm=1).
[2025-07-15 20:33:46.372] [784] [engine] [trace] RawPublisherSvc::Fsm (id=1).
[2025-07-15 20:33:46.372] [784] [ipc] [trace] Route Ch Msg (cl=6, tag=0, seq=1).
[2025-07-15 20:33:46.372] [784] [engine] [trace] RawPublisherSvc::handleEvent(Input).
[2025-07-15 20:33:46.372] [784] [engine] [trace] RawPublisherSvc::handleInputEvent config (fsm_id=1).
[2025-07-15 20:33:46.372] [784] [engine] [debug] RawPublisherSvc::handleInputEvent: setPriority=4 (fsm_id=1).
[2025-07-15 20:33:46.372] [784] [ipc] [trace] Route Ch Msg (cl=6, tag=0, seq=2).
[2025-07-15 20:33:46.372] [784] [engine] [trace] RawPublisherSvc::handleEvent(Input).
[2025-07-15 20:33:46.372] [784] [engine] [trace] RawPublisherSvc::handleInputEvent publish (fsm_id=1).
[2025-07-15 20:33:46.372] [784] [ipc] [debug] Route Ch End (cl=6, tag=0, keep_alive=false, err=null).
[2025-07-15 20:33:46.372] [784] [engine] [debug] RawPublisherSvc::handleEvent(Completed(alive=false)) (fsm_id=1).
[2025-07-15 20:33:46.372] [784] [ipc] [trace] ~Gateway(cl=6, tag=0, err=null).
[2025-07-15 20:33:46.372] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=11).
[2025-07-15 20:33:46.372] [784] [ipc] [debug] End of client stream - closing connection (id=6, fd=11).
[2025-07-15 20:33:46.372] [784] [ipc] [debug] Pipe is disconnected (cl=6).
[2025-07-15 20:33:46.375] [784] [ipc] [debug] Route Ch End (cl=5, tag=0, keep_alive=false, err=null).
[2025-07-15 20:33:46.375] [784] [engine] [debug] RawSubscriberSvc::handleEvent(Completed(alive=false)) (fsm_id=1).
[2025-07-15 20:33:46.375] [784] [engine] [warning] RawSubscriberSvc: canceling processing (fsm_id=1).
[2025-07-15 20:33:46.375] [784] [ipc] [trace] ~Gateway(cl=5, tag=0, err=null).
[2025-07-15 20:33:46.375] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=9).
[2025-07-15 20:33:46.375] [784] [ipc] [debug] End of client stream - closing connection (id=5, fd=9).
[2025-07-15 20:33:46.375] [784] [ipc] [debug] Pipe is disconnected (cl=5).
[2025-07-15 20:33:46.389] [784] [] [debug] New client connection (id=7, addr='unix:').
[2025-07-15 20:33:46.389] [784] [ipc] [trace] ClientContext(fd=9, id=7).
[2025-07-15 20:33:46.389] [784] [ipc] [debug] Pipe is connected (cl=7).
[2025-07-15 20:33:46.390] [784] [ipc] [debug] Route connect request (cl=7, ver='0.1', err_code=0).
[2025-07-15 20:33:46.390] [784] [ipc] [trace] Gateway(cl=7, tag=0).
[2025-07-15 20:33:46.390] [784] [ipc] [debug] Route Ch Msg (cl=7, tag=0, seq=0, srv=0xB0714D553D4D8C84).
[2025-07-15 20:33:46.390] [784] [engine] [debug] New 'ocvsmd.svc.relay.raw_rpc_client' service channel (fsm=0).
[2025-07-15 20:33:46.390] [784] [engine] [trace] RawRpcClientSvc::Fsm (id=0).
[2025-07-15 20:33:46.391] [784] [engine] [trace] RawRpcClientSvc::start (node_id=23, svc_id=430, fsm_id=0).
[2025-07-15 20:33:46.391] [784] [ipc] [trace] Route Ch Msg (cl=7, tag=0, seq=1).
[2025-07-15 20:33:46.391] [784] [engine] [trace] RawRpcClientSvc::handleEvent(Input).
[2025-07-15 20:33:46.391] [784] [engine] [trace] RawRpcClientSvc::handleInputEvent config (fsm_id=0).
[2025-07-15 20:33:46.391] [784] [engine] [debug] RawRpcClientSvc::handleInputEvent: setPriority=5 (fsm_id=0).
[2025-07-15 20:33:46.391] [784] [ipc] [trace] Route Ch Msg (cl=7, tag=0, seq=2).
[2025-07-15 20:33:46.391] [784] [engine] [trace] RawRpcClientSvc::handleEvent(Input).
[2025-07-15 20:33:46.391] [784] [engine] [trace] RawRpcClientSvc::handleInputEvent call (fsm_id=0).
[2025-07-15 20:33:46.392] [784] [engine] [debug] RawRpcClientSvc: RPC promise success from node 23 (fsm_id=0).
[2025-07-15 20:33:46.393] [784] [ipc] [debug] Route Ch End (cl=7, tag=0, keep_alive=false, err=null).
[2025-07-15 20:33:46.393] [784] [engine] [debug] RawRpcClientSvc::handleEvent(Completed(alive=false)) (fsm_id=0).
[2025-07-15 20:33:46.393] [784] [ipc] [trace] ~Gateway(cl=7, tag=0, err=null).
[2025-07-15 20:33:46.393] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=9).
[2025-07-15 20:33:46.393] [784] [ipc] [debug] End of client stream - closing connection (id=7, fd=9).
[2025-07-15 20:33:46.393] [784] [ipc] [debug] Pipe is disconnected (cl=7).
[2025-07-15 20:33:46.409] [784] [] [debug] New client connection (id=8, addr='unix:').
[2025-07-15 20:33:46.409] [784] [ipc] [trace] ClientContext(fd=9, id=8).
[2025-07-15 20:33:46.409] [784] [ipc] [debug] Pipe is connected (cl=8).
[2025-07-15 20:33:46.409] [784] [ipc] [debug] Route connect request (cl=8, ver='0.1', err_code=0).
[2025-07-15 20:33:46.410] [784] [ipc] [trace] Gateway(cl=8, tag=0).
[2025-07-15 20:33:46.410] [784] [ipc] [debug] Route Ch Msg (cl=8, tag=0, seq=0, srv=0x5FAE48D0F51BC328).
[2025-07-15 20:33:46.410] [784] [engine] [debug] New 'ocvsmd.svc.node.exec_cmd' service channel (fsm=2).
[2025-07-15 20:33:46.410] [784] [engine] [trace] ExecCmdSvc::Fsm (id=2).
[2025-07-15 20:33:46.410] [784] [ipc] [debug] Route Ch End (cl=8, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:46.410] [784] [engine] [debug] ExecCmdSvc::handleEvent(Completed(alive=true)) (fsm_id=2).
[2025-07-15 20:33:46.411] [784] [engine] [debug] ExecCmdSvc: RPC promise success from node 23 (status=0, fsm_id=2).
[2025-07-15 20:33:46.411] [784] [ipc] [trace] ~Gateway(cl=8, tag=0, err=null).
[2025-07-15 20:33:46.412] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:46.412] [784] [ipc] [debug] End of client stream - closing connection (id=8, fd=9).
[2025-07-15 20:33:46.412] [784] [ipc] [debug] Pipe is disconnected (cl=8).
[2025-07-15 20:33:46.424] [784] [] [debug] New client connection (id=9, addr='unix:').
[2025-07-15 20:33:46.424] [784] [ipc] [trace] ClientContext(fd=9, id=9).
[2025-07-15 20:33:46.424] [784] [ipc] [debug] Pipe is connected (cl=9).
[2025-07-15 20:33:46.424] [784] [ipc] [debug] Route connect request (cl=9, ver='0.1', err_code=0).
[2025-07-15 20:33:46.424] [784] [ipc] [trace] Gateway(cl=9, tag=0).
[2025-07-15 20:33:46.424] [784] [ipc] [debug] Route Ch Msg (cl=9, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:46.424] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=0).
[2025-07-15 20:33:46.424] [784] [engine] [trace] AccessRegsSvc::Fsm (id=0).
[2025-07-15 20:33:46.425] [784] [ipc] [trace] Route Ch Msg (cl=9, tag=0, seq=1).
[2025-07-15 20:33:46.425] [784] [ipc] [debug] Route Ch End (cl=9, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:46.425] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=0).
[2025-07-15 20:33:46.445] [784] [ipc] [trace] ~Gateway(cl=9, tag=0, err=null).
[2025-07-15 20:33:46.445] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:46.445] [784] [ipc] [debug] End of client stream - closing connection (id=9, fd=9).
[2025-07-15 20:33:46.445] [784] [ipc] [debug] Pipe is disconnected (cl=9).
[2025-07-15 20:33:47.457] [784] [] [debug] New client connection (id=10, addr='unix:').
[2025-07-15 20:33:47.457] [784] [ipc] [trace] ClientContext(fd=9, id=10).
[2025-07-15 20:33:47.457] [784] [ipc] [debug] Pipe is connected (cl=10).
[2025-07-15 20:33:47.458] [784] [ipc] [debug] Route connect request (cl=10, ver='0.1', err_code=0).
[2025-07-15 20:33:47.458] [784] [ipc] [trace] Gateway(cl=10, tag=0).
[2025-07-15 20:33:47.458] [784] [ipc] [debug] Route Ch Msg (cl=10, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:47.458] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=1).
[2025-07-15 20:33:47.458] [784] [engine] [trace] AccessRegsSvc::Fsm (id=1).
[2025-07-15 20:33:47.458] [784] [ipc] [trace] Route Ch Msg (cl=10, tag=0, seq=1).
[2025-07-15 20:33:47.458] [784] [ipc] [debug] Route Ch End (cl=10, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:47.458] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=1).
[2025-07-15 20:33:47.460] [784] [ipc] [trace] ~Gateway(cl=10, tag=0, err=null).
[2025-07-15 20:33:47.460] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:47.460] [784] [ipc] [debug] End of client stream - closing connection (id=10, fd=9).
[2025-07-15 20:33:47.460] [784] [ipc] [debug] Pipe is disconnected (cl=10).
[2025-07-15 20:33:47.479] [784] [] [debug] New client connection (id=11, addr='unix:').
[2025-07-15 20:33:47.479] [784] [ipc] [trace] ClientContext(fd=9, id=11).
[2025-07-15 20:33:47.479] [784] [ipc] [debug] Pipe is connected (cl=11).
[2025-07-15 20:33:47.480] [784] [ipc] [debug] Route connect request (cl=11, ver='0.1', err_code=0).
[2025-07-15 20:33:47.480] [784] [ipc] [trace] Gateway(cl=11, tag=0).
[2025-07-15 20:33:47.480] [784] [ipc] [debug] Route Ch Msg (cl=11, tag=0, seq=0, srv=0x5FAE48D0F51BC328).
[2025-07-15 20:33:47.480] [784] [engine] [debug] New 'ocvsmd.svc.node.exec_cmd' service channel (fsm=3).
[2025-07-15 20:33:47.480] [784] [engine] [trace] ExecCmdSvc::Fsm (id=3).
[2025-07-15 20:33:47.480] [784] [ipc] [debug] Route Ch End (cl=11, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:47.480] [784] [engine] [debug] ExecCmdSvc::handleEvent(Completed(alive=true)) (fsm_id=3).
[2025-07-15 20:33:47.481] [784] [engine] [debug] ExecCmdSvc: RPC promise success from node 23 (status=0, fsm_id=3).
[2025-07-15 20:33:47.481] [784] [ipc] [trace] ~Gateway(cl=11, tag=0, err=null).
[2025-07-15 20:33:47.482] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:47.482] [784] [ipc] [debug] End of client stream - closing connection (id=11, fd=9).
[2025-07-15 20:33:47.482] [784] [ipc] [debug] Pipe is disconnected (cl=11).
[2025-07-15 20:33:47.502] [784] [] [debug] New client connection (id=12, addr='unix:').
[2025-07-15 20:33:47.502] [784] [ipc] [trace] ClientContext(fd=9, id=12).
[2025-07-15 20:33:47.503] [784] [ipc] [debug] Pipe is connected (cl=12).
[2025-07-15 20:33:47.503] [784] [ipc] [debug] Route connect request (cl=12, ver='0.1', err_code=0).
[2025-07-15 20:33:47.503] [784] [ipc] [trace] Gateway(cl=12, tag=0).
[2025-07-15 20:33:47.503] [784] [ipc] [debug] Route Ch Msg (cl=12, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:47.503] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=2).
[2025-07-15 20:33:47.503] [784] [engine] [trace] AccessRegsSvc::Fsm (id=2).
[2025-07-15 20:33:47.503] [784] [ipc] [trace] Route Ch Msg (cl=12, tag=0, seq=1).
[2025-07-15 20:33:47.503] [784] [ipc] [debug] Route Ch End (cl=12, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:47.503] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=2).
[2025-07-15 20:33:47.518] [784] [ipc] [trace] ~Gateway(cl=12, tag=0, err=null).
[2025-07-15 20:33:47.518] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:47.518] [784] [ipc] [debug] End of client stream - closing connection (id=12, fd=9).
[2025-07-15 20:33:47.518] [784] [ipc] [debug] Pipe is disconnected (cl=12).
[2025-07-15 20:33:48.531] [784] [] [debug] New client connection (id=13, addr='unix:').
[2025-07-15 20:33:48.531] [784] [ipc] [trace] ClientContext(fd=9, id=13).
[2025-07-15 20:33:48.531] [784] [ipc] [debug] Pipe is connected (cl=13).
[2025-07-15 20:33:48.532] [784] [ipc] [debug] Route connect request (cl=13, ver='0.1', err_code=0).
[2025-07-15 20:33:48.532] [784] [ipc] [trace] Gateway(cl=13, tag=0).
[2025-07-15 20:33:48.532] [784] [ipc] [debug] Route Ch Msg (cl=13, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:48.532] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=3).
[2025-07-15 20:33:48.532] [784] [engine] [trace] AccessRegsSvc::Fsm (id=3).
[2025-07-15 20:33:48.532] [784] [ipc] [trace] Route Ch Msg (cl=13, tag=0, seq=1).
[2025-07-15 20:33:48.532] [784] [ipc] [debug] Route Ch End (cl=13, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:48.532] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=3).
[2025-07-15 20:33:48.544] [784] [ipc] [trace] ~Gateway(cl=13, tag=0, err=null).
[2025-07-15 20:33:48.544] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:48.544] [784] [ipc] [debug] End of client stream - closing connection (id=13, fd=9).
[2025-07-15 20:33:48.544] [784] [ipc] [debug] Pipe is disconnected (cl=13).
[2025-07-15 20:33:49.558] [784] [] [debug] New client connection (id=14, addr='unix:').
[2025-07-15 20:33:49.558] [784] [ipc] [trace] ClientContext(fd=9, id=14).
[2025-07-15 20:33:49.558] [784] [ipc] [debug] Pipe is connected (cl=14).
[2025-07-15 20:33:49.558] [784] [ipc] [debug] Route connect request (cl=14, ver='0.1', err_code=0).
[2025-07-15 20:33:49.559] [784] [ipc] [trace] Gateway(cl=14, tag=0).
[2025-07-15 20:33:49.559] [784] [ipc] [debug] Route Ch Msg (cl=14, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:49.559] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=4).
[2025-07-15 20:33:49.559] [784] [engine] [trace] AccessRegsSvc::Fsm (id=4).
[2025-07-15 20:33:49.559] [784] [ipc] [trace] Route Ch Msg (cl=14, tag=0, seq=1).
[2025-07-15 20:33:49.559] [784] [ipc] [trace] Msg payload read is not ready (fd=9).
[2025-07-15 20:33:49.559] [784] [ipc] [debug] Route Ch End (cl=14, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:49.559] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=4).
[2025-07-15 20:33:49.561] [784] [ipc] [trace] ~Gateway(cl=14, tag=0, err=null).
[2025-07-15 20:33:49.561] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:49.561] [784] [ipc] [debug] End of client stream - closing connection (id=14, fd=9).
[2025-07-15 20:33:49.561] [784] [ipc] [debug] Pipe is disconnected (cl=14).
[2025-07-15 20:33:50.574] [784] [] [debug] New client connection (id=15, addr='unix:').
[2025-07-15 20:33:50.574] [784] [ipc] [trace] ClientContext(fd=9, id=15).
[2025-07-15 20:33:50.574] [784] [ipc] [debug] Pipe is connected (cl=15).
[2025-07-15 20:33:50.574] [784] [ipc] [debug] Route connect request (cl=15, ver='0.1', err_code=0).
[2025-07-15 20:33:50.574] [784] [ipc] [trace] Gateway(cl=15, tag=0).
[2025-07-15 20:33:50.574] [784] [ipc] [debug] Route Ch Msg (cl=15, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:50.574] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=5).
[2025-07-15 20:33:50.574] [784] [engine] [trace] AccessRegsSvc::Fsm (id=5).
[2025-07-15 20:33:50.575] [784] [ipc] [trace] Route Ch Msg (cl=15, tag=0, seq=1).
[2025-07-15 20:33:50.575] [784] [ipc] [debug] Route Ch End (cl=15, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:50.575] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=5).
[2025-07-15 20:33:50.577] [784] [ipc] [trace] ~Gateway(cl=15, tag=0, err=null).
[2025-07-15 20:33:50.577] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:50.577] [784] [ipc] [debug] End of client stream - closing connection (id=15, fd=9).
[2025-07-15 20:33:50.577] [784] [ipc] [debug] Pipe is disconnected (cl=15).
[2025-07-15 20:33:51.591] [784] [] [debug] New client connection (id=16, addr='unix:').
[2025-07-15 20:33:51.591] [784] [ipc] [trace] ClientContext(fd=9, id=16).
[2025-07-15 20:33:51.591] [784] [ipc] [debug] Pipe is connected (cl=16).
[2025-07-15 20:33:51.591] [784] [ipc] [debug] Route connect request (cl=16, ver='0.1', err_code=0).
[2025-07-15 20:33:51.592] [784] [ipc] [trace] Gateway(cl=16, tag=0).
[2025-07-15 20:33:51.592] [784] [ipc] [debug] Route Ch Msg (cl=16, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:51.592] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=6).
[2025-07-15 20:33:51.592] [784] [engine] [trace] AccessRegsSvc::Fsm (id=6).
[2025-07-15 20:33:51.592] [784] [ipc] [trace] Route Ch Msg (cl=16, tag=0, seq=1).
[2025-07-15 20:33:51.592] [784] [ipc] [debug] Route Ch End (cl=16, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:51.592] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=6).
[2025-07-15 20:33:51.596] [784] [ipc] [trace] ~Gateway(cl=16, tag=0, err=null).
[2025-07-15 20:33:51.596] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:51.596] [784] [ipc] [debug] End of client stream - closing connection (id=16, fd=9).
[2025-07-15 20:33:51.596] [784] [ipc] [debug] Pipe is disconnected (cl=16).
[2025-07-15 20:33:52.610] [784] [] [debug] New client connection (id=17, addr='unix:').
[2025-07-15 20:33:52.610] [784] [ipc] [trace] ClientContext(fd=9, id=17).
[2025-07-15 20:33:52.610] [784] [ipc] [debug] Pipe is connected (cl=17).
[2025-07-15 20:33:52.610] [784] [ipc] [debug] Route connect request (cl=17, ver='0.1', err_code=0).
[2025-07-15 20:33:52.611] [784] [ipc] [trace] Gateway(cl=17, tag=0).
[2025-07-15 20:33:52.611] [784] [ipc] [debug] Route Ch Msg (cl=17, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:52.611] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=7).
[2025-07-15 20:33:52.611] [784] [engine] [trace] AccessRegsSvc::Fsm (id=7).
[2025-07-15 20:33:52.611] [784] [ipc] [trace] Route Ch Msg (cl=17, tag=0, seq=1).
[2025-07-15 20:33:52.611] [784] [ipc] [debug] Route Ch End (cl=17, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:52.611] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=7).
[2025-07-15 20:33:52.612] [784] [ipc] [trace] ~Gateway(cl=17, tag=0, err=null).
[2025-07-15 20:33:52.613] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:52.613] [784] [ipc] [debug] End of client stream - closing connection (id=17, fd=9).
[2025-07-15 20:33:52.613] [784] [ipc] [debug] Pipe is disconnected (cl=17).
[2025-07-15 20:33:53.626] [784] [] [debug] New client connection (id=18, addr='unix:').
[2025-07-15 20:33:53.626] [784] [ipc] [trace] ClientContext(fd=9, id=18).
[2025-07-15 20:33:53.626] [784] [ipc] [debug] Pipe is connected (cl=18).
[2025-07-15 20:33:53.626] [784] [ipc] [debug] Route connect request (cl=18, ver='0.1', err_code=0).
[2025-07-15 20:33:53.627] [784] [ipc] [trace] Gateway(cl=18, tag=0).
[2025-07-15 20:33:53.627] [784] [ipc] [debug] Route Ch Msg (cl=18, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:53.627] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=8).
[2025-07-15 20:33:53.627] [784] [engine] [trace] AccessRegsSvc::Fsm (id=8).
[2025-07-15 20:33:53.627] [784] [ipc] [trace] Route Ch Msg (cl=18, tag=0, seq=1).
[2025-07-15 20:33:53.627] [784] [ipc] [debug] Route Ch End (cl=18, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:53.627] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=8).
[2025-07-15 20:33:53.631] [784] [ipc] [trace] ~Gateway(cl=18, tag=0, err=null).
[2025-07-15 20:33:53.631] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:53.631] [784] [ipc] [debug] End of client stream - closing connection (id=18, fd=9).
[2025-07-15 20:33:53.631] [784] [ipc] [debug] Pipe is disconnected (cl=18).
[2025-07-15 20:33:54.644] [784] [] [debug] New client connection (id=19, addr='unix:').
[2025-07-15 20:33:54.645] [784] [ipc] [trace] ClientContext(fd=9, id=19).
[2025-07-15 20:33:54.645] [784] [ipc] [debug] Pipe is connected (cl=19).
[2025-07-15 20:33:54.645] [784] [ipc] [debug] Route connect request (cl=19, ver='0.1', err_code=0).
[2025-07-15 20:33:54.646] [784] [ipc] [trace] Gateway(cl=19, tag=0).
[2025-07-15 20:33:54.646] [784] [ipc] [debug] Route Ch Msg (cl=19, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:54.646] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=9).
[2025-07-15 20:33:54.646] [784] [engine] [trace] AccessRegsSvc::Fsm (id=9).
[2025-07-15 20:33:54.646] [784] [ipc] [trace] Route Ch Msg (cl=19, tag=0, seq=1).
[2025-07-15 20:33:54.647] [784] [ipc] [debug] Route Ch End (cl=19, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:54.647] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=9).
[2025-07-15 20:33:54.649] [784] [ipc] [trace] ~Gateway(cl=19, tag=0, err=null).
[2025-07-15 20:33:54.650] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:54.650] [784] [ipc] [debug] End of client stream - closing connection (id=19, fd=9).
[2025-07-15 20:33:54.650] [784] [ipc] [debug] Pipe is disconnected (cl=19).
[2025-07-15 20:33:55.664] [784] [] [debug] New client connection (id=20, addr='unix:').
[2025-07-15 20:33:55.665] [784] [ipc] [trace] ClientContext(fd=9, id=20).
[2025-07-15 20:33:55.665] [784] [ipc] [debug] Pipe is connected (cl=20).
[2025-07-15 20:33:55.665] [784] [ipc] [debug] Route connect request (cl=20, ver='0.1', err_code=0).
[2025-07-15 20:33:55.665] [784] [ipc] [trace] Msg payload read is not ready (fd=9).
[2025-07-15 20:33:55.665] [784] [ipc] [trace] Gateway(cl=20, tag=0).
[2025-07-15 20:33:55.666] [784] [ipc] [debug] Route Ch Msg (cl=20, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:55.666] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=10).
[2025-07-15 20:33:55.666] [784] [engine] [trace] AccessRegsSvc::Fsm (id=10).
[2025-07-15 20:33:55.666] [784] [ipc] [trace] Route Ch Msg (cl=20, tag=0, seq=1).
[2025-07-15 20:33:55.666] [784] [ipc] [debug] Route Ch End (cl=20, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:55.666] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=10).
[2025-07-15 20:33:55.669] [784] [ipc] [trace] ~Gateway(cl=20, tag=0, err=null).
[2025-07-15 20:33:55.669] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:55.669] [784] [ipc] [debug] End of client stream - closing connection (id=20, fd=9).
[2025-07-15 20:33:55.669] [784] [ipc] [debug] Pipe is disconnected (cl=20).
[2025-07-15 20:33:56.682] [784] [] [debug] New client connection (id=21, addr='unix:').
[2025-07-15 20:33:56.683] [784] [ipc] [trace] ClientContext(fd=9, id=21).
[2025-07-15 20:33:56.683] [784] [ipc] [debug] Pipe is connected (cl=21).
[2025-07-15 20:33:56.683] [784] [ipc] [debug] Route connect request (cl=21, ver='0.1', err_code=0).
[2025-07-15 20:33:56.683] [784] [ipc] [trace] Gateway(cl=21, tag=0).
[2025-07-15 20:33:56.683] [784] [ipc] [debug] Route Ch Msg (cl=21, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:56.683] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=11).
[2025-07-15 20:33:56.683] [784] [engine] [trace] AccessRegsSvc::Fsm (id=11).
[2025-07-15 20:33:56.683] [784] [ipc] [trace] Route Ch Msg (cl=21, tag=0, seq=1).
[2025-07-15 20:33:56.683] [784] [ipc] [debug] Route Ch End (cl=21, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:56.683] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=11).
[2025-07-15 20:33:56.686] [784] [ipc] [trace] ~Gateway(cl=21, tag=0, err=null).
[2025-07-15 20:33:56.686] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:56.686] [784] [ipc] [debug] End of client stream - closing connection (id=21, fd=9).
[2025-07-15 20:33:56.687] [784] [ipc] [debug] Pipe is disconnected (cl=21).
[2025-07-15 20:33:57.701] [784] [] [debug] New client connection (id=22, addr='unix:').
[2025-07-15 20:33:57.701] [784] [ipc] [trace] ClientContext(fd=9, id=22).
[2025-07-15 20:33:57.701] [784] [ipc] [debug] Pipe is connected (cl=22).
[2025-07-15 20:33:57.701] [784] [ipc] [debug] Route connect request (cl=22, ver='0.1', err_code=0).
[2025-07-15 20:33:57.702] [784] [ipc] [trace] Gateway(cl=22, tag=0).
[2025-07-15 20:33:57.702] [784] [ipc] [debug] Route Ch Msg (cl=22, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:57.702] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=12).
[2025-07-15 20:33:57.702] [784] [engine] [trace] AccessRegsSvc::Fsm (id=12).
[2025-07-15 20:33:57.702] [784] [ipc] [trace] Route Ch Msg (cl=22, tag=0, seq=1).
[2025-07-15 20:33:57.702] [784] [ipc] [debug] Route Ch End (cl=22, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:57.702] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=12).
[2025-07-15 20:33:57.704] [784] [ipc] [trace] ~Gateway(cl=22, tag=0, err=null).
[2025-07-15 20:33:57.704] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:57.704] [784] [ipc] [debug] End of client stream - closing connection (id=22, fd=9).
[2025-07-15 20:33:57.704] [784] [ipc] [debug] Pipe is disconnected (cl=22).
[2025-07-15 20:33:58.720] [784] [] [debug] New client connection (id=23, addr='unix:').
[2025-07-15 20:33:58.720] [784] [ipc] [trace] ClientContext(fd=9, id=23).
[2025-07-15 20:33:58.720] [784] [ipc] [debug] Pipe is connected (cl=23).
[2025-07-15 20:33:58.720] [784] [ipc] [debug] Route connect request (cl=23, ver='0.1', err_code=0).
[2025-07-15 20:33:58.720] [784] [ipc] [trace] Gateway(cl=23, tag=0).
[2025-07-15 20:33:58.721] [784] [ipc] [debug] Route Ch Msg (cl=23, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:58.721] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=13).
[2025-07-15 20:33:58.721] [784] [engine] [trace] AccessRegsSvc::Fsm (id=13).
[2025-07-15 20:33:58.721] [784] [ipc] [trace] Route Ch Msg (cl=23, tag=0, seq=1).
[2025-07-15 20:33:58.721] [784] [ipc] [debug] Route Ch End (cl=23, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:58.721] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=13).
[2025-07-15 20:33:58.722] [784] [ipc] [trace] ~Gateway(cl=23, tag=0, err=null).
[2025-07-15 20:33:58.723] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:58.723] [784] [ipc] [debug] End of client stream - closing connection (id=23, fd=9).
[2025-07-15 20:33:58.723] [784] [ipc] [debug] Pipe is disconnected (cl=23).
[2025-07-15 20:33:59.736] [784] [] [debug] New client connection (id=24, addr='unix:').
[2025-07-15 20:33:59.736] [784] [ipc] [trace] ClientContext(fd=9, id=24).
[2025-07-15 20:33:59.736] [784] [ipc] [debug] Pipe is connected (cl=24).
[2025-07-15 20:33:59.737] [784] [ipc] [debug] Route connect request (cl=24, ver='0.1', err_code=0).
[2025-07-15 20:33:59.737] [784] [ipc] [trace] Gateway(cl=24, tag=0).
[2025-07-15 20:33:59.737] [784] [ipc] [debug] Route Ch Msg (cl=24, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:33:59.737] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=14).
[2025-07-15 20:33:59.737] [784] [engine] [trace] AccessRegsSvc::Fsm (id=14).
[2025-07-15 20:33:59.737] [784] [ipc] [trace] Route Ch Msg (cl=24, tag=0, seq=1).
[2025-07-15 20:33:59.737] [784] [ipc] [debug] Route Ch End (cl=24, tag=0, keep_alive=true, err=null).
[2025-07-15 20:33:59.737] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=14).
[2025-07-15 20:33:59.739] [784] [ipc] [trace] ~Gateway(cl=24, tag=0, err=null).
[2025-07-15 20:33:59.740] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:33:59.740] [784] [ipc] [debug] End of client stream - closing connection (id=24, fd=9).
[2025-07-15 20:33:59.740] [784] [ipc] [debug] Pipe is disconnected (cl=24).
[2025-07-15 20:34:00.754] [784] [] [debug] New client connection (id=25, addr='unix:').
[2025-07-15 20:34:00.754] [784] [ipc] [trace] ClientContext(fd=9, id=25).
[2025-07-15 20:34:00.754] [784] [ipc] [debug] Pipe is connected (cl=25).
[2025-07-15 20:34:00.754] [784] [ipc] [debug] Route connect request (cl=25, ver='0.1', err_code=0).
[2025-07-15 20:34:00.755] [784] [ipc] [trace] Gateway(cl=25, tag=0).
[2025-07-15 20:34:00.755] [784] [ipc] [debug] Route Ch Msg (cl=25, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:00.755] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=15).
[2025-07-15 20:34:00.755] [784] [engine] [trace] AccessRegsSvc::Fsm (id=15).
[2025-07-15 20:34:00.755] [784] [ipc] [trace] Route Ch Msg (cl=25, tag=0, seq=1).
[2025-07-15 20:34:00.755] [784] [ipc] [debug] Route Ch End (cl=25, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:00.755] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=15).
[2025-07-15 20:34:00.757] [784] [ipc] [trace] ~Gateway(cl=25, tag=0, err=null).
[2025-07-15 20:34:00.757] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:00.757] [784] [ipc] [debug] End of client stream - closing connection (id=25, fd=9).
[2025-07-15 20:34:00.757] [784] [ipc] [debug] Pipe is disconnected (cl=25).
[2025-07-15 20:34:01.770] [784] [] [debug] New client connection (id=26, addr='unix:').
[2025-07-15 20:34:01.770] [784] [ipc] [trace] ClientContext(fd=9, id=26).
[2025-07-15 20:34:01.770] [784] [ipc] [debug] Pipe is connected (cl=26).
[2025-07-15 20:34:01.770] [784] [ipc] [debug] Route connect request (cl=26, ver='0.1', err_code=0).
[2025-07-15 20:34:01.770] [784] [ipc] [trace] Gateway(cl=26, tag=0).
[2025-07-15 20:34:01.770] [784] [ipc] [debug] Route Ch Msg (cl=26, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:01.770] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=16).
[2025-07-15 20:34:01.770] [784] [engine] [trace] AccessRegsSvc::Fsm (id=16).
[2025-07-15 20:34:01.770] [784] [ipc] [trace] Route Ch Msg (cl=26, tag=0, seq=1).
[2025-07-15 20:34:01.770] [784] [ipc] [debug] Route Ch End (cl=26, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:01.770] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=16).
[2025-07-15 20:34:01.772] [784] [ipc] [trace] ~Gateway(cl=26, tag=0, err=null).
[2025-07-15 20:34:01.773] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:01.773] [784] [ipc] [debug] End of client stream - closing connection (id=26, fd=9).
[2025-07-15 20:34:01.773] [784] [ipc] [debug] Pipe is disconnected (cl=26).
[2025-07-15 20:34:02.794] [784] [] [debug] New client connection (id=27, addr='unix:').
[2025-07-15 20:34:02.794] [784] [ipc] [trace] ClientContext(fd=9, id=27).
[2025-07-15 20:34:02.794] [784] [ipc] [debug] Pipe is connected (cl=27).
[2025-07-15 20:34:02.794] [784] [ipc] [debug] Route connect request (cl=27, ver='0.1', err_code=0).
[2025-07-15 20:34:02.794] [784] [ipc] [trace] Gateway(cl=27, tag=0).
[2025-07-15 20:34:02.794] [784] [ipc] [debug] Route Ch Msg (cl=27, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:02.794] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=17).
[2025-07-15 20:34:02.795] [784] [engine] [trace] AccessRegsSvc::Fsm (id=17).
[2025-07-15 20:34:02.795] [784] [ipc] [trace] Route Ch Msg (cl=27, tag=0, seq=1).
[2025-07-15 20:34:02.795] [784] [ipc] [debug] Route Ch End (cl=27, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:02.795] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=17).
[2025-07-15 20:34:02.797] [784] [ipc] [trace] ~Gateway(cl=27, tag=0, err=null).
[2025-07-15 20:34:02.798] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:02.798] [784] [ipc] [debug] End of client stream - closing connection (id=27, fd=9).
[2025-07-15 20:34:02.798] [784] [ipc] [debug] Pipe is disconnected (cl=27).
[2025-07-15 20:34:03.811] [784] [] [debug] New client connection (id=28, addr='unix:').
[2025-07-15 20:34:03.812] [784] [ipc] [trace] ClientContext(fd=9, id=28).
[2025-07-15 20:34:03.812] [784] [ipc] [debug] Pipe is connected (cl=28).
[2025-07-15 20:34:03.812] [784] [ipc] [debug] Route connect request (cl=28, ver='0.1', err_code=0).
[2025-07-15 20:34:03.813] [784] [ipc] [trace] Gateway(cl=28, tag=0).
[2025-07-15 20:34:03.813] [784] [ipc] [debug] Route Ch Msg (cl=28, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:03.813] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=18).
[2025-07-15 20:34:03.813] [784] [engine] [trace] AccessRegsSvc::Fsm (id=18).
[2025-07-15 20:34:03.813] [784] [ipc] [trace] Route Ch Msg (cl=28, tag=0, seq=1).
[2025-07-15 20:34:03.813] [784] [ipc] [debug] Route Ch End (cl=28, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:03.813] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=18).
[2025-07-15 20:34:03.816] [784] [ipc] [trace] ~Gateway(cl=28, tag=0, err=null).
[2025-07-15 20:34:03.817] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:03.817] [784] [ipc] [debug] End of client stream - closing connection (id=28, fd=9).
[2025-07-15 20:34:03.817] [784] [ipc] [debug] Pipe is disconnected (cl=28).
[2025-07-15 20:34:04.837] [784] [] [debug] New client connection (id=29, addr='unix:').
[2025-07-15 20:34:04.837] [784] [ipc] [trace] ClientContext(fd=9, id=29).
[2025-07-15 20:34:04.837] [784] [ipc] [debug] Pipe is connected (cl=29).
[2025-07-15 20:34:04.837] [784] [ipc] [debug] Route connect request (cl=29, ver='0.1', err_code=0).
[2025-07-15 20:34:04.838] [784] [ipc] [trace] Gateway(cl=29, tag=0).
[2025-07-15 20:34:04.838] [784] [ipc] [debug] Route Ch Msg (cl=29, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:04.838] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=19).
[2025-07-15 20:34:04.838] [784] [engine] [trace] AccessRegsSvc::Fsm (id=19).
[2025-07-15 20:34:04.838] [784] [ipc] [trace] Route Ch Msg (cl=29, tag=0, seq=1).
[2025-07-15 20:34:04.838] [784] [ipc] [debug] Route Ch End (cl=29, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:04.838] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=19).
[2025-07-15 20:34:04.840] [784] [ipc] [trace] ~Gateway(cl=29, tag=0, err=null).
[2025-07-15 20:34:04.840] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:04.840] [784] [ipc] [debug] End of client stream - closing connection (id=29, fd=9).
[2025-07-15 20:34:04.840] [784] [ipc] [debug] Pipe is disconnected (cl=29).
[2025-07-15 20:34:05.854] [784] [] [debug] New client connection (id=30, addr='unix:').
[2025-07-15 20:34:05.854] [784] [ipc] [trace] ClientContext(fd=9, id=30).
[2025-07-15 20:34:05.854] [784] [ipc] [debug] Pipe is connected (cl=30).
[2025-07-15 20:34:44.063] [784] [] [debug] New client connection (id=86, addr='unix:').
[2025-07-15 20:34:44.064] [784] [ipc] [trace] ClientContext(fd=9, id=86).
[2025-07-15 20:34:44.064] [784] [ipc] [debug] Pipe is connected (cl=86).
[2025-07-15 20:34:44.064] [784] [ipc] [debug] Route connect request (cl=86, ver='0.1', err_code=0).
[2025-07-15 20:34:44.064] [784] [ipc] [trace] Gateway(cl=86, tag=0).
[2025-07-15 20:34:44.064] [784] [ipc] [debug] Route Ch Msg (cl=86, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:44.064] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=54).
[2025-07-15 20:34:44.064] [784] [engine] [trace] AccessRegsSvc::Fsm (id=54).
[2025-07-15 20:34:44.065] [784] [ipc] [trace] Route Ch Msg (cl=86, tag=0, seq=1).
[2025-07-15 20:34:44.065] [784] [ipc] [debug] Route Ch End (cl=86, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:44.065] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=54).
[2025-07-15 20:34:44.066] [784] [ipc] [trace] ~Gateway(cl=86, tag=0, err=null).
[2025-07-15 20:34:44.066] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:44.066] [784] [ipc] [debug] End of client stream - closing connection (id=86, fd=9).
[2025-07-15 20:34:44.066] [784] [ipc] [debug] Pipe is disconnected (cl=86).
[2025-07-15 20:34:44.078] [784] [] [debug] New client connection (id=87, addr='unix:').
[2025-07-15 20:34:44.078] [784] [ipc] [trace] ClientContext(fd=9, id=87).
[2025-07-15 20:34:44.078] [784] [ipc] [debug] Pipe is connected (cl=87).
[2025-07-15 20:34:44.078] [784] [ipc] [trace] Msg payload read is not ready (fd=9).
[2025-07-15 20:34:44.079] [784] [ipc] [debug] Route connect request (cl=87, ver='0.1', err_code=0).
[2025-07-15 20:34:44.079] [784] [ipc] [trace] Gateway(cl=87, tag=0).
[2025-07-15 20:34:44.079] [784] [ipc] [debug] Route Ch Msg (cl=87, tag=0, seq=0, srv=0x5FAE48D0F51BC328).
[2025-07-15 20:34:44.079] [784] [engine] [debug] New 'ocvsmd.svc.node.exec_cmd' service channel (fsm=19).
[2025-07-15 20:34:44.079] [784] [engine] [trace] ExecCmdSvc::Fsm (id=19).
[2025-07-15 20:34:44.079] [784] [ipc] [debug] Route Ch End (cl=87, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:44.079] [784] [engine] [debug] ExecCmdSvc::handleEvent(Completed(alive=true)) (fsm_id=19).
[2025-07-15 20:34:44.081] [784] [engine] [debug] ExecCmdSvc: RPC promise success from node 23 (status=0, fsm_id=19).
[2025-07-15 20:34:44.081] [784] [ipc] [trace] ~Gateway(cl=87, tag=0, err=null).
[2025-07-15 20:34:44.081] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:44.081] [784] [ipc] [debug] End of client stream - closing connection (id=87, fd=9).
[2025-07-15 20:34:44.082] [784] [ipc] [debug] Pipe is disconnected (cl=87).
[2025-07-15 20:34:44.096] [784] [] [debug] New client connection (id=88, addr='unix:').
[2025-07-15 20:34:44.096] [784] [ipc] [trace] ClientContext(fd=9, id=88).
[2025-07-15 20:34:44.096] [784] [ipc] [debug] Pipe is connected (cl=88).
[2025-07-15 20:34:44.096] [784] [ipc] [debug] Route connect request (cl=88, ver='0.1', err_code=0).
[2025-07-15 20:34:44.097] [784] [ipc] [trace] Gateway(cl=88, tag=0).
[2025-07-15 20:34:44.097] [784] [ipc] [debug] Route Ch Msg (cl=88, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:44.097] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=55).
[2025-07-15 20:34:44.097] [784] [engine] [trace] AccessRegsSvc::Fsm (id=55).
[2025-07-15 20:34:44.097] [784] [ipc] [trace] Route Ch Msg (cl=88, tag=0, seq=1).
[2025-07-15 20:34:44.097] [784] [ipc] [debug] Route Ch End (cl=88, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:44.097] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=55).
[2025-07-15 20:34:44.112] [784] [ipc] [trace] ~Gateway(cl=88, tag=0, err=null).
[2025-07-15 20:34:44.113] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:44.113] [784] [ipc] [debug] End of client stream - closing connection (id=88, fd=9).
[2025-07-15 20:34:44.113] [784] [ipc] [debug] Pipe is disconnected (cl=88).
[2025-07-15 20:34:45.127] [784] [] [debug] New client connection (id=89, addr='unix:').
[2025-07-15 20:34:45.127] [784] [ipc] [trace] ClientContext(fd=9, id=89).
[2025-07-15 20:34:45.127] [784] [ipc] [debug] Pipe is connected (cl=89).
[2025-07-15 20:34:45.127] [784] [ipc] [debug] Route connect request (cl=89, ver='0.1', err_code=0).
[2025-07-15 20:34:45.127] [784] [ipc] [trace] Gateway(cl=89, tag=0).
[2025-07-15 20:34:45.127] [784] [ipc] [debug] Route Ch Msg (cl=89, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:45.127] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=56).
[2025-07-15 20:34:45.127] [784] [engine] [trace] AccessRegsSvc::Fsm (id=56).
[2025-07-15 20:34:45.127] [784] [ipc] [trace] Route Ch Msg (cl=89, tag=0, seq=1).
[2025-07-15 20:34:45.127] [784] [ipc] [debug] Route Ch End (cl=89, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:45.127] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=56).
[2025-07-15 20:34:45.138] [784] [ipc] [trace] ~Gateway(cl=89, tag=0, err=null).
[2025-07-15 20:34:45.138] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:45.138] [784] [ipc] [debug] End of client stream - closing connection (id=89, fd=9).
[2025-07-15 20:34:45.138] [784] [ipc] [debug] Pipe is disconnected (cl=89).
[2025-07-15 20:34:46.151] [784] [] [debug] New client connection (id=90, addr='unix:').
[2025-07-15 20:34:46.152] [784] [ipc] [trace] ClientContext(fd=9, id=90).
[2025-07-15 20:34:46.152] [784] [ipc] [debug] Pipe is connected (cl=90).
[2025-07-15 20:34:46.152] [784] [ipc] [debug] Route connect request (cl=90, ver='0.1', err_code=0).
[2025-07-15 20:34:46.152] [784] [ipc] [trace] Gateway(cl=90, tag=0).
[2025-07-15 20:34:46.152] [784] [ipc] [debug] Route Ch Msg (cl=90, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:46.152] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=57).
[2025-07-15 20:34:46.153] [784] [engine] [trace] AccessRegsSvc::Fsm (id=57).
[2025-07-15 20:34:46.153] [784] [ipc] [trace] Route Ch Msg (cl=90, tag=0, seq=1).
[2025-07-15 20:34:46.153] [784] [ipc] [debug] Route Ch End (cl=90, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:46.153] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=57).
[2025-07-15 20:34:46.155] [784] [ipc] [trace] ~Gateway(cl=90, tag=0, err=null).
[2025-07-15 20:34:46.155] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:46.155] [784] [ipc] [debug] End of client stream - closing connection (id=90, fd=9).
[2025-07-15 20:34:46.155] [784] [ipc] [debug] Pipe is disconnected (cl=90).
[2025-07-15 20:34:47.170] [784] [] [debug] New client connection (id=91, addr='unix:').
[2025-07-15 20:34:47.171] [784] [ipc] [trace] ClientContext(fd=9, id=91).
[2025-07-15 20:34:47.171] [784] [ipc] [debug] Pipe is connected (cl=91).
[2025-07-15 20:34:47.171] [784] [ipc] [debug] Route connect request (cl=91, ver='0.1', err_code=0).
[2025-07-15 20:34:47.171] [784] [ipc] [trace] Gateway(cl=91, tag=0).
[2025-07-15 20:34:47.171] [784] [ipc] [debug] Route Ch Msg (cl=91, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:47.171] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=58).
[2025-07-15 20:34:47.171] [784] [engine] [trace] AccessRegsSvc::Fsm (id=58).
[2025-07-15 20:34:47.172] [784] [ipc] [trace] Route Ch Msg (cl=91, tag=0, seq=1).
[2025-07-15 20:34:47.172] [784] [ipc] [debug] Route Ch End (cl=91, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:47.172] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=58).
[2025-07-15 20:34:47.174] [784] [ipc] [trace] ~Gateway(cl=91, tag=0, err=null).
[2025-07-15 20:34:47.174] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:47.174] [784] [ipc] [debug] End of client stream - closing connection (id=91, fd=9).
[2025-07-15 20:34:47.174] [784] [ipc] [debug] Pipe is disconnected (cl=91).
[2025-07-15 20:34:48.195] [784] [] [debug] New client connection (id=92, addr='unix:').
[2025-07-15 20:34:48.195] [784] [ipc] [trace] ClientContext(fd=9, id=92).
[2025-07-15 20:34:48.195] [784] [ipc] [debug] Pipe is connected (cl=92).
[2025-07-15 20:34:48.195] [784] [ipc] [trace] Msg payload read is not ready (fd=9).
[2025-07-15 20:34:48.196] [784] [ipc] [debug] Route connect request (cl=92, ver='0.1', err_code=0).
[2025-07-15 20:34:48.196] [784] [ipc] [trace] Gateway(cl=92, tag=0).
[2025-07-15 20:34:48.196] [784] [ipc] [debug] Route Ch Msg (cl=92, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:48.196] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=59).
[2025-07-15 20:34:48.196] [784] [engine] [trace] AccessRegsSvc::Fsm (id=59).
[2025-07-15 20:34:48.196] [784] [ipc] [trace] Route Ch Msg (cl=92, tag=0, seq=1).
[2025-07-15 20:34:48.197] [784] [ipc] [debug] Route Ch End (cl=92, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:48.197] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=59).
[2025-07-15 20:34:50.196] [784] [ipc] [debug] Route Ch End (cl=92, tag=0, keep_alive=false, err=null).
[2025-07-15 20:34:50.196] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=false)) (fsm_id=59).
[2025-07-15 20:34:50.196] [784] [engine] [warning] AccessRegsSvc: canceling processing (fsm_id=59).
[2025-07-15 20:34:50.196] [784] [ipc] [trace] ~Gateway(cl=92, tag=0, err=null).
[2025-07-15 20:34:50.196] [784] [ipc] [debug] Zero bytes of msg header read - end of stream (fd=9).
[2025-07-15 20:34:50.196] [784] [ipc] [debug] End of client stream - closing connection (id=92, fd=9).
[2025-07-15 20:34:50.196] [784] [ipc] [debug] Pipe is disconnected (cl=92).
[2025-07-15 20:34:51.217] [784] [] [debug] New client connection (id=93, addr='unix:').
[2025-07-15 20:34:51.217] [784] [ipc] [trace] ClientContext(fd=9, id=93).
[2025-07-15 20:34:51.217] [784] [ipc] [debug] Pipe is connected (cl=93).
[2025-07-15 20:34:51.218] [784] [ipc] [debug] Route connect request (cl=93, ver='0.1', err_code=0).
[2025-07-15 20:34:51.218] [784] [ipc] [trace] Gateway(cl=93, tag=0).
[2025-07-15 20:34:51.218] [784] [ipc] [debug] Route Ch Msg (cl=93, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:51.218] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=60).
[2025-07-15 20:34:51.218] [784] [engine] [trace] AccessRegsSvc::Fsm (id=60).
[2025-07-15 20:34:51.218] [784] [ipc] [trace] Route Ch Msg (cl=93, tag=0, seq=1).
[2025-07-15 20:34:51.218] [784] [ipc] [debug] Route Ch End (cl=93, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:51.218] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=60).
[2025-07-15 20:34:51.221] [784] [ipc] [trace] ~Gateway(cl=93, tag=0, err=null).
[2025-07-15 20:34:51.222] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:51.222] [784] [ipc] [debug] End of client stream - closing connection (id=93, fd=9).
[2025-07-15 20:34:51.222] [784] [ipc] [debug] Pipe is disconnected (cl=93).
[2025-07-15 20:34:52.235] [784] [] [debug] New client connection (id=94, addr='unix:').
[2025-07-15 20:34:52.236] [784] [ipc] [trace] ClientContext(fd=9, id=94).
[2025-07-15 20:34:52.236] [784] [ipc] [debug] Pipe is connected (cl=94).
[2025-07-15 20:34:52.236] [784] [ipc] [debug] Route connect request (cl=94, ver='0.1', err_code=0).
[2025-07-15 20:34:52.236] [784] [ipc] [trace] Gateway(cl=94, tag=0).
[2025-07-15 20:34:52.236] [784] [ipc] [debug] Route Ch Msg (cl=94, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:52.236] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=61).
[2025-07-15 20:34:52.236] [784] [engine] [trace] AccessRegsSvc::Fsm (id=61).
[2025-07-15 20:34:52.237] [784] [ipc] [trace] Route Ch Msg (cl=94, tag=0, seq=1).
[2025-07-15 20:34:52.237] [784] [ipc] [debug] Route Ch End (cl=94, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:52.237] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=61).
[2025-07-15 20:34:52.238] [784] [ipc] [trace] ~Gateway(cl=94, tag=0, err=null).
[2025-07-15 20:34:52.239] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:52.239] [784] [ipc] [debug] End of client stream - closing connection (id=94, fd=9).
[2025-07-15 20:34:52.239] [784] [ipc] [debug] Pipe is disconnected (cl=94).
[2025-07-15 20:34:53.254] [784] [] [debug] New client connection (id=95, addr='unix:').
[2025-07-15 20:34:53.254] [784] [ipc] [trace] ClientContext(fd=9, id=95).
[2025-07-15 20:34:53.254] [784] [ipc] [debug] Pipe is connected (cl=95).
[2025-07-15 20:34:53.254] [784] [ipc] [debug] Route connect request (cl=95, ver='0.1', err_code=0).
[2025-07-15 20:34:53.254] [784] [ipc] [trace] Gateway(cl=95, tag=0).
[2025-07-15 20:34:53.254] [784] [ipc] [debug] Route Ch Msg (cl=95, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:53.255] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=62).
[2025-07-15 20:34:53.255] [784] [engine] [trace] AccessRegsSvc::Fsm (id=62).
[2025-07-15 20:34:53.255] [784] [ipc] [trace] Route Ch Msg (cl=95, tag=0, seq=1).
[2025-07-15 20:34:53.255] [784] [ipc] [debug] Route Ch End (cl=95, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:53.255] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=62).
[2025-07-15 20:34:53.256] [784] [ipc] [trace] ~Gateway(cl=95, tag=0, err=null).
[2025-07-15 20:34:53.256] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:53.256] [784] [ipc] [debug] End of client stream - closing connection (id=95, fd=9).
[2025-07-15 20:34:53.256] [784] [ipc] [debug] Pipe is disconnected (cl=95).
[2025-07-15 20:34:54.273] [784] [] [debug] New client connection (id=96, addr='unix:').
[2025-07-15 20:34:54.273] [784] [ipc] [trace] ClientContext(fd=9, id=96).
[2025-07-15 20:34:54.273] [784] [ipc] [debug] Pipe is connected (cl=96).
[2025-07-15 20:34:54.273] [784] [ipc] [debug] Route connect request (cl=96, ver='0.1', err_code=0).
[2025-07-15 20:34:54.273] [784] [ipc] [trace] Gateway(cl=96, tag=0).
[2025-07-15 20:34:54.273] [784] [ipc] [debug] Route Ch Msg (cl=96, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:54.274] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=63).
[2025-07-15 20:34:54.274] [784] [engine] [trace] AccessRegsSvc::Fsm (id=63).
[2025-07-15 20:34:54.274] [784] [ipc] [trace] Route Ch Msg (cl=96, tag=0, seq=1).
[2025-07-15 20:34:54.274] [784] [ipc] [debug] Route Ch End (cl=96, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:54.274] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=63).
[2025-07-15 20:34:54.276] [784] [ipc] [trace] ~Gateway(cl=96, tag=0, err=null).
[2025-07-15 20:34:54.276] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:54.276] [784] [ipc] [debug] End of client stream - closing connection (id=96, fd=9).
[2025-07-15 20:34:54.276] [784] [ipc] [debug] Pipe is disconnected (cl=96).
[2025-07-15 20:34:55.297] [784] [] [debug] New client connection (id=97, addr='unix:').
[2025-07-15 20:34:55.297] [784] [ipc] [trace] ClientContext(fd=9, id=97).
[2025-07-15 20:34:55.297] [784] [ipc] [debug] Pipe is connected (cl=97).
[2025-07-15 20:34:55.297] [784] [ipc] [debug] Route connect request (cl=97, ver='0.1', err_code=0).
[2025-07-15 20:34:55.298] [784] [ipc] [trace] Gateway(cl=97, tag=0).
[2025-07-15 20:34:55.298] [784] [ipc] [debug] Route Ch Msg (cl=97, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:55.298] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=64).
[2025-07-15 20:34:55.298] [784] [engine] [trace] AccessRegsSvc::Fsm (id=64).
[2025-07-15 20:34:55.298] [784] [ipc] [trace] Route Ch Msg (cl=97, tag=0, seq=1).
[2025-07-15 20:34:55.298] [784] [ipc] [debug] Route Ch End (cl=97, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:55.298] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=64).
[2025-07-15 20:34:55.300] [784] [ipc] [trace] ~Gateway(cl=97, tag=0, err=null).
[2025-07-15 20:34:55.301] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:55.301] [784] [ipc] [debug] End of client stream - closing connection (id=97, fd=9).
[2025-07-15 20:34:55.301] [784] [ipc] [debug] Pipe is disconnected (cl=97).
[2025-07-15 20:34:56.314] [784] [] [debug] New client connection (id=98, addr='unix:').
[2025-07-15 20:34:56.314] [784] [ipc] [trace] ClientContext(fd=9, id=98).
[2025-07-15 20:34:56.314] [784] [ipc] [debug] Pipe is connected (cl=98).
[2025-07-15 20:34:56.314] [784] [ipc] [debug] Route connect request (cl=98, ver='0.1', err_code=0).
[2025-07-15 20:34:56.314] [784] [ipc] [trace] Gateway(cl=98, tag=0).
[2025-07-15 20:34:56.315] [784] [ipc] [debug] Route Ch Msg (cl=98, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:56.315] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=65).
[2025-07-15 20:34:56.315] [784] [engine] [trace] AccessRegsSvc::Fsm (id=65).
[2025-07-15 20:34:56.315] [784] [ipc] [trace] Route Ch Msg (cl=98, tag=0, seq=1).
[2025-07-15 20:34:56.315] [784] [ipc] [debug] Route Ch End (cl=98, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:56.315] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=65).
[2025-07-15 20:34:56.316] [784] [ipc] [trace] ~Gateway(cl=98, tag=0, err=null).
[2025-07-15 20:34:56.317] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:56.317] [784] [ipc] [debug] End of client stream - closing connection (id=98, fd=9).
[2025-07-15 20:34:56.317] [784] [ipc] [debug] Pipe is disconnected (cl=98).
[2025-07-15 20:34:57.330] [784] [] [debug] New client connection (id=99, addr='unix:').
[2025-07-15 20:34:57.330] [784] [ipc] [trace] ClientContext(fd=9, id=99).
[2025-07-15 20:34:57.331] [784] [ipc] [debug] Pipe is connected (cl=99).
[2025-07-15 20:34:57.331] [784] [ipc] [debug] Route connect request (cl=99, ver='0.1', err_code=0).
[2025-07-15 20:34:57.331] [784] [ipc] [trace] Gateway(cl=99, tag=0).
[2025-07-15 20:34:57.331] [784] [ipc] [debug] Route Ch Msg (cl=99, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:57.331] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=66).
[2025-07-15 20:34:57.331] [784] [engine] [trace] AccessRegsSvc::Fsm (id=66).
[2025-07-15 20:34:57.331] [784] [ipc] [trace] Route Ch Msg (cl=99, tag=0, seq=1).
[2025-07-15 20:34:57.332] [784] [ipc] [debug] Route Ch End (cl=99, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:57.332] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=66).
[2025-07-15 20:34:57.333] [784] [ipc] [trace] ~Gateway(cl=99, tag=0, err=null).
[2025-07-15 20:34:57.333] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:57.333] [784] [ipc] [debug] End of client stream - closing connection (id=99, fd=9).
[2025-07-15 20:34:57.333] [784] [ipc] [debug] Pipe is disconnected (cl=99).
[2025-07-15 20:34:58.347] [784] [] [debug] New client connection (id=100, addr='unix:').
[2025-07-15 20:34:58.347] [784] [ipc] [trace] ClientContext(fd=9, id=100).
[2025-07-15 20:34:58.347] [784] [ipc] [debug] Pipe is connected (cl=100).
[2025-07-15 20:34:58.347] [784] [ipc] [debug] Route connect request (cl=100, ver='0.1', err_code=0).
[2025-07-15 20:34:58.348] [784] [ipc] [trace] Gateway(cl=100, tag=0).
[2025-07-15 20:34:58.348] [784] [ipc] [debug] Route Ch Msg (cl=100, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:58.348] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=67).
[2025-07-15 20:34:58.348] [784] [engine] [trace] AccessRegsSvc::Fsm (id=67).
[2025-07-15 20:34:58.348] [784] [ipc] [trace] Route Ch Msg (cl=100, tag=0, seq=1).
[2025-07-15 20:34:58.348] [784] [ipc] [debug] Route Ch End (cl=100, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:58.348] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=67).
[2025-07-15 20:34:58.352] [784] [ipc] [trace] ~Gateway(cl=100, tag=0, err=null).
[2025-07-15 20:34:58.352] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:58.352] [784] [ipc] [debug] End of client stream - closing connection (id=100, fd=9).
[2025-07-15 20:34:58.352] [784] [ipc] [debug] Pipe is disconnected (cl=100).
[2025-07-15 20:34:59.373] [784] [] [debug] New client connection (id=101, addr='unix:').
[2025-07-15 20:34:59.373] [784] [ipc] [trace] ClientContext(fd=9, id=101).
[2025-07-15 20:34:59.373] [784] [ipc] [debug] Pipe is connected (cl=101).
[2025-07-15 20:34:59.373] [784] [ipc] [debug] Route connect request (cl=101, ver='0.1', err_code=0).
[2025-07-15 20:34:59.373] [784] [ipc] [trace] Gateway(cl=101, tag=0).
[2025-07-15 20:34:59.373] [784] [ipc] [debug] Route Ch Msg (cl=101, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:34:59.373] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=68).
[2025-07-15 20:34:59.373] [784] [engine] [trace] AccessRegsSvc::Fsm (id=68).
[2025-07-15 20:34:59.373] [784] [ipc] [trace] Route Ch Msg (cl=101, tag=0, seq=1).
[2025-07-15 20:34:59.374] [784] [ipc] [debug] Route Ch End (cl=101, tag=0, keep_alive=true, err=null).
[2025-07-15 20:34:59.374] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=68).
[2025-07-15 20:34:59.375] [784] [ipc] [trace] ~Gateway(cl=101, tag=0, err=null).
[2025-07-15 20:34:59.376] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:34:59.376] [784] [ipc] [debug] End of client stream - closing connection (id=101, fd=9).
[2025-07-15 20:34:59.376] [784] [ipc] [debug] Pipe is disconnected (cl=101).
[2025-07-15 20:35:00.396] [784] [] [debug] New client connection (id=102, addr='unix:').
[2025-07-15 20:35:00.396] [784] [ipc] [trace] ClientContext(fd=9, id=102).
[2025-07-15 20:35:00.396] [784] [ipc] [debug] Pipe is connected (cl=102).
[2025-07-15 20:35:00.397] [784] [ipc] [debug] Route connect request (cl=102, ver='0.1', err_code=0).
[2025-07-15 20:35:00.397] [784] [ipc] [trace] Gateway(cl=102, tag=0).
[2025-07-15 20:35:00.397] [784] [ipc] [debug] Route Ch Msg (cl=102, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:35:00.397] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=69).
[2025-07-15 20:35:00.397] [784] [engine] [trace] AccessRegsSvc::Fsm (id=69).
[2025-07-15 20:35:00.397] [784] [ipc] [trace] Route Ch Msg (cl=102, tag=0, seq=1).
[2025-07-15 20:35:00.397] [784] [ipc] [debug] Route Ch End (cl=102, tag=0, keep_alive=true, err=null).
[2025-07-15 20:35:00.398] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=69).
[2025-07-15 20:35:00.400] [784] [ipc] [trace] ~Gateway(cl=102, tag=0, err=null).
[2025-07-15 20:35:00.401] [784] [ipc] [debug] Connection reset by peer (fd=9).
[2025-07-15 20:35:00.401] [784] [ipc] [debug] End of client stream - closing connection (id=102, fd=9).
[2025-07-15 20:35:00.401] [784] [ipc] [debug] Pipe is disconnected (cl=102).
[2025-07-15 20:35:01.416] [784] [] [debug] New client connection (id=103, addr='unix:').
[2025-07-15 20:35:01.416] [784] [ipc] [trace] ClientContext(fd=9, id=103).
[2025-07-15 20:35:01.416] [784] [ipc] [debug] Pipe is connected (cl=103).
[2025-07-15 20:35:01.416] [784] [ipc] [debug] Route connect request (cl=103, ver='0.1', err_code=0).
[2025-07-15 20:35:01.417] [784] [ipc] [trace] Gateway(cl=103, tag=0).
[2025-07-15 20:35:01.417] [784] [ipc] [debug] Route Ch Msg (cl=103, tag=0, seq=0, srv=0x80FEF6131F8355B9).
[2025-07-15 20:35:01.417] [784] [engine] [debug] New 'ocvsmd.svc.node.access_registers' service channel (fsm=70).
[2025-07-15 20:35:01.417] [784] [engine] [trace] AccessRegsSvc::Fsm (id=70).
[2025-07-15 20:35:01.417] [784] [ipc] [trace] Route Ch Msg (cl=103, tag=0, seq=1).
[2025-07-15 20:35:01.417] [784] [ipc] [debug] Route Ch End (cl=103, tag=0, keep_alive=true, err=null).
[2025-07-15 20:35:01.417] [784] [engine] [debug] AccessRegsSvc::handleEvent(Completed(alive=true)) (fsm_id=70).
[2025-07-15 20:35:03.417] [784] [engine] [warning] ListRegsSvc: RPC promise failure for node 23 (err=TimedOut, fsm_id=70).

phihalip · July 18, 2025, 9:54pm

Created an issue ticket in Github:

github.com/OpenCyphal-Garage/ocvsmd

Daemon Crashes When Encountering Timeout During Register Access

opened 09:54PM - 18 Jul 25 UTC

phihalip

We seem to have found a potential flaw in the OCVSMD daemon cleanup code that ca…uses it to crash when we probe a node’s register and receive a timeout error. The specific scenario we’ve encountered this is when the we try to probe the node’s status register to get the status of a software update WHILE the node is updating, which prevents it from responding in time and causes the daemon reach timeout while waiting for a response. Some time afterwards, the OCVSMD code tries to access an object that was prematurely cleaned up due to the timeout and causes the daemon to crash. Here’s the full backtrace we pulled from the crashed daemon using GDB: [backtrace_ocvsmd.txt](https://github.com/user-attachments/files/21323251/backtrace_ocvsmd.txt) Here’s the server logs we found after the daemon had crashed: [Server Log Crash.txt](https://github.com/user-attachments/files/21323248/Server.Log.Crash.txt)