Page MenuHomePhabricator

[Session Length] Missing sessions
Closed, ResolvedPublic

Description

In a few analyses, we have begun to suspect that we are recording fewer sessions than we should expect given our pageviews, unique devices, and chosen sampling rate. We wondered if the sessionTick instrument was perhaps not sending tick 0 immediately on page load, but was instead waiting until after the first interval (tick) had passed. However this was not the case. As written, tick 0 should be sent immediately on page load. There could be some latency from the event output buffer (which we should measure and quantify or work around if necessary), but not enough to explain the numbers we see.

While testing on Firefox 80.0, it was found that sessionTick events would not fire, and the reason was traced to mw.requestIdleCallback, which is simply window.requestIdleCallback during these tests, pointing perhaps to an upstream bug in detecting idle states. Adding a manual timeout value (50ms was chosen, in line with the requestIdleCallback polyfill in mw.startup) solved the issue.

It's unknown how many browsers may be affected by this, or if this alone explains the missing sessions. I will update the description as we learn more.

Needed for QA:

Event Timeline

Change 672722 had a related patch set uploaded (by Jason Linehan; owner: Jason Linehan):
[mediawiki/extensions/WikimediaEvents@master] [BUG] sessionTick: Ensures requestIdleCallback fires in <=50ms

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

jlinehan renamed this task from [Session Length] Send tick 0 after page loads to [Session Length] Missing sessions.Mar 16 2021, 1:38 PM
jlinehan updated the task description. (Show Details)
jlinehan added a subscriber: Krinkle.

See also https://codepen.io/Krinkle/pen/XNGEvv which may be of help. Consider using (or asking for, check officewiki) a BrowserStack account to pinpoint if this is a recent Ff regression.

Alternatively, which steps can I use to reproduce this bug?

How may I reproduce this bug?

See also https://codepen.io/Krinkle/pen/XNGEvv which may be of help.

Hmm, codepen works fine for me. Maybe it isn't upstream then? Here is a screenshot. To try and reproduce, if you go to devwiki in FF and paste

window.requestIdleCallback( function() { mw.log.warn("I should print"); } )

in the web console, at least for my FF80 and vagrant instance, the callback will never fire.

requestIdleTimeout.png (1×1 px, 155 KB)

Note I cannot reproduce this in production. It may have something to do with my vagrant environment. Related to the particular question of session length, it does appear that the first tick is hitting the trackQueue within a couple of seconds of pageload on FF80 (see screenshot). Still troubleshooting.

hmm.png (448×1 px, 174 KB)

Works for me both in prod on HTTPS and on localhost over HTTP, using my regular browser (latest Firefox stable, macOS; Firefox 86.0).

cap.png (1×2 px, 577 KB)

Works for me both in prod on HTTPS and on localhost over HTTP, using my regular browser (latest Firefox stable, macOS; Firefox 86.0).

Determined cause of missing sessions to be unrelated to this, I assume this is a misconfiguration with my local environment somehow, so @Krinkle no need to follow up further on this I think. Thanks for your help, sorry for the distraction.

Description of bug (in the instrument) is on the patch notes. Only one of 'sessionReset' or 'sessionTick' could be sent at a time, and since 'sessionReset' is sent when a new session starts, this was preventing us from receiving a 'sessionTick' event right away from newly-started sessions. Patch to correct this is uploaded now. Thanks @mpopov and @Mholloway for helping to troubleshoot.

Change 672722 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@master] [BUG] sessionTick: Tick right away on sessionReset

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

Change 672821 had a related patch set uploaded (by Mholloway; owner: Jason Linehan):
[mediawiki/extensions/WikimediaEvents@wmf/1.36.0-wmf.35] [BUG] sessionTick: Tick right away on sessionReset

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

Change 672821 merged by jenkins-bot:
[mediawiki/extensions/WikimediaEvents@wmf/1.36.0-wmf.35] [BUG] sessionTick: Tick right away on sessionReset

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

Mentioned in SAL (#wikimedia-operations) [2021-03-17T18:57:59Z] <catrope@deploy1002> Synchronized php-1.36.0-wmf.35/extensions/WikimediaEvents/: sessionTick: Tick right away on sessionReset (T277515) (duration: 01m 10s)

@jlinehan: Six months later, should this task still remain open? Asking as all patches have been merged.