[FragmenterSplitFunds] Claiming process should poll to wait for mempool transaction propagation

[Janaka-Steph]

Working on Tdex Dashboard Testnet support.

I run the daemon with this command:

docker run -it -d --name tdexd \
-p 9945:9945 -p 9000:9000 \
-v `pwd`/tdexd:/home/user/.tdex-daemon \
-e TDEX_NO_MACAROONS=false \
-e TDEX_NETWORK="testnet" \
-e TDEX_BASE_ASSET="144c654344aa716d6f3abcc1ca90e5641e4e2a7f633bc09fe3baf64585819a49" \
-e TDEX_LOG_LEVEL=5 \
-e TDEX_FEE_ACCOUNT_BALANCE_THRESHOLD=1000 \
-e TDEX_EXPLORER_ENDPOINT="https://blockstream.info/liquidtestnet/api" \
ghcr.io/tdex-network/tdexd:v0.8.0-rc.1

I attempt to send some Testnet funds to the Fee account.

Sending 0.001 tL-BTC from my Green wallet to fee deposit address: https://blockstream.info/liquidtestnet/tx/bc86c3ade6e7d041ae44d4467bc924f4717ee65ae22c58c199be9e835eeab4b8#blinded=1000000,144c654344aa716d6f3abcc1ca90e5641e4e2a7f633bc09fe3baf64585819a49,5e282fa594ece024012c5c59c254953ebad8d4b351362aade259e555b68da83c,45e22c2a14875cf5f5f6b887de03bcfec2baf024c16083dc11243e0801b21000,899743,144c654344aa716d6f3abcc1ca90e5641e4e2a7f633bc09fe3baf64585819a49,c34ffe4307bf327b0b39b5f2971940c4659193ef36e7d3f294eefd31befacc17,49e835336fbb6107955b9815337a5f9fb159105d6aacc00ceff7b4bec3203f98

Fragmentation Tx: https://blockstream.info/liquidtestnet/tx/bd1b708695b8966083d18706b9ed92e88f39fa34441ead7efeff7000b6803c46

