o/
Prior to Thursday, 28th September, if your client-side EventLogging instrumentation logged event via mw.track, then only events tracked during the first pageview of a user's session were logged.
Now, technically, the events weren't ignored or dropped. Instead, the subscriber for the "event" topic was never subscribed when the module was loaded from the ResourceLoader's cache and so events published on that topic simply weren't received and logged.
This bug was discovered while testing some instrumentation maintained by Readers Web [0] and independently by Timo Tijhof, who submitted the ideal fix [1] promptly.
-Sam
[0] https://phabricator.wikimedia.org/T175918 [1] https://gerrit.wikimedia.org/r/#/c/378804/
--- Engineering Manager Readers
Timezone: BST (UTC+1) IRC (Freenode): phuedx
Thanks for the post, this bug will definitely bias any data people got with mw.track. If the data is found to be so broken as to be useless, should we delete it up through the date the fix goes live? Asking people who use mw.track, not Sam
On Thu, Oct 12, 2017 at 6:41 AM, Sam Smith samsmith@wikimedia.org wrote:
o/
Prior to Thursday, 28th September, if your client-side EventLogging instrumentation logged event via mw.track, then only events tracked during the first pageview of a user's session were logged.
Now, technically, the events weren't ignored or dropped. Instead, the subscriber for the "event" topic was never subscribed when the module was loaded from the ResourceLoader's cache and so events published on that topic simply weren't received and logged.
This bug was discovered while testing some instrumentation maintained by Readers Web [0] and independently by Timo Tijhof, who submitted the ideal fix [1] promptly.
-Sam
[0] https://phabricator.wikimedia.org/T175918 [1] https://gerrit.wikimedia.org/r/#/c/378804/
Engineering Manager Readers
Timezone: BST (UTC+1) IRC (Freenode): phuedx
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Please have in mind that hiting this bug is a race condition and it is hit in a minority of cases, not all times. The essence of the bug has to do with the subscription to the "load" event. In some instances the event had already happened by the time the EL code was loaded.
Thanks,
Nuria
On Thu, Oct 12, 2017 at 7:35 AM, Dan Andreescu dandreescu@wikimedia.org wrote:
Thanks for the post, this bug will definitely bias any data people got with mw.track. If the data is found to be so broken as to be useless, should we delete it up through the date the fix goes live? Asking people who use mw.track, not Sam
On Thu, Oct 12, 2017 at 6:41 AM, Sam Smith samsmith@wikimedia.org wrote:
o/
Prior to Thursday, 28th September, if your client-side EventLogging instrumentation logged event via mw.track, then only events tracked during the first pageview of a user's session were logged.
Now, technically, the events weren't ignored or dropped. Instead, the subscriber for the "event" topic was never subscribed when the module was loaded from the ResourceLoader's cache and so events published on that topic simply weren't received and logged.
This bug was discovered while testing some instrumentation maintained by Readers Web [0] and independently by Timo Tijhof, who submitted the ideal fix [1] promptly.
-Sam
[0] https://phabricator.wikimedia.org/T175918 [1] https://gerrit.wikimedia.org/r/#/c/378804/
Engineering Manager Readers
Timezone: BST (UTC+1) IRC (Freenode): phuedx
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Regarding "minority of cases", is this based on a quantitative estimate? I would be interested to learn more about this.
In any case though, Nuria is correct in pointing out that it's less than 100% - it's certainly possible that events are being sent again later in the session (this happened e.g. when I reproduced the bug here: https://phabricator.wikimedia.org/T175918#3612580 , and is also evident in data e.g. from the previous Popups experiments).
On Thu, Oct 12, 2017 at 2:14 PM, Nuria Ruiz nuria@wikimedia.org wrote:
Please have in mind that hiting this bug is a race condition and it is hit in a minority of cases, not all times. The essence of the bug has to do with the subscription to the "load" event. In some instances the event had already happened by the time the EL code was loaded.
Thanks,
Nuria
On Thu, Oct 12, 2017 at 7:35 AM, Dan Andreescu dandreescu@wikimedia.org wrote:
Thanks for the post, this bug will definitely bias any data people got with mw.track. If the data is found to be so broken as to be useless, should we delete it up through the date the fix goes live? Asking people who use mw.track, not Sam
On Thu, Oct 12, 2017 at 6:41 AM, Sam Smith samsmith@wikimedia.org wrote:
o/
Prior to Thursday, 28th September, if your client-side EventLogging instrumentation logged event via mw.track, then only events tracked during the first pageview of a user's session were logged.
Now, technically, the events weren't ignored or dropped. Instead, the subscriber for the "event" topic was never subscribed when the module was loaded from the ResourceLoader's cache and so events published on that topic simply weren't received and logged.
This bug was discovered while testing some instrumentation maintained by Readers Web [0] and independently by Timo Tijhof, who submitted the ideal fix [1] promptly.
-Sam
[0] https://phabricator.wikimedia.org/T175918 [1] https://gerrit.wikimedia.org/r/#/c/378804/
Engineering Manager Readers
Timezone: BST (UTC+1) IRC (Freenode): phuedx
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Regarding "minority of cases", is this based on a quantitative estimate? I would be interested to learn more about this.Yes, this is race
condition, subscribing to onload is an anti-pattern as it is not a promise, but more often than not it would have worked fine. You can see that on the data too (which might make more sense to you) the fix went live on 2017-09-28 and you can see no noticeable increase on NavigationTiming events: https://grafana.wikimedia.org/dashboard-solo/db/eventlogging-schema?orgId=1&... var-schema=NavigationTiming&from=1505250864328&to=1507842864328&panelId=9
In the Popup case you might have hit this race condition perhaps more often (that can be), it will be easy enough to verify when you set up your next experiment.
Thanks,
Nuria
On Thu, Oct 12, 2017 at 9:33 PM, Tilman Bayer tbayer@wikimedia.org wrote:
Regarding "minority of cases", is this based on a quantitative estimate? I would be interested to learn more about this.
In any case though, Nuria is correct in pointing out that it's less than 100% - it's certainly possible that events are being sent again later in the session (this happened e.g. when I reproduced the bug here: https://phabricator.wikimedia.org/T175918#3612580 , and is also evident in data e.g. from the previous Popups experiments).
On Thu, Oct 12, 2017 at 2:14 PM, Nuria Ruiz nuria@wikimedia.org wrote:
Please have in mind that hiting this bug is a race condition and it is
hit
in a minority of cases, not all times. The essence of the bug has to do
with
the subscription to the "load" event. In some instances the event had already happened by the time the EL code was loaded.
Thanks,
Nuria
On Thu, Oct 12, 2017 at 7:35 AM, Dan Andreescu <dandreescu@wikimedia.org
wrote:
Thanks for the post, this bug will definitely bias any data people got with mw.track. If the data is found to be so broken as to be useless, should we delete it up through the date the fix goes live? Asking
people
who use mw.track, not Sam
On Thu, Oct 12, 2017 at 6:41 AM, Sam Smith samsmith@wikimedia.org
wrote:
o/
Prior to Thursday, 28th September, if your client-side EventLogging instrumentation logged event via mw.track, then only events tracked during the first pageview of a user's session were logged.
Now, technically, the events weren't ignored or dropped. Instead, the subscriber for the "event" topic was never subscribed when the module was loaded from the ResourceLoader's cache and so events published on that topic simply weren't received and logged.
This bug was discovered while testing some instrumentation maintained by Readers Web [0] and independently by Timo Tijhof, who submitted the ideal fix [1] promptly.
-Sam
[0] https://phabricator.wikimedia.org/T175918 [1] https://gerrit.wikimedia.org/r/#/c/378804/
Engineering Manager Readers
Timezone: BST (UTC+1) IRC (Freenode): phuedx
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
-- Tilman Bayer Senior Analyst Wikimedia Foundation IRC (Freenode): HaeB
Analytics mailing list Analytics@lists.wikimedia.org https://lists.wikimedia.org/mailman/listinfo/analytics
Hey all,
It turns out that I wasn't subscribed to this list before I started the thread :/ I tried to respond with the following to with Thunderbird after reading through the thread via Gmane and directly but neither approach worked.
On 13/10/2017 16:04, Nuria Ruiz wrote:
Regarding "minority of cases", is this based on a quantitative
estimate? I would be interested to learn more about this.Yes, this is race condition, subscribing to onload is an anti-pattern as
it is not a promise, but more often than not it would have worked fine. You can see that on the data too (which might make more sense to you) the fix went live on 2017-09-28 and you can see no noticeable increase on NavigationTiming events: https://grafana.wikimedia.org/dashboard-solo/db/eventlogging -schema?orgId=1&var-schema=NavigationTiming&from= 1505250864328&to=1507842864328&panelId=9https://grafana.wikimedia.org /dashboard-solo/db/eventlogging-schema?orgId=1&var-schema= NavigationTiming&from=1505250864328&to=1507842864328&panelId=9
In the Popup case you might have hit this race condition perhaps more often (that can be), it will be easy enough to verify when you set up your next experiment.
Thanks,
Nuria
Hey Nuria,
I've double-checked the implementation of the NavigationTiming instrumentation and I believe that it wouldn't have been affected by this bug. The instrumentation uses `mw.eventLog.logEvent` (or `.logFailure`) directly to log events [0] and not `mw.track`. Moreover, those lines that send the NavigationTiming events haven't been touched in two years or more [1].
A good example of the effect that the fix had would be the MobileWebSearch schema [2].
Regardless, I'm glad we have data to suggest that the bug didn't have as much of an impact as I originally suggested.
Thanks!
-Sam
[0] https://github.com/wikimedia/mediawiki-extensions-Navigation Timing/blob/0d4d7a664e/modules/ext.navigationTiming.js#L206-L209 [1] https://github.com/wikimedia/mediawiki-extensions-Navigation Timing/blame/0d4d7a664e/modules/ext.navigationTiming.js#L206-L209 [2] https://grafana.wikimedia.org/dashboard/db/eventlogging-sche ma?orgId=1&var-schema=MobileWebSearch&from=1505952000000&to=1507161600000