Probably related: T384414

Please unbreak again.

mailman-web has been restarted, it seems to be a bit faster now

Again. Please unbreak this permanently.

In T353891#11178837, @Krd wrote:

Again. Please unbreak this permanently.

Given the amount of scrapers on our mailman. If you can burst the AI bubble, it'd help us a lot.

To SRE-Collab: Maybe this can somehow use the CDN blocks?

My suspicion is that it's slow because it's inefficient. That's why I asked for stack traces. Profiling would also do the job.

Change #1188288 had a related patch set uploaded (by Ladsgroup; author: Amir Sarabadani):

[operations/puppet@production] lists: Bump number of uwsgi processes to 12 (from 4)

https://gerrit.wikimedia.org/r/1188288

Change #1188288 merged by Ladsgroup:

[operations/puppet@production] lists: Bump number of uwsgi processes to 12 (from 4)

https://gerrit.wikimedia.org/r/1188288

Change #1188294 had a related patch set uploaded (by Jcrespo; author: Jcrespo):

[operations/puppet@production] mailman: Update monitoring to 13 mailman processes

https://gerrit.wikimedia.org/r/1188294

Change #1188294 merged by Jcrespo:

[operations/puppet@production] mailman: Update monitoring to 13 mailman processes

https://gerrit.wikimedia.org/r/1188294

Change #1188320 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: add a local disk cache

https://gerrit.wikimedia.org/r/1188320

Change #1188320 merged by Arnaudb:

[operations/puppet@production] mailman: add a local disk cache

https://gerrit.wikimedia.org/r/1188320

Change #1188708 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] Revert^2 "mailman: add a local disk cache"

https://gerrit.wikimedia.org/r/1188708

Change #1188708 merged by Arnaudb:

[operations/puppet@production] Revert^2 "mailman: add a local disk cache"

https://gerrit.wikimedia.org/r/1188708

Change #1188796 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] Revert^3 "mailman: add a local disk cache"

https://gerrit.wikimedia.org/r/1188796

Change #1188796 abandoned by Arnaudb:

[operations/puppet@production] Revert^3 "mailman: add a local disk cache"

Reason:

wrong patch

https://gerrit.wikimedia.org/r/1188796

Change #1188798 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] Revert^4 "mailman: add a local disk cache"

https://gerrit.wikimedia.org/r/1188798

Change #1188798 merged by Arnaudb:

[operations/puppet@production] Revert^4 "mailman: add a local disk cache"

https://gerrit.wikimedia.org/r/1188798

https://gerrit.wikimedia.org/r/1188798 creates a 1GB local disk cache that should help with those performance issues.

cache is around 100MB and the UI is slowing down again

