From 141c91e0b4dc7c9347108c0235b626f837447195 Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 12:17:42 +0100 Subject: [PATCH 1/8] configure kinesis agent to pick up log file pattern --- dotcom-rendering/cdk/lib/userData.ts | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/dotcom-rendering/cdk/lib/userData.ts b/dotcom-rendering/cdk/lib/userData.ts index ed0d5c5a27c..e6d320700d7 100644 --- a/dotcom-rendering/cdk/lib/userData.ts +++ b/dotcom-rendering/cdk/lib/userData.ts @@ -34,7 +34,7 @@ export const getUserData = ({ `sudo NODE_ENV=$NODE_ENV GU_STAGE=$GU_STAGE -u dotcom-rendering -g frontend make start-prod`, - `/opt/aws-kinesis-agent/configure-aws-kinesis-agent ${region} ${elkStreamId} /var/log/dotcom-rendering/dotcom-rendering.log`, + `/opt/aws-kinesis-agent/configure-aws-kinesis-agent ${region} ${elkStreamId} /var/log/dotcom-rendering/dotcom-rendering*.log`, ].join('\n'); return userData; From dff6bdfc93a32d9ce7c7e0361caf8004bd7c72ce Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 12:43:56 +0100 Subject: [PATCH 2/8] Logger writes to separate files for each app instance --- dotcom-rendering/src/server/lib/logging.ts | 23 +++++++++++++++------- 1 file changed, 16 insertions(+), 7 deletions(-) diff --git a/dotcom-rendering/src/server/lib/logging.ts b/dotcom-rendering/src/server/lib/logging.ts index 2e316dd6e1d..aaf331ee545 100644 --- a/dotcom-rendering/src/server/lib/logging.ts +++ b/dotcom-rendering/src/server/lib/logging.ts @@ -3,16 +3,22 @@ import type { LoggingEvent } from 'log4js'; import { addLayout, configure, getLogger, shutdown } from 'log4js'; import { loggingStore } from './logging-store'; +// write separate log files for each app instance +// required when running multiple processes +// aws-kinesis-agent is configured to look for a file pattern to pick all log files up +const logNamePostfix = process.env.NODE_APP_INSTANCE + ? `-${process.env.NODE_APP_INSTANCE}` + : ''; + +const logName = `dotcom-rendering${logNamePostfix}.log`; + const logLocation = process.env.NODE_ENV === 'production' && !process.env.DISABLE_LOGGING_AND_METRICS - ? '/var/log/dotcom-rendering/dotcom-rendering.log' - : `${path.resolve('logs')}/dotcom-rendering.log`; + ? `/var/log/dotcom-rendering/${logName}` + : `${path.resolve('logs')}/${logName}`; -const stage = - typeof process.env.GU_STAGE === 'string' - ? process.env.GU_STAGE.toUpperCase() - : 'DEV'; +console.log(`!!! ${logLocation}`); const logFields = (logEvent: LoggingEvent): unknown => { const { request } = loggingStore.getStore() ?? { @@ -22,7 +28,10 @@ const logFields = (logEvent: LoggingEvent): unknown => { const coreFields = { stack: 'frontend', app: 'dotcom-rendering', - stage, + stage: + typeof process.env.GU_STAGE === 'string' + ? process.env.GU_STAGE.toUpperCase() + : 'DEV', '@timestamp': logEvent.startTime, '@version': 1, level: logEvent.level.levelStr, From 1e72d5a814dad53ecb7a00bd189219c8dabf7b7c Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 13:02:12 +0100 Subject: [PATCH 3/8] update cdk snapshot --- .../cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap b/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap index 70e275fdda2..b3ec5c1bc70 100644 --- a/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap +++ b/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap @@ -1035,7 +1035,7 @@ sudo NODE_ENV=$NODE_ENV GU_STAGE=$GU_STAGE -u dotcom-rendering -g frontend make { "Ref": "ELKStreamId", }, - " /var/log/dotcom-rendering/dotcom-rendering.log", + " /var/log/dotcom-rendering/dotcom-rendering*.log", ], ], }, From 48e275b0ad0e9581424d5af750ced2571a4eb80f Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 15:14:14 +0100 Subject: [PATCH 4/8] disable log4js clustering --- dotcom-rendering/src/server/lib/logging.ts | 2 ++ 1 file changed, 2 insertions(+) diff --git a/dotcom-rendering/src/server/lib/logging.ts b/dotcom-rendering/src/server/lib/logging.ts index aaf331ee545..a4c9c0deca4 100644 --- a/dotcom-rendering/src/server/lib/logging.ts +++ b/dotcom-rendering/src/server/lib/logging.ts @@ -88,6 +88,8 @@ const enableLog4j = { development: { appenders: ['console'], level: 'info' }, }, pm2: true, + // tell log4js not to cluster logs and write to seperate files + disableClustering: true, }; if (process.env.DISABLE_LOGGING_AND_METRICS === 'true') { From bfaf1cfd01d50d7fdeb505b8b49bb2509a143071 Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 16:31:56 +0100 Subject: [PATCH 5/8] add thread_name to logs to denote app instance number --- dotcom-rendering/src/server/lib/logging.ts | 8 +++----- 1 file changed, 3 insertions(+), 5 deletions(-) diff --git a/dotcom-rendering/src/server/lib/logging.ts b/dotcom-rendering/src/server/lib/logging.ts index a4c9c0deca4..2df5d70dcb8 100644 --- a/dotcom-rendering/src/server/lib/logging.ts +++ b/dotcom-rendering/src/server/lib/logging.ts @@ -6,11 +6,8 @@ import { loggingStore } from './logging-store'; // write separate log files for each app instance // required when running multiple processes // aws-kinesis-agent is configured to look for a file pattern to pick all log files up -const logNamePostfix = process.env.NODE_APP_INSTANCE - ? `-${process.env.NODE_APP_INSTANCE}` - : ''; - -const logName = `dotcom-rendering${logNamePostfix}.log`; +const appInstance = process.env.NODE_APP_INSTANCE ?? '0'; +const logName = `dotcom-rendering-${appInstance}.log`; const logLocation = process.env.NODE_ENV === 'production' && @@ -37,6 +34,7 @@ const logFields = (logEvent: LoggingEvent): unknown => { level: logEvent.level.levelStr, level_value: logEvent.level.level, request, + thread_name: appInstance, }; // log4js uses any[] to type data but we want to coerce it here // because we now depend on the type to log the result properly From 9d8109818bd2e57ec2a22bcfdd15e3122470d556 Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Mon, 2 Oct 2023 17:06:33 +0100 Subject: [PATCH 6/8] tidy up comments --- dotcom-rendering/src/server/lib/logging.ts | 5 ++--- 1 file changed, 2 insertions(+), 3 deletions(-) diff --git a/dotcom-rendering/src/server/lib/logging.ts b/dotcom-rendering/src/server/lib/logging.ts index 2df5d70dcb8..84be53a5a6e 100644 --- a/dotcom-rendering/src/server/lib/logging.ts +++ b/dotcom-rendering/src/server/lib/logging.ts @@ -5,7 +5,8 @@ import { loggingStore } from './logging-store'; // write separate log files for each app instance // required when running multiple processes -// aws-kinesis-agent is configured to look for a file pattern to pick all log files up +// NODE_APP_INSTANCE is set by pm2 +// aws-kinesis-agent is configured to look for a file pattern const appInstance = process.env.NODE_APP_INSTANCE ?? '0'; const logName = `dotcom-rendering-${appInstance}.log`; @@ -15,8 +16,6 @@ const logLocation = ? `/var/log/dotcom-rendering/${logName}` : `${path.resolve('logs')}/${logName}`; -console.log(`!!! ${logLocation}`); - const logFields = (logEvent: LoggingEvent): unknown => { const { request } = loggingStore.getStore() ?? { request: { pageId: 'outside-request-context' }, From c33215fd44044e59fd336d28db09eff3a44a59c1 Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Wed, 4 Oct 2023 14:03:33 +0100 Subject: [PATCH 7/8] Consolidate all process logs --- dotcom-rendering/src/server/lib/logging.ts | 14 ++++++-------- 1 file changed, 6 insertions(+), 8 deletions(-) diff --git a/dotcom-rendering/src/server/lib/logging.ts b/dotcom-rendering/src/server/lib/logging.ts index 84be53a5a6e..4f87080a203 100644 --- a/dotcom-rendering/src/server/lib/logging.ts +++ b/dotcom-rendering/src/server/lib/logging.ts @@ -3,12 +3,7 @@ import type { LoggingEvent } from 'log4js'; import { addLayout, configure, getLogger, shutdown } from 'log4js'; import { loggingStore } from './logging-store'; -// write separate log files for each app instance -// required when running multiple processes -// NODE_APP_INSTANCE is set by pm2 -// aws-kinesis-agent is configured to look for a file pattern -const appInstance = process.env.NODE_APP_INSTANCE ?? '0'; -const logName = `dotcom-rendering-${appInstance}.log`; +const logName = `dotcom-rendering.log`; const logLocation = process.env.NODE_ENV === 'production' && @@ -33,7 +28,8 @@ const logFields = (logEvent: LoggingEvent): unknown => { level: logEvent.level.levelStr, level_value: logEvent.level.level, request, - thread_name: appInstance, + // NODE_APP_INSTANCE is set by pm2 + thread_name: process.env.NODE_APP_INSTANCE ?? '0', }; // log4js uses any[] to type data but we want to coerce it here // because we now depend on the type to log the result properly @@ -85,7 +81,9 @@ const enableLog4j = { development: { appenders: ['console'], level: 'info' }, }, pm2: true, - // tell log4js not to cluster logs and write to seperate files + // log4js cluster mode handling does not work as it prevents + // logs from processes other than the main process from + // writing to the log. disableClustering: true, }; From 297ff365a04ec4cee3da30f345edad605e63a946 Mon Sep 17 00:00:00 2001 From: Ravi <7014230+arelra@users.noreply.github.com> Date: Wed, 4 Oct 2023 14:14:57 +0100 Subject: [PATCH 8/8] remove file pattern from kinesis-agent --- .../cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap | 2 +- dotcom-rendering/cdk/lib/userData.ts | 2 +- 2 files changed, 2 insertions(+), 2 deletions(-) diff --git a/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap b/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap index b3ec5c1bc70..70e275fdda2 100644 --- a/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap +++ b/dotcom-rendering/cdk/lib/__snapshots__/dotcom-rendering.test.ts.snap @@ -1035,7 +1035,7 @@ sudo NODE_ENV=$NODE_ENV GU_STAGE=$GU_STAGE -u dotcom-rendering -g frontend make { "Ref": "ELKStreamId", }, - " /var/log/dotcom-rendering/dotcom-rendering*.log", + " /var/log/dotcom-rendering/dotcom-rendering.log", ], ], }, diff --git a/dotcom-rendering/cdk/lib/userData.ts b/dotcom-rendering/cdk/lib/userData.ts index e6d320700d7..ed0d5c5a27c 100644 --- a/dotcom-rendering/cdk/lib/userData.ts +++ b/dotcom-rendering/cdk/lib/userData.ts @@ -34,7 +34,7 @@ export const getUserData = ({ `sudo NODE_ENV=$NODE_ENV GU_STAGE=$GU_STAGE -u dotcom-rendering -g frontend make start-prod`, - `/opt/aws-kinesis-agent/configure-aws-kinesis-agent ${region} ${elkStreamId} /var/log/dotcom-rendering/dotcom-rendering*.log`, + `/opt/aws-kinesis-agent/configure-aws-kinesis-agent ${region} ${elkStreamId} /var/log/dotcom-rendering/dotcom-rendering.log`, ].join('\n'); return userData;