[bug]: `fundchannel` command hangs due to missing grouped-asset support #947

Liongrass · 2024-06-12T08:52:03Z

Background

I'm running litd in integrated mode, tapd is set to commit 76ec8ac232e1076ff2564928ec3700c72fafd267 on Bitcoin testnet3.

I have recently created a new grouped asset with the command:

tapcli --tlscertpath ~/.lit/tls.cert --rpcserver=localhost:8443 --network=testnet assets mint --type normal --name neo2oin --supply 100000 --meta_bytes 66616e746173746963206d6f6e6579 --new_grouped_asset

I then finalized the batch with:

tapcli --tlscertpath ~/.lit/tls.cert --rpcserver=localhost:8443 --network=testnet assets mint finalize

I then tried to open a channel to another node:

litcli --network=testnet --macaroonpath=~/.lnd/data/chain/bitcoin/testnet/admin.macaroon ln fundchannel --node_key 03e347d089c071c27680e26299223e80a740cf3e3fc4b4237fa219bb67121a670b --sat_per_vbyte 101 --asset_amount 1000 --asset_id 9ce3596b3c88cf41bff26e1931cbc85d17ee19484f5e3e34357c1951d6831814

The ln fundchannel command just hangs. I have attached logs and an LND profile below.

goprofile.txt
2024-06-12_open channel hangs.txt

The text was updated successfully, but these errors were encountered:

jharveyb · 2024-06-12T19:36:31Z

Looks like you hang waiting for funding ACK? It's the last log line from TCHN subsystem.

151:2024-06-12 06:54:01.313 [INF] TCHN: Waiting for funding ack...

Do you have logs from the other node as well?

HannahMR · 2024-06-13T18:05:14Z

Attached are the logs from my litd testnet node from a time period when Leo made an attempt to open a channel to me.

The logs are from 2024-06-13 15:51:31 UTC to 2024-06-13 15:55:58 UTC
Error logs.txt

GeorgeTsagk · 2024-06-17T18:58:27Z

Attached are the logs from my litd testnet node from a time period when Leo made an attempt to open a channel to me.

The logs are from 2024-06-13 15:51:31 UTC to 2024-06-13 15:55:58 UTC
Error logs.txt

weird, couldn't find any funding related logs in your logs, are you sure the snapshot window is right?

You should be seeing at least some TCHN sub-system logs, which is the channel funding logic in tapd

dstadulis · 2024-06-18T09:02:51Z

weird, couldn't find any funding related logs in your logs

Leo is the initiator (and would be performing funding) Hannah would be accepting the channel

HannahMR · 2024-06-18T18:18:47Z

Right, my logs are from when Leo was opening a channel to me.

I can attempt to open a channel to Leo and send those logs if that would be helpful.

dstadulis · 2024-06-18T19:08:33Z

Current theory is that the failure is due to the asset being a group key

Roasbeef · 2024-06-18T19:13:27Z

Main action item here: refactor the existing itest in tapd to use a grouped asset.

Liongrass · 2024-06-20T15:49:52Z

I'm on litd 980ee938aa1e7a45633216aff8775ca8d05c12aa now, using the 0-19-staging branch. I have modified go.mod to be on tapd v0.3.3-0.20240617174248-daf9676006b0.

I have a newly minted asset with group key 020d3ee08cadd6e34ab08f9b40d31ef05fc28b14e2bffd4810f35329317b4c9909 that I would like to use to open a channel. I execute litcli --network=testnet --macaroonpath=~/.lnd/data/chain/bitcoin/testnet/admin.macaroon ln fundchannel --node_key 03e347d089c071c27680e26299223e80a740cf3e3fc4b4237fa219bb67121a670b --sat_per_vbyte 101 --asset_amount 1000 --asset_id 9ce3596b3c88cf41bff26e1931cbc85d17ee19484f5e3e34357c1951d6831814

The command just hangs. I have attached my logs from the moment that I execute the litcli ln fundchannel command.
2024-06-20_open channel hangs.txt

HannahMR · 2024-06-20T15:52:57Z

I was the receiving node in Leo's attempt to open a channel with asset_id 9ce3596b3c88cf41bff26e1931cbc85d17ee19484f5e3e34357c1951d6831814. I am also running litd using the 0-19-staging branch.

Attached are the logs form the attempt.
lndsecondJune20.log

ffranr · 2024-06-24T12:04:17Z

I'm on litd 980ee938aa1e7a45633216aff8775ca8d05c12aa now, using the 0-19-staging branch. I have modified go.mod to be on tapd v0.3.3-0.20240617174248-daf9676006b0.

