Mainnet instance is slow (both queries and to sync) #118

aciceri · 2023-04-20T09:43:19Z

aciceri
Apr 20, 2023

Hello,
we've been using for months some internal shared instances between several teams and projects for preview and preprod networks and they worked without any problem. Recently I've enabled an instance also for mainnet but now:

it's not fully synced although it has been active for days
querying it is slow (and sometimes it also times out, but maybe it's the proxy and not directly kupo, still we cannot afford to 45+ seconds)

I was using v2.2.0 but now I've updated to v2.4.0 (without deleting the db, had I to do so?), this is how I run it:

'kupo' '--node-socket' '/run/cardano-node/node.socket' '--node-config' '/cardano-configurations/network/mainnet/cardano-node/config.json' '--host' 'localhost' '--port' '1442' '--workdir' '/var/lib/kupo' '--match' '*/*' '--since' 'origin

The cardano-node' config.json is taken from here
Also

$ curl https://<my_instance>/health                                               
# TYPE kupo_connection_status gauge                              
kupo_connection_status  1.0
# TYPE kupo_most_recent_checkpoint counter
kupo_most_recent_checkpoint  89367590
# TYPE kupo_most_recent_node_tip counter
kupo_most_recent_node_tip  90416992

Even if the delta between kupo_most_recent_node_tip and kupo_most_recent_node_tip is slowly decreasing it seems to be taking days.
I still have to try enabling --prune-utxo as suggested in #110 since I'm not sure that this is compatible to our needs. In case I want to enable it, should I remove the db before?
Is Kupo supposed to be used indexing everything since origin without pruning utxos on mainnet? Right now the kupo.sqlite3 is 146GB.

KtorZ · 2023-04-20T10:08:39Z

KtorZ
Apr 20, 2023
Maintainer

it's not fully synced although it has been active for days

When indexing over a long slot range, you should enable --defer-db-indexes; and turn off the flag once synchronized. That should give you some nice speed-up. Mainnet takes a bit of time to synchronize though, it's large! Note that from the perspective of the node, Kupo is "only" a client application and as a consequence, if your node is also syncing, it will not prioritize requests from Kupo but prioritize synchronization from the network. Which means that while the node is syncing, Kupo (or any client application really) is almost idle and receives blocks at a very low pace from the node. As soon as the node reaches the stable area, it'll start shifting more resources to client applications.

querying it is slow (and sometimes it also times out, but maybe it's the proxy and not directly kupo)

I'd love a confirmation of that; Logs should actually give you request times on Kupo so you should be able to tell whether it's kupo or somewhere else in your infra. I haven't observed or measured any particular slow time and largest queries on Kupo (several hundred thousands of results) are typically resolved under 10s on a standard dev machine.

without deleting the db, had I to do so?

No, database migrations should handle that for you; there hasn't been any database schema changes though since v2.2.0

0 replies

aciceri · 2023-04-20T10:34:40Z

aciceri
Apr 20, 2023
Author

I'd love a confirmation of that; Logs should actually give you request times on Kupo so you should be able to tell whether it's kupo or somewhere else in your infra

Same request done two times: https://<my-kupo>/matches/0@6740390094dd6ef6b0672d7d3e6f646c1d87104513130518d6b7a1a16d0ec51d
First time it answered in more than 4 seconds, the second time it timed out. Here are the logs:

Apr 20 10:21:04 ctl-runtime-mainnet kupo-start[245138]: {"severity":"Info","timestamp":"2023-04-20T10:21:04.575855912Z","thread":"118","message":{"Http":{"tag":"HttpResponse","status":{"statusCode":200,"statusMessage":"OK"},"time":{"milliseconds":4157}}},"version":"v2.4.0"}
Apr 20 10:21:09 ctl-runtime-mainnet kupo-start[245138]: {"severity":"Info","timestamp":"2023-04-20T10:21:09.058346923Z","thread":"120","message":{"Http":{"tag":"HttpRequest","path":["matches","0@6740390094dd6ef6b0672d7d3e6f646c1d87104513130518d6b7a1a16d0ec51d"],"method":"GET"}},"version":"v2.4.0"}
Apr 20 10:22:00 ctl-runtime-mainnet kupo-start[245138]: {"severity":"Error","timestamp":"2023-04-20T10:22:00.418465837Z","thread":"120","message":{"Http":{"tag":"HttpUnexpectedError","hint":"Thread killed by timeout manager"}},"version":"v2.4.0"}

Just to be sure I retried overtaking the reverse proxy directly curling localhost, that returns

curl: (52) Empty reply from server

When indexing over a long slot range, you should enable --defer-db-indexes; and turn off the flag once synchronized.

I'm trying, didn't know, thanks.

Which means that while the node is syncing, Kupo (or any client application really) is almost idle and receives blocks at a very low pace from the node. As soon as the node reaches the stable area, it'll start shifting more resources to client applications.

This is useful too. Luckily we have snapshots for cardano-node so it's relatively quick syncing it. We were also considering creating snapshots for kupo too.

No, database migrations should handle that for you; there hasn't been any database schema changes though since v2.2.0
Related: the db will be downsized after that I enable --prune-utxos, right? Or spent outputs will be still there but simply ignored? This was I really wanted to ask

0 replies

KtorZ · 2023-04-20T11:44:31Z

KtorZ
Apr 20, 2023
Maintainer

Hmmm. Sounds like there's something weird with your setup; I've been trying that same request on a Kupo instance running on https://demeter.run with * as a pattern (so arguably even slightly worse than your scenario) and it is very much instantaneous :

❯ time curl "https://kupo-mainnet-api-<my-project-id>.demeter.run/matches/0@6740390094dd6ef6b0672d7d3e6f646c1d87104513130518d6b7a1a16d0ec51d" | jq
[
  {
    "transaction_index": 37,
    "transaction_id": "6740390094dd6ef6b0672d7d3e6f646c1d87104513130518d6b7a1a16d0ec51d",
    "output_index": 0,
    "address": "addr1w849xkxel6pvc7kcmc88dd82hkz32fjq3ega42wchd93xlgqxxpv5",
    "value": {
      "coins": 1094740,
      "assets": {
        "735b37149eb0c2a5fb590bd60e39fe90ae3a96b6065b05d7aca99ebb.4344505f43524541544f52": 1
      }
    },
    "datum_hash": "923918e403bf43c34b4ef6b48eb2ee04babed17320d8d1b9ff9ad086e86f44ec",
    "datum_type": "inline",
    "script_hash": null,
    "created_at": {
      "slot_no": 77508372,
      "header_hash": "41dc5ac8b4a9f30b11e16ab575bf2cc0ff2a2ac3b701a129aeb960fcc3460451"
    },
    "spent_at": {
      "slot_no": 77509018,
      "header_hash": "a9cb304a0807b5dafa6dc42fa3d7e7b33a63d26d701984915e3e37e6246a1f6c"
    }
  }

curl   0.01s user 0.01s system 1% cpu 0.775 total

Especially on requests that fetch results by output reference which are literally a primary key on the underlying table. I need to add some kind of database health check to the health output, but in the meantime, if you have access to it it could help to run some sanity checks on your database and run the following commands:

sqlite> .indexes
    inputsByOutputReference         sqlite_autoindex_patterns_1
    sqlite_autoindex_binary_data_1  sqlite_autoindex_policies_1
    sqlite_autoindex_inputs_1       sqlite_autoindex_scripts_1

sqlite> .schema inputs
    CREATE TABLE inputs (
      ext_output_reference BLOB NOT NULL,
      address TEXT COLLATE NOCASE NOT NULL,
      value BLOB NOT NULL,
      datum_info BLOB,
      script_hash BLOB,
      created_at INTEGER NOT NULL,
      spent_at INTEGER, payment_credential TEXT COLLATE NOCASE GENERATED ALWAYS AS (substr(address, -56)) VIRTUAL, output_reference  BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, 1, 34)) VIRTUAL, output_index      BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -4, 2)) VIRTUAL, transaction_index BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -2))    VIRTUAL, datum_hash BLOB GENERATED ALWAYS AS (substr(datum_info, 2)) VIRTUAL,
      PRIMARY KEY (ext_output_reference)
    );
    CREATE UNIQUE INDEX inputsByOutputReference ON inputs(output_reference);

