search

comit-network / xmr-btc-swap

Bitcoin–Monero Cross-chain Atomic Swap
GNU General Public License v3.0
650 stars 82 forks source link

[0.3 XMR] `monero-wallet-rpc` failed to fetch transaction while doing a transaction #1061

Open robert-j-webb opened 2 years ago

robert-j-webb commented 2 years ago

Not sure quite what's going on here, but when doing a normal transaction, I'm seeing

Waiting for Monero transaction finality txid=xxxxx target_confirmations=10
`monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=xxxxx
Connected to Alice at <address>
`monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=xxxxx

And the monero wallet rpc message keeps repeating.

delta1 commented 2 years ago

Did you try restarting monero-wallet-rpc ? Does the same message persist? Do you have any logs from monero-wallet-rpc ?

jxadl commented 2 years ago

Same issue here. How do I restart monero-wallet-rpc? Please help, I got my funds locked.

delta1 commented 2 years ago

swap cli spawns its own monero-wallet-rpc, so I think you'll have to copy your swap-id, cancel your swap process with ctrl+c, and then run swap resume --swap-id <swap-id>

jxadl commented 2 years ago

After running swap resume --swap-id <swap-id> problem continues, the same message keeps on repeating in a loop.

delta1 commented 2 years ago

Which version of swap cli are you running?

Please also try adding the --debug flag to give more info

delta1 commented 2 years ago

I'm adding some debug info in #1088 so once that is merged you can try the preview build and we can hopefully figure out what's happening in the wallet rpc call

jxadl commented 2 years ago

swap version: 0.10.2

./swap --debug resume --swap-id <redacted_swap_id>
2022-08-03T15:23:10.2536689+02:00 DEBUG Using existing sqlite database.
2022-08-03T15:23:10.2609838+02:00 DEBUG Reading in seed from C:\Users\xadli\AppData\Roaming\xmr-btc-swap\data\cli\mainnet\seed.pem
2022-08-03T15:23:11.3629669+02:00 DEBUG Starting monero-wallet-rpc port=60990
2022-08-03T15:23:18.7087391+02:00 DEBUG Opened Monero wallet monero_wallet_name=swap-tool-blockchain-monitoring-wallet
2022-08-03T15:23:20.7552569+02:00 DEBUG Network layer initialized peer_id=<redacted>
2022-08-03T15:23:20.7575701+02:00 DEBUG Advancing state state=XMR lock transaction transfer proof received
2022-08-03T15:23:20.75842+02:00  INFO Waiting for Monero transaction finality txid=<redacted> target_confirmations=10
2022-08-03T15:23:20.7723541+02:00  WARN `monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=<redacted>
2022-08-03T15:23:20.9912499+02:00  INFO Connected to Alice at /ip4/45.138.50.29/tcp/9939/p2p/12D3KooWMgGjeW7ErQxCQzaeHiXxJn42wegCPFepixEXfBJT1PNS
2022-08-03T15:23:25.7723249+02:00 DEBUG Found relevant Bitcoin transaction txid=<redacted> status=unseen
2022-08-03T15:23:32.7808794+02:00  WARN `monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=<redacted>
2022-08-03T15:23:44.7741106+02:00  WARN `monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=<redacted>
2022-08-03T15:23:56.7644423+02:00  WARN `monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=<redacted>

...and so on.

delta1 commented 2 years ago

@jxadl please try the new preview build which should provide an error message from the wallet rpc

https://github.com/comit-network/xmr-btc-swap/releases/tag/preview

allconnected commented 2 years ago

Had the same issue. Updating swap.exe to the preview release mentioned by @delta1 fixed this issue. Had to replace the swap.exe and executed swap resume --swap-id <swap_id>. The swap didn't finish fully tough, I had to manually open the wallet where it was 'swapped' to and send it to my address.

delta1 commented 2 years ago

Thanks @allconnected so you didn’t see the same error message at all?

Will be doing a new release soon 👌

allconnected commented 2 years ago

@delta1 I did see the same error message. If you mean this one: `monero-wallet-rpc` failed to fetch transaction, may need to be restarted txid=xxxxx

lescuer97 commented 2 years ago

just got the monero-wallet-rpc message for the first time

delta1 commented 2 years ago

just got the monero-wallet-rpc message for the first time

... and then what happened?

delta1 commented 2 years ago

Spotted this too, with error message Failed to parse transaction from daemon - trying to create a reproducing test case

lescuer97 commented 2 years ago

e

Basically it just keeps sending the message about the error and it doesn't progress on sending messages about locks in ALICE. This also happened to me with @binarybaron asb

IMPORTANT NOTE: the btc got punished, even before the 72 confirmations

delta1 commented 2 years ago

