Page MenuHomePhabricator

PagePreviews events system sends duplicate and incorrect events
Closed, ResolvedPublic5 Estimated Story Points

Description

AC

  • Check if T161769 is fixed by this as part of sign off. If it isn't pull it into the current sprint.

@Tbayer is reviewing T161769.

QA Steps (Technical)

Run through the scenarios below, making a detailed note of the events that were logged.


Scenario 1:

Action: User hovers a link, waits to show page preview, moves mouse over the page preview, moves mouse away from page preview
Events sent: dismissed (after moving mouse from link to popup), and dismissed again (when moving out of popup)

Scenario 2:

Action: User hovers a link, waits to show page preview, clicks CTRL+click to open link in new tab, moves mouse away from link
Events Sent: opened, dismissed, dismissed
Events Sent: opened, dwelledButAbandoned, dwelledButAbandoned (different scenario, popup was visible, but because some (look below for general issue) reason browser sends dwelledButAbandoned)
Expected events: opened, dismissed

Scenario 3:

Action: User hovers a link, waits to show page preview, moves mouse pointer over the popup, clicks CTRL+click to open link in new tab, moves mouse away from page preview
Events sent: dismissed, dwelledButAbandoned (happens when user moves mouse out of popup over a link)
Events sent: dismissed, dismissed (Chromium, Firefox)
Expected events: opened, dismissed

Scenario 4:

Action: User hovers a link, then moves mouse below the link (where popup will appear), popup appears and stays under mouse
Events sent: dwelledButAbandoned, dwelledButAbandoned
Expected events: dwelledButAbandoned, no popup is shown

Scenario 5:

Action: User hovers a link, popup loads, then quickly moves mouse out of the page preview and then immediately brings mouse back over popup, moves mouse away from page preview
Events sent: dismissed every time mouse leaves the popup, because move gets back over the page preview popup doesn't dismiss, I'm able to send 10-20 dismiss events for same popup (even it stays on top)
Expected events: only one dismissed event when popup actually gets closed

Scenario 6:

Action: Slow connection/network hiccup, user moves mouse over link couple times before AJAX call is made and moves mouse away from link
Events sent: dwelledButAbandoned as many times as mouse was over the link sent after AJAX request is made
Expected events: current scenario is correct (but make sure each dwelledButAbandoned event has a different linkInteractionToken)

Scenario 7:

The killer feature
Action: User hovers a link, popup appears, moves mouse over popup, moves it back over the same link, clicks CTRL+click to open link in new tab, moves mouse away from page preview
Events set: dismissed, dwelledButAbandoned, opened, dwelledButAbandoned, dwelledButAbandoned
Expected events: opened

General issue:

If mouse pointer is over popup, and leaves popup over link (hover over link, hover over popup, hover back over link, move mouse pointer away) browser sends dwelledButAbandoned event even popup was visible

Tested:

  • Chromium 56
  • Firefox 51

For reference:

Related Objects

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes

Change 344103 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] eventLogging: Model interactions in EL reducer

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

Change 344179 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] preview: Add click behavior

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

Change 344180 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] eventLogging: SETTINGS_SHOW logs an event

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

Change 344389 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] eventLogging: Extract createAbandonEvent function

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

Change 344390 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] eventLogging: Log abandon event when user dwells

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

Change 344104 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] renderer: Bind behavior when preview is shown

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

An engineer should QA this first (and second!). @bmansurov: Who's the lucky QA'er?

  • Scenario 4: It's still happening, but not on the first try. Only one dwelledButAbandoned is sent the first time. On subsequent tries I see two events.
  • It's not clear to me how to re-produce the scenario 6. Can someone explain it?
  • The other scenarios seem to have been fixed.

@bmansurov - on a slow connection (download ~30kb/s, latency: ~1s) it takes at least a second/two before client gets AJAX response. In this time (AJAX call is made but no response yet) you can hover over a link couple time.

When AJAX request is completed system starts triggering events. If you place the mouse pointer over a link two times (after each focus user moves mouse somewhere else and then go back over a link) system triggers two (or more depends on how many times mouse was over a link) dwelledButAbandoned event.

As I said current flow is probably correct - but my first assumption was - when AJAX request is made (and still in progress) we shouldn't register new actions for current link.

@bmansurov - on a slow connection (download ~30kb/s, latency: ~1s) it takes at least a second/two before client gets AJAX response. In this time (AJAX call is made but no response yet) you can hover over a link couple time.

