Merge pull request #35 from KnpLabs/change/set-higher-default-timeouts

Set higher default timeouts
KnpLabs · May 28, 2021 · b7ad91d · b7ad91d
2 parents 042b9a2 + 9e939aa
commit b7ad91d
Show file tree

Hide file tree

Showing 7 changed files with 57 additions and 42 deletions.
diff --git a/src/configuration.js b/src/configuration.js
@@ -77,8 +77,8 @@ const generate = () => ({
   queue: {
     redis_dsn: process.env.QUEUE_REDIS_DSN,
     job: {
-      stale_timeout: Number(process.env.QUEUE_JOB_STALE_TIMEOUT ?? 2000),
-      timeout: Number(process.env.QUEUE_JOB_TIMEOUT ?? 6000),
+      stale_timeout: Number(process.env.QUEUE_JOB_STALE_TIMEOUT ?? 10000),
+      timeout: Number(process.env.QUEUE_JOB_TIMEOUT ?? 30000),
     },
   },
   manager: {
@@ -91,7 +91,7 @@ const generate = () => ({
   worker: {
     enabled: 1 === Number(process.env.WORKER_ENABLED ?? 1),
     renderer: {
-      timeout: Number(process.env.WORKER_RENDERER_TIMEOUT ?? 5000),
+      timeout: Number(process.env.WORKER_RENDERER_TIMEOUT ?? 20000),
       authorized_request_domains: commaSeparatedStringToArray(
         process.env.WORKER_RENDERER_AUTHORIZED_REQUEST_DOMAINS ?? '*',
       ),

diff --git a/src/configuration.test.js b/src/configuration.test.js
@@ -29,14 +29,14 @@ describe('configuration :: createConfiguration', () => {
       queue: {
         redis_dsn: 'redis://redis:6379',
         job: {
-          stale_timeout: 2000,
-          timeout: 6000,
+          stale_timeout: 10000,
+          timeout: 30000,
         },
       },
       worker: {
         enabled: true,
         renderer: {
-          timeout: 5000,
+          timeout: 20000,
           authorized_request_domains: [
             '*',
           ],
@@ -67,14 +67,14 @@ describe('configuration :: createConfiguration', () => {
       queue: {
         redis_dsn: 'redis://redis:6379',
         job: {
-          stale_timeout: 2000,
-          timeout: 6000,
+          stale_timeout: 10000,
+          timeout: 30000,
         },
       },
       worker: {
         enabled: true,
         renderer: {
-          timeout: 5000,
+          timeout: 20000,
           authorized_request_domains: [
             '*',
           ],
@@ -105,14 +105,14 @@ describe('configuration :: createConfiguration', () => {
       queue: {
         redis_dsn: 'redis://redis:6379',
         job: {
-          stale_timeout: 2000,
-          timeout: 6000,
+          stale_timeout: 10000,
+          timeout: 30000,
         },
       },
       worker: {
         enabled: false,
         renderer: {
-          timeout: 5000,
+          timeout: 20000,
           authorized_request_domains: [
             '*',
           ],
@@ -128,13 +128,13 @@ describe('configuration :: createConfiguration', () => {
   it(`creates a configuration`, () => {
     process.env.LOG_LEVEL = 'ERROR'
     process.env.QUEUE_REDIS_DSN = 'redis://redis:6379'
-    process.env.QUEUE_JOB_STALE_TIMEOUT = 10000
-    process.env.QUEUE_JOB_TIMEOUT = 30000
+    process.env.QUEUE_JOB_STALE_TIMEOUT = 2000
+    process.env.QUEUE_JOB_TIMEOUT = 6000
     process.env.MANAGER_ENABLED = 1
     process.env.MANAGER_HTTP_SERVER_PORT = 8081
     process.env.MANAGER_HTTP_SERVER_HOST = '127.0.0.1'
     process.env.WORKER_ENABLED = 1
-    process.env.WORKER_RENDERER_TIMEOUT = 20000
+    process.env.WORKER_RENDERER_TIMEOUT = 5000
     process.env.WORKER_RENDERER_AUTHORIZED_REQUEST_DOMAINS = 'localhost, nginx'
     process.env.WORKER_RENDERER_AUTHORIZED_REQUEST_RESOURCES = 'document, script'
     process.env.WORKER_RENDERER_REDIRECTIONS = 'http://example.com|http://nginx'
@@ -153,14 +153,14 @@ describe('configuration :: createConfiguration', () => {
       queue: {
         redis_dsn: 'redis://redis:6379',
         job: {
-          stale_timeout: 10000,
-          timeout: 30000,
+          stale_timeout: 2000,
+          timeout: 6000,
         },
       },
       worker: {
         enabled: true,
         renderer: {
-          timeout: 20000,
+          timeout: 5000,
           authorized_request_domains: [
             'localhost',
             'nginx',

diff --git a/src/manager/http-server/index.js b/src/manager/http-server/index.js
@@ -8,6 +8,6 @@ export default (configuration, logger, queue, requestRegistry) => pipe(
   app => app.listen(
     configuration.manager.http_server.port,
     configuration.manager.http_server.host,
-    () => logger.info('Manager http server started.'),
+    () => logger.debug('Manager http server started.'),
   ),
 )(express())
diff --git a/src/manager/http-server/middlewares/render.js b/src/manager/http-server/middlewares/render.js
@@ -4,7 +4,7 @@ import { DEFAULT_JOB_OPTIONS } from '../../../queue'
 // default :: (Configuration, Logger, Queue, RequestRegistry) -> Express.app -> Express.app
 export default (configuration, logger, queue, requestRegistry) => app =>
   app.get('/render', (req, res, next) => call(pipe(
-    () => logger.info(`Render request for url "${req.query.url}" started.`),
+    () => logger.debug(`Render request for url "${req.query.url}" started.`),
     ifElse(
       () => compose(complement(isNil), path(['query', 'url']))(req),
       pipe(

diff --git a/src/manager/index.js b/src/manager/index.js
@@ -1,39 +1,56 @@
-import { T, always, call, cond, juxt, pipe, tap, when } from 'ramda'
-import TimeoutError from '../error/TimeoutError'
-import { TimeoutError as PuppeteerTimeoutError } from 'puppeteer-core'
+import { T, always, call, cond, juxt, pipe, tap, test, when } from 'ramda'
 import createRequestRegistry from './requestRegistry'
 import initHttpServer from './http-server'
 
+// resolveJobDuration :: Job -> Integer
+const resolveJobDuration = job => ((new Date()).getTime() - job.data.queuedAt) / 1000
+
+// resolveStatusCodeFromError :: String -> Integer
 const resolveStatusCodeFromError = cond([
-  [error => error instanceof TimeoutError, always(504)],
-  [error => error instanceof PuppeteerTimeoutError, always(504)],
+  [error => test(/timeout/i, error), always(504)],
+  [error => test(/timed out/i, error), always(504)],
   [T, always(500)],
 ])
 
-// onJobCompleted :: (Logger, RequestRegistry) -> Function
-const onJobCompleted = (logger, requestRegistry) => (jobId, result) => when(
+// onJobCompleted :: (Logger, Queue, RequestRegistry) -> Function
+const onJobCompleted = (logger, queue, requestRegistry) => (jobId, result) => when(
   jobId => requestRegistry.has(jobId),
   juxt([
     jobId => requestRegistry.complete(jobId, JSON.parse(result)),
-    jobId => logger.info(`Completed job "${jobId}"`),
+    async jobId => {
+      const job = await queue.getJob(jobId)
+
+      logger.info(`${jobId} ${job.data.url} 200 ${resolveJobDuration(job)}`)
+
+      job.remove()
+    },
   ]),
 )(jobId)
 
-// onJobFailed :: (Logger, RequestRegistry) -> Function
-const onJobFailed = (logger, requestRegistry) => (jobId, error) => when(
+// onJobFailed :: (Logger, Queue, RequestRegistry) -> Function
+const onJobFailed = (logger, queue, requestRegistry) => (jobId, error) => when(
   jobId => requestRegistry.has(jobId),
   juxt([
-    jobId => requestRegistry.fail(jobId, resolveStatusCodeFromError(error)),
-    jobId => logger.error(`Job "${jobId}" has failed. ${error}.`),
+    jobId => requestRegistry.fail(
+      jobId,
+      resolveStatusCodeFromError(error),
+    ),
+    async jobId => {
+      const job = await queue.getJob(jobId)
+
+      logger.error(`${jobId} ${job.data.url} ${resolveStatusCodeFromError(error)} ${resolveJobDuration(job)} ${error}`)
+
+      job.remove()
+    },
   ]),
 )(jobId)
 
 // initManager :: (Configuration, Logger, Queue) -> _
 export default (configuration, logger, queue) => call(pipe(
-  () => logger.info('Initializing manager.'),
+  () => logger.debug('Initializing manager.'),
   () => createRequestRegistry(),
-  tap(requestRegistry => queue.on('global:completed', onJobCompleted(logger, requestRegistry))),
-  tap(requestRegistry => queue.on('global:failed', onJobFailed(logger, requestRegistry))),
+  tap(requestRegistry => queue.on('global:completed', onJobCompleted(logger, queue, requestRegistry))),
+  tap(requestRegistry => queue.on('global:failed', onJobFailed(logger, queue, requestRegistry))),
   requestRegistry => initHttpServer(configuration, logger, queue, requestRegistry),
-  () => logger.info('Manager initialized.'),
+  () => logger.debug('Manager initialized.'),
 ))
diff --git a/src/queue.js b/src/queue.js
@@ -8,8 +8,6 @@ export const DEFAULT_QUEUE_OPTIONS = {}
 
 export const DEFAULT_JOB_OPTIONS = {
   attempts: 1,
-  removeOnComplete: true,
-  removeOnFail: true,
 }
 
 // createQueue :: (String, Object) -> Queue

diff --git a/src/worker/index.js b/src/worker/index.js
@@ -4,15 +4,15 @@ import render from './renderers/chrome'
 
 // initWorker :: (Configuration, Logger, Queue) -> _
 export default (configuration, logger, queue) => call(pipe(
-  () => logger.info('Initializing worker.'),
+  () => logger.debug('Initializing worker.'),
   () => queue.process(1, async job => {
-    if ((new Date()).getTime() - job.queuedAt > configuration.queue.job.stale_timeout) {
+    if ((new Date()).getTime() - job.data.queuedAt > configuration.queue.job.stale_timeout) {
       throw new TimeoutError(`Job "${job.id}" with url "${job.data.url}" timed out."`)
     }
 
-    logger.info(`Processing job "${job.id}" with url "${job.data.url}".`)
+    logger.debug(`Processing job "${job.id}" with url "${job.data.url}".`)
 
     return await render(configuration, logger)(job.data.url)
   }),
-  () => logger.info('Worker initialized.'),
+  () => logger.debug('Worker initialized.'),
 ))