Outgoing DNS requests from Mastodon fail, but work fine from Mastodon pods

[magsol]

Steps to reproduce the problem

Make any kind of external DNS request through Mastodon--either through the iOS app, the web application, or tootctl. The most egregious example I can find is to run tootctl domains crawl.

Expected behaviour

The 1491 domains my own instance has connected with should be crawled.

Actual behaviour

All 1491 are listed as having failed.

Other symptomatic behavior:

• in iOS app or web platform, attached media on toots are listed as "Not Available"
• cascading "Dead" jobs in Sidekiq UI
• oddly, running wget from the mastodon-web or mastodon-sidekiq pod's command line works just fine

Detailed description

I've been running my own instance for the past month and it's been working fine, up until one of the 5 nodes in the kubernetes cluster died. Since then (and even since rebooting the node), my instance has been unable to load attached media from other users, and sidekiq logs show a huge crush of ActivityPub::ProcessingWorker and RedownloadMediaWorker errors in the logs, all some version of (for example)

HTTP::ConnectionError: failed to connect: No address for mstdn.social on https://mstdn.social/users/joshgammon#main-key

or

HTTP::ConnectionError: failed to connect: No address for storage.googleapis.com on https://storage.googleapis.com/hci-social-storage/media_attachments/files/109/518/502/735/903/135/original/4371fe6bdb5...

or

HTTP::ConnectionError: failed to connect: No address for cdn.masto.host on https://cdn.masto.host/genomicsocial/media_attachments/files/109/518/387/703/532/618/original/893502d01e02b331.png

Point being: it's not specific to the other instances, but rather a symptom of something wrong on mine. I even ran tootctl domains crawl on the mastodon-web pod, and got this:

> tootctl domains crawl
1491/?? | ----- | ETA: ??:??:??
Visited 1491 domains, 1491 failed (20s elapsed)
Total servers: 0
Total registered: 0
Total active last week: 0
Total joined last week: 0

The system folder mount is empty, as my instance is unable to load any external media, due to its inability to resolve any external URLs.

I modified the coredns ConfigMap to include logging, and what I see from running tootctl domains crawl looks something like this:

[INFO] 10.42.4.54:41815 - 15743 "A IN postgres-postgresql.mastodon.svc.cluster.local.mastodon.svc.cluster.local. udp 91 false 512" NXDOMAIN qr,aa,rd 184 0.000899857s
[INFO] 10.42.4.54:41815 - 25679 "AAAA IN postgres-postgresql.mastodon.svc.cluster.local.mastodon.svc.cluster.local. udp 91 false 512" NXDOMAIN qr,aa,rd 184 0.001215796s
[INFO] 10.42.4.54:34881 - 23008 "AAAA IN postgres-postgresql.mastodon.svc.cluster.local.svc.cluster.local. udp 82 false 512" NXDOMAIN qr,aa,rd 175 0.000927615s
[INFO] 10.42.4.54:34881 - 19691 "A IN postgres-postgresql.mastodon.svc.cluster.local.svc.cluster.local. udp 82 false 512" NXDOMAIN qr,aa,rd 175 0.001279166s
[INFO] 10.42.4.54:34443 - 18651 "A IN postgres-postgresql.mastodon.svc.cluster.local.cluster.local. udp 78 false 512" NXDOMAIN qr,aa,rd 171 0.000958986s
[INFO] 10.42.4.54:34443 - 24017 "AAAA IN postgres-postgresql.mastodon.svc.cluster.local.cluster.local. udp 78 false 512" NXDOMAIN qr,aa,rd 171 0.001321184s
[INFO] 10.42.4.54:49648 - 44863 "AAAA IN postgres-postgresql.mastodon.svc.cluster.local.capybara-dragon.ts.net. udp 87 false 512" NOERROR qr,rd,ra 163 0.025753144s
[INFO] 10.42.4.54:49648 - 14646 "A IN postgres-postgresql.mastodon.svc.cluster.local.capybara-dragon.ts.net. udp 87 false 512" NOERROR qr,rd,ra 163 0.026018585s
[INFO] 10.42.4.54:34292 - 18936 "AAAA IN postgres-postgresql.mastodon.svc.cluster.local. udp 64 false 512" NOERROR qr,aa,rd 157 0.000602028s
[INFO] 10.42.4.54:34292 - 33742 "A IN postgres-postgresql.mastodon.svc.cluster.local. udp 64 false 512" NOERROR qr,aa,rd 126 0.000845506s
[INFO] 10.42.4.54:53217 - 21259 "A IN spore.social.mastodon.svc.cluster.local. udp 57 false 512" NXDOMAIN qr,aa,rd 150 0.000843562s
[INFO] 10.42.4.54:53217 - 22436 "A IN spore.social.svc.cluster.local. udp 48 false 512" NXDOMAIN qr,aa,rd 141 0.000785544s
[INFO] 10.42.4.54:53217 - 59641 "A IN spore.social.cluster.local. udp 44 false 512" NXDOMAIN qr,aa,rd 137 0.000655472s
[INFO] 10.42.4.54:53217 - 40900 "A IN spore.social.capybara-dragon.ts.net. udp 53 false 512" NOERROR qr,rd,ra 129 0.025045155s
[INFO] 10.42.4.54:1985 - 55029 "A IN storage.googleapis.com.mastodon.svc.cluster.local. udp 67 false 512" NXDOMAIN qr,aa,rd 160 0.000553918s
[INFO] 10.42.4.54:1985 - 11502 "A IN storage.googleapis.com.svc.cluster.local. udp 58 false 512" NXDOMAIN qr,aa,rd 151 0.000552325s
[INFO] 10.42.4.54:1985 - 2564 "A IN storage.googleapis.com.cluster.local. udp 54 false 512" NXDOMAIN qr,aa,rd 147 0.000454993s
[INFO] 10.42.4.54:1985 - 57659 "A IN storage.googleapis.com.capybara-dragon.ts.net. udp 63 false 512" NOERROR qr,rd,ra 139 0.025018711s
...