When AJAX request is completed system starts triggering events. If you place the mouse pointer over a link two times (after each focus user moves mouse somewhere else and then go back over a link) system triggers two (or more depends on how many times mouse was over a link) dwelledButAbandoned event.

As I said current flow is probably correct - but my first assumption was - when AJAX request is made (and still in progress) we shouldn't register new actions for current link.

Yes, as mentioned above, both alternatives should be OK (i.e. since several hovers happened, several events should be sent ideally, but it would also be tolerable in this situation to send only one dwelledButAbandoned event for that link). In any case though we should still make sure that these events have different link interaction tokens, upholding the general principle that a link interaction ends once the mouse has moved away from both link and card (or a link has been opened). I'm amending the task for description for extra clarity.

I have also amended the expected outcome in scenarios 2 and 3 to clarify that only the opened event should be sent when a link interaction ends in a CTRL-click open (consistent with the state diagram).

.... so does this truly "need more work"? Or should this be doing @phuedx ... not clear what you had in mind when you assigned this to yourself.

@bmansurov I'll pick up the next round of QA, thanks for doing it! (If there's anything left to QA right now let me know).

Change 346970 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] actions: Add token to FETCH_COMPLETE

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

Change 346979 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] reducers: Reduce FETCH_COMPLETE if token matches

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

^ The two changes above should address #1 of T159490#3150331.

Change 346970 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] actions: Add token to FETCH_COMPLETE

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

The above patches have been reviewed. I noticed a JS error in console by hoviring over a link and moving to another link. I don't think I have the exact steps, but the bug is pretty easily reproducible if you have a couple of links next to each other and you dwell on one and move to another etc. This is the error:

Uncaught TypeError: Cannot read property 'token' of undefined at ./src/reducers/eventLogging.js.module.exports

Change 346979 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] reducers: Reduce FETCH_COMPLETE if token matches

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

The above patches have been reviewed. I noticed a JS error in console by hoviring over a link and moving to another link. I don't think I have the exact steps, but the bug is pretty easily reproducible if you have a couple of links next to each other and you dwell on one and move to another etc. This is the error:

Uncaught TypeError: Cannot read property 'token' of undefined at ./src/reducers/eventLogging.js.module.exports

This is also covered by T162373: JS exception in Catalan wiki → TypeError: Cannot read property 'started' of undefined. I believe the bug was highlighted – not caused – by rEPOP82648226ef14: renderer: Bind behavior when preview is shown so I intend to fix it as part of this task. @Jhernandez: If it's alright with you, I'll mark the other task as a duplicate of this one.

Sounds great

I've seen it happen in ABANDON_END, but wasn't able to capture the redux log or anything useful.

Change 347598 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] actions: Add token to PREVIEW_SHOW

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

Change 347599 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] Hygiene: DRY up eventLogging reducer

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

Change 347600 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] reducers: Make PREVIEW_SHOW require a token

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

Change 347598 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] actions: Add token to PREVIEW_SHOW

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

Change 347599 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] Hygiene: DRY up eventLogging reducer

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

Change 347600 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] reducers: Make PREVIEW_SHOW require a token

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

Some local QA, code should be in beta cluster soon.

QAd scenario 1, only one event sent:

{
  "linkInteractionToken": "ad25285cffe6d1a4",
  "totalInteractionTime": 11694,
  "action": "dismissed",
  "previewType": "page"
}

QAd scenario 2, only one event sent when control clicking:

{
  "action": "opened",
  "linkInteractionToken": "8eb3d6b9b99920a7",
  "totalInteractionTime": 6720
}

When you go away from the preview later though, the expected event dismissed is sent because you abandoned the preview:

{
  "linkInteractionToken": "8eb3d6b9b99920a7",
  "totalInteractionTime": 19379,
  "action": "dismissed",
  "previewType": "page"
}

@phuedx Is that the expected behavior?

Do we need to re-QA all the scenarios? probably yes. I'll have a look tomorrow.

@Tbayer Regarding ^

In scenario 2, there are two interactions sent, one when clicking, and another one when hovering out. The scenario is not specific enough with the steps, so only until clicking, it seems correct. But if you account for going off the preview then the dismissed is sent.

Do you want just the click event or both click and dismissed? (Technically the popup is still open when you ctrl click and the interaction is ongoing). Do you want to keep that data and filter it out / be aware of it when analyzing or should we kill the interaction on click even if the popup stays open?

In the State diagram it says that only the click event should be sent (kill interaction on click), even if the popup is still open after a ctrl+click.