Yeah... https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ is still slow :(

with T286066: Put lists.wikimedia.org web interface behind CDN done it should be better:

In T286066#11701033, @ABran-WMF wrote:

mailman-web is now behind CDN:

$ dig -x $(dig A lists.wikimedia.org +short) +short
text-lb.drmrs.wikimedia.org.

the MX is now:

$ dig MX lists.wikimedia.org +short
10 lists1004.wikimedia.org.

and it'll be updated in T278495: Figure out plan for mailman IP situation

Please let us know if it still feels sluggish

edit:

testing the url highlighted in:

In T353891#11234974, @Reedy wrote:

Yeah... https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ is still slow :(

it looks like mailman is still slow

I can’t login either

In T353891#11701217, @Reedy wrote:

I can’t login either

Interesting, I've been able to logout/login with my mobile and desktop browsers. Have you tried to login from a private browsing session?

Yup, same behaviour. Not that I’ve logged in on my mobile in a while anyway… nor was it a tab I already had open etc

Change #1251016 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: increase envoy timeout

https://gerrit.wikimedia.org/r/1251016

Change #1251016 merged by Arnaudb:

[operations/puppet@production] mailman: increase envoy timeout

https://gerrit.wikimedia.org/r/1251016

https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ is available again, envoy needed more time to wait for the upstream

Change #1251026 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: keep SECURE_PROXY_SSL_HEADER on X-Forwarded-Proto

https://gerrit.wikimedia.org/r/1251026

Change #1251026 merged by Arnaudb:

[operations/puppet@production] mailman: keep SECURE_PROXY_SSL_HEADER on X-Forwarded-Proto

https://gerrit.wikimedia.org/r/1251026

In T353891#11701257, @Reedy wrote:

Yup, same behaviour. Not that I’ve logged in on my mobile in a while anyway… nor was it a tab I already had open etc

I can't seem to reproduce the CSRF behavior you're mentioning. When testing with: {P89843} I see the relevant CSRF bits. I've discarded a header that was not useful for mailman, but it did not change the tests ouptut

I can login and logout normally on firefox, I can't reproduce the CSRF error

Mobile FF does the same for me…

In T353891#11701203, @ABran-WMF wrote:

with T286066: Put lists.wikimedia.org web interface behind CDN done it should be better:

Please let us know if it still feels sluggish

https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ takes 111 seconds to load per FireFox network timing API data collected just now on my home network. That time is all attributed to "waiting". I think it is quite likely that the Python app is doing something inefficient or reliant on an underpowered backend service.

In T353891#11704396, @bd808 wrote:

https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ takes 111 seconds to load per FireFox network timing API data collected just now on my home network. That time is all attributed to "waiting". I think it is quite likely that the Python app is doing something inefficient or reliant on an underpowered backend service.

Maybe if we had profiling data we could figure out what inefficient thing it is doing.

I again cannot open https://lists.wikimedia.org/postorius/lists/daily-article-l.lists.wikimedia.org/ because it always times out. Please fix.

Please unbreak now.

In T353891#11997498, @Krd wrote:

As said, daily-article-l is not manageable for months because the interface times out every time. Please unbreak.

I've just tried to load https://lists.wikimedia.org/hyperkitty/list/daily-article-l@lists.wikimedia.org/ and it took ~2s to load, no timeout on my end and I can't seem to be able to reproduce that issue on any page.
I'm wondering if this is linked to your accounts somehow, as @bd808 reported the same thing here:

In T353891#11704396, @bd808 wrote:

https://lists.wikimedia.org/postorius/lists/mediawiki-announce.lists.wikimedia.org/ takes 111 seconds to load per FireFox network timing API data collected just now on my home network. That time is all attributed to "waiting". I think it is quite likely that the Python app is doing something inefficient or reliant on an underpowered backend service.

Have you tried from a private browsing window? with a different account?

The link loads when not logged in. As soon as you log in, I assume it loads the user list of 30k entries or so and breaks.

this is the weird thing, I tried to log in and refresh the page and still get the same snappy result:

edit: @Jelto found a page where the bug happens also for me

TL;DR (generated)

• Root cause: when logged in, Postorius' ListSummaryView fetches the entire pending-subscription-requests collection of the list just to check whether the current user has a pending request. On large lists this takes 100s+ and produces the 504/timeout everyone reports. Logged-out is fast because that code path only runs when authenticated.
• Why it's so slow: these lists have a huge backlog of stale, unconfirmed bot/spam subscription requests (type: subscription, token_owner: subscriber), some dating back to 2021. mediawiki-announce has 6314 (→ 108s); daily-article-l has 9573 (Krd's list); 29,442 pending requests instance-wide. Mailman Core materializes the whole collection before paginating, so even ?count=3 takes ~50s.
• The pending eviction that should clean this up isn't running on the host (Core's tasks runner) — that's why 2021 entries survive and the backlog keeps growing.
• Separate, second O(n) issue: the member-management page calls roster/member = 245s / 15.6 MB for the ~30k-member roster. Same shape (unpaginated O(n)), different endpoint.
• Known upstream since 2021, and not fixed: ListSummaryView still does [r['email'] for r in self.mailing_list.requests] in current master → upgrading Postorius will not fix this page (the owner settings page was optimized, this one wasn't).
• None of the previous mitigations (uwsgi 4→12, 1 GB diskcache, CDN, 120s envoy timeout) could help — they all sit downstream of a single slow Core call; raising the timeout just turns the 504 into a 108s wait.

Proposed fixes: (1) purge the stale pending requests (immediate, high-impact, low-risk — biggest wins on daily-article-l & mediawiki-announce); (2) fix/enable the Core task runner so the backlog doesn't rebuild; (3) patch Postorius (ListSummaryView should check only the current user's addresses / use a count endpoint, and paginate the roster) — locally, plus an upstream MR.

