[bug] Panic in `AccountToAPIAccountPublic` when looking up account from Catodon

[CDN18]

Describe the bug with a clear and concise description of what the bug is.

Catodon is a new fork of firefish/misskey: https://catodon.social/about-catodon However, while gts can interact with misskey instances without problem, it get panicked while federating with catodon.

What's your GoToSocial Version?

v0.13.1

GoToSocial Arch

arm64 Docker

What happened?

Gotosocial can't federate with catodon instances.

What you expected to happen?

Being able to federate with catodon without problem.

How to reproduce it?

1. search for an account on catodon.social
2. see error

Anything else we need to know?

Log:

timestamp="10/01/2024 16:26:41.359" func=server.glob..func1.Logger.func13.1 level=INFO latency="2.67464ms" userAgent=MoshidonAndroid method=GET statusCode=200 path=/api/v2/search clientIP=0.0.0.0 requestID=9p3k5x4c04000y0pzhxg msg="OK: wrote 59B"

timestamp="10/01/2024 16:26:43.482" func=server.glob..func1.Logger.func13.1 level=ERROR stacktrace="()\n\t/usr/local/go/src/runtime/panic.go:261\nruntime.sigpanic()\n\t/usr/local/go/src/runtime/signal_unix.go:861\ntypeutils.(*Converter).AccountToAPIAccountPublic()\n\t/drone/src/internal/typeutils/internaltofrontend.go:218\nsearch.(*Processor).packageAccounts()\n\t/drone/src/internal/processing/search/util.go:79\nsearch.(*Processor).packageSearchResult()\n\t/drone/src/internal/processing/search/util.go:184\nsearch.(*Processor).Get()\n\t/drone/src/internal/processing/search/get.go:199\nsearch.(*Module).SearchGETHandler()\n\t/drone/src/internal/api/client/search/searchget.go:232\n()\n\t/drone/src/vendor/github.com/gin-gonic/gin/context.go:174\ngzip.(*gzipHandler).Handle()\n\t/drone/src/vendor/github.com/gin-contrib/gzip/handler.go:60\n" requestID=k27k5x4c04001xzaafj0 msg="recovered panic: runtime error: invalid memory address or nil pointer dereference"

timestamp="10/01/2024 16:26:43.483" func=server.glob..func1.Logger.func13.1 level=INFO latency="2.7246ms" userAgent=MoshidonAndroid method=GET statusCode=200 path=/api/v2/search clientIP=0.0.0.0 errors="Error #01: recovered panic: runtime error: invalid memory address or nil pointer dereference\n" requestID=k27k5x4c04001xzaafj0 msg="OK: wrote 23B"

[tsmethurst]

Thanks, will take a look soon.

[tsmethurst]

Looked through the logic a bit, following the stack trace in the panic. It looks like the panic is occurring because account.Locked is nil instead of a pointer to either true or false. This doesn't make a lot of sense, because we should always fall back to setting that.

Could you possibly share which account is triggering this issue? I can't replicate it with the account https://catodon.social/users/9ms2ccihepv4shhy (admin of catodon.social); searching for that account works just fine from my GtS instance.

[CDN18]

Certainly. The account I tried to search for is @cdn@catodon.social.

I tried open the url https://catodon.social/users/9ms2ccihepv4shhy and got the same error. I switched the log level to debug but got no more info.

[tsmethurst]

Hmm, I can look up @cdn@catodon.social without any problems as well. Tried it on an instance using sqlite, and one using postgres, and both were OK.

I also looked up the ActivityPub representation of https://catodon.social/users/9ms2ccihepv4shhy and it looks fine, nothing really out of the ordinary. They use a few null fields where omitted fields would probably be better, but we account for that. So I'm not really sure what the issue is, hmm

[tsmethurst]

Just to update on this, someone else saw the same bug (see issue linked above). Try as I might, I couldn't replicate it on the testrig, but I have added a workaround (see PR linked above).

[CDN18]

Thanks for the update! I've updated my instance to b2cacd6b0188f983d1b99f968dfa465a98c9f925 and the behavior has changed a bit:

