Open Ultimator14 opened 1 year ago
What version are you running? I suspect this was already fixed as part of https://github.com/jointakahe/takahe/pull/634, it's just not in a release yet.
I'm on main. The build is from yesterday
The error does not occur when I reduce gunicorn workers to 1 (GUNICORN_EXTRA_CMD_ARGS: "--reload -w 1"
).
But posts and follows are still not displayed. That is probably another issue.
OK - I'll see if I can investigate it soon then. It might be a few weeks. Looks like some sort of error in the new fetching code, maybe - have you tried the current stable release to see if it still breaks there?
No I haven't and unfortunately I can't downgrade due to database issues. I'll try to check this with a test instance.
Ah right, we've had migrations on main since the release (which is incidentally why I have not done a patch release yet). Let me know what you find - if this is caused by our fix for the other error breaking search, it would be good to know.
But posts and follows are still not displayed. That is probably another issue.
I did some research and at least for mastodon, only follows of the local instance are shown in the mobile app. And for posts, only future posts are downloaded to the local instance and counted. That means if I search for a new user once, the user is known to my server from that point in time. If I check the users profile via the mobile app, it shows me 0 follows and 0 posts (except there are pinned posts, which will be backfilled). If the user posts something from now on, it appears on the profile and the post numbers goes up by one. If I follow, the follow number goes up by one. To get the actual number of posts and followers, I have to check the web page of the remote profile.
It looks like this is desired behavior.
if this is caused by our fix for the other error breaking search, it would be good to know.
The same error also occurs on 0.9.0. Error log for version 0.9.0 below.
takahe-web | Internal Server Error: /api/v2/search
takahe-web | Traceback (most recent call last):
takahe-web | File "/takahe/activities/services/search.py", line 38, in search_identities_handle
takahe-web | raise Identity.DoesNotExist()
takahe-web | users.models.identity.Identity.DoesNotExist
takahe-web |
takahe-web | During handling of the above exception, another exception occurred:
takahe-web |
takahe-web | Traceback (most recent call last):
takahe-web | File "/usr/local/lib/python3.11/site-packages/asgiref/sync.py", line 349, in main_wrap
takahe-web | raise exc_info[1]
takahe-web | File "/takahe/users/models/identity.py", line 362, in by_username_and_domain
takahe-web | return cls.objects.get(
takahe-web | ^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/manager.py", line 87, in manager_method
takahe-web | return getattr(self.get_queryset(), name)(*args, **kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", line 637, in get
takahe-web | raise self.model.DoesNotExist(
takahe-web | users.models.identity.Identity.DoesNotExist: Identity matching query does not exist.
takahe-web |
takahe-web | During handling of the above exception, another exception occurred:
takahe-web |
takahe-web | Traceback (most recent call last):
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
takahe-web | return self.cursor.execute(sql, params)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/psycopg/cursor.py", line 737, in execute
takahe-web | raise ex.with_traceback(None)
takahe-web | psycopg.errors.UniqueViolation: duplicate key value violates unique constraint "users_identity_actor_uri_key"
takahe-web | DETAIL: Key (actor_uri)=(https://jointakahe.takahe.social/@takahe@jointakahe.org/) already exists.
takahe-web | The above exception was the direct cause of the following exception:
takahe-web |
takahe-web | Traceback (most recent call last):
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/core/handlers/exception.py", line 55, in inner
takahe-web | response = get_response(request)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/core/handlers/base.py", line 197, in _get_response
takahe-web | response = wrapped_callback(request, *callback_args, **callback_kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/takahe/api/decorators.py", line 46, in inner
takahe-web | return function(request, *args, **kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/hatchway/view.py", line 302, in __call__
takahe-web | response = self.view(request, **kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/takahe/api/views/search.py", line 35, in search
takahe-web | search_result = searcher.search_all()
takahe-web | ^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/takahe/activities/services/search.py", line 139, in search_all
takahe-web | "identities": self.search_identities_handle(),
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/takahe/activities/services/search.py", line 48, in search_identities_handle
takahe-web | identity = Identity.by_username_and_domain(
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/takahe/users/models/identity.py", line 382, in by_username_and_domain
takahe-web | return cls.objects.create(
takahe-web | ^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/manager.py", line 87, in manager_method
takahe-web | return getattr(self.get_queryset(), name)(*args, **kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", line 658, in create
takahe-web | obj.save(force_insert=True, using=self.db)
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/base.py", line 814, in save
takahe-web | self.save_base(
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/base.py", line 877, in save_base
takahe-web | updated = self._save_table(
takahe-web | ^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/base.py", line 1020, in _save_table
takahe-web | results = self._do_insert(
takahe-web | ^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/base.py", line 1061, in _do_insert
takahe-web | return manager._insert(
takahe-web | ^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/manager.py", line 87, in manager_method
takahe-web | return getattr(self.get_queryset(), name)(*args, **kwargs)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/query.py", line 1805, in _insert
takahe-web | return query.get_compiler(using=using).execute_sql(returning_fields)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/models/sql/compiler.py", line 1822, in execute_sql
takahe-web | cursor.execute(sql, params)
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 102, in execute
takahe-web | return super().execute(sql, params)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 67, in execute
takahe-web | return self._execute_with_wrappers(
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 80, in _execute_with_wrappers
takahe-web | return executor(sql, params, many, context)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 84, in _execute
takahe-web | with self.db.wrap_database_errors:
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/utils.py", line 91, in __exit__
takahe-web | raise dj_exc_value.with_traceback(traceback) from exc_value
takahe-web | File "/usr/local/lib/python3.11/site-packages/django/db/backends/utils.py", line 89, in _execute
takahe-web | return self.cursor.execute(sql, params)
takahe-web | ^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^^
takahe-web | File "/usr/local/lib/python3.11/site-packages/psycopg/cursor.py", line 737, in execute
takahe-web | raise ex.with_traceback(None)
takahe-web | django.db.utils.IntegrityError: duplicate key value violates unique constraint "users_identity_actor_uri_key"
takahe-web | DETAIL: Key (actor_uri)=(https://jointakahe.takahe.social/@takahe@jointakahe.org/) already exists.
Thanks, appreciate you checking! I can't easily replicate it on my own server, but the traceback you provided should hopefully be enough to put a potential fix in place anyway.
Hmm, taking at a look at the source code, we already have something in place to stop this happening - it's meant to check if the user exists right before it makes it.
Are you able to go into the Django Admin for me and get a screenshot of what the https://jointakahe.takahe.social/@takahe@jointakahe.org/
/ @takahe@jointakahe.org
identity looks like, if it even exists? I suspect something about the record is corrupted but I don't know how.
Are you able to go into the Django Admin for me and get a screenshot of what the
https://jointakahe.takahe.social/@takahe@jointakahe.org/
/@takahe@jointakahe.org
identity looks like, if it even exists? I suspect something about the record is corrupted but I don't know how.
Like this?
Without looking at the code I assume this is a concurrency issue because it only occurs the first time a search for a user. I guess there are two processes that check for the existence of the db entry, both get the result that it doesn't exist and both try to create it. The creation fails the second time because the first one already created it. The issue also doesn't occur with only one worker.
Ah, I missed that it only happens on the first search for a user, sorry - you're probably right. The search endpoint should only be called once, but my guess is that the client you're using calls it twice for some reason.
OK, the commit I just landed above should fix it - I made that whole process happen in a transaction. Let me know if it doesn't and we can reopen.
Ah nvm the error still occurs. Same as before :/
I did some testing and added a few print statements to see whats wrong.
And I got the following output (random number per process, time, message), sorted by time:
244 16.09.2023 09:38:36.219160 Entering transaction atomic
244 16.09.2023 09:38:36.219348 else-before-return
61503 16.09.2023 09:38:36.227405 Entering transaction atomic
61503 16.09.2023 09:38:36.227565 else-before-return
61503 16.09.2023 09:38:36.682489 try-before-return
61503 16.09.2023 09:38:36.687559 domain-before-return
244 16.09.2023 09:38:36.704224 try-before-return
So there are two processes that run concurrently. But even with atomic transaction, the second process starts executing the code before the first one is finished.
Maybe also relevant: I see no error in the docker log, it's only sent via mail due to the TAKAHE_ERROR_EMAILS
setting.
Atomic transactions don't guarantee that the code isn't run concurrently, just that the view of the database should be linear - though that's obviously not quite what's happening here.
I have some other ideas about how to fix this, so I'll try one of those in the next commit.
Did that next commit happen?
I'm using Tusky as client app for my own takahe server. In the takahe configuration I enabled
ERROR_EMAILS
. Whenever I search for a (remote) handle the first time e.g.@takahe@jointakahe.org
using the Tusky search, I get two mails informing me about a server error.(full message see below)
This happens independently of the remote server software. I noticed this for mastodon, takahe, kbin and also some others. This only happens if the user is unknown to the server, so the very first time I do the search. Afterwards, the error does no longer occur but only the pinned posts are shown in the Tusky app and follows are also not displayed correctly (see screenshot).
Log in error mail (The log leaks some usernames and passwords, I redacted them manually):
Screenshot from the Tusky app: