Crash by transaction conflict in wallet

[fivepiece]

How to reproduce:

1. send funds to an address in electrum

EPS:

11:54:17,713776 [  LOG] Found new tx: {'fee': 3800, 'height': 0, 'tx_hash': '9a793494a83cb161d727342cf39f187bbab907440afe6c5aac17fde876d98286'}

electrum history:

{
    "summary": {
        "end_balance": "10. BTC",
        "end_date": null,
        "expenditures": "0. BTC",
        "income": "10. BTC",
        "start_balance": "0. BTC",
        "start_date": null
    },
    "transactions": [
        {
            "balance": "10. BTC",
            "confirmations": 0,
            "date": null,
            "height": -2,
            "label": "",
            "timestamp": null,
            "txid": "9a793494a83cb161d727342cf39f187bbab907440afe6c5aac17fde876d98286",
            "value": "10. BTC"
        }
    ]
}

2. use bumpfee to create a conflict (here bank is just a regtest node to distribute money. not the same one that EPS runs on top of)

bitcoin-cli:

$ bank-cli bumpfee 9a793494a83cb161d727342cf39f187bbab907440afe6c5aac17fde876d98286
{
  "txid": "2056ea4973d7d2236d086dfc89b8ece13669fa3e61b304b4f50814d4dbaf1fe7",
  "origfee": 0.00003800,
  "fee": 0.00004750,
  "errors": [
  ]
}

EPS:

11:56:07,976394 [  LOG] Found new tx: {'fee': 4750, 'height': 0, 'tx_hash': '2056ea4973d7d2236d086dfc89b8ece13669fa3e61b304b4f50814d4dbaf1fe7'}

electrum history:

{
    "summary": {
        "end_balance": "20. BTC",
        "end_date": null,
        "expenditures": "0. BTC",
        "income": "20. BTC",
        "start_balance": "0. BTC",
        "start_date": null
    },
    "transactions": [
        {
            "balance": "10. BTC",
            "confirmations": 0,
            "date": null,
            "height": -2,
            "label": "",
            "timestamp": null,
            "txid": "9a793494a83cb161d727342cf39f187bbab907440afe6c5aac17fde876d98286",
            "value": "10. BTC"
        },
        {
            "balance": "20. BTC",
            "confirmations": 0,
            "date": null,
            "height": -2,
            "label": "",
            "timestamp": null,
            "txid": "2056ea4973d7d2236d086dfc89b8ece13669fa3e61b304b4f50814d4dbaf1fe7",
            "value": "10. BTC"
        }
    ]
}

there are two unconfirmed transactions, electrum seems to think that our balance is increased by the amount in both

3. generate one block

EPS:

11:59:34,121537 [  LOG] A transaction confirmed: 9a793494a83cb161d727342cf39f187bbab907440afe6c5aac17fde876d98286
Traceback (most recent call last):
  File "p2pkh/server.py", line 290, in run_electrum_server
    recv_data = sock.recv(4096)
  File "/usr/lib/python3.5/ssl.py", line 922, in recv
    return self.read(buflen)
  File "/usr/lib/python3.5/ssl.py", line 799, in read
    return self._sslobj.read(len, buffer)
  File "/usr/lib/python3.5/ssl.py", line 585, in read
    v = self._sslobj.read(len)
socket.timeout: The read operation timed out

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
  File "p2pkh/server.py", line 485, in <module>
    main()
  File "p2pkh/server.py", line 482, in main
    poll_interval_connected, certfile, keyfile)
  File "p2pkh/server.py", line 304, in run_electrum_server
    on_heartbeat_connected(sock, rpc, txmonitor)
  File "p2pkh/server.py", line 86, in on_heartbeat_connected
    updated_scripthashes = txmonitor.check_for_updated_txes()
  File "/home/user/software/crypto/electrum-personal-server/electrumpersonalserver/transactionmonitor.py", line 239, in check_for_updated_txes
    updated_scrhashes2 = self.check_for_confirmations()
  File "/home/user/software/crypto/electrum-personal-server/electrumpersonalserver/transactionmonitor.py", line 265, in check_for_confirmations
    block = self.rpc.call("getblockheader", [tx["blockhash"]])
KeyError: 'blockhash'

Perhaps we should be looking at the "walletconflicts" field in gettransaction, also not attempt to return proofs for unconfirmed transactions?

[chris-belcher]

I think this is the fundamental source of the bug: https://github.com/chris-belcher/electrum-personal-server/blob/e86e946ecb331ab3b6b3debe18e7a7d4c06bfc6c/electrumpersonalserver/transactionmonitor.py#L261

It should also check whether tx["confirmations"] == -1, which means a conflict. And then remove that tx from the list of transactions waiting to be confirmed.

[chris-belcher]

To elaborate, the only reason that Electrum is asking for the merkle proof is because it thinks that transaction got confirmed. When in reality it became conflicted.

Edit: ignore this, I got confused with the other crash bug.

