[21:52:51] we're just about at 50% buster in eqiad now (will pass it in a few hours) - so I don't think there's any more utility in having buster-only excimer data anymore [21:53:21] I'll upload patches in a few to turn it off and can deploy them later if there are no objections [21:58:13] https://gerrit.wikimedia.org/r/q/topic:%2522excimer-buster%2522+status:open [22:04:05] legoktm: sure, glad it was of use. Saw the graphs etc [22:04:33] So... apcu regresses even further for extension registry? [22:04:54] Maybe time to put more work into reducing the blob size [22:05:17] There were more things to move out if I recall correctly [22:06:53] about half of the slowdown is because APCUBagOStuff triggers autoloading for a bunch of other stuff, and while the slowdown is Autoloading related, ExtensionRegistry gets the blame [22:07:12] it does look like apcu itself is slower though [22:16:27] legoktm: hm.. where/how do you see the autoloader cost there? [22:16:47] https://people.wikimedia.org/~legoktm/T273312/data/clean/images/flamegraphs/2021-02-02.index.svg [22:16:58] and I looked at Setup.php specifically [22:17:46] huh, interesting [22:17:52] and you see the stack of loadFromQueue / MediumBagOStuff::get / APCUBagOStuff::doGet / AutoLoader::autload - the last two are bright red [22:17:52] I've not seen autoloader called from doGet before [22:18:00] yeah, I see it [22:18:14] I don't understand though, what is it loading? [22:18:37] are we storing serialized php objects there perhaps? [22:19:07] given it is called via MediumBag, it isn't the APCU/parent class chain being loaded at that point since that's already loaded naturally [22:23:16] we shouldn't be storing any serialized objects/stuff... [22:24:49] https://phabricator.wikimedia.org/P14211 I don't see anything being loaded by MW's autoloader locally [22:27:51] right [22:28:07] https://performance.wikimedia.org/arclamp/svgs/daily/2021-02-09.excimer.load.svgz [22:28:11] it does exist consistently though [22:28:16] at least now [22:28:24] * Krinkle looks for mostly-pre-buster sample [22:28:48] https://performance.wikimedia.org/arclamp/svgs/daily/2020-11-22.excimer.load.svgz [22:28:51] here as well [22:29:03] 30% [22:29:39] gonna livehack mwdebug to dump the value pre-unserialize [22:43:04] legoktm: https://people.wikimedia.org/~krinkle/ [22:43:12] heh, guess what one of hte last files there is from 2018 [22:43:19] flamegraph diff [22:43:20] xD [22:44:03] so here's a dump of the ext registry key on mediawikiwiki https://people.wikimedia.org/~krinkle/apcu-extreg-wmf30.txt [22:44:13] $blob = apcu_fetch( $key . self::KEY_SUFFIX ); [22:44:13] + if ($blob !== false && strpos(wfGetAllCallers(),'ExtensionRegistry') !== false) { echo __METHOD__ . '/' . $key; var_dump($blob); die; } [22:44:35] * legoktm reads through [22:44:47] I haven't spotted any objects so far [22:44:55] but I do see that indeed a big chunk of this is globals [22:44:59] which are stored twice [22:45:33] previously analysed at https://phabricator.wikimedia.org/T187154#6034369 [22:46:28] and a few comments hgiher up at https://phabricator.wikimedia.org/T187154#5954675 [22:46:40] " TestAutoloadClasses – See T240535 " [22:46:41] T240535: Clean up ExtensionRegistry autoloading mess - https://phabricator.wikimedia.org/T240535 [22:46:47] we sitl haven't sorted out that mess [22:46:53] though it's not particularly big [22:48:37] and credits still stored twice as well [22:49:23] or not.. no, not twice, but we still don't need it afaik on most web reqs so can robably become an attribute for SpecialVersion [22:50:08] gahhh we're storing the config twice [22:50:57] found an object [22:51:08] MessagePosterModule [22:51:14] object(ResourceLoaderFilePath)#56 [22:51:31] interseting [22:51:51] https://gerrit.wikimedia.org/g/mediawiki/core/+/29d4f397e6d03492b3a26553c09c5e19ec0330ac/includes/registration/ExtensionProcessor.php#588 [22:52:24] could be worse I suppose [22:52:31] dep-free value object [22:52:34] https://gerrit.wikimedia.org/r/plugins/gitiles/mediawiki/core/+/77cf34fae7fa49c2f5d912edf8ae4b3a6111e455%5E%21/#F1 from October [22:54:34] https://gerrit.wikimedia.org/g/mediawiki/core/+/29d4f397e6d03492b3a26553c09c5e19ec0330ac/includes/resourceloader/ResourceLoaderFilePath.php looks pretty self-contained [22:54:50] yeah, that shouldn't cause that much overhead [22:55:29] if I apply some handwavey calculations and consider flamegraph for load.php as being a call graph for a median ~50ms load.php resp [22:56:15] that puts ExtensionRegistry at 5-10ms (8-10%) based on December/January data [22:56:38] only 5% on yesterday's flame graph though [22:56:44] but it was red on yours? [22:57:02] oh [22:57:03] multi version [22:57:14] https://performance.wikimedia.org/arclamp/svgs/daily/2021-01-08.excimer.load.svgz [22:57:19] ok, one version [22:57:29] yeah still ~8% [22:58:43] dropping config from the cache should be easy [22:59:32] credits is used by ExtensionRegistry::isLoaded() [22:59:47] though we don't need full authorship/etc. info, just name and version [22:59:48] https://performance.wikimedia.org/xhgui/run/symbol?id=60246530386ebcf0aa29c802&symbol=ExtensionRegistry%3A%3AloadFromQueue [22:59:56] after 3 warmups [23:00:06] 13ms for the call, of which 9ms in get/doGet [23:01:19] and an estmated (estimated because tideways/xhprof only capture parent/child pairs, so anything deeper is global average of all apcu->doGet calls)... estimated 0.02ms in AutoLoader within doGet [23:01:59] legoktm: yeah, I figured wed split it up [23:02:49] brb, gonna get some food, then I'll start filing some phab tasks and looking at code [23:20:45] oh, we do need the full credits at runtime [23:20:56] it's passed as the first parameter to the callback [23:20:57] $cb( $info['credits'][$name] ); [23:23:05] IIRC that was a concession to some extension devs so they could just keep the version in extension.json and then define the FOO_VERSION constant in a callback [23:25:12] hm.. well, version is not everything [23:25:20] how is that used in practice? [23:27:14] https://github.com/JeroenDeDauw/Maps/blob/0a6d802a3190bab2b8cd42640b06ed08fc3bcec4/MapsRegistration.php#L21 [23:27:22] that's the only instance I can find in codesearch [23:27:49] of course, I'm sure people named their callbacks something other than onRegistration() [23:30:54] legoktm: right, at runtime for the handful of callbacks we have we can pass $callback( [ 'name' => …, 'version' => … ]) to shim it perhaps? [23:31:40] also, now that we have 'constants' in extnsion.json, it could perhaps even be removed entirely if this one is fixed [23:32:04] but that's harder to pull off in a non breaking way [23:32:57] fine to keep though if its just those two keys [23:33:05] well there's very little utility for a FOO_VERSION constant anymore. ExtensionRegistry protects against double loading and if you want to check if something else is loaded, you'd see ExtensionRegistry::isLoaded() [23:33:13] yeah [23:33:22] it was only needed during the migration process [23:33:23] but we need name+version anyway right? [23:33:28] for isLoaded() etc [23:33:28] yes [23:33:45] so we can make the data structue very mnimal (no sub array) and just pass this in for now to the callback [23:34:06] versions => [ $name => $version ] [23:34:19] and for callback( 'name' => $name, 'version' => $version ) [23:37:25] * legoktm writes up for phab