Xud: [Connext] walletdeposit returns 500 server error

[jgarzik]

Background

1. Successful xud setup, using all-default configuration.
2. Successful walletdeposit eth. 0.8 ETH appear as expected in the Wallet Balance column of getbalance.
3. Attempts to openchannel fail with the same error:

mainnet > openchannel ETH 0.8
Error: 2 UNKNOWN: failed to open ETH channel for 80000000: connext server error 500: Internal Server Error

Your environment

• version of xud: 1.0.1-d04e4bd5
• which operating system (uname -a on *Nix): Linux whi1 4.15.0-117-generic #118-Ubuntu SMP Fri Sep 4 20:02:41 UTC 2020 x86_64 x86_64 x86_64 GNU/Linux

• version of btcd, bitcoind, ltcd, litecoind, geth, parity, connext, lnd or other chain backend: all xud defaults for light-node:
  connext 1.3.3
  LND-BTC 0.11.0-beta commit=v0.11.0-beta
  LND-LTC 0.11.0-beta.rc1 commit=v0.11.0-beta.rc1

• any other relevant environment details:

Steps to reproduce

1. deposit ETH
2. openchannel on ETH

Expected behaviour

channel opens

Actual behaviour

500 server error, shown above

[jgarzik]

mainnet > status
┌───────────┬────────────────────────────────────────────────┐
│ SERVICE   │ STATUS                                         │
├───────────┼────────────────────────────────────────────────┤
│ bitcoind  │ Ready (light mode)                             │
├───────────┼────────────────────────────────────────────────┤
│ litecoind │ Ready (light mode)                             │
├───────────┼────────────────────────────────────────────────┤
│ geth      │ Ready (light mode)                             │
├───────────┼────────────────────────────────────────────────┤
│ lndbtc    │ Ready                                          │
├───────────┼────────────────────────────────────────────────┤
│ lndltc    │ Ready                                          │
├───────────┼────────────────────────────────────────────────┤
│ connext   │ Ready                                          │
├───────────┼────────────────────────────────────────────────┤
│ boltz     │ Ready                                          │
├───────────┼────────────────────────────────────────────────┤
│ xud       │ Ready                                          │
└───────────┴────────────────────────────────────────────────┘

[jgarzik]

Tried same with 0.7 ETH, rather than 0.8 as displayed in getbalance.

That succeeded.

[kilrau]

Thank you for opening this issue! That sounds very much like https://github.com/connext/rest-api-client/issues/93 (gas estimation missing), what do you think guys? @michael1011 @erkarl

[raladev]

tested, it is not gas err.

1. when u trying to open channel for full amount, some micro eth's are added to your amount, as a result u got not enough funds err.

Screenshot from 2020-09-11 14-45-18
Screenshot from 2020-09-11 14-45-17

1. also i did not get response for deposit call several times when tried to withdraw full amount and as a result got infinite wait for openchannel command
   Screenshot from 2020-09-11 15-24-38

Connext client log:

2020-09-11T12:11:26.025Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 36 ms
[1599826286749] INFO  (81 on connext): received request
    url: "/deposit"
    id: 16604
    reqId: 16604
