diff --git a/extension.json b/extension.json index bb2194b93..21c096367 100644 --- a/extension.json +++ b/extension.json @@ -55,7 +55,8 @@ "dependencies": [ "rangefix", "ext.discussionTools.parser", - "ext.discussionTools.modifier" + "ext.discussionTools.modifier", + "ext.discussionTools.logger" ], "messages": [ "discussiontools-error-comment-disappeared", @@ -64,6 +65,14 @@ "discussiontools-replywidget-loading" ] }, + "ext.discussionTools.logger": { + "packageFiles": [ + "logger.js" + ], + "dependencies": [ + "mediawiki.util" + ] + }, "ext.discussionTools.init": { "packageFiles": [ "dt.init.js" @@ -100,6 +109,7 @@ ], "dependencies": [ "ext.discussionTools.controller", + "ext.discussionTools.logger", "mediawiki.widgets.AbandonEditDialog" ] }, diff --git a/modules/controller.js b/modules/controller.js index a0b70cc33..3faeddfcd 100644 --- a/modules/controller.js +++ b/modules/controller.js @@ -3,6 +3,7 @@ var parser = require( 'ext.discussionTools.parser' ), modifier = require( 'ext.discussionTools.modifier' ), + logger = require( 'ext.discussionTools.logger' ), pageDataCache = {}, $pageContainer, scrollPadding = { top: 10, bottom: 10 }, @@ -26,6 +27,16 @@ function setupComment( comment ) { .on( 'click', function () { var $link = $( this ); + logger( { + action: 'init', + type: 'page', + mechanism: 'click', + // TODO: when we have actual visual mode, this needs to do better at + // working out which will be used: + // eslint-disable-next-line camelcase + editor_interface: config.useVisualEditor ? 'wikitext-2017' : 'wikitext' + } ); + $link.addClass( 'dt-init-replylink-active' ); // TODO: Allow users to use multiple reply widgets simlutaneously // Currently as all widgets share the same Parsoid doc, this could @@ -55,6 +66,11 @@ function setupComment( comment ) { }, function () { $link.removeClass( 'dt-init-replylink-active' ); $pageContainer.removeClass( 'dt-init-replylink-open' ); + + logger( { + action: 'abort', + type: 'preinit' + } ); } ); } widgetPromise.then( function ( replyWidget ) { @@ -62,6 +78,9 @@ function setupComment( comment ) { replyWidget.setup(); replyWidget.scrollElementIntoView( { padding: scrollPadding } ); replyWidget.focus(); + + logger( { action: 'ready' } ); + logger( { action: 'loaded' } ); } ); } ); diff --git a/modules/dt.ui.ReplyWidget.js b/modules/dt.ui.ReplyWidget.js index 80b40d649..17c42ba79 100644 --- a/modules/dt.ui.ReplyWidget.js +++ b/modules/dt.ui.ReplyWidget.js @@ -1,5 +1,6 @@ var controller = require( 'ext.discussionTools.controller' ), - modifier = require( 'ext.discussionTools.modifier' ); + modifier = require( 'ext.discussionTools.modifier' ), + logger = require( 'ext.discussionTools.logger' ); /** * DiscussionTools ReplyWidget class @@ -132,9 +133,19 @@ ReplyWidget.prototype.tryTeardown = function () { if ( !( data && data.action === 'discard' ) ) { return $.Deferred().reject().promise(); } + logger( { + action: 'abort', + mechanism: 'cancel', + type: 'abandon' + } ); } ); } else { promise = $.Deferred().resolve().promise(); + logger( { + action: 'abort', + mechanism: 'cancel', + type: 'nochange' + } ); } promise.then( function () { widget.teardown(); @@ -201,6 +212,10 @@ ReplyWidget.prototype.onInputChange = function () { } ); }; +ReplyWidget.prototype.onFirstTransaction = function () { + logger( { action: 'firstChange' } ); +}; + /** * Bind the beforeunload handler, if needed and if not already bound. * @@ -250,8 +265,12 @@ ReplyWidget.prototype.onReplyClick = function () { this.setPending( true ); + logger( { action: 'saveIntent' } ); + // We must get a new copy of the document every time, otherwise any unsaved replies will pile up this.getParsoidCommentData().then( function ( parsoidData ) { + logger( { action: 'saveAttempt' } ); + return controller.postReply( widget, parsoidData ); } ).catch( function ( code, data ) { // Handle edit conflicts. Load the latest revision of the page, then try again. If the parent @@ -300,12 +319,45 @@ ReplyWidget.prototype.onReplyClick = function () { repliedTo: widget.comment.id } ); mw.hook( 'wikipage.content' ).fire( $container ); + + logger( { + action: 'saveSuccess', + // eslint-disable-next-line camelcase + revision_id: data.newrevid + } ); }, function ( code, data ) { + var typeMap = { + // Compare to ve.init.mw.ArticleTargetEvents.js in VisualEditor. + editconflict: 'editConflict', + wasdeleted: 'editPageDeleted', + abusefilter: 'extensionAbuseFilter', + 'abusefilter-disallowed': 'extensionAbuseFilter', + captcha: 'extensionCaptcha', + spamprotectiontext: 'extensionSpamBlacklist', + titleblacklist: 'extensionTitleBlacklist', + 'titleblacklist-forbidden-edit': 'extensionTitleBlacklist', + badtoken: 'userBadToken', + newuser: 'userNewUser', + spamblacklist: 'extensionSpamBlacklist', + empty: 'responseEmpty', + unknown: 'responseUnknown', + pagedeleted: 'editPageDeleted' + }; + widget.errorMessage = new OO.ui.MessageWidget( { type: 'error', label: widget.api.getErrorMessage( data ) } ); widget.errorMessage.$element.insertBefore( widget.replyBodyWidget.$element ); + + if ( data.edit && data.edit.captcha ) { + code = 'captcha'; + } + logger( { + action: 'saveFailure', + message: code, + type: typeMap[ code ] || 'responseUnknown' + } ); } ).always( function () { widget.setPending( false ); } ); diff --git a/modules/dt.ui.ReplyWidgetPlain.js b/modules/dt.ui.ReplyWidgetPlain.js index df2a6eb33..d2d912c24 100644 --- a/modules/dt.ui.ReplyWidgetPlain.js +++ b/modules/dt.ui.ReplyWidgetPlain.js @@ -55,6 +55,13 @@ ReplyWidgetPlain.prototype.isEmpty = function () { return !this.replyBodyWidget.getValue().trim(); }; +ReplyWidgetPlain.prototype.setup = function () { + // Parent method + ReplyWidgetPlain.super.prototype.setup.call( this ); + + this.replyBodyWidget.once( 'change', this.onFirstTransaction.bind( this ) ); +}; + ReplyWidgetPlain.prototype.onKeyDown = function ( e ) { // Parent method ReplyWidgetPlain.super.prototype.onKeyDown.call( this, e ); diff --git a/modules/dt.ui.ReplyWidgetVisual.js b/modules/dt.ui.ReplyWidgetVisual.js index 90694c0b2..a3700a031 100644 --- a/modules/dt.ui.ReplyWidgetVisual.js +++ b/modules/dt.ui.ReplyWidgetVisual.js @@ -54,7 +54,8 @@ ReplyWidgetVisual.prototype.setup = function () { this.mode = this.replyBodyWidget.target.getSurface().getMode(); // Events - this.replyBodyWidget.target.getSurface().getModel().getDocument().connect( this, { transact: this.onInputChangeThrottled } ); + this.replyBodyWidget.target.getSurface().getModel().getDocument().connect( this, { transact: this.onInputChangeThrottled } ) + .once( 'transact', this.onFirstTransaction.bind( this ) ); this.replyBodyWidget.target.getSurface().connect( this, { submit: 'onReplyClick' } ); }; diff --git a/modules/logger.js b/modules/logger.js new file mode 100644 index 000000000..f21291b05 --- /dev/null +++ b/modules/logger.js @@ -0,0 +1,187 @@ +'use strict'; + +var trackdebug = !!mw.util.getParamValue( 'trackdebug' ); + +/** + * Logs an event to http://meta.wikimedia.org/wiki/Schema:EditAttemptStep + * @instance + * @param {Object} data + */ +module.exports = function ( data ) { + mw.track( 'dt.schemaEditAttemptStep', data ); +}; + +// Ensure 'ext.eventLogging' first, it provides mw.eventLog.randomTokenMatch. +// (No explicit dependency is set because we want this to just quietly not-happen +// if EventLogging isn't installed.) +mw.loader.using( 'ext.eventLogging' ).done( function () { + var // Schema class is provided by ext.eventLogging + Schema = mw.eventLog.Schema, + user = mw.user, + sampleRate = mw.config.get( 'wgWMESchemaEditAttemptStepSamplingRate' ), + actionPrefixMap = { + firstChange: 'first_change', + saveIntent: 'save_intent', + saveAttempt: 'save_attempt', + saveSuccess: 'save_success', + saveFailure: 'save_failure' + }, + timing = {}, + session = {}, + /** + * Edit schema + * https://meta.wikimedia.org/wiki/Schema:EditAttemptStep + */ + /* eslint-disable camelcase */ + schemaEditAttemptStep = new Schema( + 'EditAttemptStep', + sampleRate, + // defaults: + { + page_id: mw.config.get( 'wgArticleId' ), + revision_id: mw.config.get( 'wgRevisionId' ), + page_title: mw.config.get( 'wgPageName' ), + page_ns: mw.config.get( 'wgNamespaceNumber' ), + user_id: user.getId(), + user_class: user.isAnon() ? 'IP' : undefined, + user_editcount: mw.config.get( 'wgUserEditCount', 0 ), + mw_version: mw.config.get( 'wgVersion' ), + platform: 'desktop', + integration: 'page', + page_token: user.getPageviewToken(), + session_token: user.sessionId(), + version: 1 + } + ); + /* eslint-enable camelcase */ + + function log() { + // mw.log is a no-op unless resource loader is in debug mode, so + // this allows trackdebug to work independently + // eslint-disable-next-line no-console + console.log.apply( console, arguments ); + } + + function computeDuration( action, event, timeStamp ) { + // This is duplicated from the VisualEditor extension + // (ve.init.mw.trackSubscriber.js). Changes to this should be kept in + // sync with that file, so the data remains consistent. + if ( event.timing !== undefined ) { + return event.timing; + } + + switch ( action ) { + case 'ready': + return timeStamp - timing.init; + case 'loaded': + return timeStamp - timing.init; + case 'firstChange': + return timeStamp - timing.ready; + case 'saveIntent': + return timeStamp - timing.ready; + case 'saveAttempt': + return timeStamp - timing.saveIntent; + case 'saveSuccess': + case 'saveFailure': + // HERE BE DRAGONS: the caller must compute these themselves + // for sensible results. Deliberately sabotage any attempts to + // use the default by returning -1 + mw.log.warn( 'dt.schemaEditAttemptStep: Do not rely on default timing value for saveSuccess/saveFailure' ); + return -1; + case 'abort': + switch ( event.abort_type ) { + case 'preinit': + return timeStamp - timing.init; + case 'nochange': + case 'switchwith': + case 'switchwithout': + case 'switchnochange': + case 'abandon': + return timeStamp - timing.ready; + case 'abandonMidsave': + return timeStamp - timing.saveAttempt; + } + mw.log.warn( 'dt.schemaEditAttemptStep: Unrecognized abort type', event.type ); + return -1; + } + mw.log.warn( 'dt.schemaEditAttemptStep: Unrecognized action', action ); + return -1; + } + + mw.trackSubscribe( 'dt.schemaEditAttemptStep', function ( topic, data ) { + var actionPrefix = actionPrefixMap[ data.action ] || data.action, + timeStamp = mw.now(), + duration = 0; + + // Update the rolling session properties + if ( data.action === 'init' ) { + // eslint-disable-next-line camelcase + session.editing_session_id = mw.user.generateRandomSessionId(); + } + // eslint-disable-next-line camelcase + session.editor_interface = data.editor_interface || session.editor_interface; + + // Schema's kind of a mess of special properties + if ( data.action === 'init' || data.action === 'abort' || data.action === 'saveFailure' ) { + data[ actionPrefix + '_type' ] = data.type; + } + if ( data.action === 'init' || data.action === 'abort' ) { + data[ actionPrefix + '_mechanism' ] = data.mechanism; + } + if ( data.action !== 'init' ) { + // Schema actually does have an init_timing field, but we don't want to + // store it because it's not meaningful. + duration = Math.round( computeDuration( data.action, data, timeStamp ) ); + data[ actionPrefix + '_timing' ] = duration; + } + if ( data.action === 'saveFailure' ) { + data[ actionPrefix + '_message' ] = data.message; + } + + // Remove renamed properties + delete data.type; + delete data.mechanism; + delete data.timing; + delete data.message; + // eslint-disable-next-line camelcase + data.is_oversample = + !mw.eventLog.inSample( 1 / sampleRate ); + + if ( data.action === 'abort' && data.abort_type !== 'switchnochange' ) { + timing = {}; + } else { + timing[ data.action ] = timeStamp; + } + + // Switching between visual and source produces a chain of + // abort/ready/loaded events and no init event, so suppress them for + // consistency with desktop VE's logging. + if ( data.abort_type === 'switchnochange' ) { + // The initial abort, flagged as a switch + return; + } + if ( timing.abort ) { + // An abort was previously logged + if ( data.action === 'ready' ) { + // Just discard the ready + return; + } + if ( data.action === 'loaded' ) { + // Switch has finished; remove the abort timing so we stop discarding events. + delete timing.abort; + return; + } + } + + $.extend( data, session ); + + if ( trackdebug ) { + log( topic + '.' + data.action, duration + 'ms', data, schemaEditAttemptStep.defaults ); + } else { + schemaEditAttemptStep.log( + data, + mw.config.get( 'wgWMESchemaEditAttemptStepOversample' ) ? 1 : sampleRate + ); + } + } ); +} );