1. When search for an account (e.g. admin@catodon.social) that was never searched before, The client will throw an error.
2. The second time it will return an empty account, with default avatar and default join date, and the returned account will always be locked.

gotosocial  | timestamp="21/01/2024 10:52:54.649" func=httpclient.(*Client).DoSigned level=INFO method=GET url=https://catodon.social/.well-known/webfinger?resource=acct%3Aadmin%40catodon.social requestID=rzjtcawd04000mk1k9vg pubKeyID=https://<my_gts_url>/users/<my_username>/main-key msg="performing request"
gotosocial  | timestamp="21/01/2024 10:52:54.719" func=httpclient.(*Client).DoSigned level=INFO method=GET url=https://catodon.social/users/9ms2ccihepv4shhy requestID=rzjtcawd04000mk1k9vg pubKeyID=https://<my_gts_url>/users/<my_username>/main-key msg="performing request"
gotosocial  | timestamp="21/01/2024 10:52:54.786" func=server.glob..func1.Logger.func13.1 level=INFO latency="2.87056ms" userAgent="Firefish/23.12-alpha.3 (https://catodon.social)" method=GET statusCode=200 path=/users/cdn/main-key clientIP=128.140.97.170 pubKeyID=https://catodon.social/users/9mse2oi2deom9503#main-key requestID=fzkacawd04000q5a7k0g msg="OK: wrote 560B"
gotosocial  | timestamp="21/01/2024 10:52:54.797" func=server.glob..func1.Logger.func13.1 level=INFO latency="198.10388ms" userAgent="***" method=GET statusCode=200 path=/api/v2/search clientIP=0.0.0.0 requestID=rzjtcawd04000mk1k9vg msg="OK: wrote 59B"
gotosocial  | timestamp="21/01/2024 10:53:16.239" func=typeutils.(*Converter).AccountToAPIAccountPublic.func1 level=WARN requestID=8wxaeawd04001bdy22p0 msg="locked ptr was nil, using default true"
gotosocial  | timestamp="21/01/2024 10:53:16.239" func=typeutils.(*Converter).AccountToAPIAccountPublic.func1 level=WARN requestID=8wxaeawd04001bdy22p0 msg="discoverable ptr was nil, using default false"
gotosocial  | timestamp="21/01/2024 10:53:16.239" func=typeutils.(*Converter).AccountToAPIAccountPublic.func1 level=WARN requestID=8wxaeawd04001bdy22p0 msg="bot ptr was nil, using default false"
gotosocial  | timestamp="21/01/2024 10:53:16.239" func=typeutils.(*Converter).AccountToAPIAccountPublic.func1 level=WARN requestID=8wxaeawd04001bdy22p0 msg="enableRSS ptr was nil, using default false"
gotosocial  | timestamp="21/01/2024 10:53:16.239" func=server.glob..func1.Logger.func13.1 level=INFO latency="7.9246ms" userAgent="***" method=GET statusCode=200 path=/api/v2/search clientIP=0.0.0.0 requestID=8wxaeawd04001bdy22p0 msg="OK: wrote 329B"
gotosocial  | timestamp="21/01/2024 10:53:16.444" func=server.glob..func1.Logger.func13.1 level=INFO latency="7.59208ms" userAgent="***" method=GET statusCode=200 path=/api/v1/accounts/relationships clientIP=0.0.0.0 requestID=2gxteawd04000k90gzag msg="OK: wrote 174B"
gotosocial  | timestamp="21/01/2024 10:53:16.652" func=server.glob..func1.Logger.func13.1 level=INFO latency="4.16376ms" userAgent="***" method=GET statusCode=200 path=/api/v1/accounts/01HMNTDSEE55HT0VEV8659WQ30/statuses clientIP=0.0.0.0 requestID=x0xteawd040015n192c0 msg="OK: wrote 26B"
gotosocial  | timestamp="21/01/2024 10:53:16.658" func=server.glob..func1.Logger.func13.1 level=INFO latency="4.1352ms" userAgent="***" method=GET statusCode=200 path=/api/v1/accounts/01HMNTDSEE55HT0VEV8659WQ30/statuses clientIP=0.0.0.0 requestID=xrxteawd04001b07rc5g msg="OK: wrote 26B"

