problems with universe sync --universe_host universe.lightning.finance:10029

[MegalithicBTC]

I'm working with tapd and I think I may have found a reproducible problem.

Here are my steps.

1. Clone this repository.
2. Switch to tag v0.3.3
3. Run make install
4. Confirm binary version: tapd --version

user@PR2:/src$ tapd --version
tapd version 0.3.3-alpha commit=v0.3.3

5. Enable inserts with these commands:

tapcli universe federation config global --proof_type transfer --allow_insert true
tapcli  universe federation config global --proof_type issuance --allow_insert true

6. attempt to sync the default universe

tapcli universe sync --universe_host universe.lightning.finance:10029

7. See attached logs:
   combined_log.txt

8. Note that these logs end with:

2024-04-24 14:46:42.320 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to register proofs: unable to register proofs: unable to verify issuance proofs: unable to verify proof: group key not known: 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e: group verifier: no matching asset group: sql: no rows in result set: group key not known

9. Run tapcli universe stats, and see that nothing has synced yet

tapcli universe stats

{
    "num_total_assets": "0",
    "num_total_groups": "0",
    "num_total_syncs": "0",
    "num_total_proofs": "0"
}

Note -- this was performed on a fresh SQlite database. On a different machine, using Postgres, about 2 days ago, I think I was able to successfully sync universe.lightning.finance:10029, and following that, I had seen that tapcli universe stats returned thousands of assets.... but then I started adding more universes to my federation, I started seeing Max DB retries failures.... So I assumed that one of the universes I has synced had corrupted data. But I could not figure out how to REMOVE a universe, or reliably identify or delete "bad" assets, so I decided to start from the beginning again with a fresh SQLite database that I could easily delete.

[jharveyb]

Thanks for the report! How many cores does this system have?

Also, do you have logs that contain the Max DB retries message? There is a related known issue, #675 for that.

Re: delete federation server, there should be a command universe federation del. You can also manually delete universe info for specific assets.

Will try and repro in a debug setting.

[MegalithicBTC]

This system has 24 cores. On my other system, I am going to try to reproduce the Max DB retries issue now and see if I can get logs.

[MegalithicBTC]

On my original machine, using a Postgres backend, I just tried tapcli universe sync --universe_host universe.lightning.finance:10029.