[chris-belcher]

Pull the latest master, the commit https://github.com/chris-belcher/electrum-personal-server/commit/cbd7953d8857566b756d0302bf423bd1b882f726 hopefully fixes this crash bug.

[fivepiece]

Yep, seems to have fixed the crash using crash when using the flow described above :

A tx is sent:

19:55:46,807598 [  LOG] Found new tx: {'height': 0, 'fee': 3800, 'tx_hash': '23f89ab86b8b21d5c26e45b3adafeac34355958bd08a62dff746c1c0c078ee99'}

bumpfee is called, electrum shows two unconfirmed transactions, our balance is wrong (the two transactions are considered as both paying to us independently)

19:55:56,862341 [  LOG] Found new tx: {'height': 0, 'fee': 4771, 'tx_hash': 'e3180d1158b22bb4d06e2f94e57a42cfbaf0c9b5e474972a9d5500a2ac1083c7'}

A block is mined:

19:58:56,958999 [  LOG] A transaction confirmed: e3180d1158b22bb4d06e2f94e57a42cfbaf0c9b5e474972a9d5500a2ac1083c7
19:58:56,961204 [  LOG] A transaction became conflicted: 23f89ab86b8b21d5c26e45b3adafeac34355958bd08a62dff746c1c0c078ee99

Eventually electrum shows one confirmed transaction and correct balance. I'm wondering if it's possible to both fix the wrong balance report on our end while neither are confirmed and to also keep the non-mined conflicting transaction so it doesn't disappear entirely from the wallet, kinda like core does with keeping the record of the conflicted txs.

[chris-belcher]

When the conflicted transactions issue came up, in #electrum IRC I had a discussion and it was said that Electrum's protocol doesn't handle conflicted transactions at all, so I doubt there's a way to keep the conflicted one.

The wrong unconfirmed balance is weird, because I expected Electrum wallet to detect that both transactions spend the them input and therefore can't both be confirmed. It's weird because Electrum's own bumpfee feature gets handled expectedly (when sending).

One thing worth trying I could do is have testnet bitcoins sent from one Electrum wallet to another, and then see how the receiving Electrum wallet handles fee bumped transactions.

[bwhm]

Hi, Thanks for this great software. I am new to github, and not the strongest technical person, so please bear with me: I've had the same issue with server.py crashing after an RBF transaction. I created both transactions in electrum, but whenever I tried to broadcast the replacement, server.py would crash without broadcasting. I think I was able to broadcast eventually, but I can't remember for sure. I did try restart/delete wallet.dat/reimport/rescan, and I think that did the trick, but I might have ended pushing the raw tx through somewhere else.

Regardless, the electrum wallet did accept the replacement tx before I logged out (it was still unconfirmed). Now, whenever I try to open that particular wallet, server.py crashes immediately (EPS runs fine with other wallets.) The electrum wallet does not update the tx to confirmed, and another incoming tx is not shown. Both can be seen in the log file however. All this was on v0.1.1. I then forked your repo, and tried cloning the fork to include all the new commits since last release.

First I tried just copying in the old config.cfg file and run server.py, but the same happened - ie. crashing whenever I open the wallet with the RBF tx. After stopping bitcoind, deleting wallet, reimporting/rescanning, server.py now crashes by itself immediately after listing all the tx's in the log file.

Any idea what I can do here? Any particular commits to include or avoid? If needed, I can clean up the log files and send them to you.

Sorry for hijacking the thread with such a long post!

[chris-belcher]

Thanks for the bug report @bwhm I'll try to reproduce it. I don't know what can be done to fix it, I'll have to figure it out.

[bwhm]

Not sure if it will provide any help, but here is the censored log files using the forked version (not v0.1.1.):

07:40:59,856721 [DEBUG] current working directory is: /home/pi/electrum-personal-server 07:40:59,861233 [DEBUG] obtaining auth from rpc_user/pass 07:40:59,940045 [ LOG] Obtaining bitcoin addresses to monitor . . . 07:41:15,409983 [ LOG] Obtained list of addresses to monitor in 15.469574451446533sec 07:41:15,410420 [ LOG] Building history with 200 addresses . . . 07:41:16,062798 [DEBUG] listtransactions skip=0 len(ret)=30 xxx adding obtained tx =nnnn xxx 07:41:16,923734 [DEBUG] unconfirmed_txes = {} 07:41:16,924021 [DEBUG] reorganizable_txes = [] 07:41:16,924136 [DEBUG] last_known_wallettxid = (not the RBF tx, but the more incoming recent one)_ 07:41:17,011384 [DEBUG] address_history = xxx 07:41:17,011899 [ LOG] Found n txes. History built in 1.5135867595672607sec

Note that "07:41:16,062798 [DEBUG] listtransactions skip=0 len(ret)=30" is something I have seen with v0.1.1 as well, and I think it always leads to a crash.

[chris-belcher]

Thanks. I'll try sending a RBF fee-bumped transaction on testnet and see how Electrum and the server handles it.

