Extension:EventLogging

To measure the effects of changes in MediaWiki's user interface we need to collect aggregate data on how users (both readers and authenticated editors) interact with specific UI elements. Several WMF projects used Extension:ClickTracking to this aim – an extension that was originally developed in the context of the Usability Initiative which suffers from numerous problems and limitations. This page describes an improved method for logging user-generated events that the E3 team is developing.

Background
The ClickTracking extension has been used in the past few years to collect data about user-generated events in the context of product development analysis. Examples include: When used for this purpose, the format and type of data collected has been documented on Meta, see for example the clicktracking specifications for Article Feedback project. Logging user-generated events via the ClickTracking API imposes several constraints on the data format and raises major scalability concerns. The new event logger is redesigned to be agnostic about the type of event-related data that needs to be collected and to overcome performance/scalability issues.
 * counting impressions and measuring click-through and conversion rates of various calls to action;
 * measuring the breakdown of clicks on inbound links pointing to a special page;
 * ensuring that the sampling/bucketing methods used for the purpose of A/B testing are accurate;

Event data
All events collected by the logger include the following set of required data: Event identifiers fall into one of these broad categories: Event identifiers can also include bucket or user group information, used in the context of A/B tests. The log can include additional data for each event, such as link targets, user data made available in JS variables, computed values such as time on page, etc. All data collected by the event logger is subject to the Wikimedia Foundation's privacy policy.
 * 1) an event identifier
 * 2) a timestamp
 * 3) an anonymous token assigned to the client
 * impressions of a page or a UI element
 * clicks on specific UI elements
 * form submit actions
 * server-generated events

Logging events in JavaScript
Event data is logged in the form of key-value arrays that are sent by the client as requests to a URL such as:  http:// bits.wikimedia.org/event.gif?key=val&foo=bar&... there are limitations on Ajax XMLHttpRequest cross-domain policies, etc.
 * URLEncode nested structures like JSON
 * so in JavaScript (jQuery or other DOM manipulation) just create an img and set this as its src URL

bits.w.o is served by separate cluster with a varnish front-end (not squid). varnish can do simple responses, so configure it to return HTTP 204 "No content"
 * supported even by older browsers

Varnish "logging" just fills a shared memory segment circular buffer. A separate command-line tool `varnishlog` can filter on the pattern "event.gif" and pipe to a tool that sends stdin to the log collection machine "vanadium"
 * (see for syntax)

limits
 * query string is limited (by whom? browsers, network layers... ?) to 2000 characters in some cases, so system will emit an error if data goes over.
 * don't send Unicode data, so have to encode them somehow.

For more than 2000 characters, and in general, send a hash or some other ID that the back-end can related to database information. E.g. username hash to relate to previous actions, or userID of logged in user to relate to edit counts.

Transmitting event data
The sending tool is zpub, the receiver on vanadium is zsub, these are very simple C programs Ori wrote that use the ZeroMQ intelligent light-weight transport layer. One publishes the events in the varnish logs, the other subscribes to the events.
 * ZeroMQ has lots of useful features: lightweight, handles one end or the other going away, etc.
 * interest in it from other teams

is packaged, puppetized, and primed for production.

Processing logged events
The listener on the log collection machine "vanadium" is zsub, subscribing to the ZeroMQ publisher. So the listener receives the log of the http:// bits.wikimedia.org/event.gif?key=val&foo=bar&...request, extracts the key-value pairs, and stores them in:

Storing event data
Vanadium will run redis, a distributed key-value store, to store user-generated event data.

Redis has features beyond memcache :
 * can nest a set of key-value pairs inside a key, e.g. 'ori' can have user_id => xy, lastview -> abc
 * has sorted sets
 * the sorted set is sorted by a score, e.g. timestamp, or userid
 * say an event comes in, first goes to the sorted set for the event_id
 * this is what's useful for rev tagging, which is annotating an edit with additional information (rather than trying to add columns to the page table)
 * redis server can override timestamp if it's too out of sync
 * has its own pub-sub, so a connector can watch for certain kinds of events coming in and hook them back into mySQL. Or can do batch import.

So vanadium's redis stores all the key-value info from events. For analysis, we could import data sets from vanadium into another redis instance on another system, or import into a conventional SQL database.