(many, many more entries follow, all looking qualitatively the same as above)

It seems like the URLs it's hitting are... odd. The first few in particular that have to do with the local postgres database are especially odd, where the domain suffix is repeated. For reference, its actual FQDN looks like this: postgres-postgresql.mastodon.svc.cluster.local, which does finally seem to show up about 9-10 lines down.

On the mastodon-sidekiq pod, the /etc/resolv.conf looks like this:

search mastodon.svc.cluster.local svc.cluster.local cluster.local capybara-dragon.ts.net
nameserver 10.43.0.10
options ndots:5

So Mastodon doesn't seem able to resolve anything, BUT I can run basic curl/wget commands from within the Mastodon pods and... they work just fine. I picked an instance at random from that list of 1491, ran wget -O- https://tootsweet.social/api/v1/instance on the same pod, and got back the correct response:

wget -O - https://tootsweet.social/api/v1/instance
--2022-12-15 16:06:11--  https://tootsweet.social/api/v1/instance
Resolving tootsweet.social (tootsweet.social)... 167.99.188.53
Connecting to tootsweet.social (tootsweet.social)|167.99.188.53|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [application/json]
Saving to: 'STDOUT'

-                                           [<=>                                                                            ]       0  --.-KB/s               {"uri":"tootsweet.social","title":"Mastodon","short_description":"","description":"","email":"helper@deliciousfluiddynamics.com","version":"4.0.2","urls":{"streaming_api":"wss://tootsweet.social"},"stats":{"user_count":2,"status_count":919,"domain_count":4094},"thumbnail":"https://tootsweet.social/packs/media/images/preview-6399aebd96ccf025654e2977454f168f.png","languages":["en"],"registrations":false,"approval_required":false,"invites_enabled":false,"configuration":{"accounts":{"max_featured_tags":10},"statuses":{"max_characters":500,"max_media_attachments":4,"characters_reserved_per_url":23},"media_attachments":{"supported_mime_types":["image/jpeg","image/png","image/gif","image/heic","image/heif","image/webp","image/avif","video/webm","video/mp4","video/quicktime","video/ogg","audio/wave","audio/wav","audio/x-wav","audio/x-pn-wave","audio/vnd.wave","audio/ogg","audio/vorbis","audio/mpeg","audio/mp3","audio/webm","audio/flac","audio/aac","audio/m4a","audio/x-m4a","audio/mp4","audio/3gpp","video/x-ms-asf"],"image_size_limit":10485760,"image_matrix_limit":16777216,"video_size_limit":41943040,"video_frame_rate_limit":60,"video_matrix_limit":2304000},"polls":{"max_options":4,"max_characters_per_option":50,"min_expiration":300,"max_expiration":2629746}},"contact_account":{"id":"27","username":"devlon","acct":"devlon","display_name":"Devlon","locked":false,"bot":false,"discoverable":true,"group":false,"created_at":"2022-11-09T00:00:00.000Z","note":"\u003cp\u003eTechnologist, sometimes photographer, and rabid (no really... it\u0026#39;s a problem) coffee lover. There will be daily latte art posts. Sorry not sorry.\u003c/p\u003e","url":"https://tootsweet.social/@devlon","avatar":"https://tootsweet-social.s3.amazonaws.com/accounts/avatars/000/000/027/original/2ec908ba1dbf6f87.jpeg","avatar_static":"https://tootsweet-social.s3.amazonaws.com/accounts/avatars/000/000/027/original/2ec908ba1dbf6f87.jpeg","header":"https://tootsweet-social.s3.amazonaws.com/accounts/headers/000/000/027/original/52a3a1aa1abf2dc5.png","header_static":"https://tootsweet-social.s3.amazonaws.com/accounts/headers/000/000/027/original/52a3a1aa1abf2dc5.png","followers_count":24,"following_count":54,"statuses_count":121,"last_status_at":"2022-12-14","noindex":false,"emojis":[],"fields":[{"name":"Pronouns","value":"he/him","verified_at":null},{"name":"Location","value":"🇨🇦","verified_at":null},{"name":"GitHub","value":"\u003ca href=\"https://github.com/duthied\" target=\"_blank\" rel=\"nofollow noopener noreferrer me\"\u003e\u003cspan class=\"invisible\"\u003ehttps://\u003c/span\u003e\u003cspan class=\"\"\u003egithub.com/duthied\u003c/span\u003e\u003cspan class=\"invisible\"\u003e\u003c/span\u003-                                           [ <=>                                                                           ]   2.70K  --.-KB/s    in 0s      

2022-12-15 16:06:12 (18.7 MB/s) - written to stdout [2760]

Here's what coredns sees when I run that command:

[INFO] 10.42.4.54:56518 - 18772 "A IN tootsweet.social.mastodon.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.001055151s
[INFO] 10.42.4.54:56518 - 50253 "AAAA IN tootsweet.social.mastodon.svc.cluster.local. udp 61 false 512" NXDOMAIN qr,aa,rd 154 0.00141685s
[INFO] 10.42.4.54:46823 - 62641 "AAAA IN tootsweet.social.svc.cluster.local. udp 52 false 512" NXDOMAIN qr,aa,rd 145 0.00111178s
[INFO] 10.42.4.54:46823 - 62391 "A IN tootsweet.social.svc.cluster.local. udp 52 false 512" NXDOMAIN qr,aa,rd 145 0.001530885s
[INFO] 10.42.4.54:47867 - 12879 "AAAA IN tootsweet.social.cluster.local. udp 48 false 512" NXDOMAIN qr,aa,rd 141 0.000826969s
[INFO] 10.42.4.54:47867 - 52547 "A IN tootsweet.social.cluster.local. udp 48 false 512" NXDOMAIN qr,aa,rd 141 0.001275s
[INFO] 10.42.4.54:40987 - 55897 "AAAA IN tootsweet.social.capybara-dragon.ts.net. udp 57 false 512" NOERROR qr,rd,ra 133 0.025944494s
[INFO] 10.42.4.54:40987 - 45092 "A IN tootsweet.social.capybara-dragon.ts.net. udp 57 false 512" NOERROR qr,rd,ra 133 0.026364358s
[INFO] 10.42.4.54:56727 - 38692 "AAAA IN tootsweet.social. udp 34 false 512" NOERROR qr,rd,ra 123 0.124643249s
[INFO] 10.42.4.54:56727 - 13398 "A IN tootsweet.social. udp 34 false 512" NOERROR qr,rd,ra 66 0.750268088s

which, given the final entry, suggests it eventually figures out the correct FQDN. Basically, it seems like: the problem ABSOLUTELY is an inability to resolve anything outside of my instance, despite the pods themselves appearing to be able to access things just fine.

Specifications

Mastodon 4.0.2 (via helm)
Postgres 15.0 / Redis 7.0 / OpenSearch (each installed separately)
5x Raspberry Pi running Ubuntu 22.04 and k3s
Traefik as ingress proxy, metallb as LoadBalancer

[magsol]

Significantly updated the ticket with more details around what coredns is seeing, and information around the iterations of FQDNs that coredns is making as it attempts to resolve outgoing requests.

[magsol]

This is about as much as I could boil it down to try and illustrate what's going on:

1. run tootctl domains crawl mastodon.social on the mastodon-sidekiq pod's command line

> tootctl domains crawl mastodon.social
1/?? |-=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---=---|  ETA: ??:??:??
Visited 1 domains, 1 failed (20s elapsed)

Here's what coredns saw:

[INFO] 10.42.4.54:18022 - 62567 "A IN mastodon.social.mastodon.svc.cluster.local. udp 60 false 512" NXDOMAIN qr,aa,rd 153 0.000743195s
[INFO] 10.42.4.54:18022 - 57434 "A IN mastodon.social.svc.cluster.local. udp 51 false 512" NXDOMAIN qr,aa,rd 144 0.000692677s
[INFO] 10.42.4.54:18022 - 13287 "A IN mastodon.social.cluster.local. udp 47 false 512" NXDOMAIN qr,aa,rd 140 0.000629197s
[INFO] 10.42.4.54:18022 - 16425 "A IN mastodon.social.capybara-dragon.ts.net. udp 56 false 512" NOERROR qr,rd,ra 132 0.025352936s

2. run wget -O- https://mastodon.social/api/v1/instance on the mastodon-sidekiq pod's command line

> wget -O- https://mastodon.social/api/v1/instance
--2022-12-15 22:34:48--  https://mastodon.social/api/v1/instance
Resolving mastodon.social (mastodon.social)... 136.243.102.156
Connecting to mastodon.social (mastodon.social)|136.243.102.156|:443... connected.
HTTP request sent, awaiting response... 200 OK
Length: unspecified [application/json]
Saving to: 'STDOUT'

-                                       [<=>                                                                ]       0  --.-KB/s               {"uri":"mastodon.social","title":"Mastodon","short_description":"The original server operated by the Mastodon gGmbH non-profit","description":"","email":"staff@mastodon.social","version":"4.0.2","urls":{"streaming_api":"wss://mastodon.social"},"stats":{"user_count":909990,"status_count":45303933,"domain_count":44979},"thumbnail":"https://files.mastodon.social/site_uploads/files/000/000/001/@1x/57c12f441d083cde.png","languages":["en"],"registrations":true,"approval_required":false,"invites_enabled":true,"configuration":{"accounts":{"max_featured_tags":10},"statuses":{"max_characters":500,"max_media_attachments":4,"characters_reserved_per_url":23},"media_attachments":{"supported_mime_types":["image/jpeg","image/png","image/gif","image/heic","image/heif","image/webp","image/avif","video/webm","video/mp4","video/quicktime","video/ogg","audio/wave","audio/wav","audio/x-wav","audio/x-pn-wave","audio/vnd.wave","audio/ogg","audio/vorbis","audio/mpeg","audio/mp3","audio/webm","audio/flac","audio/aac","audio/m4a","audio/x-m4a","audio/mp4","audio/3gpp","video/x-ms-asf"],"image_size_limit":10485760,"image_matrix_limit":16777216,"video_size_limit":41943040,"video_frame_rate_limit":60,"video_matrix_limit":2304000},"polls":{"max_options":4,"max_characters_per_option":50,"min_expiration":300,"max_expiration":2629746}},"contact_account":{"id":"1","username":"Gargron","acct":"Gargron","display_name":"Eugen Rochko","locked":false,"bot":false,"discoverable":true,"group":false,"created_at":"2016-03-16T00:00:00.000Z","note":"\u003cp\u003eFounder, CEO and lead developer \u003cspan class=\"h-card\"\u003e\u003ca href=\"https://mastodon.social/@Mastodon\" class=\"u-url mention\"\u003e@\u003cspan\u003eMastodon\u003c/span\u003e\u003c/a\u003e\u003c/span\u003e, Germany.\u003c/p\u003e","url":"https://mastodon.social/@Gargron","avatar":"https://files.mastodon.social/accounts/avatars/000/000/001/original/dc4286ceb8fab734.jpg","avatar_static":"https://files.mastodon.social/accounts/avatars/000/000/001/original/dc4286ceb8fab734.jpg","header":"https://files.mastodon.social/accounts/headers/000/000/001/original/3b91c9965d00888b.jpeg","header_static":"https://files.mastodon.social/accounts/headers/000/000/001/original/3b91c9965d00888b.jpeg","followers_count":268369,"following_count":329,"statuses_count":72894,"last_status_at":"2022-12-15","noindex":false,"emojis":[],"fields":[{"name":"Patreon","value":"\u003ca href=\"https://www.patreon.com/mastodon\" target=\"_blank\" rel=\"nofollow noopener noreferrer me\"\u003e\u003cspan class=\"invisible\"\u003ehttps://www.\u003c/span\u003e\u003cspan class=\"\"\u003epatreon.com/mastodon\u003c/span\u003e\u003cspan class=\"invisible\"\u003e\u003c/span\u003e\u003c/a\u003e","verified_at":null}]},"rules":[{"id":"1","text":"Sexually explicit or violent media must be marked as sensitive when posting"},{"id":"2","text":"No racism, sexism, homophobia, transphobia, xenophobia, or casteism"},{"id":"3","text":"No incitement of violence or promotion of violent ideologies"},{"id":"4","text":"No harassment, dogpiling or doxxing of other users"},{"id":"5","text":"No content illegal in Germany"},{"id":"7","-                                       [ <=>                                                               ]   3.14K  --.-KB/s    in 0s      

2022-12-15 22:34:49 (21.6 MB/s) - written to stdout [3216]

And, again, what coredns saw:

[INFO] 10.42.4.54:60019 - 28984 "A IN mastodon.social.mastodon.svc.cluster.local. udp 60 false 512" NXDOMAIN qr,aa,rd 153 0.000872194s
[INFO] 10.42.4.54:60019 - 46898 "AAAA IN mastodon.social.mastodon.svc.cluster.local. udp 60 false 512" NXDOMAIN qr,aa,rd 153 0.001167561s
[INFO] 10.42.4.54:54590 - 29067 "A IN mastodon.social.svc.cluster.local. udp 51 false 512" NXDOMAIN qr,aa,rd 144 0.000800842s
[INFO] 10.42.4.54:54590 - 8337 "AAAA IN mastodon.social.svc.cluster.local. udp 51 false 512" NXDOMAIN qr,aa,rd 144 0.00112795s
[INFO] 10.42.4.54:52212 - 50000 "AAAA IN mastodon.social.cluster.local. udp 47 false 512" NXDOMAIN qr,aa,rd 140 0.000774769s
[INFO] 10.42.4.54:52212 - 27724 "A IN mastodon.social.cluster.local. udp 47 false 512" NXDOMAIN qr,aa,rd 140 0.001158098s
[INFO] 10.42.4.54:53357 - 55835 "AAAA IN mastodon.social.capybara-dragon.ts.net. udp 56 false 512" NOERROR qr,aa,rd,ra 132 0.000494661s
[INFO] 10.42.4.54:53357 - 23063 "A IN mastodon.social.capybara-dragon.ts.net. udp 56 false 512" NOERROR qr,aa,rd,ra 132 0.000873268s
[INFO] 10.42.4.54:33878 - 60951 "AAAA IN mastodon.social. udp 33 false 512" NOERROR qr,aa,rd,ra 117 0.000507642s
[INFO] 10.42.4.54:33878 - 18196 "A IN mastodon.social. udp 33 false 512" NOERROR qr,aa,rd,ra 64 0.000862045s

In both cases, there's a cascading resolution from *.mastodon.svc.cluster.local up to something closer and closer to the actual FQDN, mastodon.social. In case 2 (using wget) it successfully reaches this point; in case 1, however, it seems to stop just before then and so never resolves.

I have no explanation for this behavior, since it's taking place on the same pod. Any insights would be greatly appreciated.

[magsol]

I've no idea why, but: running apt-get remove tailscale and rebooting each node in sequence seems to have fixed things.

It's confusing to me, because everything was working fine for the past four weeks--tailscale was installed that whole period--and only stopped working when one of the five nodes of the cluster died.

But removing tailscale seems to have solved things, or at least allowed them to self-heal, inasmuch as kubernetes does.

There is some media that is more stubborn about re-loading--aggressive caching?--but the primary issue seems to have been resolved.

[jing8956]

@magsol Recently I had a similar issue. After some investigation, I came to a preliminary conclusion: the DNS server returned the wrong RCode.

This is the log from coredns when I use wget to request misskey.io

[INFO] 10.244.0.239:44721 - 26246 "AAAA IN misskey.io.default.svc.cluster.local. udp 54 false 512" NXDOMAIN qr,aa,rd 147 0.000071499s
[INFO] 10.244.0.239:44721 - 59576 "A IN misskey.io.default.svc.cluster.local. udp 54 false 512" NXDOMAIN qr,aa,rd 147 0.000058899s
[INFO] 10.244.0.239:54329 - 48 "AAAA IN misskey.io.svc.cluster.local. udp 46 false 512" NXDOMAIN qr,aa,rd 139 0.000038499s
[INFO] 10.244.0.239:54329 - 63030 "A IN misskey.io.svc.cluster.local. udp 46 false 512" NXDOMAIN qr,aa,rd 139 0.0000719s
[INFO] 10.244.0.239:39361 - 53540 "AAAA IN misskey.io.cluster.local. udp 42 false 512" NXDOMAIN qr,aa,rd 135 0.0000403s
[INFO] 10.244.0.239:39361 - 41766 "A IN misskey.io.cluster.local. udp 42 false 512" NXDOMAIN qr,aa,rd 135 0.000107098s
[INFO] 10.244.0.239:40671 - 30362 "A IN misskey.io.lan. udp 32 false 512" REFUSED qr,rd,ra 32 0.00256897s
[INFO] 10.244.0.239:40671 - 9115 "AAAA IN misskey.io.lan. udp 32 false 512" REFUSED qr,rd,ra 32 0.002667569s
[INFO] 10.244.0.239:40671 - 30362 "A IN misskey.io.lan. udp 32 false 512" REFUSED qr,rd,ra 32 0.00177628s
[INFO] 10.244.0.239:40671 - 9115 "AAAA IN misskey.io.lan. udp 32 false 512" REFUSED qr,rd,ra 32 0.001887478s
[INFO] 10.244.0.239:33098 - 16805 "AAAA IN misskey.io. udp 28 false 512" NOERROR qr,rd,ra 131 0.002718469s
[INFO] 10.244.0.239:33098 - 6826 "A IN misskey.io. udp 28 false 512" NOERROR qr,aa,rd,ra 146 0.002761868s

When mastodon requests to misskey.io.lan., the recursive query stops, because the RCode returned by DNS is REFUSED and not NXDOMAIN.
wget ignores this error to continue DNS queries so it works fine.

(Machine translation is used)

[Shanesan]

@jing8956 How did you solve this issue?

[jing8956]

@Shanesan I did indeed deploy a non-mainstream DNS server product as the primary DNS. At that time, it did not return the RCode NXDOMAIN of the superior DNS (Openwrt) as a result, but returned REFUSE. Therefore, the command host <domain> will also fail.
Once I confirmed that this issue was caused by it, I reported it to the author.
As a temporary measure until the fix is implemented, I configured an internal IP http_proxy for Mastodon.

(AI translation is used)