Page MenuHomePhabricator

2% of /w/load.php spent in WebStart/onBeforeCreateEchoEvent for Wikibase
Closed, ResolvedPublic

Description

/includes/WebStart.php

  • EchoHooks::initEchoExtension (3.05%)
    • Wikibase\Client\Hooks\EchoNotificationsHandlers::onBeforeCreateEchoEvent
    • Wikibase\Client\Hooks\EchoNotificationsHandlers::newFromGlobalState (2.63%)
	public static function onBeforeCreateEchoEvent(
		array &$notifications,
		array &$notificationCategories,
		array &$icons
	) {
		$self = self::newFromGlobalState();
		$self->doBeforeCreateEchoEvent( $notifications, $notificationCategories, $icons );
	}

For example: https://performance.wikimedia.org/xenon/svgs/daily/2017-10-01.load.svgz

Screen Shot 2017-10-03 at 19.24.12.png (1×2 px, 425 KB)

The doBeforeCreateEchoEvent() method call itself is trivial. Most time is spent in newFromGlobalState(), which requires numerous services that are not used.

  • NamespaceChecker (unused)
  • RepoLinker (unused)
  • WikibaseClient (mostly unused, except for Settings)
    • WikibaseClient//SiteLookup (unused)
    • WikibaseClient//DataTypeDefinitions (unused)
    • WikibaseClient//Settings (used)

The most expensive here is SiteLookup and NamespaceChecker, which are both created here for the unrelated hook onWikibaseHandleChange - which is not called on most requests and not worth blocking WebStart on all web requests.

From a brief look it seems that the main problem is that all hook handlers share the same singleton for injection (instead of obtaining their own services as needed), which means calling one hook ends up also requiring services for other hooks.

A deeper problem is that these services have expensive constructors, which is unexpected, and likely the reason why this approach was assumed to be unproblematic.

Patch-For-Review:


See also: T160678: Reduce ChronologyProtector init cost for load.php

Event Timeline

The above flame graph is from HHVM profiling samples over 24 hours from production traffic. While useful to see the overall impact on average, it does not provide timings (due to being sampled). Here two profiles from XHGui for an individual request (including flamegraph).

https://performance.wikimedia.org/xhgui/run/flamegraph?id=59d4a63a3f3dfacf5d63a6ab (total: 1.3s)

  • EchoNotificationsHandlers::onBeforeCreateEchoEvent (111ms, 8%)

https://performance.wikimedia.org/xhgui/run/flamegraph?id=59d4a5ef3f3dfacf5daf6f40 (total: 45s)

  • EchoNotificationsHandlers::onBeforeCreateEchoEvent (231ms, 1%)

This should probably indeed be split up into different handlers, which might solve some of the problems here.

Also we could probably make WikibaseClient faster by lazy-creating the SiteLookup.

Regarding the NamespaceChecker construction: This is in parts so expensive due to the closure in mediawiki-config ($wgWBClientSettings['excludeNamespaces'] = function () { … } in wmf-config/Wikibase.php). We should try to avoid getting this setting if possible, but I don't see a nice way to make this faster.

Change 382383 had a related patch set uploaded (by Aude; owner: Aude):
[mediawiki/extensions/Wikibase@master] Split Echo hook handlers based on services needed

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

Change 382386 had a related patch set uploaded (by Aude; owner: Aude):
[mediawiki/extensions/Wikibase@master] Split hook handler that runs on Echo extension setup

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

Change 382386 abandoned by Aude:
Split hook handler that runs on Echo extension setup

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

Change 382383 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Split Echo hook handlers based on services needed

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

thiemowmde moved this task from incoming to in progress on the Wikidata board.
thiemowmde added a subscriber: Lydia_Pintscher.

Change 382383 merged by jenkins-bot:
[mediawiki/extensions/Wikibase@master] Split Echo hook handlers based on services needed

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

@aude Thanks for the quick patch!

	public static function newFromGlobalState() {
-		$wikibaseClient = WikibaseClient::getDefaultInstance();
-		$settings = $wikibaseClient->getSettings();
+		$settings = WikibaseSettings::getClientSettings();

		return new self(
-			$wikibaseClient->newRepoLinker(),
-			$wikibaseClient->getNamespaceChecker(),
			$settings->getSetting( 'echoIcon' )

Very nice. I didn't know WikibaseSettings::getClientSettings existed. That also avoids creating WikibaseClient's services.

@Krinkle is it okay for this to wait to go out w/ the train next week or should we consider a backport?

(while I'm sure the patch works good, I would prefer the train, so the code has time on test wikis etc.)

@aude Next week is fine. This isn't a regression from current week's branch.

thiemowmde updated the task description. (Show Details)

@aude, @Krinkle, can we consider this done? Do you have new numbers to compare with the previous state as it is described in this tickets description?

For the moment I'm moving this ticket back, since it seems nothing happened for about a month.

Yep, this is resolved. It's no longer part of the trace for load.php. Thanks!.

Before
Screen Shot 2017-10-26 at 17.30.04.png (504×2 px, 241 KB)
Screen Shot 2017-10-26 at 17.30.08.png (358×2 px, 196 KB)
After
Screen Shot 2017-10-26 at 17.30.14.png (560×2 px, 237 KB)