This redis part might be replaced by Kraken project from Analytics.

Hadoop might be a more efficient solution for much larger datasets, but redis is very performant.

Data Model

 * transcluded from subpage /Data model

Current implementation

 * ''obsolete, see Event logging

is a test Node implementation of serializing query strings into redis.

It's not currently hooked into ZeroMQ, it's responding directly to HTTP requests. However it's simple matter to change it to read URLs from stdin, and then pipe the output of zsub to it.

Event logging vs Extension:ClickTracking

 * the log line generated by CT always includes the user data isLoggedIn and (if logged in) edit count and edit counts over three time periods. The new approach doesn't have the overhead of retrieving these, but
 * the JS code issuing track events has access to most of the same information in JavaScript variables and can add it to the track action.
 * or back-end analytics code can relate a logged-in user to the same info from DB tables.
 * CT sets a non-persistent token in the clicktracking-session cookie when it issues a track action
 * E3 Experiments add data to the userbuckets cookie when bucketing users in an experiment
 * there are many other tokens available, e.g. the mediaWiki.user.id cookie issued by JS mw.user.id, etc.

Persistent anonymous user token
In October E3 code began generating and setting a mediaWiki.user.id anonymous user token cookie for all users who view any page on en-wiki (in experiments/openTasks.js). This is a 32-character random (using Math.random) identifier.
 * the user gets a different cookie if the user clears cookies.
 * if multiple users use the same browser, they will all share the same cookie

The same cookie is also set by the JavaScript mw.user.id function if a user is not logged in to the wiki (otherwise mw.user.id returns the user's login name). Article Feedback Tool 4 calls this function when a user submits article feedback. ACUX v1 also alls this function for all new users creating an account.

Notes:
 * user.id is a bad confusing name. The function mw.user.id either returns a logged-in user's username, or an anonymous token; the cookie mediaWiki.user.id always holds this anonymous token. Neither is anything to do with the user_id in the user table, a numeric identifier associated with a particular user that is available in PHP as $wgUser->getId.
 * Also note that this "anon user token" is unrelated to the user_token in the user table, which may be made available as the session cookie "{$wgCookiePrefix}Token" if you check Remember my login on this browser at login.

Other cookies

 * ClickTracking has clicktracking-session, but this is not persistent. Can't link a user action to events that happen later unless is bucketed and/or logs in.
 * E3Experiments has its e3token (in lib/track.js) which is a murmurhash3 of the username (if logged in) or the time. This randomizes the username or time, so that bucketing based on it is predictable yet random. The function e3.track logs this as 'token', but in October 2012 is seemingly unused.
 * There is a similar session cookie "{$wgCookiePrefix}Session"
 * The JS function, mw.user.sessionId, stores a random token similar to user.id in a session cookie named mediaWiki.user.sessionId. spage hasn't yet found code invoking this.
 * CentralAuth sets additional session and token cookies.

Transition
Diederik's team is happy to have E3 develop this

Analytics is happy for E3 to use this in the interim while Kraken is developed, and for the general zpub send to back-end approach.

Hoping to test this on labs, varnish and redis are in place on various servers.

Currently WMF has imposed a limit on ClickTracking usage, so we only sample a small percentage of impressions. The new system should be better, but can only identify new limit of new system in production.

Probably leave the existing ClickTracking extension running, and transition E3 experiments over to using this improved version. Clients continue to call $.trackAction and similar JavaScript functions, but their implementation will change, from XMLHttpRequests of api.php, to requests of the event.gif.

Early feedback
Tim Starling:
 * Instead respond with status 200 empty response? but empty response can make browser wait, and 204 well-supported.
 * Instead use the upcoming varnish patch to send UDP messages? but using a message queue decouples the notification from varnish
 * Why not then use this approach for other Wikimedia projects? their call.

Alternatives
We could cut out the middlemen and request the beacon image from a new analytics.wikimedia.org domain, route this directly to the Node server, and have Node return the status 204 as well as feeding the key-value pairs into Redis. Fewer layers, but:
 * node not optimized for traffic
 * we can rely on varnish front-end to filter out extraneous and bogus requests
 * by piggybacking off bits.w.o, we get its geographical replication