deso-protocol/run

TxErrorDuplicate

Roberrtom opened this issue · 19 comments

According to the instructions, I set up the environment, but encountered 2 errors.

backend | E0624 08:15:00.272022 1 server.go:1360] Server._handleTransactionBundle: Rejected transaction < TxHash: 03b5cc51ac247e55c3b0ce7a110a8c5ec7647a0c67c920562bd8e5f0b47b27ea, TxnType: BC1YLgJxJipZBW5Z7DBymqERREjRmRiRDF28T9sVQs8faG4MMsUiGjS, PubKey: SUBMIT_POST > from peer [ Remote Address: 95.216.8.224:9013 PeerID=7 ] from mempool: TxErrorDuplicate
backend | E0624 08:15:00.272566 1 server.go:1360] Server._handleTransactionBundle: Rejected transaction < TxHash: b6bdbfd0a8d5645c70cdc23cca9284efd43e085db88dd1e0b766445d4d51f32a, TxnType: BC1YLgkU6Yru4GXc4w73tb1Jfg6gB2uvk7UCXvHZcKstAT2XiMinCmc, PubKey: SUBMIT_POST > from peer [ Remote Address: 95.216.8.224:9013 PeerID=7 ] from mempool: TxErrorDuplicate
backend | E0624 08:15:00.272795 1 server.go:1360] Server._handleTransactionBundle: Rejected transaction < TxHash: 024554b9e9332bccd744c9008e84dd84c3dc7c7136b0c9ee15da88e576e5b5df, TxnType: BC1YLi9hJcM7eUEna1msmVN2pmVddDDaXBpC3jXsV1A88tGmqPsK4uk, PubKey: FOLLOW > from peer [ Remote Address: 95.216.8.224:9013 PeerID=7 ] from mempool: TxErrorDuplicate
backend | E0624 08:15:00.272957 1 server.go:1360] Server._handleTransactionBundle: Rejected transaction < TxHash: 9e4c9cf09b4c20d6a8d303b5d5e17a788540b268f84b0a6755bc77f09cf43adc, TxnType: BC1YLgqYVCtaHUC8Vu3dhCxJ2gin9Z5JaocxRUchYZ92wFqqTX7Ffcy, PubKey: LIKE > from peer [ Remote Address: 95.216.8.224:9013 PeerID=7 ] from mempool: TxErrorDuplicate
backend | E0624 08:15:00.273115 1 server.go:1360] Server._handleTransactionBundle: Rejected transaction < TxHash: 03a145f8fcd3b881d2fc43f48608e0a8f41ee83ca0deaca4a804b209dfe4d8af, TxnType: BC1YLhEETYrWhmHP7mQc3YicMzofjA5oGdSW9wntMu1PYfpp4SgQpv3, PubKey: LIKE > from peer [ Remote Address: 95.216.8.224:9013 PeerID=7 ] from mempool: TxErrorDuplicate

And another:

E0624 08:20:48.222504 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting

These errors have appeared many times, especially the first one.

If I want to mine, besides setting MINER_PUBLIC_KEYS and MAX_BLOCK_TEMPLATES_CACHE(here I set to 2000) in dev.env, what other parameters must I set?

I would be very grateful for any guidance.

Also facing the same issue

I've had this issue as well.

Seeing this as well. This started happening after setting txindex=true in dev.env.

NOTE: If txIndex=false, the notifications do not work. Any ideas??

