dtr-org / unit-e

A digital currency for a new era of decentralized trust
https://unit-e.io
MIT License
45 stars 15 forks source link

feature_no_esperanza_tx_relay_delay.py is floating #819

Closed frolosofsky closed 5 years ago

frolosofsky commented 5 years ago

Dear Mergeable, please shut up and stop spamming.

 test  2019-03-21 08:17:42.665000 TestFramework (ERROR): Assertion failed
Traceback (most recent call last):
  File "/home/travis/build/dtr-org/unit-e/build/unit-e-i686-pc-linux-gnu/test/functional/test_framework/test_framework.py", line 154, in main
    self.run_test()
  File "/home/travis/build/dtr-org/unit-e/build/unit-e-i686-pc-linux-gnu/test/functional/feature_no_esperanza_tx_relay_delay.py", line 184, in run_test
    delay = calc_vote_relay_delay(generate_node=node3, record_from=node1, record_to=node0)
  File "/home/travis/build/dtr-org/unit-e/build/unit-e-i686-pc-linux-gnu/test/functional/feature_no_esperanza_tx_relay_delay.py", line 84, in calc_vote_relay_delay
    sync_mempools([generate_node, record_from, record_to], timeout=10)
  File "/home/travis/build/dtr-org/unit-e/build/unit-e-i686-pc-linux-gnu/test/functional/test_framework/util.py", line 451, in sync_mempools
    ["\nNode %d: %s" % entry for entry in mempools.items()]))
AssertionError: Mempool sync failed:
Node 0: {'8d42e99427e3e7f3922ac945c64538b53d562b35fd41d1ea78a19bd9bc2a6b72'}
Node 1: {'8d42e99427e3e7f3922ac945c64538b53d562b35fd41d1ea78a19bd9bc2a6b72'}
Node 3: set() 

log.txt

kostyantyn commented 5 years ago

I had a look at it. The issue is caused by the bidirectional connections we have. Here what I see in logs:

node4 08:17:32.499560 UpdateTip: new best=479432abf8d0ff6f3e97bcea6e819312e4baf34dd205184841f758860d3a529c height=18 version=0x20000000 log2_work=5.2479275 tx=34 date='2019-03-21 08:17:34' progress=1.000000 cache=0.0MiB(0txo) 
node0 08:17:32.501461 UpdateTip: new best=479432abf8d0ff6f3e97bcea6e819312e4baf34dd205184841f758860d3a529c height=18 version=0x20000000 log2_work=5.2479275 tx=34 date='2019-03-21 08:17:34' progress=1.000000 cache=0.0MiB(0txo) 
node1 08:17:32.509251 UpdateTip: new best=479432abf8d0ff6f3e97bcea6e819312e4baf34dd205184841f758860d3a529c height=18 version=0x20000000 log2_work=5.2479275 tx=34 date='2019-03-21 08:17:34' progress=1.000000 cache=0.0MiB(0txo) 
node2 08:17:32.511159 UpdateTip: new best=479432abf8d0ff6f3e97bcea6e819312e4baf34dd205184841f758860d3a529c height=18 version=0x20000000 log2_work=5.2479275 tx=34 date='2019-03-21 08:17:34' progress=1.000000 cache=0.0MiB(0txo) 
node3 08:17:32.515410 ERROR: IsVotable: vote for wrong target_epoch=8. validator=6cb00591c9da64afc2930d2151bb7bb4e0c1cd09 current_epoch=8
node3 08:17:32.530314 UpdateTip: new best=479432abf8d0ff6f3e97bcea6e819312e4baf34dd205184841f758860d3a529c height=18 version=0x20000000 log2_work=5.2479275 tx=34 date='2019-03-21 08:17:34' progress=1.000000 cache=0.0MiB(0txo) 

Node3 receives vote earlier than it processed the block. It can be fixed by using unidirectional connections in the test but when I tried to do it, noticed that we have an issue with syncing blocks. Here is the reproducible test: https://github.com/dtr-org/unit-e/pull/824

Once we resolve it, I'll change connect_nodes_bi to connect_nodes and it should resolve the floating problem that occurred.