(Full investigation below — done by pairing with the Claude trial.)

 Investigation

Knowing very little about mailman, I paired up with our Claude trial to sort this out.
After a few steps, it appeared that it might be an issue on the DB side, all workers are idling while the page timeouts.
The model gave me a for loop to validate that hypothesis against mailman's API:

$   PW=$(sudo rg -oP '^\s*admin_pass:\s*\K\S+' /etc/mailman3/mailman.cfg)
  L=mediawiki-announce.lists.wikimedia.org
  for ep in "lists/$L" "lists/$L/roster/member" "lists/$L/roster/owner" "lists/$L/roster/moderator"; do
    echo "=== $ep ==="
    curl -s -o /dev/null -u "restadmin:$PW" \
      -w 'http=%{http_code} ttfb=%{time_starttransfer}s total=%{time_total}s size=%{size_download}\n' \
      "http://localhost:8001/3.1/$ep"
  done
=== lists/mediawiki-announce.lists.wikimedia.org ===
http=200 ttfb=0.080794s total=0.080911s size=494
=== lists/mediawiki-announce.lists.wikimedia.org/roster/member ===
http=200 ttfb=245.803348s total=245.809631s size=15637830
=== lists/mediawiki-announce.lists.wikimedia.org/roster/owner ===
http=200 ttfb=0.149384s total=0.149504s size=6714
=== lists/mediawiki-announce.lists.wikimedia.org/roster/moderator ===
http=200 ttfb=0.030590s total=0.030714s size=90

Highlighting:

=== lists/mediawiki-announce.lists.wikimedia.org/roster/member ===
http=200 ttfb=245.803348s total=245.809631s size=15637830

So @Krd, you're right to assume:

In T353891#11997522, @Krd wrote:

The link loads when not logged in. As soon as you log in, I assume it loads the user list of 30k entries or so and breaks.

Digging a littler further on that, it turns out that mailman seems to be using a non paginated query, because reproducing the same problematic curl over a smaller set of accounts gives a faster result:

$ curl -s -o /dev/null -u "restadmin:$PW" -w 'http=%{http_code} ttfb=%{time_starttransfer}s total=%{time_total}s size=%{size_download}\n' "http://localhost:8001/3.1/lists/$L/roster/member?count=100&page=1"
http=200 ttfb=1.940268s total=1.940408s size=63608

So, the query time increases with the member count value

$ for c in 1 10 100 1000; do printf 'count=%-5s ' "$c"; curl -s -o /dev/null -u "restadmin:$PW" -w 'total=%{time_total}s size=%{size_download}\n' "http://localhost:8001/3.1/lists/$L/roster/member?count=$c&page=1"; done
count=1     total=0.670914s size=753
count=10    total=0.799409s size=6490
count=100   total=1.920941s size=63608
count=1000  total=11.999044s size=650922

Once this has been identified, I steered the analysis in the direction of the underlying cause.
A few tests and web searches later, Claude gave me that answer:

Root-caused. Two separate O(n) Core endpoints; the one in every report here is the pending-requests listing.

Method: uwsgi py-tracebacker + process state showed all 12 web workers idle (blocked in
socket recv, zero CPU) during a 103s load — so the time is spent waiting on Mailman Core,
not in Django. Timing the Core REST endpoints that ListSummaryView calls, directly:

lists/<list> (settings)            0.08s
lists/<list>/member/<email>        0.02s   (per-user membership lookup — fine)
members/find?...                   0.03s
lists/<list>/requests              108s    <-- bottleneck
lists/<list>/requests/count        0.47s   -> 6314

ListSummaryView (the page in every report here) runs, only when logged in:

pending_requests = [r['email'] for r in self.mailing_list.requests]

