toddsundsted / ktistec

Single user ActivityPub (https://www.w3.org/TR/activitypub/) server.
GNU Affero General Public License v3.0
366 stars 20 forks source link

The ktistec instance has slowed down considerably. #99

Closed vrthra closed 5 months ago

vrthra commented 6 months ago

I was running the version of the server v2.0.0-10, and I found somewhat suddenly that the server is taking too long to reply. After a restart, I found that the server has stopped serving any content, timing out on any request.

I tried to update to the latest github main, but it seems that it errors out, and ktistec does not come up any longer. Any idea? (I have my db backed up, so no information is lost).

SQLite3 version 3.37.2
add-down-at-to-actors: applied in 0.0069s
add-index-on-iri-to-accounts: applied in 0.0044s
migrate-notifications: applied in 0.1709s
create-last-times: applied in 0.0089s
migrate-account-state: applied in 0.0086s
rename-column-on-objects: applied in 0.0072s
add-index-on-subject-iri-to-tasks: applied in 0.5212s
fix-indexes-on-relationships: applied in 71.1283s
remove-index-on-created-at-from-tasks: applied in 0.8132s
delete-old-notifications: applied in 12.0772s
Unhandled exception in spawn: Channel is closed (Channel::ClosedError)
  from /data/crystal-1.10.1-1/share/crystal/src/channel.cr:228:8 in 'send'
  from /data/crystal-1.10.1-1/share/crystal/src/log/dispatch.cr:55:7 in 'dispatch'
  from /data/crystal-1.10.1-1/share/crystal/src/log/backend.cr:24:5 in 'dispatch'
  from /data/crystal-1.10.1-1/share/crystal/src/log/log.cr:36:3 in 'exec'
  from /data/ktistec/src/workers/task_worker.cr:84:5 in 'destroy_old_tasks'
  from /data/ktistec/src/ktistec/server.cr:11:5 in '->'
  from /data/crystal-1.10.1-1/share/crystal/src/fiber.cr:146:11 in 'run'
  from /data/crystal-1.10.1-1/share/crystal/src/fiber.cr:98:34 in '->'
  from ???
Unhandled exception: undefined constant: Notification (Ktistec::Compiler::LinkError)
  from /data/ktistec/src/utils/compiler.cr:171:5 in 'instantiate'
  from /data/ktistec/src/utils/compiler.cr:35:27 in 'compile'
  from /data/ktistec/src/rules/content_rules.cr:101:3 in 'domain'
  from /data/ktistec/src/framework/framework.cr:155:7 in '__crystal_main'
  from /data/crystal-1.10.1-1/share/crystal/src/crystal/main.cr:129:5 in 'main_user_code'
  from /data/crystal-1.10.1-1/share/crystal/src/crystal/main.cr:115:7 in 'main'
  from /data/crystal-1.10.1-1/share/crystal/src/crystal/main.cr:141:3 in 'main'
  from /lib/x86_64-linux-gnu/libc.so.6 in '??'
  from /lib/x86_64-linux-gnu/libc.so.6 in '__libc_start_main'
  from ./server in '_start'
  from ???
$

This is what it shows when I restart the server, using the backed up db and older version of the server

[development] Ktistec is ready to lead at http://0.0.0.0:3000
2024-05-05 06:03:29 UTC 409 POST /actors/rahul/inbox 46.97ms
2024-05-05T06:03:31.735583Z   INFO - verification failed: invalid signature: signed by keyId=https://mastodon.social/users/regehr#main-key
2024-05-05 06:03:32 UTC 200 POST /actors/rahul/inbox 539.5ms
2024-05-05 06:03:46 UTC 400 POST /actors/rahul/inbox 473.55ms
2024-05-05 06:03:47 UTC 409 POST /actors/rahul/inbox 17.63ms
2024-05-05 06:03:47 UTC 409 POST /actors/rahul/inbox 9.86ms
2024-05-05 06:03:58 UTC 302 GET / 1.31ms
2024-05-05 06:03:59 UTC 200 GET /actors/rahul 528.63ms
2024-05-05T06:03:59.122929Z   WARN - Slow query [   399.036ms] -- SELECT "a"."id","a"."created_at","a"."updated_at","a"."type","a"."undone_at","a"."iri","a"."visible","a"."published","a"."actor_iri","a"."object_iri","a"."target_iri","a"."to","a"."cc","a"."summary" FROM activities AS a JOIN actors AS act ON act.iri = a.actor_iri JOIN objects AS obj ON obj.iri = a.object_iri WHERE a.actor_iri = ? AND a.object_iri = ? AND a.type = "ActivityPub::Activity::Announce"  AND act.deleted_at is NULL AND act.blocked_at is NULL AND obj.deleted_at is NULL AND obj.blocked_at is NULL AND a.undone_at IS NULL -- args: ["https://gopinath.org/actors/rahul", "https://zirk.us/users/TheVulgarTongue/statuses/112386225361998299"]
2024-05-05 06:03:59 UTC 304 GET /3rd/semantic-2.4.1.min.css 816.05µs
2024-05-05 06:03:59 UTC 304 GET /dist/site.bundle.js 611.07µs
2024-05-05 06:03:59 UTC 409 POST /actors/rahul/inbox 9.64ms
2024-05-05 06:04:00 UTC 304 GET /favicon-16x16.png 863.04µs
2024-05-05 06:04:04 UTC 409 POST /actors/rahul/inbox 8.98ms
2024-05-05 06:05:11 UTC 200 GET /remote/objects/387093/thread 64513.62ms
2024-05-05T06:05:11.576222Z   WARN - Slow query [ 64476.514ms] -- SELECT count(a.id) FROM activities AS a JOIN relationships AS r ON r.to_iri = a.iri JOIN actors AS act ON act.iri = a.actor_iri JOIN objects AS obj ON obj.iri = a.object_iri WHERE r.from_iri = ? AND obj.iri = ? AND r.type = "Relationship::Content::Inbox" AND r.confirmed = 1   AND act.deleted_at is NULL AND act.blocked_at is NULL AND obj.deleted_at is NULL AND obj.blocked_at is NULL AND a.undone_at IS NULL -- args: ["https://gopinath.org/actors/rahul", "https://autistics.life/users/zaxxon/statuses/112371176515432824"]

Checking for what you asked for in here

SQLite version 3.37.2 2022-01-06 13:25:41
Enter ".help" for usage hints.
sqlite> select count(*) from accounts;
1
sqlite> select count(*) from collections ;
0
sqlite> select count(*) from migrations ;
34
sqlite> select count(*) from points ;
45523
sqlite> select count(*) from tag_statistics ;
48540
sqlite> select count(*) from activities ;
675361
sqlite> select count(*) from filter_terms ;
0
sqlite> select count(*) from objects;
388656
sqlite> select count(*) from relationships ;
607625
sqlite> select count(*) from tags;
533238
sqlite> select count(*) from actors;
219229
sqlite> select count(*) from last_times ;
Error: in prepare, no such table: last_times (1)
sqlite> select count(*) from options ;
4
sqlite> select count(*) from sessions;
4440
sqlite> select count(*) from tasks;
32562
sqlite> 

(I see that the SQLite version is not a blacklisted one.)

toddsundsted commented 6 months ago

undefined constant: Notification (Ktistec::Compiler::LinkError)

it looks like etc/rules/content.rules is the wrong one for v2.0.0-10. Notification as a rule type, no longer exists.

content.rules is loaded at runtime. you will want to make sure all of the files in etc/ are correct for the version of the server you are running (and are upgraded along with your server).

what does your build process do? i'll document what has to remain/change when upgrading.

vrthra commented 6 months ago

Ahh, that was the issue. I had compiled the server binary and copied it over to the old installation. I did not think about changes in the etc. Apologies for the confusion.