From 249b0622d15d67a17fa5ceaee8e36f9f848d226d Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Fri, 10 Apr 2020 13:07:24 +0200 Subject: [PATCH 1/6] Make flawed integration tests explode by fixing nock expectations Up until now, a handful of integration tests has been flawed because we didn't actually verify all nock.js expectations (read: nock.js scope) had been fulfilled. That was due to a desire to run several methods as a one-liner instead of one per line; ``` filesScope.done() && existingRepoLabelsScope.done() ``` That could make sense at first glance, but there's a very important catch we didn't think about when writing it; it requires `.done()` to return a truthy value or else what comes after `.done()` will not be executed. The `.done()` method on nock.js' scope either throws an exception if the expectation it represents has not been met, or returns `undefined` when all is good. That `undefined` value stops the subsequent methods on the same line to be executed. In other words, we have always just checked the first expectation, and none of the subsequent ones on the same line. The changes introduced in this commit executes these `.done()`s on their own line which sadly causes all of the related tests to explode at the moment. Why most of these expectations haven't been met is probably due to timing issues, since we don't wait for all the related code to have finished executing before the tests are run. As of now, the code has been written in a fashion that allows incoming HTTPS requests to be get their response ASAP, whilst the code pushing PR statuses to github.com or trigger Jenins builds are still running. That raises some challenges for our integration tests since they don't really know when the code is finished, meaning tests can run. Upcoming changes will fix that by ensuring incoming requests will get their response *after* all relevant code has succeeded or failed. That will introduce quite a big refactor job, but the end result will be a lot more robust tests that can be trusted. --- test/integration/node-labels-webhook.test.js | 27 ++++++++++++++++--- .../integration/trigger-jenkins-build.test.js | 7 ++++- 2 files changed, 29 insertions(+), 5 deletions(-) diff --git a/test/integration/node-labels-webhook.test.js b/test/integration/node-labels-webhook.test.js index 273bd99f..ddd6100a 100644 --- a/test/integration/node-labels-webhook.test.js +++ b/test/integration/node-labels-webhook.test.js @@ -44,7 +44,12 @@ tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues/ .reply(200) t.plan(1) - t.tearDown(() => filesScope.done() && existingRepoLabelsScope.done() && newLabelsScope.done() && clock.uninstall()) + t.tearDown(() => { + filesScope.done() + existingRepoLabelsScope.done() + newLabelsScope.done() + clock.uninstall() + }) supertest(app) .post('/hooks/github') @@ -78,7 +83,12 @@ tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => .reply(200) t.plan(1) - t.tearDown(() => filesScope.done() && existingRepoLabelsScope.done() && newLabelsScope.done() && clock.uninstall()) + t.tearDown(() => { + filesScope.done() + existingRepoLabelsScope.done() + newLabelsScope.done() + clock.uninstall() + }) supertest(app) .post('/hooks/github') @@ -107,7 +117,11 @@ tap.test('Does not create labels which does not already exist', (t) => { .reply(200, readFixture('repo-labels.json')) t.plan(1) - t.tearDown(() => filesScope.done() && existingRepoLabelsScope.done() && clock.uninstall()) + t.tearDown(() => { + filesScope.done() + existingRepoLabelsScope.done() + clock.uninstall() + }) supertest(app) .post('/hooks/github') @@ -142,7 +156,12 @@ tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { .reply(200) t.plan(1) - t.tearDown(() => filesScope.done() && existingRepoLabelsScope.done() && newLabelsScope.done() && clock.uninstall()) + t.tearDown(() => { + filesScope.done() + existingRepoLabelsScope.done() + newLabelsScope.done() + clock.uninstall() + }) supertest(app) .post('/hooks/github') diff --git a/test/integration/trigger-jenkins-build.test.js b/test/integration/trigger-jenkins-build.test.js index 090cbbe8..9ccbaf9f 100644 --- a/test/integration/trigger-jenkins-build.test.js +++ b/test/integration/trigger-jenkins-build.test.js @@ -44,7 +44,12 @@ tap.test('Sends POST request to https://ci.nodejs.org', (t) => { .reply(200) t.plan(1) - t.tearDown(() => collaboratorsScope.done() && ciJobScope.done() && commentScope.done() && clock.uninstall()) + t.tearDown(() => { + collaboratorsScope.done() + ciJobScope.done() + commentScope.done() + clock.uninstall() + }) supertest(app) .post('/hooks/github') From e34a7c8f65e51457b2d2166766cf7e8952d2c55e Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Sat, 11 Apr 2020 11:12:54 +0200 Subject: [PATCH 2/6] Remove majority of fake timers use while testing As a precursor to running test assertions after we *know* all work has been done, most our use of fake timers gets removed here as it will not be needed anymore and even causes some challenges not easily solved when requests starts hanging due to work not having finished yet and the culprit is timers not running as they normally do. --- test/integration/node-labels-webhook.test.js | 13 ------------- test/integration/trigger-jenkins-build.test.js | 5 ----- test/unit/node-repo.test.js | 2 +- 3 files changed, 1 insertion(+), 19 deletions(-) diff --git a/test/integration/node-labels-webhook.test.js b/test/integration/node-labels-webhook.test.js index ddd6100a..2170621a 100644 --- a/test/integration/node-labels-webhook.test.js +++ b/test/integration/node-labels-webhook.test.js @@ -5,7 +5,6 @@ const url = require('url') const nock = require('nock') const supertest = require('supertest') const proxyquire = require('proxyquire') -const lolex = require('lolex') const testStubs = { './github-secret': { @@ -24,7 +23,6 @@ const readFixture = require('../read-fixture') setupNoRequestMatchHandler() tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues//labels', (t) => { - const clock = lolex.install() const expectedLabels = ['timers'] const webhookPayload = readFixture('pull-request-opened.json') @@ -48,7 +46,6 @@ tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues/ filesScope.done() existingRepoLabelsScope.done() newLabelsScope.done() - clock.uninstall() }) supertest(app) @@ -57,13 +54,11 @@ tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues/ .send(webhookPayload) .expect(200) .end((err, res) => { - clock.runAll() t.equal(err, null) }) }) tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => { - const clock = lolex.install() const expectedLabels = ['timers', 'v6.x'] const webhookPayload = readFixture('pull-request-opened-v6.x.json') @@ -87,7 +82,6 @@ tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => filesScope.done() existingRepoLabelsScope.done() newLabelsScope.done() - clock.uninstall() }) supertest(app) @@ -96,14 +90,12 @@ tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => .send(webhookPayload) .expect(200) .end((err, res) => { - clock.runAll() t.equal(err, null) }) }) // reported bug: https://github.com/nodejs/github-bot/issues/58 tap.test('Does not create labels which does not already exist', (t) => { - const clock = lolex.install() const webhookPayload = readFixture('pull-request-opened-mapproxy.json') const filesScope = nock('https://api.github.com') @@ -120,7 +112,6 @@ tap.test('Does not create labels which does not already exist', (t) => { t.tearDown(() => { filesScope.done() existingRepoLabelsScope.done() - clock.uninstall() }) supertest(app) @@ -129,14 +120,12 @@ tap.test('Does not create labels which does not already exist', (t) => { .send(webhookPayload) .expect(200) .end((err, res) => { - clock.runAll() t.equal(err, null) }) }) // reported bug: https://github.com/nodejs/github-bot/issues/92 tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { - const clock = lolex.install() const expectedLabels = ['V8 Engine'] const webhookPayload = readFixture('pull-request-opened-v8.json') @@ -160,7 +149,6 @@ tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { filesScope.done() existingRepoLabelsScope.done() newLabelsScope.done() - clock.uninstall() }) supertest(app) @@ -169,7 +157,6 @@ tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { .send(webhookPayload) .expect(200) .end((err, res) => { - clock.runAll() t.equal(err, null) }) }) diff --git a/test/integration/trigger-jenkins-build.test.js b/test/integration/trigger-jenkins-build.test.js index 9ccbaf9f..f659f98c 100644 --- a/test/integration/trigger-jenkins-build.test.js +++ b/test/integration/trigger-jenkins-build.test.js @@ -5,7 +5,6 @@ const url = require('url') const nock = require('nock') const supertest = require('supertest') const proxyquire = require('proxyquire') -const lolex = require('lolex') const readFixture = require('../read-fixture') const app = proxyquire('../../app', { @@ -19,8 +18,6 @@ const app = proxyquire('../../app', { }) tap.test('Sends POST request to https://ci.nodejs.org', (t) => { - const clock = lolex.install() - const originalJobUrlValue = process.env.JENKINS_JOB_URL_NODE const originalTokenValue = process.env.JENKINS_BUILD_TOKEN_NODE process.env.JENKINS_JOB_NODE = 'node-test-pull-request-lite-pipeline' @@ -48,7 +45,6 @@ tap.test('Sends POST request to https://ci.nodejs.org', (t) => { collaboratorsScope.done() ciJobScope.done() commentScope.done() - clock.uninstall() }) supertest(app) @@ -59,7 +55,6 @@ tap.test('Sends POST request to https://ci.nodejs.org', (t) => { .end((err, res) => { process.env.JENKINS_JOB_URL_NODE = originalJobUrlValue process.env.JENKINS_BUILD_TOKEN_NODE = originalTokenValue - clock.runAll() t.equal(err, null) }) }) diff --git a/test/unit/node-repo.test.js b/test/unit/node-repo.test.js index 396ee7c1..038d9081 100644 --- a/test/unit/node-repo.test.js +++ b/test/unit/node-repo.test.js @@ -1,9 +1,9 @@ 'use strict' -const lolex = require('lolex') const proxyquire = require('proxyquire') const sinon = require('sinon') const tap = require('tap') +const lolex = require('lolex') const logger = require('../../lib/logger') const githubClient = require('../../lib/github-client') From d7adb14801dc02ba9eb022fdc70fb797dd33cbd5 Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Tue, 14 Apr 2020 14:18:01 +0200 Subject: [PATCH 3/6] Reinitialise app before each label integration test to avoid label cache Several existing integration tests were failing because there was nock.js expectations created that wanted to see existing repository labels being fetched from github.com. Since we cache repository labels for an hour, the said retrieval of labels only happened in the first of label integration tests, whilst not in the subsequent ones since the labels had been put in a cache by then. We don't want to depend on the order of running tests, but rather start from a clean slate everytime, these changes ensure we reinitialise the `app` in every related test, resulting in clean labels cache everytime. --- test/integration/node-labels-webhook.test.js | 6 ++++-- 1 file changed, 4 insertions(+), 2 deletions(-) diff --git a/test/integration/node-labels-webhook.test.js b/test/integration/node-labels-webhook.test.js index 2170621a..eef6a414 100644 --- a/test/integration/node-labels-webhook.test.js +++ b/test/integration/node-labels-webhook.test.js @@ -16,13 +16,12 @@ const testStubs = { } } -const app = proxyquire('../../app', testStubs) - const readFixture = require('../read-fixture') setupNoRequestMatchHandler() tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues//labels', (t) => { + const app = proxyquire('../../app', testStubs) const expectedLabels = ['timers'] const webhookPayload = readFixture('pull-request-opened.json') @@ -59,6 +58,7 @@ tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues/ }) tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => { + const app = proxyquire('../../app', testStubs) const expectedLabels = ['timers', 'v6.x'] const webhookPayload = readFixture('pull-request-opened-v6.x.json') @@ -96,6 +96,7 @@ tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => // reported bug: https://github.com/nodejs/github-bot/issues/58 tap.test('Does not create labels which does not already exist', (t) => { + const app = proxyquire('../../app', testStubs) const webhookPayload = readFixture('pull-request-opened-mapproxy.json') const filesScope = nock('https://api.github.com') @@ -126,6 +127,7 @@ tap.test('Does not create labels which does not already exist', (t) => { // reported bug: https://github.com/nodejs/github-bot/issues/92 tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { + const app = proxyquire('../../app', testStubs) const expectedLabels = ['V8 Engine'] const webhookPayload = readFixture('pull-request-opened-v8.json') From 1639a84059686735703f44c1864d89b3ac596e94 Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Sat, 11 Apr 2020 09:41:07 +0200 Subject: [PATCH 4/6] Respond to GitHub events webhook HTTPS requests when all work is done With the goal of making our integration tests more robust and actually reliable, these changes makes sure incoming requests related to GitHub events, gets responded to after all work is done. This makes a big difference for our test suite as we now know when it is safe to run assertions. Up until now we've responded to said requests immediately and kicked off work like setting PR labels and similar, asynchronously. Although that could make sense considering what's done in runtime, it makes life hard when wanting to verify the behaviour while testing since we don't know when all the works has completed. Conceptually these changes consists of: - Installing and using [events-async](https://www.npmjs.com/package/events-async) to know when all event listeners has completed - Promisify all the event listeners since the above npm package uses promises instead of callbacks to handle async tasks --- app.js | 6 +- lib/github-comment.js | 23 ++-- lib/github-events.js | 16 ++- lib/node-repo.js | 119 +++++++++--------- package-lock.json | 5 + package.json | 1 + scripts/node-subsystem-label.js | 10 +- scripts/trigger-jenkins-build.js | 73 ++++++----- test/integration/node-labels-webhook.test.js | 2 + .../integration/trigger-jenkins-build.test.js | 4 +- test/unit/node-repo.test.js | 56 ++++----- 11 files changed, 162 insertions(+), 153 deletions(-) diff --git a/app.js b/app.js index 82684c49..b553f153 100644 --- a/app.js +++ b/app.js @@ -4,6 +4,7 @@ const glob = require('glob') const express = require('express') const bodyParser = require('body-parser') const bunyanMiddleware = require('bunyan-middleware') +const AsyncEventEmitter = require('events-async') const logger = require('./lib/logger') const authMiddleware = require('./lib/auth-middleware') @@ -11,6 +12,7 @@ const authMiddleware = require('./lib/auth-middleware') const captureRaw = (req, res, buffer) => { req.raw = buffer } const app = express() +const events = new AsyncEventEmitter() const scriptsToLoad = process.env.SCRIPTS || './scripts/**/*.js' const logsDir = process.env.LOGS_DIR || '' @@ -29,12 +31,12 @@ app.use(bunyanMiddleware({ obscureHeaders: ['x-hub-signature'] })) -require('./lib/github-events')(app) +require('./lib/github-events')(app, events) // load all the files in the scripts folder glob.sync(scriptsToLoad).forEach((file) => { logger.info('Loading:', file) - require(file)(app) + require(file)(app, events) }) app.use(function logUnhandledErrors (err, req, res, next) { diff --git a/lib/github-comment.js b/lib/github-comment.js index 221bc195..90ea2e15 100644 --- a/lib/github-comment.js +++ b/lib/github-comment.js @@ -2,15 +2,16 @@ const githubClient = require('./github-client') -exports.createPrComment = function createPrComment ({ owner, repo, number, logger }, body) { - githubClient.issues.createComment({ - owner, - repo, - number, - body - }, (err) => { - if (err) { - logger.error(err, 'Error while creating comment on GitHub') - } - }) +exports.createPrComment = async function createPrComment ({ owner, repo, number, logger }, body) { + try { + await githubClient.issues.createComment({ + owner, + repo, + number, + body + }) + } catch (err) { + logger.error(err, 'Error while creating comment on GitHub') + throw err + } } diff --git a/lib/github-events.js b/lib/github-events.js index b4bd6b9b..00523af1 100644 --- a/lib/github-events.js +++ b/lib/github-events.js @@ -2,8 +2,8 @@ const debug = require('debug')('github-events') const githubSecret = require('./github-secret') -module.exports = (app) => { - app.post('/hooks/github', (req, res) => { +module.exports = (app, events) => { + app.post('/hooks/github', async (req, res) => { const event = req.headers['x-github-event'] if (!event) { res.writeHead(400, 'Event Header Missing') @@ -19,9 +19,15 @@ module.exports = (app) => { const data = req.body data.action = data.action ? event + '.' + data.action : event - res.end() + try { + await app.emitGhEvent(data, req.log) + res.status(200) + } catch (err) { + req.log.error(err, 'Error while emitting GitHub event') + res.status(500) + } - app.emitGhEvent(data, req.log) + res.end() }) app.emitGhEvent = function emitGhEvent (data, logger) { @@ -45,6 +51,6 @@ module.exports = (app) => { data.logger.info('Emitting GitHub event') debug(data) - app.emit(data.action, data, org, repo, data.sender.login) + return events.emit(data.action, data, org, repo, data.sender.login) } } diff --git a/lib/node-repo.js b/lib/node-repo.js index 5b39f84b..1c3ee860 100644 --- a/lib/node-repo.js +++ b/lib/node-repo.js @@ -9,9 +9,12 @@ const existingLabelsCache = new LRU({ max: 1, maxAge: 1000 * 60 * 60 }) const fiveSeconds = 5 * 1000 -function deferredResolveLabelsThenUpdatePr (options) { +const sleep = (ms) => new Promise(resolve => setTimeout(resolve, ms)) + +async function deferredResolveLabelsThenUpdatePr (options) { const timeoutMillis = (options.timeoutInSec || 0) * 1000 - setTimeout(resolveLabelsThenUpdatePr, timeoutMillis, options) + await sleep(timeoutMillis) + return resolveLabelsThenUpdatePr(options) } function resolveLabelsThenUpdatePr (options) { @@ -25,35 +28,36 @@ function resolveLabelsThenUpdatePr (options) { }, cb) } - retry({ times: 5, interval: fiveSeconds }, getFiles, (err, res) => { - if (err) { - return options.logger.error(err, 'Error retrieving files from GitHub') - } + return new Promise((resolve, reject) => { + retry({ times: 5, interval: fiveSeconds }, getFiles, (err, res) => { + if (err) { + options.logger.error(err, 'Error retrieving files from GitHub') + return reject(err) + } - const filepathsChanged = res.data.map((fileMeta) => fileMeta.filename) - const resolvedLabels = resolveLabels(filepathsChanged, options.baseBranch) + const filepathsChanged = res.data.map((fileMeta) => fileMeta.filename) + const resolvedLabels = resolveLabels(filepathsChanged, options.baseBranch) - fetchExistingThenUpdatePr(options, resolvedLabels) + resolve(fetchExistingThenUpdatePr(options, resolvedLabels)) + }) }) } -function fetchExistingThenUpdatePr (options, labels) { - fetchExistingLabels(options, (err, existingLabels) => { - if (err) { - options.logger.error(err, 'Error retrieving existing repo labels') - - updatePrWithLabels(options, labels) - return - } - +async function fetchExistingThenUpdatePr (options, labels) { + try { + const existingLabels = await fetchExistingLabels(options) const labelsToAdd = stringsInCommon(existingLabels, labels) - options.logger.debug('Resolved labels: ' + labelsToAdd) + options.logger.debug('Resolved labels: ' + labelsToAdd, labels, existingLabels) - updatePrWithLabels(options, labelsToAdd) - }) + return updatePrWithLabels(options, labelsToAdd) + } catch (err) { + options.logger.error(err, 'Error retrieving existing repo labels') + + return updatePrWithLabels(options, labels) + } } -function updatePrWithLabels (options, labels) { +async function updatePrWithLabels (options, labels) { // no need to request github if we didn't resolve any labels if (!labels.length) { return @@ -61,18 +65,18 @@ function updatePrWithLabels (options, labels) { options.logger.debug('Trying to add labels: ' + labels) - githubClient.issues.addLabels({ - owner: options.owner, - repo: options.repo, - number: options.prId, - labels: labels - }, (err) => { - if (err) { - return options.logger.error(err, 'Error while adding labels') - } + try { + await githubClient.issues.addLabels({ + owner: options.owner, + repo: options.repo, + number: options.prId, + labels: labels + }) options.logger.info('Added labels: ' + labels) - }) + } catch (err) { + options.logger.error(err, 'Error while adding labels') + } } function removeLabelFromPR (options, label) { @@ -99,51 +103,44 @@ function removeLabelFromPR (options, label) { }) } -function fetchExistingLabels (options, cb) { +async function fetchExistingLabels (options) { const cacheKey = `${options.owner}:${options.repo}` if (existingLabelsCache.has(cacheKey)) { - return cb(null, existingLabelsCache.get(cacheKey)) + return existingLabelsCache.get(cacheKey) } - fetchLabelPages(options, 1, (err, existingLabels) => { - if (err) { - return cb(err) - } - - existingLabels = existingLabels.data || existingLabels || [] - const existingLabelNames = existingLabels.map((label) => label.name) + const labelsResult = await fetchLabelPages(options, 1) + const existingLabels = labelsResult.data || labelsResult || [] + const existingLabelNames = existingLabels.map((label) => label.name) - // cache labels so we don't have to fetch these *all the time* - existingLabelsCache.set(cacheKey, existingLabelNames) - options.logger.debug('Filled existing repo labels cache: ' + existingLabelNames) + // cache labels so we don't have to fetch these *all the time* + existingLabelsCache.set(cacheKey, existingLabelNames) + options.logger.debug('Filled existing repo labels cache: ' + existingLabelNames) - cb(null, existingLabelNames) - }) + return existingLabelNames } -function fetchLabelPages (options, startPageNum, cb) { +async function fetchLabelPages (options, startPageNum, cb) { // the github client API is somewhat misleading, // this fetches *all* repo labels not just for an issue - githubClient.issues.getLabels({ + const result = await githubClient.issues.getLabels({ owner: options.owner, repo: options.repo, page: startPageNum, per_page: 100 - }, (err, res) => { - const existingLabels = res.data || [] - if (err) { - return cb(err) - } - if (!githubClient.hasNextPage(res)) { - return cb(null, existingLabels) - } - fetchLabelPages( - options, - startPageNum + 1, - (err, remainingLabels) => err ? cb(err) : cb(null, existingLabels.concat(remainingLabels)) - ) }) + + const existingLabels = result.data || [] + if (!githubClient.hasNextPage(result)) { + return existingLabels + } + + const remainingLabels = await fetchLabelPages( + options, + startPageNum + 1) + + return existingLabels.concat(remainingLabels) } function getBotPrLabels (options, cb) { diff --git a/package-lock.json b/package-lock.json index 484ff03b..b7669c9e 100644 --- a/package-lock.json +++ b/package-lock.json @@ -1463,6 +1463,11 @@ "resolved": "https://registry.npmjs.org/etag/-/etag-1.8.1.tgz", "integrity": "sha1-Qa4u62XvpiJorr/qg6x9eSmbCIc=" }, + "events-async": { + "version": "1.2.1", + "resolved": "https://registry.npmjs.org/events-async/-/events-async-1.2.1.tgz", + "integrity": "sha512-bI2+3DF7SoORyw9xooadSyKHEFCZmkNx+fwe1mWCNUdSkkcsNQQeSvNw/ludXqWEI0zS3b93r07Uslnk304tXg==" + }, "events-to-array": { "version": "1.1.2", "resolved": "https://registry.npmjs.org/events-to-array/-/events-to-array-1.1.2.tgz", diff --git a/package.json b/package.json index 4ddc0983..1ab10604 100644 --- a/package.json +++ b/package.json @@ -20,6 +20,7 @@ "bunyan-middleware": "0.8.0", "debug": "^2.2.0", "dotenv": "^2.0.0", + "events-async": "^1.2.1", "express": "^4.13.4", "github": "^13.1.1", "glob": "^7.0.3", diff --git a/scripts/node-subsystem-label.js b/scripts/node-subsystem-label.js index 409e882b..ce3bd0b9 100644 --- a/scripts/node-subsystem-label.js +++ b/scripts/node-subsystem-label.js @@ -4,8 +4,10 @@ const debug = require('debug')('node_subsystem_label') const nodeRepo = require('../lib/node-repo') -module.exports = function (app) { - app.on('pull_request.opened', handlePrCreated) +const timeoutInSec = process.env.WAIT_SECONDS_BEFORE_RESOLVING_LABELS || 2 + +module.exports = function (app, events) { + events.on('pull_request.opened', handlePrCreated) } function handlePrCreated (event, owner, repo) { @@ -20,12 +22,12 @@ function handlePrCreated (event, owner, repo) { // by not hard coding the owner repo to nodejs/node here, // we can test these this script in a different repo than // *actual* node core as long as the repo is named "node" - nodeRepo.resolveLabelsThenUpdatePr({ + return nodeRepo.resolveLabelsThenUpdatePr({ owner, repo, prId, logger, baseBranch, - timeoutInSec: 2 + timeoutInSec }) } diff --git a/scripts/trigger-jenkins-build.js b/scripts/trigger-jenkins-build.js index 3392d6fb..44a5b53b 100644 --- a/scripts/trigger-jenkins-build.js +++ b/scripts/trigger-jenkins-build.js @@ -58,62 +58,61 @@ function triggerBuild (options, cb) { options.logger.debug('Triggering Jenkins build') - request.post({ - uri: `https://ci.nodejs.org/blue/rest/organizations/jenkins/pipelines/${jobName}/runs/`, - headers: { authorization }, - qs: { token: buildAuthToken }, - json: { parameters: buildParametersForRepo(options, repo) } - }, (err, response, body) => { - if (err) { - return cb(err) - } else if (response.statusCode !== 200) { - return cb(new Error(`Expected 200 from Jenkins, got ${response.statusCode}: ${body}`)) - } - - cb(null, { jobName, jobId: response.body.id }) + return new Promise((resolve, reject) => { + request.post({ + uri: `https://ci.nodejs.org/blue/rest/organizations/jenkins/pipelines/${jobName}/runs/`, + headers: { authorization }, + qs: { token: buildAuthToken }, + json: { parameters: buildParametersForRepo(options, repo) } + }, (err, response, body) => { + if (err) { + return reject(err) + } else if (response.statusCode !== 200) { + return reject(new Error(`Expected 200 from Jenkins, got ${response.statusCode}: ${body}`)) + } + + resolve({ jobName, jobId: response.body.id }) + }) }) } -function triggerBuildIfValid (options) { +async function triggerBuildIfValid (options) { const { owner, repo, author, logger } = options - githubClient.repos.checkCollaborator({ owner, repo, username: author }, function onResponse (err) { - if (err) { - return logger.debug(`Ignoring comment to me by @${options.author} because they are not a repo collaborator`) - } + try { + await githubClient.repos.checkCollaborator({ owner, repo, username: author }) + } catch (_err) { + logger.debug(`Ignoring comment to me by @${options.author} because they are not a repo collaborator`) + return + } - triggerBuild(options, function onBuildTriggered (err, result) { - if (err) { - return logger.error(err, 'Error while triggering Jenkins build') - } + try { + const result = await triggerBuild(options) + const jobUrl = `https://ci.nodejs.org/job/${result.jobName}/${result.jobId}` + logger.info({ jobUrl }, 'Jenkins build started') - const jobUrl = `https://ci.nodejs.org/job/${result.jobName}/${result.jobId}` - logger.info({ jobUrl }, 'Jenkins build started') - createPrComment(options, `Lite-CI: ${jobUrl}`) - }) - }) + return createPrComment(options, `Lite-CI: ${jobUrl}`) + } catch (err) { + logger.error(err, 'Error while triggering Jenkins build') + throw err + } } -module.exports = (app) => { - app.on('issue_comment.created', handleCommentCreated) - - app.on('pull_request.opened', handlePullCreated) +module.exports = (app, events) => { + events.on('issue_comment.created', handleCommentCreated) + events.on('pull_request.opened', handlePullCreated) } function handleCommentCreated (event, owner, repo) { const { number, logger, comment: { body, user: { login: author } } } = event const options = { owner, repo, number, logger, author } - if (wasBotMentionedInCiComment(body)) { - triggerBuildIfValid(options) - } + return wasBotMentionedInCiComment(body) ? triggerBuildIfValid(options) : Promise.resolve() } function handlePullCreated (event, owner, repo) { const { number, logger, pull_request: { user: { login: author } } } = event const options = { owner, repo, number, logger, author } - if (repo === 'node') { - triggerBuildIfValid(options) - } + return repo === 'node' ? triggerBuildIfValid(options) : Promise.resolve() } diff --git a/test/integration/node-labels-webhook.test.js b/test/integration/node-labels-webhook.test.js index eef6a414..1d4060c3 100644 --- a/test/integration/node-labels-webhook.test.js +++ b/test/integration/node-labels-webhook.test.js @@ -16,6 +16,8 @@ const testStubs = { } } +process.env.WAIT_SECONDS_BEFORE_RESOLVING_LABELS = 0 + const readFixture = require('../read-fixture') setupNoRequestMatchHandler() diff --git a/test/integration/trigger-jenkins-build.test.js b/test/integration/trigger-jenkins-build.test.js index f659f98c..d9b8e6f3 100644 --- a/test/integration/trigger-jenkins-build.test.js +++ b/test/integration/trigger-jenkins-build.test.js @@ -24,7 +24,7 @@ tap.test('Sends POST request to https://ci.nodejs.org', (t) => { process.env.JENKINS_BUILD_TOKEN_NODE = 'myToken' const webhookPayload = readFixture('pull-request-opened.json') - const pipelineUrl = 'https://ci.nodejs.org/blue/organizations/jenkins/node-test-pull-request-lite-pipeline/detail/node-test-pull-request-lite-pipeline/1/pipeline' + const pipelineUrl = 'https://ci.nodejs.org/job/node-test-pull-request-lite-pipeline/1' const collaboratorsScope = nock('https://api.github.com') .filteringPath(ignoreQueryParams) @@ -37,7 +37,7 @@ tap.test('Sends POST request to https://ci.nodejs.org', (t) => { const commentScope = nock('https://api.github.com') .filteringPath(ignoreQueryParams) - .post('/repos/nodejs/node/issues/19/comments', { body: `@phillipj build started: ${pipelineUrl}` }) + .post('/repos/nodejs/node/issues/19/comments', { body: `Lite-CI: ${pipelineUrl}` }) .reply(200) t.plan(1) diff --git a/test/unit/node-repo.test.js b/test/unit/node-repo.test.js index 038d9081..e92c7216 100644 --- a/test/unit/node-repo.test.js +++ b/test/unit/node-repo.test.js @@ -9,8 +9,8 @@ const logger = require('../../lib/logger') const githubClient = require('../../lib/github-client') const readFixture = require('../read-fixture') -tap.test('fetchExistingLabels(): caches existing repository labels', (t) => { - sinon.stub(githubClient.issues, 'getLabels').yields(null, []) +tap.test('fetchExistingLabels(): caches existing repository labels', async (t) => { + sinon.stub(githubClient.issues, 'getLabels', () => Promise.resolve([])) sinon.stub(githubClient, 'hasNextPage', () => false) const nodeRepo = proxyquire('../../lib/node-repo', { './github-client': githubClient @@ -22,16 +22,14 @@ tap.test('fetchExistingLabels(): caches existing repository labels', (t) => { githubClient.hasNextPage.restore() }) - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, () => { - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, () => { - t.ok(githubClient.issues.getLabels.calledOnce) - }) - }) + await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) + await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) + t.ok(githubClient.issues.getLabels.calledOnce) }) -tap.test('fetchExistingLabels(): cache expires after one hour', (t) => { +tap.test('fetchExistingLabels(): cache expires after one hour', async (t) => { const clock = lolex.install() - sinon.stub(githubClient.issues, 'getLabels').yields(null, []) + sinon.stub(githubClient.issues, 'getLabels', () => Promise.resolve([])) sinon.stub(githubClient, 'hasNextPage', () => false) const nodeRepo = proxyquire('../../lib/node-repo', { './github-client': githubClient @@ -44,53 +42,49 @@ tap.test('fetchExistingLabels(): cache expires after one hour', (t) => { clock.uninstall() }) - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, () => { - // fetch labels again after 1 hour and 1 minute - clock.tick(1000 * 60 * 61) + await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, () => { - t.equal(githubClient.issues.getLabels.callCount, 2) - }) - }) + // fetch labels again after 1 hour and 1 minute + clock.tick(1000 * 60 * 61) + + await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) + t.equal(githubClient.issues.getLabels.callCount, 2) }) -tap.test('fetchExistingLabels(): yields an array of existing label names', (t) => { +tap.test('fetchExistingLabels(): yields an array of existing label names', async (t) => { const labelsFixture = readFixture('repo-labels.json') - sinon.stub(githubClient.issues, 'getLabels').yields(null, labelsFixture) + sinon.stub(githubClient.issues, 'getLabels', () => Promise.resolve(labelsFixture)) sinon.stub(githubClient, 'hasNextPage', () => false) const nodeRepo = proxyquire('../../lib/node-repo', { './github-client': githubClient }) - t.plan(2) + t.plan(1) t.tearDown(() => { githubClient.issues.getLabels.restore() githubClient.hasNextPage.restore() }) - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, (err, existingLabels) => { - t.equal(err, null) - t.ok(existingLabels.includes('cluster')) - }) + const existingLabels = await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) + t.ok(existingLabels.includes('cluster')) }) -tap.test('fetchExistingLabels(): can retrieve more than 100 labels', (t) => { +tap.test('fetchExistingLabels(): can retrieve more than 100 labels', async (t) => { const labelsFixturePage1 = readFixture('repo-labels.json') const labelsFixturePage2 = readFixture('repo-labels-page-2.json') - sinon.stub(githubClient.issues, 'getLabels', (options, cb) => cb(null, options.page === 1 ? labelsFixturePage1 : labelsFixturePage2)) + sinon.stub(githubClient.issues, 'getLabels', (options) => Promise.resolve(options.page === 1 ? labelsFixturePage1 : labelsFixturePage2)) sinon.stub(githubClient, 'hasNextPage', (listing) => listing === labelsFixturePage1) const nodeRepo = proxyquire('../../lib/node-repo', { './github-client': githubClient }) - t.plan(3) + t.plan(2) t.tearDown(() => { githubClient.issues.getLabels.restore() githubClient.hasNextPage.restore() }) - nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }, (err, existingLabels) => { - t.equal(err, null) - t.ok(existingLabels.includes('cluster')) - t.ok(existingLabels.includes('windows')) - }) + + const existingLabels = await nodeRepo._fetchExistingLabels({ owner: 'nodejs', repo: 'node', logger }) + t.ok(existingLabels.includes('cluster')) + t.ok(existingLabels.includes('windows')) }) tap.test('getBotPrLabels(): returns labels added by nodejs-github-bot', (t) => { From 47c3ecdbc06654637782325bc897d429f882268e Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Fri, 8 May 2020 23:21:12 +0200 Subject: [PATCH 5/6] Move require() of all scripts from ./app.js to ./server.js These changes comes as a result of making tests more resilient. When running focused integration tests, we have some expectations of what kinds of requests are sent to github.com and what the end result should be after the bot has run all its magic. Those expectations are written to only have one specific script in mind, e.g. what should happen when pushing Jenkins updates or what should happen when labelling PRs. Up until now, all of our scripts has been setup by `require()`ing them inside `./app.js`. That means all has been setup and thereby reacted to incoming github.com webhook requests we've sent to the github-bot while testing. That's far from ideal because we cannot have "simple" and focused expectations about which github.com requests are expected and what they should get in response. Hence these changes; whilst running tests, we only `require()` the respective script the tests relates to. Although to keep the automagic of setting up all script when the github-bot is started in production, we move the lines of code that iterates over the available scripts into `./server.js` instead which is *only* executed in production, not by when testing. --- app.js | 10 +------- server.js | 10 +++++++- test/integration/node-labels-webhook.test.js | 25 ++++++++++++++++--- test/integration/ping.test.js | 4 ++- test/integration/push-jenkins-update.test.js | 4 ++- .../integration/trigger-jenkins-build.test.js | 4 ++- 6 files changed, 40 insertions(+), 17 deletions(-) diff --git a/app.js b/app.js index b553f153..b0b2308d 100644 --- a/app.js +++ b/app.js @@ -1,6 +1,5 @@ 'use strict' -const glob = require('glob') const express = require('express') const bodyParser = require('body-parser') const bunyanMiddleware = require('bunyan-middleware') @@ -14,7 +13,6 @@ const captureRaw = (req, res, buffer) => { req.raw = buffer } const app = express() const events = new AsyncEventEmitter() -const scriptsToLoad = process.env.SCRIPTS || './scripts/**/*.js' const logsDir = process.env.LOGS_DIR || '' app.use(bodyParser.json({ verify: captureRaw })) @@ -33,15 +31,9 @@ app.use(bunyanMiddleware({ require('./lib/github-events')(app, events) -// load all the files in the scripts folder -glob.sync(scriptsToLoad).forEach((file) => { - logger.info('Loading:', file) - require(file)(app, events) -}) - app.use(function logUnhandledErrors (err, req, res, next) { logger.error(err, 'Unhandled error while responding to incoming HTTP request') res.status(500).end() }) -module.exports = app +module.exports = { app, events } diff --git a/server.js b/server.js index e08b9f08..41b63ea1 100644 --- a/server.js +++ b/server.js @@ -2,6 +2,7 @@ require('dotenv').load({ silent: true }) +const glob = require('glob') const logger = require('./lib/logger') const { spawnSync } = require('child_process') @@ -19,7 +20,14 @@ if (process.env.NODE_REPO_DIR) { } const port = process.env.PORT || 3000 -const app = require('./app') +const scriptsToLoad = process.env.SCRIPTS || './scripts/**/*.js' +const { app, events } = require('./app') + +// load all the files in the scripts folder +glob.sync(scriptsToLoad).forEach((file) => { + logger.info('Loading:', file) + require(file)(app, events) +}) app.listen(port, () => { logger.info('Listening on port', port) diff --git a/test/integration/node-labels-webhook.test.js b/test/integration/node-labels-webhook.test.js index 1d4060c3..2f5a26f5 100644 --- a/test/integration/node-labels-webhook.test.js +++ b/test/integration/node-labels-webhook.test.js @@ -20,10 +20,27 @@ process.env.WAIT_SECONDS_BEFORE_RESOLVING_LABELS = 0 const readFixture = require('../read-fixture') +// Clearing the require cache is needed due to labels being cached into a singleton variable. +// To ensure every test can run on its own without relying on other tests having run already +// resulted in the cache being filled up, we enforce all tests to run without any "cache warming", +// hence labels has to be fetched every time +function clearRequireCache () { + for (const modulePath of Object.keys(require.cache)) { + delete require.cache[modulePath] + } +} + +function initializeApp () { + const { app, events } = proxyquire('../../app', testStubs) + clearRequireCache() + require('../../scripts/node-subsystem-label')(app, events) + return app +} + setupNoRequestMatchHandler() tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues//labels', (t) => { - const app = proxyquire('../../app', testStubs) + const app = initializeApp() const expectedLabels = ['timers'] const webhookPayload = readFixture('pull-request-opened.json') @@ -60,7 +77,7 @@ tap.test('Sends POST request to https://api.github.com/repos/nodejs/node/issues/ }) tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => { - const app = proxyquire('../../app', testStubs) + const app = initializeApp() const expectedLabels = ['timers', 'v6.x'] const webhookPayload = readFixture('pull-request-opened-v6.x.json') @@ -98,7 +115,7 @@ tap.test('Adds v6.x label when PR is targeting the v6.x-staging branch', (t) => // reported bug: https://github.com/nodejs/github-bot/issues/58 tap.test('Does not create labels which does not already exist', (t) => { - const app = proxyquire('../../app', testStubs) + const app = initializeApp() const webhookPayload = readFixture('pull-request-opened-mapproxy.json') const filesScope = nock('https://api.github.com') @@ -129,7 +146,7 @@ tap.test('Does not create labels which does not already exist', (t) => { // reported bug: https://github.com/nodejs/github-bot/issues/92 tap.test('Adds V8 Engine label when PR has deps/v8 file changes', (t) => { - const app = proxyquire('../../app', testStubs) + const app = initializeApp() const expectedLabels = ['V8 Engine'] const webhookPayload = readFixture('pull-request-opened-v8.json') diff --git a/test/integration/ping.test.js b/test/integration/ping.test.js index 104095a7..3f9c0207 100644 --- a/test/integration/ping.test.js +++ b/test/integration/ping.test.js @@ -3,7 +3,9 @@ const tap = require('tap') const request = require('request') -const app = require('../../app') +const { app, events } = require('../../app') + +require('../../scripts/ping')(app, events) tap.test('GET /ping responds with status 200 / "pong"', (t) => { const server = app.listen() diff --git a/test/integration/push-jenkins-update.test.js b/test/integration/push-jenkins-update.test.js index 8f79d6b2..ee3a66bf 100644 --- a/test/integration/push-jenkins-update.test.js +++ b/test/integration/push-jenkins-update.test.js @@ -5,10 +5,12 @@ const url = require('url') const nock = require('nock') const supertest = require('supertest') -const app = require('../../app') +const { app, events } = require('../../app') const readFixture = require('../read-fixture') +require('../../scripts/jenkins-status')(app, events) + tap.test('Sends POST requests to https://api.github.com/repos/nodejs/node/statuses/', (t) => { const jenkinsPayload = readFixture('success-payload.json') diff --git a/test/integration/trigger-jenkins-build.test.js b/test/integration/trigger-jenkins-build.test.js index d9b8e6f3..2548c4c5 100644 --- a/test/integration/trigger-jenkins-build.test.js +++ b/test/integration/trigger-jenkins-build.test.js @@ -7,7 +7,7 @@ const supertest = require('supertest') const proxyquire = require('proxyquire') const readFixture = require('../read-fixture') -const app = proxyquire('../../app', { +const { app, events } = proxyquire('../../app', { './github-secret': { isValid: () => true, @@ -17,6 +17,8 @@ const app = proxyquire('../../app', { } }) +require('../../scripts/trigger-jenkins-build')(app, events) + tap.test('Sends POST request to https://ci.nodejs.org', (t) => { const originalJobUrlValue = process.env.JENKINS_JOB_URL_NODE const originalTokenValue = process.env.JENKINS_BUILD_TOKEN_NODE From 06521318225e9e1f0362a0a17e524df83086b5f6 Mon Sep 17 00:00:00 2001 From: Phillip Johnsen Date: Sat, 11 Apr 2020 23:52:10 +0200 Subject: [PATCH 6/6] Add missing timers and v6.x label in integration labels fixture Since several existing integration tests expected these labels to exist in the first page of labels results from github.com, but wasn't raised as an error until now that the tests has been refactored. --- test/_fixtures/repo-labels-page-2.json | 7 ------- test/_fixtures/repo-labels.json | 10 ++++++++++ 2 files changed, 10 insertions(+), 7 deletions(-) diff --git a/test/_fixtures/repo-labels-page-2.json b/test/_fixtures/repo-labels-page-2.json index db72898d..ad0ccb5c 100644 --- a/test/_fixtures/repo-labels-page-2.json +++ b/test/_fixtures/repo-labels-page-2.json @@ -14,13 +14,6 @@ "color": "eb6420", "default": false }, - { - "id": 364835500, - "url": "https://api.github.com/repos/nodejs/node/labels/v6.x", - "name": "v6.x", - "color": "c2e0c6", - "default": false - }, { "id": 441404503, "url": "https://api.github.com/repos/nodejs/node/labels/v7.x", diff --git a/test/_fixtures/repo-labels.json b/test/_fixtures/repo-labels.json index 46a461f1..b3d5e759 100644 --- a/test/_fixtures/repo-labels.json +++ b/test/_fixtures/repo-labels.json @@ -154,6 +154,16 @@ "url": "https://api.github.com/repos/nodejs/node/labels/V8 Engine", "name": "V8 Engine", "color": "0052cc" + }, + { + "url": "https://api.github.com/repos/nodejs/node/labels/timers", + "name": "timers", + "color": "f7c6c7" + }, + { + "url": "https://api.github.com/repos/nodejs/node/labels/v6.x", + "name": "v6.x", + "color": "c2e0c6" } ], "meta": {