diff --git a/.gitignore b/.gitignore index 1f1b4e7a79..c59baf646e 100644 --- a/.gitignore +++ b/.gitignore @@ -22,3 +22,5 @@ cookie-jar.txt /addon/install.rdf /addon/webextension/_locales /*.xpi +# Created by py.test: +/test/server/.cache diff --git a/bin/require.pip b/bin/require.pip index 6326e88a9b..d691a00e5d 100644 --- a/bin/require.pip +++ b/bin/require.pip @@ -2,3 +2,4 @@ flake8==3.3.0 GitPython==2.1.3 requests==2.18.2 sarge==0.1.4 +pytest==3.2.1 diff --git a/circle.yml b/circle.yml index e522bb92ba..1e44b4a420 100644 --- a/circle.yml +++ b/circle.yml @@ -33,6 +33,7 @@ test: # server tests - ./bin/test-request put '{}' - ./bin/load_test_exercise.py http://localhost:10080 + - npm run test:server # run zap baseline against the server - docker pull owasp/zap2docker-weekly # || true to temporarily disable this from making the tests fail: diff --git a/package.json b/package.json index 28e4687b8a..601e034838 100644 --- a/package.json +++ b/package.json @@ -88,6 +88,7 @@ "posttest": "npm run lint", "test": "make bootstrap_zip && mocha test/", "test:selenium": "make bootstrap_zip && mocha test/test.js", + "test:server": "make .venv && cd test/server && ../../.venv/bin/pytest", "make_versions_exact": "node bin/build-scripts/make_versions_exact.js", "update_outdated": "david update && npm run make_versions_exact && npm update && npm outdated", "fill_database": "make .venv && ./.venv/bin/python ./bin/load_test_exercise.py -q --little-image --create=50 --read-shot=0 --read-my-shots=0 --search=0 --new-account http://localhost:10080" diff --git a/server/src/config.js b/server/src/config.js index 2c6ed98215..072a77e446 100644 --- a/server/src/config.js +++ b/server/src/config.js @@ -121,6 +121,13 @@ var conf = convict({ default: 0, env: "FORCE_DB_VERSION", arg: "force-db-version" + }, + logQueryLimit: { + doc: "Log queries that take more than time amount of time (in milliseconds)", + format: "int", + default: 50, + env: "LOG_QUERY_LIMIT", + arg: "log-query-limit" } }, gaId: { diff --git a/server/src/db.js b/server/src/db.js index 1d10a6622d..23a628e6ea 100644 --- a/server/src/db.js +++ b/server/src/db.js @@ -2,6 +2,7 @@ const config = require("./config").getProperties(); const pg = require("pg"); const mozlog = require("./logging").mozlog("db"); +const logQueryLimit = config.db.logQueryLimit; let user = encodeURIComponent(config.db.user); let dbname = encodeURIComponent(config.db.dbname || config.db.user); @@ -28,10 +29,12 @@ function getConnection() { } exports.queryWithClient = function(client, ...params) { + let timer = initTiming(); return new Promise((resolve, reject) => { // Babel only supports spreads as the final element of a list; i.e., // `[...params, value]` is invalid. params.push(function afterQuery(err, result) { + timer(); if (err) { reject(err); } else { @@ -47,9 +50,11 @@ exports.getConnection = getConnection; exports.constr = constr; exports.select = function(sql, args) { + let timer = initTiming(); return getConnection().then(function([client, done]) { return exports.queryWithClient(client, sql, args).then(({rows}) => { done(); + timer(); return rows; }, (error) => { done(); @@ -59,9 +64,11 @@ exports.select = function(sql, args) { }; exports.insert = function(sql, args) { + let timer = initTiming(); return getConnection().then(function([client, done]) { return exports.queryWithClient(client, sql, args).then(() => { done(); + timer(); return true; }).catch(err => { done(); @@ -75,7 +82,9 @@ exports.insert = function(sql, args) { }; exports.update = function(sql, args) { + let timer = initTiming(); return exports.exec(sql, args).then((result) => { + timer(); return result.rowCount; }); }; @@ -115,9 +124,11 @@ exports.transaction = function(func) { exports.del = exports.update; exports.exec = function(sql, args) { + let timer = initTiming(); return getConnection().then(function([client, done]) { return exports.queryWithClient(client, sql, args).then(result => { done(); + timer(); return result; }, err => { done(); @@ -133,3 +144,49 @@ exports.markersForArgs = function(starting, numberOfArgs) { } return result.join(", "); }; + +function doNothing() { +} + +function initTiming() { + if (!logQueryLimit) { + return doNothing; + } + let caller = getCallerPosition(2); + if (caller == "skip") { + // This happens when getCallerPosition detects we shouldn't time this function call + return doNothing; + } + let start = Date.now(); + return function() { + let time = Date.now() - start; + if (time >= logQueryLimit) { + mozlog.info("db-timing", {caller, time}); + } + }; +} + +const skipCaller = /\/server\/db.js:/; +const abortTiming = /\/server\/db.js:/; + +function getCallerPosition(stacklevel) { + // Obviously the caller knows its position, so we really + // want the caller of the caller of this function + let exc = new Error(); + let lines = exc.stack.split("\n"); + let index = stacklevel + 2; + while (lines[index] && skipCaller.test(lines[index])) { + if (abortTiming.test(lines[index])) { + // This is a case where this function is being called by another function + // inside this module; when that happens we know this call is already + // being logged, and don't need to log it + return "skip"; + } + index++; + } + let caller = lines[index]; + if (!caller) { + return "unknown"; + } + return caller.replace(/^ */, "") +} diff --git a/server/src/servershot.js b/server/src/servershot.js index 7d55d1c783..7612183dd3 100644 --- a/server/src/servershot.js +++ b/server/src/servershot.js @@ -197,7 +197,7 @@ class Shot extends AbstractShot { `INSERT INTO data (id, deviceid, value, url, title, searchable_version, searchable_text) VALUES ($1, $2, $3, $4, $5, $6, ${searchable.query})`, [this.id, this.ownerId, JSON.stringify(json), url, title, searchable.version].concat(searchable.args) - ).then((rowCount) => { + ).then((result) => { return clipRewrites.commit(client); }).then(() => { return oks; @@ -375,10 +375,11 @@ Shot.get = function(backend, id, deviceId, accountId) { return null; } let json = JSON.parse(rawValue.value); + let jsonTitle = json.userTitle || (json.openGraph && json.openGraph.title) || json.docTitle; + json.docTitle = jsonTitle || rawValue.title; if (!json.url && rawValue.url) { json.url = rawValue.url; } - json.docTitle = ""; let shot = new Shot(rawValue.userid, backend, id, json); shot.urlIfDeleted = rawValue.url; shot.accountId = rawValue.accountId; @@ -759,10 +760,10 @@ ClipRewrites = class ClipRewrites { return db.queryWithClient( client, - `INSERT INTO images (id, shotid, clipid, url, contenttype) - VALUES ($1, $2, $3, $4, $5) + `INSERT INTO images (id, shotid, clipid, url, contenttype, size) + VALUES ($1, $2, $3, $4, $5, $6) `, - [data.uuid, this.shot.id, clipId, data.url, data.binary.contentType]); + [data.uuid, this.shot.id, clipId, data.url, data.binary.contentType, data.binary.data.length]); }) ); }).then(() => { @@ -774,14 +775,14 @@ ClipRewrites = class ClipRewrites { return db.queryWithClient( client, - `INSERT INTO images (id, shotid, clipid, url, contenttype) - VALUES ($1, $2, $3, $4, $5) + `INSERT INTO images (id, shotid, clipid, url, contenttype, size) + VALUES ($1, $2, $3, $4, $5, $6) `, // Since we don't have a clipid for the thumbnail and the column is NOT NULL, // Use the thumbnail uuid as the clipid. This allows figuring out which // images are thumbnails, too. [this.toInsertThumbnail.uuid, this.shot.id, this.toInsertThumbnail.uuid, - this.toInsertThumbnail.url, this.toInsertThumbnail.contentType]); + this.toInsertThumbnail.url, this.toInsertThumbnail.contentType, this.toInsertThumbnail.binary.data.length]); }).then(() => { this.committed = true; }); @@ -855,6 +856,10 @@ Shot.upgradeSearch = function() { return resolve(); } Shot.get("upgrade_search_only", rows[index].id).then((shot) => { + // This shouldn't really happen, but apparently can... + if (!shot) { + return; + } return shot.upgradeSearch(); }).then(() => { index++; diff --git a/test/server/clientlib.py b/test/server/clientlib.py index bf4e3a4a53..557fdb304e 100644 --- a/test/server/clientlib.py +++ b/test/server/clientlib.py @@ -108,8 +108,11 @@ def search_shots(self, q): resp.raise_for_status() -def make_example_shot(deviceId, pad_image_to_length=None, **overrides): - image = random.choice(example_images) +def make_example_shot(deviceId, pad_image_to_length=None, image_index=None, **overrides): + if image_index is None: + image = random.choice(example_images) + else: + image = example_images[image_index] text = [] for i in range(10): text.append(random.choice(text_strings)) diff --git a/test/server/test_file_management.py b/test/server/test_file_management.py old mode 100755 new mode 100644 index 9621f179a6..b005e7a4b0 --- a/test/server/test_file_management.py +++ b/test/server/test_file_management.py @@ -1,4 +1,3 @@ -#!../../.venv/bin/python import os import urllib import clientlib diff --git a/test/server/test_responses.py b/test/server/test_responses.py old mode 100755 new mode 100644 index f1b14e52ee..2afa977be1 --- a/test/server/test_responses.py +++ b/test/server/test_responses.py @@ -1,5 +1,3 @@ -#!../../.venv/bin/python - from clientlib import ScreenshotsClient import random from requests import HTTPError diff --git a/test/server/test_shot_put_auth.py b/test/server/test_shot_put_auth.py old mode 100755 new mode 100644 index 272617d934..892a385cf1 --- a/test/server/test_shot_put_auth.py +++ b/test/server/test_shot_put_auth.py @@ -1,5 +1,3 @@ -#!../../.venv/bin/python - import urlparse from clientlib import ScreenshotsClient import random @@ -22,7 +20,7 @@ def test_put_auth(): assert "A_TEST_SITE_1" in shot_page["page"] try: second_user.create_shot(shot_id=shot_id, docTitle="A_TEST_SITE_2") - except requests.HTTPError, e: + except requests.HTTPError as e: if e.response.status_code != 403: raise else: @@ -34,5 +32,20 @@ def test_put_auth(): assert shot_page["clip_content"] == second_shot_page["clip_content"] +def test_update(): + user = ScreenshotsClient() + user.login() + shot_url = user.create_shot(docTitle="A_TEST_SITE_1", image_index=0) + shot_page = user.read_shot(shot_url) + assert "A_TEST_SITE_1" in shot_page["page"] + shot_id = urlparse.urlsplit(shot_url).path.strip("/") + user.create_shot(shot_id=shot_id, docTitle="A_TEST_SITE_2", image_index=1) + later_shot_page = user.read_shot(shot_url) + assert "A_TEST_SITE_2" in later_shot_page["page"] + assert later_shot_page["clip_content"] + assert later_shot_page["clip_content"] != shot_page["clip_content"] + assert later_shot_page["clip_url"] != shot_page["clip_url"] + + if __name__ == "__main__": test_put_auth()