backend     | I0720 16:36:27.048737       1 txindex.go:253] Update: Updating txindex tip (height: 5681, hash: 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c) to block tip (height: 44291, hash: 0000000000009506b5ec329d3f8cfda5b422152636a1d16138552f289141fb63) ...
backend     | E0720 16:36:27.342400       1 txindex.go:158] tryUpdateTxindex: Problem running update: Update: Problem attaching block < TstampSecs: 1615496857, Height: 5682, Hash: 000000000100f81d585172e388879f01606fd21d0fe51cf97bcbf2b50b66729e, ParentHash 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c, Status: HEADER_VALIDATED | BLOCK_PROCESSED | BLOCK_STORED | BLOCK_VALIDATED, CumWork: 1675316375086380>: RuleErrorDuplicateBlock
backend     | I0720 16:36:28.197230       1 server.go:536] Received header bundle with 0 headers in state FULLY_CURRENT from peer [ Remote Address: 35.232.92.5:17000 PeerID=1 ]. Downloaded ( 44291 / 44291 ) total headers
backend     | I0720 16:36:28.358635       1 txindex.go:253] Update: Updating txindex tip (height: 5681, hash: 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c) to block tip (height: 44291, hash: 0000000000009506b5ec329d3f8cfda5b422152636a1d16138552f289141fb63) ...
backend     | E0720 16:36:28.751132       1 txindex.go:158] tryUpdateTxindex: Problem running update: Update: Problem attaching block < TstampSecs: 1615496857, Height: 5682, Hash: 000000000100f81d585172e388879f01606fd21d0fe51cf97bcbf2b50b66729e, ParentHash 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c, Status: HEADER_VALIDATED | BLOCK_PROCESSED | BLOCK_STORED | BLOCK_VALIDATED, CumWork: 1675316375086380>: RuleErrorDuplicateBlock
backend     | I0720 16:36:29.702848       1 base.go:116] Refreshing exchange rate...
backend     | I0720 16:36:29.766939       1 txindex.go:253] Update: Updating txindex tip (height: 5681, hash: 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c) to block tip (height: 44291, hash: 0000000000009506b5ec329d3f8cfda5b422152636a1d16138552f289141fb63) ...
backend     | E0720 16:36:30.081981       1 txindex.go:158] tryUpdateTxindex: Problem running update: Update: Problem attaching block < TstampSecs: 1615496857, Height: 5682, Hash: 000000000100f81d585172e388879f01606fd21d0fe51cf97bcbf2b50b66729e, ParentHash 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c, Status: HEADER_VALIDATED | BLOCK_PROCESSED | BLOCK_STORED | BLOCK_VALIDATED, CumWork: 1675316375086380>: RuleErrorDuplicateBlock
backend     | I0720 16:36:30.788746       1 base.go:156] Blockchain exchange rate: 10019 [10019 10019 10019 10019 10019 10019 10019 10019 10019 10019]
backend     | I0720 16:36:30.788837       1 base.go:182] Final exchange rate: 10019
backend     | I0720 16:36:31.097156       1 txindex.go:253] Update: Updating txindex tip (height: 5681, hash: 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c) to block tip (height: 44291, hash: 0000000000009506b5ec329d3f8cfda5b422152636a1d16138552f289141fb63) ...
backend     | E0720 16:36:31.411106       1 txindex.go:158] tryUpdateTxindex: Problem running update: Update: Problem attaching block < TstampSecs: 1615496857, Height: 5682, Hash: 000000000100f81d585172e388879f01606fd21d0fe51cf97bcbf2b50b66729e, ParentHash 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c, Status: HEADER_VALIDATED | BLOCK_PROCESSED | BLOCK_STORED | BLOCK_VALIDATED, CumWork: 1675316375086380>: RuleErrorDuplicateBlock
backend     | I0720 16:36:32.425890       1 txindex.go:253] Update: Updating txindex tip (height: 5681, hash: 000000000036f47ad2bdcf003c027505286ced6cc0fca2b4f50c7297e116f37c) to block tip (height: 44291, hash: 0000000000009506b5ec329d3f8cfda5b422152636a1d16138552f289141fb63) ...

If this happens the only solution at the moment is to delete the txindex data directory. We're currently rewriting txindex so this issue will hopefully be closed when that rewrite launches.

I set TXINDEX to false, and resynchronized all the blocks, but still reported the same TxErrorDuplicate error.

tijno commented

@Roberrtom did you wipe the txindex db before resync ?

if you did and still having issues - check if your running out of resources / have too many open files.

Oh, I did not wipe the txindex db, so how do I remove it?

@Roberrtom also note you will need to set TXINDEX to true, or you'll run into issues with notification. After the initial header and block sync, keep monitoring to see the progress of the TXINDEX indexing process. Its best to do the sync with TXINDEX set to true, or you'll have to redo the whole thing.

Also keep an eye on your disk space metrics. You need a significant amount of disk space for the txindex. Its best to start with more resources than you need (for example, it takes ~32G RAM for the initial sync), then scale down later.

@Roberrtom check this out:
#60 (comment)

I entered the /db/badgerdb folder, but there is no file related to txindex.

tijno commented

@Roberrtom from memory its in one of the subfolders of /db/badgerdb/

i think it may be data subfolder

or you can try

find /db -iname txindex