The error message above Failed to parse transaction from daemon means that the wallet-rpc inside the swap cli is failing to parse the response from the monero daemon. I suspect that the melo.tools/rino nodes are already upgraded to the newer monero version, while the swap cli is still using the older version.

Will confirm this once #1081 is complete

delta1 commented 2 years ago

The cause is the swap cli using an older version of the wallet-rpc.

Manual fix: replace with latest monero-wallet-rpc executable (at least v0.18.0) in the swap/monero folder

(on linux this is ~/.local/share/xmr-btc-swap/cli/<network>/monero )

Upcoming fix in new release after #1100: remove the above folder and swap will download the newer binary

binarybaron commented 1 year ago

@delta1 This issue still seems to persist on the asb side in some cases. See the logs below for an example. Restarting the asb seems to fix the issue.

Maybe we need to wait for some time for the daemon to properly register the newly submitted transaction?

mainnet_asb  | 2022-12-28T15:51:17.320455736Z DEBUG ask_price=0.0095689 BTC xmr=2.000000000000 XMR max_bitcoin_for_monero=0.01913764 BTC
mainnet_asb  | 2022-12-28T15:51:17.593121474Z DEBUG Estimated fee for transaction weight=548 fee_rate=23.154 sats_per_vbyte=3172.0980
mainnet_asb  | 2022-12-28T15:51:17.629852128Z DEBUG Estimated fee for transaction weight=548 fee_rate=23.154 sats_per_vbyte=3172.0980
mainnet_asb  | 2022-12-28T15:51:18.626422959Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=started rate=0.0095689
BTC
mainnet_asb  | 2022-12-28T15:52:24.094491185Z DEBUG Got notification for new block block_height=769278
mainnet_asb  | 2022-12-28T15:52:25.364037503Z DEBUG Bitcoin transaction status changed txid=d3495246e5c4c7a76b1f1c9f05f24c1a1b0f1e6f5c70b7e7a5fb1288ef951bb6
new_status=in mempool old_status=unseen
mainnet_asb  | 2022-12-28T15:52:25.463475796Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=bitcoin lock
transaction in mempool rate=0.0095667 BTC
mainnet_asb  | 2022-12-28T15:52:25.508002233Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Waiting for Bitcoin transaction finality txid=d3495246e5c4c7a76b1f1c9f05f24c1a1b0f1e6f5c70b7e7a5fb1288ef951bb6 required_confirmation=1
mainnet_asb  | 2022-12-28T15:59:25.880809931Z DEBUG Got notification for new block block_height=769279
mainnet_asb  | 2022-12-28T15:59:26.340546788Z DEBUG Bitcoin transaction status changed txid=d3495246e5c4c7a76b1f1c9f05f24c1a1b0f1e6f5c70b7e7a5fb1288ef951bb6
new_status=confirmed with 1 blocks old_status=in mempool
mainnet_asb  | 2022-12-28T15:59:26.34094725Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Waiting for Bitcoin transaction finality txid=d3495246e5c4c7a76b1f1c9f05f24c1a1b0f1e6f5c70b7e7a5fb1288ef951bb6 seen_confirmations=1 needed_confirmations=1
mainnet_asb  | 2022-12-28T15:59:26.405621859Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=btc
is locked rate=0.0095744 BTC
mainnet_asb  | 2022-12-28T16:01:23.424243788Z DEBUG New connection established peer=12D3KooWAXG7aigLEQPWg3x8gTNxco3i6Czb8q5Dk274GeYSwcTb address=/ip4/*****/tcp/7271
mainnet_asb  | 2022-12-28T16:02:26.028763082Z DEBUG swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Successfully initiated Monero transfer amount=0.156768280575 XMR to=6c0a200ce9a7b22626f1ad31fd65d2be308a69020373ae19b3f6ec6f3df3b107 tx_id=e2f39fddc9ddd48eec0186596ab5da37619cc2db2436e35d0b0135793dfc2cdc
mainnet_asb  | 2022-12-28T16:02:26.179117594Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=xmr
lock transaction sent rate=0.0095744 BTC
mainnet_asb  | 2022-12-28T16:02:26.190760252Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Waiting for Monero transaction finality txid=e2f39fddc9ddd48eec0186596ab5da37619cc2db2436e35d0b0135793dfc2cdc target_confirmations=1
mainnet_asb  | 2022-12-28T16:02:27.279412818Z DEBUG Got notification for new block block_height=769280
mainnet_asb  | 2022-12-28T16:02:29.280340479Z DEBUG Bitcoin transaction status changed txid=d3495246e5c4c7a76b1f1c9f05f24c1a1b0f1e6f5c70b7e7a5fb1288ef951bb6
new_status=confirmed with 2 blocks old_status=confirmed with 1 blocks
mainnet_asb  | 2022-12-28T16:02:29.289945671Z DEBUG swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Failed to get transaction
from daemon data=None
mainnet_asb  | 2022-12-28T16:02:29.300652822Z  WARN swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: `monero-wallet-rpc` failed
to fetch transaction, may need to be restarted txid=e2f39fddc9ddd48eec0186596ab5da37619cc2db2436e35d0b0135793dfc2cdc Failed
to get transaction from daemon
mainnet_asb  | 2022-12-28T16:05:58.173500067Z DEBUG New connection established peer=12D3KooWAXG7aigLEQPWg3x8gTNxco3i6Czb8q5Dk274GeYSwcTb address=/ip4/*****/tcp/7317
mainnet_asb  | 2022-12-28T16:06:26.205792789Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Received new confirmation
for Monero lock tx txid=e2f39fddc9ddd48eec0186596ab5da37619cc2db2436e35d0b0135793dfc2cdc seen_confirmations=1 needed_confirmations=1
mainnet_asb  | 2022-12-28T16:06:26.258378323Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=xmr
is locked rate=0.0095744 BTC
mainnet_asb  | 2022-12-28T16:06:26.330679741Z DEBUG Bob acknowledged transfer proof peer=12D3KooWAXG7aigLEQPWg3x8gTNxco3i6Czb8q5Dk274GeYSwcTb
mainnet_asb  | 2022-12-28T16:06:26.34248353Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=xmr lock transfer proof
sent rate=0.0095744 BTC
mainnet_asb  | 2022-12-28T16:06:44.163944231Z DEBUG New connection established peer=QmSu99WA5QWjQfG2k83mLXSkb8tpSxDN3k4dQD61TKtVLT address=/ip4/*****/tcp/59878
mainnet_asb  | 2022-12-28T16:06:44.248948607Z DEBUG ask_price=0.0095744 BTC xmr=1.843201079425 XMR max_bitcoin_for_monero=0.01764739 BTC
mainnet_asb  | 2022-12-28T16:06:53.944871949Z DEBUG Lost connection to peer: Connection error: I/O error: unexpected end of file peer=QmSu99WA5QWjQfG2k83mLXSkb8tpSxDN3k4dQD61TKtVLT address=/ip4/*****/tcp/59878
mainnet_asb  | 2022-12-28T16:06:58.018123572Z  INFO Initialized tracing level=debug
mainnet_asb  | 2022-12-28T16:06:58.018289806Z  INFO Reading config file path=/asb-data/config_mainnet.toml
mainnet_asb  | 2022-12-28T16:06:58.031460118Z DEBUG Using existing sqlite database.
mainnet_asb  | 2022-12-28T16:06:58.058622574Z DEBUG Reading in seed from /asb-data/seed.pem
mainnet_asb  | 2022-12-28T16:06:58.058875891Z DEBUG Opening Bitcoin wallet
mainnet_asb  | 2022-12-28T16:07:11.123615943Z DEBUG Opening Monero wallet
mainnet_asb  | 2022-12-28T16:07:13.920431258Z DEBUG Opened Monero wallet monero_wallet_name=asb-wallet
mainnet_asb  | 2022-12-28T16:07:13.922669647Z  INFO Initialized Bitcoin wallet bitcoin_balance=0 BTC
mainnet_asb  | 2022-12-28T16:07:13.923280102Z  INFO Initialized Monero wallet monero_balance=***** XMR
mainnet_asb  | 2022-12-28T16:07:13.924969327Z  WARN Tor not found. Running on clear net
mainnet_asb  | 2022-12-28T16:07:13.935728896Z  INFO Network layer initialized peer_id=12D3KooWMiriru5viqde3BMFLTqPur8Yrjpp4ULFc76ubQLfuYYX
mainnet_asb  | 2022-12-28T16:07:13.937918033Z DEBUG Connected to Kraken websocket API
mainnet_asb  | 2022-12-28T16:07:13.937955724Z DEBUG Subscribed to updates for ticker
mainnet_asb  | 2022-12-28T16:07:13.952175023Z  INFO Resuming swap swap_id=a1dcde29-7b57-46d0-9b4f-c37d48279c74
mainnet_asb  | 2022-12-28T16:07:13.953045696Z  INFO New listen address reported address=/ip4/127.0.0.1/tcp/9940/ws
mainnet_asb  | 2022-12-28T16:07:13.953074066Z  INFO swap{id=a1dcde29-7b57-46d0-9b4f-c37d48279c74}: Advancing state state=xmr
lock transfer proof sent rate=0.0095744 BTC
binarybaron commented 1 year ago

