Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Error Adding Local Alias : SCID not found #1016

Closed
vanditshah99 opened this issue Jul 12, 2024 · 15 comments
Closed

Error Adding Local Alias : SCID not found #1016

vanditshah99 opened this issue Jul 12, 2024 · 15 comments
Labels
bug Something isn't working

Comments

@vanditshah99
Copy link

Hi Team, We have recently tested Single Hop and Multi-Hop Payment Transfers via a Mock RFQ middleware in between.

So, the case was RFQ middleware node generated an invoice via this command

user@aw60:/src$ ./litcli-assetfunctions-testnet.sh ln addinvoice --asset_id d421c41e5cccc7a46853a67a77f9bfbff0e46b636be45080b70d6228430c2675 --asset_amount  10
Asking peer 0310fc0c9bec84463bfc7fc2c9c8de4ebb1a0417e89c4aaeb0be14ea80390959b3 for quote to buy assets to receive for invoice over 10 units; waiting up to 60s

Our Node used the conventional way via paying using GRPC of LND ( lncli payinvoice).
The taproot-Asset daemon of our node went down and the error noted in the console was

received a critical error from sub-server (taproot-assets), shutting down: failed to handle outgoing message: error adding local alias: base SCID not found for an asset: d421c41e5cccc7a46853a67a77f9bfbff0e46b636be45080b70d6228430c2675"

We restarted LITD and have been good to go since then, But I think the issue struck when trying to populate alias SCID for the first time.

The team is trying to catch up to the logs of the node, might update in the comment if we retrieve one, as it's been quite a few hours since we noticed the issue.

LITD version used

578f65f301b8:/# litcli -n testnet getinfo
{
    "version":  "0.13.99-alpharc3 commit=v0.13.99-alpha.rc3"
}
@vanditshah99 vanditshah99 added the bug Something isn't working label Jul 12, 2024
@GeorgeTsagk
Copy link
Member

GeorgeTsagk commented Jul 12, 2024

Hey @vanditshah99

Thank you for the early testing, and for opening this issue

Looks like this was expected behavior according to our codebase, as we would not be able to match a real channel with an empty asset id.

This was recently changed in #1011 and will no longer cause the daemon to terminate.

We restarted LITD and have been good to go since then, But I think the issue struck when trying to populate alias SCID for the first time.

After the restart, did you try to pay with the same command? (i.e lncli payinvoice)

@guggero
Copy link
Member

guggero commented Jul 12, 2024

Thanks for the report. This is the correct repository for litd issues. But since this mainly concerns the Taproot Asset channel functionality, I'm going to transfer the issue to the Taproot Asset repository, so we can track all the bugs in a single place.

@guggero guggero transferred this issue from lightninglabs/lightning-terminal Jul 12, 2024
@vanditshah99
Copy link
Author

Hey @vanditshah99

Thank you for the early testing, and for opening this issue

Looks like this was expected behavior according to our codebase, as we would not be able to match a real channel with an empty asset id.

This was recently changed in #1011 and will no longer cause the daemon to terminate.

We restarted LITD and have been good to go since then, But I think the issue struck when trying to populate alias SCID for the first time.

After the restart, did you try to pay with the same command? (i.e lncli payinvoice)

Oh yes, we did. we checked the scenario, where in a taproot asset ln invoice is paid by lncli payinvoice, worked well 👍

@guggero
Copy link
Member

guggero commented Jul 12, 2024

The scenario that failed, was that a multi-hop or single-hop (direct channel) payment?

@vanditshah99
Copy link
Author

It was a single hop payment.

@guggero
Copy link
Member

guggero commented Jul 15, 2024

And did you have other channels (non-asset channels) on either of the sender/receiver node?

@vanditshah99
Copy link
Author

Yes, The receiver had a lightning channel with another node as well

@guggero
Copy link
Member

guggero commented Jul 15, 2024

Okay, thanks. I'll try to reproduce this and let you know if I have more questions.

@guggero
Copy link
Member

guggero commented Jul 15, 2024

Hmm, I'm having trouble reproducing this... Do you still have the logs from when it happened (please always attach logs if possible)?
If no logs are available anymore, can you please try to reproduce with the latest RC4?

@vanditshah99
Copy link
Author

vanditshah99 commented Jul 15, 2024

We were actively testing it with two other peer nodes, so until we completed testing and gathered info about the bugs, we found that server didn't persist the logs, let us try with latest rc4, and see if we can reproduce it. Thanks