Note, that on this machine, I had recently added and then removed some federations. To remove them, I used: tapcli universe federation del. After noticing that removing the federations did not remove any assets, I had also tried to randomly remove a few assets using tapcli universe delete, and it seemed I was able to delete a few, but then I did get errors, something like "unable to delete because of an existing group" (or something like that, sorry, don't have those logs.)

In any case, I just ran tapcli universe sync --universe_host universe.lightning.finance:10029, which ran for a while but errored out with

[tapcli] rpc error: code = Unknown desc = unable to sync universe: unable to register proofs: unable to register proofs: unable to register new issuance proofs: sql unique constraint violation: ERROR: duplicate key value violates unique constraint "mssmt_nodes_pkey" (SQLSTATE 23505)

here are the complete logs:

tapd_combined.log

Given that I have been playing with this instance of tapd for a few days it might not be the best candidate for study... the issue I reported a few hours ago might be "cleaner" to study as I was able to reproduce it with a totally new SQlite database.

[jharveyb]

I think federation del should prevent future syncs with that server, but not delete info you already synced from them.

Both of the new errors are interesting; pretty sure we test deletion of assets from a universe and re-syncing.

[MegalithicBTC]

Definitely let me know if there's anything else you would like me to test on my end.

[MegalithicBTC]

In case it's helpful: I have continued to find that I can follow these exact steps: #889 (comment) ... and always end with this error:

taproot-1  | 2024-04-29 16:51:08.234 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to register proofs: unable to register proofs: unable to verify issuance proofs: unable to verify proof: group key not known: 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e: group verifier: no matching asset group: sql: no rows in result set: group key not known

So at least that seems like some kind of straightforward data consistency error and not some kind of intermittent race condition or something harder to understand.

[MegalithicBTC]

Am testing this again on a fresh install. I do always get this error when trying to sync:

taproot-1  | 2024-04-29 16:51:08.234 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to register proofs: unable to register proofs: unable to verify issuance proofs: unable to verify proof: group key not known: 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e: group verifier: no matching asset group: sql: no rows in result set: group key not known

So it seems there is specifically an issue with this group key 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e - or perhaps (as you mentioned something about number of CPUs) there is a race condition having something to do with asset groups.

Getting assets from the default universe consistently fails and the only way to proceed is to comment out the body of this function...

taproot-assets/proof/verifier.go

Line 360 in 91a51d6

groupKey := p.Asset.GroupKey.GroupPubKey

.... which then allows more syncing activity to proceed. (I would guess commenting this out on a production system would be totally unsafe.)

I am able to then get more assets, but eventually the process halts again with:

taproot-taproot-1  | 2024-05-15 20:48:48.064 [DBG] UNIV: Looking up root node for base Universe (universe.Identifier) issuance-e1c3c2ef355476766bdb0188db8942ff855ccb00c7a6c971c22c0e54a9c1771f
taproot-taproot-1  | 
taproot-taproot-1  | 2024-05-15 20:48:48.064 [ERR] RPCS: [/universerpc.Universe/SyncUniverse]: unable to sync universe: unable to register proofs: unable to register proofs: unable to register new issuance proofs: db tx retries exceeded

So there is another hack to get beyond this point, which is to increase DefaultNumTxRetries in interfaces.go to something unreasonably high, like 500...

taproot-assets/tapdb/interfaces.go

Line 23 in 91a51d6

DefaultNumTxRetries = 10

.. After this, anecdotally, it seems that if I then run tapd for several days or weeks, eventually I stop seeing the db tx retries exceeded messages, and on this long-running node, I have gotten to:

user@AW64:/src$ tapcli universe stats
{
    "num_total_assets": "33144",
    "num_total_groups": "93",
    "num_total_syncs": "0",
    "num_total_proofs": "68612"
}

My guess is to try to find the problem, I should start with a fresh database, and then log all SQL statements, to find out which ones are erroring, but I have not yet figured out how I could log the SQL activity from tapd. Is there a logger setting, or some place I can put a logging statement, in order to log the underlying SQL?

[jharveyb]

You should be able to run tapd with global and per-package debug logging settings with the same format as for lnd:

https://docs.lightning.engineering/lightning-network-tools/lnd/lnd.conf

The DB subsystem is TADB.

So there is another hack to get beyond this point, which is to increase DefaultNumTxRetries in interfaces.go to something unreasonably high, like 500...

Yup, this is #675. It should make partial progress to being fully in sync, which sounds like what happened in your case. Should of these defaults are reachable via config settings, but we're looking to expose more (or just increase them).

Getting assets from the default universe consistently fails and the only way to proceed is to comment out the body of this function...

I think you should actually be able to ignore this group, and then you'd avoid that issue during sync:

tapcli universe federation config local --group_key 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e --allow_insert false
tapcli universe federation config local --group_key 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e --allow_export false

You could also delete any info you did already sync with 'universe delete' & the group key.

[MegalithicBTC]

Thanks, will try that to ignore the group.

BTW I already have this in my tapd.conf

debuglevel=trace

My understanding is that this should set the lowest level of debugging possible for every subsystem. So my guess is that even with TADB=trace it might be that SQL statements aren't logged.

[MegalithicBTC]

Look like I was able to do universe delete and the config local commands, I will try syncing again to confirm that this group_key is ignored.

And for anyone reading this thread in the future, the full commands require that you set --proof_type, so I found them to be successful with:

tapcli universe federation config local --group_key 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e --allow_export false --proof_type transfer
and
tapcli universe federation config local --group_key 03f9c974a0618b1ae5e57a5e29c9cc6367473add473febbdc842fe6eef26d8693e --allow_export false --proof_type issuance

[MegalithicBTC]

I am running another sync and still getting a lot of "tx serialization error". If I could print the SQL statements, then I could likely do more --allow_export false to disable trying to import those assets. Would be great to find a way to log the SQL statements. The SQL handling is wrapped in so many functions that I have been so far unable to figure out how to hack into the code to try to print the SQL statements but do let me know if you have a hint of where that could be done.

[MegalithicBTC]

Also, another tapd instance I am finding that universe sync is failing because of a (possibly unrelated?) database issue:

tapcli universe sync --universe_host universe.lightning.finance:10029
[tapcli] rpc error: code = Unknown desc = unable to sync universe: unable to register proofs: unable to register proofs: unable to register new issuance proofs: sql unique constraint violation: ERROR: duplicate key value violates unique constraint "mssmt_nodes_pkey" (SQLSTATE 23505)

Again here if I could figure out how to log the raw SQL I could try to diagnose.

[jharveyb]

That looks new, is that with the same config of trying to sync the full state of the Lightning Labs universe?

[MegalithicBTC]

Yes. I think there are multiple database issues. Still would like to try to figure out what is going on, but would need a way to log the SQL.