Since 60befa399 in #9441, bip68-sequence.py (one of the extended rpc tests, not run by travis) has been failing:
0Initializing test directory /var/folders/pw/k25spdv971g8xhccyx5t3yyr0000gn/T/test5y497icn/9191
1Running test disable flag
2Running test sequence-lock-confirmed-inputs
3Running test sequence-lock-unconfirmed-inputs
4Running test BIP68 not consensus before versionbits activation
5Verifying nVersion=2 transactions aren't standard
6Activating BIP68 (and 112/113)
7Assertion failed: Block sync to height 432 timed out:
8 {'hash': '05c02af44675851560cb13b1b59f2a7f08ff3bef4e3db19f6a08e79cb51cce62', 'height': 432}
9 {'hash': '30f24ff219ac23291d1489710ad467726b7ab202f70923d4bd5707dacfb05051', 'height': 328}
10 File "/Users/sdaftuar/projects/ccl-bitcoin/qa/rpc-tests/test_framework/test_framework.py", line 145, in main
11 self.run_test()
12 File "./bip68-sequence.py", line 58, in run_test
13 self.activateCSV()
14 File "./bip68-sequence.py", line 409, in activateCSV
15 sync_blocks(self.nodes)
16 File "/Users/sdaftuar/projects/ccl-bitcoin/qa/rpc-tests/test_framework/util.py", line 147, in sync_blocks
17 maxheight, "".join("\n {!r}".format(tip) for tip in tips)))
18Stopping nodes
19Not cleaning up dir /var/folders/pw/k25spdv971g8xhccyx5t3yyr0000gn/T/test5y497icn/9191
20Failed
I git bisected the problem back to the above commit; the issue seems to be that the inactivity checking at https://github.com/theuni/bitcoin/blob/60befa3997b98d3f913010f2621bec734f643526/src/net.cpp#L1298 is comparing times that are coming from two different places: GetTime() which can use mocktime, and GetTimeMicros() which does not, and the bip68-sequence.py test uses mocktime. (Using GetTimeMicros() for nLastRecv is newly introduced in the commit above.)
Really, it’s sort of remarkable/lucky that we didn’t have test failures relating to how mocktime interacts with the networking code before. I’m not sure what the right way to fix this is – I started by trying to narrowly just fix this issue by changing nTimeConnected, nLastSend, and the starting nTime used in the inactivity check to all be based off system clock (eg GetTimeMicros()/1000000), but then that broke some of our other tests that I think must have been relying on mocktime having an effect on some of these things (maxuploadtarget.py, receivedby.py, and listtransactions.py all failed – I didn’t investigate exactly what happened so it’s possible my fix just had a simple mistake).
Anyway I think we need a thoughtful approach to how to use GetTime() vs. GetTimeMicros() for the various times we have, especially in net.cpp/net_processing.cpp, and this is a bug that I think we need to fix for 0.14 so we’re not shipping broken tests.
