feature_pruning intermittent failure #16614

issue MarcoFalke opened this issue on August 14, 2019
  1. MarcoFalke commented at 5:18 PM on August 14, 2019: member

    Node 3 fails to shut down after creating the big chain. Note that the nodes are successfully synced.

    commit b499d8576f30d13dfe9000852afe47ee1c28cfbe (current master)

    CPU: Cortex-A53 Storage: USB thumb drive (ext4)

    Excerpt:

    node0 2019-08-14T06:29:37.079325Z [httpworker.0] ThreadRPCServer method=getbestblockhash user=__cookie__ 
     node1 2019-08-14T06:29:37.083038Z [http] Received a POST request for / from 127.0.0.1:33462 
     node1 2019-08-14T06:29:37.083290Z [httpworker.2] ThreadRPCServer method=getbestblockhash user=__cookie__ 
     node2 2019-08-14T06:29:37.086935Z [http] Received a POST request for / from 127.0.0.1:53415 
     node2 2019-08-14T06:29:37.087197Z [httpworker.2] ThreadRPCServer method=getbestblockhash user=__cookie__ 
     node3 2019-08-14T06:29:37.090709Z [http] Received a POST request for / from 127.0.0.1:53069 
     node3 2019-08-14T06:29:37.090965Z [httpworker.0] ThreadRPCServer method=getbestblockhash user=__cookie__ 
     node4 2019-08-14T06:29:37.094709Z [http] Received a POST request for / from 127.0.0.1:38946 
     node4 2019-08-14T06:29:37.094986Z [httpworker.3] ThreadRPCServer method=getbestblockhash user=__cookie__ 
     test  2019-08-14T06:29:37.096000Z TestFramework.node3 (DEBUG): Stopping node 
     node3 2019-08-14T06:29:37.098496Z [http] Received a POST request for / from 127.0.0.1:53069 
     node3 2019-08-14T06:29:37.098716Z [httpworker.1] ThreadRPCServer method=stop user=__cookie__ 
     node3 2019-08-14T06:29:37.253095Z [init] Interrupting HTTP server 
     node3 2019-08-14T06:29:37.253290Z [init] Interrupting HTTP RPC server 
     node3 2019-08-14T06:29:37.253334Z [init] Interrupting RPC 
     node3 2019-08-14T06:29:37.253394Z [init] Shutdown: In progress... 
     node3 2019-08-14T06:29:37.253453Z [addcon] addcon thread exit 
     node3 2019-08-14T06:29:37.253553Z [shutoff] Stopping HTTP RPC server 
     node3 2019-08-14T06:29:37.253600Z [shutoff] Unregistering HTTP handler for / (exactmatch 1) 
     node3 2019-08-14T06:29:37.253639Z [shutoff] Unregistering HTTP handler for /wallet/ (exactmatch 0) 
     node3 2019-08-14T06:29:37.253675Z [shutoff] Stopping RPC 
     node3 2019-08-14T06:29:37.254002Z [shutoff] RPC stopped. 
     node3 2019-08-14T06:29:37.254039Z [shutoff] Stopping HTTP server 
     node3 2019-08-14T06:29:37.254071Z [shutoff] Waiting for HTTP worker threads to exit 
     node3 2019-08-14T06:29:37.254254Z [shutoff] Waiting for HTTP event thread to exit 
     node3 2019-08-14T06:29:37.254307Z [http] Exited http event loop 
     node3 2019-08-14T06:29:37.254421Z [opencon] opencon thread exit 
     node3 2019-08-14T06:29:37.254505Z [shutoff] Stopped HTTP server 
     node3 2019-08-14T06:29:37.254556Z [shutoff] BerkeleyEnvironment::Flush: [/media/root/d33157a4-698b-4041-9228-773d8c578807/test_runner_root_001/test_runner_₿_🏃_20190814_061943/feature_pruning_126/node3/regtest/wallets] Flush(false) 
     node3 2019-08-14T06:29:37.254593Z [shutoff] BerkeleyEnvironment::Flush: Flush(false) took               0ms 
     node3 2019-08-14T06:29:37.277901Z [msghand] msghand thread exit 
     node3 2019-08-14T06:29:37.296390Z [net] net thread exit 
     node0 2019-08-14T06:29:47.791668Z [msghand] sending ping (8 bytes) peer=0 
     node1 2019-08-14T06:29:48.296300Z [msghand] received: ping (8 bytes) peer=0 
     node1 2019-08-14T06:29:48.296416Z [msghand] sending pong (8 bytes) peer=0 
     node0 2019-08-14T06:29:48.296818Z [msghand] sending ping (8 bytes) peer=1 
     node2 2019-08-14T06:29:48.297144Z [msghand] received: ping (8 bytes) peer=1 
     node0 2019-08-14T06:29:48.297146Z [msghand] sending ping (8 bytes) peer=2 
     node2 2019-08-14T06:29:48.297283Z [msghand] sending pong (8 bytes) peer=1 
     node0 2019-08-14T06:29:48.297308Z [msghand] sending ping (8 bytes) peer=3 
     node0 2019-08-14T06:29:48.297675Z [msghand] received: pong (8 bytes) peer=0 
     node0 2019-08-14T06:29:48.297778Z [msghand] received: pong (8 bytes) peer=1 
     node4 2019-08-14T06:29:48.297926Z [msghand] received: ping (8 bytes) peer=0 
     node4 2019-08-14T06:29:48.298011Z [msghand] sending pong (8 bytes) peer=0 
     node0 2019-08-14T06:29:48.298324Z [msghand] received: pong (8 bytes) peer=3 
     node3 2019-08-14T06:29:48.331208Z [shutoff] Flushed 0 addresses to peers.dat  11035ms 
     node3 2019-08-14T06:29:48.331290Z [shutoff] disconnecting peer=0 
     node3 2019-08-14T06:29:48.331453Z [shutoff] Cleared nodestate for peer=0 
     node0 2019-08-14T06:29:48.331708Z [net] socket recv error Connection reset by peer (104) 
     node0 2019-08-14T06:29:48.331764Z [net] disconnecting peer=2 
     node3 2019-08-14T06:29:48.331825Z [scheduler] scheduler thread interrupt 
     node0 2019-08-14T06:29:48.331846Z [net] Cleared nodestate for peer=2 
     test  2019-08-14T06:30:37.184000Z TestFramework.utils (ERROR): wait_until() failed. Predicate: '''' 
                                           def is_node_stopped(self):
                                               """Checks whether the node has stopped.
                                               Returns True if the node has stopped. False otherwise.
                                               This method is responsible for freeing resources (self.process)."""
                                               if not self.running:
                                                   return True
                                               return_code = self.process.poll()
                                               if return_code is None:
                                                   return False
                                               # process has stopped. Assert that it didn't return an error code.
                                               assert return_code == 0, self._node_msg(
                                                   "Node returned non-zero exit code (%d) when stopping" % return_code)
                                               self.running = False
                                               self.process = None
                                               self.rpc_connected = False
                                               self.rpc = None
                                               self.log.debug("Node stopped")
                                               return True
                                       '''
     test  2019-08-14T06:30:37.185000Z TestFramework (ERROR): Assertion failed 
                                       Traceback (most recent call last):
                                         File "/root/workspace/bitcoin-core/test/functional/test_framework/test_framework.py", line 194, in main
                                           self.run_test()
                                         File "/root/workspace/bitcoin-core/test/functional/feature_pruning.py", line 365, in run_test
                                           self.stop_node(3)
                                         File "/root/workspace/bitcoin-core/test/functional/test_framework/test_framework.py", line 393, in stop_node
                                           self.nodes[i].wait_until_stopped()
                                         File "/root/workspace/bitcoin-core/test/functional/test_framework/test_node.py", line 306, in wait_until_stopped
                                           wait_until(self.is_node_stopped, timeout=timeout)
                                         File "/root/workspace/bitcoin-core/test/functional/test_framework/util.py", line 225, in wait_until
                                           raise AssertionError("Predicate {} not true after {} seconds".format(predicate_source, timeout))
                                       AssertionError: Predicate ''''
                                           def is_node_stopped(self):
                                               """Checks whether the node has stopped.
                                               Returns True if the node has stopped. False otherwise.
                                               This method is responsible for freeing resources (self.process)."""
                                               if not self.running:
                                                   return True
                                               return_code = self.process.poll()
                                               if return_code is None:
                                                   return False
                                               # process has stopped. Assert that it didn't return an error code.
                                               assert return_code == 0, self._node_msg(
                                                   "Node returned non-zero exit code (%d) when stopping" % return_code)
                                               self.running = False
                                               self.process = None
                                               self.rpc_connected = False
                                               self.rpc = None
                                               self.log.debug("Node stopped")
                                               return True
                                       ''' not true after 60 seconds
    
  2. fanquake added the label Tests on Aug 14, 2019
  3. MarcoFalke commented at 5:29 PM on August 14, 2019: member

    It might just be busy flushing the utxo set on shutdown?

  4. MarcoFalke closed this on Mar 8, 2021

  5. DrahtBot locked this on Aug 18, 2022
Contributors
Labels

github-metadata-mirror

This is a metadata mirror of the GitHub repository bitcoin/bitcoin. This site is not affiliated with GitHub. Content is generated from a GitHub metadata backup.
generated: 2026-04-17 06:14 UTC

This site is hosted by @0xB10C
More mirrored repositories can be found on mirror.b10c.me