root@vultr:# docker ps
CONTAINER ID IMAGE COMMAND CREATED STATUS PORTS NAMES
81f3b9f0fd35 nginx:latest "/docker-entrypoint.…" 4 days ago Up 12 hours 0.0.0.0:80->80/tcp, :::80->80/tcp, 0.0.0.0:443->443/tcp, :::443->443/tcp nginx
71b4ec5fbcfb bitclout/frontend:stable "/frontend/run.sh" 4 days ago Up 12 hours 80/tcp, 443/tcp, 2019/tcp, 0.0.0.0:8080->8080/tcp, :::8080->8080/tcp frontend
b672587216f7 bitclout/backend:stable "/bitclout/bin/backe…" 4 days ago Up 12 hours 0.0.0.0:17000-17001->17000-17001/tcp, :::17000-17001->17000-17001/tcp backend
root@vultr:
# docker exec b6 ls /db
backend.b672587216f7.root.log
backend.b672587216f7.root.log.20210721-090606.1
backend.b672587216f7.root.log.20210721-121923.1
backend.b672587216f7.root.log.20210721-143721.1
backend.b672587216f7.root.log.20210721-161731.1
backend.b672587216f7.root.log.20210721-162249.1
backend.b672587216f7.root.log.20210722-115327.1
backend.b672587216f7.root.log.20210723-031510.1
backend.b672587216f7.root.log.20210723-042108.1
backend.b672587216f7.root.log.20210723-042153.1
backend.b672587216f7.root.log.20210723-042452.1
backend.b672587216f7.root.log.20210723-062753.1
backend.b672587216f7.root.log.20210725-123141.1
backend.b672587216f7.root.log.20210725-155927.1
backend.b672587216f7.root.log.20210725-163042.1
backend.b672587216f7.root.log.20210725-163121.1
badgerdb
bitcoin_manager
peers.json
root@vultr:# docker exec b6 find /db -iname txindex
root@vultr:
# docker exec b6 ls /db/bitcoin_manager
peers.json

I searched everywhere in db folder, but still didn't find the txindex file.

tijno commented

Restart backend container and look at the first 20 or so log output messages after restart.

My logs:
Attaching to frontend, backend, nginx
backend | I0726 06:40:03.771229 1 config.go:133] Logging to directory /db
backend | I0726 06:40:03.771600 1 config.go:134] Running node in MAINNET mode
backend | I0726 06:40:03.771633 1 config.go:135] Data Directory: /db
backend | I0726 06:40:03.771636 1 config.go:169] Max Inbound Peers: 125
backend | I0726 06:40:03.771640 1 config.go:170] Protocol listening on port 17000
backend | I0726 06:40:03.771644 1 config.go:173] Mining with public keys: [BC1YLjDTgn5jhBPcp2K7nbfwz1FX6yroaK3mxHQrd1kTXpUdWb1sZW4]
backend | I0726 06:40:03.771649 1 config.go:176] Rate Limit Feerate: 0
backend | I0726 06:40:03.771652 1 config.go:177] Min Feerate: 100
backend | badger 2021/07/26 06:40:04 INFO: All 655 tables opened in 203ms
backend | badger 2021/07/26 06:40:04 INFO: Discard stats nextEmptySlot: 0
backend | badger 2021/07/26 06:40:04 INFO: Set nextTxnTs to 178207
backend | I0726 06:40:06.485834 1 mempool.go:2137] Calling StartReadOnlyUtxoViewRegenerator...
backend | I0726 06:40:06.485938 1 server.go:1762] Server.Start: Starting Server
backend | I0726 06:40:06.485995 1 block_producer.go:535] BitcoinManager is time-current; proceeding with producing blocks!
backend | I0726 06:40:06.486029 1 node.go:40] GlobalState BadgerDB Dir: /db/badgerdb/global_state
backend | I0726 06:40:06.486037 1 node.go:41] GlobalState BadgerDB ValueDir: /db/badgerdb/global_state/badgerdb
backend | I0726 06:40:06.486053 1 connection_manager.go:796] Full node socket initialized
backend | I0726 06:40:06.486059 1 miner.go:291] BitCloutMiner.Start: Starting miner with difficulty target 000001FFFF000000000000000000000000000000000000000000000000000000
backend | I0726 06:40:06.486159 1 miner.go:293] BitCloutMiner.Start: Block tip height 45924, cum work 00000000000000000000000000000000000000000000000053cdeb17c674accc, and difficulty 000000000000c13b4a7a9ba027157ca53fb56a6d34ed0feba7273c9fcc744b4a
backend | badger 2021/07/26 06:40:06 INFO: All 1 tables opened in 0s
backend | badger 2021/07/26 06:40:06 INFO: Discard stats nextEmptySlot: 0
backend | badger 2021/07/26 06:40:06 INFO: Set nextTxnTs to 1
backend | badger 2021/07/26 06:40:06 INFO: Deleting empty file: /db/badgerdb/global_state/badgerdb/000014.vlog

