`asb` wallet inaccessible after refreshing it with `monero-wallet-cli`
icy-ux opened this issue · 21 comments
Describe the bug
After accessing the asb wallet (asb-wallet) using monero-wallet-cli, asb is no longer able to access the wallet. This persists even after monero-wallet-rpc has been restarted, and after the entire machine has been restarted.
As part of troubleshooting #1061 I refreshed the wallet with monero-wallet-cli. This worked, but now I can't run asb anymore.
Lost/trapped Funds
No
Debug logs
2023-01-09T13:59:57.426024255Z DEBUG Opening Monero wallet
Error: Unable to create Monero wallet, please ensure that the monero-wallet-rpc is available
Caused by:
0: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
1: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
Platform:
- ASB
- Software Version
asb 0.12.0 - Operating System: Debian 11.6
Thanks for the report. When you open the wallet with the monero-wallet-cli did it make you set a password?
Thanks yeah confirmed that it's an empty password. Busy investigating further, trying to reproduce. Any logs from monero-wallet-rpc?
Nothing in journalctl -u monero-wallet-rpc. There are no relevant logs in /var/log/monero/. Should I look somewhere else?
Found a monero-wallet-rpc.log, which contained the following relevant if unhelpful entry:
2023-01-10 11:08:03.427 [RPC0] ERROR wallet.wallet2 src/wallet/wallet2.cpp:4744 boost::filesystem::exists(m_wallet_file, ignored_ec). THROW EXCEPTION: error::file_exists
2023-01-10 11:08:05.480 [RPC0] ERROR wallet.wallet2 src/wallet/wallet2.cpp:4744 boost::filesystem::exists(m_wallet_file, ignored_ec). THROW EXCEPTION: error::file_exists
Basically asb is trying to create the wallet after failing to open it, but that's expected behaviour when it fails to open a wallet. What we want to know is why the wallet opening failed in the first place...
One potential clue: monero-wallet-rpc seems to be automatically loading the wallet file:
2023-01-10 11:08:00.843 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5642 Loaded wallet keys file, with public address: 4redacted
This is happening even after restart, I guess because something somewhere has cached the (blank) password?
monero-wallet-rpc also seems to be looping:
2023-01-10 11:12:46.647 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5642 Loaded wallet keys file, with public address: 4redacted
2023-01-10 11:12:46.705 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5737 Failed to open portable binary, trying unportable
2023-01-10 11:12:46.750 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5759 Failed to open portable binary, trying unportable
2023-01-10 11:12:47.751 [RPC0] ERROR wallet.wallet2 src/wallet/wallet2.cpp:4744 boost::filesystem::exists(m_wallet_file, ignored_ec). THROW EXCEPTION: error::file_exists
2023-01-10 11:12:53.789 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5642 Loaded wallet keys file, with public address: 4redacted
2023-01-10 11:12:53.846 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5737 Failed to open portable binary, trying unportable
2023-01-10 11:12:54.069 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5759 Failed to open portable binary, trying unportable
2023-01-10 11:12:58.233 [RPC0] ERROR wallet.wallet2 src/wallet/wallet2.cpp:4744 boost::filesystem::exists(m_wallet_file, ignored_ec). THROW EXCEPTION: error::file_exists
This is happening regardless of whether asb is running, I think.
Ah, I had asb running as a systemd service and it was failing to start, thus the repeated tries in the monero-wallet-rpc log.
Stopped the asb systemd service. Restarted monero-wallet-rpc. Ran asb again. Same issue.
Appears monero-wallet-rpc is loading the wallet successfully (!!!) after asb fails.
Here asb fails at :52 ...
2023-01-10T11:21:52.839216578Z DEBUG Opening Monero wallet
Error: Unable to create Monero wallet, please ensure that the monero-wallet-rpc is available
Caused by:
0: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
1: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
And here monero-wallet-rpc succeeds at opening the wallet at :54, having started at :39...
2023-01-10 11:21:39.657 7f1268e8d7c0 WARNING wallet.rpc src/wallet/wallet_rpc_server.cpp:4559 Starting wallet RPC server
2023-01-10 11:21:54.006 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5642 Loaded wallet keys file, with public address: 4redacted
@delta1 Can it be that asb simply needs a longer timeout when loading an existing wallet?
I'm not reproducing this on the latest master.
- stopped
monero-wallet-rpc - opened the
asb-walletwithmonero-wallet-cliversion 0.18.1.2 - ran set_daemon and refresh successfully
- started
monero-wallet-rpc - started asb without issue
I've added a debug log in PR #1274, once that's merged you can use the ASB preview build to get a log message for why that wallet isn't opening. Hopefully it helps us debug this.
Thanks. Yes, having a binary will help, I tried building it (on Debian 11.3, Rust 1.62.1) but build failed:
Compiling bitcoin_hashes v0.11.0
error[E0658]: use of unstable library feature 'array_from_fn'
--> /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/enum-iterator-1.2.0/src/lib.rs:554:18 latest
|
554 | Some(core::array::from_fn(|_| unreachable!()))
| ^^^^^^^^^^^^^^^^^^^^
|
= note: see issue #89379 <https://github.com/rust-lang/rust/issues/89379> for more information
error[E0658]: use of unstable library feature 'array_from_fn'
--> /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/enum-iterator-1.2.0/src/lib.rs:557:18
|
557 | Some(core::array::from_fn(|_| x.clone()))
| ^^^^^^^^^^^^^^^^^^^^
|
= note: see issue #89379 <https://github.com/rust-lang/rust/issues/89379> for more information
error[E0658]: use of unstable library feature 'array_from_fn'
--> /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/enum-iterator-1.2.0/src/lib.rs:563:18
|
563 | Some(core::array::from_fn(|_| unreachable!()))
| ^^^^^^^^^^^^^^^^^^^^
|
= note: see issue #89379 <https://github.com/rust-lang/rust/issues/89379> for more information
error[E0658]: use of unstable library feature 'array_from_fn'
--> /home/user/.cargo/registry/src/github.com-1ecc6299db9ec823/enum-iterator-1.2.0/src/lib.rs:566:18
|
566 | Some(core::array::from_fn(|_| x.clone()))
| ^^^^^^^^^^^^^^^^^^^^
|
= note: see issue #89379 <https://github.com/rust-lang/rust/issues/89379> for more information
Compiling serde_urlencoded v0.7.1
Using +nightly build still fails:
~/xmr/xmr-btc-swap$ cargo +nightly build --release --bin asb
Compiling swap v0.12.1 (/home/user/xmr/xmr-btc-swap/swap)
error: failed to run custom build command for `swap v0.12.1 (/home/user/xmr/xmr-btc-swap/swap)`
Caused by:
process didn't exit successfully: `/home/user/xmr/xmr-btc-swap/target/release/build/swap-fa5d4a1e85978ad5/build-script-build` (exit status: 1)
--- stderr
Error: could not find repository from '/home/user/xmr/xmr-btc-swap/swap'; class=Repository (6); code=NotFound (-3)
You need Rust stable 1.62 or newer. Strange, you could try a newer Rust stable.
#1274 is merged, please try the binary from the preview build when it's ready
https://github.com/comit-network/xmr-btc-swap/releases/tag/preview
build action run
https://github.com/comit-network/xmr-btc-swap/actions/runs/3883255410
Hmm this slipped in: stephaneyfx/enum-iterator#20
You'll need 1.63 or newer
Well, rust-toolchain.toml forces it to the 1.26 channel:
rust-toolchain.toml
2:channel = "1.62"
But even with +nightly, the custom build script at swap/build.rs fails, giving the 2nd error message above.
I downloaded the preview release with wget -c "https://github.com/comit-network/xmr-btc-swap/releases/download/preview/asb_preview_Linux_x86_64.tar" , extracted it, and tried running it. Unfortunately the error message is not helpful:
2023-01-10T12:39:28.145782647Z DEBUG Opening Monero wallet
2023-01-10T12:39:29.568034566Z DEBUG Open wallet response error error=JSON-RPC request failed with code -1: Failed to open wallet
Error: Unable to create Monero wallet, please ensure that the monero-wallet-rpc is available
Caused by:
0: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
1: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
Here's the corresponding monero-wallet-rpc log entries:
2023-01-10 12:39:29.406 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5642 Loaded wallet keys file, with public address: 4redacted
2023-01-10 12:39:29.489 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5737 Failed to open portable binary, trying unportable
2023-01-10 12:39:29.530 [RPC0] WARNING wallet.wallet2 src/wallet/wallet2.cpp:5759 Failed to open portable binary, trying unportable
2023-01-10 12:39:30.702 [RPC0] ERROR wallet.wallet2 src/wallet/wallet2.cpp:4744 boost::filesystem::exists(m_wallet_file, ignored_ec). THROW EXCEPTION: error::file_exists
As we can see, monero-wallet-rpc successfully loaded the wallet keys file at 29.406 while asb failed at 29.568, and the final file_exists error didn't come until 30.702, so I really don't know what's going on here.
(see edits above)
@icy-ux please try the binary here to get a more detailed error message: https://github.com/comit-network/xmr-btc-swap/releases/tag/preview
@delta1 I did, the more detailed error message is this line in the above quoted logs:
2023-01-10T12:39:29.568034566Z DEBUG Open wallet response error error=JSON-RPC request failed with code -1: Failed to open wallet
This is the preview binary before you updated the build stuff. I don't see any code changes in the more recent commit which would affect the error message. If I'm wrong, please let me know and I will update the binary.
That’s what we were looking for but not very helpful 😕
I suspect it’s a permissions issue. Can you check that the asb-wallet is owned and rwx for your systemd service/root user?
You mentioned that your asb is run as a systemd service, is it possible when you used the monero-wallet-cli you changed the owner or perms?
My asb is run as a systemd service using the user account asb. Here are the current permissions for the wallet:
# ls -al asb-wallet*
-rwx--x--x 1 asb nogroup 4428761 9. Jan 13:52 asb-wallet
-rw------- 1 asb nogroup 1680 9. Jan 06:32 asb-wallet.keys
-rw------- 1 asb asb 4428761 10. Jan 12:39 asb-wallet.unportable
For all these tests, I naturally have been runing the asb binary as this user, passing the config file which the systemd service has been using (and was using back when everything was working):
$ sudo -u asb ./asb --config /etc/asb/config.toml balance
2023-01-10T18:41:16.148424092Z INFO Initialized tracing level=debug
2023-01-10T18:41:16.148457804Z INFO Reading config file path=/etc/asb/config.toml
2023-01-10T18:41:16.148665271Z DEBUG Using existing sqlite database.
2023-01-10T18:41:16.149285342Z DEBUG Reading in seed from /etc/asb/seed.pem
2023-01-10T18:41:16.149298249Z DEBUG Opening Monero wallet
2023-01-10T18:41:17.668920066Z DEBUG Open wallet response error error=JSON-RPC request failed with code -1: Failed to open wallet
Error: Unable to create Monero wallet, please ensure that the monero-wallet-rpc is available
Caused by:
0: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
1: JSON-RPC request failed with code -21: Cannot create wallet. Already exists.
For the sake of completeness, here's the relevant section of the config.toml:
[monero]
wallet_rpc_url = "http://127.0.0.1:18083/json_rpc"
network = "Mainnet"
Here's what happens when I run monero-wallet-cli as the asb user:
$ sudo -u asb monero-wallet-cli
[sudo] Passwort für user:
This is the command line monero wallet. It needs to connect to a monero
daemon to work correctly.
WARNING: Do not reuse your Monero keys on another fork, UNLESS this fork has key reuse mitigations built in. Doing so will harm your privacy.
Monero 'Fluorine Fermi' (v0.18.1.2-release)
Logging to monero-wallet-cli.log
Specify wallet file name (e.g., MyWallet). If the wallet doesn't exist, it will be created.
Wallet file name (or Ctrl-C to quit): /etc/asb/asb-wallet
Wallet and key files found, loading...
Wallet password:
Opened wallet: [redacted]
**********************************************************************
Use the "help" command to see a simplified list of available commands.
Use "help all" to see the list of all available commands.
Use "help <command>" to see a command's documentation.
**********************************************************************
Background mining not enabled. Run "set setup-background-mining 1" to change.
Starting refresh...
Refresh done, blocks received: 873
Untagged accounts:
Account Balance Unlocked balance Label
* 0 [redacted] [redacted] [redacted] Primary account
------------------------------------------------------------------------------------
Total [redacted] [redacted]
Currently selected account: [0] Primary account
Tag: (No tag assigned)
Balance: [redacted], unlocked balance: [redacted]
Background refresh thread started
Able to duplicate the error using a bare JSON-RPC call:
$ curl -X POST http://localhost:18083/json_rpc -d '{"jsonrpc":"2.0","id":"0","method":"open_wallet","params":{"filename":"asb-wallet"}}' -H 'Content-Type: application/json'
{
"error": {
"code": -1,
"message": "Failed to open wallet"
},
"id": "0",
"jsonrpc": "2.0"
}
I took a look at what monero-wallet-rpc was doing using strace -o rpc-out.txt /usr/local/bin/monero-wallet-rpc --daemon-host 127.0.0.1:18089 --rpc-bind-port 18083 --disable-rpc-login --wallet-dir /etc/asb.
The results were singularly underwhelming. Nothing related to accessing the wallet seems to appear in the strace log. Even the write calls for the logging messages relating to there being no wallet do not appear in the strace log.
That leaves the few error messages we do have. Failed to open portable binary, trying unportable seems to be related to an updated Monero wallet file format that requires us to delete the wallet cache.
Renamimg asb-wallet.unportable to asb-wallet.unportable.bak did not help.
So renamed the asb-wallet to asb-wallet-old, and created a new wallet.
Now we have a new address, which is printed by running asb start.
2023-01-11T09:52:07.609955865Z WARN The Monero balance is 0, make sure to deposit funds at monero_address=4redacted
Used monero-wallet-cli to sweep the balance from swept all balance to the new address.
[wallet 4old]: sweep_all 4redacted
Now DB won't load:
2023-01-11T09:48:08.103342655Z ERROR Failed to load swaps from database: invalid type: sequence, expected a string at line 1 column 1761
Since we don't have any open swaps we can trash the old DB and start afresh.
So rename the database to sqlite.bak and it works.
Now open the new asb-wallet using monero-wallet-cli (press enter, blank password). Don't turn on mining.
New incoming Tx is shown as locked balance.
Close monero-wallet-cli.
Run asb. Total XMR balance is shown as 0.
Wait until incoming Tx confirms. Check status using monero-wallet-cli:
Height 27redacted, txid <2redacted>, redacted, idx 0/0
Refresh done, blocks received: 17
Untagged accounts:
Account Balance Unlocked balance Label
* 0 redacted redacted [whole balance] Primary account
asb still shows balance as 0.
Summary of the original problem and its solution
- There was a change to the Monero wallet (cache) format which appears to have broken
monero-wallet-rpc's ability to access the wallet - Renaming the wallet and letting
asbcreate a new wallet fixed the problem
Current problem
- XMR sent to the new wallet address is not recognised by
asb, even if it is visible usingmonero-wallet-clias unlocked balance.
Looking at the monero-wallet-rpc logs, seems it's having trouble parsing the transaction:
2023-01-11 10:30:37.598 7fa106c4f700 ERROR cn src/cryptonote_basic/cryptonote_format_utils.cpp:215 Failed to parse transaction from blob
2023-01-11 10:30:37.598 7fa10674e700 ERROR cn src/cryptonote_basic/cryptonote_format_utils.cpp:215 Failed to parse transaction from blob
2023-01-11 10:30:37.598 7fa10624d700 ERROR cn src/cryptonote_basic/cryptonote_format_utils.cpp:215 Failed to parse transaction from blob
2023-01-11 10:30:37.598 [RPC0] ERROR cn src/cryptonote_basic/cryptonote_format_utils.cpp:215 Failed to parse transaction from blob
Since monero-wallet-rpc seems to be causing lots of problems, maybe I have an old version?
$ whereis monero-wallet-rpc
monero-wallet-rpc: /usr/bin/monero-wallet-rpc /usr/local/bin/monero-wallet-rpc
$ /usr/bin/monero-wallet-rpc --version
Monero 'Fluorine Fermi' (v0.18.1.2-release)
$ /usr/local/bin/monero-wallet-rpc --version
Monero 'Oxygen Orion' (v0.17.2.3-release)
A ha, looks like I got stuck with 2 copies of monero-wallet-rpc and one hasn't been updated.
$ sudo rm -rf /usr/local/bin/monero-wallet-rpc
$ sudo vim /etc/systemd/system/monero-wallet-rpc # update the systemd service to use the binary at /usr/bin/
$ sudo systemctl stop monero-wallet-rpc
$ sudo systemctl daemon-reload
$ sudo systemctl start monero-wallet-rpc
Then after running asb balance it shows an XMR balance of 0 initially. Running asb balance again shows the correct balance.
Summary of the problem and its solution
- There were two
monero-wallet-rpcbinaries on my system. One binary was old and had not been updated - The old version of
monero-wallet-rpchad been unable to handle newer versions of transactions, wallet formats, etc - Deleting the old version, and having the systemd service use the newer binary, fixed the problem
Thank you for your write-up @icy-ux it is appreciated. Sorry I couldn't reproduce your issue but glad you found a way around it, definitely seems related to the different wallet rpc versions especially since those coincided with before/after the most recent hard fork.
Closing for now, thanks again for your debugging and just reopen this issue if necessary.