gettransaction rpc command sometimes returns wrong results (probably after a orphaned block)

[vvanderkroef]

Sometimes gettransaction returns wrong results. This has probably something to do with orphaned blocks. I ran into this when playing with some code to list unspent transactions for an account (using listunspentforaccount) and then for each transaction calling gettransaction and store the results. After a while there was 1 transaction I could not find in the block it was supposed to be in.

This was what I did:

gettransaction 8d335bfdf5393308349eaab726bcb47b116d2bb37c858b716e3ad95b6a67ca65

{ "amount": 0.00000000, "fee": -0.00226000, "confirmations": 41, "blockhash": "62723efc2c0a8570d40f9c10f080001dadcd5584aeb4d6d96e95fd8c76307894", "blockindex": 2, "blocktime": 1581695783, "txid": "fbfa09a250caba19a8bc162c5fd0ee6d69b9f257b2c97f54561d5108b9f435ac", }

As you can see the txid of the result does not match the transactionid I requested. The txid from the result is indeed in the block, but it's not the transaction I want.

getblock 62723efc2c0a8570d40f9c10f080001dadcd5584aeb4d6d96e95fd8c76307894

{ "hash": "62723efc2c0a8570d40f9c10f080001dadcd5584aeb4d6d96e95fd8c76307894", "tx": [ "dfc612d9281c66242ce73a6be28af69e163c5afed0be02d9f9d7c1dc18002c45", "c65d9244789ba2a7c80d912838ece714eacab4661ad13d2a753a860ab9d0c8f9", "fbfa09a250caba19a8bc162c5fd0ee6d69b9f257b2c97f54561d5108b9f435ac" ], }

Now I closed and reopened my wallet and executed the command again:

gettransaction 8d335bfdf5393308349eaab726bcb47b116d2bb37c858b716e3ad95b6a67ca65

{ "amount": 0.00000000, "fee": -0.00226000, "confirmations": 110, "blockhash": "1aa5896ed00994d1a5ea135e9a8ab7d05e4b0bbe9216e4d3a10210789abf0c65", "blockindex": 2, "blocktime": 1581696123, "txid": "8d335bfdf5393308349eaab726bcb47b116d2bb37c858b716e3ad95b6a67ca65", }

Now this seems to be correct, the txid matches the transactionid. As you can see the transaction is part of an other block.

getblock 1aa5896ed00994d1a5ea135e9a8ab7d05e4b0bbe9216e4d3a10210789abf0c65

{ "hash": "1aa5896ed00994d1a5ea135e9a8ab7d05e4b0bbe9216e4d3a10210789abf0c65", "tx": [ "a62b50cf6b657567813d34ae9bb064ef4878e34be9ea8934881b6a576509174a", "1e2a6b04d2ee963cc50e44258562180ceff2b5593d8ac274c85f1bb80573dfd7", "8d335bfdf5393308349eaab726bcb47b116d2bb37c858b716e3ad95b6a67ca65", "51f99c542b6da93d5b405425ace316d9fee2ea2b4f0e3a7b49283b79f2d1cdf3" ], }

I think this happens when the block gets orphaned after you have executed the gettransaction command and caching the results or something like that.

Expected behaviour

gettransacction should always return the correct data.

What version of Gulden are you using?

v2.1.0.24

[mjmacleod]

Did you try issuing the command more than once before restarting the wallet?

[devlz303]

yes, I was investigating what was wrong. And then I thought to myself, maybe it has something to do with caching. So I executed the command multiple times with the incorrect result. Then I closed and reopened the wallet and now the result was correct.

[mjmacleod]

This is on testnet? Do block 1aa5896ed00994d1a5ea135e9a8ab7d05e4b0bbe9216e4d3a10210789abf0c65 and 62723efc2c0a8570d40f9c10f080001dadcd5584aeb4d6d96e95fd8c76307894 share a common height?

[vvanderkroef]

Yes, it's on testnet (I probably should have mentioned it right away). 1aa5896ed00994d1a5ea135e9a8ab7d05e4b0bbe9216e4d3a10210789abf0c65 -> "height": 505727 62723efc2c0a8570d40f9c10f080001dadcd5584aeb4d6d96e95fd8c76307894 -> "height": 505722

[mjmacleod]

hrm, both blocks are in the chain but at different heights, so I'm not sure about orphan blocks having anything to do with this. Do you have any other data that makes you think its specifically something to do with orphans, or is that just a hunch?

[vvanderkroef]

Just a hunch. It was the only thing I could think of why a transaction would first appear in 505722 and later in 505727. Somehow it was first accepted in a block, but at a later time it was not anymore.

I the meantime I have changed my code so it isn't affected by this anymore. But maybe I will try to make a test situation to find out if it happens again.

[vvanderkroef]

I'm trying to create a simple test situation, but right now it keeps crashing my wallet. What I do in my test. I have 2 accounts in my wallet (source and destination). Each 5 seconds the following is done:

1. execute getblockcount to find out if a new block is found
2. if a new block is found execute move source destination 10
3. execute listunspentforaccount destination 0 to get the unspent transactions
4. for each unspent transaction execute gettransaction <txid> to get the transaction
5. wait for 5 seconds and move to step 1.

The first time this succeeds, but when the next block is found step 3 fails. The rpc call makes the wallet crash. It's not because of that particular rpc call, because after this happened 5 times I changed step 2 into:

2. if a new block is found execute move source destination 10 and move to step 5.

And now the wallet crashes at step 1 when executing getblockcount.

So I have some struggles to get this test working.

[mjmacleod]

Clearly this needs to be looked into (both issues), however I'm on a tight timeline to deliver phase 4 in march so need to be careful with time usage before diving into this.

I don't want to chase down an issues thats possibly already solved - would you be able to give it a test on a 2.2_development branch build and see if it still occurs on that? Or alternatively if you can provide me with a testnet wallet and a basic script I can setup that reproduces the issue then I can look into it quickly.

[vvanderkroef]

Yes, ofcourse phase 4 is way more important than these issues.

I didn't find a 2.2_development branch build and building it by myself will take a bit more time because last time I did that was about 6 months ago or so.

Here's a bit more information. I've turned on debugging and let the crash happen again. Maybe you can find more in the attached debug.log. One thing I noticed, in the debug.log in the last lines before the crash I saw this line:

2020-02-15 22:23:53 GUI: "NotifyTransactionChanged: 6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a status= 1"

In my database I kept a log for al unspent transactions and the outcome for gettransaction 6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a was:

{ "amount": 0, "fee": -0.00226, "confirmations": 1, "blockhash": "5a6da61823f95c4cefb2442cd42eec69b6e3b7d7bae79c5eaf67d763fda9a92b", "blockindex": 2, "blocktime": 1581805315, "txid": "6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a", "walletconflicts": [], "time": 1581804620, "timereceived": 1581804620, "bip125-replaceable": "no", "details": [ { "account": "053d1bb4-ba0e-4691-8de5-ee34cd9bf5f7", "accountlabel": "issue-196-to", "address": "TGe3sXHD8NYjzC9qCJUze2qaxWwGa233oa", "category": "receive", "amount": 10, "vout": 1, "secured_by_checkpoint": "no" }, { "account": "4ca65887-af6a-4535-9981-e511a75cd482", "accountlabel": "issue-196-from", "address": "TKWTg8JRajMPbF19p5MSaNKgXk3rgbUWep", "category": "send", "amount": -929.98358722, "vout": 0, "fee": -0.00226, "secured_by_checkpoint": "no", "abandoned": false }, { "account": "4ca65887-af6a-4535-9981-e511a75cd482", "accountlabel": "issue-196-from", "address": "TRVPLJX2qWN8ezsWL1RE4cNrpWndzKkMwD", "category": "receive", "amount": 919.98132722, "vout": 0, "secured_by_checkpoint": "no" } ], "hex": "020000000142900d70c4728a35816f2d4b94f13a83b248c3bc6b64b6df29a564088720c5f8010000006b483045022100c9f051186ecfb6f5a7f8003876b89ae9d89f28e6f2a26461cd407d36da4613af0220184cf779d58e94e6b2f57687c676825c1cadf5ef67380fd43db6fd62d4e159b901210284e03cd2afb6c9112531637520a1c35f130588775f8cec5bbf0e94273b9599fdfeffffff02f219846b150000001976a914aa3efd7ac76f1d1bec567d3f0e095014dafa757188ac00ca9a3b000000001976a91449295b1e19dc0480c999c59f78498265f7a9f65588ac00000000" }

But when I opened the wallet after the crash and I execute gettransaction 6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a the result is:

{ "amount": 0.00000000, "fee": -0.00226000, "confirmations": 5, "blockhash": "29fad3a3b8005e98694fc01ef07135196dab76894457e5ee582fc521b3c9e8e2", "blockindex": 2, "blocktime": 1581805315, "txid": "6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a", "walletconflicts": [ ], "time": 1581804620, "timereceived": 1581804620, "bip125-replaceable": "no", "details": [ { "account": "053d1bb4-ba0e-4691-8de5-ee34cd9bf5f7", "accountlabel": "issue-196-to", "address": "TGe3sXHD8NYjzC9qCJUze2qaxWwGa233oa", "category": "receive", "amount": 10.00000000, "vout": 1, "secured_by_checkpoint": "no" }, { "account": "4ca65887-af6a-4535-9981-e511a75cd482", "accountlabel": "issue-196-from", "address": "TKWTg8JRajMPbF19p5MSaNKgXk3rgbUWep", "category": "send", "amount": -929.98358722, "vout": 0, "fee": -0.00226000, "secured_by_checkpoint": "no", "abandoned": false }, { "account": "4ca65887-af6a-4535-9981-e511a75cd482", "accountlabel": "issue-196-from", "address": "TRVPLJX2qWN8ezsWL1RE4cNrpWndzKkMwD", "category": "receive", "amount": 919.98132722, "vout": 0, "secured_by_checkpoint": "no" } ], "hex": "020000000142900d70c4728a35816f2d4b94f13a83b248c3bc6b64b6df29a564088720c5f8010000006b483045022100c9f051186ecfb6f5a7f8003876b89ae9d89f28e6f2a26461cd407d36da4613af0220184cf779d58e94e6b2f57687c676825c1cadf5ef67380fd43db6fd62d4e159b901210284e03cd2afb6c9112531637520a1c35f130588775f8cec5bbf0e94273b9599fdfeffffff02f219846b150000001976a914aa3efd7ac76f1d1bec567d3f0e095014dafa757188ac00ca9a3b000000001976a91449295b1e19dc0480c999c59f78498265f7a9f65588ac00000000" }

