Take heapdump and coredumps on low memory (#2430)

* NONE: admin endpoint

* NONE: debug

* NONE: add gdb, fix build

* NONE: fix Dockerfile

* NONE: fix build

* NONE: fix build

* some fixes

* NONE: couple of fixes

* NONE: add uploading to s3

* NONE: fix s3 uploading

* NONE: better logging

* NONE: tests

* NONE: add heapdump generator, too

* NONE: self-review

* NONE: fix tests

* NONE: missing labels

* NONE: comment

* NONE: fix tests

Author: bgvozdev

.env.test

@@ -62,3 +62,7 @@ MICROS_PLATFORM_STATSD_HOST=localhost
 MICROS_PLATFORM_STATSD_PORT=8125
 
 JIRA_TEST_SITES=https://site-1.some-test.atlassian.net,https://site-2.some-test.atlassian.net,https://site-3.some-test.atlassian.net
+
+S3_DUMPS_BUCKET_NAME=my-bucket
+S3_DUMPS_BUCKET_PATH=my/path
+S3_DUMPS_BUCKET_REGION=my-region

Dockerfile

@@ -3,6 +3,10 @@ FROM node:14.21-alpine3.16 as build
 # adding python for node-gyp
 RUN apk add g++ make python3
 
+# For coredumps
+RUN apk add gdb
+RUN apk add bash
+
 # adding to solve vuln
 RUN apk add --update --upgrade busybox libretls openssl zlib curl
 

Dockerfile.prod

@@ -3,6 +3,10 @@ FROM node:14.21-alpine3.16 as build
 # adding python for node-gyp
 RUN apk add g++ make python3
 
+# For coredumps
+RUN apk add gdb
+RUN apk add bash
+
 # adding to solve vuln
 RUN apk add --update --upgrade busybox
 RUN apk add --update --upgrade libretls
@@ -31,6 +35,10 @@ RUN apk add --update --upgrade zlib
 # For debugging curl command
 RUN apk add curl
 
+# For coredumps
+RUN apk add gdb
+RUN apk add bash
+
 USER node
 COPY --chown=node:node --from=build /app /app
 # Add this the service Dockerfile, at the final stage if multi-stage

bin/start-server-micros.sh

@@ -15,6 +15,13 @@ case "$MICROS_GROUP" in
   ;;
 esac
 
-export DATABASE_URL=postgres://$PG_DATABASE_ROLE:$PG_DATABASE_PASSWORD@$PG_DATABASE_BOUNCER:$PG_DATABASE_PORT/$PG_DATABASE_SCHEMA
+case "$MICROS_ENVTYPE" in
+  "dev")
+    export NODE_OPTIONS="--max-old-space-size=250" # since ddev nodes have smaller memory available in general
+  ;;
+esac
 
+export DATABASE_URL=postgres://$PG_DATABASE_ROLE:$PG_DATABASE_PASSWORD@$PG_DATABASE_BOUNCER:$PG_DATABASE_PORT/$PG_DATABASE_SCHEMA
+echo "We are at:"
+pwd
 npm run "${COMMAND}"

docker-compose.yml

@@ -89,3 +89,4 @@ services:
       dockerfile: etc/app-install/Dockerfile
     env_file:
       - .env
+

github-for-jira.sd.yml

@@ -158,6 +158,17 @@ resources:
         # Name of the RDS resource from above
         resource: rds
 
+  - type: s3
+    name: "dumps" # for heapdumps, temp resource, will be deleted after the investigation is over
+    attributes:
+      dataType:
+        - UGC/Label                # name of GitHub org / Jira site
+        - PII/IndirectConfidential # name of GitHub org
+        - UGC/Configuration        # data about the installation of the GitHub app into Jira sites
+        - Security/Secret          # shared Connect secret
+        - UGC/PrimaryIdentifier    # references to GitHub entities (commits, pull requests, etc.) and Jira issues
+        - UGC/Primary              # GitHub entities (non-persistent) like commits, pull requests, etc.
+
   - name: deployment-history-cache
     type: dynamo-db
     attributes: &table-attributes

package.json

@@ -18,8 +18,8 @@
 		"start:main": "tsnd -r tsconfig-paths/register --watch=.env*,db/config.json --inspect=0.0.0.0:9229 --respawn --transpile-only -- src/main.ts",
 		"start:worker": "tsnd -r tsconfig-paths/register --watch=.env*,db/config.json --inspect=0.0.0.0:9230 --respawn --transpile-only -- src/worker.ts",
 		"start:production": "run-p start:main:production start:worker:production",
