diff --git a/.changeset/plenty-cobras-join.md b/.changeset/plenty-cobras-join.md new file mode 100644 index 000000000..f6ee1aaf3 --- /dev/null +++ b/.changeset/plenty-cobras-join.md @@ -0,0 +1,5 @@ +--- +'@openfn/ws-worker': patch +--- + +log duration of runs and server capacity diff --git a/packages/ws-worker/src/api/claim.ts b/packages/ws-worker/src/api/claim.ts index a6fb85c65..3881bf6c9 100644 --- a/packages/ws-worker/src/api/claim.ts +++ b/packages/ws-worker/src/api/claim.ts @@ -35,7 +35,9 @@ const claim = ( const activeWorkers = Object.keys(app.workflows).length; if (activeWorkers >= maxWorkers) { - logger.debug('skipping claim attempt: server at capacity'); + logger.debug( + `skipping claim attempt: server at capacity (${activeWorkers}/${maxWorkers})` + ); return reject(new Error('Server at capacity')); } @@ -43,8 +45,8 @@ const claim = ( logger.debug('skipping claim attempt: websocket unavailable'); return reject(new Error('No websocket available')); } + logger.debug(`requesting run (capacity ${activeWorkers}/${maxWorkers})`); - logger.debug('requesting run...'); app.queueChannel .push(CLAIM, { demand: 1 }) .receive('ok', ({ runs }: ClaimReply) => { diff --git a/packages/ws-worker/src/server.ts b/packages/ws-worker/src/server.ts index 5e15e69c3..cbc294ae7 100644 --- a/packages/ws-worker/src/server.ts +++ b/packages/ws-worker/src/server.ts @@ -181,6 +181,7 @@ function createServer(engine: RuntimeEngine, options: ServerOptions = {}) { app.execute = async ({ id, token }: ClaimRun) => { if (app.socket) { try { + const start = Date.now(); app.workflows[id] = true; const { @@ -197,7 +198,10 @@ function createServer(engine: RuntimeEngine, options: ServerOptions = {}) { // Callback to be triggered when the work is done (including errors) const onFinish = () => { - logger.debug(`workflow ${id} complete: releasing worker`); + const duration = (Date.now() - start) / 1000; + logger.debug( + `workflow ${id} complete in ${duration}s: releasing worker` + ); delete app.workflows[id]; runChannel.leave(); diff --git a/packages/ws-worker/src/start.ts b/packages/ws-worker/src/start.ts index c1c3f987b..56e22ad0a 100644 --- a/packages/ws-worker/src/start.ts +++ b/packages/ws-worker/src/start.ts @@ -9,6 +9,8 @@ const args = cli(process.argv); const logger = createLogger('SRV', { level: args.log }); +logger.info('Starting worker server...'); + if (args.lightning === 'mock') { args.lightning = 'ws://localhost:8888/worker'; if (!args.secret) { @@ -25,7 +27,7 @@ const [minBackoff, maxBackoff] = args.backoff .map((n: string) => parseInt(n, 10) * 1000); function engineReady(engine: any) { - logger.debug('Creating worker server...'); + logger.debug('Creating worker instance'); const workerOptions: ServerOptions = { port: args.port, @@ -61,6 +63,7 @@ function engineReady(engine: any) { logger.debug('Worker options:', humanOptions); createWorker(engine, workerOptions); + logger.success('Worker started OK'); } if (args.mock) {