I have a newly minted asset with group key 020d3ee08cadd6e34ab08f9b40d31ef05fc28b14e2bffd4810f35329317b4c9909 that I would like to use to open a channel. I execute litcli --network=testnet --macaroonpath=~/.lnd/data/chain/bitcoin/testnet/admin.macaroon ln fundchannel --node_key 03e347d089c071c27680e26299223e80a740cf3e3fc4b4237fa219bb67121a670b --sat_per_vbyte 101 --asset_amount 1000 --asset_id 9ce3596b3c88cf41bff26e1931cbc85d17ee19484f5e3e34357c1951d6831814

The command just hangs. I have attached my logs from the moment that I execute the litcli ln fundchannel command. 2024-06-20_open channel hangs.txt

@Liongrass @HannahMR the litd 0-19-staging branch has now been updated to use the latest tapd and relevant lnd branch. A bunch of fixes are included. go.mod shouldn't require modification. If possible please re-run your test.

Liongrass · 2024-06-24T17:33:21Z

We both upgraded to the latest commit in the 0-19-staging branch (fa32097a4d0deee7e84872690194d18f108cf5a5) but still ran into the same issue. We used the same grouped asset. I have attached my logs below.

2024-06-24_open channel hangs.txt

We'll try again with a non-grouped asset!

HannahMR · 2024-06-24T17:42:24Z

My logs from the latest attempt
lndJune24Grouped.log

Liongrass · 2024-06-24T18:26:21Z

I minted a non-grouped asset with asset_id 50079900c674b425b40b10d142c86a3cb8e463411e8477998384995e7befe895, but I was unable to open a channel with it nonetheless.

In this case, both nodes were unable to sync to the universe with the command tapcli --tlscertpath ~/.lit/tls.cert --rpcserver=localhost:8443 --network=testnet universe sync --universe_host testnet.universe.lightning.finance:10029 --asset_id 50079900c674b425b40b10d142c86a3cb8e463411e8477998384995e7befe895 with the error 2024-06-24 18:07:20.623 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to fetch roots for universe sync: missing universe id

Logs:

2024-06-24 18:07:20.196 [INF] LITD: Handling gRPC request: /universerpc.Universe/SyncUniverse
2024-06-24 18:07:20.204 [DBG] RPCS: [/universerpc.Universe/SyncUniverse] requested
2024-06-24 18:07:20.206 [INF] UNIV: Attempting to sync universe: host=testnet.universe.lightning.finance:10029, sync_type=issuance, ids=([]universe.Identifier) (len=1 cap=1) {
 (universe.Identifier) issuance-50079900c674b425b40b10d142c86a3cb8e463411e8477998384995e7befe895
}

