qa: Intermittent failure in `interface_zmq.py` #34189

issue hebasto opened this issue on January 2, 2026

hebasto commented at 11:43 AM on January 2, 2026: member

On NetBSD 10.1, https://github.com/hebasto/bitcoin-core-nightly/actions/runs/20650397747/job/59294288757:

83/282 - interface_zmq.py failed, Duration: 24 s

stdout:
2026-01-02T07:12:07.928049Z TestFramework (INFO): PRNG seed is: 38669556040563964
2026-01-02T07:12:07.929628Z TestFramework (INFO): Initializing test directory /home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test_runner_₿_🏃_20260102_070533/interface_zmq_208
2026-01-02T07:12:08.575045Z TestFramework (INFO): Running basic test with tcp protocol
2026-01-02T07:12:09.507193Z TestFramework (INFO): Generate 5 blocks (and 5 coinbase txes)
2026-01-02T07:12:09.530057Z TestFramework (INFO): Wait for tx from second node
2026-01-02T07:12:10.562029Z TestFramework (INFO): Test the getzmqnotifications RPC
2026-01-02T07:12:10.564742Z TestFramework (INFO): Running basic test with ipc protocol
2026-01-02T07:12:11.856205Z TestFramework (INFO): Generate 5 blocks (and 5 coinbase txes)
2026-01-02T07:12:12.058310Z TestFramework (INFO): Wait for tx from second node
2026-01-02T07:12:13.083968Z TestFramework (INFO): Test the getzmqnotifications RPC
2026-01-02T07:12:13.086669Z TestFramework (INFO): Testing 'sequence' publisher
2026-01-02T07:12:14.885021Z TestFramework (INFO): Wait for tx from second node
2026-01-02T07:12:15.908518Z TestFramework (INFO): Testing sequence notifications with mempool sequence values
2026-01-02T07:12:15.908753Z TestFramework (INFO): Testing RBF notification
2026-01-02T07:12:18.053138Z TestFramework (INFO): Testing reorg notifications
2026-01-02T07:12:21.179247Z TestFramework (INFO): Evict mempool transaction by block conflict
2026-01-02T07:12:21.227439Z TestFramework (INFO): Testing 'mempool sync' usage of sequence notifier
2026-01-02T07:12:31.964971Z TestFramework (ERROR): Unexpected exception
Traceback (most recent call last):
  File "/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test/functional/test_framework/test_framework.py", line 142, in main
    self.run_test()
    ~~~~~~~~~~~~~^^
  File "/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/build/test/functional/interface_zmq.py", line 130, in run_test
    self.test_reorg()
    ~~~~~~~~~~~~~~~^^
  File "/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/build/test/functional/interface_zmq.py", line 291, in test_reorg
    assert_equal(self.nodes[1].getbestblockhash(), hashblock.receive().hex())
                                                   ~~~~~~~~~~~~~~~~~^^
  File "/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/build/test/functional/interface_zmq.py", line 70, in receive
    return self._receive_from_publisher_and_check()
           ~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~^^
  File "/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/build/test/functional/interface_zmq.py", line 57, in _receive_from_publisher_and_check
    topic, body, seq = self.socket.recv_multipart()
                       ~~~~~~~~~~~~~~~~~~~~~~~~~~^^
  File "/usr/pkg/lib/python3.13/site-packages/zmq/sugar/socket.py", line 799, in recv_multipart
    parts = [self.recv(flags, copy=copy, track=track)]
             ~~~~~~~~~^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
  File "zmq/backend/cython/_zmq.py", line 1218, in zmq.backend.cython._zmq.Socket.recv
  File "zmq/backend/cython/_zmq.py", line 1253, in zmq.backend.cython._zmq.Socket.recv
  File "zmq/backend/cython/_zmq.py", line 1413, in zmq.backend.cython._zmq._recv_copy
  File "zmq/backend/cython/_zmq.py", line 1408, in zmq.backend.cython._zmq._recv_copy
  File "zmq/backend/cython/_zmq.py", line 186, in zmq.backend.cython._zmq._check_rc
zmq.error.Again: Resource temporarily unavailable
2026-01-02T07:12:32.029675Z TestFramework (INFO): Not stopping nodes as test failed. The dangling processes will be cleaned up later.
2026-01-02T07:12:32.029851Z TestFramework (WARNING): Not cleaning up dir /home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test_runner_₿_🏃_20260102_070533/interface_zmq_208
2026-01-02T07:12:32.029981Z TestFramework (ERROR): Test failed. Test logging available at /home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test_runner_₿_🏃_20260102_070533/interface_zmq_208/test_framework.log
2026-01-02T07:12:32.030241Z TestFramework (ERROR): 
2026-01-02T07:12:32.030452Z TestFramework (ERROR): Hint: Call /home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test/functional/combine_logs.py '/home/runner/work/bitcoin-core-nightly/bitcoin-core-nightly/test_runner_₿_🏃_20260102_070533/interface_zmq_208' to consolidate all logs
2026-01-02T07:12:32.030546Z TestFramework (ERROR): 
2026-01-02T07:12:32.030632Z TestFramework (ERROR): If this failure happened unexpectedly or intermittently, please file a bug and provide a link or upload of the combined log.
2026-01-02T07:12:32.030825Z TestFramework (ERROR): https://github.com/bitcoin/bitcoin/issues
2026-01-02T07:12:32.030973Z TestFramework (ERROR): 