@vanditshah99
Copy link
Author

@guggero we accidentally came across this issue again, what we did

  1. Node 1 minted assets
  2. Node 2 synced the universe
  3. Node 1 connects to node 2 as peers

Now we directly try AddAssetBuyOrder

{
    "min_asset_amount":10,
    "timeout_seconds":15,
    "peer_pub_key":"A1a0YjGCFe2iTH1enk7eUXpyfJiZrGrL8nOjlqQhGjeS"
}

Node 2 which is the peer node logs are as follows

2024-07-31 06:11:17.659 [DBG] RFQS: Order handler is registering an asset sale policy given a buy accept message: BuyAccept(peer=0310fc0c9bec84463bfc7fc2c9c8de4ebb1a0417e89c4aaeb0be14ea80390959b3, id=d78f50f99909e66b9f7a8bb5256cd08e97669e2b83a507e23e5db68424382ee0, ask_price=158, expiry=1722409877, scid=4493948681845223136)
2024-07-31 06:11:17.659 [DBG] RPCS: [/lnrpc.Lightning/ListChannels] requested
2024-07-31 06:11:17.660 [DBG] RPCS: [listchannels] fetched 0 channels from DB
2024-07-31 06:11:17.660 [TRC] TSVR: InlineParseCustomData called with *lnrpc.ListChannelsResponse
2024-07-31 06:11:17.660 [ERR] RFQS: Error in RFQ manager: failed to handle outgoing message: error adding local alias: add alias: base SCID not found for asset: f8ffc554dad8a3780c408297a70b70af1c8d96cae3c167ff55cbd6308edb2a08
2024-07-31 06:11:19.209 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.3.82:37943: EOF
2024-07-31 06:11:19.501 [TRC] TCHN: Request to handle: *lnwire.GossipTimestampRange
2024-07-31 06:11:19.501 [TRC] TCHN: Request to handle: 265
2024-07-31 06:11:19.501 [DBG] TCHN: Failed to handle: *lnwire.GossipTimestampRange
2024-07-31 06:11:19.501 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:19.501 [DBG] CHDB: ChanUpdatesInHorizon hit percentage: NaN (0/0)
2024-07-31 06:11:19.501 [INF] DISC: GossipSyncer(0310fc0c9bec84463bfc7fc2c9c8de4ebb1a0417e89c4aaeb0be14ea80390959b3): applying new update horizon: start=2042-07-14 01:04:00 +0000 UTC, end=2042-07-14 01:04:00 +0000 UTC, backlog_size=0
2024-07-31 06:11:19.559 [DBG] HLCK: invoking success callback
2024-07-31 06:11:19.581 [DBG] SRVR: Sending 0 messages to peer 02e76d0188c85c4bc13939533f6c4f5f21768d3e0a86fc32552a37969be0c6abe0
2024-07-31 06:11:19.582 [DBG] SRVR: Sending 0 messages to peer 02db3ba0d5b512f58ee0833b40ea62c62e78c1d997457cc03caeb17d06ec12ab69
2024-07-31 06:11:19.582 [DBG] SRVR: Sending 0 messages to peer 031ba13b2a008cd5ed17bfc8df660210aa37fbac6ce5951fa1e01cdbc74059d92e
2024-07-31 06:11:19.582 [DBG] SRVR: Sending 0 messages to peer 0310fc0c9bec84463bfc7fc2c9c8de4ebb1a0417e89c4aaeb0be14ea80390959b3

Node 1 Logs which requests AddAssetBuyOrder

