NOMERGE DEBUG WIP ignore #33028

maflcko commented at 10:39 AM on July 21, 2025: member

No description provided.

NOMERGE DEBUG WIP ignore d0dd8d47f9

DrahtBot commented at 10:39 AM on July 21, 2025: contributor

The following sections might be updated with supplementary metadata relevant to reviewers and maintainers.

Code Coverage & Benchmarks

For details see: https://corecheck.dev/bitcoin/bitcoin/pulls/33028.

Reviews

See the guideline for information on the review process. A summary of reviews will appear here.

Conflicts

No conflicts as of last run.

Revert "NOMERGE DEBUG WIP ignore"

This reverts commit d0dd8d47f9e68646a892b959db1a487063710305.

8003185aec

DrahtBot added the label CI failed on Jul 23, 2025

maflcko commented at 8:26 PM on July 24, 2025: member

this is just too difficult to reproduce

maflcko closed this on Jul 24, 2025

maflcko deleted the branch on Jul 24, 2025

in src/common/run_command.cpp:29 in d0dd8d47f9 outdated

  24 | @@ -24,11 +25,15 @@ UniValue RunCommandParseJSON(const std::string& str_command, const std::string&
  25 |  
  26 |      if (str_command.empty()) return UniValue::VNULL;
  27 |  
  28 | +    LogWarning("cmd='%s'; std_in='%s'", str_command, str_std_in);
  29 |      auto c = sp::Popen(str_command, sp::input{sp::PIPE}, sp::output{sp::PIPE}, sp::error{sp::PIPE}, sp::close_fds{true});

maflcko commented at 8:38 PM on July 24, 2025:

It just reproduced. i guess the deadlock happens inside Popen, as there are no logs lines after this one:

./test/functional/combine_logs.py /ci_container_base/ci/scratch/test_runner/test_runner_₿_🏃_20250724_203021/rpc_signer_0/ | grep -C3 'warning'
 test  2025-07-24T20:30:49.464060Z TestFramework.bitcoincli (DEBUG): Running bitcoin-cli ['-datadir=/ci_container_base/ci/scratch/test_runner/test_runner_₿_🏃_20250724_203021/rpc_signer_0/node3', 'enumeratesigners'] 
 node3 2025-07-24T20:30:49.490680Z [http] [httpserver.cpp:308] [void http_request_cb(struct evhttp_request *, void *)] [http] Received a POST request for / from 127.0.0.1:33846 
 node3 2025-07-24T20:30:49.492128Z [httpworker.6] [rpc/request.cpp:243] [void JSONRPCRequest::parse(const UniValue &)] [rpc] ThreadRPCServer method=enumeratesigners user=__cookie__ 
 node3 2025-07-24T20:30:49.493232Z [httpworker.6] [common/run_command.cpp:28] [UniValue RunCommandParseJSON(const std::string &, const std::string &)] [warning] cmd='fake.py enumerate'; std_in='' 
 test  2025-07-24T20:30:49.535768Z TestFramework.bitcoincli (DEBUG): Running bitcoin-cli ['-datadir=/ci_container_base/ci/scratch/test_runner/test_runner_₿_🏃_20250724_203021/rpc_signer_0/node1', 'enumeratesigners'] 
 node1 2025-07-24T20:30:49.574899Z [http] [httpserver.cpp:308] [void http_request_cb(struct evhttp_request *, void *)] [http] Received a POST request for / from 127.0.0.1:50128 
 node1 2025-07-24T20:30:49.577214Z [httpworker.2] [rpc/request.cpp:243] [void JSONRPCRequest::parse(const UniValue &)] [rpc] ThreadRPCServer method=enumeratesigners user=__cookie__ 
 node1 2025-07-24T20:30:49.578193Z [httpworker.2] [common/run_command.cpp:28] [UniValue RunCommandParseJSON(const std::string &, const std::string &)] [warning] cmd='/usr/bin/python3 /ci_container_base/test/functional/mocks/signer.py enumerate'; std_in='' 
 node0 2025-07-24T20:30:50.820025Z [msghand] [logging/timer.h:58] [void BCLog::Timer<std::chrono::duration<long long, std::ratio<1, 1000000>>>::Log(const std::string &) [TimeType = std::chrono::duration<long long, std::ratio<1, 1000000>>]] [lock] Enter: lock contention connman.m_nodes_mutex, net.h:1648 started 
 node0 2025-07-24T20:30:50.822652Z [msghand] [logging/timer.h:58] [void BCLog::Timer<std::chrono::duration<long long, std::ratio<1, 1000000>>>::Log(const std::string &) [TimeType = std::chrono::duration<long long, std::ratio<1, 1000000>>]] [lock] Enter: lock contention connman.m_nodes_mutex, net.h:1648 completed (2304μs) 
 node3 2025-07-24T20:30:51.944591Z [msghand] [logging/timer.h:58] [void BCLog::Timer<std::chrono::duration<long long, std::ratio<1, 1000000>>>::Log(const std::string &) [TimeType = std::chrono::duration<long long, std::ratio<1, 1000000>>]] [lock] Enter: lock contention connman.m_nodes_mutex, net.h:1648 started

maflcko commented at 8:46 PM on July 24, 2025:

Same bt as in #32524 (comment):

Thread 33 (Thread 0xf5933b40 (LWP 2485619) "b-httpworker.2"):
[#0](/bitcoin-bitcoin/0/)  0xf7f8e589 in __kernel_vsyscall ()
[#1](/bitcoin-bitcoin/1/)  0xf7aaeac7 in read () from /lib32/libc.so.6
[#2](/bitcoin-bitcoin/2/)  0x57dae8b6 in subprocess::util::read_atmost_n (fp=0x595e06d0, buf=0xf59305e4 "", read_upto=1024) at ./util/subprocess.h:437
[#3](/bitcoin-bitcoin/3/)  0x57dc2e19 in subprocess::Popen::execute_process (this=0xf5930cd8) at ./util/subprocess.h:1247
[#4](/bitcoin-bitcoin/4/)  0x57daf434 in subprocess::Popen::Popen<subprocess::input, subprocess::output, subprocess::error, subprocess::close_fds> (this=0xf5930cd8, cmd_args="/usr/bin/python3 /ci_container_base/test/functional/mocks/signer.py enumerate", args=..., args=..., args=..., args=...) at ./util/subprocess.h:964
[#5](/bitcoin-bitcoin/5/)  0x57dad600 in RunCommandParseJSON (str_command="/usr/bin/python3 /ci_container_base/test/functional/mocks/signer.py enumerate", str_std_in="") at ./common/run_command.cpp:29
[#6](/bitcoin-bitcoin/6/)  0x57ad2547 in ExternalSigner::Enumerate (command="/usr/bin/python3 /ci_container_base/test/functional/mocks/signer.py", signers=std::__debug::vector of length 0, capacity 0, chain="regtest") at ./external_signer.cpp:28
[#7](/bitcoin-bitcoin/7/)  0x56e31dab in enumeratesigners()::$_0::operator()(RPCHelpMan const&, JSONRPCRequest const&) const (this=0xf5931ba0, self=..., request=...) at ./rpc/external_signer.cpp:51