Skip to content
This repository has been archived by the owner on Jan 17, 2023. It is now read-only.

Commit

Permalink
Fix #936, send timing information to GA for more steps
Browse files Browse the repository at this point in the history
This changes the signature of sendTiming() and is more explicit about that signature
Add functions to help time pieces of the process
  • Loading branch information
ianb committed Nov 15, 2016
1 parent cbecc70 commit 352398c
Show file tree
Hide file tree
Showing 4 changed files with 171 additions and 34 deletions.
20 changes: 18 additions & 2 deletions addon/lib/req.js
Original file line number Diff line number Diff line change
Expand Up @@ -78,11 +78,27 @@ exports.sendEvent = function (action, label, options) {
});
};

exports.sendTiming = function(event, action, timing) {
exports.sendTiming = function(timings) {
if (! Array.isArray(timings)) {
timings = [timings];
}
for (let timing of timings) {
if (! timing.category) {
timing.category = "addon";
}
for (let prop in timing) {
if (['category', 'variable', 'time', 'label'].indexOf(prop) === -1) {
throw new Error(`Unexpected timing property: ${prop}`);
}
}
if (timing.category === undefined || timing.variable === undefined || timing.time === undefined) {
throw new Error("Timing missing required property");
}
}
let main = require("./main");
exports.request(`${main.getBackend()}/timing`, {
method: "POST",
content: JSON.stringify({event, action, timing}),
content: JSON.stringify({timings}),
contentType: "application/json"
});
};
Expand Down
90 changes: 63 additions & 27 deletions addon/lib/shooter.js
Original file line number Diff line number Diff line change
Expand Up @@ -24,6 +24,7 @@ const { setTimeout, clearTimeout } = require("sdk/timers");
const shotstore = require("./shotstore");
const getCookies = require("./get-cookies");
const fixUrl = require("./fix-url");
const { timeFunction, startTimer } = require("./timing");

let shouldShowTour = false; // eslint-disable-line no-unused-vars

Expand All @@ -44,7 +45,6 @@ function escapeForHTML(text) {
function extractWorker(tab, options) {
let timeLimit = options.timeLimit;
let useReadability = options.useReadability;
let timeStarted = new Date();
if (timeLimit === undefined) {
timeLimit = 10000; // 10 second default
}
Expand All @@ -66,8 +66,6 @@ function extractWorker(tab, options) {
const worker = tab.attach({contentScriptFile});
watchWorker(worker);
worker.port.on("data", function (data) {
let timeFinished = new Date();
sendTiming("addon", "extract-data", timeFinished - timeStarted);
worker.destroy();
if (timedOut) {
console.error("extractWorker resolved after timeout");
Expand Down Expand Up @@ -128,6 +126,9 @@ const ShotContext = Class({
},

takeShot: function () {
let finishTimer = startTimer({
variable: "take-shot"
});
let loadingTab;
let doneSuperFast = false;
this.copyUrlToClipboard();
Expand All @@ -146,15 +147,13 @@ const ShotContext = Class({
if (loadingTab) {
loadingTab.url = this.shot.viewUrl;
}
finishTimer();
this.destroy();
}).catch((error) => {
this.destroy();
finishTimer();
throw error;
}));
this._collectionCompletePromise.then(() => {
// FIXME remove when we are sure we don't want this feature
//this.copyRichDataToClipboard();
});
},

uploadShot: function() {
Expand Down Expand Up @@ -315,18 +314,28 @@ const ShotContext = Class({
the HTML, and other misc stuff. Immediately updates the
shot as that information comes in */
collectInformation: function () {
let timings = [];
let finishCollectInformation = startTimer({
timings,
variable: "collect-information"
});
if (this.tab.url.startsWith("about:")) {
sendEvent("start-shot-about-page");
} else if (this.tab.url.search(/^https?:/i) === -1) {
let scheme = this.tab.url.replace(/:.*/, "");
sendEvent("start-shot-non-http", scheme);
}
watchPromise(callScript(
this.tab,
self.data.url("framescripts/add-ids.js"),
"pageshot@addIds",
{annotateForPage: this.annotateForPage}
).then((function (result) {
watchPromise(timeFunction({
func: callScript,
args: [
this.tab,
self.data.url("framescripts/add-ids.js"),
"pageshot@addIds",
{annotateForPage: this.annotateForPage}
],
timings,
variable: "add-ids"
})).then((result) => {
if (result.isXul) {
// Abandon hope all ye who enter!
sendEvent("abort-start-shot", "xul-page");
Expand All @@ -345,12 +354,17 @@ const ShotContext = Class({
var prefInlineCss = require("sdk/simple-prefs").prefs.inlineCss;
var useReadability = require("sdk/simple-prefs").prefs.useReadability;
var promises = [];
promises.push(watchPromise(extractWorker(this.tab, {useReadability})).then(watchFunction(function (attrs) {
promises.push(watchPromise(timeFunction({
func: extractWorker,
args: [this.tab, {useReadability}],
timings,
variable: "extract-data"
}).then((attrs) => {
let passwordFields = attrs.passwordFields;
delete attrs.passwordFields;
this.checkIfPublic({passwordFields});
this.shot.update(attrs);
}, this)));
})));
// FIXME We may want to parameterize this function so full screen thumbnails can be turned on
/*
promises.push(watchPromise(this.makeFullScreenThumbnail().then((screenshot) => {
Expand All @@ -359,15 +373,20 @@ const ShotContext = Class({
});
})));
*/
promises.push(watchPromise(callScript(
this.tab,
self.data.url("framescripts/make-static-html.js"),
"pageshot@documentStaticData",
{prefInlineCss, annotateForPage: this.annotateForPage},
15000)).then((attrs) => {
this.shot.update(attrs);
})
);
promises.push(watchPromise(timeFunction({
func: callScript,
args: [
this.tab,
self.data.url("framescripts/make-static-html.js"),
"pageshot@documentStaticData",
{prefInlineCss, annotateForPage: this.annotateForPage},
15000
],
timings,
variable: "make-static-html"
}).then((attrs) => {
this.shot.update(attrs);
})));
promises.push(watchPromise(getFavicon(this.tab).then(
(url) => {
if (url.search(/^https?:\/\//i) !== -1) {
Expand All @@ -385,8 +404,12 @@ const ShotContext = Class({
throw error;
}
)));
watchPromise(allPromisesComplete(promises).then(this._collectionCompleteDone));
}).bind(this)));
watchPromise(allPromisesComplete(promises).then(() => {
this._collectionCompleteDone();
finishCollectInformation();
sendTiming(timings);
}));
});
},

/** Called anytime the shot is updated; currently this has no side-effects so it does nothing */
Expand Down Expand Up @@ -446,6 +469,11 @@ const ShotContext = Class({
/** Renders this object unusable, and unregisters any handlers */
destroy: function () {
this._destroying = true;
if (! this._destroyingTimer) {
this._destroyingTimer = startTimer({
variable: "destroy"
});
}
if (this._deregisters) {
for (let i=0; i<this._deregisters.length; i++) {
let item = this._deregisters[i];
Expand All @@ -462,6 +490,9 @@ const ShotContext = Class({
this.interactiveWorker.destroy();
this.interactiveWorker = null;
}
if (! this._destroyingTimer.done) {
this._destroyingTimer();
}
};

if (this.interactiveWorker) {
Expand Down Expand Up @@ -507,7 +538,12 @@ class Shot extends AbstractShot {
sendEvent("upload-retry", `times-${times}`);
}
times++;
return this._sendJson(attrs, "put");
return timeFunction({
func: this._sendJson,
_this: this,
args: [attrs, "put"],
variable: "upload-shot"
});
}, 3, 1000);
}

Expand Down
80 changes: 80 additions & 0 deletions addon/lib/timing.js
Original file line number Diff line number Diff line change
@@ -0,0 +1,80 @@
const { sendTiming } = require("./req");

/** Times a function, from calling the function to completion
If the function returns a promise, "completion" means when that promise resolves
Arguments:
timings: an array; if given, the timings will be stored in the list, if not
given, then the timings will be sent immediately
func: a function to call
_this: call the function bound to _this
args: an array of args
variable: the GA timing variable
category: GA timing category (default "addon")
label: GA timing label
*/
exports.timeFunction = function (options) {
let timings = options.timings;
let sendImmediately = timings === undefined;
timings = timings || [];
let func = options.func;
let _this = options._this || null;
let args = options.args;
let startTime = Date.now();
let result = func.apply(_this, args);
function finish() {
let time = Date.now() - startTime;
timings.push({
variable: options.variable,
label: options.label,
category: options.category,
time
});
if (sendImmediately) {
sendTiming(timings);
}
}
if (result.then) {
let timedResult = result.then((val) => {
finish();
return val;
}, (error) => {
finish();
throw error;
});
return timedResult;
} else {
finish();
return result;
}
};

/** Creates a timer, which when called will complete a timing
Arguments, as in timeFunction():
timing, category, variable, label
*/
exports.startTimer = function (options) {
let start = Date.now();
let timings = options.timings;
let sendImmediately = timings === undefined;
timings = timings || [];
function finish() {
let time = Date.now() - start;
if (finish.done) {
throw new Error("Tried to call startTimer()() twice");
}
finish.done = true;
timings.push({
variable: options.variable,
label: options.label,
category: options.category,
time
});
if (sendImmediately) {
sendTiming(timings);
}
}
finish.done = false;
return finish;
};
15 changes: 10 additions & 5 deletions server/src/server.js
Original file line number Diff line number Diff line change
Expand Up @@ -377,11 +377,16 @@ app.post("/timing", function (req, res) {
}
hashUserId(req.deviceId).then((userUuid) => {
let userAnalytics = ua(config.gaId, userUuid.toString());
userAnalytics.timing(
bodyObj.event,
bodyObj.action,
bodyObj.timing
).send();
let sender = userAnalytics;
for (let item of bodyObj.timings) {
sender = sender.timing({
userTimingCategory: item.category,
userTimingVariableName: item.variable,
userTimingTime: item.time,
userTimingLabel: item.label
});
}
sender.send();
simpleResponse(res, "OK", 200);
}).catch((e) => {
errorResponse(res, "Error creating user UUID:", e);
Expand Down

0 comments on commit 352398c

Please sign in to comment.