3. I tried sending a follow request, it get's displayed as pending but the catodon.social account doesn't recieve the follow request (nor the follower state changed on the catodon side), error level log occurs.

gotosocial  | timestamp="21/01/2024 10:24:47.788" func=workers.(*Processor).ProcessFromClientAPI level=INFO activityType=Create objectType=Follow fromAccount=cdn requestID=mmm8tawd040010zd7wy0 msg="processing from client API"
gotosocial  | timestamp="21/01/2024 10:24:47.789" func=server.glob..func1.Logger.func13.1 level=INFO latency="7.98628ms" userAgent="***" method=POST statusCode=200 path=/api/v1/accounts/01HMNRNVREJ7XXH3N6GCYMW745/follow clientIP=*.*.*.* requestID=mmm8tawd040010zd7wy0 msg="OK: wrote 178B"
gotosocial  | timestamp="21/01/2024 10:24:47.789" func=federation.(*federatingActor).Send level=INFO requestID=mmm8tawd040010zd7wy0 msg="send activity Follow via outbox https://<my_gts_url>/users/<my_username>/outbox"
gotosocial  | timestamp="21/01/2024 10:24:47.800" func=workers.(*clientAPI).CreateFollowReq level=ERROR requestID=mmm8tawd040010zd7wy0 msg="error federating follow request: Follow: error sending activity *typefollow.ActivityStreamsFollow via outbox https://<my_gts_url>/users/<my_username>/outbox: func1: error delivering to : invalid http request: empty url host"
gotosocial  | timestamp="21/01/2024 10:24:51.502" func=server.glob..func1.Logger.func13.1 level=INFO latency="3.66168ms" userAgent="***" method=GET statusCode=200 path=/api/v1/accounts/relationships clientIP=*.*.*.* requestID=58vrtawd040001fnnkpg msg="OK: wrote 180B"

[tsmethurst]

Ah thank you, that's very helpful! It looks like you're getting a zero account passed around at some point. Interesting! Thank you for the logs :) Will take another look at this.

[tsmethurst]

If you restart your instance and look up the same account again, does the behavior change? Or is it the same?

[CDN18]

If you restart your instance and look up the same account again, does the behavior change? Or is it the same?

It does not change. I tried looking up the database according to #2527 and found no account in table accounts with domain catodon.social

Below is my query:

SELECT * FROM public.accounts WHERE domain = "catodon.social";

[tsmethurst]

Alright thanks! Could you please try the following:

SELECT * FROM public.accounts WHERE domain IS NULL AND username = "admin";

And let me know if there are any results?

[CDN18]

SELECT * FROM public.accounts WHERE domain IS NULL AND username = "admin";

This query yields no results.

[tsmethurst]

Alright, thank you! One final thing, could you try:

SELECT * FROM public.accounts WHERE domain = "" AND username = "admin";

[CDN18]

SELECT * FROM public.accounts WHERE domain = "" AND username = "admin";

Certainly! This query also yields no result.

[tsmethurst]

Okay, I think we have to get a bit nuts here. Could you do me a favor and set your GTS_LOG_LEVEL to trace, restart your instance, try the query again, and paste all the logs that it generates at the time you do the search? It will generate a whole LOT of database query logs which I should be able to use to help debug this. You can help narrow down the logs by grepping on the request id of the /search response.

[CDN18]

Okay! I've changed the log level, re-searched @admin@catodon.social (by viewing the profile directly) for 2 times and initiated a follow request.

Here's the complete log: https://pastebin.mozilla.org/ce1qqWxU And the db query gets the same result (which is zero row).

[tsmethurst]

Thank you very much!

[tsmethurst]

If you feel like helping me out again, could you kindly do the following:

SELECT * FROM accounts WHERE id = '01HMPADDYNZYGV6AQCVD7S691X';