Even though it has been mined, Tdex daemon returned an error failed to broadcast transaction: sendrawtransaction RPC error: {\"code\":-25,\"message\":\"bad-txns-inputs-missingorspent\"}.

On second fragmentation try I got no funds detected for fee fragmenter.

$ tdex feefragmenter balance
{
        "balance": {
        }
}

Funds are in the limbos.

[Janaka-Steph]

Other try from CLI. Send 0.0001 tL-BTC, wait 1 confirmation.

// First split
$ tdex feefragmenter split    

fetching fee fragmenter funds
calculating fragments for LBTC funds
detected 1 fund(s) of total amount 10000 that will be split into 2 fragments
crafting fee deposit transaction
broadcasting transaction
fee account funding transaction: 8e2c4227117c2884d28966f299d7c1a669951465336baa7426c8b70490c166a3
claiming deposits for fee account
[tdex] rpc error: code = Unknown desc = failed to claim deposits: Transaction not found

$ tdex feefragmenter balance  
{
        "balance": {
                "144c654344aa716d6f3abcc1ca90e5641e4e2a7f633bc09fe3baf64585819a49": {
                        "total_balance": "10000",
                        "confirmed_balance": "10000",
                        "unconfirmed_balance": "0"
                }
        }
}

// Second Split
$ tdex feefragmenter split    

fetching fee fragmenter funds
calculating fragments for LBTC funds
detected 1 fund(s) of total amount 10000 that will be split into 2 fragments
crafting fee deposit transaction
broadcasting transaction
[tdex] rpc error: code = Unknown desc = failed to broadcast transaction: sendrawtransaction RPC error: {"code":-25,"message":"bad-txns-inputs-missingorspent"}

$ tdex feefragmenter balance
{
        "balance": {
        }
}

[tiero]

crafting fee deposit transaction broadcasting transaction fee account funding transaction: 8e2c4227117c2884d28966f299d7c1a669951465336baa7426c8b70490c166a3

Mmm transactions exists 🤔

https://blockstream.info/liquidtestnet/tx/8e2c4227117c2884d28966f299d7c1a669951465336baa7426c8b70490c166a3

What to do in theses cases @altafan

[tiero]

I think the claim process must account for this and allow to "retry" a process. There can be many problems, ie. explorer down, not looking for txid etc.. @altafan

[altafan]

this is really weird because the transaction seems to be both rejected and included in mempool at the same time by the elements node.

Ideally, if the broadcast fails, the funds should still be owned by the fragmenter and the user could retry to run the split command. This situation is really awkward though.

[tiero]

Funds are currently in a limbo, ie. not clear where they are.

@Janaka-Steph can you try mount the daemon in a new data directory (ie. -v pwd/tdexd2:/home/user/.tdex-daemon) to start clean and then tdex init --restore to see if we can restore funds?

[altafan]

@Janaka-Steph can you try mount the daemon in a new data directory (ie. -v pwd/tdexd2:/home/user/.tdex-daemon) to start clean and then tdex init --restore to see if we can restore funds?

This is equivalent to claiming the funds manually. The restore process does that for you.

[tiero]

ATM, it seems more a bug of the elements node: If a transaction is rejected because it breaks the protocol rules, no way it should be included in mempool and in blockchain eventually.

No, the second error is correct (ie. bad-txns-inputs-missingorspent), because the problem was in the first split attempt which has been complete succesfully where we got [tdex] rpc error: code = Unknown desc = failed to claim deposits: Transaction not found

The states are not in sync with the chain basically

[altafan]

ok, maybe the daemon runs to fast here: after broadcasting the tx it immediately try to claim the funds pretending the tx has been included at least in mempool. Would be better to "wait" (ie poll the explorer) until it appears in mempool before proceeding with the claiming.

[Janaka-Steph]

After rm tdexd and restoring I can see my fee balance with tdex fee balance. However feefragmenter account has not been restored.

$ tdex feefragmenter balance
[tdex] rpc error: code = Unknown desc = account not found

[tiero]

ok, maybe the daemon runs to fast here: after broadcasting the tx it immediately try to claim the funds pretending the tx has been included at least in mempool. Would be better to "wait" (ie poll the explorer) until it appears in mempool before proceeding with the claiming.

Yes, real world scenario we should have a bit of waiting and/or polling mechanics with sensible timeout until we reach 1 confirmation onchain for the first split

[altafan]

Yes, real world scenario we should have a bit of waiting and/or polling mechanics with sensible timeout until we reach 1 confirmation onchain for the first split

It's enough for the tx to be included in mempool actually. The daemon will start watching those outpoits to mark them as confirmed after the claim in case they are still uconfirmed.

[altafan]

After rm tdexd and restoring I can see my fee balance with tdex fee balance. However feefragmenter account has not been restored.

The restore does not involve the fragmenters accounts because their utxos are fetched directly from the explorer, without storing them. Try to generate 10 addresses with tdex feefragmenter deposit --num_of_addresses 10. The balance should be "restored" with this trick.

[tiero]

Changed the title, to be more meaningful whats the problem is.

Let's include in the next rc.2 @altafan

[tiero]

For some reaons, initializing a testnet daemon myself, it happened again to me

1) Deposit of fragmenter address some LBTC 2) Wait for 1 minute confirmation 3) Click on Confirm Deposit 4) after a while I get random "Error 400 or 500..."

The funds have been slitted succesfully, but fee balance account is 0

Here the stacktrace and the calls to show the status of funds

