Nanopub-query seems slower since last update

[tkuhn]

I don't have any numbers, but Nanopub Query seems slower since the last update. E.g. parts in Nanodash load with more delay.

I also see that it's sometimes (but not always) trying to re-load the latest nanopub over and over:

query-1  | Loaded 1 update(s). Counter: 61800, target was: 61800
query-1  | Loading 61800: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Loaded 1 update(s). Counter: 61800, target was: 61800
query-1  | Loading 61800: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Loaded 1 update(s). Counter: 61800, target was: 61800
query-1  | Loading 61800: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A
query-1  | Already loaded: https://w3id.org/np/RA4-353uWQVyW5KHPOdJdZZxo_759gRGH0WihON-6zF-A

[tkuhn]

I don't see any obvious relation to the latest changes on your side, @Ostrzyciel, but maybe you have a hunch what's going on here?

[Ostrzyciel]

Sure, I'll take a look, I'll try to do it this week, but no promises since I'm travelling :)

[tkuhn]

Great, thank you! :)

[Ostrzyciel]

I ran the latest version of Query and Registry on my system, and I don't see any significant slowdown since last time, in loading. I also profiled the process and the flamegraph looks as expected. The recent changes to Jelly are definitely not the issue, as Jelly parsing barely even registers on the plot. We also ran internal benchmarks comparing Jelly-JVM 2.10 to 3.x, and we can confirm there is no performance regression there.

As we discussed in Slovenia, I think the most likely cause is what you mentioned – crawlers. On another site that I manage, AI crawlers account for most of the traffic, and can eat up immense amounts of CPU and RAM, as they blindly scrape everything, including the more expensive pages that require complex queries for them to be displayed.

You could examine the Nginx logs for user agents and see if there is anything suspicious. I can't give you a one-liner for this, as the log format depends on your configuration. Roughly, you need to:

• enable the access log, if not done already: https://docs.nginx.com/nginx/admin-guide/monitoring/logging/#set-up-the-access-log
• let it run for a few hours (or days)
• grep the logs searching for the part that's specified as $http_user_agent in the log entry template
• pipe it through uniq
• see if there are any known AI crawler user agents https://www.coryd.dev/posts/2024/go-ahead-and-block-ai-web-crawlers/

I think it's worth doing this for both Nanodash and Query.

I use Logstash+Elastic+Kibana (ELK stack) to make this process nicer, but this requires quite a lot of setting up.

Unfortunately, blocking these crawlers is not easy. They typically do not respect robots.txt. You can try blocking them one-by-one by creating custom rules in nginx config (if user agent from the "bad" list -> drop connection). But then they also fake their use agents to look like innocuous Firefox or Safari users. It's an awful situation to be in, if you are maintaining a small website with a complex backend.

For user-facing applications, there are solutions from companies like Cloudflare that will automatically block bots, run them through captchas, lock them in elaborate AI-generated mazes, and so on: https://blog.cloudflare.com/declaring-your-aindependence-block-ai-bots-scrapers-and-crawlers-with-a-single-click/

It's crazy how far this went...

In any case, I think it's best to first examine these logs, so that we can rule out the AI bots being at play here. If it's not them, I will dig deeper, but I'm out of other ideas for the moment.

For the other part about getting stuck loading a nanopub, I've created a separate issue to make this easier to track: #40

[Ostrzyciel]

Oops... I ran the tests on an older version of Registry and Query, not the latest. Apologies, let me re-run this.

[Ostrzyciel]

OK, I re-run the test on the latest-latest versions of Registry and Query, and the findings are the same :) I see no slowdown.

Sorry for the confusion.

[tkuhn]

Thanks for checking and the detailed answer. Crazy indeed...

I will set up the logging as you suggest, and then we'll see...