Closed MarcelKlammer closed 1 year ago
Testable using a testnet with an account that only holds ADA, no tokens. Then rapid sending to same account.
eg. 502 ADA on account > send 450, then 460, then 470, 480, 490 in rapid succession.
Also: sync_utxo_cbor_by_hash_idx needs to be checked as well.
Most rapid transactions had 2 inputs. Checking for spent utxos in a single call should see "spent" status of both inputs change at the same time.
Sometimes only one is returned as "spent" or visible on chain, which might be an error in Phryhose?
Screenshots:
1st: 32:02: block was on chain for 14 seconds already. 2nd: 14s after block no dbsync had that block, a few even lower 3nd: 1:40 min later still most on the 4999 block.
Could also be a delay in reporting/monitoring as well, but I doubt it.
The original issue reported about sorting is fixed and deployed. Regarding time for block insertion, this is a reporting / monitoring issue as seen below. Though firehose seems be a bit quicker than dbsync.
Here are some stats directly from system logs for adoption time between node, firehose, and dbsync. Node and dbsync only have 10th/ms resolution but doesn't really matter. The conclusion I draw is that the more complex the block is, the more tables dbsync has to touch and update, while firehose does much less processing for each block and this is much quicker.
What is still unclear is if the timestamp logged is when the processing of the block and insertion into Postgres is complete or if this is when the block is seen but yet to be processed.
grep 926194 /opt/cardano/mainnet/logs/node0.json | jq -r '.at' | uniq
9261940 2023-09-08 06:23:22.12Z
9261941 2023-09-08 06:23:27.08Z
9261942 2023-09-08 06:24:16.22Z
9261943 2023-09-08 06:24:18.16Z
9261944 2023-09-08 06:24:45.34Z
9261945 2023-09-08 06:24:50.29Z
9261946 2023-09-08 06:26:54.43Z
9261947 2023-09-08 06:28:12.25Z
9261948 2023-09-08 06:28:16.15Z
9261949 2023-09-08 06:28:42.27Z
firehoselog_mainnet | grep 926194
9261940 2023-09-08 06:23:22.130 (+.01)
9261941 2023-09-08 06:23:27.085 (+.01)
9261942 2023-09-08 06:24:16.227 (+.01)
9261943 2023-09-08 06:24:18.168 (+.01)
9261944 2023-09-08 06:24:45.343 (+.01)
9261945 2023-09-08 06:24:50.294 (+.01)
9261946 2023-09-08 06:26:54.443 (+.01)
9261947 2023-09-08 06:28:12.264 (+.01)
9261948 2023-09-08 06:28:16.157 (+.01)
9261949 2023-09-08 06:28:42.282 (+.01)
grep 926194 /opt/cardano/mainnet/logs/dbsync.json | jq -r '.at'
9261940 2023-09-08T06:23:22.29Z (+.17)
9261941 2023-09-08T06:23:27.20Z (+.12)
9261942 2023-09-08T06:24:16.57Z (+.35)
9261943 2023-09-08T06:24:18.50Z (+.34)
9261944 2023-09-08T06:24:45.43Z (+.09)
9261945 2023-09-08T06:24:50.76Z (+.47)
9261946 2023-09-08T06:26:55.00Z (+.57)
9261947 2023-09-08T06:28:12.81Z (+.56)
9261948 2023-09-08T06:28:17.05Z (+.90)
9261949 2023-09-08T06:28:42.55Z (+.28)
With signTxs implemented it will happen more frequently, that multiple transaction of the same account are in a single block.
Currently the SQL sorts by slot, with isn't enough, it must also be ordered by txIndex in a block.