stderr:
[node 1] Cleaning up leftover process
[node 0] Cleaning up leftover process

hebasto added the label RPC/REST/ZMQ on Jan 5, 2026
Hijanhv referenced this in commit 7777691e06 on Feb 5, 2026
Hijanhv referenced this in commit 3acb8d93ea on Feb 11, 2026
Hijanhv referenced this in commit 1d98f423e2 on Feb 11, 2026
Hijanhv referenced this in commit 1257527ccc on Feb 11, 2026
Hijanhv referenced this in commit 6ef00c23bd on Feb 12, 2026
Hijanhv referenced this in commit 8e57b4e519 on Feb 12, 2026
Hijanhv commented at 10:46 AM on February 13, 2026: none

@hebasto please review my pr
fanquake added the label CI failed on Feb 27, 2026
fanquake commented at 12:28 PM on February 27, 2026: member

Has this happened again? Is there a reproducer?
l0rinc commented at 12:38 PM on February 27, 2026: contributor

It did fail in https://github.com/bitcoin/bitcoin/actions/runs/22481350032/job/65120077395, but it's probably related to #34503
fanquake commented at 12:39 PM on February 27, 2026: member

That isn't related to this report.

maflcko commented at 12:52 PM on February 27, 2026: member

Yes, I think this is real. It can be reproduced via:

diff --git a/src/validationinterface.cpp b/src/validationinterface.cpp
index c7be6abc3a..4cb8435cef 100644
--- a/src/validationinterface.cpp
+++ b/src/validationinterface.cpp
@@ -12,6 +12,7 @@
 #include <kernel/types.h>
 #include <primitives/block.h>
 #include <primitives/transaction.h>
+#include <random.h>
 #include <util/check.h>
 #include <util/log.h>
 #include <util/task_runner.h>
@@ -154,6 +155,8 @@ void ValidationSignals::SyncWithValidationInterfaceQueue()
     promise.get_future().wait();
 }
 
+static FastRandomContext g_rnd{};
+
 // Use a macro instead of a function for conditional logging to prevent
 // evaluating arguments when logging is not enabled.
 //
@@ -164,6 +167,7 @@ void ValidationSignals::SyncWithValidationInterfaceQueue()
         LOG_EVENT("Enqueuing " fmt, local_name, __VA_ARGS__);  \
         m_internals->m_task_runner->insert([=] { \
             LOG_EVENT(fmt, local_name, __VA_ARGS__);           \
+            UninterruptibleSleep(1ms * g_rnd.randrange(95));   \
             event();                                           \
         });                                                    \
     } while (0)
diff --git a/test/functional/interface_zmq.py b/test/functional/interface_zmq.py
index 6717007626..c29f2a98ef 100755
--- a/test/functional/interface_zmq.py
+++ b/test/functional/interface_zmq.py
@@ -174,7 +174,7 @@ class ZMQTest (BitcoinTestFramework):
 
         # set subscriber's desired timeout for the test
         for sub in subscribers:
-            sub.socket.set(zmq.RCVTIMEO, recv_timeout*1000)
+            sub.socket.set(zmq.RCVTIMEO, int(recv_timeout*1000))
 
         self.connect_nodes(0, 1)
         if sync_blocks:
@@ -269,7 +269,7 @@ class ZMQTest (BitcoinTestFramework):
         # Should only notify the tip if a reorg occurs
         hashblock, hashtx = self.setup_zmq_test(
             [(topic, address) for topic in ["hashblock", "hashtx"]],
-            recv_timeout=2)  # 2 second timeout to check end of notifications
+            recv_timeout=0.001)  # 2 second timeout to check end of notifications
         self.disconnect_nodes(0, 1)
 
         # Generate 1 block in nodes[0] with 1 mempool tx and receive all notifications

achow101 added this to the milestone 31.0 on Feb 27, 2026
achow101 closed this on Feb 27, 2026
achow101 referenced this in commit 9cad97f6cd on Feb 27, 2026

Contributors

Labels

RPC/REST/ZMQ CI failed

Milestone
31.0

Linked (view graph)

#34508 test: fix intermittent failure in interface_zmq.py #34557 test: fix intermittent failure in interface_zmq.py #34574 fix intermittent failure in interface_zmq.py #34594 fix flaky zmq test that randomly fails on recv #34690 test: Add missing timeout_factor to zmq socket