0 replies

aciceri · 2023-04-20T12:02:10Z

aciceri
Apr 20, 2023
Author

Sounds like there's something weird with your setup

Glad to hear that, at least now I know that what I'm trying to do is doable :)

if you have access to it it could help to run some sanity checks on your database and run the following commands:

Here's to you:

sqlite> .indexes
inputsByAddress                 sqlite_autoindex_binary_data_1
inputsByCreatedAt               sqlite_autoindex_inputs_1     
inputsByOutputReference         sqlite_autoindex_patterns_1   
inputsByPaymentCredential       sqlite_autoindex_policies_1   
policiesByPolicyId              sqlite_autoindex_scripts_1    
sqlite> .schema inputs
CREATE TABLE inputs (
  ext_output_reference BLOB NOT NULL,
  address TEXT COLLATE NOCASE NOT NULL,
  value BLOB NOT NULL,
  datum_info BLOB,
  script_hash BLOB,
  created_at INTEGER NOT NULL,
  spent_at INTEGER, payment_credential TEXT COLLATE NOCASE GENERATED ALWAYS AS (substr(address, -56)) VIRTUAL, output_reference  BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, 1, 34)) VIRTUAL, output_index      BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -4, 2)) VIRTUAL, transaction_index BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -2))    VIRTUAL, datum_hash BLOB GENERATED ALWAYS AS (substr(datum_info, 2)) VIRTUAL,
  PRIMARY KEY (ext_output_reference)
);
CREATE UNIQUE INDEX inputsByOutputReference ON inputs(output_reference);
CREATE INDEX inputsByAddress ON inputs(address COLLATE NOCASE, spent_at);
CREATE INDEX inputsByPaymentCredential ON inputs(payment_credential COLLATE NOCASE, spent_at);
CREATE INDEX inputsByCreatedAt ON inputs(created_at);