I believe that's the database ID of the catodon.social user in your database. I'm extremely curious what on earth is actually stored for that account.

[tsmethurst]

(That should be the last piece of the puzzle by the way, whether it turns something up or not. The rest of the fix will be me or kim stepping through the code line by line and seeing where it's going wrong.)

[CDN18]

No problem! I went through the above process again as my instance got restarted because of auto-update.

The log shows that I'm querying 01HMQBAG5HH7WTZZSM3JKBFNFM's statuses, so I changed the ID in the query:

SELECT * FROM accounts WHERE id = '01HMPADDYNZYGV6AQCVD7S691X';

This query also yields no result. Seems that the account was never stored in the database ...?

p.s: Nor did I get any result if I don't change the id.

[tsmethurst]

I did some heavy debugging yesterday, and managed to figure out what's happening in another thread: https://github.com/superseriousbusiness/gotosocial/issues/2527

So my expectation is that this is a similar issue, and that Catodon instance is returning a 4xx code in response to your requests, which GtS doesn't handle gracefully at this point. As with that other issue, I think the fix is to implement better fallback behavior when an instance returns a 4xx code. I'm working on that on a branch now :)

[daenney]

With #2563 merged, I think that resolves this one?

[CDN18]

Partly, after upgrading to e3052e8c825da699162ea25367e860ac3c66f461 the zero account was never returned. Now it returns 403 Forbidden on request of an account:

gotosocial  | timestamp="27/01/2024 13:44:45.932" func=httpclient.(*Client).DoSigned level=INFO method=GET url=https://catodon.social/.well-known/webfinger?resource=acct%3Aadmin%40catodon.social requestID=a5j2mjwd04001h3qe1ng pubKeyID=https://<my_gts_url>/users/<my_gts_username>/main-key msg="performing request"
gotosocial  | timestamp="27/01/2024 13:44:45.994" func=httpclient.(*Client).DoSigned level=INFO method=GET url=https://catodon.social/users/9ms2ccihepv4shhy requestID=a5j2mjwd04001h3qe1ng pubKeyID=https://<my_gts_url>/users/<my_gts_username>/main-key msg="performing request"
gotosocial  | timestamp="27/01/2024 13:44:46.071" func=server.glob..func1.Logger.func13.1 level=INFO latency="3.00056ms" userAgent="Firefish/23.12-alpha.3 (https://catodon.social)" method=GET statusCode=200 path=/users/<my_gts_username>/main-key clientIP=128.140.97.170 pubKeyID=https://catodon.social/users/9mse2oi2deom9503#main-key requestID=yhj2mjwd04000vh987r0 msg="OK: wrote 560B"
gotosocial  | timestamp="27/01/2024 13:44:46.080" func=gtsmodel.(*Account).IsNew level=INFO requestID=a5j2mjwd04001h3qe1ng msg="enrichAccount: error dereferencing https://catodon.social/users/9ms2ccihepv4shhy: Dereference: GET request to https://catodon.social/users/9ms2ccihepv4shhy failed: status=\"403 Forbidden\" body=\"Forbidden\""
gotosocial  | timestamp="27/01/2024 13:44:46.080" func=server.glob..func1.Logger.func13.1 level=INFO latency="175.2886ms" userAgent="***" method=GET statusCode=200 path=/api/v2/search clientIP=*.*.*.* requestID=a5j2mjwd04001h3qe1ng msg="OK: wrote 59B"

Maybe my instance was blocked on their side...? I have never interacted with any catodon account before...

[tsmethurst]

Mm, well I'm relieved it's the same bug as the honk federation issue. With the fix in place it looks like things are working as intended, you're now getting the failed call logged and getting a 200 back from the search with no results, which is fine. Aside from that there's nothing we can do if they're returning 403, so I will close this.

[CDN18]

Understand, thanks very much for your diligent work in resolving this anyway 😆 Should I come across a solution finally, I'll be sure to give an update here for future reference.

Update: Try to search from the Catodon side for any account of gts side first. Then they can federate like a charm!

[tsmethurst]

You're welcome! ❤️