i.e. it fetches the ENTIRE pending-requests collection just to check whether the current
user has a pending subscription. mediawiki-announce has 6314 pending subscription requests
dating back to 2021 — unconfirmed bot/spam subscribe attempts (type: subscription,
token_owner: subscriber, junk domains). Core materializes all 6314 before paginating, so
even ?count=3 takes 50s. That is the 100s+ logged-in load, and exactly why it is fast
logged-out (the is_authenticated branch is the only caller).

Separately, the member-management page calls roster/member = 245s / 15.6MB for the
~30k-member roster — same O(n) shape, different endpoint.

Note: pending_request_life: 3d is set in mailman.cfg, but 2021 entries are still present,
so pending eviction is not actually running. Needs a separate look, otherwise the backlog
rebuilds.

Proposed fixes:

1. Immediate / high-impact / low-risk: purge the stale pending subscription requests on affected lists (years-old unconfirmed bot attempts). That alone makes the logged-in summary page fast again. Check daily-article-l and other large/old lists for the same.
2. Fix why pending_request_life eviction isn't running, so the backlog doesn't rebuild.
3. Upstream (postorius): ListSummaryView should not fetch the full requests collection to check one user — use a targeted query / the count endpoint. Same for paginating the members roster.

Upstream status (checked):

• This is a known problem since 2021: "the requests API call will timeout if there are a number of pending requests ... the UI should not try to load all the pending members just for the sake of showing the number" (mailman-users, Jan 2021). Related open Postorius issue #314.
• It is NOT fixed upstream for this code path. Postorius did switch the *owner settings* page to count-based APIs in 1.3.4/1.3.6 (already in our 1.3.8), but ListSummaryView still does [r['email'] for r in self.mailing_list.requests] in current master. So upgrading Postorius will NOT fix this page — it needs a local patch and/or a new upstream MR (only check the current user's 1-3 addresses, not the whole collection).
• Why the backlog never expires: Core 3.3.5+ has a Task runner that evicts expired pendings hourly, but (un)subscription requests awaiting user confirmation were pended with a too-long lifetime, so they are never evicted (hence 2021 entries surviving). Worth confirming the tasks runner is actually enabled here.

Refs:

• mailman-users thread: https://lists.mailman3.org/archives/list/mailman-users@mailman3.org/thread/JOJAJKFEZGQAJDYGSQJOMJGXZWDCAT2X/
• Postorius issue #314: https://gitlab.com/mailman/postorius/-/issues/314
• Task runner: https://docs.mailman3.org/projects/mailman/en/latest/src/mailman/runners/docs/task.html

The task-runner does not seem to be active on the host:

$ sudo journalctl -u mailman3 | rg -i 'task|evict'
$

I tried to evaluate the impact of a purge:

$  curl -s -u "restadmin:$PW" "http://localhost:8001/3.1/lists?count=2000&page=1" \
    | rg -oP '"list_id":\s*"\K[^"]+' \
    | while read -r lid; do
        c=$(curl -s -u "restadmin:$PW" "http://localhost:8001/3.1/lists/$lid/requests/count" | rg -oP '"count":\s*\K\d+')
        printf '%s\t%s\n' "${c:-?}" "$lid"
      done | sort -rn | tee /tmp/req_counts.tsv | head -40
9573	daily-article-l.lists.wikimedia.org
6314	mediawiki-announce.lists.wikimedia.org
1584	mediawiki-api-announce.lists.wikimedia.org
1475	wikimediaannounce-l.lists.wikimedia.org
1359	1lib1ref.lists.wikimedia.org
901	affcom-members.lists.wikimedia.org
873	african-wikimedia-developers.lists.wikimedia.org
856	affiliates.lists.wikimedia.org
852	abstract-wikipedia.lists.wikimedia.org
643	daily-image-l.lists.wikimedia.org
273	wikidata.lists.wikimedia.org
228	mediawiki-l.lists.wikimedia.org
197	wll.lists.wikimedia.org
175	xmldatadumps-l.lists.wikimedia.org
171	wikimedia-l.lists.wikimedia.org
166	open-glam.lists.wikimedia.org
141	wikitech-l.lists.wikimedia.org
128	wikilovesafrica.lists.wikimedia.org
114	wikimediameta-l.lists.wikimedia.org
93	wikidata-tech.lists.wikimedia.org
89	unblock-zh.lists.wikimedia.org
84	wikitech-ambassadors.lists.wikimedia.org
72	lgbt.lists.wikimedia.org
69	wikipedia-l.lists.wikimedia.org
61	mediawiki-api.lists.wikimedia.org
56	ai.lists.wikimedia.org
52	education.lists.wikimedia.org
51	dagbani.lists.wikimedia.org
50	african-wikimedians.lists.wikimedia.org
49	wiki-research-l.lists.wikimedia.org
49	mediawiki-enterprise.lists.wikimedia.org
48	wikipedia-bn.lists.wikimedia.org
48	wikimedia_nyc.lists.wikimedia.org
48	wikija-l.lists.wikimedia.org
46	translators-l.lists.wikimedia.org
45	analytics-announce.lists.wikimedia.org
44	eduwiki.lists.wikimedia.org
42	unblock-en-l.lists.wikimedia.org
42	ambassador-announce-l.lists.wikimedia.org
41	wikiml-l.lists.wikimedia.org

$ awk -F'\t' '{s+=$1} END{print "total pendings:", s}' /tmp/req_counts.tsv
total pendings: 29442

We might want to take a snapshot before the purge, but that's the most actionable item at this stage.

Change #1299445 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: discard stale pending subscription requests

https://gerrit.wikimedia.org/r/1299445

Change #1299448 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: discard stale pending subscription requests

https://gerrit.wikimedia.org/r/1299448

Change #1299445 abandoned by Arnaudb:

[operations/puppet@production] mailman: discard stale pending subscription requests

https://gerrit.wikimedia.org/r/1299445

Thanks for the thorough investigation! I want to clean them up until it becomes automated but the UI is not showing anything pending on https://lists.wikimedia.org/postorius/lists/daily-article-l.lists.wikimedia.org/subscription_requests

I do see the data in pended and pendedkeyvalue so I might manually just get rid of them to reduce the pain a bit.

Thanks @Ladsgroup, per our chat on IRC I'll run the script produced by Claude manually on the instance. First with --dry-run, then I'll export the data before wiping it out.

In T353891#11998503, @gerritbot wrote:

Change #1299448 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/puppet@production] mailman: discard stale pending subscription requests

https://gerrit.wikimedia.org/r/1299448

After reviewing/patching the script, I tested it on lists1004 with --dry-run, first on daily-article-l.lists.wikimedia.org:

$ time sudo python3 /tmp/test.py 30 --dry-run --list daily-article-l.lists.wikimedia.org --record /tmp/stale-subs-dryrun.tsv && wc -l /tmp/stale-subs-dryrun.tsv
[...]
real	2m43.269s
user	0m0.237s
sys	0m0.084s
9574 /tmp/stale-subs-dryrun.tsv

and then on all lists:

$ time sudo python3 /tmp/test.py 30 --dry-run --record /tmp/stale-subs-dryrun.tsv && wc -l /tmp/stale-subs-dryrun.tsv
[...]
real	8m52.560s
user	0m4.667s
sys	0m0.898s
28795 /tmp/stale-subs-dryrun.tsv

I'll run the purge and store the outcome in my homedir, and then merge the patch bringing the timer for that logic to be run regularly

Change #1299506 had a related patch set uploaded (by Arnaudb; author: Arnaudb):

[operations/alerts@master] mailman: add alerts for discard_stale_subscriptions

https://gerrit.wikimedia.org/r/1299506

Change #1299448 merged by Arnaudb:

[operations/puppet@production] mailman: discard stale pending subscription requests

https://gerrit.wikimedia.org/r/1299448

Change #1299506 merged by jenkins-bot:

[operations/alerts@master] mailman: add alerts for discard_stale_subscriptions

https://gerrit.wikimedia.org/r/1299506

Appear to work fine now. Thank you!