2 replies

KtorZ Apr 20, 2023
Maintainer

That looks about right. Can you also check for:

sqlite> SELECT COUNT(*) FROM inputs;
sqlite> SELECT COUNT(*) FROM policies;
sqlite> SELECT COUNT(*) FROM checkpoints;

aciceri Apr 20, 2023
Author

Running those queries took a bit:

sqlite> SELECT COUNT(*) FROM inputs;
158056994
sqlite> SELECT COUNT(*) FROM policies;
245161619
sqlite> SELECT COUNT(*) FROM checkpoints;
8642523

KtorZ · 2023-04-20T12:41:52Z

KtorZ
Apr 20, 2023
Maintainer

Question: is your infra running on a fast SSD?

2 replies

aciceri Apr 20, 2023
Author

It's on a "cloud host" (then a VM) but it should be relatively fast. Let me benchmark it.

aciceri Apr 20, 2023
Author

$ hdparm -Tt /dev/sda

/dev/sda:
 Timing cached reads:   38168 MB in  1.99 seconds = 19138.51 MB/sec
 Timing buffered disk reads: 4412 MB in  3.00 seconds = 1470.41 MB/sec

aciceri · 2023-04-20T13:02:54Z

aciceri
Apr 20, 2023
Author

Could be this related to the fact that I've other services connected to the same cardano node socket?
Perhaps I don't have enough free memory on my system? How much memory is Kupo supposed to use?

4 replies

KtorZ Apr 20, 2023
Maintainer

Could be this related to the fact that I've other services connected to the same cardano node socket?

Possibly. Do you have an idea of what kind of traffic the single instance needs to support at the moment? Kupo does relatively fine with few concurrent clients (< 100) but isn't generally meant to handle massive loads.

Perhaps I don't have enough free memory on my system? How much memory is Kupo supposed to use?

Once synchronized, it sits somewhere between 150MB and 500MB. So it shouldn't really be a factor.

aciceri Apr 20, 2023
Author

Possibly.

Do you know how can I check if this is the case? Just disabling other services?

Do you have an idea of what kind of traffic the single instance needs to support at the moment? Kupo does relatively fine with few concurrent clients (< 100) but isn't generally meant to handle massive loads.