Whats the actual crash message? Hopefully there would be a stack trace.

[bwhm]

The final entry in the debug.log file was "Found n txes ..." I have deleted the entire folder now to try again, but if there is somewhere else to look I can get back to you after rescan is complete.

[bwhm]

Hi again,

I have been running the script with screen, so I didn't notice this before as it doesn't show up in the log file:

Traceback (most recent call last):
  File "./server.py", line 534, in <module>
    main()
  File "./server.py", line 531, in main
    poll_interval_listening, poll_interval_connected, certfile, keyfile)
  File "./server.py", line 340, in run_electrum_server
    txmonitor)
  File "./server.py", line 117, in handle_query
    tx = rpc.call("gettransaction", [query["params"][0]])
  File "/home/pi/electrum-personal-server/electrumpersonalserver/jsonrpc.py", line 58, in call
    raise JsonRpcError(response["error"])
electrumpersonalserver.jsonrpc.JsonRpcError: {'code': -5, 'message': 'Invalid or non-wallet transaction id'}

This was the latest master. I am guessing it is the replaced transaction acting up. Unless the error is obvious to you, maybe there is a way I can edit the code manually to disregard it for now?

[chris-belcher]

Looks like the crash comes from this line https://github.com/chris-belcher/electrum-personal-server/blob/247e63061ef4686fa54660883e35931276874cc1/server.py#L117

So looks Bitcoin Core has seen the new fee-bumped transaction and deleted the old transaction from its wallet, then Electrum requests the old transaction which Bitcoin Core doesn't have. If so, what should happen is Core should somehow find out that a transaction was changed and then send a blockchain.scripthash.subscribe update with the new history including the new fee-bumped transaction.

Before that, I should play with Electrum and fee bumping a bit to see exactly what's happening and if my hypothesis above is true.

[chris-belcher]

I haven't been able to reproduce that crash. I sent a transaction and then fee bumped it. Electrum and EPS handled it correctly.

Bitcoin Core never deletes wallet transactions, it just makes them conflicted. I'm using the master branch which handles conflicted transactions correctly. Although you said your version of EPS includes all the latest commits, so that should handle conflicts too.

Let me know if it happens again, and save the debug logs of it happening if you can.

[bwhm]

Hi Chris,

I have been away for a while, but just downloaded newest release of Electrum (3.2.2) and EPS (0.1.3). Unfortunately, the results are the same:

Traceback (most recent call last): File "./server.py", line 559, in main() File "./server.py", line 556, in main poll_interval_listening, poll_interval_connected, certfile, keyfile) File "./server.py", line 364, in run_electrum_server txmonitor) File "./server.py", line 119, in handle_query tx = rpc.call("gettransaction", [query["params"][0]]) File "/home/pi/electrum-personal-server/electrumpersonalserver/jsonrpc.py", line 58, in call raise JsonRpcError(response["error"]) electrumpersonalserver.jsonrpc.JsonRpcError: {'message': 'Invalid or non-wallet transaction id', 'code': -5}

Note that my other wallet is running just fine, and it's just when I open this one it crashes. Let me know if there is anything else I can provide to assist in solving this. Unfortunately, I don't have the skills required to help you myself...

[chris-belcher]

So just so I understand from the beginning. You created a RBF transaction some time ago and it is still in your wallet.dat (and on the blockchain). Now when you try to sync your Electrum wallet with Electrum Personal Server, the server crashes with that error message?

[bwhm]

That is what I think is happening, yes. As far as I understand, this shouldn't matter, but I think I pushed the tx through a different node... I have deleted all files and rescanned a couple times, but not after these latest updates. This has fixed some crashes on startup before. I'll give that another try.

If that doesn't help, and I am the only one having this problem, maybe it's better to try on a regular electrum server and sweep it?

[chris-belcher]

Yes using a regular electrum server would work, but it doesn't help us fix this bug.

I'll try reproducing the bug on testnet by creating RBF transactions and maybe broadcasting them through other nodes.

Nobody else has reported a similar crash to my knowledge.

[bwhm]

Hello again Chris,

I have now synced a pruned node to test, but unfortunately got the same result.

Not my intention to push you on this issue, just to let you know that it wasn't that particular node. If you have any suggestions on node/eps configuration, I will of course try them out. If it matters EPS is running on OSX. I will try on a windows machine in a couple of days, and leave another comment if I get a different result.

[chris-belcher]

I've been reading some of Bitcoin Core's source code. @bwhm when you sync'd a pruned node did you keep the same wallet.dat ? If so you could try doing -zapwallettxes once and see if that fixes the problem.

[bwhm]

I replaced my old mac, and re-created the wallet (not copied) in electrum. I had also upgraded EPS on my Pi in the meantime, and possibly even updated core. Unfortunately, I can't tell you which of the many options that actually resolved it.

Was going to report back, but I completely forgot... Sorry, and thanks again for the excellent software.