[PERF] UTBot consumes CPU in spinlocks

[alexey-utkin]

Description
utbot always high cpu

PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND
76423 root 20 0 326360 132448 53944 R 99.9 0.0 906:58.32 grpcpp_sync_ser
77189 root 20 0 326360 132448 53944 R 99.7 0.0 906:47.70 grpcpp_sync_ser

Thread 1 (process 77189):
#0 0x00007feef3a02dd7 in sched_yield () from /root/data/utbot/utbot_distr/server-install/../lib/libc.so.6
#1 0x00000000010a82a9 in __gthread_yield () at /usr/lib/gcc/x86_64-linux-gnu/9/../../../../include/x86_64-linux-gnu/c++/9/bits/gthr-default.h:693
#2 yield () at /usr/lib/gcc/x86_64-linux-gnu/9/../../../../include/c++/9/thread:356
#3 Server::TestsGenServiceImpl::provideLoggingCallbacks(std::__cxx11::basic_string<char, std::char_traits, std::allocator > const&, grpc_impl::ServerWritertestsgen::LogEntry, std::__cxx11::basic_string<char, std::char_traits, std::allocator > const&, void ()(void*, loguru::Message const&), std::map<std::__cxx11::basic_string<char, std::char_traits, std::allocator >, std::atomic, std::less<std::__cxx11::basic_string<char, std::char_traits, std::allocator > >, std::allocator<std::pair<std::__cxx11::basic_string<char, std::char_traits, std::allocator > const, std::atomic > > >&, bool) (this=, callbackPrefix=..., writer=, logLevel=..., handler=0x10a7790 <Server::gtestLog(void*, loguru::Message const&)>, channelStorage=..., openFiles=false) at ../src/Server.cpp:415
#4 0x00000000010a881a in Server::TestsGenServiceImpl::OpenGTestChannel(grpc_impl::ServerContext*, testsgen::LogChannelRequest const*, grpc_impl::ServerWritertestsgen::LogEntry) (this=0x7ffe621671a0, context=, request=0x7780e70, writer=0x7feef3a02dd7 <sched_yield+7>) at ../src/Server.cpp:448
#5 0x00000000011bb3c6 in operator() (this=, service=0x7feef04b5290, ctx=0x13, req=0x7feef3a02dd7 <sched_yield+7>, writer=0x0) at protobuf/testgen.grpc.pb.cc:637
#6 std::_Function_handler<grpc::Status (testsgen::TestsGenService::Service, grpc_impl::ServerContext*, testsgen::LogChannelRequest const*, grpc_impl::ServerWritertestsgen::LogEntry), testsgen::TestsGenService::Service::ServerWriter()::$_4>::_M_invoke(std::_Any_data const&, testsgen::TestsGenService::Service&&, grpc_impl::ServerContext*&&, testsgen::LogChannelRequest const*&&, grpc_impl::ServerWritertestsgen::LogEntry&&) (__functor=..., __args=<unknown type in /root/data/utbot/utbot_distr/server-install/utbot, CU 0x2b5d3cb, DIE 0x2cfe3cf>, __args=<unknown type in /root/data/utbot/utbot_distr/server-install/utbot, CU 0x2b5d3cb, DIE 0x2cfe3cf>, __args=<unknown type in /root/data/utbot/utbot_distr/server-install/utbot, CU 0x2b5d3cb, DIE 0x2cfe3cf>, __args=<unknown type in /root/data/utbot/utbot_distr/server-install/utbot, CU 0x2b5d3cb, DIE 0x2cfe3cf>) at /usr/lib/gcc/x86_64-linux-gnu/9/../../../../include/c++/9/bits/std_function.h:285
#7 0x000000000120974e in operator() (this=0x8, __args=0x7feef04b5510, __args=0x7feef04b5510, __args=0x7feef04b5510, __args=0x7feef04b5510) at /usr/lib/gcc/x86_64-linux-gnu/9/../../../../include/c++/9/bits/std_function.h:688
#8 operator() (this=) at /utbot_distr/install/include/grpcpp/impl/codegen/method_handler_impl.h:191
#9 grpc_impl::internal::CatchingFunctionHandler<grpc_impl::internal::ServerStreamingHandler<testsgen::TestsGenService::Service, testsgen::LogChannelRequest, testsgen::LogEntry>::RunHandler(grpc::internal::MethodHandler::HandlerParameter const&)::{lambda()#1}>(grpc_impl::internal::ServerStreamingHandler<testsgen::TestsGenService::Service, testsgen::LogChannelRequest, testsgen::LogEntry>::RunHandler(grpc::internal::MethodHandler::HandlerParameter const&)::{lambda()#1}&&) (handler=) at /utbot_distr/install/include/grpcpp/impl/codegen/method_handler_impl.h:42
#10 0x0000000001208e6e in grpc_impl::internal::ServerStreamingHandler<testsgen::TestsGenService::Service, testsgen::LogChannelRequest, testsgen::LogEntry>::RunHandler(grpc::internal::MethodHandler::HandlerParameter const&) (this=0x765b590, param=...) at /utbot_distr/install/include/grpcpp/impl/codegen/method_handler_impl.h:190
#11 0x00000000025afddc in grpc_impl::Server::SyncRequest::CallData::ContinueRunAfterInterception() ()
#12 0x00000000025afbf7 in grpc_impl::Server::SyncRequest::CallData::Run(std::shared_ptr<grpc_impl::Server::GlobalCallbacks> const&, bool) ()
#13 0x00000000025b0359 in grpc_impl::Server::SyncRequestThreadManager::DoWork(void, bool, bool) ()
#14 0x00000000025c97b5 in grpc::ThreadManager::MainWorkLoop() ()
#15 0x00000000025c8d0b in grpc::ThreadManager::WorkerThread::Run() ()
#16 0x00000000025c8ba6 in ZZN4grpc13ThreadManager12WorkerThreadC4EPS0_ENKUlPvE_clES3 ()
#17 0x00000000025c8bc6 in ZZN4grpc13ThreadManager12WorkerThreadC4EPS0_ENUlPvE_4_FUNES3 ()
#18 0x00000000029876b1 in ZZN9grpc_core12_GLOBAL__N_120ThreadInternalsPosixC4EPKcPFvPvES4_PbRKNS_6Thread7OptionsEENKUlS4_E_clES4 ()
#19 0x00000000029876fb in ZZN9grpc_core12_GLOBAL__N_120ThreadInternalsPosixC4EPKcPFvPvES4_PbRKNS_6Thread7OptionsEENUlS4_E_4_FUNES4 ()
#20 0x00007feef6e116db in start_thread () from /root/data/utbot/utbot_distr/server-install/../lib/libpthread.so.0
#21 0x00007feef3a2061f in clone () from /root/data/utbot/utbot_distr/server-install/../lib/libc.so.6

[alexey-utkin]

I see the questionable code in

Status Server::TestsGenServiceImpl::provideLoggingCallbacks(
    const std::string &callbackPrefix,
    ServerWriter<LogEntry> *writer,
    const std::string &logLevel,
    loguru::log_handler_t handler,
    std::map<std::string, std::atomic_bool> &channelStorage,
    bool openFiles)

the suspicious fragment is

        while (holdLockFlag[callbackName].exchange(true, std::memory_order_acquire)) {
            std::this_thread::yield();
        }