From 713f5b2426f628b96e57f30f841fb59927f2de1a Mon Sep 17 00:00:00 2001 From: Ivan Date: Thu, 25 Mar 2021 18:09:45 +0800 Subject: [PATCH] feat(pipeline-tasks): debug log. --- package-lock.json | 169 +++++++++++++++++-- package.json | 4 +- src/app.module.ts | 2 +- src/pipeline-tasks/pipeline-task.consumer.ts | 15 +- src/pipeline-tasks/pipeline-tasks.service.ts | 41 +++-- 5 files changed, 203 insertions(+), 28 deletions(-) diff --git a/package-lock.json b/package-lock.json index 2c62e64..6e7f0d7 100644 --- a/package-lock.json +++ b/package-lock.json @@ -23,6 +23,7 @@ "bull": "^3.20.1", "class-transformer": "^0.3.2", "class-validator": "^0.13.1", + "debug": "^4.3.1", "graphql": "^15.5.0", "graphql-tools": "^7.0.2", "js-yaml": "^4.0.0", @@ -40,6 +41,7 @@ "@nestjs/cli": "^7.5.1", "@nestjs/schematics": "^7.1.3", "@nestjs/testing": "^7.5.1", + "@types/debug": "^4.1.5", "@types/express": "^4.17.8", "@types/jest": "^26.0.15", "@types/js-yaml": "^4.0.0", @@ -2827,6 +2829,12 @@ "@types/express": "*" } }, + "node_modules/@types/debug": { + "version": "4.1.5", + "resolved": "https://registry.npmjs.org/@types/debug/-/debug-4.1.5.tgz", + "integrity": "sha512-Q1y515GcOdTHgagaVFhHnIFQ38ygs/kmxdNpvpou+raI9UO3YZcHDngBSYKQklcKlvA7iuQlmIKbzvmxcOE9CQ==", + "dev": true + }, "node_modules/@types/eslint": { "version": "7.2.6", "resolved": "https://registry.npmjs.org/@types/eslint/-/eslint-7.2.6.tgz", @@ -5174,6 +5182,14 @@ "node": ">= 0.8" } }, + "node_modules/body-parser/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dependencies": { + "ms": "2.0.0" + } + }, "node_modules/brace-expansion": { "version": "1.1.11", "resolved": "https://registry.npmjs.org/brace-expansion/-/brace-expansion-1.1.11.tgz", @@ -6163,13 +6179,21 @@ "integrity": "sha512-YzhyDAwA4TaQIhM5go+vCLmU0UikghC/t9DTQYZR2M/UvZ1MdOhPezSDZcjj9uqQJOMqjLcpWtyW2iNINdlatQ==" }, "node_modules/debug": { - "version": "2.6.9", - "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", - "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "version": "4.3.1", + "resolved": "https://registry.npmjs.org/debug/-/debug-4.3.1.tgz", + "integrity": "sha512-doEwdvm4PCeK4K3RQN2ZC2BYUBaxwLARCqZmMjtF8a51J2Rb0xpVloFRnCODwqjpwnAoao4pelN8l3RJdv3gRQ==", "dependencies": { - "ms": "2.0.0" + "ms": "2.1.2" + }, + "engines": { + "node": ">=6.0" } }, + "node_modules/debug/node_modules/ms": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.2.tgz", + "integrity": "sha512-sGkPx+VjMtmA6MX27oA4FBFELFCZZ4S4XqeGOXCv68tT+jb3vk/RyaKWP0PTKyWtmLSM0b+adUTEvbs1PEaH2w==" + }, "node_modules/debuglog": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/debuglog/-/debuglog-1.0.1.tgz", @@ -7129,6 +7153,15 @@ "node": ">=0.10.0" } }, + "node_modules/expand-brackets/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dev": true, + "dependencies": { + "ms": "2.0.0" + } + }, "node_modules/expand-brackets/node_modules/define-property": { "version": "0.2.5", "resolved": "https://registry.npmjs.org/define-property/-/define-property-0.2.5.tgz", @@ -7210,6 +7243,14 @@ "node": ">= 0.10.0" } }, + "node_modules/express/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dependencies": { + "ms": "2.0.0" + } + }, "node_modules/express/node_modules/path-to-regexp": { "version": "0.1.7", "resolved": "https://registry.npmjs.org/path-to-regexp/-/path-to-regexp-0.1.7.tgz", @@ -7510,6 +7551,14 @@ "node": ">= 0.8" } }, + "node_modules/finalhandler/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dependencies": { + "ms": "2.0.0" + } + }, "node_modules/find-up": { "version": "4.1.0", "resolved": "https://registry.npmjs.org/find-up/-/find-up-4.1.0.tgz", @@ -11310,10 +11359,7 @@ "node_modules/observable-to-async-generator": { "version": "1.0.1-rc", "resolved": "https://registry.npmjs.org/observable-to-async-generator/-/observable-to-async-generator-1.0.1-rc.tgz", - "integrity": "sha512-fSV1h5D6fv1X3vfeOQF6u7Mq5VUrM1K5AxfgAIjVqLBhDHQFg/Jp9J3fOc2CR6EDr/JFjs7IxbRlvDigVh7Wgg==", - "peerDependencies": { - "rxjs": "6.x.x" - } + "integrity": "sha512-fSV1h5D6fv1X3vfeOQF6u7Mq5VUrM1K5AxfgAIjVqLBhDHQFg/Jp9J3fOc2CR6EDr/JFjs7IxbRlvDigVh7Wgg==" }, "node_modules/on-finished": { "version": "2.3.0", @@ -13094,6 +13140,19 @@ "node": ">= 0.8.0" } }, + "node_modules/send/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dependencies": { + "ms": "2.0.0" + } + }, + "node_modules/send/node_modules/debug/node_modules/ms": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.0.0.tgz", + "integrity": "sha1-VgiurfwAvmwpAd9fmGF4jeDVl8g=" + }, "node_modules/send/node_modules/ms": { "version": "2.1.1", "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.1.tgz", @@ -13402,6 +13461,15 @@ "node": ">=0.10.0" } }, + "node_modules/snapdragon/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dev": true, + "dependencies": { + "ms": "2.0.0" + } + }, "node_modules/snapdragon/node_modules/define-property": { "version": "0.2.5", "resolved": "https://registry.npmjs.org/define-property/-/define-property-0.2.5.tgz", @@ -18247,6 +18315,12 @@ "@types/express": "*" } }, + "@types/debug": { + "version": "4.1.5", + "resolved": "https://registry.npmjs.org/@types/debug/-/debug-4.1.5.tgz", + "integrity": "sha512-Q1y515GcOdTHgagaVFhHnIFQ38ygs/kmxdNpvpou+raI9UO3YZcHDngBSYKQklcKlvA7iuQlmIKbzvmxcOE9CQ==", + "dev": true + }, "@types/eslint": { "version": "7.2.6", "resolved": "https://registry.npmjs.org/@types/eslint/-/eslint-7.2.6.tgz", @@ -20356,6 +20430,16 @@ "qs": "6.7.0", "raw-body": "2.4.0", "type-is": "~1.6.17" + }, + "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "requires": { + "ms": "2.0.0" + } + } } }, "brace-expansion": { @@ -21170,11 +21254,18 @@ "integrity": "sha512-YzhyDAwA4TaQIhM5go+vCLmU0UikghC/t9DTQYZR2M/UvZ1MdOhPezSDZcjj9uqQJOMqjLcpWtyW2iNINdlatQ==" }, "debug": { - "version": "2.6.9", - "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", - "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "version": "4.3.1", + "resolved": "https://registry.npmjs.org/debug/-/debug-4.3.1.tgz", + "integrity": "sha512-doEwdvm4PCeK4K3RQN2ZC2BYUBaxwLARCqZmMjtF8a51J2Rb0xpVloFRnCODwqjpwnAoao4pelN8l3RJdv3gRQ==", "requires": { - "ms": "2.0.0" + "ms": "2.1.2" + }, + "dependencies": { + "ms": { + "version": "2.1.2", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.2.tgz", + "integrity": "sha512-sGkPx+VjMtmA6MX27oA4FBFELFCZZ4S4XqeGOXCv68tT+jb3vk/RyaKWP0PTKyWtmLSM0b+adUTEvbs1PEaH2w==" + } } }, "debuglog": { @@ -21937,6 +22028,15 @@ "to-regex": "^3.0.1" }, "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dev": true, + "requires": { + "ms": "2.0.0" + } + }, "define-property": { "version": "0.2.5", "resolved": "https://registry.npmjs.org/define-property/-/define-property-0.2.5.tgz", @@ -22008,6 +22108,14 @@ "vary": "~1.1.2" }, "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "requires": { + "ms": "2.0.0" + } + }, "path-to-regexp": { "version": "0.1.7", "resolved": "https://registry.npmjs.org/path-to-regexp/-/path-to-regexp-0.1.7.tgz", @@ -22263,6 +22371,16 @@ "parseurl": "~1.3.3", "statuses": "~1.5.0", "unpipe": "~1.0.0" + }, + "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "requires": { + "ms": "2.0.0" + } + } } }, "find-up": { @@ -25392,8 +25510,7 @@ "observable-to-async-generator": { "version": "1.0.1-rc", "resolved": "https://registry.npmjs.org/observable-to-async-generator/-/observable-to-async-generator-1.0.1-rc.tgz", - "integrity": "sha512-fSV1h5D6fv1X3vfeOQF6u7Mq5VUrM1K5AxfgAIjVqLBhDHQFg/Jp9J3fOc2CR6EDr/JFjs7IxbRlvDigVh7Wgg==", - "requires": {} + "integrity": "sha512-fSV1h5D6fv1X3vfeOQF6u7Mq5VUrM1K5AxfgAIjVqLBhDHQFg/Jp9J3fOc2CR6EDr/JFjs7IxbRlvDigVh7Wgg==" }, "on-finished": { "version": "2.3.0", @@ -26838,6 +26955,21 @@ "statuses": "~1.5.0" }, "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "requires": { + "ms": "2.0.0" + }, + "dependencies": { + "ms": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.0.0.tgz", + "integrity": "sha1-VgiurfwAvmwpAd9fmGF4jeDVl8g=" + } + } + }, "ms": { "version": "2.1.1", "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.1.tgz", @@ -27024,6 +27156,15 @@ "use": "^3.1.0" }, "dependencies": { + "debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "dev": true, + "requires": { + "ms": "2.0.0" + } + }, "define-property": { "version": "0.2.5", "resolved": "https://registry.npmjs.org/define-property/-/define-property-0.2.5.tgz", diff --git a/package.json b/package.json index af0ec83..795d78d 100644 --- a/package.json +++ b/package.json @@ -10,7 +10,7 @@ "build": "nest build", "format": "prettier --write \"src/**/*.ts\" \"test/**/*.ts\"", "start": "nest start", - "start:dev": "nest start --watch", + "start:dev": "DEBUG=fennec:*,simple-git:* nest start --watch", "start:debug": "DEBUG=simple-git,simple-git:* nest start --debug --watch", "start:prod": "node dist/main", "lint": "eslint \"{src,apps,libs,test}/**/*.ts\" --fix", @@ -36,6 +36,7 @@ "bull": "^3.20.1", "class-transformer": "^0.3.2", "class-validator": "^0.13.1", + "debug": "^4.3.1", "graphql": "^15.5.0", "graphql-tools": "^7.0.2", "js-yaml": "^4.0.0", @@ -53,6 +54,7 @@ "@nestjs/cli": "^7.5.1", "@nestjs/schematics": "^7.1.3", "@nestjs/testing": "^7.5.1", + "@types/debug": "^4.1.5", "@types/express": "^4.17.8", "@types/jest": "^26.0.15", "@types/js-yaml": "^4.0.0", diff --git a/src/app.module.ts b/src/app.module.ts index dac1ebc..377cf78 100644 --- a/src/app.module.ts +++ b/src/app.module.ts @@ -51,7 +51,7 @@ import { RedisModule } from 'nestjs-redis'; host: configService.get('db.redis.host', 'localhost'), port: configService.get('db.redis.port', 6379), password: configService.get('db.redis.password', ''), - keyPrefix: configService.get('db.redis.prefix', 'fennec'), + keyPrefix: configService.get('db.redis.prefix', 'fennec') + ':', }), inject: [ConfigService], }), diff --git a/src/pipeline-tasks/pipeline-task.consumer.ts b/src/pipeline-tasks/pipeline-task.consumer.ts index bfa76f1..27b6e60 100644 --- a/src/pipeline-tasks/pipeline-task.consumer.ts +++ b/src/pipeline-tasks/pipeline-task.consumer.ts @@ -16,6 +16,10 @@ import { PipelineUnits } from './enums/pipeline-units.enum'; import { PipelineTaskLogMessage } from './models/pipeline-task-log-message.module'; import { TaskStatuses } from './enums/task-statuses.enum'; import { PipelineTaskLogsService } from './pipeline-task-logs.service'; +import debug from 'debug'; + +const log = debug('fennec:pipeline-tasks:consumer'); + @Processor(PIPELINE_TASK_QUEUE) export class PipelineTaskConsumer { constructor( @@ -35,6 +39,7 @@ export class PipelineTaskConsumer { task.startedAt = new Date(); task.status = TaskStatuses.working; task = await this.service.updateTask(task); + log('start job'); await job.update(task); const workspaceRoot = this.reposService.getWorkspaceRootByTask(task); @@ -46,20 +51,26 @@ export class PipelineTaskConsumer { ) ?? { type: type, scripts: [] }, ); + log('task have [%o] units', units); try { for (const unit of units) { const unitLog = new PipelineTaskLogs(); unitLog.unit = unit.type; unitLog.startedAt = new Date(); + log('curr unit is %s', unit.type); try { // 检出代码前执行 git checkout if (unit.type === PipelineUnits.checkout) { + log('begin checkout'); await this.reposService.checkout(task, workspaceRoot); unitLog.status = TaskStatuses.success; + log('end checkout'); } for (const script of unit.scripts) { unitLog.logs += `[RUN SCRIPT] ${script}`; + log('begin runScript %s', script); await this.runScript(script, workspaceRoot, task, unit.type); + log('end runScript %s', script); } unitLog.status = TaskStatuses.success; } catch (err) { @@ -82,7 +93,7 @@ export class PipelineTaskConsumer { task.status = TaskStatuses.success; } catch (err) { task.status = TaskStatuses.failed; - console.log(err); + log('task is failed', err); } finally { task.endedAt = new Date(); task = await this.service.updateTask(task); @@ -124,11 +135,13 @@ export class PipelineTaskConsumer { @OnQueueCompleted() onCompleted(job: Job) { + log('queue onCompleted'); this.service.doNextTask(job.data.pipeline); } @OnQueueFailed() onFailed(job: Job) { + log('queue onFailed'); this.service.doNextTask(job.data.pipeline); } } diff --git a/src/pipeline-tasks/pipeline-tasks.service.ts b/src/pipeline-tasks/pipeline-tasks.service.ts index ea36f2b..2292d3b 100644 --- a/src/pipeline-tasks/pipeline-tasks.service.ts +++ b/src/pipeline-tasks/pipeline-tasks.service.ts @@ -12,6 +12,9 @@ import { LockFailedException } from '../commons/exceptions/lock-failed.exception import { PubSub } from 'apollo-server-express'; import { TaskStatuses } from './enums/task-statuses.enum'; import { isNil } from 'ramda'; +import debug from 'debug'; + +const log = debug('fennec:pipeline-tasks:service'); @Injectable() export class PipelineTasksService { @@ -30,23 +33,30 @@ export class PipelineTasksService { where: { id: dto.pipelineId }, relations: ['project'], }); - // const hasUnfinishedTask = await this.repository - // .findOne({ - // pipelineId: pipeline.id, - // status: In([TaskStatuses.pending, TaskStatuses.working]), - // }) - // .then((val) => !isNil(val)); - // if (hasUnfinishedTask) { - // throw new ConflictException( - // 'there are still unfinished task in the current pipeline.', - // ); - // } + const hasUnfinishedTask = await this.repository + .findOne({ + pipelineId: dto.pipelineId, + commit: dto.commit, + status: In([TaskStatuses.pending, TaskStatuses.working]), + }) + .then((val) => !isNil(val)); + if (hasUnfinishedTask) { + throw new ConflictException( + 'There are the same tasks among the unfinished tasks!', + ); + } const task = await this.repository.save(this.repository.create(dto)); task.pipeline = pipeline; const tasksKey = this.getRedisTokens(pipeline)[1]; const redis = this.redis.getClient(); await redis.lpush(tasksKey, JSON.stringify(task)); + log( + 'add task %s:%s-%s', + task.id, + task.pipeline.branch, + task.commit.slice(0, 6), + ); await this.doNextTask(pipeline); return task; } @@ -63,6 +73,7 @@ export class PipelineTasksService { const [lckKey, tasksKey] = this.getRedisTokens(pipeline); const redis = this.redis.getClient(); + log('doNextTask()'); const unLck = await new Promise<() => Promise>( async (resolve, reject) => { const lckValue = Date.now().toString(); @@ -90,7 +101,15 @@ export class PipelineTasksService { (await redis.rpop(tasksKey).finally(() => unLck())) ?? 'null', ); if (task) { + log( + 'add task (%s:%s-%s) to queue', + task.id, + task.pipeline.branch, + task.commit.slice(0, 6), + ); await this.queue.add(task); + } else { + log('task is empty'); } }