[1599826286750] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:11:26.754Z [DepositController] Deposit started: {"amount":"5998766850000000000"}
2020-09-11T12:11:26.755Z [DepositController] Depositing 5998766850000000000 of 0x0000000000000000000000000000000000000000 into channel
2020-09-11T12:11:27.985Z [DepositController] requestDepositRights started: {"assetId":"0x0000000000000000000000000000000000000000"}
2020-09-11T12:11:27.987Z [CF-GetAppInstances] Executing with params: {"multisigAddress":"0x9F26..9b1C"}
2020-09-11T12:11:28.005Z [CF-GetAppInstances] Before execution complete in 18 ms
2020-09-11T12:11:28.007Z [CF-RpcRouter] Processed chan_getAppInstances method in 20 ms
2020-09-11T12:11:28.541Z [DepositController] Calling propose install
2020-09-11T12:11:28.543Z [CF-GetFreeBalanceState] Executing with params: {"multisigAddress":"0x9F26..9b1C","assetId":"0x0000..0000"}
2020-09-11T12:11:28.548Z [CF-GetFreeBalanceState] Before execution complete in 6 ms
2020-09-11T12:11:28.561Z [CF-GetFreeBalanceState] Executed method implementation in 12 ms
2020-09-11T12:11:28.561Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 19 ms
2020-09-11T12:11:28.562Z [CF-ProposeInstall] Executing with params: {"abiEncodings":{"stateEncoding":"tuple( tuple( address to, uint256 amount)[2] transfers, address multisigAddress, address assetId, uint256 startingTotalAmountWithdrawn, uint256 startingMultisigBalance)"},"appDefinition":"0x4aE3..B644","initialState":{"transfers":[{"amount":"0","to":"0x7AdF..08A6"},{"amount":"0","to":"0xE223..1BA6"}],"multisigAddress":"0x9F26..9b1C","assetId":"0x0000..0000","startingTotalAmountWithdrawn":"25000000000000000000","startingMultisigBalance":"50000000000000000"},"initiatorDeposit":"0","initiatorDepositAssetId":"0x0000..0000","multisigAddress":"0x9F26..9b1C","outcomeType":"SINGLE_ASSET_TWO_PARTY_COIN_TRANSFER","responderIdentifier":"indra6WRA..4cBh","responderDeposit":"0","responderDepositAssetId":"0x0000..0000","defaultTimeout":"8640","stateTimeout":"8640"}
2020-09-11T12:11:28.617Z [NodeApiClient] Node responded to indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5.indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh.1337.lock.acquire.0x9F263F85CB47B041291C506E17C976800c929b1C request in 54 ms
2020-09-11T12:11:28.617Z [CF-ProposeInstall] Acquired locks 0x9F263F85CB47B041291C506E17C976800c929b1C in 55 ms
2020-09-11T12:11:28.624Z [CF-ProposeInstall] Before execution complete in 6 ms
2020-09-11T12:11:28.625Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Initiation started
[1599826288976] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:11:28.978Z [CF-GetFreeBalanceState] Executing with params: {"multisigAddress":"0x9F26..9b1C","assetId":"0x0000..0000"}
2020-09-11T12:11:28.982Z [CF-GetFreeBalanceState] Before execution complete in 4 ms
[1599826288984] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:11:28.985Z [CF-GetFreeBalanceState] Executing with params: {"multisigAddress":"0x9F26..9b1C","assetId":"0x61F6..C94D"}
2020-09-11T12:11:28.994Z [CF-GetFreeBalanceState] Executed method implementation in 12 ms
2020-09-11T12:11:28.996Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 19 ms
2020-09-11T12:11:28.999Z [CF-GetFreeBalanceState] Before execution complete in 14 ms
2020-09-11T12:11:29.006Z [CF-GetFreeBalanceState] Executed method implementation in 6 ms
2020-09-11T12:11:29.007Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 22 ms
2020-09-11T12:11:29.072Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Signed set state commitment 0xb905d05661693ee61edd9f263b8e2758382f62a13f8c6d2c3a62975d1802dec4 & conditional transfer commitment 0x4f22c0cba83f26cf72799228cf742aa4ad9998a0e9ee5cc562ae2da29ba41ba4 in 17 ms
2020-09-11T12:11:29.359Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Persisted app instance 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa in 10 ms
2020-09-11T12:11:29.413Z [NodeApiClient] Node responded to indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5.indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh.1337.lock.release.0x9F2

Connext node logs:

2020-09-11T12:03:21.920Z [OnchainTransactionService] Success sending transaction! Tx mined at block 177273 on chain 1337: 0x4b0194b8e3357364bd1a6ffb0ada159f5c484d2a3c14b6ef1689567bdf28e48c in 12145ms
2020-09-11T12:11:28.589Z [LockService] Acquiring lock for 0x9F263F85CB47B041291C506E17C976800c929b1C (TTL: 21000 ms)
2020-09-11T12:11:28.590Z [LockService] Acquired lock for 0x9F263F85CB47B041291C506E17C976800c929b1C (value 625a14f2cd55b52be10e0489d372cf73) after waiting 1 ms
2020-09-11T12:11:28.590Z [MessagingInterface] Responded to indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5.indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh.1337.lock.acquire.0x9F263F85CB47B041291C506E17C976800c929b1C in 3 ms
2020-09-11T12:11:29.164Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Response started
2020-09-11T12:11:29.222Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Validated proposal 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa in 58 ms
2020-09-11T12:11:29.237Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Asserted valid signature responder propose in 9 ms
2020-09-11T12:11:29.247Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Asserted valid initiator signature on conditional transaction in 9 ms
2020-09-11T12:11:29.250Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Signed initial state responder propose in 3 ms
2020-09-11T12:11:29.255Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Signed conditional tx commitment in 8 ms
2020-09-11T12:11:29.309Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Persisted app instance 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa in 16 ms
2020-09-11T12:11:29.310Z [CF-ProposeProtocol] [0x9F263F85CB47B041291C506E17C976800c929b1C] Response finished in 146 ms
2020-09-11T12:11:29.310Z [AppRegistryService] installOrReject for app 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa with params {"abiEncodings":{"stateEncoding":"tuple( tuple( address to, uint256 amount)[2] transfers, address multisigAddress, address assetId, uint256 startingTotalAmountWithdrawn, uint256 startingMultisigBalance)"},"appDefinition":"0x4aE34Dcb47a2134BCf6B139dDf2351458596B644","initialState":{"transfers":[{"amount":{"_hex":"0x00","_isBigNumber":true},"to":"0x7AdFEb6096544Fc3a5880A47F94877f2197C08A6"},{"amount":{"_hex":"0x00","_isBigNumber":true},"to":"0xE223A8135A27733Fed9e4812f443EC15ece31BA6"}],"multisigAddress":"0x9F263F85CB47B041291C506E17C976800c929b1C","assetId":"0x0000000000000000000000000000000000000000","startingTotalAmountWithdrawn":{"_hex":"0x015af1d78b58c40000","_isBigNumber":true},"startingMultisigBalance":{"_hex":"0xb1a2bc2ec50000","_isBigNumber":true}},"initiatorDeposit":{"_hex":"0x00","_isBigNumber":true},"initiatorDepositAssetId":"0x0000000000000000000000000000000000000000","multisigAddress":"0x9F263F85CB47B041291C506E17C976800c929b1C","outcomeType":"SINGLE_ASSET_TWO_PARTY_COIN_TRANSFER","responderIdentifier":"indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh","responderDeposit":{"_hex":"0x00","_isBigNumber":true},"responderDepositAssetId":"0x0000000000000000000000000000000000000000","defaultTimeout":{"_hex":"0x21c0","_isBigNumber":true},"stateTimeout":{"_hex":"0x21c0","_isBigNumber":true},"initiatorIdentifier":"indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5"} from indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5 started
2020-09-11T12:11:29.312Z [CF-RequestHandler] Event for propose protocol was processed in 164 ms
2020-09-11T12:11:29.335Z [CF-Install] Executing with params: {"appIdentityHash":"0x2c87..f5aa","multisigAddress":"0x9F26..9b1C"}
2020-09-11T12:11:29.336Z [LockService] Waiting on lock for 0x9F263F85CB47B041291C506E17C976800c929b1C (locked: 0x9F26..9b1C)
2020-09-11T12:11:29.384Z [LockService] Releasing lock for 0x9F263F85CB47B041291C506E17C976800c929b1C after 795 ms
2020-09-11T12:11:29.385Z [LockService] Done releasing lock for 0x9F263F85CB47B041291C506E17C976800c929b1C
2020-09-11T12:11:29.386Z [MessagingInterface] Responded to indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5.indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh.1337.lock.release.0x9F263F85CB47B041291C506E17C976800c929b1C in 2 ms
2020-09-11T12:11:29.386Z [LockService] Acquired lock for 0x9F263F85CB47B041291C506E17C976800c929b1C (value edbe2a8d07b241cee11cb79631a0b474) after waiting 49 ms
2020-09-11T12:11:29.387Z [CF-Install] Acquired locks 0x9F263F85CB47B041291C506E17C976800c929b1C in 52 ms
2020-09-11T12:11:29.389Z [CF-Install] Before execution complete in 2 ms
2020-09-11T12:11:29.390Z [CF-InstallProtocol] [0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa] Initiation started
2020-09-11T12:11:29.395Z [CF-InstallProtocol] [0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa] Validated app 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa in 5 ms
2020-09-11T12:11:29.520Z [CF-InstallProtocol] [0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa] Verified responder's sig on free balance update in 8 ms
2020-09-11T12:11:29.551Z [CF-InstallProtocol] [0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa] Initiation finished in 161 ms
2020-09-11T12:11:29.552Z [CF-Install] Executed method implementation in 162 ms
2020-09-11T12:11:29.552Z [LockService] Releasing lock for 0x9F263F85CB47B041291C506E17C976800c929b1C after 215 ms
2020-09-11T12:11:29.553Z [LockService] Done releasing lock for 0x9F263F85CB47B041291C506E17C976800c929b1C
2020-09-11T12:11:29.554Z [CF-RpcRouter] Processed chan_install method in 219 ms
2020-09-11T12:11:29.554Z [AppRegistryService] runPostInstallTasks for app name DepositApp 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa started
2020-09-11T12:11:29.555Z [AppRegistryService] runPostInstallTasks for app DepositApp 0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa completed
2020-09-11T12:15:50.361Z [TransferService] Start pruneExpiredApps for channel 0xd51713C7FeB775483542e5A8c178a9Cfb4BB06b1 on chainId 1337
2020-09-11T12:15:50.371Z [TransferService] Removing 0 expired apps on chainId 1337
2020-09-11T12:15:50.372Z [TransferService] Finish pruneExpiredApps for channel 0xd51713C7FeB775483542e5A8c178a9Cfb4BB06b1 on chainId 1337
2020-09-11T12:15:50.384Z [TransferService] Start pruneExpiredApps for channel 0xD441157D85c7F2cf68eA22670B83691Be020D4b9 on chainId 1337
2020-09-11T12:15:50.397Z [TransferService] Removing 0 expired apps on chainId 1337
2020-09-11T12:15:50.397Z [TransferService] Finish pruneExpiredApps for channel 0xD441157D85c7F2cf68eA22670B83691Be020D4b9 on chainId 1337
2020-09-11T12:15:50.409Z [TransferService] Start pruneExpiredApps for channel 0x8464f906925377b2cb7A9a112C48De1bEF09416d on chainId 1337
2020-09-11T12:15:50.416Z [TransferService] Removing 0 expired apps on chainId 1337
2020-09-11T12:15:50.417Z [TransferService] Finish pruneExpiredApps for channel 0x8464f906925377b2cb7A9a112C48De1bEF09416d on chainId 1337
2020-09-11T12:15:50.436Z [TransferService] Start pruneExpiredApps for channel 0x7C351a3CF3a1f55b86Fe00744f263665DE232377 on chainId 1337
2020-09-11T12:15:50.445Z [TransferService] Removing 5 expired apps on chainId 1337
2020-09-11T12:15:50.445Z [CF-Uninstall] Executing with params: {"appIdentityHash":"0x12f5..9649","multisigAddress":"0x7C35..2377"}
2020-09-11T12:15:50.446Z [LockService] Acquiring lock for 0x7C351a3CF3a1f55b86Fe00744f263665DE232377 (TTL: 21000 ms)
2020-09-11T12:15:50.447Z [LockService] Acquiring lock for 0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649 (TTL: 21000 ms)
2020-09-11T12:15:50.448Z [LockService] Acquired lock for 0x7C351a3CF3a1f55b86Fe00744f263665DE232377 (value df3428def26e4e672e3b0886ad37a346) after waiting 2 ms
2020-09-11T12:15:50.448Z [LockService] Acquired lock for 0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649 (value 119685b1b637b3b1521d0fb95e420cf6) after waiting 1 ms
2020-09-11T12:15:50.448Z [CF-Uninstall] Acquired locks 0x7C351a3CF3a1f55b86Fe00744f263665DE232377,0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649 in 3 ms
2020-09-11T12:15:50.459Z [CF-Uninstall] Before execution complete in 10 ms
2020-09-11T12:15:50.461Z [CF-UninstallProtocol] [0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649] Initiation started
2020-09-11T12:15:50.467Z [CF-Uninstall] Caught error while running protocol, syncing channels and retrying chan_uninstall with params {"appIdentityHash":"0x12f5..9649","multisigAddress":"0x7C35..2377"}. Error: App info does not exist for appDefinition 0xEbC87089c5283A94Da92E3021EDe4b429c02e996
    at CFCoreService.getAppInfoByAppDefinitionAddress (webpack:///./src/cfCore/cfCore.service.ts?:384:19)
    at AppRegistryService.eval (webpack:///./src/appRegistry/appRegistry.service.ts?:176:56)
    at Generator.next (<anonymous>)
    at eval (webpack:///./src/appRegistry/appRegistry.service.ts?:17:71)
    at new Promise (<anonymous>)
    at __awaiter (webpack:///./src/appRegistry/appRegistry.service.ts?:13:12)
    at AppRegistryService.uninstallMiddleware (webpack:///./src/appRegistry/appRegistry.service.ts?:173:45)
    at AppRegistryService.eval (webpack:///./src/appRegistry/appRegistry.service.ts?:68:37)
    at Generator.next (<anonymous>)
    at fulfilled (webpack:///./src/appRegistry/appRegistry.service.ts?:14:58)
    at runMicrotasks (<anonymous>)
    at processTicksAndRejections (internal/process/task_queues.js:93:5)
2020-09-11T12:15:50.484Z [CF-Uninstall] All locks acquired, syncing
2020-09-11T12:15:50.487Z [CF-SyncProtocol] [0x7C351a3CF3a1f55b86Fe00744f263665DE232377] Initiation started: {"multisigAddress":"0x7C351a3CF3a1f55b86Fe00744f263665DE232377","initiatorIdentifier":"indra6WRA6HQQTDQD1FC3KmdbpePijdcgLTqAdi2xy2Q2HqNeGn4cBh","responderIdentifier":"indra8gMKp7mJs2zRbYwxWeMwFCo9mC6gSww1AMUbnuNuKRqvbJAdgY","appIdentityHash":"0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649","chainId":1337}
2020-09-11T12:16:00.492Z [CF-Uninstall] Caught error in method controller while attempting retry + sync: Error: IO_SEND_AND_WAIT timed out after 10s waiting for counterparty reply in sync
    at eval (webpack:///./node_modules/@connext/cf-core/dist/cfCore.js?:129:23)
    at async ProtocolRunner.runProtocol (webpack:///./node_modules/@connext/cf-core/dist/machine/protocol-runner.js?:89:33)
    at async ProtocolRunner.initiateProtocol (webpack:///./node_modules/@connext/cf-core/dist/machine/protocol-runner.js?:44:33)
    at async UninstallController.executeMethod (webpack:///./node_modules/@connext/cf-core/dist/methods/controller.js?:80:37)
    at async RpcRouter.dispatch (webpack:///./node_modules/@connext/cf-core/dist/rpc-router.js?:20:25)
2020-09-11T12:16:00.493Z [CF-Uninstall] Acquired locks 0x7C351a3CF3a1f55b86Fe00744f263665DE232377,0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649 in 10033 ms
2020-09-11T12:16:00.493Z [TransferService] Failed to uninstall expired app 0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649: IO_SEND_AND_WAIT timed out after 10s waiting for counterparty reply in sync
2020-09-11T12:16:00.492Z [LockService] Releasing lock for 0x7C351a3CF3a1f55b86Fe00744f263665DE232377 after 10046 ms
2020-09-11T12:16:00.493Z [LockService] Releasing lock for 0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649 after 10046 ms
2020-09-11T12:16:00.493Z [LockService] Done releasing lock for 0x7C351a3CF3a1f55b86Fe00744f263665DE232377
2020-09-11T12:16:00.493Z [LockService] Done releasing lock for 0x12f505224a14d93f04188b475773b18da5d20b8994e447f01b817de9dc5d9649

1. also after several attempts i lost my malance -_-

cli output:

Balance:
┌──────────┬───────────────┬────────────────────────────┬───────────────────────────────┐
│ Currency │ Total Balance │ Channel Balance (Tradable) │ Wallet Balance (Not Tradable) │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ BTC      │ 3.49999987    │ 2.39999987 (1.1 inactive)  │ 0                             │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ ETH      │ 5.99876685    │ 0                          │ 5.99876685                    │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ USDT     │ 2000          │ 1000                       │ 1000                          │
└──────────┴───────────────┴────────────────────────────┴───────────────────────────────┘
simnet > openchannel eth 5.99876685
^Csimnet > getbalance

Balance:
┌──────────┬───────────────┬────────────────────────────┬───────────────────────────────┐
│ Currency │ Total Balance │ Channel Balance (Tradable) │ Wallet Balance (Not Tradable) │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ BTC      │ 3.49999987    │ 2.39999987 (1.1 inactive)  │ 0                             │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ ETH      │ 5.99876685    │ 0                          │ 5.99876685                    │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ USDT     │ 2000          │ 1000                       │ 1000                          │
└──────────┴───────────────┴────────────────────────────┴───────────────────────────────┘
simnet > openchannel eth 5.99876685
^Csimnet > openchannel eth 5.9987668
^Csimnet > getbalance

Balance:
┌──────────┬───────────────┬────────────────────────────┬───────────────────────────────┐
│ Currency │ Total Balance │ Channel Balance (Tradable) │ Wallet Balance (Not Tradable) │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ BTC      │ 3.49999987    │ 2.39999987 (1.1 inactive)  │ 0                             │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ ETH      │ 5.99876685    │ 0                          │ 5.99876685                    │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ USDT     │ 2000          │ 1000                       │ 1000                          │
└──────────┴───────────────┴────────────────────────────┴───────────────────────────────┘
simnet > openchannel eth 5.9987
Error: 2 UNKNOWN: failed to open ETH channel for 599870000: connext server error 500: Internal Server Error
simnet > getbalance

Balance:
┌──────────┬───────────────┬────────────────────────────┬───────────────────────────────┐
│ Currency │ Total Balance │ Channel Balance (Tradable) │ Wallet Balance (Not Tradable) │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ BTC      │ 3.49999987    │ 2.39999987 (1.1 inactive)  │ 0                             │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ ETH      │ 5.99876685    │ 0                          │ 5.99876685                    │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ USDT     │ 2000          │ 1000                       │ 1000                          │
└──────────┴───────────────┴────────────────────────────┴───────────────────────────────┘
simnet > openchannel eth 5.9987
^Csimnet > openchannel eth 5
^Csimnet > openchannel eth 1
Error: 2 UNKNOWN: failed to open ETH channel for 100000000: connext server error 500: Internal Server Error
simnet > getbalance

Balance:
┌──────────┬───────────────┬────────────────────────────┬───────────────────────────────┐
│ Currency │ Total Balance │ Channel Balance (Tradable) │ Wallet Balance (Not Tradable) │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ BTC      │ 3.49999987    │ 2.39999987 (1.1 inactive)  │ 0                             │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ ETH      │ 0.99854034    │ 0                          │ 0.99854034                    │
├──────────┼───────────────┼────────────────────────────┼───────────────────────────────┤
│ USDT     │ 2000          │ 1000                       │ 1000                          │
└──────────┴───────────────┴────────────────────────────┴───────────────────────────────┘

connext_client_output:

[1599827101147] INFO  (81 on connext): received request
    url: "/deposit"
    id: 17147
    reqId: 17147
[1599827101148] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:25:01.172Z [DepositController] Deposit started: {"amount":"5998700000000000000"}
2020-09-11T12:25:01.173Z [DepositController] Depositing 5998700000000000000 of 0x0000000000000000000000000000000000000000 into channel
2020-09-11T12:25:01.411Z [DepositController] requestDepositRights started: {"assetId":"0x0000000000000000000000000000000000000000"}
2020-09-11T12:25:01.413Z [CF-GetAppInstances] Executing with params: {"multisigAddress":"0x9F26..9b1C"}
2020-09-11T12:25:01.425Z [CF-GetAppInstances] Before execution complete in 12 ms
2020-09-11T12:25:01.435Z [CF-GetAppInstances] Executed method implementation in 8 ms
2020-09-11T12:25:01.437Z [CF-RpcRouter] Processed chan_getAppInstances method in 24 ms
2020-09-11T12:25:01.437Z [DepositController] requestDepositRights for assetId 0x0000000000000000000000000000000000000000 complete: {"appIdentityHash":"0x2c8792da1b13dd3e96d97bd67d6dbb840ebadacd26a2f75a9b8203aa45a0f5aa","multisigAddress":"0x9F263F85CB47B041291C506E17C976800c929b1C"}
2020-09-11T12:25:01.438Z [DepositController] Sending deposit transaction to chain
[1599827102188] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:25:02.190Z [CF-GetFreeBalanceState] Executing with params: {"multisigAddress":"0x9F26..9b1C","assetId":"0x0000..0000"}
[1599827102192] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5
2020-09-11T12:25:02.193Z [CF-GetFreeBalanceState] Executing with params: {"multisigAddress":"0x9F26..9b1C","assetId":"0x61F6..C94D"}
2020-09-11T12:25:02.197Z [CF-GetFreeBalanceState] Before execution complete in 7 ms
2020-09-11T12:25:02.199Z [CF-GetFreeBalanceState] Before execution complete in 6 ms
2020-09-11T12:25:02.210Z [CF-GetFreeBalanceState] Executed method implementation in 13 ms
2020-09-11T12:25:02.210Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 20 ms
2020-09-11T12:25:02.216Z [CF-GetFreeBalanceState] Executed method implementation in 17 ms
2020-09-11T12:25:02.217Z [CF-RpcRouter] Processed chan_getFreeBalanceState method in 24 ms
[1599827102410] ERROR (81 on connext): processing response error (body={"id":34721,"jsonrpc":"2.0","error":{"message":"the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5","code":-32000,"data":{"stack":"r: the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5\n    at i (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212813)\n    at /home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212944\n    at A.getQueuedNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:17:119640)\n    at S.createTransactionWithCorrectNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212624)\n    at S.processTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:209233)\n    at S.processNextAction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:206080)\n    at S._queueTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:205198)\n    at S.queueRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:203579)\n    at p.eth_sendRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:193695)\n    at p.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:190541)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at n.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:188823)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at f.s.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:169286)\n    at f.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:167096)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)","name":"r"}}}, error={"code":-32000,"data":{"stack":"r: the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5\n    at i (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212813)\n    at /home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212944\n    at A.getQueuedNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:17:119640)\n    at S.createTransactionWithCorrectNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212624)\n    at S.processTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:209233)\n    at S.processNextAction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:206080)\n    at S._queueTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:205198)\n    at S.queueRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:203579)\n    at p.eth_sendRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:193695)\n    at p.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:190541)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at n.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:188823)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at f.s.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:169286)\n    at f.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:167096)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)","name":"r"}}, requestBody="{\"method\":\"eth_sendRawTransaction\",\"params\":[\"0xf86e058502540be40082587b949f263f85cb47b041291c506e17c976800c929b1c88533fa9de1622c00080820a96a037341d7d7ca2baa42c5f83991574eb0fa9d75606f978dfccf88e9dc753ede9b4a00b58dc3040ce8114e3d295eec9921ab6136885a1210c0a66cd786d63b3acdc4f\"],\"id\":34721,\"jsonrpc\":\"2.0\"}", requestMethod="POST", url="http://connext.simnet.exchangeunion.com:8545", code=SERVER_ERROR, version=web/5.0.1)
    Error: processing response error (body={"id":34721,"jsonrpc":"2.0","error":{"message":"the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5","code":-32000,"data":{"stack":"r: the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5\n    at i (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212813)\n    at /home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212944\n    at A.getQueuedNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:17:119640)\n    at S.createTransactionWithCorrectNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212624)\n    at S.processTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:209233)\n    at S.processNextAction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:206080)\n    at S._queueTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:205198)\n    at S.queueRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:203579)\n    at p.eth_sendRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:193695)\n    at p.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:190541)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at n.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:188823)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at f.s.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:169286)\n    at f.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:167096)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)","name":"r"}}}, error={"code":-32000,"data":{"stack":"r: the tx doesn't have the correct nonce. account has nonce of: 6 tx has nonce of: 5\n    at i (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212813)\n    at /home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212944\n    at A.getQueuedNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:17:119640)\n    at S.createTransactionWithCorrectNonce (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:212624)\n    at S.processTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:209233)\n    at S.processNextAction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:206080)\n    at S._queueTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:205198)\n    at S.queueRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:203579)\n    at p.eth_sendRawTransaction (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:193695)\n    at p.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:190541)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at n.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:188823)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)\n    at f.s.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:169286)\n    at f.handleRequest (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:167096)\n    at t (/home/connext/ganache/node_modules/ganache-cli/build/ganache-core.node.cli.js:37:52700)","name":"r"}}, requestBody="{\"method\":\"eth_sendRawTransaction\",\"params\":[\"0xf86e058502540be40082587b949f263f85cb47b041291c506e17c976800c929b1c88533fa9de1622c00080820a96a037341d7d7ca2baa42c5f83991574eb0fa9d75606f978dfccf88e9dc753ede9b4a00b58dc3040ce8114e3d295eec9921ab6136885a1210c0a66cd786d63b3acdc4f\"],\"id\":34721,\"jsonrpc\":\"2.0\"}", requestMethod="POST", url="http://connext.simnet.exchangeunion.com:8545", code=SERVER_ERROR, version=web/5.0.1)
        at Logger.makeError (/app/node_modules/@ethersproject/logger/lib/index.js:179:21)
        at Logger.throwError (/app/node_modules/@ethersproject/logger/lib/index.js:188:20)
        at /app/node_modules/@ethersproject/web/lib/index.js:192:32
        at step (/app/node_modules/@ethersproject/web/lib/index.js:33:23)
        at Object.next (/app/node_modules/@ethersproject/web/lib/index.js:14:53)
        at fulfilled (/app/node_modules/@ethersproject/web/lib/index.js:5:58)
        at runMicrotasks (<anonymous>)
        at processTicksAndRejections (internal/process/task_queues.js:97:5)
[1599827102423] INFO  (81 on connext): request completed
    url: "/deposit"
    statusCode: 500
    reqId: 17147
[1599827105167] INFO  (81 on connext): Getting client for publicIdentifier: indra7GFej81aBFjQjEeStYCKbf8mqWD5N39k4Y8QSfwzh4zjcArhP5

[erkarl]

@jgarzik thanks for reporting this. Looks like there was a small precision loss when converting our internal units. I've added a temporary fix to this in https://github.com/ExchangeUnion/xud/pull/1893

Longer term solution is to move all internal amounts to use something like bignumber.js or bn.js. This is a refactoring that we've postponed for quite some time now since it hasn't really been an issue and it's most likely quite time consuming. Sorry for that.

CC @raladev

[jgarzik]

I guess there are two issues?

1. Precision in balances output leads user to use incorrect balance value in commands.
2. Using an invalid (too-large) balance gives a very confusing error message, versus a "X specified amount < Y available balance" message.

[erkarl]

I guess there are two issues?

Exactly. One of them we can fix from xud side. The other needs a proper status code from connext client in order to display the nicer error message to the end user.

1. Precision in balances output leads user to use incorrect balance value in commands.

https://github.com/ExchangeUnion/xud/pull/1893 as a quick fix + eventually move away from JavaScript number type. I'll start planning this refactoring as it's annoying to have these issues pop up.

2. Using an invalid (too-large) balance gives a very confusing error message, versus a "X specified amount < Y available balance" message.

Connext side: https://github.com/connext/rest-api-client/issues/23

Thanks again for bringing this issue up.

[kilrau]

I'll start planning this refactoring as it's annoying to have these issues pop up.

Here is the issue btw: https://github.com/ExchangeUnion/xud/issues/1797 and I just bumped the prio.