As first step just me manually running curl :)
Later we'll see, however I can set up a load balancer.

Once synchronized, it sits somewhere between 150MB and 500MB.

Not much then. But I noticed that available memory was like 200-300MB so I scaled the instance and now I'm waiting for cardano-node to revalidate all the chunks. It costs nothing to try.

KtorZ Apr 21, 2023
Maintainer

Do you know how can I check if this is the case? Just disabling other services?

I am wondering what those "other services" are? If they are keeping the instance busy, you should see requests in Kupo's logs.

But I noticed that available memory was like 200-300MB so I scaled the instance and now I'm waiting for cardano-node to revalidate all the chunks.

That sounds possibly limiting indeed; perhaps that's what causing some issue. Also, another question; what is your node reporting as a current tip?

aciceri Apr 21, 2023
Author

I've increased the memory (now it's not a problem anymore for sure) and restarted Kupo adding --defer-db-indexes and --prune-utxo but it didn't seem faster. So I put backupped that kupo.sqlite3 and I've tried restarting Kupo with those arguments and ad the beginning it seemed faster but probably it was only because first blocks are smaller...

But now the db seems smaller (I cannot be sure until I reach the same slot I reached before since the number and size of transactions is not constant). Now with the new db I'm around slot 45.699.401 (after many hours, is it normal?) and the db is 2.3G while the other db (that was about at a slot greater than 8.000.000) weighted 147G.

I am wondering what those "other services" are? If they are keeping the instance busy, you should see requests in Kupo's logs.

I meant that they could keep the cardano node busy "stealing" resources that it could dedicate kupo. I'm talking about ogmios-datum-cache and ogmios but I think that the latter is stateless and interact with the node only if queried, so only the former keeps querying the node.

what is your node reporting as a current tip?

{
    "block": 8674940,
    "epoch": 407,
    "era": "Babbage",
    "hash": "a3e7d04484e9a7b09cd7a40c3a167d93f15d8bcfd99b28f46ceb2f270be53367",
    "slot": 90506432,
    "syncProgress": "100.00"
}

It's the same reported by cexplorer, it looks updated.

aciceri · 2023-04-21T10:28:07Z

aciceri
Apr 21, 2023
Author

Do you think this could be cause by an older cardano node version? Honestly I can't see how but I'm running out of ideas, right now I'm using 1.35.4. Should I update it?

0 replies

KtorZ · 2023-04-21T13:32:03Z

KtorZ
Apr 21, 2023
Maintainer

I've tried restarting Kupo with those arguments and ad the beginning it seemed faster but probably it was only because first blocks are smaller...

Yes; Kupo will inevitably slow down during synchronization if you just look at slot numbers / block numbers because the chain is getting more dense. Not much really happened during the first two years of history and the Byron era is relatively empty. Starting from Mary era things start to get serious with multi-assets and first NFT projects, then Alonzo really kicks it off in terms of activity. So yes, synchronizing the first 70% of the chain takes something like 10x less time than the last 30%. That's not a Kupo issue, just the way the chain is populated.

Synchronizing the entire mainnet will take something around 12-18h depending on your hardware requirement. And not also that this demands more memory (1-2GB) than once synchronized. So if you have less memory available, you may likely run into issues.

But now the db seems smaller (I cannot be sure until I reach the same slot I reached before since the number and size of transactions is not constant). Now with the new db I'm around slot 45.699.401 (after many hours, is it normal?) and the db is 2.3G while the other db (that was about at a slot greater than 8.000.000) weighted 147G.

Yes, if you are passing --prune-utxo, the history isn't kept around; only the edge of the UTxO graph is kept so the database is much smaller. On mainnet, that's about ~10M entries at the moment, versus ~150M if you keep them all around. Note that you're not suppose to change the pruning mode of operation after indexing. Disable --prune-utxo will not have dramatic consequences but you'll miss the whole part that you've already pruned; but adding --prune-utxo on a non-pruned database will force Kupo to attempt deleting its entire history (so multiple hundred million rows) in one go which is a really bad idea. I could make this more incremental but I don't quite see the use case for it. Perhaps a warning and crashing would actually be preferable.