-		"start:main:production": "node -r tsconfig-paths/register src/main",
-		"start:worker:production": "node -r tsconfig-paths/register src/worker",
+		"start:main:production": "TS_NODE_BASEURL=\"build\" node --expose-gc -r tsconfig-paths/register build/src/main",
+		"start:worker:production": "TS_NODE_BASEURL=\"build\" node --expose-gc -r tsconfig-paths/register build/src/worker",
 		"setup": "dotenv -- ts-node -r tsconfig-paths/register prestart.ts",
 		"build": "tsc -p ./tsconfig.json && yarn spa:build",
 		"build:release": "tsc -p ./tsconfig.release.json && yarn spa:build",
@@ -77,6 +77,7 @@
 		"date-fns": "^1.29.0",
 		"dotenv": "^16.0.1",
 		"dotenv-expand": "^8.0.3",
+		"dumpme": "^1.0.3",
 		"event-loop-lag": "^1.4.0",
 		"express": "^4.17.3",
 		"express-async-handler": "^1.2.0",

src/config/env.ts

@@ -15,7 +15,7 @@ const nodeEnv: EnvironmentEnum = EnvironmentEnum[getNodeEnv()];
 	`.env.${nodeEnv}`,
 	".env"
 ].map((env) => expand(config({
-	path: path.resolve(__dirname, "../..", env)
+	path: path.resolve(process.cwd(), env)
 })));
 
 type Transforms<T, K extends keyof T = keyof T> = {
@@ -26,6 +26,9 @@ const transforms: Transforms<EnvVars> = {
 	MICROS_ENV: (value?: string) => EnvironmentEnum[value || EnvironmentEnum.development],
 	MICROS_GROUP: (value?: string) => value || "",
 	NODE_ENV: () => nodeEnv,
+	S3_DUMPS_BUCKET_NAME: (value?: string) => value ?? "",
+	S3_DUMPS_BUCKET_PATH: (value?: string) => value ?? "",
+	S3_DUMPS_BUCKET_REGION: (value?: string) => value ?? "",
 	PROXY: () => {
 		const proxyHost = process.env.EXTERNAL_ONLY_PROXY_HOST;
 		const proxyPort = process.env.EXTERNAL_ONLY_PROXY_PORT;
@@ -156,4 +159,8 @@ export interface EnvVars {
 	MICROS_PLATFORM_STATSD_PORT: string;
 
 	JIRA_TEST_SITES: string;
+
+	S3_DUMPS_BUCKET_NAME: string;
+	S3_DUMPS_BUCKET_PATH: string;
+	S3_DUMPS_BUCKET_REGION: string;
 }

src/config/feature-flags.ts

@@ -31,7 +31,8 @@ export enum BooleanFlags {
 	DELETE_MESSAGE_ON_BACKFILL_WHEN_OTHERS_WORKING_ON_IT = "delete-message-on-backfill-when-others-working-on-it",
 	USE_NEW_5KU_SPA_EXPERIENCE = "enable-5ku-experience--cloud-connect",
 	USE_INSTALLATION_CLIENT_CHECK_PERMISSION = "use-installation-client-to-check-permission",
-	USE_CUSTOM_ROOT_CA_BUNDLE = "use-custom-root-ca-bundle"
+	USE_CUSTOM_ROOT_CA_BUNDLE = "use-custom-root-ca-bundle",
+	GENERATE_CORE_HEAP_DUMPS_ON_LOW_MEM = "generate-core-heap-dumps-on-low-mem"
 }
 
 export enum StringFlags {

src/main.ts

@@ -26,6 +26,8 @@ const CONF_WORKER_KEEP_ALIVE_PERIOD_MSEC = 7000;
 const CONF_MASTER_WORKERS_POLL_INTERVAL_MSEC = Math.floor(
 	CONF_WORKER_KEEP_ALIVE_PERIOD_MSEC * (2 + Math.random()) // different from KEEP_ALIVE to keep logs separated
 );
+const CONF_WORKER_DUMP_INTERVAL_MSEC = 10000;
+const CONF_WORKER_DUMP_LOW_HEAP_PCT = 25;
 
 const handleErrorsGracefully = (logger: Logger, intervalsToClear: NodeJS.Timeout[]) => {
 	process.on("uncaughtExceptionMonitor", (err, origin) => {
@@ -52,7 +54,11 @@ const handleErrorsGracefully = (logger: Logger, intervalsToClear: NodeJS.Timeout
 
 const troubleshootUnresponsiveWorkers_worker = () => {
 	handleErrorsGracefully(unresponsiveWorkersLogger,
-		[startMonitorOnWorker(unresponsiveWorkersLogger, CONF_WORKER_KEEP_ALIVE_PERIOD_MSEC)]
+		startMonitorOnWorker(unresponsiveWorkersLogger, {
+			iAmAliveInervalMsec: CONF_WORKER_KEEP_ALIVE_PERIOD_MSEC,
+			dumpIntervalMsec: CONF_WORKER_DUMP_INTERVAL_MSEC,
+			lowHeapAvailPct: CONF_WORKER_DUMP_LOW_HEAP_PCT
+		})
 	);
 };
 

src/routes/api/api-router.test.ts

@@ -362,6 +362,19 @@ describe("API Router", () => {
 
 		});
 
+		describe("fill-mem-and-generate-coredump", () => {
+			it("should return 200", () => {
+				return supertest(app)
+					.post("/api/fill-mem-and-generate-coredump?arraySize=2&nIter=7")
+					.set("host", "127.0.0.1")
+					.set("X-Slauth-Mechanism", "slauthtoken")
+					.expect(200)
+					.then((response) => {
+						expect(response.body).toEqual({ allocated: 14, dumpGenerated: false });
+					});
+			});
+		});
+
 		describe("Ping", () => {
 
 			it("Should fail on missing url", () => {

src/routes/api/api-router.ts

@@ -24,6 +24,9 @@ import { ApiResetSubscriptionFailedTasks } from "./api-reset-subscription-failed
 import { RecoverCommitsFromDatePost } from "./commits-from-date/recover-commits-from-dates";
 import { ResetFailedAndPendingDeploymentCursorPost } from "./commits-from-date/reset-failed-and-pending-deployment-cursors";
 import { ApiRecryptPost } from "./api-recrypt-post";
+import { GenerateOnceCoredumpGenerator } from "services/generate-once-coredump-generator";
+import { GenerateOncePerNodeHeadumpGenerator } from "services/generate-once-per-node-headump-generator";
+
 export const ApiRouter = Router();
 
 // TODO: remove this duplication because of the horrible way to do logs through requests
@@ -98,6 +101,59 @@ ApiRouter.post("/recrypt", ApiRecryptPost);
 
 ApiRouter.post("/ping", ApiPingPost);
 
+/**
+ * Workable parameters for ddev (250Mb heap):
+ *
+ * to occupy ~25% of mem and generate coredump:
+ * 	- ?arraySize=20000&nIter=400&pctThreshold=75
+ *
+ * to generate coredump straight away, without occupying any extra mem:
+ * 	- ?arraySize=1 &nIter=1&pcThreshold=100
+ *
+ * to generate heapdump:
+ * 	- ?arraySize=20000&nIter=400&pctThreshold=75&heap=true
+ *
+ * If you are generating heapdumps, you'll need to ssh to the instance and delete the lock file, because
+ * in production only one heapdump is allowed per node due to extremely high CPU/mem usage!
+ *
+ */
+const FillMemAndGenerateCoreDump = (req: Request, res: Response) => {
+	const nIter = parseInt(req.query?.nIter?.toString() || "0");
+	const arraySize = parseInt(req.query?.arraySize?.toString() || "10");
+	const pctThreshold = parseInt(req.query?.pctThreshold?.toString() || "50");
+	const heap = !!req.query?.heap;
+	req.log.info({
+		nIter, arraySize, pctThreshold, heap
+	}, "FillMemAndGenerateCoreDump triggered");
+
+	const generator: GenerateOncePerNodeHeadumpGenerator | GenerateOnceCoredumpGenerator =
+		heap ? new GenerateOncePerNodeHeadumpGenerator({
+			logger: req.log,
+			lowHeapAvailPct: pctThreshold
+		}) : new GenerateOnceCoredumpGenerator({
+			logger: req.log,
+			lowHeapAvailPct: pctThreshold
+		});
+
+	let dumpGenerated = false;
+	const allocate = (iter: number) => {
+		if (generator.maybeGenerateDump()) {
+			dumpGenerated = true;
+			return [];
+		}
+		const arr = new Array(arraySize).fill(`${Math.random()} This is a test string. ${Math.random()}`);
+
+		if (iter + 1 < nIter) {
+			const anotherOne = allocate(iter + 1);
+			return arr.concat(anotherOne);
+		}
+		return arr;
+	};
+	res.json({ allocated: allocate(0).length, dumpGenerated: dumpGenerated });
+};
+
+ApiRouter.post("/fill-mem-and-generate-coredump", FillMemAndGenerateCoreDump);
+
 // TODO: remove once move to DELETE /:installationId/:jiraHost
 ApiRouter.delete(
 	"/deleteInstallation/:installationId/:jiraHost/github-app-id/:gitHubAppId",

src/services/generate-once-coredump-generator.test.ts

@@ -0,0 +1,41 @@
+import { GenerateOnceCoredumpGenerator } from "services/generate-once-coredump-generator";
+import { getLogger } from "config/logger";
+import fs from "fs";
+import dumpme from "dumpme";
+import { hasEnoughFreeHeap } from "utils/heap-size-utils";
+
+jest.mock("utils/heap-size-utils");
+jest.mock("fs");
+jest.mock("dumpme");
+
+describe("coredump-generator", () => {
+	let generator: GenerateOnceCoredumpGenerator;
+
+	beforeEach(() => {
+		generator = new GenerateOnceCoredumpGenerator({
+			logger: getLogger("test"),
+			lowHeapAvailPct: 20
+		});
+	});
+
+	it("should not create coredump when enough memory available", () => {
+		(hasEnoughFreeHeap as jest.Mock).mockReturnValue(true);
+		expect(generator.maybeGenerateDump()).toBeFalsy();
+		expect(dumpme).not.toBeCalled();
+		expect(fs.renameSync).not.toBeCalled();
+	});
+
+	it("should create coredump when heap is too small", () => {
+		(hasEnoughFreeHeap as jest.Mock).mockReturnValue(false);
+		expect(generator.maybeGenerateDump()).toBeTruthy();
+		expect(dumpme).toBeCalled();
+		expect(fs.renameSync).toBeCalledWith(`/tmp/dump_core.${process.pid.toString()}`, `/tmp/dump_core.${process.pid.toString()}.ready`);
+	});
+
+	it("should create only a single coredump file", () => {
+		(hasEnoughFreeHeap as jest.Mock).mockReturnValue(false);
+		expect(generator.maybeGenerateDump()).toBeTruthy();
+		expect(generator.maybeGenerateDump()).toBeFalsy();
+		expect(dumpme).toBeCalledTimes(1);
+	});
+});

src/services/generate-once-coredump-generator.ts

@@ -0,0 +1,49 @@
+import Logger from "bunyan";
+import dumpme from "dumpme";
+import fs from "fs";
+import { hasEnoughFreeHeap } from "utils/heap-size-utils";
+
+/**
+ * Please note: it will generate the coredump only once for this instance! If you need to take it multiple times,
+ * create a new object.
+ */
+export class GenerateOnceCoredumpGenerator {
+	private config: {
+		logger: Logger,
+		lowHeapAvailPct: number,
+	};
+
+	private coreDumpGenerated = false;
+
+	constructor(config: {
+		logger: Logger,
+		lowHeapAvailPct: number,
+	}) {
+		this.config = config;
+	}
+
+	/**
+	 * In case of success, a file will be generated with the path /tmp/dump_core.PID
+	 */
+	public maybeGenerateDump(): boolean {
+		if (this.coreDumpGenerated) {
+			return false;
+		}
+
+		if (!hasEnoughFreeHeap(this.config.lowHeapAvailPct, this.config.logger)) {
+			this.config.logger.info(`Triggering coredump...`);
+
+			const tsBeforeDump = Date.now();
+			dumpme(undefined, `/tmp/dump_core`); // pid will be added by dumpme() as a suffix
+			const tsAfterDump = Date.now();
+
+			this.config.logger.info(`Core dump was created, took ${tsAfterDump - tsBeforeDump}`);
+
+			fs.renameSync(`/tmp/dump_core.${process.pid.toString()}`, `/tmp/dump_core.${process.pid.toString()}.ready`);
+			this.coreDumpGenerated = true;
+			return true;
+		}
+
+		return false;
+	}
+}

src/services/generate-once-per-node-headump-generator.ts

@@ -0,0 +1,56 @@
+import Logger from "bunyan";
+import fs from "fs";
+import { hasEnoughFreeHeap } from "utils/heap-size-utils";
+import v8 from "v8";
+
+const LOCk_FILE_PATH = "/tmp/hd_generated";
+
+/**
+ * Taking heapdump is very expensive, therefore it can be triggered only once per EC2 per the whole lifetime of the node!
+ */
+export class GenerateOncePerNodeHeadumpGenerator {
+	private config: {
+		logger: Logger,
+		lowHeapAvailPct: number,
+	};
+
+	constructor(config: {
+		logger: Logger,
+		lowHeapAvailPct: number,
+	}) {
+		this.config = config;
+	}
+
+	public maybeGenerateDump() {
+		if (this.generatedEarlier()) {
+			return false;
+		}
+
+		if (!hasEnoughFreeHeap(this.config.lowHeapAvailPct, this.config.logger)) {
+			this.markAsGeneratedEarlier();
+
+			this.config.logger.info(`Triggering heapdump...`);
+
+			const heapSnapshotStream = v8.getHeapSnapshot();
+			const writeStream = fs.createWriteStream("/tmp/dump_heap.generating");
+
+			heapSnapshotStream.pipe(writeStream);
+
+			writeStream.on("finish", () => {
+				this.config.logger.info("Heapdump was generated and saved!");
+				fs.renameSync("/tmp/dump_heap.generating", "/tmp/dump_heap.ready");
+			});
+			return true;
+		}
+
+		return false;
+	}
+
+	private generatedEarlier() {
+		return fs.existsSync(LOCk_FILE_PATH);
+	}
+
+	private markAsGeneratedEarlier() {
+		fs.writeFileSync(LOCk_FILE_PATH, new Date().toISOString());
+	}
+}