offchaindatahandler: duplicated items in download queue

[p4u]

For some reason, when creating a new process, the offchaindatahandler adds twice the metadata files in the download queue.

2023-05-11T22:46:16.796+02:00 INF data/ipfs.go:162 > published file cid=bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm protocol=ipfs size=139
2023-05-11T22:46:26.711+02:00 INF offchaindatahandler/offchaindatahandler.go:80 > importing data type="election metadata" uri=ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm
2023-05-11T22:46:26.711+02:00 INF offchaindatahandler/offchaindatahandler.go:80 > importing data type="election metadata" uri=ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm
2023-05-11T22:46:26.711+02:00 INF data/ipfs.go:314 > retrieved file path=/ipfs/bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm size=139
2023-05-11T22:46:26.711+02:00 INF offchaindatahandler/metadata.go:17 > metadata downloaded successfully from ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm (139 bytes)
2023-05-11T22:46:26.711+02:00 INF data/ipfs.go:314 > retrieved file path=/ipfs/bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm size=139
2023-05-11T22:46:26.711+02:00 INF offchaindatahandler/metadata.go:17 > metadata downloaded successfully from ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm (139 bytes)
2023-05-11T22:46:26.728+02:00 INF vochain status blockTime=1m:15.00 elections=108 height=17502 mempool=1 peers=9 voteCache=0 votes=168620 votes/min=0
2023-05-11T22:46:32.785+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:32.899+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:33.13+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:33.394+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:33.97+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:34.441+02:00 INF api/censuses.go:252 > added 8192 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:35.115+02:00 INF api/censuses.go:252 > added 848 keys to census b0a0dab1a8f67195e30cf2ef523bcb3fd36a30874638fb36b4df1e85adb67afa
2023-05-11T22:46:35.419+02:00 INF data/ipfs.go:162 > published file cid=bafybeicmwyyuroqewy4alukfhpe63ut5ircbntisgst32eowat5nntuegq protocol=ipfs size=1363382
2023-05-11T22:46:35.901+02:00 INF data/ipfs.go:162 > published file cid=bafybeigtibqubhk3zpcsgfnnod3tdkmsxhpnnz3vopsaizwwr6kcitq4na protocol=ipfs size=404
2023-05-11T22:46:46.729+02:00 INF vochain status blockTime=1m:15.00 elections=108 height=17503 mempool=1 peers=9 voteCache=0 votes=168620 votes/min=0
2023-05-11T22:46:46.923+02:00 INF state/process.go:73 > new election censusOrigin=OFF_CHAIN_TREE_WEIGHTED censusRoot=25ba540e02eca83db072d9d27489d79c2500df2beb530dbd15f6034a89744a8f censusURI=ipfs://bafybeicmwyyuroqewy4alukfhpe63ut5ircbntisgst32eowat5nntuegq endBlock=35086 entityId=ff612e5cce7d59349a0af3e8ecee5a52d9b4003f envelopeType={} height=17504 maxCensusSize=50000 mode={"autoStart":true,"interruptible":true} processId=c5d2460186f7ff612e5cce7d59349a0af3e8ecee5a52d9b4003f020000000000 startBlock=17505 status=1 voteOptions={"costExponent":10000,"maxCount":1,"maxTotalCost":2,"maxValue":2,"maxVoteOverwrites":1}
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/offchaindatahandler.go:80 > importing data type="election metadata" uri=ipfs://bafybeigtibqubhk3zpcsgfnnod3tdkmsxhpnnz3vopsaizwwr6kcitq4na
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/offchaindatahandler.go:76 > importing data type="external census" uri=ipfs://bafybeicmwyyuroqewy4alukfhpe63ut5ircbntisgst32eowat5nntuegq
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/offchaindatahandler.go:80 > importing data type="election metadata" uri=ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/offchaindatahandler.go:80 > importing data type="election metadata" uri=ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/metadata.go:17 > metadata downloaded successfully from ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm (139 bytes)
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/metadata.go:17 > metadata downloaded successfully from ipfs://bafybeib657ytxm2gidcjgnc7jhljhtsbxogdhqyf3hazz32a2yr7p3mclm (139 bytes)
2023-05-11T22:46:46.939+02:00 INF data/ipfs.go:314 > retrieved file path=/ipfs/bafybeigtibqubhk3zpcsgfnnod3tdkmsxhpnnz3vopsaizwwr6kcitq4na size=404
2023-05-11T22:46:46.939+02:00 INF offchaindatahandler/metadata.go:17 > metadata downloaded successfully from ipfs://bafybeigtibqubhk3zpcsgfnnod3tdkmsxhpnnz3vopsaizwwr6kcitq4na (404 bytes)
2023-05-11T22:46:46.943+02:00 INF data/ipfs.go:314 > retrieved file path=/ipfs/bafybeicmwyyuroqewy4alukfhpe63ut5ircbntisgst32eowat5nntuegq size=1363382
2023-05-11T22:47:06.729+02:00 INF vochain status blockTime=1m:12.00 elections=109 height=17505 mempool=0 peers=8 voteCache=0 votes=168620 votes/min=0

[altergui]

i noticed there's also duplicate items when creating a new account

vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.658Z DBG vochain/app.go:354 > deliver tx hash=82df536866ce2c67fec89c610a1ce8f20a1be700dbfe865b1a4febe59b212d5c height=84 tx={"Payload":{"SetAccount":{"SIK":"OO81R7Cbr9ApnnN3cI5jUmblKEm4UPiwEcjm+Xh8yxA=","account":"WxBshN4ymUiYB+Ozzjm7bHwnnZc=","faucetPackage":{"payload":"CI+8hQYSFFsQbITeMplImAfjs845u2x8J52XGIgn","signature":"+D/X87hrROkTouJ8ZzK7esk55SkuqFMDK5vNm+OpqdYw9+id4+fVed7ed2J+Wyti6+3btfDgwVuSgy14WZkQaQE="},"infoURI":"ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu","nonce":0,"txtype":23}}} type=setAccount
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.659Z DBG state/account.go:187 > creating account 0x5B106c84dE3299489807E3B3Ce39bb6c7c279D97 with infoURI ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu balance 0 and delegates []
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.659Z DBG state/account.go:202 > setAccount: address 0x5B106c84dE3299489807E3B3Ce39bb6c7c279D97, nonce 0, infoURI ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu, balance: 0, delegates: [], processIndex: 0
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.659Z DBG offchaindatahandler/offchaindatahandler.go:151 > adding account info metadata ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu to queue
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.659Z DBG state/sik.go:76 > setSIK (create) address=0x5B106c84dE3299489807E3B3Ce39bb6c7c279D97 sik=38ef3547b09bafd0299e7377708e635266e52849b850f8b011c8e6f9787ccb10
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.659Z DBG state/sik.go:246 > updateSIKRoots (created) blockNumber=84 newSikRoot=47f23290ed0c804e9c209dded29a3eb3521d435d609593c9d9a542f4c4551929
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/balances.go:245 > transferring balance amount=1 from=b0d03e77c629ed48fbb33e2c402d70cab3103792 to=ffffffffffffffffffffffffffffffffffffffff
--
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/account.go:202 > setAccount: address 0xFFfFfFffFFfffFFfFFfFFFFFffFFFffffFfFFFfF, nonce 0, infoURI , balance: 1, delegates: [], processIndex: 0
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/balances.go:215 > consuming faucet payload created by 0xB0D03E77C629ED48Fbb33E2c402d70cAb3103792 with amount 5000 and identifier 12672527 (keyHash: 6ac8b596fcc8fb875d79cc0e335130f471eb52061cf4c4c72a4b180a2c6ce206)
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/balances.go:245 > transferring balance amount=5000 from=b0d03e77c629ed48fbb33e2c402d70cab3103792 to=5b106c84de3299489807e3b3ce39bb6c7c279d97
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/account.go:202 > setAccount: address 0xB0D03E77C629ED48Fbb33E2c402d70cAb3103792, nonce 0, infoURI , balance: 994999, delegates: [], processIndex: 0
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG state/account.go:202 > setAccount: address 0x5B106c84dE3299489807E3B3Ce39bb6c7c279D97, nonce 0, infoURI ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu, balance: 5000, delegates: [], processIndex: 0
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z DBG offchaindatahandler/offchaindatahandler.go:151 > adding account info metadata ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu to queue
vocdoni-demo-voconed-1  | 2023-10-02T13:03:54.66Z INF offchaindatahandler/offchaindatahandler.go:79 > importing data type="election metadata" uri=ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu
--
vocdoni-demo-voconed-1  | 2023-10-02T13:03:55.382Z DBG ipfs/ipfs.go:317 > rawdata received: {"version":"1.0","languages":[],"name":{"default":"test org"},"description":{"default":""},"newsFeed":{"default":""},"media":{"avatar":"","header":"","logo":""},"meta":{}}
vocdoni-demo-voconed-1  | 2023-10-02T13:03:55.382Z INF ipfs/ipfs.go:323 > retrieved file path=/ipfs/bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu size=171
vocdoni-demo-voconed-1  | 2023-10-02T13:03:55.383Z DBG httprouter/message.go:65 > response: (200) {"address":"5b106c84de3299489807e3b3ce39bb6c7c279d97","nonce":0,"balance":5000,"electionIndex":0,"infoURL":"ipfs://bafybeibteg7t6feq3fzj4qp4mjbz2frf75vcwwb2qec6g7mphmiujwkwyu","metadata":{"version":"1.0","name":{"default":"test org"},"description":{"default":""},"newsFeed":{"default":""},"media":{},"meta":{}},"sik":"38ef3547b09bafd0299e7377708e635266e52849b850f8b011c8e6f9787ccb10"}
vocdoni-demo-voconed-1  | 2023-10-02T13:03:55.383Z DBG middleware/logger.go:158 > "GET http://localhost:8081/v2/accounts/0x5B106c84dE3299489807E3B3Ce39bb6c7c279D97 HTTP/1.1" from 172.20.0.1:34928 - 200 385B in 839.078µs

and in that case, it's because during TxType_CREATE_ACCOUNT there's a call to CreateAccount

vocdoni-node/vochain/transaction/transaction.go

Line 219 in 8ce1665

if err := t.state.CreateAccount(

and immediately after, if there's a FaucetPackage, TransferBalance is called

vocdoni-node/vochain/transaction/transaction.go

Line 257 in 8ce1665

if err := t.state.TransferBalance(&vochaintx.TokenTransfer{

both CreateAccount and TransferBalance call SetAccount (first with balance=0 and then with balance=5000)
but there's not enough time between CreateAccount and TransferBalance for IPFS to fetch the metadata.

in this case, i'd just consider it WONTFIX. or if anything, fix the queue handler to ignore duplicate items

also, i noticed the debug message is misleading, it says importing data type="election metadata" both in case of election metadata AND account metadata. so i'm thinking what you encountered in your logs is actually duplicate ACCOUNT metadata downloads, during account creation, and not during election creation