Page MenuHomePhabricator

opened in new tab events logged incorrectly for hovercards off group in chrome
Closed, ResolvedPublic5 Story Points

Description

From: https://phabricator.wikimedia.org/T145665#2703398, opened in new tab events seem to be logging incorrectly in Chrome for the hovercards off group, with total interaction time recorded much lower than expected.

Original comment:
This may be specific to Chrome – I'm using Chrome (53.0.2785.143) – but ⌘-clicking a link will trigger a focus DOM event whereas right-clicking the link and selecting "Open Link in New Tab" won't. This focus event zeroes the timing data for this link interaction.

Related Objects

Event Timeline

There are a very large number of changes, so older changes are hidden. Show Older Changes
ovasileva triaged this task as High priority.Oct 11 2016, 3:09 PM
ovasileva moved this task from Incoming to Upcoming on the Readers-Web-Backlog board.
Jdlrobson moved this task from To Do to Doing on the Reading-Web-Sprint-83-Y? board.
Jdlrobson updated the task description. (Show Details)Oct 12 2016, 9:40 PM

I'm not sure what the guidance is for solving this.

If you right click a link you trigger a mouseleave/blur event which hides the popup.

The only way I can think to solve this is as follows:
Don't log anything in this situation - if the user is using the right clicking on a link (not the hovercard) are they really interacting with hovercards?

Thoughts?

I've written some hygiene patches during my investigations to untangle what's going on here - Ia9f4ae6e343c9114c9fde7d9e98899d4eb43998a

Someone should feel free to take this over from me before next standup.
I've been mostly getting familiar with the logging code and trying to get it to a position where I can add unit tests and keep it in one place. @Jhernandez you've got mail => https://github.com/joakin/hovercards-tests/pull/1
@ovasileva => https://phabricator.wikimedia.org/T147846#2710768

Just to clarify:

  • right-clicking does not trigger a focus event and is recorded correctly
  • ⌘-clicking triggers a focus event which zeroes the time causing the low interaction times

Do we have a way of filtering these?
How do we track ⌘-click on other browsers?
Do we know why this is only an issue for hovercards off? (is it?)

I'm not sure what the guidance is for solving this.
If you right click a link you trigger a mouseleave/blur event which hides the popup.
The only way I can think to solve this is as follows:
Don't log anything in this situation - if the user is using the right clicking on a link (not the hovercard) are they really interacting with hovercards?
Thoughts?

I think they're both important, in terms of measuring interaction times with hovercards on and off.

Hovercards off:

  1. User sees page of interest
  2. User opens in new tab

expected - fairly short interaction time

Hovercards on:

  1. User sees page of interest
  2. User hovers and views hovercards
  3. User continues to open page in new tab

