Page MenuHomePhabricator

Investigate why comments are slow to post on patchdemo
Closed, ResolvedPublic

Description

Behavior

  1. Visit: https://patchdemo.wmflabs.org/wikis/292134a3316743768728e0552c1e7cc3/wiki/Talk:Nellie_Bly
  2. Log in as username: Bob / pw: patchdemo1
  3. Click any [ reply ] link on the page
  4. Draft a comment
  5. Click Reply
  6. "Solve" captcha
  7. Tool enters its loading/in-progress-posting state

Actual

  1. ❗️Tool returns to its drafting state with the following error appearing within it: The server did not respond within the expected time.:

Screen Shot 2021-04-01 at 4.49.52 PM.png (658×1 px, 95 KB)

Expected

  1. ✅ Comment you drafted in "Step 4." is posted successfully published

Done

  • "Expected behavior` is implemented

Event Timeline

ppelberg created this task.

It asked me to solve a CAPTCHA when I wasn't adding a link. I don't know if that's expected.

It eventually posted a ==New section== for me, but it was slow. I got the red error message on a Reply.

It asked me to solve a CAPTCHA when I wasn't adding a link. I don't know if that's expected.

CAPTCHA is expected, tho I'm glad you mentioned it as I'd forgotten to include it in the task description.

ppelberg lowered the priority of this task from High to Low.Apr 2 2021, 3:57 AM

This task is moot for now considering the most up-to-date prototype [i] seems to be working as expected.


i. https://patchdemo.wmflabs.org/wikis/77cda30f9d/wiki/Talk:Main_Page#Moving_article

matmarex subscribed.

It might not matter for now, but issues with Patchdemo being slow keep reappearing, so I figure now is as good of a time to debug it as any.

So, I installed https://www.mediawiki.org/wiki/Excimer and followed the instructions there to produce a flame graph of the relevant API request, adding the following code in LocalSettings.php:

if ( isset( $_POST['action'] ) && $_POST['action'] === 'discussiontoolsedit' ) {
	$profiler = new ExcimerProfiler;
	$profiler->setPeriod( 0.0001 );
	$profiler->setEventType( EXCIMER_CPU );
	$profiler->start();
	register_shutdown_function( function () use ( $profiler ) {
		$profiler->stop();
		$pipe = popen( "/var/www/html/wikis/292134a3316743768728e0552c1e7cc3/w/FlameGraph/flamegraph.pl > /var/www/html/wikis/292134a3316743768728e0552c1e7cc3/w/profile.svg", "w" );
		fwrite( $pipe, $profiler->getLog()->formatCollapsed() );
	} );
}

Which produces the following output:

profile_annotated.png (4×2 px, 2 MB)

(Original SVG file, where you can zoom in and view whole function names, see also the image on the right)

Two problems are apparent, I annotated them on the image:

  1. [blue circles] We parse the wikitext of the page 5 times, which is definitely way too many (at most 2 would be reasonable, one for the current user viewing the page and one canonical parse using default settings for non-logged-in users).

    This probably affects production wikis as well, but caching and job queue setup might make it less bad. In particular, the last 2 parses happening inside DeferredUpdates probably are executed in the job queue in production.
  1. [green circles] Within each parse, about half of the time is spent waiting on HTTP requests (using the Guzzle library), which are probably fetching image data from Commons.

    This is specific to the setup on Patchdemo, in production wikis this is done more efficiently with direct database queries.

I'm not sure what we can (or should) do about these, I'm stopping here for now and might look at this more next week.

[green circles] Within each parse, about half of the time is spent waiting on HTTP requests (using the Guzzle library), which are probably fetching image data from Commons.

I think this is T235551.

ppelberg renamed this task from Difficulty posting comments with topic subscription prototype to Investigate why comments are slow to post on patchdemo.Apr 7 2021, 5:23 PM
ppelberg moved this task from Doing to Ready for Sign Off on the Editing-team (Kanban Board) board.