windows-latest test_bilateral_transaction_timestamps failure

[qstokkink]

Our main branch tester failed:

================================== FAILURES ===================================
___ TestBandwidthAccountingCommunity.test_bilateral_transaction_timestamps ____

self = <tribler.core.components.bandwidth_accounting.tests.test_community.TestBandwidthAccountingCommunity testMethod=test_bilateral_transaction_timestamps>

    async def test_bilateral_transaction_timestamps(self):
        """
        Test creating subsequent transactions and check whether the timestamps are different.
        """
        tx1 = await self.overlay(ID1).do_payout(self.peer(ID2), 500)
        tx2 = await self.overlay(ID1).do_payout(self.peer(ID2), 500)
    
>       assert tx1.timestamp != tx2.timestamp
E       assert 1700491736162 != 1700491736162
E        +  where 1700491736162 = BandwidthTransactionData(sequence_number=1, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\xc3\xbaE\x8b\xa5+^\xf9g\xa7\x1e!\x1c\xf94U\x84T\xcd\xc5%I\xa4\xab\xda1\xba\x14F\xc40C#\xd1Y\xbdO\x94w\xf2\xcb\x7f\x89e', public_key_b=b'LibNaCLPK:\x13L\x90>\xa2\x19\xc9\x8f\x94\x0e_\xe8\xca|\x87\x97\xa7\xab\x9f\xae\xbb\xcb\x8a\xd3*h\xb68m[SGR\x1e\x7f\x15\xcf|1=\xeb\x8c\xd8\x1bd\x8f\xc8\xbb/\x8e\x8f?Bx\xb0\xa5\xe7\xeb\xb3\xd8\xd2\xc3\xd4\x88', signature_a=b'p\xba\xc8\xd2Rj\xdc\x03\xf7\xb1\xf2\xb1*\xfc#\xdc\x8b\xbf\x1a\x1cg\x82\xd3^\x85\xd3\xd44\xb0;i\x89\xf0\xd8z\xfd\xf6\xe1[\xc9\x0c\x08g\xb4\x17S\\8(]0aj\x8e\x0c\xc7~/u\xc9\xb3>2\x06', signature_b=b'\x8d\xa8\xec3\xd8\xf5\xef\x9d\xf4#\xa0\xb6Nny\x1851v\xd2d\xe8aC\x82\xb4+\x9bm\x0e\xe1\x811*~\x88\xbc5\x95IH\xeb\x85\x1c\x94i\x91\t%\xb2\xc5\x8a\xc6\x16\x0f\xb5\x83\xb0\xddNc\xe9f\x07', amount=500, timestamp=1700491736162).timestamp
E        +  and   1700491736162 = BandwidthTransactionData(sequence_number=2, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\xc3\xbaE\x8b\xa5+^\xf9g\xa7\x1e!\x1c\xf94U\x84T\xcd\xc5%I\xa4\xab\xda1\xba\x14F\xc40C#\xd1Y\xbdO\x94w\xf2\xcb\x7f\x89e', public_key_b=b'LibNaCLPK:\x13L\x90>\xa2\x19\xc9\x8f\x94\x0e_\xe8\xca|\x87\x97\xa7\xab\x9f\xae\xbb\xcb\x8a\xd3*h\xb68m[SGR\x1e\x7f\x15\xcf|1=\xeb\x8c\xd8\x1bd\x8f\xc8\xbb/\x8e\x8f?Bx\xb0\xa5\xe7\xeb\xb3\xd8\xd2\xc3\xd4\x88', signature_a=b"-\xaa\xb6O\xe3P(\xb7\xff\xf0\xff\x11\\fc\xa1\xd44\x19\xc5\xc3\x90+\xb1\xc0\x1e\x8e'*pq\x07\x158\x1eX &_j\xa4\xc0^\xd2\xf3;-SP\x04f6\xa8p\xb9x\xbay\x1f5\x8b\x08\x10\x08", signature_b=b'&\xa24\x82\x9ck,\xbc:\xf5a\x8e\x1bA\xe1\xd3Z\xec\xd04\xc0\xc0\xdd\xe9\x92\xdd\xd4\x8c\xa9\x0c\x15\xb5\x8c\xd3f\x1a\x7f&\xd9\xb5}\t\xad\x0e\xea\xa40\x04e\x16M\xc0\xcb_%\x87\xa1G\xdd\x98"d\xdc\x08', amount=1000, timestamp=1700491736162).timestamp

self       = <tribler.core.components.bandwidth_accounting.tests.test_community.TestBandwidthAccountingCommunity testMethod=test_bilateral_transaction_timestamps>
tx1        = BandwidthTransactionData(sequence_number=1, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\...x95IH\xeb\x85\x1c\x94i\x91\t%\xb2\xc5\x8a\xc6\x16\x0f\xb5\x83\xb0\xddNc\xe9f\x07', amount=500, timestamp=1700491736162)
tx2        = BandwidthTransactionData(sequence_number=2, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\...x7f&\xd9\xb5}\t\xad\x0e\xea\xa40\x04e\x16M\xc0\xcb_%\x87\xa1G\xdd\x98"d\xdc\x08', amount=1000, timestamp=1700491736162)

src\tribler\core\components\bandwidth_accounting\tests\test_community.py:74: AssertionError
------------------------------ Captured log call ------------------------------
14:48:56.146 WARNING ProxyOverlay(101) Cannot anonymize community traffic without TunnelEndpoint
14:48:56.146 INFO ProxyOverlay(22) Init. Settings: testnet=False outgoing_query_interval=30 max_tx_returned_in_query=10.
14:48:56.146 INFO ProxyOverlay(50) Started bandwidth accounting community with public key 4c69624e61434c504b3ad324263f85c94b5946e56d0326a90209906128dec3ba458ba52b5ef967a71e211cf934558454cdc52549a4abda31ba1446c4304323d159bd4f9477f2cb7f8965
14:48:56.146 WARNING ProxyOverlay(101) Cannot anonymize community traffic without TunnelEndpoint
14:48:56.146 INFO ProxyOverlay(22) Init. Settings: testnet=False outgoing_query_interval=30 max_tx_returned_in_query=10.
14:48:56.146 INFO ProxyOverlay(50) Started bandwidth accounting community with public key 4c69624e61434c504b3a134c903ea219c98f940e5fe8ca7c8797a7ab9faebbcb8ad32a68b6386d5b5347521e7f15cf7c313deb8cd81b648fc8bb2f8e8f3f4278b0a5e7ebb3d8d2c3d488
14:48:56.177 INFO ProxyOverlay(193) Unloading the bandwidth accounting community.
14:48:56.177 INFO ProxyOverlay(193) Unloading the bandwidth accounting community.
============================= slowest 3 durations =============================
6.12s call     src/tribler/core/components/tunnel/tests/test_triblertunnel_community.py::TestTriblerTunnelCommunity::test_payouts
6.09s call     src/tribler/core/components/restapi/rest/tests/test_rest_manager.py::test_api_key_disabled
6.07s call     src/tribler/core/components/restapi/rest/tests/test_rest_manager.py::test_api_key_fail
=========================== short test summary info ===========================
FAILED src/tribler/core/components/bandwidth_accounting/tests/test_community.py::TestBandwidthAccountingCommunity::test_bilateral_transaction_timestamps - assert 1700491736162 != 1700491736162
 +  where 1700491736162 = BandwidthTransactionData(sequence_number=1, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\xc3\xbaE\x8b\xa5+^\xf9g\xa7\x1e!\x1c\xf94U\x84T\xcd\xc5%I\xa4\xab\xda1\xba\x14F\xc40C#\xd1Y\xbdO\x94w\xf2\xcb\x7f\x89e', public_key_b=b'LibNaCLPK:\x13L\x90>\xa2\x19\xc9\x8f\x94\x0e_\xe8\xca|\x87\x97\xa7\xab\x9f\xae\xbb\xcb\x8a\xd3*h\xb68m[SGR\x1e\x7f\x15\xcf|1=\xeb\x8c\xd8\x1bd\x8f\xc8\xbb/\x8e\x8f?Bx\xb0\xa5\xe7\xeb\xb3\xd8\xd2\xc3\xd4\x88', signature_a=b'p\xba\xc8\xd2Rj\xdc\x03\xf7\xb1\xf2\xb1*\xfc#\xdc\x8b\xbf\x1a\x1cg\x82\xd3^\x85\xd3\xd44\xb0;i\x89\xf0\xd8z\xfd\xf6\xe1[\xc9\x0c\x08g\xb4\x17S\\8(]0aj\x8e\x0c\xc7~/u\xc9\xb3>2\x06', signature_b=b'\x8d\xa8\xec3\xd8\xf5\xef\x9d\xf4#\xa0\xb6Nny\x1851v\xd2d\xe8aC\x82\xb4+\x9bm\x0e\xe1\x811*~\x88\xbc5\x95IH\xeb\x85\x1c\x94i\x91\t%\xb2\xc5\x8a\xc6\x16\x0f\xb5\x83\xb0\xddNc\xe9f\x07', amount=500, timestamp=1700491736162).timestamp
 +  and   1700491736162 = BandwidthTransactionData(sequence_number=2, public_key_a=b'LibNaCLPK:\xd3$&?\x85\xc9KYF\xe5m\x03&\xa9\x02\t\x90a(\xde\xc3\xbaE\x8b\xa5+^\xf9g\xa7\x1e!\x1c\xf94U\x84T\xcd\xc5%I\xa4\xab\xda1\xba\x14F\xc40C#\xd1Y\xbdO\x94w\xf2\xcb\x7f\x89e', public_key_b=b'LibNaCLPK:\x13L\x90>\xa2\x19\xc9\x8f\x94\x0e_\xe8\xca|\x87\x97\xa7\xab\x9f\xae\xbb\xcb\x8a\xd3*h\xb68m[SGR\x1e\x7f\x15\xcf|1=\xeb\x8c\xd8\x1bd\x8f\xc8\xbb/\x8e\x8f?Bx\xb0\xa5\xe7\xeb\xb3\xd8\xd2\xc3\xd4\x88', signature_a=b"-\xaa\xb6O\xe3P(\xb7\xff\xf0\xff\x11\\fc\xa1\xd44\x19\xc5\xc3\x90+\xb1\xc0\x1e\x8e'*pq\x07\x158\x1eX &_j\xa4\xc0^\xd2\xf3;-SP\x04f6\xa8p\xb9x\xbay\x1f5\x8b\x08\x10\x08", signature_b=b'&\xa24\x82\x9ck,\xbc:\xf5a\x8e\x1bA\xe1\xd3Z\xec\xd04\xc0\xc0\xdd\xe9\x92\xdd\xd4\x8c\xa9\x0c\x15\xb5\x8c\xd3f\x1a\x7f&\xd9\xb5}\t\xad\x0e\xea\xa40\x04e\x16M\xc0\xcb_%\x87\xa1G\xdd\x98"d\xdc\x08', amount=1000, timestamp=1700491736162).timestamp
===== 1 failed, 1348 passed, 3 skipped, 499 warnings in 374.63s (0:06:14) =====
Error: Process completed with exit code 1.

The timestamp appears to stem from:

tribler/src/tribler/core/components/bandwidth_accounting/db/transaction.py

Line 35 in 8d03b99

timestamp: int = field(default_factory=lambda: int(round(time.time() * 1000)))

However, especially on Windows, the granularity of time.time() can be bad. In fact, according to the official Python docs:

Note that even though the time is always returned as a floating point number, not all systems provide time with a better precision than 1 second. While this function normally returns non-decreasing values, it can return a lower value than a previous call if the system clock has been set back between the two calls.

Asserting any change in time.time() should not be in the unit tests.