Continuing the discussion from 0.17.1rc1 reindex (full), assumevalid=0:
A curiosity regarding the txindex rebuild; this may be a (minor) issue. It appears that the txindex thread stops running when the chainstate reindex is complete. As a result the txindex doesn’t seem to be fully completed/enabled until a subsequent restart of the node.
This began when I noticed this about the latest reindex run - at the start:
2019-09-29T15:30:28Z txindex thread start 2019-09-29T15:30:28Z txindex is enabled 2019-09-29T15:30:28Z txindex thread exit
The txindex thread appears to have started running…
We can see that the index was, in fact, built during the reindexing because of the many
WriteBatch memory usage: db=txindex message showing the memory size growing, as expected.
Here are the lines right after that last block was indexed from disk:
2019-09-30T04:08:16Z UpdateTip: new best=000000019f550bf1039de36e359d2f13697fe1f5d35430222f4382f2650447a6 height=601193 version=0x20000000 log2_work=87.340668 tx=266527475 date='2019-09-30T03:35:43Z' progress=0.634711 cache=228.9MiB(1402671txo) 2019-09-30T04:08:16Z - Connect postprocess: 0.00ms [115.95s (0.19ms/blk)] 2019-09-30T04:08:16Z - Connect block: 2.00ms [37577.23s (62.50ms/blk)] 2019-09-30T04:08:16Z WriteBatch memory usage: db=txindex, before=13.0MiB, after=13.0MiB
The txindex appears to be getting updated.
All subsequent blocks (synced from network instead of disk) looked like the txindex was being updated with new incoming blocks just fine. Example:
2019-09-30T13:00:06Z UpdateTip: new best=000000018d8867310263292b5567e43a114adbe9c48366a93974f57e30065529 height=601255 version=0x20000000 log2_work=87.340668 tx=266527766 date='2019-09-30T12:59:55Z' progress=0.634596 cache=228.9MiB(1402505txo) 2019-09-30T13:00:06Z - Connect postprocess: 1.00ms [115.99s (0.19ms/blk)] 2019-09-30T13:00:06Z - Connect block: 2.00ms [37577.39s (62.50ms/blk)] 2019-09-30T13:00:06Z WriteBatch memory usage: db=txindex, before=13.0MiB, after=13.0MiB
Buuuut… When I restarted the node several hours later (after removing the
reindex=1 from the config so that it doesn’t wipe everything out again), I got this:
[main] debug=1 #assumevalid=0 #reindex=1 txindex=1
Debug log start:
2019-09-30T16:39:40Z 2019-09-30T16:39:40Z Bitcoin Gold version v0.17.1rc1 (release build) 2019-09-30T16:39:40Z InitParameterInteraction: parameter interaction: -whitelistforcerelay=1 -> setting -whitelistrelay=1 2019-09-30T16:39:41Z Assuming ancestors of block 00000001ddb50bf6de8012bf8cd15bebc278c7e75ce5f77409ab78a291bd7e36 have valid signatures.
Then the txindex started with:
2019-09-30T16:40:03Z txindex thread start 2019-09-30T16:40:03Z Syncing txindex with block chain from height 543459
This was strange, to me. Why height 543459? The node was already in sync up to block 601193 many hours earlier.
I watched some of the (usual?) activity, as the txindex was parsed (being built? or just being read?) until it completed, about a minute later:
2019-09-30T16:40:32Z WriteBatch memory usage: db=txindex, before=7.6MiB, after=7.6MiB 2019-09-30T16:40:32Z WriteBatch memory usage: db=txindex, before=7.6MiB, after=7.6MiB 2019-09-30T16:40:32Z txindex is enabled at height 601268 2019-09-30T16:40:32Z txindex thread exit
I restarted the node one more time. Then I got this at the start:
(I’ve clipped some lines here)
2019-09-30T17:33:27Z txindex thread start 2019-09-30T17:33:27Z Syncing txindex with block chain from height 601273 2019-09-30T17:33:27Z WriteBatch memory usage: db=txindex, before=0.0MiB, after=0.0MiB 2019-09-30T17:33:27Z txindex is enabled at height 601273 2019-09-30T17:33:27Z txindex thread exit
So this is a “clean” start of the node. It appears that the txindex was not fully completed on the first reindex run, and that it did not finish up until the next startup of the node.
I confirmed this in another way - the first big reindex was completed at 2019-09-30T04:08:16Z, which is 12:08 AM my time. Looking at the actual txindex database files on my drive, I can see that they were being written quickly and actively right up until the big reindex completed. Then the txindex stopped being built until the node was restarted 13 hours later:
I don’t know if this is normal behavior or not, but it may be worth noting for anyone who needs the services provided by a complete txindex… After running the txindex on a rebuild, you may want to restart the node to ensure all indexing is complete.
This appears to be a (minor) bug in the txindex implementation for BTG (& BTC); I suspect they stop the txindexing thread when the main index is completed, but the txindex is not yet fully rebuilt - it can be running behind by many, many thousands of blocks. The txindex rebuild does not start up again until the node is restarted. This is probably worth noting as an issue in Github to be resolved so that this runs more as expected in the future; I don’t yet know if the same issue exists in Bitcoin Core or not.