2024-07-31 06:11:00.359 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:00.359 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Received NodeAnnouncement(node=03423cb1bd00c92af9cf91ed64a454cc97362038d549e1297028cf83fd3ea1b6d5, update_time=2024-07-31 06:10:07 +0000 UTC) from 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:00.359 [DBG] TCHN: Failed to handle: *lnwire.NodeAnnouncement
2024-07-31 06:11:00.359 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:00.359 [DBG] DISC: Processing ChannelUpdate: peer=032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576, short_chan_id=2615181809600299008,
2024-07-31 06:11:00.359 [DBG] DISC: Processing NodeAnnouncement: peer=032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576, timestamp=2024-07-31 06:10:07 +0000 UTC, node=03423cb1bd00c92af9cf91ed64a454cc97362038d549e1297028cf83fd3ea1b6d5
2024-07-31 06:11:00.359 [DBG] DISC: Validating ChannelUpdate: channel=2615181809600299008, from node=02c6bb69fd7615c70ee271ed64d12a9f233da8836ac79b0a21a43d0149a246c0a7, has edge=true
2024-07-31 06:11:00.359 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Received NodeAnnouncement(node=02be8f360e57600486b93dd33ea0872a4e14a259924ba4084f27d693a77d151158, update_time=2024-07-31 06:09:22 +0000 UTC) from 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:00.359 [DBG] TCHN: Failed to handle: *lnwire.NodeAnnouncement
2024-07-31 06:11:00.359 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:00.360 [DBG] DISC: Processing NodeAnnouncement: peer=032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576, timestamp=2024-07-31 06:09:22 +0000 UTC, node=02be8f360e57600486b93dd33ea0872a4e14a259924ba4084f27d693a77d151158
2024-07-31 06:11:00.360 [DBG] CRTR: Received ChannelEdgePolicy for channel 2615181809600299008
2024-07-31 06:11:00.359 [DBG] CRTR: Checking stale node 303334323363623162643030633932616639636639316564363461343534636339373336323033386435343965313239373032386366383366643365613162366435 got Ignoring outdated announcement for 03423cb1bd00c92af9cf91ed64a454cc97362038d549e1297028cf83fd3ea1b6d5
2024-07-31 06:11:00.360 [DBG] DISC: Skipped processing stale node: 03423cb1bd00c92af9cf91ed64a454cc97362038d549e1297028cf83fd3ea1b6d5
2024-07-31 06:11:00.867 [DBG] DISC: Processed NodeAnnouncement: peer=032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576, timestamp=2024-07-31 06:09:22 +0000 UTC, node=02be8f360e57600486b93dd33ea0872a4e14a259924ba4084f27d693a77d151158
2024-07-31 06:11:00.873 [DBG] DISC: Processed ChannelUpdate: peer=032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576, short_chan_id=2615181809600299008, timestamp=2024-07-31 06:09:54 +0000 UTC
2024-07-31 06:11:07.419 [DBG] PEER: Peer(02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7@52.226.214.80:9735
2024-07-31 06:11:07.419 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:07.419 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:07.419 [DBG] PEER: Peer(02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7): Sending Pong(len(pong_bytes)=16) to 02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7@52.226.214.80:9735
2024-07-31 06:11:07.428 [DBG] PEER: Peer(02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7@52.226.214.80:9735
2024-07-31 06:11:07.431 [DBG] PEER: Peer(02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7): Received Pong(len(pong_bytes)=3173) from 02eb311fca318454d00ed19fee12b5fe3bb6058034a1cb0f1e094d2c075ff93ee7@52.226.214.80:9735
2024-07-31 06:11:07.431 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:07.431 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:07.616 [DBG] PEER: Peer(0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2@54.245.111.71:9735
2024-07-31 06:11:07.620 [DBG] PEER: Peer(0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2@54.245.111.71:9735
2024-07-31 06:11:07.621 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:07.621 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:07.621 [DBG] PEER: Peer(0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2): Sending Pong(len(pong_bytes)=2918) to 0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2@54.245.111.71:9735
2024-07-31 06:11:07.692 [DBG] PEER: Peer(0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2): Received Pong(len(pong_bytes)=634) from 0236e31dcc11311b09d1cfe54c82897fac4d8c3e28fcb7fb8744de385e0cf8ffb2@54.245.111.71:9735
2024-07-31 06:11:07.692 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:07.692 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:09.185 [DBG] PEER: Peer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c@164.90.144.205:41934
2024-07-31 06:11:09.270 [DBG] PEER: Peer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): Received Pong(len(pong_bytes)=2604) from 020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c@164.90.144.205:41934
2024-07-31 06:11:09.271 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:09.271 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:09.276 [DBG] PEER: Peer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c@164.90.144.205:41934
2024-07-31 06:11:09.276 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:09.276 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:09.276 [DBG] PEER: Peer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): Sending Pong(len(pong_bytes)=3913) to 020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c@164.90.144.205:41934
2024-07-31 06:11:09.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:57347: EOF
2024-07-31 06:11:16.086 [DBG] LNWL: filterManager updated moving median to: 1000 sat/kb
2024-07-31 06:11:17.234 [INF] WTCL: (taproot) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-07-31 06:11:17.234 [INF] WTCL: (legacy) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-07-31 06:11:17.234 [INF] WTCL: (anchor) Client stats: tasks(received=0 accepted=0 ineligible=0) sessions(acquired=0 exhausted=0)
2024-07-31 06:11:17.650 [INF] LITD: Handling REST request: /v1/taproot-assets/rfq/buyorder/asset-id/f8ffc554dad8a3780c408297a70b70af1c8d96cae3c167ff55cbd6308edb2a08
2024-07-31 06:11:17.650 [INF] LITD: Handling gRPC request: /rfqrpc.Rfq/AddAssetBuyOrder
2024-07-31 06:11:17.651 [DBG] RPCS: [/rfqrpc.Rfq/AddAssetBuyOrder] requested
2024-07-31 06:11:17.652 [DBG] RFQS: Manager handling outgoing message: BuyRequest(peer=0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792, id=d78f50f99909e66b9f7a8bb5256cd08e97669e2b83a507e23e5db68424382ee0, asset_id=f8ffc554dad8a3780c408297a70b70af1c8d96cae3c167ff55cbd6308edb2a08, asset_group_key=, asset_amount=10, bid_price=158)
2024-07-31 06:11:17.652 [DBG] RFQS: Stream handling outgoing message: BuyRequest(peer=0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792, id=d78f50f99909e66b9f7a8bb5256cd08e97669e2b83a507e23e5db68424382ee0, asset_id=f8ffc554dad8a3780c408297a70b70af1c8d96cae3c167ff55cbd6308edb2a08, asset_group_key=, asset_amount=10, bid_price=158)
2024-07-31 06:11:17.654 [DBG] RPCS: [/lnrpc.Lightning/SendCustomMessage] requested
2024-07-31 06:11:17.658 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Sending custom(type=52884) to 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:19.255 [DBG] NANN: HostAnnouncer checking for any IP changes...
2024-07-31 06:11:19.258 [DBG] NANN: No IP changes detected for hosts: [taplit.tryspeed.dev:9751]
2024-07-31 06:11:19.260 [DBG] HLCK: invoking success callback
2024-07-31 06:11:19.493 [DBG] DISC: Rotating active GossipSyncer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792) with GossipSyncer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c)
2024-07-31 06:11:19.493 [DBG] DISC: Transitioning active GossipSyncer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792) to passive
2024-07-31 06:11:19.494 [DBG] DISC: GossipSyncer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): transitioning from ActiveSync to PassiveSync
2024-07-31 06:11:19.494 [INF] DISC: GossipSyncer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): applying gossipFilter(start=0001-01-01 00:00:00 +0000 UTC, end=0001-01-01 00:00:00 +0000 UTC)
2024-07-31 06:11:19.494 [DBG] DISC: GossipSyncer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): state=chansSynced, type=PassiveSync
2024-07-31 06:11:19.494 [DBG] DISC: Transitioning passive GossipSyncer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c) to active
2024-07-31 06:11:19.494 [DBG] DISC: GossipSyncer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): transitioning from PassiveSync to ActiveSync
2024-07-31 06:11:19.494 [INF] DISC: GossipSyncer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): applying gossipFilter(start=2024-07-31 06:11:19.494398499 +0000 UTC m=+602405.086032608, end=2160-09-06 12:39:34.494398499 +0000 UTC)
2024-07-31 06:11:19.494 [DBG] DISC: GossipSyncer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): state=chansSynced, type=ActiveSync
2024-07-31 06:11:19.494 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Sending GossipTimestampRange(chain_hash=000000000933ea01ad0ee984209779baaec3ced90fa3f408719526f8d77f4943, first_stamp=2042-07-14 01:04:00 +0000 UTC, stamp_range=0) to 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:19.494 [DBG] PEER: Peer(020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c): Sending GossipTimestampRange(chain_hash=000000000933ea01ad0ee984209779baaec3ced90fa3f408719526f8d77f4943, first_stamp=2024-07-31 06:11:19 +0000 UTC, stamp_range=4294967295) to 020c3b59b1854d31b94c0dd9df1019d251b4cd5565129f7ad16e3ec8c4671afd8c@164.90.144.205:41934
2024-07-31 06:11:19.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:55844: EOF
2024-07-31 06:11:22.457 [DBG] LQDY: no rules configured for autoloop
2024-07-31 06:11:22.998 [DBG] UNIV: Federation envoy handling new tick event
2024-07-31 06:11:22.999 [INF] UNIV: Synchronizing with 1 federation members
2024-07-31 06:11:22.999 [INF] UNIV: Syncing Universe state with server=(universe.ServerAddr) {
 ID: (int64) 1,
 addrStr: (string) (len=40) "testnet.universe.lightning.finance:10029",
 addr: (net.Addr) <nil>
}