tijno commented

i think you still have txindex disabled - maybe you cleared volumes after disabling and not enabled it so db does not exist yet.

enable it and down+up compose

Yes, because such TxErrorDuplicate errors keep appearing, I set txIndex=false to disable index. So you mean I re-enable it and manually delete it after generating the txIndex file?

I set txIndex=true, and the txindex file can be found in the db, but the error is still reported.

tijno commented

@Roberrtom if there is no TXIndex folder here: /db/badgerdb/txindex then there is no DB to delete. So you can leave it off.

Note that without TXIndex notifications and some api/v1/ endpoints wont work.

If you keep hitting TxErrorDuplicate errors - you may want to try these settings in your dev.env file:

force connection to main bitclout only: CONNECT_IPS=bitclout-seed-4.io
disable mining by not having any keys MINER_PUBLIC_KEYS=
keep txindex on false until fully synced: TXINDEX=false
Ignore Invs until synced IGNORE_INBOUND_INVS=true
Read only until synced READ_ONLY_MODE=false

@Roberrtom if there is no TXIndex folder here: /db/badgerdb/txindex then there is no DB to delete. So you can leave it off.

Note that without TXIndex notifications and some api/v1/ endpoints wont work.

If you keep hitting TxErrorDuplicate errors - you may want to try these settings in your dev.env file:

force connection to main bitclout only: CONNECT_IPS=bitclout-seed-4.io
disable mining by not having any keys MINER_PUBLIC_KEYS=
keep txindex on false until fully synced: TXINDEX=false
Ignore Invs until synced IGNORE_INBOUND_INVS=true
Read only until synced READ_ONLY_MODE=false

I followed what you said, modified the configuration, and synchronized all the Txindex. The previous TxErrorDuplicate error does not appear now, but it always shows the following content, even if I stop and restart it several times. Is this normal?

backend | I0729 03:57:05.659739 1 block_producer.go:322] Produced block with 1 txns with approx 0 total txns in mempool
backend | E0729 03:57:09.438774 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | E0729 03:57:14.648125 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:15.337806 1 base.go:116] Refreshing exchange rate...
backend | I0729 03:57:15.748326 1 block_producer.go:322] Produced block with 1 txns with approx 0 total txns in mempool
backend | I0729 03:57:19.447712 1 base.go:156] Blockchain exchange rate: 10345 [10345 10345 10345 10345 10345 10345 10345 10345 10345 10345]
backend | I0729 03:57:19.448431 1 base.go:182] Final exchange rate: 10345
backend | E0729 03:57:19.757675 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | E0729 03:57:25.136725 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:25.836892 1 block_producer.go:322] Produced block with 1 txns with approx 0 total txns in mempool
backend | I0729 03:57:29.536159 1 base.go:116] Refreshing exchange rate...
backend | E0729 03:57:30.346521 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:33.545831 1 base.go:156] Blockchain exchange rate: 10345 [10345 10345 10345 10345 10345 10345 10345 10345 10345 10345]
backend | I0729 03:57:33.545954 1 base.go:182] Final exchange rate: 10345
backend | E0729 03:57:35.635512 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:35.845620 1 block_producer.go:322] Produced block with 1 txns with approx 0 total txns in mempool
backend | E0729 03:57:40.845012 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:43.551007 1 base.go:116] Refreshing exchange rate...
backend | I0729 03:57:45.854420 1 block_producer.go:322] Produced block with 1 txns with approx 0 total txns in mempool
backend | E0729 03:57:46.054322 1 peer.go:145] AddBitCloutMessage: Not enqueueing message GET_HEADERS because peer is disconnecting
backend | I0729 03:57:47.633917 1 base.go:156] Blockchain exchange rate: 10345 [10345 10345 10345 10345 10345 10345 10345 10345 10345 10345]
backend | I0729 03:57:47.634119 1 base.go:182] Final exchange rate: 10345