We use bounties to incentivize development and reward contributors. All issues available for a bounty have the Bounty 💰 label.

To receive the bounty of this issue, you agree to these conditions:

icy-ux commented 1 year ago

Seeing this issue with asb. It looks like XMR from the relevant transaction (which happened in August 2022 and reached state btc is redeemed) is still locked.

There is already a workaround for a related issue when this crops up from the taker/swap tool side.

For asb users, there is a singular wallet, asb-wallet, which can be accessed using monero-wallet-cli (password is blank).

I am currently waiting on monero-wallet-ci to finish refreshing the wallet. Maybe that will fix it.

icy-ux commented 1 year ago

Refreshing the wallet with monero-wallet-cli worked, but rendered the wallet inaccessible by asb, see #1273

icy-ux commented 1 year ago

Resolved this problem after considerable troubleshooting in #1273 .

Summary of the solution

This does not appear to be an issue which can be directly fixed by code changes to asb or xmr-btc-swap. The best we could likely do is make a JSON-RPC get_version call to monero-wallet-rpc and hardcode a minimum acceptable version value, telling the user to upgrade their monero-wallet-rpc if they are using too low a version.

icy-ux commented 1 year ago

@binarybaron Not sure if this qualifies for the bounty, I'll let you decide.

binarybaron commented 1 year ago

