Some events are out of order
Closed, ResolvedPublic

Description

Looking at events associated with a user from T210003: Deferred update causes "Retrieving hash salt for user ID failed", I see:

  1. 200 GET request to view the WelcomeSurvey
  2. 302 POST request to Special:CreateAccount
  3. 302 POST request to Special:WelcomeSurvey

The correct order should be

  1. 302 POST request to Special:CreateAccount
  2. 200 GET request to view the WelcomeSurvey
  3. 302 POST request to Special:WelcomeSurvey

To fix this, we could do one of the following:

  1. modify the schema to create a custom timestamp property, set this timestamp when we begin the logging process, and @nettrom_WMF can query on this timestamp instead of the one on the eventlogging capsule
  2. Use deferred updates in PRESEND mode for all event logging
  3. Use deferred updates in PRESEND mode for POST requests only

I prefer the last option.

kostajh created this task.Tue, Nov 20, 8:18 PM
Restricted Application added a subscriber: Aklapper. · View Herald TranscriptTue, Nov 20, 8:18 PM

Change 474981 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/WikimediaEvents@master] Transmit POST event logging data in PRESEND mode

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

kostajh claimed this task.

Change 474977 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/WikimediaEvents@master] Initialize hashing salt immediately instead of in deferred update

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

Change 474981 abandoned by Kosta Harlan:
Transmit POST event logging data in PRESEND mode

Reason:
Merged with other 474977

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

Change 474977 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@master] EditorJourney: Adjust DeferredUpdates usage

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

Change 474997 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/WikimediaEvents@wmf/1.33.0-wmf.4] EditorJourney: Adjust DeferredUpdates usage

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

Change 474997 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@wmf/1.33.0-wmf.4] EditorJourney: Adjust DeferredUpdates usage

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

Change 475128 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/WikimediaEvents@master] EditorJourney: Adjust DeferredUpdates usage

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

Change 475128 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@master] EditorJourney: Adjust DeferredUpdates usage

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

Change 475472 had a related patch set uploaded (by Kosta Harlan; owner: Kosta Harlan):
[mediawiki/extensions/WikimediaEvents@wmf/1.33.0-wmf.4] EditorJourney: Adjust DeferredUpdates usage

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

Change 475472 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@wmf/1.33.0-wmf.4] EditorJourney: Adjust DeferredUpdates usage

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

Stashbot added a subscriber: Stashbot.

Mentioned in SAL (#wikimedia-operations) [2018-11-26T19:25:06Z] <ebernhardson@deploy1001> Synchronized php-1.33.0-wmf.4/extensions/WikimediaEvents/includes/: SWAT T210003 T210004 EditorJourney: Adjust DeferredUpdates usage (duration: 00m 46s)

Etonkovidova closed this task as Resolved.Mon, Nov 26, 10:09 PM
Etonkovidova added a subscriber: Etonkovidova.

Checked the fix in betalabs - the order of events is correct now:
For example,

 [log]> select event_user_id,  timestamp, wiki, event_action, event_title, event_page_title, event_request_method from EditorJourney_18504997 where event_user_id=15602 order by timestamp asc\G
*************************** 1. row ***************************
       event_user_id: 15602
           timestamp: 20181126210205
                wiki: enwiki
        event_action: view
         event_title: CreateAccount
    event_page_title: Welcome, ET135!
event_request_method: POST
*************************** 2. row ***************************
       event_user_id: 15602
           timestamp: 20181126210205
                wiki: enwiki
        event_action: view
         event_title: WelcomeSurvey
    event_page_title: Welcome, ET135!
event_request_method: GET
*************************** 3. row ***************************
       event_user_id: 15602
           timestamp: 20181126210231
                wiki: enwiki
        event_action: view
         event_title: WelcomeSurvey
    event_page_title: Welcome, ET135!
event_request_method: POST