time="2021-12-08T16:30:22Z" level=debug msg=/Operator/GetFeeFragmenterAddress
time="2021-12-08T16:32:18Z" level=debug msg="Total allocated: 2.336GB, Heap allocated: 0.247GB, Allocated objects count: 314174, Freed objects count: 299476"
time="2021-12-08T16:32:18Z" level=debug msg="Num of go routines: 52\n"
time="2021-12-08T16:33:22Z" level=debug msg=/Operator/FeeFragmenterSplitFunds
time="2021-12-08T16:34:36Z" level=debug msg=/Operator/FeeFragmenterSplitFunds
time="2021-12-08T16:35:22Z" level=debug msg=/Operator/ListDeposits
time="2021-12-08T16:35:25Z" level=debug msg=/Operator/ListDeposits
time="2021-12-08T16:35:28Z" level=debug msg=/Operator/ListDeposits
time="2021-12-08T16:35:34Z" level=debug msg="added 50 unspents"
time="2021-12-08T16:35:34Z" level=debug msg="added 50 deposits for account 0"
time="2021-12-08T16:35:34Z" level=info msg="fee account funded. Trades can be served"

ubuntu@ip-172-31-37-72:~/tdex-box-testnet$ docker exec tdexd-testnet tdex feefragmenter balance
{
    "balance": {
    }
}
ubuntu@ip-172-31-37-72:~/tdex-box-testnet$ docker exec tdexd-testnet tdex listdeposits --account_index 0
{
    "account_index": "0",
    "deposits": [
        {
            "utxo": {
                "outpoint": {
                    "hash": "d127b8613be7328b84a806decb40df7db43bd096e155a18bb31f7e20fec6692f",
                    "index": 49
                },
                "value": "9748992",
                "asset": "144c654344aa716d6f3abcc1ca90e5641e4e2a7f633bc09fe3baf64585819a49"
            },
            "timestamp_unix": "1638981334",
            "timestamp_utc": "2021-12-08 16:35:34 +0000 UTC"
        },
        {... many other 50 outpoints}
    ]
}
ubuntu@ip-172-31-37-72:~/tdex-box-testnet$ docker exec tdexd-testnet tdex fee balance
{
    "available_balance": "0",
    "total_balance": "0"
}

[tiero]

Note: It seems that the call returns that error before FeeFragmenterSplitFunds actually finished: I think either the proxy or grpcweb client in the dashboard which is "closing" unexpectly, becuase after the error the daemon "keeps" working and the logs about fund added to fee account come some time later

time="2021-12-08T16:51:29Z" level=debug msg=/Operator/FeeFragmenterSplitFunds

The Dashaboard gets an error here ie. timeout

wait aorund 30 seconds, in the daemon logs:

time="2021-12-08T16:53:42Z" level=debug msg="added 50 unspents"
time="2021-12-08T16:53:42Z" level=debug msg="added 50 deposits for account 0"
time="2021-12-08T16:53:42Z" level=info msg="fee account funded. Trades can be served"
time="2021-12-08T16:54:20Z" level=debug msg=/Operator/GetFeeFragmenterBalance

[altafan]

By default, the explorer used by the daemon is configured with a request timeout of 15 seconds. This might be the cause of the issue.

You should try exporting the env var TDEX_EXPLORER_REQUEST_TIMEOUT=40000 to increase it like for example to 40 seconds.

[tiero]

🤔 not sure is problem of the exploer: the deposits are credited/added AFTER the request returns error 500

I would try to use Bloom instead of dashboard to see if it happens the same, cc/ @Janaka-Steph

[altafan]

https://github.com/tdex-network/tdex-daemon/blob/master/internal/core/application/operator_service.go#L1997-L2017

The problem is that the reply Fragmentation succeeded is written to the channel BEFORE spawning the goroutine to update the vault domain with the newly derived addresses for the fee account.

Because the channel is closed client side due to some timeout problem, the goroutine is not spawned at all. So, the unspent are written, but not the addresses in the vault domain. Every subsequent fragmentation will reuse those addresses.

This is extremely evident for the very first fragmentation: after getting the error, if you try to list all addresses for the fee account with the cli tdex fee addresses you will get an error acccount not found because the internal vault hasn't been updated.