1273

Hey, thanks for the write up. I'm 100% sure I'm not on an old version of monero-wallet-rpc (v0.18.1.2). My daemon is fully synced and the RPC is functional. I don't think this issue is related to an incompatible version (or at least not entirely).

I'm experiencing this issue for (almost) all swaps but it's not preventing them from being successful. I think the asb fails to fetch the transaction immediately after publishing it but when it retries some time later, it is able to proceed with the swap.

icy-ux commented 1 year ago

@binarybaron Checking twice may do the trick.

As I observed while getting this fixed:

Then after running asb balance it shows an XMR balance of 0 initially. Running asb balance again shows the correct balance.

In the logs, this manifested as follows. I will present entries from the monero-wallet-rpc and asb interleaved, to make it more clear what's going on.

2023-01-11T10:36:42.612719073Z DEBUG Opening Monero wallet

2023-01-11 10:36:44.392 [RPC0]  WARNING wallet.wallet2  src/wallet/wallet2.cpp:5569     Loaded wallet keys file, with public address: 4redacted

2023-01-11T10:36:44.5046187Z DEBUG Opened Monero wallet monero_wallet_name=asb-wallet
2023-01-11T10:36:44.506220222Z  INFO monero_balance=total balance: 0.000000000000, unlocked balance: 0.000000000000

2023-01-11 10:36:49.764     7f0d965e8700        WARNING wallet.wallet2  src/wallet/wallet2.cpp:1920     Transaction extra has unsupported format: <edredacted>
2023-01-11 10:36:49.764     7f0d96ae9700        WARNING wallet.wallet2  src/wallet/wallet2.cpp:1920     Transaction extra has unsupported format: <23redacted>
2023-01-11 10:36:49.797 [RPC0]  WARNING wallet.wallet2  src/wallet/wallet2.cpp:2219     Received money: [redacted], with tx: <25redacted>            

2023-01-11T10:37:11.524766901Z DEBUG Opening Monero wallet
2023-01-11T10:37:12.730423111Z DEBUG Opened Monero wallet monero_wallet_name=asb-wallet
2023-01-11T10:37:12.730862155Z  INFO monero_balance=total balance: [redacted], unlocked balance: [redacted]

2023-01-11 10:37:12.701 [RPC0]  WARNING wallet.wallet2  src/wallet/wallet2.cpp:5569     Loaded wallet keys file, with public address: 4redacted
2023-01-11 10:42:12.600     7f0d965e8700        WARNING wallet.wallet2  src/wallet/wallet2.cpp:1920     Transaction extra has unsupported format: <dredacted>

What we see is:

  1. asb opens the XMR wallet the first time
  2. about 100ms later, monero-wallet-rpc reports a balance of 0, which asb displays
  3. 300ms after that, monero-wallet-rpc discovers that the balance is not 0 and that the wallet had received a tx
  4. when I open asb again, it queries the balance and monero-wallet-rpc returns the correct balance

This is perfectly consistent with what you report: the first time asb queries wallet state, it gets outdated information. Then, some hundreds of milliseconds later, the back-end gets up-to-date information and the second query by asb returns the correct information.

The obvious solution would be to find the code path which is producing the error, and then insert a retry (after 1000ms?) before entering an error condition.

icy-ux commented 1 year ago

@binarybaron try #1277 and see if that fixes it for you

delta1 commented 1 year ago

related: https://github.com/monero-project/monero/issues/2875#issuecomment-347698558

binarybaron commented 1 year ago

I don't think the Transaction extra has unsupported format log message is related to this issue