Let us know, if you confirm we kill interaction after ctrl click even if the popup is still open then there is some more work to be done on the task.


I'll have a full qa pass tomorrow on the events.

@Jhernandez Indeed, in scenario 2, just the click event should be recorded - as mentioned last week in T159490#3151975 ; that's why the "dismissed" is struck out in the task description.

(This is a bit of a simplification, as we're not accounting for any reading activity on the still open card after the click, but basically we can justify this by considering that in this situation there is already a full pageview being recorded for that article, alongside the viewing of its card before the click.)

^ Per T159490#3172692.

A note for my future (tomorrow morning) self: CLICK events should finalise the interaction in the eventLogging reducer.

Change 347829 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] reducers: Make LINK_CLICK finalize interaction

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

Change 347829 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] reducers: Make LINK_CLICK finalize interaction

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

Done a full QA on Chrome locally, everything seems fine.

  • Scenario 1
  • Scenario 2
  • Scenario 3
  • Scenario 4
    • I'm only seeing one, but the popups some times appear depending on the timing and if the request is cached. This is very hard to reproduce by hand.
  • Scenario 5
  • Scenario 6
  • Scenario 7
  • General issue

Back to doing for @phuedx to do some cleanup/hygiene on the event logging reducer before closing up.

I don't think there are any open patches currently on this...

Change 348266 had a related patch set uploaded (by Phuedx):
[mediawiki/extensions/Popups@master] reducers: Update eventLogging documentation

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

Change 348266 merged by jenkins-bot:
[mediawiki/extensions/Popups@master] reducers: Update eventLogging documentation

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

@pmiazga: There's a minor bug in the code that handles the user clicking a link, which is fixed by rEPOP2c171d7f2550: reducers: Don't destroy interaction on LINK_CLICK. Just something to be aware of while you're re-running the scenarios (#2 specifically). See T162924: PagePreviews sending "dwelledButAbandoned" after "opened" for more detail.

@phuedx - there is an issue:

[Popups] Value null is the wrong type for property "totalInteractionTime" (integer expected)

<anonymous> https://en.wikipedia.beta.wmflabs.org/w/load.php:42:180
	handler https://en.wikipedia.beta.wmflabs.org/w/load.php:154:832
	jQuery.Callbacks/fire https://en.wikipedia.beta.wmflabs.org/w/load.php:45:104
	jQuery.Callbacks/fire https://en.wikipedia.beta.wmflabs.org/w/load.php:45:239
	jQuery.Callbacks/self.fireWith https://en.wikipedia.beta.wmflabs.org/w/load.php:46:431
	jQuery.Callbacks/self.fire https://en.wikipedia.beta.wmflabs.org/w/load.php:46:474
	mw.track https://en.wikipedia.beta.wmflabs.org/w/load.php:154:614
	Schema.prototype.log https://en.wikipedia.beta.wmflabs.org/w/load.php:133:222
	["./src/changeListeners/eventLogging.js"]/module.exports/< https://en.wikipedia.beta.wmflabs.org/w/load.php:69:684
	["./src/changeListener.js"]/module.exports/< https://en.wikipedia.beta.wmflabs.org/w/load.php:69:429
	dispatch https://en.wikipedia.beta.wmflabs.org/w/load.php:55:722
	createThunkMiddleware/</</< https://en.wikipedia.beta.wmflabs.org/w/load.php:50:404
	dispatch https://en.wikipedia.beta.wmflabs.org/w/load.php:58:566
	["./src/actions.js"]/actions.linkDwell/< https://en.wikipedia.beta.wmflabs.org/w/load.php:68:22
	createThunkMiddleware/</</< https://en.wikipedia.beta.wmflabs.org/w/load.php:50:356
	bindActionCreator/< https://en.wikipedia.beta.wmflabs.org/w/load.php:58:964
	["./src/index.js"]/</</< https://en.wikipedia.beta.wmflabs.org/w/load.php:80:897
	jQuery.event.dispatch https://en.wikipedia.beta.wmflabs.org/w/load.php:65:913
	jQuery.event.add/elemData.handle https://en.wikipedia.beta.wmflabs.org/w/load.php:60:459

Failing scenario: 5
Hover a popup, wait till popup appears, then quickly move mouse around the popup so the popup stays visible but mouse leaves the popup area couple times. Difficult to reproduce but possible

Sentry event_Id: bd703a6e020e4d219f0499b36ef8c69c

Looks like the main problem is fixed. A minor related bug is being solved in T162924. While testing I found two smaller issues - T163350 and T163348