Do you think this could be cause by an older cardano node version? Honestly I can't see how but I'm running out of ideas, right now I'm using 1.35.4. Should I update it?

I hardly think so; I've been running on 1.35.4 for a while actually. Node versions usually do not touch the client interfaces so it doesn't really impact these areas. You could likely even connect to a 1.10.0 node and still be able to synchronize through Byron and Shelley.

0 replies

ironmask285 · 2023-08-28T03:45:42Z

ironmask285
Aug 28, 2023

hic, I got same issue, here's my check:
qlite> SELECT COUNT() FROM checkpoints;
4725031
sqlite> SELECT COUNT() FROM policies;
302999859
sqlite> .indexes
inputsByOutputReference sqlite_autoindex_patterns_1
sqlite_autoindex_binary_data_1 sqlite_autoindex_policies_1
sqlite_autoindex_inputs_1 sqlite_autoindex_scripts_1
sqlite> .schema inputs
CREATE TABLE inputs (
ext_output_reference BLOB NOT NULL,
address TEXT COLLATE NOCASE NOT NULL,
value BLOB NOT NULL,
datum_info BLOB,
script_hash BLOB,
created_at INTEGER NOT NULL,
spent_at INTEGER, payment_credential TEXT COLLATE NOCASE GENERATED ALWAYS AS (substr(address, -56)) VIRTUAL, output_reference BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, 1, 34)) VIRTUAL, output_index BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -4, 2)) VIRTUAL, transaction_index BLOB NOT NULL GENERATED ALWAYS AS (substr(ext_output_reference, -2)) VIRTUAL, datum_hash BLOB GENERATED ALWAYS AS (substr(datum_info, 2)) VIRTUAL,
PRIMARY KEY (ext_output_reference)
);
sqlite> select count(address) from inputs;
187468627
can you help me ?

1 reply

KtorZ Aug 28, 2023
Maintainer

Your database is missing all crucial indexes. You need to restart it without the "--defer-db-indexes" flag.

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Mainnet instance is slow (both queries and to sync) #118

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Replies: 9 comments 9 replies

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

{{title}}

{{title}}

{{title}}

{{title}}

{{editor}}'s edit

{{editor}}'s edit

Select a reply

Mainnet instance is slow (both queries and to sync) #118

aciceri Apr 20, 2023

Replies: 9 comments · 9 replies

KtorZ Apr 20, 2023 Maintainer

aciceri Apr 20, 2023 Author

KtorZ Apr 20, 2023 Maintainer

aciceri Apr 20, 2023 Author

KtorZ Apr 20, 2023 Maintainer

aciceri Apr 20, 2023 Author

KtorZ Apr 20, 2023 Maintainer

aciceri Apr 20, 2023 Author

aciceri Apr 20, 2023 Author

aciceri Apr 20, 2023 Author

KtorZ Apr 20, 2023 Maintainer

aciceri Apr 20, 2023 Author

KtorZ Apr 21, 2023 Maintainer

aciceri Apr 21, 2023 Author

aciceri Apr 21, 2023 Author

KtorZ Apr 21, 2023 Maintainer

ironmask285 Aug 28, 2023

KtorZ Aug 28, 2023 Maintainer

aciceri
Apr 20, 2023

Replies: 9 comments 9 replies

KtorZ
Apr 20, 2023
Maintainer

aciceri
Apr 20, 2023
Author

KtorZ
Apr 20, 2023
Maintainer

aciceri
Apr 20, 2023
Author

KtorZ Apr 20, 2023
Maintainer

aciceri Apr 20, 2023
Author

KtorZ
Apr 20, 2023
Maintainer

aciceri Apr 20, 2023
Author

aciceri Apr 20, 2023
Author

aciceri
Apr 20, 2023
Author

KtorZ Apr 20, 2023
Maintainer

aciceri Apr 20, 2023
Author

KtorZ Apr 21, 2023
Maintainer

aciceri Apr 21, 2023
Author

aciceri
Apr 21, 2023
Author

KtorZ
Apr 21, 2023
Maintainer

ironmask285
Aug 28, 2023

KtorZ Aug 28, 2023
Maintainer