|
2024-10-28 21:59:42
|
<Krinkle>
|
TimStarling: Reedy: semi-random ping - I wonder if either of you have noticed and/or have looked at regression around Special:Contributions. It seems to have fallen back in latency quite a bit back. And a few excimer runs show that indeed there is a ton of repeat work being done that I thoguht we fixed a few years ago. e.g. https://performance.wikimedia.org/excimer/profile/abe9b7b82ac31b52
|
|
2024-10-28 22:01:09
|
<Krinkle>
|
it's like 1-2s minimum for basic 50 edits for any given user. stands out: revDateLink(), generateRollback(), lots of repeat queries and message parsing.
|
|
2024-10-28 22:03:07
|
<Krinkle>
|
hm.. I'm getting 500 by default. Has that always been the case if you have a higher API limit, that the UI also defaults to 500?
|
|
2024-10-28 22:03:45
|
<Krinkle>
|
It's tied to `rclimit` now apparently.
|
|
2024-10-28 22:04:56
|
<Krinkle>
|
I tend to reflexively change watchlist and special:recentchanges to 500 when I view them. I don't think I've ever before realized that this also sets the default for page history, user contribs, and special:log.
|
|
2024-10-28 22:05:26
|
<Krinkle>
|
It still seems like something that should batch more efficiently, so not sure that's the only thing. It's certainly quicker with 50.
|
|
2024-10-28 22:06:30
|
<TimStarling>
|
are you saying something is setting rclimit without you realising?
|
|
2024-10-28 22:07:37
|
<Krinkle>
|
I'm saying I wasn't expecting rclimit to apply outside recent changes. I don't care either way, but if it means I"m signing up for a 2s delay on every contribs link and page history link I open, then no. I don't mind it for RC given that's usualy the start of a more in-depth workflow.
|
|
2024-10-28 22:07:41
|
<TimStarling>
|
the Special:Preferences label says "Number of edits to show in recent changes, page histories, and in logs, by default"
|
|
2024-10-28 22:08:16
|
<Krinkle>
|
Yeah, I see that. I search for 500 in prefs and found that. I wonder if that's alwyas been the case, but this is a red herring if the cause is that loading 500 revs used to be fast.
|
|
2024-10-28 22:08:22
|
<TimStarling>
|
but it's in the recentchanges tab
|
|
2024-10-28 22:08:54
|
<Krinkle>
|
I'm more interested in making it so that seemingly-simple page history and contribs responses aren't slow.
|
|
2024-10-28 22:09:17
|
<Krinkle>
|
with limit 500 there's 217 db select queries. most coming in via LinkHolderArray::replaceInternal
|
|
2024-10-28 22:09:22
|
<Krinkle>
|
https://performance.wikimedia.org/xhgui/run/symbol?id=672009d842997c3ebc1d391d&symbol=Wikimedia%5CRdbms%5CSelectQueryBuilder%3A%3AfetchResultSet
|
|
2024-10-28 22:10:12
|
<TimStarling>
|
since 2007: https://static-codereview.wikimedia.org/MediaWiki/22010.html
|
|
2024-10-28 22:11:08
|
<TimStarling>
|
set in the base class so it would have been applied to more things as we migrated them to Pager
|
|
2024-10-28 22:13:26
|
<Krinkle>
|
Yeah ok that's not new then. I don't really mind it. I don't think it makes sense per-se given the difference in how one consumes watchlist/rc vs logs/contribs. Like when I open watchlist or RC, I"m generally going to have it open for a while and I don't yet know what to look for. Whereas logs or contribs one almost always has a purpose, I'm just waiting for it to load so I can click the next link, e.g. the last edit on the page, or that
|
|
2024-10-28 22:13:26
|
<Krinkle>
|
edit I know myself or someone else made 3 minutes ago.
|
|
2024-10-28 22:13:50
|
<Krinkle>
|
nvm RE LinkHolderArray, classic XHProf useless tuple fake data.
|
|
2024-10-28 22:15:11
|
<Krinkle>
|
most of them are rollback count and page protection store
|
|
2024-10-28 22:15:53
|
<Krinkle>
|
I wonder if something regressed in message parsing that it's so expensive for simple strings
|
|
2024-10-28 22:19:26
|
<TimStarling>
|
in the sandwich view for Message::format, the callee side seems more or less as expected
|
|
2024-10-28 22:20:05
|
<TimStarling>
|
lots of {{plural}} which you can't simply cache in the pager, it needs the parser for that
|
|
2024-10-28 22:21:52
|
<TimStarling>
|
Message::format is 22%
|
|
2024-10-28 22:29:47
|
<TimStarling>
|
ok there are a couple of odd things in message parsing
|
|
2024-10-28 22:30:29
|
<TimStarling>
|
you don't need limit reports for messages (Parser::makeLimitReport)
|
|
2024-10-28 22:30:51
|
<Krinkle>
|
I'm looking at showCharacterDifference as well. wgMiserMode is on, incl on Wikitech.
|
|
2024-10-28 22:31:02
|
<TimStarling>
|
you shouldn't need tidying, the input should be tidy enough, although that's a breaking change at this point
|
|
2024-10-28 22:32:18
|
<TimStarling>
|
Parser::finalizeHeadings() is very expensive, that's a recent change, November 2023
|
|
2024-10-28 22:32:39
|
<Krinkle>
|
but `rc-change-size-new` tooltip escapes that optimisation
|
|
2024-10-28 22:33:24
|
<Krinkle>
|
TimStarling: right, that could perhaps be guarded based on `interface` mode
|
|
2024-10-28 22:33:47
|
<Krinkle>
|
ParserOptions->getInterfaceMessage that is
|
|
2024-10-28 22:34:44
|
<Krinkle>
|
RE: finalizeHeadings, you mean https://gerrit.wikimedia.org/r/c/mediawiki/core/+/975064 ?
|
|
2024-10-28 22:35:52
|
<TimStarling>
|
yes, and it's a very simple fix, the cost here is just due to the DOMUtils::parseHTML() call, but it's only needed in the loop body and $headlines is empty
|
|
2024-10-28 22:36:41
|
<TimStarling>
|
I mean the DOMUtils::parseHTML() call needs to be skipped when $headlines is empty
|
|
2024-10-28 22:41:03
|
<TimStarling>
|
this is 2.4% of your profile but at least it is easy
|
|
2024-10-28 22:41:42
|
<Krinkle>
|
right, that's ~57% of finalizeHeadings, or 1.2% in https://performance.wikimedia.org/excimer/profile/abe9b7b82ac31b52
|
|
2024-10-28 22:42:10
|
<Krinkle>
|
ah 2.4% cumulative yeah, there's a few more places
|
|
2024-10-28 22:43:31
|
<TimStarling>
|
generateRollback() could be fixed by just removing those links -- generate them on the client side if they are needed
|
|
2024-10-28 22:43:36
|
<Krinkle>
|
we presumably don't expose TOCData on interface messages, but there may be some non-obvious cases like special pages with interace messages and a TOC where we add to outputpage with metadata. Afaik we parse those normally though as not as interface. I don't think TOC works there today, but worth checking if that's exposed somewhere. Could ptentially cut more in that case.
|
|
2024-10-28 22:48:04
|
<Krinkle>
|
the cost isn't in the csrf token (which we could add client-side like we do with patrol already, for ajax-ification) but the revision count and message plural parsing. The csrf token could be remoed in favour of a form fallback (right now it lacks that, but easy to add). assuming most of the rollback links will have the same single digit number, that could be cached inline to an extent, waiving potential customisations that permuate the
|
|
2024-10-28 22:48:04
|
<Krinkle>
|
interface message based on other factors we don't anticipate.
|
|
2024-10-28 22:50:08
|
<Krinkle>
|
the revision count... it seems like that information ought to be in memory already. But it's structured to act on one rev at a time.
|
|
2024-10-28 22:51:00
|
<Krinkle>
|
It might miss a few for the last row but for most it'll have the revs between it and the next 10 (ShowRollbackEditCount)
|
|
2024-10-28 22:51:17
|
<Krinkle>
|
but that seems like something that's probably always worked this way.
|
|
2024-10-28 22:51:26
|
<Krinkle>
|
no smoking gun that made it slow recently
|
|
2024-10-28 22:52:06
|
<TimStarling>
|
I think doing 500 rows was always pretty slow, I don't remember that being fast
|
|
2024-10-28 22:52:37
|
<TimStarling>
|
it's slow for different reasons now, we're finding new ways to keep it slow despite faster CPUs etc.
|
|
2024-10-28 22:53:33
|
<Krinkle>
|
> We need metrics for special page views, by analogy with the action metrics https://phabricator.wikimedia.org/T257002#7313928
|
|
2024-10-28 22:54:02
|
<Krinkle>
|
https://grafana-rw.wikimedia.org/d/rLMucuf4k/mediawiki-entrypoint-profiling?orgId=1&var-entrypoint=index_Contributions&var-http_method=GET&var-time_grouping_unit=3h
|
|
2024-10-28 22:54:09
|
<Krinkle>
|
we do have something like that now
|
|
2024-10-28 22:54:39
|
<TimStarling>
|
RestrictionStore::getRestrictions() is 209ms in your profile, that could benefit from batching
|
|
2024-10-28 22:54:51
|
<Krinkle>
|
I recall it covering this latency metric as well https://grafana-rw.wikimedia.org/d/8j5fqcuVk/mediawiki-action-timing-index-php but it seems there isn't an equivalent for that
|
|
2024-10-28 22:55:30
|
<TimStarling>
|
WAN cache in front of a single fast query is questionable, especially when it is called 500 times
|
|
2024-10-28 22:56:24
|
<Krinkle>
|
right, that presumably helps on HistoryPager but not ContribsPager
|
|
2024-10-28 22:57:07
|
<TimStarling>
|
the existence of RestrictionStore with its in-process cache would make batching pretty straightforward, it's obvious how to implement that
|
|
2024-10-28 22:57:54
|
<Krinkle>
|
History pager has doBatchLookups() to place this
|
|
2024-10-28 22:58:37
|
<Krinkle>
|
ContribPager.... not but,, ah yes the same, doBatchLookups in the parent, ContributionsPager, because those are obviously two different things.
|
|
2024-10-28 23:00:07
|
<TimStarling>
|
119ms for ConvertibleTimestamp::setTimestamp(), that is a very hot few lines of code
|
|
2024-10-28 23:01:27
|
<Krinkle>
|
ref T341319, I recall reviewing that for RestrictionStore, but doesn't help with `rollback`
|
|
2024-10-28 23:01:42
|
<stashbot>
|
T341319: RecentChanges: Improve performance of Special:RecentChanges rendering - https://phabricator.wikimedia.org/T341319
|
|
2024-10-28 23:01:59
|
<Krinkle>
|
https://gerrit.wikimedia.org/r/c/mediawiki/core/+/938220
|
|
2024-10-28 23:02:05
|
<Krinkle>
|
> When rendering Special:RecentChanges for an user with rollback rights,
|
|
2024-10-28 23:02:16
|
<TimStarling>
|
the setTimestamp() calls mostly come from ConditionalDefaultsLookup, which is new (Nov 2023)
|
|
2024-10-28 23:02:25
|
<Krinkle>
|
.. or maybe it does. Right, of course, you can't protect against rollback.
|
|
2024-10-28 23:04:06
|
<Krinkle>
|
I guess that's for `$authority->probablyCan( 'edit', $title );`, right above `$authority->probablyCan( 'rollback', $title ) ` also in PagerTools
|
|
2024-10-28 23:04:34
|
<Krinkle>
|
has dinner ready
|
|
2024-10-28 23:05:15
|
<Krinkle>
|
I might file a few tasks for this under T341319 or another related task if you don't. Also if you're compelled to patch, CC me :)
|
|
2024-10-28 23:06:31
|
<TimStarling>
|
memoizing of ConditionalDefaultsLookup::getOptionDefaultForUser() looks straightforward and would save a substantial fraction of 96ms
|
|
2024-10-28 23:06:42
|
<Krinkle>
|
TimStarling: unrelated, I'm writing a patch to tear out the shared in lock mode, we came to the same conclusion (I only noticed your analysis in the early history after I already did my own). I did end up when and "why" it was was added, https://phabricator.wikimedia.org/T199393#10270676
|
|
2024-10-28 23:07:02
|
<Krinkle>
|
end up finding*
|
|
2024-10-28 23:07:19
|
<TimStarling>
|
sounds good
|
|
2024-10-28 23:07:26
|
<Krinkle>
|
there's a ton of abstraction that's been erected since so i'll need to tear some of that down as well or make it no-op.
|
|
2024-10-28 23:07:47
|
<TimStarling>
|
thanks for merging my installer patches
|
|
2024-10-28 23:07:57
|
<TimStarling>
|
do you want to be added as a reviewer on the rest of them?
|
|
2024-10-28 23:08:06
|
<Krinkle>
|
you can try, no promises though
|
|
2024-10-28 23:08:17
|
<Krinkle>
|
feel free to.
|
|
2024-10-28 23:08:24
|
<TimStarling>
|
ok, thanks
|