Page MenuHomePhabricator

Logging broken for GettingStarted (page-save-success logged as page-impression)
Closed, ResolvedPublic

Description

Author: swalling

Description:
Looking at the logs for the latest GettingStarted schema (GettingStartedNavbar_5496876) I am not finding a page-save-success event since June 6th.

This may have something to do with the VisualEditor split test or maybe not. I am seeing very few events (28 total) of any kind being logged on enwiki after 2013-06-20 when logging for the VE split test was enabled. This is obviously wrong, since there were more than 150 revisions tagged as gettingstarted-edit yesterday alone.


Version: unspecified
Severity: normal

Details

Reference
bz50204

Event Timeline

bzimport raised the priority of this task from to Needs Triage.Nov 22 2014, 2:05 AM
bzimport set Reference to bz50204.

The latest GettingStartedNavbar table is GettingStartedNavbar_5588671 (easiest way to see is SHOW TABLES).

However, that doesn't convincingly explain why the latest (by timestamp) enwiki entries in GettingStartedNavbar_5496876 are a long string of page-save-attempt (the last of which is on 2013-06-26), but the latest page-save-success is 2013-06-06.

It could be a coincidence, but it's worth looking into.

swalling wrote:

(In reply to comment #1)

The latest GettingStartedNavbar table is GettingStartedNavbar_5588671
(easiest
way to see is SHOW TABLES).

Resolving as not a bug, accordingly, because there's no RESOLVED STEVENISDUMB. ;)

swalling wrote:

(In reply to comment #1)

The latest GettingStartedNavbar table is GettingStartedNavbar_5588671
(easiest
way to see is SHOW TABLES).

However, that doesn't convincingly explain why the latest (by timestamp)
enwiki
entries in GettingStartedNavbar_5496876 are a long string of
page-save-attempt
(the last of which is on 2013-06-26), but the latest page-save-success is
2013-06-06.

It could be a coincidence, but it's worth looking into.

Okay, you were correct, this is worth looking in to. In the most recent logs (GettingStartedNavbar_5588671) it seems we are not logging any page-save-success events for the returnto funnel. Logging for other events in the returnto funnel seem normal, and page saves all gettingstarted funnels (copyedit, clarify, addlinks) are normal.

GettingStarted only logs page-save-success if wgPostEdit is true. On my local wiki I printed log messages from the two routines, and they sometimes came out:

about to log returnto page-impression
postEdit.js set wgPostEdit true!

So the postEdit.js is running *after* openTask.js and that's why the wrong event is logged. On enwiki with resourceLoaderDebug cookie it did log a page-save-success event (go look at GettingStartedNavbar_5588671 where event_userId = 19275523), but without the RL debug in regular operation GS logs page-impression.

RL loads postEdit first in its mw.loader.load() call at the end of the page body, but I don't know what RL's guarantee of code execution ordering is.

Adding a dependency to ext.gettingstarted.openTask:

'mediawiki.action.view.postEdit', // need this to run prior

seemed to fix it locally; another fix would be to use

mw.hook( 'postEdit' ).add( function ()

as VE does instead of changing the action from page-impression to page-save-success.

I don't know how VE affects this, this was all clicking [Edit source].

Change 71575 had a related patch set uploaded by Spage:
postEdit module needs to run before openTask

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

Change 71575 merged by jenkins-bot:
postEdit needs to run before GS logging

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

S's patch fixes the post-edit issue locally, which I believe is the same one I mentioned in comment 1.

  • Bug 51208 has been marked as a duplicate of this bug. ***

There are still no page-save-success + returnto events in prod, so there may be an RL issue.

Re-opening until we're sure it's fixed.

A relevant query is:

SELECT COUNT(*) FROM GettingStartedNavbar_5588671 WHERE wiki = "enwiki"
AND event_action = "page-save-success" AND event_funnel = "returnto";

swalling wrote:

https://gerrit.wikimedia.org/r/#/c/71575/ was scheduled to be deployed last week, but we flubbed a bit and it did not go out to 1.22wmf9 until today.

I am still seeing only one page-save-success in the returnto funnel as of today, so the patch not getting deployed may be the likely culprit.

Looks properly fixed with the 2013-07-18 rollout of wmf10 to enwiki that included this fix, plus and later that day the changes to restore GettingStarted after CentralAuth/SUL2 changed.

SELECT LEFT( timestamp, 8), COUNT(*) FROM GettingStartedNavbar_5588671 WHERE wiki = "enwiki" AND event_action = "page-save-success" AND event_funnel = "returnto" GROUP BY 1;

+---------------------+----------+

LEFT( timestamp, 8)COUNT(*)

+---------------------+----------+

201307021
2013071817
20130719235

+---------------------+----------+