hypothesis - perhaps a longer interaction time? (assuming they're reading the hovercard)

Change 315583 had a related patch set uploaded (by Phuedx):
Log events in one central place

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

phuedx added a subscriber: phuedx.Oct 13 2016, 1:03 PM

I've written some hygiene patches during my investigations to untangle what's going on here - Ia9f4ae6e343c9114c9fde7d9e98899d4eb43998a

@gerritbot can write that comment for you!

Do we know why this is only an issue for hovercards off? (is it?)

IIRC it is only an issue for the Hovercards OFF. Hovercards ON keeps track of which link was last interacted with by the user so that it can handle situations like this.

I believe this task is effectively a duplicate of T142723: Title attributes not properly removed on hover. Fixing the problems with the focus event described in that task will most likely solve this issue as I believe some of the logging is done from the related code. I'd like to suggest merging this task into T142723 and pulling T142723 into the sprint. We can always reopen this task if it turns out the two are not related.

I'm sorry, I've not made much progress on this. The event logging is a maze and I'm really keen to make this code easier for us all to work with.

Devs: We currently bind data to every single link and use this when we log. I'd rather we were event driven and let the events set this data in one central place. For example there are 2 events we do not log but events in the Hovercards lifecycle - the hovering of a link and the display of the hovercard. I'd like to record when these events happen and use them to drive the population of the data we log. So for example perceivedWait would be calculated on a display event and dwellStartTime on a hover event. I wanted to check this sounds sane to everyone before continuing with this approach. I've jotted some rough ideas down in patch form here:
https://gerrit.wikimedia.org/r/315862

If anyone has a better idea for an approach also please chip in with those ideas.

I'm sorry, I've not made much progress on this. The event logging is a maze and I'm really keen to make this code easier for us all to work with.

IMO, that would be amazing and worth the time, even if it takes a little while, especially considering all the issues we've had. Do you have any more concrete ideas on how to organize this?

@Jdlrobson: We use this same approach in MobileWebSearchLogger. The tests are also easy to read as they simply send events in (by triggering the event handlers) and make asserts about the events sent out.

Change 316481 had a related patch set uploaded (by Jdlrobson):
Multiple hover events should not clear dwellStartTime

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

Okay I've got a simplified approach I'm happy to run with for the time being. I've opened up a new task T148468 to describe the things that I'm seeing that I do not like.

I've not sure if it's out of scope for this task, but if a user right clicks on a menu and clicks a link, it's worth pointing out we don't currently log a "opened in new tab" event.

@phuedx is there actually a way to view your comments in diffusion or a way to navigate to the gerrit patch via these links you paste? I see no way....

See the ChangeId property in the Details section of the Diffusion page.

This comment was removed by jhobs.

I misread your comment, ignore my previous response.

@Jdlrobson: In future, could you keep hygiene changes like rEPOP7dfad14da17c: Directory structure should reflect the ResourceLoader definitions out of the change of changes? While it's a useful change, it's not clear to me why it's critical, i.e. why it should block merging the other changes that fix this bug.

phuedx added a comment.EditedOct 20 2016, 11:11 AM

Further to my review of PS3 of rEPOPee1db4eda616: Event and hover events are logged but not recorded and T147846#2717292, I drew the following, which I hope clarifies what I was thinking:

@phuedx as I explained earlier the hygiene patches helped me understand the code and problem so was necessary and critical for me to get this work done, even if they seem unrelated to the goal. I was getting extremely confused with what code went where and when it was loaded.

Jdlrobson added subscribers: pmiazga, bmansurov.EditedOct 21 2016, 5:01 PM

Update on this task - please help:

I'm hoping rEPOP7dfad14da17c: Directory structure should reflect the ResourceLoader definitions helps reviewers too but I should note that if it's really seen as getting in the way you can manually cherry pick the patch that follows onto the master branch without problem (note not via Gerrit interface as Gerrit cannot handle renaming folders).

rEPOP74231eba4a86: Hygiene: Remove dead code is +2ed. If someone is impatient and would like to see this merged see above comment, this can easily be merged now.

rEPOP9ea5d8dbcc84: Hygiene: Rename track topic to be more consistent with new plans has been amended and needs review. Hopefully +2able.

rEPOP87e7b0520ac7: Event and hover events are logged but not recorded is -1ed by Sam but I've replied to his comments and am waiting for a reply on rEPOP7b37314cc4a8: ext.popups.schemaPopups manages logic of whether to log events. @jhobs @Jhernandez
@bmansurov @pmiazga input encouraged.

rEPOP6df26eedbbf4: Multiple hover events should not clear dwellStartTime which finally fixes the problem is still needing some kind of review.

NHarateh_WMF set the point value for this task to 5.Oct 24 2016, 4:19 PM

I've reviewed rEPOP366eddd7addf: Hygiene: Rename track topic to be more consistent with new plans but it needs testing and I'm about to go on a break.

… and rEPOP073075936018: Hygiene: Move logic for duplicate events into getMassagedData needs a little work but looks promising.

@Jdlrobson: I'm having a hard time following the chain in Gerrit. The new interface lists a lot of related commits, which change as you move through the chain. Could you list the changes that need merging again?

Jdlrobson added a comment.EditedOct 25 2016, 6:08 PM

I'm having a hard time myself and I wrote them :)
I'm having a lot of trouble rebasing so please focus on the earlier patches in the chain - I want some reassurance I am taking the right approach.

Remaining patches are:

rEPOP7b37314cc4a8: ext.popups.schemaPopups manages logic of whether to log events

I'm sorry, I've not made much progress on this. The event logging is a maze and I'm really keen to make this code easier for us all to work with.
Devs: We currently bind data to every single link and use this when we log. I'd rather we were event driven and let the events set this data in one central place. For example there are 2 events we do not log but events in the Hovercards lifecycle - the hovering of a link and the display of the hovercard. I'd like to record when these events happen and use them to drive the population of the data we log. So for example perceivedWait would be calculated on a display event and dwellStartTime on a hover event. I wanted to check this sounds sane to everyone before continuing with this approach. I've jotted some rough ideas down in patch form here:
https://gerrit.wikimedia.org/r/315862

So from the data analysis perspective, things have been facilitated a little by the fact that the schema was designed to log only one event per link interaction (apart from the case of "tapped settings cog" + "disabled", which occurred only very rarely in the huwiki experiment).
But I agree that expanding the schema in this way could make sense - it will cause a little extra work during analysis, but should also yield some useful additional information.

I have made a state diagram for the current Schema:Popups instrumentation, which should also help thinking about these issues. E.g. the two additional events you propose would correspond to the arrows on the bottom right and top center left.


(Source is here - feel free to fix or tweak things, or to fork it for other purposes like documenting such proposed future versions of the schema.)

That's a great diagram @Tbayer

phuedx added a comment.EditedOct 27 2016, 2:48 PM

Notes that I've made while reviewing @Jdlrobson's change:

  • When the page loads I should see a page loaded event 👍
  • After the page has loaded, when I hover over a link and left-click it I should see an opened in same tab event 👍
    • Should the event have the perceivedWait property?
  • After the page has loaded, when I hover over a link and ⌘-click it I should see an opened in new tab event 👍
    • Should the event have the perceivedWait property?
  • After the page has loaded, when I hover over a link, wait, and then move my mouse away from the link I should see a dwelledButAbandoned event 👍
  • After the page has loaded, when I hover over a link, wait until the popup appears, and then move my mouse away from the link I should see a dismissed event 👍
    • And I repeat the interactions for the same link I should see a dismissed event with a different linkInteractionToken property 👍
      • BUG perceivedWait and totalInteractionTime always increase.

Notes that I've made while reviewing @Jdlrobson's change:

  • When the page loads I should see a page loaded event 👍
  • After the page has loaded, when I hover over a link and left-click it I should see an opened in same tab event 👍
    • Should the event have the perceivedWait property?

No, only if the link is clicked from within an already rendered card. (At least that has been my understanding, see also the description in the schema documentation, which defines perceivedWait as the "Amount of time (in milliseconds) between the instant the user started dwelling on a link and the instant the preview text rendered visibly, as determined strictly client-side. Not set if hovercards disabled.")

  • After the page has loaded, when I hover over a link and ⌘-click it I should see an opened in new tab event 👍
    • Should the event have the perceivedWait property?

same as above

  • After the page has loaded, when I hover over a link, wait, and then move my mouse away from the link I should see a dwelledButAbandoned event 👍
  • After the page has loaded, when I hover over a link, wait until the popup appears, and then move my mouse away from the link I should see a dismissed event 👍
    • And I repeat the interactions for the same link I should see a dismissed event with a different linkInteractionToken property 👍
      • BUG perceivedWait and totalInteractionTime always increase.

Change 316481 merged by jenkins-bot:
Multiple hover events should not clear dwellStartTime

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

From my review of rEPOP9477fd5fe6a2: Multiple hover events should not clear dwellStartTime:

This LGTM.
I went over all the scenarios described in T147846#2748417 as well as the scenario described in the original bug report. I also re-checked that perceivedWait was being added to events that are logged after the "display" lifecycle event, i.e. "dismissed", "tapped settings cog", "disabled".

phuedx reassigned this task from Jdlrobson to bmansurov.Oct 31 2016, 10:50 AM
phuedx added a subscriber: Jdlrobson.

Signing this off may also cover T145665.

The bug is still happening. Steps to reproduce:

  1. Visit http://reading-web-staging.wmflabs.org/wiki/Book
  2. Hover over the first link, which is the word "ink" in the first paragraph, and wait about 5 seconds.
  3. Command + Click.
  4. Inspect the Network tab, you'll see that the totalInteraction time is around 100ms.

Here is a screencast of the above steps:

bmansurov removed bmansurov as the assignee of this task.Nov 1 2016, 8:29 PM
phuedx assigned this task to bmansurov.Nov 2 2016, 5:51 AM

The staging server wasn't updating every 10 minutes and the Popups codebase was way out of date.

I ran the following and restored the corresponding crontab entry for the vagrant user: cd /srv/mediawiki-vagrant; vagrant git-update.

Thanks, @phuedx.

The interaction time seems to be correct. Opening a link in a new tab using the context menu (right click on the mouse) is sending the "dwelledButAbandoned" and not "opened in new tab" event.

phuedx added a comment.EditedNov 2 2016, 5:04 PM

@bmansurov: I thought that I'd noted this during my review but then I found that @Jdlrobson and I discussed it in IRC.

Which browsers fire an event for a context menu item being clicked? Chrome doesn't appear to.


11:12:48 <phuedx> jdlrobson: hover, wait for popup to appear, right-click and open in new tab -> dismissed event
11:13:33 <jdlrobson> phuedx: what's the problem? it shouldnt fire a dismissed event?
11:14:49 <phuedx> jdlrobson: i //assumed// (keyword) that i'd opened the link in a new tab, that i'd see an opened in new tab event
11:15:32 <phuedx> i can't write a failing test for it as there's no "click" lifecycle event
11:15:53 <jdlrobson> phuedx: https://phabricator.wikimedia.org/T147846#2710768
11:15:53 <jdlrobson> If you right click a link you trigger a mouseleave/blur event which hides the popup.
11:16:00 <jdlrobson> hence the dismissed event
11:16:10 <jdlrobson> The only way I can think to solve this is as follows: Don't log anything in this situation - if the user is using the right clicking on a link (not the hovercard) are they really interacting with hovercards?
11:17:42 <jdlrobson> we can add a click event, but it's also going to trigger a dismissed event
11:17:52 <jdlrobson> which will leave it in an ambiguous state
11:18:39 <jdlrobson> unless im missing something obvious..?
11:20:03 <phuedx> hrrrm
11:20:08 <phuedx> olliv ^
11:20:39 <phuedx> jdlrobson: to your point about "interacting with hovercards": we're logging interactions with links too
11:25:07 <@olliv> jdlrobson:  there's no way to know what they did after the right click?  We should log it as a link interaction either way + whatever they decided to do afterwards.  I agree that they're not really interacting with the hovercard though
11:26:01 <jdlrobson> so consider a case where the hovercard is open and the user right clicks the link
11:26:09 <jdlrobson> say the hovercard stays open
11:27:09 <jdlrobson> if the user clicks any context menu item we can detect it, but i dont think we can detect which one.
11:27:20 <jdlrobson> so if they click copy link in address - what do we do? trigger an open in new tab event?
11:28:32 <jdlrobson> let's say we trigger a new event with an update in schema 'clicked-context-menu-item' we could then end the hovercard lifecycle, trigger the event.
11:30:48 <phuedx> i agree that it's tricky
11:31:57 <phuedx> if there's a dom event associated with the "open link in new tab" entry of the context menu, then i don't see why we shouldn't log it
11:32:34 <phuedx> but if the schema doesn't support this, then we shouldn't extend it right this instant
11:36:13 <phuedx> jdlrobson: okay, chrome doesn't fire such an event
11:39:01 <phuedx> olliv, jdlrobson: yeah i think we can detect the right click but the schema doesn't provide for it at the moment