So the same transaction now has a different blockhash. But when I execute getblock 5a6da61823f95c4cefb2442cd42eec69b6e3b7d7bae79c5eaf67d763fda9a92b and getblock 29fad3a3b8005e98694fc01ef07135196dab76894457e5ee582fc521b3c9e8e2 they both give the same height 507085. But the block with hash 29fad3a3b8005e98694fc01ef07135196dab76894457e5ee582fc521b3c9e8e2 has -1 confirmations.

getblock 29fad3a3b8005e98694fc01ef07135196dab76894457e5ee582fc521b3c9e8e2 { "hash": "29fad3a3b8005e98694fc01ef07135196dab76894457e5ee582fc521b3c9e8e2", "confirmations": 6, "strippedsize": 899, "size": 899, "weight": 899, "height": 507085, "version": 536870912, "versionHex": "20000000", "merkleroot": "32a404a27a8eee19227e7cc54b12298f4fd8e1599e718d71bf30b1da9b4254e3", "witness_version": 0, "witness_versionHex": "00000000", "witness_time": 0, "witness_merkleroot": "0000000000000000000000000000000000000000000000000000000000000000", "tx": [ "48f76410cbfb417c113e9023ad3c4a3748f29d1a23014a2e851658d4d67fff36", "ca1566710fabf6cb842b921a4aa60de16869439775e5a2fc9ba1c4793f5593b2", "6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a" ], "time": 1581805315, "mediantime": 1581805058, "nonce": 1470693804, "pre_nonce": 428, "post_nonce": 22441, "bits": "1f2fffff", "difficulty": 317.8866892171309, "chainwork": "00000000000000000000000000000000000000000000000000000fea195668c5", "previousblockhash": "e06353394b1b5f4d4d3862700c28cd86a6cb6d497391745e6ed9b3369ea1bf31", "nextblockhash": "83db6d3fc2bd6e5c592e05b423bf6dc109d01cce018f11ebb9adc9c0f67e550a" }

getblock 5a6da61823f95c4cefb2442cd42eec69b6e3b7d7bae79c5eaf67d763fda9a92b { "hash": "5a6da61823f95c4cefb2442cd42eec69b6e3b7d7bae79c5eaf67d763fda9a92b", "confirmations": -1, "strippedsize": 1229, "size": 1294, "weight": 1294, "height": 507085, "version": 536870912, "versionHex": "20000000", "merkleroot": "32a404a27a8eee19227e7cc54b12298f4fd8e1599e718d71bf30b1da9b4254e3", "witness_version": 536870912, "witness_versionHex": "20000000", "witness_time": 1581805331, "witness_merkleroot": "39a3040db1f414f44e11c41c1b9e5c16908a5ac636578c98850851bed1ed59a5", "tx": [ "48f76410cbfb417c113e9023ad3c4a3748f29d1a23014a2e851658d4d67fff36", "ca1566710fabf6cb842b921a4aa60de16869439775e5a2fc9ba1c4793f5593b2", "6ad9fbd71040438eb00323da28dbd89cf730d43190367a799d42b6151080fc5a", "39a3040db1f414f44e11c41c1b9e5c16908a5ac636578c98850851bed1ed59a5" ], "time": 1581805315, "mediantime": 1581805058, "nonce": 1470693804, "pre_nonce": 428, "post_nonce": 22441, "bits": "1f2fffff", "difficulty": 317.8866892171309, "chainwork": "00000000000000000000000000000000000000000000000000000fea195668c6", "previousblockhash": "e06353394b1b5f4d4d3862700c28cd86a6cb6d497391745e6ed9b3369ea1bf31" }

debug.log

I hope this will give you at least some more clues for you when you have time to look at it.

[mjmacleod]

It appears that this might already be fixed in the 2.2_development branch, which will soon become the main branch. So will likely be fixed once that is released. Thanks for the report.

[mjmacleod]

This is now believed to be fixed, please advise if its not the case so we can look into it.