2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] Channel created
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] original dial target is: "52.88.202.111:10029"
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] dial target "52.88.202.111:10029" parse failed: parse "52.88.202.111:10029": first path segment in URL cannot contain colon
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] fallback to scheme "passthrough"
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/52.88.202.111:10029 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] Channel authority set to "52.88.202.111:10029"
2024-06-24 18:07:20.225 [DBG] GRPC: [core] [Channel #217] Resolver state updated: {
  "Addresses": [
    {
      "Addr": "52.88.202.111:10029",
      "ServerName": "",
      "Attributes": null,
      "BalancerAttributes": null,
      "Metadata": null
    }
  ],
  "Endpoints": [
    {
      "Addresses": [
        {
          "Addr": "52.88.202.111:10029",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Metadata": null
        }
      ],
      "Attributes": null
    }
  ],
  "ServiceConfig": null,
  "Attributes": null
} (resolver returned new addresses)
2024-06-24 18:07:20.226 [DBG] GRPC: [core] [Channel #217] Channel switches to new LB policy "pick_first"
2024-06-24 18:07:20.226 [DBG] GRPC: [core] [pick-first-lb 0xc002ab1260] Received new config {
  "shuffleAddressList": false
}, resolver state {
  "Addresses": [
    {
      "Addr": "52.88.202.111:10029",
      "ServerName": "",
      "Attributes": null,
      "BalancerAttributes": null,
      "Metadata": null
    }
  ],
  "Endpoints": [
    {
      "Addresses": [
        {
          "Addr": "52.88.202.111:10029",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Metadata": null
        }
      ],
      "Attributes": null
    }
  ],
  "ServiceConfig": null,
  "Attributes": null
}
2024-06-24 18:07:20.226 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel created
2024-06-24 18:07:20.226 [DBG] GRPC: [core] [Channel #217] Channel Connectivity change to CONNECTING
2024-06-24 18:07:20.226 [INF] UNIV: Fetching 1 roots
2024-06-24 18:07:20.227 [INF] WTCL: (legacy) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-06-24 18:07:20.227 [INF] WTCL: (anchor) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-06-24 18:07:20.226 [INF] WTCL: (taproot) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-06-24 18:07:20.227 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel Connectivity change to CONNECTING
2024-06-24 18:07:20.227 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel picks a new address "52.88.202.111:10029" to connect
2024-06-24 18:07:20.227 [DBG] GRPC: [core] [pick-first-lb 0xc002ab1260] Received SubConn state update: 0xc002ab1380, {ConnectivityState:CONNECTING ConnectionError:<nil>}
2024-06-24 18:07:20.533 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel Connectivity change to READY
2024-06-24 18:07:20.533 [DBG] GRPC: [core] [pick-first-lb 0xc002ab1260] Received SubConn state update: 0xc002ab1380, {ConnectivityState:READY ConnectionError:<nil>}
2024-06-24 18:07:20.533 [DBG] GRPC: [core] [Channel #217] Channel Connectivity change to READY
2024-06-24 18:07:20.622 [DBG] GRPC: [core] [Channel #217] Channel Connectivity change to SHUTDOWN
2024-06-24 18:07:20.622 [DBG] GRPC: [core] [Channel #217] ccBalancerWrapper: closing
2024-06-24 18:07:20.622 [DBG] GRPC: [core] [Channel #217] Closing the name resolver
2024-06-24 18:07:20.623 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel Connectivity change to SHUTDOWN
2024-06-24 18:07:20.623 [DBG] GRPC: [core] [Channel #217 SubChannel #218] Subchannel deleted
2024-06-24 18:07:20.623 [DBG] GRPC: [transport] [client-transport 0xc000903688] Closing: rpc error: code = Canceled desc = grpc: the client connection is closing
2024-06-24 18:07:20.623 [DBG] GRPC: [core] [Channel #217] Channel deleted
2024-06-24 18:07:20.623 [DBG] GRPC: [transport] [client-transport 0xc000903688] loopyWriter exiting with error: connection error: desc = "transport is closing"
2024-06-24 18:07:20.623 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to fetch roots for universe sync: missing universe id
2024-06-24 18:07:20.624 [DBG] GRPC: [transport] [server-handler-transport 0xc003d4ab40] Closing: finished writing status

dstadulis · 2024-06-25T10:30:49Z

I minted a non-grouped asset with asset_id 50079900c674b425b40b10d142c86a3cb8e463411e8477998384995e7befe895, but I was unable to open a channel with it nonetheless [...]

@GeorgeTsagk ran local tests:

Changing the asset mint to be a NewGroupedAsset seems to be passing the channel funding phase (RPCs return no error, asserts are happy)
It does crash later on though, when asserting that proofs have been uploaded to the universe
^ for this I'm not sure if I should be using some other key for the proof or smth
But def doesn't look like a core issue with the channel funding flow

Current Action

Add a grouped asset itest -- requiring debugging the universe related dysfunction [bug] Refactor existing itest in tapd to cover a grouped asset #957

dstadulis · 2024-06-27T02:09:12Z

fundchannel should no longer indefinitely hang as a 30 second timeout has been added with #971

Will monitor these user flow to ensure functionality

jharveyb · 2024-07-01T16:17:23Z

May have been related to a universe version mismatch as well.

Roasbeef · 2024-07-02T23:06:59Z

This appears to be the true culprit: #990

Liongrass · 2024-07-03T22:46:25Z

We did try again, both connected to the staging testnet universe, but the command still hangs. I did mint a new asset for this test with tapcli --tlscertpath ~/.lit/tls.cert --rpcserver=localhost:8443 --network=testnet assets mint --type normal --name lollars --supply 1000000 --decimal_display 3 --meta_bytes '{"hello":true}' --meta_type json --new_grouped_asset

We were able to successfully sync this asset from the universe with tapcli --tlscertpath ~/.lit/tls.cert --rpcserver=localhost:8443 --network=testnet universe sync --universe_host universe.staging.lightningcluster.com:10029 --asset_id a8433224c518b7e148073575ef4b6965af78996c87852c7c22992cff3db3b235

I then tried to open a channel with:

litcli --network=testnet --macaroonpath=~/.lnd/data/chain/bitcoin/testnet/admin.macaroon ln fundchannel --node_key 03e347d089c071c27680e26299223e80a740cf3e3fc4b4237fa219bb67121a670b --sat_per_vbyte 16 --asset_amount 1000 --asset_id a8433224c518b7e148073575ef4b6965af78996c87852c7c22992cff3db3b235

I have attached the logs between initiating the channel and the command timing out after 30s.
2024-07-03_open channel hangs.txt

HannahMR · 2024-07-03T22:48:37Z

We are both running v0.13.2-alpha.rc2. Below are my logs from the attempt.
lndJul3.log

Roasbeef · 2024-07-08T18:04:34Z

Closing this, updated the core issue to be tracked in these two issues:

[feature]/universe+rpc: add new command to push up proofs to universes #989
[bug] - universe: QueryAssetRoots returns an empty error when no asset root can be found #990

HannahMR · 2024-07-09T00:57:48Z

When testing with the Megalithic node we hit the same channel open issue, although now we are receiving the timeout error.

Both of our nodes are running on testnet3, using the v0.13.2-alpha.rc2 litd release, and connecting to the testnet.universe.lightning.finance universe.

First I attempted to open a channel to Megalithic using as asset minted a few weeks ago. The logs from that attempt are in the lndJul8.log file.
lndJul8.log

Later Megalithic attempted to open an asset channel to my node using a newly minted asset. Their logs from that attempt are in the lndlogs-after-trying-to-fund-channel.txt file. And my logs from that attempt are in the lndJul8Second.log file.
lndJul8Second.log
lndlogs-after-trying-to-fund-channel.txt

Liongrass added bug Something isn't working needs triage labels Jun 12, 2024

dstadulis changed the title ~~[bug]: funchannel command hangs~~ [bug]: fundchannel command hangs Jun 14, 2024

dstadulis added this to Taproot-Assets Project Board Jun 18, 2024

github-project-automation bot moved this to 🆕 New in Taproot-Assets Project Board Jun 18, 2024

dstadulis assigned GeorgeTsagk Jun 18, 2024

dstadulis moved this from 🆕 New to 🏗 In progress in Taproot-Assets Project Board Jun 18, 2024

dstadulis removed the status in Taproot-Assets Project Board Jun 18, 2024

dstadulis added this to the v0.4 milestone Jun 18, 2024

dstadulis moved this to 🔖 Ready in Taproot-Assets Project Board Jun 18, 2024

dstadulis moved this from 🔖 Ready to 🏗 In progress in Taproot-Assets Project Board Jun 18, 2024

dstadulis mentioned this issue Jun 19, 2024

[bug] Refactor existing itest in tapd to cover a grouped asset #957

Closed

guggero mentioned this issue Jun 24, 2024

Polar Test Flows Working/Not Working #942

Closed

21 tasks

dstadulis changed the title ~~[bug]: fundchannel command hangs~~ [bug]: fundchannel command hangs due to missing grouped-asset support Jun 24, 2024

This was referenced Jun 25, 2024

itest: Custom channels grouped asset lightninglabs/lightning-terminal#780

Closed

itest: Add custom channels with grouped asset test lightninglabs/lightning-terminal#781

Merged

dstadulis closed this as completed Jun 27, 2024

github-project-automation bot moved this from 🏗 In progress to ✅ Done in Taproot-Assets Project Board Jun 27, 2024

jharveyb reopened this Jul 1, 2024

dstadulis moved this from ✅ Done to 🏗 In progress in Taproot-Assets Project Board Jul 8, 2024

Roasbeef closed this as completed Jul 8, 2024

github-project-automation bot moved this from 🏗 In progress to ✅ Done in Taproot-Assets Project Board Jul 8, 2024

[bug]: fundchannel command hangs due to missing grouped-asset support #947

[bug]: fundchannel command hangs due to missing grouped-asset support #947

Comments

Liongrass commented Jun 12, 2024

Background

jharveyb commented Jun 12, 2024

Uh oh!

HannahMR commented Jun 13, 2024

Uh oh!

GeorgeTsagk commented Jun 17, 2024

Uh oh!

dstadulis commented Jun 18, 2024

Uh oh!

HannahMR commented Jun 18, 2024

Uh oh!

dstadulis commented Jun 18, 2024

Uh oh!

Roasbeef commented Jun 18, 2024

Uh oh!

Liongrass commented Jun 20, 2024

Uh oh!

HannahMR commented Jun 20, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

ffranr commented Jun 24, 2024 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Liongrass commented Jun 24, 2024

Uh oh!

HannahMR commented Jun 24, 2024

Uh oh!

Liongrass commented Jun 24, 2024

Uh oh!

dstadulis commented Jun 25, 2024 • edited by GeorgeTsagk Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Current Action

Uh oh!

dstadulis commented Jun 27, 2024

Uh oh!

jharveyb commented Jul 1, 2024

Uh oh!

Roasbeef commented Jul 2, 2024

Uh oh!

Liongrass commented Jul 3, 2024

Uh oh!

HannahMR commented Jul 3, 2024

Uh oh!

Roasbeef commented Jul 8, 2024

Uh oh!

HannahMR commented Jul 9, 2024

Uh oh!

[bug]: `fundchannel` command hangs due to missing grouped-asset support #947

[bug]: `fundchannel` command hangs due to missing grouped-asset support #947

HannahMR commented Jun 20, 2024 •

edited

Loading

ffranr commented Jun 24, 2024 •

edited

Loading

dstadulis commented Jun 25, 2024 •

edited by GeorgeTsagk

Loading