2024-07-31 06:11:22.999 [INF] UNIV: Attempting to sync universe: host=testnet.universe.lightning.finance:10029, sync_type=full, ids=([]universe.Identifier) <nil>

2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] Channel created
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] original dial target is: "54.244.179.44:10029"
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] dial target "54.244.179.44:10029" parse failed: parse "54.244.179.44:10029": first path segment in URL cannot contain colon
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] fallback to scheme "passthrough"
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] parsed dial target is: {URL:{Scheme:passthrough Opaque: User: Host: Path:/54.244.179.44:10029 RawPath: OmitHost:false ForceQuery:false RawQuery: Fragment: RawFragment:}}
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] Channel authority set to "54.244.179.44:10029"
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] Resolver state updated: {
  "Addresses": [
    {
      "Addr": "54.244.179.44:10029",
      "ServerName": "",
      "Attributes": null,
      "BalancerAttributes": null,
      "Metadata": null
    }
  ],
  "Endpoints": [
    {
      "Addresses": [
        {
          "Addr": "54.244.179.44:10029",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Metadata": null
        }
      ],
      "Attributes": null
    }
  ],
  "ServiceConfig": null,
  "Attributes": null
} (resolver returned new addresses)
2024-07-31 06:11:23.034 [DBG] GRPC: [core] [Channel #2334] Channel switches to new LB policy "pick_first"
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [pick-first-lb 0xc006670930] Received new config {
  "shuffleAddressList": false
}, resolver state {
  "Addresses": [
    {
      "Addr": "54.244.179.44:10029",
      "ServerName": "",
      "Attributes": null,
      "BalancerAttributes": null,
      "Metadata": null
    }
  ],
  "Endpoints": [
    {
      "Addresses": [
        {
          "Addr": "54.244.179.44:10029",
          "ServerName": "",
          "Attributes": null,
          "BalancerAttributes": null,
          "Metadata": null
        }
      ],
      "Attributes": null
    }
  ],
  "ServiceConfig": null,
  "Attributes": null
}
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334 SubChannel #2335] Subchannel created
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334] Channel Connectivity change to CONNECTING
2024-07-31 06:11:23.035 [INF] UNIV: Fetching 0 roots
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334 SubChannel #2335] Subchannel Connectivity change to CONNECTING
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334 SubChannel #2335] Subchannel picks a new address "54.244.179.44:10029" to connect
2024-07-31 06:11:23.035 [INF] UNIV: Obtained 0 roots from remote Universe server
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334] Channel Connectivity change to SHUTDOWN
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334] ccBalancerWrapper: closing
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [pick-first-lb 0xc006670930] Received SubConn state update: 0xc006670a50, {ConnectivityState:CONNECTING ConnectionError:<nil>}
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334] Closing the name resolver
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334 SubChannel #2335] Subchannel Connectivity change to SHUTDOWN
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334 SubChannel #2335] Subchannel deleted
2024-07-31 06:11:23.035 [DBG] GRPC: [core] [Channel #2334] Channel deleted
2024-07-31 06:11:23.035 [DBG] GRPC: [core] Creating new client transport to "{Addr: \"54.244.179.44:10029\", ServerName: \"54.244.179.44:10029\", }": connection error: desc = "transport: Error while dialing: dial tcp 54.244.179.44:10029: operation was canceled"
2024-07-31 06:11:23.035 [WRN] GRPC: [core] [Channel #2334 SubChannel #2335] grpc: addrConn.createTransport failed to connect to {Addr: "54.244.179.44:10029", ServerName: "54.244.179.44:10029", }. Err: connection error: desc = "transport: Error while dialing: dial tcp 54.244.179.44:10029: operation was canceled"
2024-07-31 06:11:29.240 [DBG] PEER: Peer(02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f@195.201.207.61:9739
2024-07-31 06:11:29.340 [DBG] PEER: Peer(02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f): Received Pong(len(pong_bytes)=1373) from 02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f@195.201.207.61:9739
2024-07-31 06:11:29.340 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:29.340 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:29.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:49427: EOF
2024-07-31 06:11:30.221 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:30.221 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:30.221 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:30.222 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Sending Pong(len(pong_bytes)=3429) to 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:30.223 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:30.225 [DBG] PEER: Peer(0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792): Received Pong(len(pong_bytes)=706) from 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792@10.0.5.196:8735
2024-07-31 06:11:30.225 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:30.225 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:30.670 [DBG] WTCL: (taproot) Unable to get new tower candidate, retrying after 5m0s -- reason: exhausted all tower candidates
2024-07-31 06:11:30.670 [DBG] WTCL: (anchor) Unable to get new tower candidate, retrying after 5m0s -- reason: exhausted all tower candidates
2024-07-31 06:11:30.670 [DBG] WTCL: (legacy) Unable to get new tower candidate, retrying after 5m0s -- reason: exhausted all tower candidates
2024-07-31 06:11:32.653 [ERR] RPCS: [/rfqrpc.Rfq/AddAssetBuyOrder]: timeout waiting for response from peer 0356b462318215eda24c7d5e9e4ede517a727c9899ac6acbf273a396a4211a3792
2024-07-31 06:11:32.653 [DBG] GRPC: [transport] [server-handler-transport 0xc001c64320] Closing: finished writing status
2024-07-31 06:11:33.246 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:33.337 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:33.337 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:33.337 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:33.337 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Sending Pong(len(pong_bytes)=16) to 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:33.338 [DBG] PEER: Peer(032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4): Received Pong(len(pong_bytes)=1049) from 032ea4d24c807bfe6df899df04f2b562a646d7467b2ab3c97cffdc98e0d1a984e4@89.38.96.141:40576
2024-07-31 06:11:33.338 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:33.338 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:37.259 [DBG] PEER: Peer(02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd): Received Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) from 02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd@142.93.149.16:9735
2024-07-31 06:11:37.259 [DBG] PEER: Peer(02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd): Sending Ping(ping_bytes=0060e621661c7d61c0672d8816abc5deae5ebc6d7a2fda2fcaf0bebd09000000000000005f4df808c1c6368e3dcc39b9720959612162464e52adc1fb5771e06990f6e9efc6d4a966c9f21419b15c31b8) to 02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd@142.93.149.16:9735
2024-07-31 06:11:37.260 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:37.260 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:37.260 [DBG] PEER: Peer(02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd): Sending Pong(len(pong_bytes)=4059) to 02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd@142.93.149.16:9735
2024-07-31 06:11:37.281 [DBG] PEER: Peer(02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd): Received Pong(len(pong_bytes)=1924) from 02146e28a3d43205b99d93c758b18d302be0086655d5a23e9bea9a6509da907dbd@142.93.149.16:9735
2024-07-31 06:11:37.281 [DBG] TCHN: Failed to handle: *lnwire.Pong
2024-07-31 06:11:37.281 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:39.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:54520: EOF
2024-07-31 06:11:49.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:56258: EOF
2024-07-31 06:11:59.358 [DBG] PEER: Peer(02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f): Received Ping(ping_bytes=00000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000000) from 02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f@195.201.207.61:9739
2024-07-31 06:11:59.358 [DBG] TCHN: Failed to handle: *lnwire.Ping
2024-07-31 06:11:59.358 [DBG] PFSM: MsgRouter: unable to route msg protofsm.PeerMsg
2024-07-31 06:11:59.358 [DBG] PEER: Peer(02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f): Sending Pong(len(pong_bytes)=939) to 02bf82e22f99dcd7ac1de4aad5152ce48f0694c46ec582567f379e0adbf81e2d0f@195.201.207.61:9739
2024-07-31 06:11:59.766 [ERR] CMGR: Can't accept connection: unable to accept connection from 10.0.2.152:52706: EOF

@guggero
Copy link
Member

guggero commented Jul 31, 2024

Thanks for the additional information. So that means you don't yet have an asset channel between node 1 and node 2?
RFQ quotes can only be requested once a channel with the given asset exists. But we should probably catch that earlier and return a more useful error message.

@vanditshah99
Copy link
Author

Yes we don't have a channel between node1 and node 2.

@ffranr
Copy link
Contributor

ffranr commented Jul 31, 2024

Created this issue to help users use the RPC endpoints correctly: #1053

@guggero
Copy link
Member

guggero commented Jul 31, 2024

Closing, as the shutdown problem was addressed with #1011 and the remaining problem is tracked in #1053.

@guggero guggero closed this as completed Jul 31, 2024
@github-project-automation github-project-automation bot moved this from 🆕 New to ✅ Done in Taproot-Assets Project Board Jul 31, 2024
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
bug Something isn't working
Projects
Status: ✅ Done
Development

No branches or pull requests

4 participants