diff --git a/README.md b/README.md index 44e7f2b8..0535ccc9 100644 --- a/README.md +++ b/README.md @@ -68,7 +68,7 @@ It is possible to change the behaviour of the data builder by defining environme Each router directory under `configs/` has a `config.js` file that defines that router's data sources as a plain JS object (no factory function — just named -fields). It is validated by `src/utils/validateConfigSources.js` +fields). It is validated by `src/utils/configSourceValidationUtils.js` (`yarn run validate-configs`, also run as part of `yarn test` in CI, and again at runtime when the data builder starts), which rejects unknown/misspelled fields and duplicate feed ids. Its exported shape is: diff --git a/scripts/validate-config-sources.js b/scripts/validate-config-sources.js index a5b3e8d1..efc87cda 100644 --- a/scripts/validate-config-sources.js +++ b/scripts/validate-config-sources.js @@ -8,7 +8,7 @@ const fs = require('fs'); const path = require('path'); const { validateConfigSources, -} = require('../src/utils/validateConfigSources.js'); +} = require('../src/utils/configSourceValidationUtils.js'); const configsDir = path.resolve(__dirname, '../configs'); diff --git a/src/config.js b/src/config.js index 13aec4ed..d27c9551 100644 --- a/src/config.js +++ b/src/config.js @@ -1,7 +1,9 @@ const assert = require('assert'); const path = require('path'); const { applyExtraSrc, buildIdMap } = require('./utils/configUtils.js'); -const { validateConfigSources } = require('./utils/validateConfigSources.js'); +const { + validateConfigSources, +} = require('./utils/configSourceValidationUtils.js'); // OBA filter erases files which it does not recognize from GTFS packages // this array specifies the file names which should be preserved diff --git a/src/index.js b/src/index.js index 8f0f037a..860b3ed7 100644 --- a/src/index.js +++ b/src/index.js @@ -1,5 +1,6 @@ const { postSlackMessage, + finalizeBuild, getStartBuildMessage, waitForNetwork, } = require('./utils/builderUtils.js'); @@ -7,8 +8,49 @@ const { update } = require('./tasks/Update'); const { SPLIT_BUILD_TYPE, timezone } = require('./config.js'); const logger = require('./logger'); +/** + * Safety net for crashes/unexpected termination that happen outside the + * normal try/catch in Update.js#update (which already reports failures and + * posts the section-timing summary itself). If a build is in flight and + * hasn't been finalized yet, report whatever section timings were recorded + * so far as a thread reply, and mark the main message as interrupted, so the + * "Starting build..." message doesn't just look stuck forever. + */ +async function reportUnexpectedTermination(err, exitCode) { + logger.error(`Fatal error: ${err && err.stack ? err.stack : err}`); + if (global.buildFinalized) { + // finalizeBuild (called from update() or a previous invocation of this + // function) always calls process.exit itself right after setting this + // flag, so if we get here with buildFinalized already true, the build + // must have succeeded (a failure's finalizeBuild call would already + // have exited the process with code 1 before this could fire). Don't + // let an unrelated stray crash/signal flip that successful outcome to a + // failure exit code (and don't post a misleading "interrupted" message + // for a build that already finished). + process.exit(0); + return; + } + if (global.messageTimeStamp) { + await finalizeBuild({ + statusMessage: 'Build interrupted unexpectedly', + statusLevel: 'error', + summaryPrefix: 'Build interrupted unexpectedly. Section timings so far', + summaryLevel: 'error', + exitCode, + }); + return; + } + process.exit(exitCode); +} + logger.info(`Using timezone: ${timezone}`); +process.on('uncaughtException', err => reportUnexpectedTermination(err, 1)); +process.on('unhandledRejection', err => reportUnexpectedTermination(err, 1)); +process.on('SIGTERM', () => + reportUnexpectedTermination(new Error('Received SIGTERM'), 0), +); + waitForNetwork().then(() => { postSlackMessage(getStartBuildMessage(SPLIT_BUILD_TYPE)) .then(response => { diff --git a/src/tasks/BuildOTPGraph.js b/src/tasks/BuildOTPGraph.js index 872ce0d7..85f442ee 100644 --- a/src/tasks/BuildOTPGraph.js +++ b/src/tasks/BuildOTPGraph.js @@ -2,6 +2,7 @@ const fs = require('fs'); const { exec, execSync } = require('child_process'); const del = require('del'); const { otpMatching, postSlackMessage } = require('../utils/builderUtils.js'); +const { formatCodeBlock } = require('../utils/formatUtils.js'); const { zipWithGlobIntoDir } = require('./ZipTask'); const { dataDir, @@ -68,7 +69,7 @@ const buildGraph = function (router) { } else { const log = lastLog.join(''); postSlackMessage( - `${router.id} build failed: ${status}:${log}`, + `${router.id} build failed: ${status}\n${formatCodeBlock(log)}`, 'error', ); reject('could not build'); diff --git a/src/tasks/OSMPreprocessing.js b/src/tasks/OSMPreprocessing.js index d476645c..7c2b1f05 100644 --- a/src/tasks/OSMPreprocessing.js +++ b/src/tasks/OSMPreprocessing.js @@ -4,6 +4,7 @@ const exec = require('child_process').exec; const through = require('through2'); const { dataDir, constants, dataToolImage, timezone } = require('../config'); const { postSlackMessage, createDir } = require('../utils/builderUtils.js'); +const { formatCodeBlock } = require('../utils/formatUtils.js'); const logger = require('../logger'); /** @@ -64,7 +65,7 @@ function preprocessWithFile( } else { const log = lastLog.join(''); postSlackMessage( - `${osmFile} + ${preprocessingInstructionsFile} OSM preprocessing failed: ${log}`, + `${osmFile} + ${preprocessingInstructionsFile} OSM preprocessing failed:\n${formatCodeBlock(log)}`, 'warn', ); global.hasFailures = true; @@ -93,7 +94,7 @@ function preprocessWithFile( } catch (e) { const log = lastLog.join(''); postSlackMessage( - `${osmFile} + ${preprocessingInstructionsFile} OSM preprocessing failed: ${log} ${e}`, + `${osmFile} + ${preprocessingInstructionsFile} OSM preprocessing failed:\n${formatCodeBlock(`${log}\n${e}`)}`, 'error', ); fse.removeSync(folder); diff --git a/src/tasks/OTPTest.js b/src/tasks/OTPTest.js index c8e29510..371360a8 100644 --- a/src/tasks/OTPTest.js +++ b/src/tasks/OTPTest.js @@ -4,6 +4,7 @@ const exec = require('child_process').exec; const through = require('through2'); const { dataDir, constants, timezone } = require('../config'); const { postSlackMessage, createDir } = require('../utils/builderUtils.js'); +const { formatCodeBlock } = require('../utils/formatUtils.js'); const logger = require('../logger'); const testTag = process.env.OTP_TAG || 'v2'; const JAVA_OPTS = process.env.JAVA_OPTS || '-Xmx9g'; @@ -37,7 +38,10 @@ function testWithOTP(otpFile, quiet = false) { logger.info(otpFile + ' Test SUCCESS'); } else { const log = lastLog.join(''); - postSlackMessage(`${otpFile} test failed: ${log}`, 'warn'); + postSlackMessage( + `${otpFile} test failed:\n${formatCodeBlock(log)}`, + 'warn', + ); global.hasFailures = true; resolve(false); } @@ -63,7 +67,10 @@ function testWithOTP(otpFile, quiet = false) { }); } catch (e) { const log = lastLog.join(''); - postSlackMessage(`${otpFile} test failed: ${log}`, 'error'); + postSlackMessage( + `${otpFile} test failed:\n${formatCodeBlock(log)}`, + 'error', + ); fse.removeSync(folder); reject(e); } diff --git a/src/tasks/Update.js b/src/tasks/Update.js index dfc7ecd1..65e72110 100644 --- a/src/tasks/Update.js +++ b/src/tasks/Update.js @@ -8,10 +8,12 @@ const gulp = require('gulp'); const { promisify } = require('util'); const { execFileSync } = require('child_process'); const fs = require('fs'); +const { postSlackMessage, finalizeBuild } = require('../utils/builderUtils.js'); +const { timeSection } = require('../utils/timerUtils.js'); const { - postSlackMessage, - updateSlackMessage, -} = require('../utils/builderUtils.js'); + getDateStringForDockerTag, + formatCodeBlock, +} = require('../utils/formatUtils.js'); require('../../gulpfile'); const { router, SPLIT_BUILD_TYPE } = require('../config'); const assert = require('assert'); @@ -21,72 +23,70 @@ const MAX_GTFS_FALLBACK = 2; // threshold for aborting data loading const start = promisify((task, cb) => gulp.series(task)(cb)); -/** - * Docker tags don't work with ':' and file names are also prettier without them. We also need to - * remove milliseconds because they are not relevant and make converting string back to ISO format - * more difficult. - * @returns date as string - */ -function getDateString() { - return new Date().toISOString().slice(0, -5).concat('Z').replace(/:/g, '.'); -} - async function handleSeeding() { - if (!process.env.NOSEED) { - logger.info('Starting seeding'); - await start('seed'); - logger.info('Seeded'); - } + await timeSection('seed', async task => { + if (!process.env.NOSEED) { + logger.info('Starting seeding'); + await start(task); + logger.info('Seeded'); + } + }); } async function handleOsmAndDemUpdate() { if (!process.env.NODEM) { - // we track data rejections using this global variable - global.hasFailures = false; - await start('dem:update'); - if (global.hasFailures) { - postSlackMessage('DEM update failed, using previous version', 'warn'); - } + await timeSection('dem:update', async task => { + // we track data rejections using this global variable + global.hasFailures = false; + await start(task); + if (global.hasFailures) { + postSlackMessage('DEM update failed, using previous version', 'warn'); + } + }); } // OSM update is more complicated. Download often fails, so there is a retry loop, // which breaks when a big enough file gets loaded if (!process.env.USE_SEEDED_OSM) { - global.blobSizeOk = false; // ugly hack but gulp does not return any values from tasks - for (let i = 0; i < 3; i++) { - await start('osm:update'); - if (global.blobSizeOk) { - break; + await timeSection('osm:update', async task => { + global.blobSizeOk = false; // ugly hack but gulp does not return any values from tasks + for (let i = 0; i < 3; i++) { + await start(task); + if (global.blobSizeOk) { + break; + } + if (i < 2) { + // sleep 10 mins before next attempt + await new Promise(resolve => setTimeout(resolve, 600000)); + } } - if (i < 2) { - // sleep 10 mins before next attempt - await new Promise(resolve => setTimeout(resolve, 600000)); + if (!global.blobSizeOk) { + global.hasFailures = true; + postSlackMessage( + 'OSM data update failed, using previous version', + 'warn', + ); } - } - if (!global.blobSizeOk) { - global.hasFailures = true; - postSlackMessage( - 'OSM data update failed, using previous version', - 'warn', - ); - } + }); } else { logger.info('Skipping OSM update and using existing seeded data'); } } async function handleTransitDataUpdate() { - await start('gtfs:update'); - await start('netex:update'); + await timeSection('gtfs:update', task => start(task)); + await timeSection('netex:update', task => start(task)); } -function handleTests() { +async function handleTests() { if (process.env.SKIPPED_SITES === 'all' || process.env.SKIP_OTP_TESTS) { logger.info('Skipping all tests'); - } else { - logger.info('Test the newly built graph with OTPQA'); - execFileSync('./src/test.sh', [], { stdio: [0, 1, 2] }); + return; } + await timeSection('./src/test.sh', task => { + logger.info('Test the newly built graph with OTPQA'); + execFileSync(task, [], { stdio: [0, 1, 2] }); + }); } async function handleGtfsFallback(logFile) { @@ -97,11 +97,13 @@ async function handleGtfsFallback(logFile) { fs.unlinkSync(logFile); // cleanup for local use if (global.failedFeeds.split(',').length > MAX_GTFS_FALLBACK) { - updateSlackMessage( + const err = new Error( 'Aborting the data update because too many quality tests failed', - 'error', ); - process.exit(1); + // Marks this as an intentional abort so update()'s catch block can post + // this exact message instead of the generic failure message. + err.isAbort = true; + throw err; } postSlackMessage( @@ -109,60 +111,55 @@ async function handleGtfsFallback(logFile) { 'warn', ); // use seed packages for failed feeds - await start('gtfs:fallback'); -} - -function reportBuildResult(name, description) { - if (global.hasFailures) { - updateSlackMessage( - `${name} ${description}, but partially falling back to older data`, - 'warn', - ); - } else { - updateSlackMessage(`${name} ${description} :white_check_mark:`); - } + await timeSection('gtfs:fallback', task => start(task)); } -function buildAndDeployDockerImages(date) { - logger.info('Deploying otp-data-server image...'); - execFileSync('./otp-data-server/deploy.sh', [date], { - stdio: [0, 1, 2], - env: { - OTP_TAG: process.env.OTP_TAG, - OTP_GRAPH_DIR: global.storageDirName, - ROUTER_NAME: process.env.ROUTER_NAME, - ORG: process.env.ORG, - DOCKER_TAG: process.env.DOCKER_TAG, - DOCKER_USER: process.env.DOCKER_USER, - DOCKER_AUTH: process.env.DOCKER_AUTH, - }, +async function buildAndDeployDockerImages(date) { + await timeSection('./otp-data-server/deploy.sh', task => { + logger.info('Deploying otp-data-server image...'); + execFileSync(task, [date], { + stdio: [0, 1, 2], + env: { + OTP_TAG: process.env.OTP_TAG, + OTP_GRAPH_DIR: global.storageDirName, + ROUTER_NAME: process.env.ROUTER_NAME, + ORG: process.env.ORG, + DOCKER_TAG: process.env.DOCKER_TAG, + DOCKER_USER: process.env.DOCKER_USER, + DOCKER_AUTH: process.env.DOCKER_AUTH, + }, + }); }); - logger.info('Deploying opentripplanner image...'); - execFileSync('./opentripplanner/deploy-otp.sh', [date], { - stdio: [0, 1, 2], - env: { - OTP_TAG: process.env.OTP_TAG, - OTP_GRAPH_DIR: global.storageDirName, - ROUTER_NAME: process.env.ROUTER_NAME, - ORG: process.env.ORG, - DOCKER_TAG: process.env.DOCKER_TAG, - DOCKER_USER: process.env.DOCKER_USER, - DOCKER_AUTH: process.env.DOCKER_AUTH, - }, + await timeSection('./opentripplanner/deploy-otp.sh', task => { + logger.info('Deploying opentripplanner image...'); + execFileSync(task, [date], { + stdio: [0, 1, 2], + env: { + OTP_TAG: process.env.OTP_TAG, + OTP_GRAPH_DIR: global.storageDirName, + ROUTER_NAME: process.env.ROUTER_NAME, + ORG: process.env.ORG, + DOCKER_TAG: process.env.DOCKER_TAG, + DOCKER_USER: process.env.DOCKER_USER, + DOCKER_AUTH: process.env.DOCKER_AUTH, + }, + }); }); } async function handleCleanup() { - if (!process.env.NOCLEANUP) { - logger.info('Remove oldest data versions from storage'); - await start('storage:cleanup'); - } + await timeSection('storage:cleanup', async task => { + if (!process.env.NOCLEANUP) { + logger.info('Remove oldest data versions from storage'); + await start(task); + } + }); } /** * This function only builds the street graph with OSM and DEM data. */ -async function buildStreetOnlyGraph(name) { +async function buildStreetOnlyGraph(routerId) { await handleCleanup(); await handleSeeding(); @@ -170,26 +167,26 @@ async function buildStreetOnlyGraph(name) { await handleOsmAndDemUpdate(); logger.info('Build street only graph'); - await start('router:buildStreetOnlyGraph'); + await timeSection('router:buildStreetOnlyGraph', task => start(task)); - const date = getDateString(); - global.storageDirName = `osm-builds/${process.env.DOCKER_TAG}/${date}/${name}`; + const date = getDateStringForDockerTag(); + global.storageDirName = `osm-builds/${process.env.DOCKER_TAG}/${date}/${routerId}`; logger.info('Uploading street graph only build data to storage'); - await start('router:store'); + await timeSection('router:store', task => start(task)); if (!process.env.NOCLEANUP) { logger.info('Remove oldest street only graph data versions from storage'); - await start('storage:cleanupStreetOnlyGraphData'); + await timeSection('storage:cleanupStreetOnlyGraphData', task => + start(task), + ); } - - reportBuildResult(name, 'street only graph data updated'); } /** * This function does the whole build. */ -async function buildGraph(name) { +async function buildGraph(routerId) { await handleCleanup(); await handleSeeding(); @@ -199,33 +196,31 @@ async function buildGraph(name) { await handleTransitDataUpdate(); logger.info('Build routing graph'); - await start('router:buildGraph'); + await timeSection('router:buildGraph', task => start(task)); - handleTests(); + await handleTests(); const logFile = 'failed_feeds.txt'; if (fs.existsSync(logFile)) { await handleGtfsFallback(logFile); // rebuild the graph logger.info('Rebuild graph using fallback data'); - await start('router:buildGraph'); + await timeSection('router:buildGraph', task => start(task)); } - const date = getDateString(); - global.storageDirName = `${process.env.DOCKER_TAG}/${date}/${name}`; + const date = getDateStringForDockerTag(); + global.storageDirName = `${process.env.DOCKER_TAG}/${date}/${routerId}`; logger.info('Uploading data to storage'); - await start('router:store'); + await timeSection('router:store', task => start(task)); - buildAndDeployDockerImages(date); - - reportBuildResult(name, 'data updated'); + await buildAndDeployDockerImages(date); } /** * This function builds the graph from prebuilt street graph data. */ -async function buildWithPrebuiltStreetGraph(name) { +async function buildWithPrebuiltStreetGraph(routerId) { await handleCleanup(); await handleSeeding(); @@ -233,49 +228,83 @@ async function buildWithPrebuiltStreetGraph(name) { await handleTransitDataUpdate(); logger.info('Build routing graph from prebuilt street only graph'); - await start('router:buildWithPrebuiltStreetGraph'); + await timeSection('router:buildWithPrebuiltStreetGraph', task => start(task)); - handleTests(); + await handleTests(); const logFile = 'failed_feeds.txt'; if (fs.existsSync(logFile)) { await handleGtfsFallback(logFile); // rebuild the graph logger.info('Rebuild graph using fallback data'); - await start('router:buildWithPrebuiltStreetGraph'); + await timeSection('router:buildWithPrebuiltStreetGraph', task => + start(task), + ); } - const date = getDateString(); - global.storageDirName = `${process.env.DOCKER_TAG}/${date}/${name}`; + const date = getDateStringForDockerTag(); + global.storageDirName = `${process.env.DOCKER_TAG}/${date}/${routerId}`; logger.info('Uploading data to storage'); - await start('router:storeForPrebuiltStreetGraphDataBuild'); - - buildAndDeployDockerImages(date); + await timeSection('router:storeForPrebuiltStreetGraphDataBuild', task => + start(task), + ); - reportBuildResult(name, 'data updated from prebuilt street only graph'); + await buildAndDeployDockerImages(date); } async function update() { // check environmental variables which needs to be defined assert(process.env.DOCKER_TAG !== undefined, 'DOCKER_TAG must be defined'); - const name = router.id; try { + let description; switch (SPLIT_BUILD_TYPE) { case 'ONLY_BUILD_STREET_GRAPH': - await buildStreetOnlyGraph(name); + await buildStreetOnlyGraph(router.id); + description = 'street only graph data updated'; break; case 'USE_PREBUILT_STREET_GRAPH': - await buildWithPrebuiltStreetGraph(name); + await buildWithPrebuiltStreetGraph(router.id); + description = 'data updated from prebuilt street only graph'; break; default: - await buildGraph(name); + await buildGraph(router.id); + description = 'data updated'; break; } + + if (global.hasFailures) { + await finalizeBuild({ + statusMessage: `${router.id} ${description}, but partially falling back to older data`, + statusLevel: 'warn', + summaryPrefix: 'Section timings', + exitCode: 0, + }); + } else { + await finalizeBuild({ + statusMessage: `:white_check_mark: ${router.id} ${description}`, + summaryPrefix: 'Section timings', + exitCode: 0, + }); + } } catch (err) { - postSlackMessage(`${name} data update failed: ${err.message}`, 'error'); - updateSlackMessage('Something went wrong with the data update', 'error'); + if (!err.isAbort) { + // post the error detail/stack as a thread reply for debugging; abort + // errors already have a concise, user-friendly message so skip this + await postSlackMessage( + `${router.id} data update failed:\n${formatCodeBlock(err.message)}`, + 'error', + ); + } + await finalizeBuild({ + statusMessage: err.isAbort + ? err.message + : 'Something went wrong with the data update', + statusLevel: 'error', + summaryPrefix: 'Section timings', + exitCode: 1, + }); } } diff --git a/src/utils/builderUtils.js b/src/utils/builderUtils.js index c7b804e5..0ccd0bcd 100644 --- a/src/utils/builderUtils.js +++ b/src/utils/builderUtils.js @@ -5,15 +5,25 @@ const axios = require('axios'); const dns = require('dns').promises; const logger = require('../logger'); const { SPLIT_BUILD_TYPE } = require('../config'); +const { + formatClockTime, + formatDuration, + formatCodeBlock, +} = require('./formatUtils.js'); +const { getSummary } = require('./timerUtils.js'); function getStartBuildMessage(splitBuildType) { switch (splitBuildType) { case 'ONLY_BUILD_STREET_GRAPH': - return 'Starting street only graph data build :rocket:'; + return withStartTimestamp( + ':rocket: Starting street only graph data build', + ); case 'USE_PREBUILT_STREET_GRAPH': - return 'Starting graph data build from prebuilt street graph :rocket:'; + return withStartTimestamp( + ':rocket: Starting graph data build from prebuilt street graph', + ); default: - return 'Starting data build :rocket:'; + return withStartTimestamp(':rocket: Starting data build'); } } @@ -39,14 +49,42 @@ const headers = { function withLevelEmoji(text, level) { switch (level) { case 'error': - return `${text} :boom:`; + return `:boom: ${text}`; case 'warn': - return `${text} :warning:`; + return `:warning: ${text}`; default: return text; } } +/** + * Prepends the current clock time to the root ("Starting build...") message + * and records the build start time, so a total duration can later be + * computed for the edited final message. + * @param {string} text + * @returns {string} + */ +function withStartTimestamp(text) { + global.buildStartTime = Date.now(); + return `(started ${formatClockTime(new Date(global.buildStartTime))}) ${text}`; +} + +/** + * Prepends the current clock time and, if known, the total elapsed duration + * since the build started to a message that edits the root/main message. + * @param {string} text + * @returns {string} + */ +function withUpdateTimestamp(text) { + const now = new Date(); + const clock = formatClockTime(now); + if (global.buildStartTime) { + const elapsed = formatDuration(now.getTime() - global.buildStartTime); + return `(${clock}, total ${elapsed}) ${text}`; + } + return `(${clock}) ${text}`; +} + async function postSlackMessage(text, level = 'info') { logger[level](text); // write important messages also to log try { @@ -78,7 +116,7 @@ async function updateSlackMessage(text, level = 'info') { 'https://slack.com/api/chat.update', { channel: process.env.SLACK_CHANNEL_ID, - text: withLevelEmoji(text, level), + text: withUpdateTimestamp(withLevelEmoji(text, level)), username, ts: global.messageTimeStamp, }, @@ -95,6 +133,39 @@ async function updateSlackMessage(text, level = 'info') { } } +async function postSectionSummarySlackMessage(prefix, level) { + const summary = getSummary(); + if (summary) { + await postSlackMessage(`${prefix}:\n${formatCodeBlock(summary)}`, level); + } +} + +/** + * Performs every terminal step for a build: + * - posts the final status message (editing the root message) + * - posts the section-timing summary as a thread reply + * - marks the build as finalized (so index.js's crash safety net doesn't double-report) + * - exits the process with the given code + * @param {object} options + * @param {string} options.statusMessage text used to edit the root message + * @param {string} [options.statusLevel] level passed to updateSlackMessage + * @param {string} options.summaryPrefix text prepended before the section summary + * @param {string} [options.summaryLevel] level passed to postSlackMessage for the summary + * @param {number} options.exitCode process exit code + */ +async function finalizeBuild({ + statusMessage, + statusLevel, + summaryPrefix, + summaryLevel, + exitCode, +}) { + await updateSlackMessage(statusMessage, statusLevel); + await postSectionSummarySlackMessage(summaryPrefix, summaryLevel); + global.buildFinalized = true; + process.exit(exitCode); +} + const UNCONNECTED = /Could not connect .*:(\d*) \(([A-Z]?[a-z]?\d{4})\) at \((\d+\.\d+), (\d+\.\d+)/; const CONNECTED = @@ -226,6 +297,7 @@ async function waitForNetwork() { module.exports = { postSlackMessage, updateSlackMessage, + finalizeBuild, getStartBuildMessage, otpMatching, parseId, diff --git a/src/utils/validateConfigSources.js b/src/utils/configSourceValidationUtils.js similarity index 100% rename from src/utils/validateConfigSources.js rename to src/utils/configSourceValidationUtils.js diff --git a/src/utils/formatUtils.js b/src/utils/formatUtils.js new file mode 100644 index 00000000..2643bdfb --- /dev/null +++ b/src/utils/formatUtils.js @@ -0,0 +1,70 @@ +const { timezone } = require('../config'); + +/** + * Formats a Date as a HH:mm:ss clock time in the configured build timezone. + * @param {Date} date + * @returns {string} + */ +function formatClockTime(date) { + return new Intl.DateTimeFormat('en-GB', { + timeZone: timezone, + hour: '2-digit', + minute: '2-digit', + second: '2-digit', + hour12: false, + }).format(date); +} + +/** + * Formats a duration in milliseconds as e.g. "1h02m03s", "12m34s" or "34s". + * @param {number} ms + * @returns {string} + */ +function formatDuration(ms) { + const totalSeconds = Math.max(0, Math.round(ms / 1000)); + const hours = Math.floor(totalSeconds / 3600); + const minutes = Math.floor((totalSeconds % 3600) / 60); + const seconds = totalSeconds % 60; + if (hours > 0) { + return `${hours}h${String(minutes).padStart(2, '0')}m${String(seconds).padStart(2, '0')}s`; + } + if (minutes > 0) { + return `${minutes}m${String(seconds).padStart(2, '0')}s`; + } + return `${seconds}s`; +} + +/** + * Wraps text in a Slack code block (monospaced, rendered as a single + * message) so raw multi-line logs/stack traces are readable instead of + * looking like plain chat text. Long text is truncated from the start, + * keeping the tail (the most relevant/recent output, e.g. the actual + * error), to guard against Slack's message size limits. + * @param {string} text + * @param {number} [maxLength] + * @returns {string} + */ +function formatCodeBlock(text, maxLength = 3800) { + const truncated = + text.length > maxLength + ? `... (truncated)\n${text.slice(-maxLength)}` + : text; + return `\`\`\`${truncated}\`\`\``; +} + +/** + * Docker tags don't work with ':' and file names are also prettier without them. We also need to + * remove milliseconds because they are not relevant and make converting string back to ISO format + * more difficult. + * @returns date as string + */ +function getDateStringForDockerTag() { + return new Date().toISOString().slice(0, -5).concat('Z').replace(/:/g, '.'); +} + +module.exports = { + formatClockTime, + formatDuration, + formatCodeBlock, + getDateStringForDockerTag, +}; diff --git a/src/utils/timerUtils.js b/src/utils/timerUtils.js new file mode 100644 index 00000000..351dea0d --- /dev/null +++ b/src/utils/timerUtils.js @@ -0,0 +1,95 @@ +const { formatDuration } = require('./formatUtils.js'); + +/** + * Ordered list of {name, start, end} entries. `end` is null while running. + * + * Tracks how long each main build section took, so a duration summary can be + * posted to Slack (as a thread reply) once the build finishes or is + * interrupted. Sections are recorded in the order they are started; a + * section name may be started/ended more than once (e.g. "build_graph" runs + * again after a GTFS fallback rebuild) and each run is kept as a separate + * entry. + */ +const sections = []; + +/** + * Marks the start of a named build section. + * @param {string} name human-readable section label, e.g. "Seeding" + */ +function startSection(name) { + sections.push({ name, start: Date.now(), end: null }); +} + +/** + * Marks the end of the most recently started, still-running section with + * the given name. + * @param {string} name section label passed to the matching startSection call + */ +function endSection(name) { + const section = [...sections] + .reverse() + .find(s => s.name === name && s.end === null); + if (section) { + section.end = Date.now(); + } +} + +/** + * Wraps an async function with startSection/endSection calls, ending the + * section even if the wrapped function throws. The task name is passed on + * to `fn` so callers can reuse it directly (e.g. as the gulp task name or + * script path to run) instead of repeating the literal string. + * @param {string} task section label — the gulp task name or script path + * this section represents, e.g. "seed" or "./src/test.sh" + * @param {(task: string) => Promise} fn function to time, called with `task` + * @returns {Promise} + */ +async function timeSection(task, fn) { + startSection(task); + try { + return await fn(task); + } finally { + endSection(task); + } +} + +/** + * Builds a simple ASCII table listing every section recorded so far and how long + * it took, including ones that never finished (marked "interrupted"). Returns + * null if no sections have been recorded yet. + * @returns {string|null} + */ +function getSummary() { + if (sections.length === 0) { + return null; + } + const rows = sections.map(({ name, start, end }) => [ + name, + end === null + ? `interrupted after ${formatDuration(Date.now() - start)}` + : formatDuration(end - start), + ]); + const nameHeader = 'Section'; + const durationHeader = 'Duration'; + const nameWidth = Math.max( + nameHeader.length, + ...rows.map(([name]) => name.length), + ); + const durationWidth = Math.max( + durationHeader.length, + ...rows.map(([, duration]) => duration.length), + ); + const formatRow = (name, duration) => + `${name.padEnd(nameWidth)} ${duration.padEnd(durationWidth)}`; + const lines = [ + formatRow(nameHeader, durationHeader), + '-'.repeat(nameWidth + durationWidth + 2), + ...rows.map(([name, duration]) => formatRow(name, duration)), + ]; + return lines.join('\n'); +} + +module.exports = { + timeSection, + getSummary, +};