diff --git a/package-lock.json b/package-lock.json index c8747fe2..41f87cce 100644 --- a/package-lock.json +++ b/package-lock.json @@ -4807,6 +4807,14 @@ "node": ">= 4.0.0" } }, + "node_modules/atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==", + "engines": { + "node": ">=8.0.0" + } + }, "node_modules/atomically": { "version": "1.7.0", "license": "MIT", @@ -7580,6 +7588,14 @@ "integrity": "sha512-DCXu6Ifhqcks7TZKY3Hxp3y6qphY5SJZmrWMDrKcERSOXWQdMhU9Ig/PYrzyw/ul9jOIyh0N4M0tbC5hodg8dw==", "dev": true }, + "node_modules/fast-redact": { + "version": "3.5.0", + "resolved": "https://registry.npmjs.org/fast-redact/-/fast-redact-3.5.0.tgz", + "integrity": "sha512-dwsoQlS7h9hMeYUq1W++23NDcBLV4KqONnITDV9DjfS3q1SgDGVrBdvvTLUotWtPSD7asWDV9/CmsZPy8Hf70A==", + "engines": { + "node": ">=6" + } + }, "node_modules/fast-unique-numbers": { "version": "8.0.13", "resolved": "https://registry.npmjs.org/fast-unique-numbers/-/fast-unique-numbers-8.0.13.tgz", @@ -15516,6 +15532,14 @@ "node": ">=10" } }, + "node_modules/on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==", + "engines": { + "node": ">=14.0.0" + } + }, "node_modules/once": { "version": "1.4.0", "license": "ISC", @@ -15883,6 +15907,48 @@ "node": ">=6" } }, + "node_modules/pino": { + "version": "9.5.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-9.5.0.tgz", + "integrity": "sha512-xSEmD4pLnV54t0NOUN16yCl7RIB1c5UUOse5HSyEXtBp+FgFQyPeDutc+Q2ZO7/22vImV7VfEjH/1zV2QuqvYw==", + "dependencies": { + "atomic-sleep": "^1.0.0", + "fast-redact": "^3.1.1", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^2.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^0.2.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^3.0.0" + }, + "bin": { + "pino": "bin.js" + } + }, + "node_modules/pino-abstract-transport": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-2.0.0.tgz", + "integrity": "sha512-F63x5tizV6WCh4R6RHyi2Ml+M70DNRXt/+HANowMflpgGFMAym/VKm6G7ZOQRjqN7XbGxK1Lg9t6ZrtzOaivMw==", + "dependencies": { + "split2": "^4.0.0" + } + }, + "node_modules/pino-abstract-transport/node_modules/split2": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz", + "integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==", + "engines": { + "node": ">= 10.x" + } + }, + "node_modules/pino-std-serializers": { + "version": "7.0.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.0.0.tgz", + "integrity": "sha512-e906FRY0+tV27iq4juKzSYPbUj2do2X2JX4EzSca1631EB2QJQUqGbDuERal7LCtOpxl6x3+nvo9NPZcmjkiFA==" + }, "node_modules/pirates": { "version": "4.0.6", "resolved": "https://registry.npmjs.org/pirates/-/pirates-4.0.6.tgz", @@ -16152,6 +16218,11 @@ "version": "2.0.1", "license": "MIT" }, + "node_modules/process-warning": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-4.0.0.tgz", + "integrity": "sha512-/MyYDxttz7DfGMMHiysAsFE4qF+pQYAA8ziO/3NcRVrQ5fSk+Mns4QZA/oRPFzvcqNoVJXQNWNAsdwBXLUkQKw==" + }, "node_modules/promise-all-reject-late": { "version": "1.0.1", "dev": true, @@ -16265,6 +16336,11 @@ ], "license": "MIT" }, + "node_modules/quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==" + }, "node_modules/quick-lru": { "version": "5.1.1", "dev": true, @@ -16395,6 +16471,14 @@ "once": "^1.3.0" } }, + "node_modules/real-require": { + "version": "0.2.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", + "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==", + "engines": { + "node": ">= 12.13.0" + } + }, "node_modules/recast": { "version": "0.23.4", "resolved": "https://registry.npmjs.org/recast/-/recast-0.23.4.tgz", @@ -16688,6 +16772,14 @@ "url": "https://github.com/sponsors/ljharb" } }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "dev": true, @@ -16871,6 +16963,14 @@ "node": ">= 10" } }, + "node_modules/sonic-boom": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.0.tgz", + "integrity": "sha512-INb7TM37/mAcsGmc9hyyI6+QR3rR1zVRu36B0NeGXKnOOLiZOfER5SA+N7X7k3yUYRzLWafduTDvJAfDswwEww==", + "dependencies": { + "atomic-sleep": "^1.0.0" + } + }, "node_modules/sort-keys": { "version": "4.2.0", "dev": true, @@ -17307,6 +17407,14 @@ "url": "https://bevry.me/fund" } }, + "node_modules/thread-stream": { + "version": "3.1.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-3.1.0.tgz", + "integrity": "sha512-OqyPZ9u96VohAyMfJykzmivOrY2wfMSf3C5TtFJVgN+Hm6aj+voFhlK+kZEIv2FBh1X6Xp3DlnCOfEQ3B2J86A==", + "dependencies": { + "real-require": "^0.2.0" + } + }, "node_modules/through": { "version": "2.3.8", "dev": true, @@ -18747,6 +18855,7 @@ "mqtt": "5.10.1", "open": "8.4.0", "p-queue": "6.6.2", + "pino": "9.5.0", "prompts": "2.4.2", "proxy-from-env": "1.1.0", "recast": "0.23.4", @@ -22497,6 +22606,11 @@ "at-least-node": { "version": "1.0.0" }, + "atomic-sleep": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/atomic-sleep/-/atomic-sleep-1.0.0.tgz", + "integrity": "sha512-kNOjDqAh7px0XWNI+4QbzoiR/nTkHAWNud2uvnJquD1/x5a7EQZMJT0AczqK0Qn67oY/TTQ1LbUKajZpp3I9tQ==" + }, "atomically": { "version": "1.7.0" }, @@ -22952,6 +23066,7 @@ "oclif": "3.7.3", "open": "8.4.0", "p-queue": "6.6.2", + "pino": "9.5.0", "prompts": "2.4.2", "proxy-from-env": "1.1.0", "recast": "0.23.4", @@ -24581,6 +24696,11 @@ "integrity": "sha512-DCXu6Ifhqcks7TZKY3Hxp3y6qphY5SJZmrWMDrKcERSOXWQdMhU9Ig/PYrzyw/ul9jOIyh0N4M0tbC5hodg8dw==", "dev": true }, + "fast-redact": { + "version": "3.5.0", + "resolved": "https://registry.npmjs.org/fast-redact/-/fast-redact-3.5.0.tgz", + "integrity": "sha512-dwsoQlS7h9hMeYUq1W++23NDcBLV4KqONnITDV9DjfS3q1SgDGVrBdvvTLUotWtPSD7asWDV9/CmsZPy8Hf70A==" + }, "fast-unique-numbers": { "version": "8.0.13", "resolved": "https://registry.npmjs.org/fast-unique-numbers/-/fast-unique-numbers-8.0.13.tgz", @@ -29808,6 +29928,11 @@ } } }, + "on-exit-leak-free": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/on-exit-leak-free/-/on-exit-leak-free-2.1.2.tgz", + "integrity": "sha512-0eJJY6hXLGf1udHwfNftBqH+g73EU4B504nZeKpz1sYRKafAghwxEJunB2O7rDZkL4PGfsMVnTXZ2EjibbqcsA==" + }, "once": { "version": "1.4.0", "requires": { @@ -30032,6 +30157,44 @@ "version": "4.0.1", "dev": true }, + "pino": { + "version": "9.5.0", + "resolved": "https://registry.npmjs.org/pino/-/pino-9.5.0.tgz", + "integrity": "sha512-xSEmD4pLnV54t0NOUN16yCl7RIB1c5UUOse5HSyEXtBp+FgFQyPeDutc+Q2ZO7/22vImV7VfEjH/1zV2QuqvYw==", + "requires": { + "atomic-sleep": "^1.0.0", + "fast-redact": "^3.1.1", + "on-exit-leak-free": "^2.1.0", + "pino-abstract-transport": "^2.0.0", + "pino-std-serializers": "^7.0.0", + "process-warning": "^4.0.0", + "quick-format-unescaped": "^4.0.3", + "real-require": "^0.2.0", + "safe-stable-stringify": "^2.3.1", + "sonic-boom": "^4.0.1", + "thread-stream": "^3.0.0" + } + }, + "pino-abstract-transport": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/pino-abstract-transport/-/pino-abstract-transport-2.0.0.tgz", + "integrity": "sha512-F63x5tizV6WCh4R6RHyi2Ml+M70DNRXt/+HANowMflpgGFMAym/VKm6G7ZOQRjqN7XbGxK1Lg9t6ZrtzOaivMw==", + "requires": { + "split2": "^4.0.0" + }, + "dependencies": { + "split2": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/split2/-/split2-4.2.0.tgz", + "integrity": "sha512-UcjcJOWknrNkF6PLX83qcHM6KHgVKNkV62Y8a5uYDVv9ydGQVwAHMKqHdJje1VTWpljG0WYpCDhrCdAOYH4TWg==" + } + } + }, + "pino-std-serializers": { + "version": "7.0.0", + "resolved": "https://registry.npmjs.org/pino-std-serializers/-/pino-std-serializers-7.0.0.tgz", + "integrity": "sha512-e906FRY0+tV27iq4juKzSYPbUj2do2X2JX4EzSca1631EB2QJQUqGbDuERal7LCtOpxl6x3+nvo9NPZcmjkiFA==" + }, "pirates": { "version": "4.0.6", "resolved": "https://registry.npmjs.org/pirates/-/pirates-4.0.6.tgz", @@ -30191,6 +30354,11 @@ "process-nextick-args": { "version": "2.0.1" }, + "process-warning": { + "version": "4.0.0", + "resolved": "https://registry.npmjs.org/process-warning/-/process-warning-4.0.0.tgz", + "integrity": "sha512-/MyYDxttz7DfGMMHiysAsFE4qF+pQYAA8ziO/3NcRVrQ5fSk+Mns4QZA/oRPFzvcqNoVJXQNWNAsdwBXLUkQKw==" + }, "promise-all-reject-late": { "version": "1.0.1", "dev": true @@ -30248,6 +30416,11 @@ "queue-microtask": { "version": "1.2.3" }, + "quick-format-unescaped": { + "version": "4.0.4", + "resolved": "https://registry.npmjs.org/quick-format-unescaped/-/quick-format-unescaped-4.0.4.tgz", + "integrity": "sha512-tYC1Q1hgyRuHgloV/YXs2w15unPVh8qfu/qCTfhTYamaw7fyhumKa2yGpdSo87vY32rIclj+4fWYQXUMs9EHvg==" + }, "quick-lru": { "version": "5.1.1", "dev": true @@ -30337,6 +30510,11 @@ "once": "^1.3.0" } }, + "real-require": { + "version": "0.2.0", + "resolved": "https://registry.npmjs.org/real-require/-/real-require-0.2.0.tgz", + "integrity": "sha512-57frrGM/OCTLqLOAh0mhVA9VBMHd+9U7Zb2THMGdBUoZVOtGbJzjxsYGDJ3A9AYYCP4hn6y1TVbaOfzWtm5GFg==" + }, "recast": { "version": "0.23.4", "resolved": "https://registry.npmjs.org/recast/-/recast-0.23.4.tgz", @@ -30505,6 +30683,11 @@ "is-regex": "^1.1.4" } }, + "safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==" + }, "safer-buffer": { "version": "2.1.2", "dev": true @@ -30612,6 +30795,14 @@ "socks": "^2.6.2" } }, + "sonic-boom": { + "version": "4.2.0", + "resolved": "https://registry.npmjs.org/sonic-boom/-/sonic-boom-4.2.0.tgz", + "integrity": "sha512-INb7TM37/mAcsGmc9hyyI6+QR3rR1zVRu36B0NeGXKnOOLiZOfER5SA+N7X7k3yUYRzLWafduTDvJAfDswwEww==", + "requires": { + "atomic-sleep": "^1.0.0" + } + }, "sort-keys": { "version": "4.2.0", "dev": true, @@ -30907,6 +31098,14 @@ "version": "5.15.0", "dev": true }, + "thread-stream": { + "version": "3.1.0", + "resolved": "https://registry.npmjs.org/thread-stream/-/thread-stream-3.1.0.tgz", + "integrity": "sha512-OqyPZ9u96VohAyMfJykzmivOrY2wfMSf3C5TtFJVgN+Hm6aj+voFhlK+kZEIv2FBh1X6Xp3DlnCOfEQ3B2J86A==", + "requires": { + "real-require": "^0.2.0" + } + }, "through": { "version": "2.3.8", "dev": true diff --git a/packages/cli/package.json b/packages/cli/package.json index 996fc6ac..b0054da2 100644 --- a/packages/cli/package.json +++ b/packages/cli/package.json @@ -91,6 +91,7 @@ "mqtt": "5.10.1", "open": "8.4.0", "p-queue": "6.6.2", + "pino": "9.5.0", "prompts": "2.4.2", "proxy-from-env": "1.1.0", "recast": "0.23.4", diff --git a/packages/cli/src/commands/deploy.ts b/packages/cli/src/commands/deploy.ts index da157a73..3db45744 100644 --- a/packages/cli/src/commands/deploy.ts +++ b/packages/cli/src/commands/deploy.ts @@ -17,6 +17,7 @@ import { splitConfigFilePath, getGitInformation } from '../services/util' import commonMessages from '../messages/common-messages' import { ProjectDeployResponse } from '../rest/projects' import { uploadSnapshots } from '../services/snapshot-service' +import { rootLogger } from '../services/logger' // eslint-disable-next-line no-restricted-syntax enum ResourceDeployStatus { @@ -58,6 +59,12 @@ export default class Deploy extends AuthCommand { } async run (): Promise { + const logger = rootLogger.child({ + cli: { + cmd: 'deploy', + }, + }) + ux.action.start('Parsing your project', undefined, { stdout: true }) const { flags } = await this.parse(Deploy) const { @@ -126,7 +133,21 @@ export default class Deploy extends AuthCommand { } try { - const { data } = await api.projects.deploy({ ...projectPayload, repoInfo }, { dryRun: preview, scheduleOnDeploy }) + const { data } = await api.projects.deploy( + { ...projectPayload, repoInfo }, + { dryRun: preview, scheduleOnDeploy }, + { + onUploadProgress: (event) => { + logger.trace({ + progress: { + sent: event.loaded, + total: event.total, + lengthComputable: event.lengthComputable, + }, + }, 'Project payload upload progress') + }, + }, + ) if (preview || output) { this.log(this.formatPreview(data, project)) } diff --git a/packages/cli/src/commands/test.ts b/packages/cli/src/commands/test.ts index 280283e2..b085d8be 100644 --- a/packages/cli/src/commands/test.ts +++ b/packages/cli/src/commands/test.ts @@ -24,6 +24,7 @@ import commonMessages from '../messages/common-messages' import { TestResultsShortLinks } from '../rest/test-sessions' import { printLn, formatCheckTitle, CheckStatus } from '../reporters/util' import { uploadSnapshots } from '../services/snapshot-service' +import { rootLogger } from '../services/logger' const DEFAULT_REGION = 'eu-central-1' const MAX_RETRIES = 3 @@ -118,6 +119,12 @@ export default class Test extends AuthCommand { static strict = false async run (): Promise { + const logger = rootLogger.child({ + cli: { + cmd: 'test', + }, + }) + ux.action.start('Parsing your project', undefined, { stdout: true }) const { flags, argv } = await this.parse(Test) @@ -154,6 +161,7 @@ export default class Test extends AuthCommand { const reporterTypes = this.prepareReportersTypes(reporterFlag as ReporterType, checklyConfig.cli?.reporters) const { data: availableRuntimes } = await api.runtimes.getAll() + logger.debug('Parsing project') const project = await parseProject({ directory: configDirectory, projectLogicalId: checklyConfig.logicalId, @@ -171,6 +179,8 @@ export default class Test extends AuthCommand { }, > {}), checklyConfigConstructs, }) + + logger.debug({ project }, 'Finished parsing project') const checks = Object.entries(project.data.check) .filter(([, check]) => { return !(check instanceof HeartbeatCheck) @@ -211,11 +221,47 @@ export default class Test extends AuthCommand { return check }) + // Separate browser checks for snapshot uploads. + const browserChecks: Array = [] for (const check of checks) { if (!(check instanceof BrowserCheck)) { continue } - check.snapshots = await uploadSnapshots(check.rawSnapshots) + if (!check.rawSnapshots?.length) { + logger.trace( + { check: { logicalId: check.logicalId } }, + 'Check has no snapshots to upload', + ) + continue + } + browserChecks.push(check) + } + + logger.info( + { count: browserChecks.length }, + 'Collected all snapshots to upload', + ) + + for (const check of browserChecks) { + const sublogger = logger.child( + { check: { logicalId: check.logicalId } }, + ) + sublogger.info( + { rawSnapshots: check.rawSnapshots }, + 'Uploading check snapshots', + ) + check.snapshots = await uploadSnapshots(check.rawSnapshots, { + onUploadProgress: (snapshot, event) => { + sublogger.trace({ + snapshot, + progress: { + sent: event.loaded, + total: event.total, + lengthComputable: event.lengthComputable, + }, + }, 'Snapshot upload progress') + }, + }) } ux.action.stop() @@ -236,6 +282,7 @@ export default class Test extends AuthCommand { const testRetryStrategy = this.prepareTestRetryStrategy(retries, checklyConfig?.cli?.retries) const runner = new TestRunner( + logger, config.getAccountId(), project, checks, @@ -251,9 +298,9 @@ export default class Test extends AuthCommand { ) runner.on(Events.RUN_STARTED, - (checks: Array<{ check: any, sequenceId: SequenceId }>, testSessionId: string) => - reporters.forEach(r => r.onBegin(checks, testSessionId)), - ) + (checks: Array<{ check: any, sequenceId: SequenceId }>, testSessionId: string) => { + reporters.forEach(r => r.onBegin(checks, testSessionId)) + }) runner.on(Events.CHECK_INPROGRESS, (check: any, sequenceId: SequenceId) => { reporters.forEach(r => r.onCheckInProgress(check, sequenceId)) diff --git a/packages/cli/src/commands/trigger.ts b/packages/cli/src/commands/trigger.ts index 0315e7e1..38e7080a 100644 --- a/packages/cli/src/commands/trigger.ts +++ b/packages/cli/src/commands/trigger.ts @@ -19,6 +19,7 @@ import { createReporters, ReporterType } from '../reporters/reporter' import { printLn } from '../reporters/util' import { TestResultsShortLinks } from '../rest/test-sessions' import { Session, RetryStrategyBuilder } from '../constructs' +import { rootLogger } from '../services/logger' const DEFAULT_REGION = 'eu-central-1' const MAX_RETRIES = 3 @@ -88,6 +89,12 @@ export default class Trigger extends AuthCommand { } async run (): Promise { + const logger = rootLogger.child({ + cli: { + cmd: 'trigger', + }, + }) + const { flags } = await this.parse(Trigger) const { location: runLocation, @@ -124,6 +131,7 @@ export default class Trigger extends AuthCommand { const ciInfo = getCiInformation() const runner = new TriggerRunner( + logger, config.getAccountId(), timeout, verbose, diff --git a/packages/cli/src/rest/checkly-storage.ts b/packages/cli/src/rest/checkly-storage.ts index 114ab3d7..f36ef3e6 100644 --- a/packages/cli/src/rest/checkly-storage.ts +++ b/packages/cli/src/rest/checkly-storage.ts @@ -1,22 +1,36 @@ -import type { AxiosInstance } from 'axios' +import type { AxiosInstance, AxiosProgressEvent } from 'axios' import type { Readable } from 'node:stream' +type UploadOptions = { + onUploadProgress?: (progressEvent: AxiosProgressEvent) => void +} + +type DownloadOptions = { + onDownloadProgress?: (progressEvent: AxiosProgressEvent) => void +} + class ChecklyStorage { api: AxiosInstance constructor (api: AxiosInstance) { this.api = api } - upload (stream: Readable) { + upload (stream: Readable, options?: UploadOptions) { return this.api.post<{ key: string }>( '/next/checkly-storage/upload', stream, - { headers: { 'Content-Type': 'application/octet-stream' } }, + { + headers: { 'Content-Type': 'application/octet-stream' }, + onUploadProgress: options?.onUploadProgress, + }, ) } - download (key: string) { - return this.api.post('/next/checkly-storage/download', { key }, { responseType: 'stream' }) + download (key: string, options?: DownloadOptions) { + return this.api.post('/next/checkly-storage/download', { key }, { + responseType: 'stream', + onDownloadProgress: options?.onDownloadProgress, + }) } } diff --git a/packages/cli/src/rest/projects.ts b/packages/cli/src/rest/projects.ts index 0e32539c..1b04cec6 100644 --- a/packages/cli/src/rest/projects.ts +++ b/packages/cli/src/rest/projects.ts @@ -1,5 +1,6 @@ -import type { AxiosInstance } from 'axios' +import type { AxiosInstance, AxiosProgressEvent } from 'axios' import type { GitInformation } from '../services/util' +import Deploy from '../commands/deploy' export interface Project { name: string @@ -34,6 +35,10 @@ export interface ProjectDeployResponse { diff: Array } +export type DeployOptions = { + onUploadProgress?: (progressEvent: AxiosProgressEvent) => void +} + class Projects { api: AxiosInstance constructor (api: AxiosInstance) { @@ -56,10 +61,11 @@ class Projects { return this.api.delete(`/next/projects/${logicalId}`) } - deploy (resources: ProjectSync, { dryRun = false, scheduleOnDeploy = true } = {}) { + deploy (resources: ProjectSync, { dryRun = false, scheduleOnDeploy = true } = {}, options?: DeployOptions) { return this.api.post( `/next-v2/projects/deploy?dryRun=${dryRun}&scheduleOnDeploy=${scheduleOnDeploy}`, resources, + { onUploadProgress: options?.onUploadProgress }, ) } } diff --git a/packages/cli/src/rest/test-sessions.ts b/packages/cli/src/rest/test-sessions.ts index cea6eb59..a31df9f2 100644 --- a/packages/cli/src/rest/test-sessions.ts +++ b/packages/cli/src/rest/test-sessions.ts @@ -1,4 +1,4 @@ -import type { AxiosInstance } from 'axios' +import type { AxiosInstance, AxiosProgressEvent } from 'axios' import { GitInformation } from '../services/util' import { RetryStrategy } from '../constructs' @@ -31,14 +31,20 @@ export type TestResultsShortLinks = { screenshotLinks: string[] } +export type RunOptions = { + onUploadProgress?: (progressEvent: AxiosProgressEvent) => void +} + class TestSessions { api: AxiosInstance constructor (api: AxiosInstance) { this.api = api } - run (payload: RunTestSessionRequest) { - return this.api.post('/next/test-sessions/run', payload) + run (payload: RunTestSessionRequest, options?: RunOptions) { + return this.api.post('/next/test-sessions/run', payload, { + onUploadProgress: options?.onUploadProgress, + }) } trigger (payload: TriggerTestSessionRequest) { diff --git a/packages/cli/src/services/abstract-check-runner.ts b/packages/cli/src/services/abstract-check-runner.ts index 73ee504c..cd5965fb 100644 --- a/packages/cli/src/services/abstract-check-runner.ts +++ b/packages/cli/src/services/abstract-check-runner.ts @@ -6,6 +6,7 @@ import { EventEmitter } from 'node:events' import type { MqttClient } from 'mqtt' import type { Region } from '..' import { TestResultsShortLinks } from '../rest/test-sessions' +import type { Logger } from './logger' // eslint-disable-next-line no-restricted-syntax export enum Events { @@ -40,6 +41,8 @@ export const DEFAULT_CHECK_RUN_TIMEOUT_SECONDS = 600 const DEFAULT_SCHEDULING_DELAY_EXCEEDED_MS = 20000 export default abstract class AbstractCheckRunner extends EventEmitter { + originalLogger: Logger + logger: Logger checks: Map testSessionId?: string // If there's an error in the backend and no check result is sent, the check run could block indefinitely. @@ -52,11 +55,14 @@ export default abstract class AbstractCheckRunner extends EventEmitter { queue: PQueue constructor ( + logger: Logger, accountId: string, timeout: number, verbose: boolean, ) { super() + this.originalLogger = logger + this.logger = logger this.checks = new Map() this.timeouts = new Map() this.queue = new PQueue({ autoStart: false, concurrency: 1 }) @@ -72,14 +78,45 @@ export default abstract class AbstractCheckRunner extends EventEmitter { }> async run () { + const checkRunSuiteId = uuid.v4() + + const logger = this.logger = this.originalLogger.child({ + checkRunSuiteId, + }) + let socketClient = null try { - socketClient = await SocketClient.connect() + logger.info('Starting check run') + + socketClient = await SocketClient.connect(logger) + + socketClient.on('close', () => { + logger.debug('MQTT client connection closed') + }) + socketClient.on('connect', () => { + // Note: does not trigger for the initial connection because by this time we're already connected. + logger.debug('MQTT client is connected') + }) + socketClient.on('disconnect', () => { + logger.debug('MQTT client has disconnected') + }) + socketClient.on('end', () => { + logger.debug('MQTT client connection has ended') + }) + socketClient.on('error', (err) => { + logger.warn({ err }, 'MQTT client encountered an error') + }) + socketClient.on('offline', () => { + logger.debug('MQTT client is offline') + }) + socketClient.on('reconnect', () => { + logger.debug('MQTT client is reconnecting') + }) - const checkRunSuiteId = uuid.v4() // Configure the socket listener and allChecksFinished listener before starting checks to avoid race conditions await this.configureResultListener(checkRunSuiteId, socketClient) + logger.info('Scheduling checks') const { testSessionId, checks } = await this.scheduleChecks(checkRunSuiteId) this.testSessionId = testSessionId this.checks = new Map( @@ -98,25 +135,37 @@ export default abstract class AbstractCheckRunner extends EventEmitter { // Otherwise, there could be a race condition causing check results to be missed by `allChecksFinished()`. const allChecksFinished = this.allChecksFinished() /// / Need to structure the checks depending on how it went + + logger.info({ checks, testSessionId }, 'Run started') this.emit(Events.RUN_STARTED, checks, testSessionId) // Start the queue after the test session run rest call is completed to avoid race conditions this.queue.start() + logger.info('Waiting for all checks to finish') await allChecksFinished + + logger.info('All checks have finished') this.emit(Events.RUN_FINISHED, testSessionId) + + logger.info('Check run completed successfully') } catch (err) { + logger.error({ err }, 'Check run failed') this.disableAllTimeouts() this.emit(Events.ERROR, err) } finally { if (socketClient) { + logger.info('Ending connection to MQTT broker') await socketClient.endAsync() } + logger.info('Finished processing check run') } } private async configureResultListener (checkRunSuiteId: string, socketClient: MqttClient): Promise { socketClient.on('message', (topic: string, rawMessage: string|Buffer) => { const message = JSON.parse(rawMessage.toString('utf8')) + this.logger.trace({ message }, 'Received message from MQTT broker') + const topicComponents = topic.split('/') const sequenceId = topicComponents[4] const checkRunId = topicComponents[5] @@ -163,6 +212,20 @@ export default abstract class AbstractCheckRunner extends EventEmitter { } } + emit (eventName: string | symbol, ...args: any[]): boolean { + this.logger.trace( + { + event: { + name: eventName, + args, + }, + }, + 'Runner event', + ) + + return super.emit(eventName, ...args) + } + async processCheckResult (result: any) { const { region, diff --git a/packages/cli/src/services/logger.ts b/packages/cli/src/services/logger.ts new file mode 100644 index 00000000..2b2edc97 --- /dev/null +++ b/packages/cli/src/services/logger.ts @@ -0,0 +1,24 @@ +import pino from 'pino' + +export const rootLogger = pino( + { + level: process.env.CHECKLY_LOG_LEVEL || 'silent', + formatters: { + bindings: (bindings) => { + return { pid: bindings.pid } + }, + level: (label) => { + return { level: label.toUpperCase() } + }, + }, + timestamp: pino.stdTimeFunctions.isoTime, + redact: { + paths: [ + 'password', + ], + }, + }, + pino.destination('checkly.debug.log'), +) + +export type Logger = pino.Logger diff --git a/packages/cli/src/services/project-parser.ts b/packages/cli/src/services/project-parser.ts index d38c2fe0..4fbfd29b 100644 --- a/packages/cli/src/services/project-parser.ts +++ b/packages/cli/src/services/project-parser.ts @@ -7,6 +7,7 @@ import { } from '../constructs' import { Ref } from '../constructs/ref' import { CheckConfigDefaults } from './checkly-config-loader' +import { rootLogger } from './logger' import type { Runtime } from '../rest/runtimes' import type { Construct } from '../constructs/construct' diff --git a/packages/cli/src/services/snapshot-service.ts b/packages/cli/src/services/snapshot-service.ts index d4ba238c..f743a6bf 100644 --- a/packages/cli/src/services/snapshot-service.ts +++ b/packages/cli/src/services/snapshot-service.ts @@ -3,6 +3,8 @@ import * as fs from 'node:fs' import * as path from 'node:path' import * as stream from 'node:stream/promises' +import type { AxiosProgressEvent } from 'axios' + import { checklyStorage } from '../rest/api' import { findFilesRecursively, pathToPosix } from './util' @@ -45,7 +47,16 @@ export function detectSnapshots (projectBasePath: string, scriptFilePath: string })) } -export async function uploadSnapshots (rawSnapshots?: Array<{ absolutePath: string, path: string }>) { +type UploadSnapshot = { + absolutePath: string + path: string +} + +type UploadSnapshotOptions = { + onUploadProgress?: (snapshot: UploadSnapshot, event: AxiosProgressEvent) => void +} + +export async function uploadSnapshots (rawSnapshots?: Array, options?: UploadSnapshotOptions) { if (!rawSnapshots?.length) { return [] } @@ -54,7 +65,11 @@ export async function uploadSnapshots (rawSnapshots?: Array<{ absolutePath: stri const snapshots: Array = [] for (const rawSnapshot of rawSnapshots) { const snapshotStream = fs.createReadStream(rawSnapshot.absolutePath) - const { data: { key } } = await checklyStorage.upload(snapshotStream) + const { data: { key } } = await checklyStorage.upload(snapshotStream, { + onUploadProgress: (event) => { + options?.onUploadProgress?.(rawSnapshot, event) + }, + }) snapshots.push({ key, path: rawSnapshot.path }) } return snapshots diff --git a/packages/cli/src/services/socket-client.ts b/packages/cli/src/services/socket-client.ts index 4465da4f..fcd11339 100644 --- a/packages/cli/src/services/socket-client.ts +++ b/packages/cli/src/services/socket-client.ts @@ -3,27 +3,44 @@ import config from '../services/config' // @ts-ignore import { getProxyForUrl } from 'proxy-from-env' import { httpsOverHttp, httpsOverHttps } from 'tunnel' +import type { Logger } from './logger' const isHttps = (protocol: string) => protocol.startsWith('https') const wait = (ms: number) => new Promise((resolve) => setTimeout(resolve, ms)) -async function backOffConnect (url: string, options: mqtt.IClientOptions, retryCount = 0): +async function backOffConnect (logger: Logger, url: string, options: mqtt.IClientOptions, retryCount = 0): Promise { + const sublogger = logger.child({ + retryCount, + url, + }) + try { + sublogger.info('Connecting to MQTT broker') return mqtt.connectAsync(url, options, false) - } catch (error) { + } catch (err) { + sublogger.setBindings({ err }) + sublogger.warn('Failed to connect to MQTT broker') + if (retryCount > 3) { - throw error + sublogger.error('Giving up further connection attempts to MQTT broker') + throw err } + + const ms = 100 * retryCount + sublogger.setBindings({ wait: ms }) + sublogger.info('Scheduling a reconnection attempt to MQTT broker') retryCount += 1 - await wait(100 * retryCount) - return backOffConnect(url, options, retryCount) + await wait(ms) + + // Note: use original logger here since we'll be doing the same operation. + return backOffConnect(logger, url, options, retryCount) } } export class SocketClient { - static connect (): Promise { + static connect (logger: Logger): Promise { const url = config.getMqttUrl() const accountId = config.getAccountId() const apiKey = config.getApiKey() @@ -33,9 +50,18 @@ export class SocketClient { password: apiKey, } + const sublogger = logger.child({ + url, + username: accountId, + password: apiKey, + }) + // Replace wss with https so the get proxy url thing the env path const proxyUrlEnv = getProxyForUrl(url.replace('wss', 'https')) if (proxyUrlEnv) { + sublogger.setBindings({ proxy: proxyUrlEnv }) + sublogger.info('Must use proxy for MQTT broker connection') + const parsedProxyUrl = new URL(proxyUrlEnv) const isProxyHttps = isHttps(parsedProxyUrl.protocol) const proxy: any = { @@ -56,6 +82,6 @@ export class SocketClient { } } } - return backOffConnect(`${url}?authenticationScheme=userApiKey`, options, 0) + return backOffConnect(sublogger, `${url}?authenticationScheme=userApiKey`, options, 0) } } diff --git a/packages/cli/src/services/test-runner.ts b/packages/cli/src/services/test-runner.ts index cb132353..10f69b2e 100644 --- a/packages/cli/src/services/test-runner.ts +++ b/packages/cli/src/services/test-runner.ts @@ -4,6 +4,7 @@ import { GitInformation } from './util' import { Check } from '../constructs/check' import { RetryStrategy, Project } from '../constructs' import { pullSnapshots } from '../services/snapshot-service' +import { Logger } from './logger' import * as uuid from 'uuid' @@ -19,6 +20,7 @@ export default class TestRunner extends AbstractCheckRunner { testRetryStrategy: RetryStrategy | null constructor ( + logger: Logger, accountId: string, project: Project, checks: Check[], @@ -32,7 +34,7 @@ export default class TestRunner extends AbstractCheckRunner { baseDirectory: string, testRetryStrategy: RetryStrategy | null, ) { - super(accountId, timeout, verbose) + super(logger, accountId, timeout, verbose) this.project = project this.checkConstructs = checks this.location = location @@ -75,6 +77,16 @@ export default class TestRunner extends AbstractCheckRunner { repoInfo: this.repoInfo, environment: this.environment, shouldRecord: this.shouldRecord, + }, { + onUploadProgress: (event) => { + this.logger.trace({ + progress: { + sent: event.loaded, + total: event.total, + lengthComputable: event.lengthComputable, + }, + }, 'Test session payload upload progress') + }, }) const { testSessionId, sequenceIds } = data const checks = this.checkConstructs.map(check => ({ check, sequenceId: sequenceIds?.[check.logicalId] })) diff --git a/packages/cli/src/services/trigger-runner.ts b/packages/cli/src/services/trigger-runner.ts index 9d6beba6..e00f1667 100644 --- a/packages/cli/src/services/trigger-runner.ts +++ b/packages/cli/src/services/trigger-runner.ts @@ -2,6 +2,7 @@ import { RetryStrategy } from '../constructs' import { testSessions } from '../rest/api' import AbstractCheckRunner, { RunLocation, SequenceId } from './abstract-check-runner' import { GitInformation } from './util' +import type { Logger } from './logger' export class NoMatchingChecksError extends Error {} @@ -16,6 +17,7 @@ export default class TriggerRunner extends AbstractCheckRunner { testRetryStrategy: RetryStrategy | null constructor ( + logger: Logger, accountId: string, timeout: number, verbose: boolean, @@ -28,7 +30,7 @@ export default class TriggerRunner extends AbstractCheckRunner { testSessionName: string | undefined, testRetryStrategy: RetryStrategy | null, ) { - super(accountId, timeout, verbose) + super(logger, accountId, timeout, verbose) this.shouldRecord = shouldRecord this.location = location this.targetTags = targetTags