From bbda96b14e59d9c74c61a6be160fec52bdaca1c9 Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:26:05 -0500 Subject: [PATCH 01/10] adds morgan and winston for structured logging --- package-lock.json | 322 +++++++++++++++++++++++++++++++++++++++++++++- package.json | 7 +- 2 files changed, 323 insertions(+), 6 deletions(-) diff --git a/package-lock.json b/package-lock.json index 8d8ec87..6645035 100644 --- a/package-lock.json +++ b/package-lock.json @@ -14,13 +14,16 @@ "@sentry/cli": "^2.40.0", "@sentry/node": "^8.47.0", "@sentry/profiling-node": "^8.47.0", - "express": "^4.21.2" + "express": "^4.21.2", + "morgan": "^1.10.0", + "winston": "^3.17.0" }, "devDependencies": { "@eslint/js": "^9.17.0", "@types/eslint-config-prettier": "^6.11.3", "@types/express": "^4.17.8", "@types/jest": "^29.5.14", + "@types/morgan": "^1.9.9", "@types/node": "^22.10.5", "@typescript-eslint/eslint-plugin": "^8.18.1", "@typescript-eslint/parser": "^8.18.1", @@ -1598,6 +1601,15 @@ "dev": true, "license": "MIT" }, + "node_modules/@colors/colors": { + "version": "1.6.0", + "resolved": "https://registry.npmjs.org/@colors/colors/-/colors-1.6.0.tgz", + "integrity": "sha512-Ir+AOibqzrIsL6ajt3Rz3LskB7OiMVHqltZmspbW/TJuTVuyOMirVqAkjfY6JISiLHgyNqicAC8AyHHGzNd/dA==", + "license": "MIT", + "engines": { + "node": ">=0.1.90" + } + }, "node_modules/@cspotcode/source-map-support": { "version": "0.8.1", "resolved": "https://registry.npmjs.org/@cspotcode/source-map-support/-/source-map-support-0.8.1.tgz", @@ -1611,6 +1623,17 @@ "node": ">=12" } }, + "node_modules/@dabh/diagnostics": { + "version": "2.0.3", + "resolved": "https://registry.npmjs.org/@dabh/diagnostics/-/diagnostics-2.0.3.tgz", + "integrity": "sha512-hrlQOIi7hAfzsMqlGSFyVucrx38O+j6wiGOf//H2ecvIEqYN4ADBSS2iLMh5UFyDunCNniUIPk/q3riFv45xRA==", + "license": "MIT", + "dependencies": { + "colorspace": "1.1.x", + "enabled": "2.0.x", + "kuler": "^2.0.0" + } + }, "node_modules/@eslint-community/eslint-utils": { "version": "4.4.1", "resolved": "https://registry.npmjs.org/@eslint-community/eslint-utils/-/eslint-utils-4.4.1.tgz", @@ -4197,6 +4220,16 @@ "dev": true, "license": "MIT" }, + "node_modules/@types/morgan": { + "version": "1.9.9", + "resolved": "https://registry.npmjs.org/@types/morgan/-/morgan-1.9.9.tgz", + "integrity": "sha512-iRYSDKVaC6FkGSpEVVIvrRGw0DfJMiQzIn3qr2G5B3C//AWkulhXgaBd7tS9/J79GWSYMTHGs7PfI5b3Y8m+RQ==", + "dev": true, + "license": "MIT", + "dependencies": { + "@types/node": "*" + } + }, "node_modules/@types/mysql": { "version": "2.15.26", "resolved": "https://registry.npmjs.org/@types/mysql/-/mysql-2.15.26.tgz", @@ -4311,6 +4344,12 @@ "@types/node": "*" } }, + "node_modules/@types/triple-beam": { + "version": "1.3.5", + "resolved": "https://registry.npmjs.org/@types/triple-beam/-/triple-beam-1.3.5.tgz", + "integrity": "sha512-6WaYesThRMCl19iryMYP7/x2OVgCtbIVflDGFpWnb9irXI3UjYE4AzmYuiUKY1AJstGijoY+MgUszMgRxIYTYw==", + "license": "MIT" + }, "node_modules/@types/yargs": { "version": "17.0.33", "resolved": "https://registry.npmjs.org/@types/yargs/-/yargs-17.0.33.tgz", @@ -4742,7 +4781,6 @@ "version": "3.2.6", "resolved": "https://registry.npmjs.org/async/-/async-3.2.6.tgz", "integrity": "sha512-htCUDlxyyCLMgaM3xXg0C0LW2xqfuQ6p05pCEIsXuyQ+a1koYKTuBMzRNwmybfLgvJDMd0r1LTn4+E0Ti6C2AA==", - "dev": true, "license": "MIT" }, "node_modules/aws-sdk-client-mock": { @@ -4911,6 +4949,24 @@ "dev": true, "license": "MIT" }, + "node_modules/basic-auth": { + "version": "2.0.1", + "resolved": "https://registry.npmjs.org/basic-auth/-/basic-auth-2.0.1.tgz", + "integrity": "sha512-NF+epuEdnUYVlGuhaxbbq+dvJttwLnGY+YixlXlME5KpQ5W3CnXA5cVTneY3SPbPDRkcjMbifrwmFYcClgOZeg==", + "license": "MIT", + "dependencies": { + "safe-buffer": "5.1.2" + }, + "engines": { + "node": ">= 0.8" + } + }, + "node_modules/basic-auth/node_modules/safe-buffer": { + "version": "5.1.2", + "resolved": "https://registry.npmjs.org/safe-buffer/-/safe-buffer-5.1.2.tgz", + "integrity": "sha512-Gd2UZBJDkXlY7GbJxfsE8/nvKkUEU1G38c1siN6QP6a9PT9MmHB8GnpscSmMJSoF8LOIrt8ud/wPtojys4G6+g==", + "license": "MIT" + }, "node_modules/body-parser": { "version": "1.20.3", "resolved": "https://registry.npmjs.org/body-parser/-/body-parser-1.20.3.tgz", @@ -5230,6 +5286,16 @@ "dev": true, "license": "MIT" }, + "node_modules/color": { + "version": "3.2.1", + "resolved": "https://registry.npmjs.org/color/-/color-3.2.1.tgz", + "integrity": "sha512-aBl7dZI9ENN6fUGC7mWpMTPNHmWUSNan9tuWN6ahh5ZLNk9baLJOnSMlrQkHcrfFgz2/RigjUVAjdx36VcemKA==", + "license": "MIT", + "dependencies": { + "color-convert": "^1.9.3", + "color-string": "^1.6.0" + } + }, "node_modules/color-convert": { "version": "2.0.1", "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-2.0.1.tgz", @@ -5247,9 +5313,43 @@ "version": "1.1.4", "resolved": "https://registry.npmjs.org/color-name/-/color-name-1.1.4.tgz", "integrity": "sha512-dOy+3AuW3a2wNbZHIuMZpTcgjGuLU/uBL/ubcZF9OXbDo8ff4O8yVp5Bf0efS8uEoYo5q4Fx7dY9OgQGXgAsQA==", - "dev": true, "license": "MIT" }, + "node_modules/color-string": { + "version": "1.9.1", + "resolved": "https://registry.npmjs.org/color-string/-/color-string-1.9.1.tgz", + "integrity": "sha512-shrVawQFojnZv6xM40anx4CkoDP+fZsw/ZerEMsW/pyzsRbElpsL/DBVW7q3ExxwusdNXI3lXpuhEZkzs8p5Eg==", + "license": "MIT", + "dependencies": { + "color-name": "^1.0.0", + "simple-swizzle": "^0.2.2" + } + }, + "node_modules/color/node_modules/color-convert": { + "version": "1.9.3", + "resolved": "https://registry.npmjs.org/color-convert/-/color-convert-1.9.3.tgz", + "integrity": "sha512-QfAUtd+vFdAtFQcC8CCyYt1fYWxSqAiK2cSD6zDB8N3cpsEBAvRxp9zOGg6G/SHHJYAT88/az/IuDGALsNVbGg==", + "license": "MIT", + "dependencies": { + "color-name": "1.1.3" + } + }, + "node_modules/color/node_modules/color-name": { + "version": "1.1.3", + "resolved": "https://registry.npmjs.org/color-name/-/color-name-1.1.3.tgz", + "integrity": "sha512-72fSenhMw2HZMTVHeCA9KCmpEIbzWiQsjN+BHcBbS9vr1mtt+vJjPdksIBNUmKAW8TFUDPJK5SUU3QhE9NEXDw==", + "license": "MIT" + }, + "node_modules/colorspace": { + "version": "1.1.4", + "resolved": "https://registry.npmjs.org/colorspace/-/colorspace-1.1.4.tgz", + "integrity": "sha512-BgvKJiuVu1igBUF2kEjRCZXol6wiiGbY5ipL/oVPwm0BL9sIpMIzM8IK7vwuxIIzOXMV3Ey5w+vxhm0rR/TN8w==", + "license": "MIT", + "dependencies": { + "color": "^3.1.3", + "text-hex": "1.0.x" + } + }, "node_modules/concat-map": { "version": "0.0.1", "resolved": "https://registry.npmjs.org/concat-map/-/concat-map-0.0.1.tgz", @@ -5524,6 +5624,12 @@ "dev": true, "license": "MIT" }, + "node_modules/enabled": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/enabled/-/enabled-2.0.0.tgz", + "integrity": "sha512-AKrN98kuwOzMIdAizXGI86UFBoo26CL21UM763y1h/GMSJ4/OHU9k2YlsmBpyScFo/wbLzWQJBMCW4+IO3/+OQ==", + "license": "MIT" + }, "node_modules/encodeurl": { "version": "2.0.0", "resolved": "https://registry.npmjs.org/encodeurl/-/encodeurl-2.0.0.tgz", @@ -6046,6 +6152,12 @@ "bser": "2.1.1" } }, + "node_modules/fecha": { + "version": "4.2.3", + "resolved": "https://registry.npmjs.org/fecha/-/fecha-4.2.3.tgz", + "integrity": "sha512-OP2IUU6HeYKJi3i0z4A19kHMQoLVs4Hc+DPqqxI2h/DPZHTm/vjsfC6P0b4jCMy14XizLBqvndQ+UilD7707Jw==", + "license": "MIT" + }, "node_modules/file-entry-cache": { "version": "8.0.0", "resolved": "https://registry.npmjs.org/file-entry-cache/-/file-entry-cache-8.0.0.tgz", @@ -6166,6 +6278,12 @@ "dev": true, "license": "ISC" }, + "node_modules/fn.name": { + "version": "1.1.0", + "resolved": "https://registry.npmjs.org/fn.name/-/fn.name-1.1.0.tgz", + "integrity": "sha512-GRnmB5gPyJpAhTQdSZTSp9uaPSvl09KoYcMQtsB9rQoOmzs9dH6ffeccH+Z+cv6P68Hu5bC6JjRh4Ah/mHSNRw==", + "license": "MIT" + }, "node_modules/forwarded": { "version": "0.2.0", "resolved": "https://registry.npmjs.org/forwarded/-/forwarded-0.2.0.tgz", @@ -6647,7 +6765,6 @@ "version": "2.0.1", "resolved": "https://registry.npmjs.org/is-stream/-/is-stream-2.0.1.tgz", "integrity": "sha512-hFoiJiTl63nn+kstHGBtewWSKnQLpyb155KHheA1l39uvtO9nWIop1p3udqPcUd/xbF1VLMO4n7OI6p7RbngDg==", - "dev": true, "license": "MIT", "engines": { "node": ">=8" @@ -7499,6 +7616,12 @@ "node": ">=6" } }, + "node_modules/kuler": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/kuler/-/kuler-2.0.0.tgz", + "integrity": "sha512-Xq9nH7KlWZmXAtodXDDRE7vs6DU1gTU8zYDHDiWLSip45Egwq3plLHzPn27NgvzL2r1LMPC1vdqh98sQxtqj4A==", + "license": "MIT" + }, "node_modules/leven": { "version": "3.1.0", "resolved": "https://registry.npmjs.org/leven/-/leven-3.1.0.tgz", @@ -7567,6 +7690,23 @@ "dev": true, "license": "MIT" }, + "node_modules/logform": { + "version": "2.7.0", + "resolved": "https://registry.npmjs.org/logform/-/logform-2.7.0.tgz", + "integrity": "sha512-TFYA4jnP7PVbmlBIfhlSe+WKxs9dklXMTEGcBCIvLhE/Tn3H6Gk1norupVW7m5Cnd4bLcr08AytbyV/xj7f/kQ==", + "license": "MIT", + "dependencies": { + "@colors/colors": "1.6.0", + "@types/triple-beam": "^1.3.2", + "fecha": "^4.2.0", + "ms": "^2.1.1", + "safe-stable-stringify": "^2.3.1", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, "node_modules/loupe": { "version": "3.1.2", "resolved": "https://registry.npmjs.org/loupe/-/loupe-3.1.2.tgz", @@ -7749,6 +7889,49 @@ "integrity": "sha512-ySViT69/76t8VhE1xXHK6Ch4NcDd26gx0MzKXLO+F7NOtnqH68d9zF94nT8ZWSxXh8ELOERsnJO/sWt1xZYw5A==", "license": "MIT" }, + "node_modules/morgan": { + "version": "1.10.0", + "resolved": "https://registry.npmjs.org/morgan/-/morgan-1.10.0.tgz", + "integrity": "sha512-AbegBVI4sh6El+1gNwvD5YIck7nSA36weD7xvIxG4in80j/UoK8AEGaWnnz8v1GxonMCltmlNs5ZKbGvl9b1XQ==", + "license": "MIT", + "dependencies": { + "basic-auth": "~2.0.1", + "debug": "2.6.9", + "depd": "~2.0.0", + "on-finished": "~2.3.0", + "on-headers": "~1.0.2" + }, + "engines": { + "node": ">= 0.8.0" + } + }, + "node_modules/morgan/node_modules/debug": { + "version": "2.6.9", + "resolved": "https://registry.npmjs.org/debug/-/debug-2.6.9.tgz", + "integrity": "sha512-bC7ElrdJaJnPbAP+1EotYvqZsb3ecl5wi6Bfi6BJTUcNowp6cvspg0jXznRTKDjm/E7AdgFBVeAPVMNcKGsHMA==", + "license": "MIT", + "dependencies": { + "ms": "2.0.0" + } + }, + "node_modules/morgan/node_modules/ms": { + "version": "2.0.0", + "resolved": "https://registry.npmjs.org/ms/-/ms-2.0.0.tgz", + "integrity": "sha512-Tpp60P6IUJDTuOq/5Z8cdskzJujfwqfOTkrwIwj7IRISpnkJnT6SyJ4PCPnGMoFjC9ddhal5KVIYtAt97ix05A==", + "license": "MIT" + }, + "node_modules/morgan/node_modules/on-finished": { + "version": "2.3.0", + "resolved": "https://registry.npmjs.org/on-finished/-/on-finished-2.3.0.tgz", + "integrity": "sha512-ikqdkGAAyf/X/gPhXGvfgAytDZtDbr+bkNUJ0N9h5MI/dmdgCs3l6hoHrcUv41sRKew3jIwrp4qQDXiK99Utww==", + "license": "MIT", + "dependencies": { + "ee-first": "1.1.1" + }, + "engines": { + "node": ">= 0.8" + } + }, "node_modules/ms": { "version": "2.1.3", "resolved": "https://registry.npmjs.org/ms/-/ms-2.1.3.tgz", @@ -7898,6 +8081,15 @@ "node": ">= 0.8" } }, + "node_modules/on-headers": { + "version": "1.0.2", + "resolved": "https://registry.npmjs.org/on-headers/-/on-headers-1.0.2.tgz", + "integrity": "sha512-pZAE+FJLoyITytdqK0U5s+FIpjN0JP3OzFi/u8Rx+EV5/W+JTWGXG8xFzevE7AjBfDqHv/8vL8qQsIhHnqRkrA==", + "license": "MIT", + "engines": { + "node": ">= 0.8" + } + }, "node_modules/once": { "version": "1.4.0", "resolved": "https://registry.npmjs.org/once/-/once-1.4.0.tgz", @@ -7908,6 +8100,15 @@ "wrappy": "1" } }, + "node_modules/one-time": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/one-time/-/one-time-1.0.0.tgz", + "integrity": "sha512-5DXOiRKwuSEcQ/l0kGCF6Q3jcADFv5tSmRaJck/OqkVFcOzutB134KRSfF0xDrL39MNnqxbHBbUUcjZIhTgb2g==", + "license": "MIT", + "dependencies": { + "fn.name": "1.x.x" + } + }, "node_modules/onetime": { "version": "5.1.2", "resolved": "https://registry.npmjs.org/onetime/-/onetime-5.1.2.tgz", @@ -8436,6 +8637,20 @@ "dev": true, "license": "MIT" }, + "node_modules/readable-stream": { + "version": "3.6.2", + "resolved": "https://registry.npmjs.org/readable-stream/-/readable-stream-3.6.2.tgz", + "integrity": "sha512-9u/sniCrY3D5WdsERHzHE4G2YCXqoG5FTHUiCC4SIbr6XcLZBY05ya9EKjYek9O5xOAwjGq+1JdGBAS7Q9ScoA==", + "license": "MIT", + "dependencies": { + "inherits": "^2.0.3", + "string_decoder": "^1.1.1", + "util-deprecate": "^1.0.1" + }, + "engines": { + "node": ">= 6" + } + }, "node_modules/require-directory": { "version": "2.1.1", "resolved": "https://registry.npmjs.org/require-directory/-/require-directory-2.1.1.tgz", @@ -8568,6 +8783,15 @@ ], "license": "MIT" }, + "node_modules/safe-stable-stringify": { + "version": "2.5.0", + "resolved": "https://registry.npmjs.org/safe-stable-stringify/-/safe-stable-stringify-2.5.0.tgz", + "integrity": "sha512-b3rppTKm9T+PsVCBEOUR46GWI7fdOs00VKZ1+9c1EWDaDMvjQc6tUwuFyIprgGgTcWoVHSKrU8H31ZHA2e0RHA==", + "license": "MIT", + "engines": { + "node": ">=10" + } + }, "node_modules/safer-buffer": { "version": "2.1.2", "resolved": "https://registry.npmjs.org/safer-buffer/-/safer-buffer-2.1.2.tgz", @@ -8763,6 +8987,21 @@ "dev": true, "license": "ISC" }, + "node_modules/simple-swizzle": { + "version": "0.2.2", + "resolved": "https://registry.npmjs.org/simple-swizzle/-/simple-swizzle-0.2.2.tgz", + "integrity": "sha512-JA//kQgZtbuY83m+xT+tXJkmJncGMTFT+C+g2h2R9uxkYIrE2yy9sgmcLhCnw57/WSD+Eh3J97FPEDFnbXnDUg==", + "license": "MIT", + "dependencies": { + "is-arrayish": "^0.3.1" + } + }, + "node_modules/simple-swizzle/node_modules/is-arrayish": { + "version": "0.3.2", + "resolved": "https://registry.npmjs.org/is-arrayish/-/is-arrayish-0.3.2.tgz", + "integrity": "sha512-eVRqCvVlZbuw3GrM63ovNSNAeA1K16kaR/LRY/92w0zxQ5/1YzwblUX652i4Xs9RwAGjW9d9y6X88t8OaAJfWQ==", + "license": "MIT" + }, "node_modules/sinon": { "version": "18.0.1", "resolved": "https://registry.npmjs.org/sinon/-/sinon-18.0.1.tgz", @@ -8847,6 +9086,15 @@ "dev": true, "license": "BSD-3-Clause" }, + "node_modules/stack-trace": { + "version": "0.0.10", + "resolved": "https://registry.npmjs.org/stack-trace/-/stack-trace-0.0.10.tgz", + "integrity": "sha512-KGzahc7puUKkzyMt+IqAep+TVNbKP+k2Lmwhub39m1AsTSkaDutx56aDCo+HLDzf/D26BIHTJWNiTG1KAJiQCg==", + "license": "MIT", + "engines": { + "node": "*" + } + }, "node_modules/stack-utils": { "version": "2.0.6", "resolved": "https://registry.npmjs.org/stack-utils/-/stack-utils-2.0.6.tgz", @@ -8879,6 +9127,15 @@ "node": ">= 0.8" } }, + "node_modules/string_decoder": { + "version": "1.3.0", + "resolved": "https://registry.npmjs.org/string_decoder/-/string_decoder-1.3.0.tgz", + "integrity": "sha512-hkRX8U1WjJFd8LsDJ2yQ/wWWxaopEsABU1XfkM8A+j0+85JAGppt16cr1Whg6KIbb4okU6Mql6BOj+uup/wKeA==", + "license": "MIT", + "dependencies": { + "safe-buffer": "~5.2.0" + } + }, "node_modules/string-length": { "version": "4.0.2", "resolved": "https://registry.npmjs.org/string-length/-/string-length-4.0.2.tgz", @@ -9024,6 +9281,12 @@ "node": "*" } }, + "node_modules/text-hex": { + "version": "1.0.0", + "resolved": "https://registry.npmjs.org/text-hex/-/text-hex-1.0.0.tgz", + "integrity": "sha512-uuVGNWzgJ4yhRaNSiubPY7OjISw4sw4E5Uv0wbjp+OzcbmVU/rsT8ujgcXJhn9ypzsgr5vlzpPqP+MBBKcGvbg==", + "license": "MIT" + }, "node_modules/tinyrainbow": { "version": "1.2.0", "resolved": "https://registry.npmjs.org/tinyrainbow/-/tinyrainbow-1.2.0.tgz", @@ -9079,6 +9342,15 @@ "integrity": "sha512-N3WMsuqV66lT30CrXNbEjx4GEwlow3v6rr4mCcv6prnfwhS01rkgyFdjPNBYd9br7LpXV1+Emh01fHnq2Gdgrw==", "license": "MIT" }, + "node_modules/triple-beam": { + "version": "1.4.1", + "resolved": "https://registry.npmjs.org/triple-beam/-/triple-beam-1.4.1.tgz", + "integrity": "sha512-aZbgViZrg1QNcG+LULa7nhZpJTZSLm/mXnHXnbAbjmN5aSa0y7V+wvv6+4WaBtpISJzThKy+PIPxc1Nq1EJ9mg==", + "license": "MIT", + "engines": { + "node": ">= 14.0.0" + } + }, "node_modules/ts-api-utils": { "version": "1.4.3", "resolved": "https://registry.npmjs.org/ts-api-utils/-/ts-api-utils-1.4.3.tgz", @@ -9333,6 +9605,12 @@ "punycode": "^2.1.0" } }, + "node_modules/util-deprecate": { + "version": "1.0.2", + "resolved": "https://registry.npmjs.org/util-deprecate/-/util-deprecate-1.0.2.tgz", + "integrity": "sha512-EPD5q1uXyFxJpCrLnCc1nHnq3gOa6DZBocAIiI2TaSCA7VCJ1UJDMagCzIkXNsUYfD1daK//LTEQ8xiIbrHtcw==", + "license": "MIT" + }, "node_modules/utils-merge": { "version": "1.0.1", "resolved": "https://registry.npmjs.org/utils-merge/-/utils-merge-1.0.1.tgz", @@ -9438,6 +9716,42 @@ "node": ">= 8" } }, + "node_modules/winston": { + "version": "3.17.0", + "resolved": "https://registry.npmjs.org/winston/-/winston-3.17.0.tgz", + "integrity": "sha512-DLiFIXYC5fMPxaRg832S6F5mJYvePtmO5G9v9IgUFPhXm9/GkXarH/TUrBAVzhTCzAj9anE/+GjrgXp/54nOgw==", + "license": "MIT", + "dependencies": { + "@colors/colors": "^1.6.0", + "@dabh/diagnostics": "^2.0.2", + "async": "^3.2.3", + "is-stream": "^2.0.0", + "logform": "^2.7.0", + "one-time": "^1.0.0", + "readable-stream": "^3.4.0", + "safe-stable-stringify": "^2.3.1", + "stack-trace": "0.0.x", + "triple-beam": "^1.3.0", + "winston-transport": "^4.9.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, + "node_modules/winston-transport": { + "version": "4.9.0", + "resolved": "https://registry.npmjs.org/winston-transport/-/winston-transport-4.9.0.tgz", + "integrity": "sha512-8drMJ4rkgaPo1Me4zD/3WLfI/zPdA9o2IipKODunnGDcuqbHwjsbB79ylv04LCGGzU0xQ6vTznOMpQGaLhhm6A==", + "license": "MIT", + "dependencies": { + "logform": "^2.7.0", + "readable-stream": "^3.6.2", + "triple-beam": "^1.3.0" + }, + "engines": { + "node": ">= 12.0.0" + } + }, "node_modules/word-wrap": { "version": "1.2.5", "resolved": "https://registry.npmjs.org/word-wrap/-/word-wrap-1.2.5.tgz", diff --git a/package.json b/package.json index 124066c..a6def94 100644 --- a/package.json +++ b/package.json @@ -19,13 +19,16 @@ "@sentry/cli": "^2.40.0", "@sentry/node": "^8.47.0", "@sentry/profiling-node": "^8.47.0", - "express": "^4.21.2" + "express": "^4.21.2", + "morgan": "^1.10.0", + "winston": "^3.17.0" }, "devDependencies": { - "@types/express": "^4.17.8", "@eslint/js": "^9.17.0", "@types/eslint-config-prettier": "^6.11.3", + "@types/express": "^4.17.8", "@types/jest": "^29.5.14", + "@types/morgan": "^1.9.9", "@types/node": "^22.10.5", "@typescript-eslint/eslint-plugin": "^8.18.1", "@typescript-eslint/parser": "^8.18.1", From 301ef70b2770f1473b728190a70b50268fa2e46c Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:26:25 -0500 Subject: [PATCH 02/10] function for getting a logger --- src/logger.ts | 11 +++++++++++ 1 file changed, 11 insertions(+) create mode 100644 src/logger.ts diff --git a/src/logger.ts b/src/logger.ts new file mode 100644 index 0000000..ec77d3f --- /dev/null +++ b/src/logger.ts @@ -0,0 +1,11 @@ +import winston from "winston"; + +const { combine, timestamp, json, errors, splat } = winston.format; + +export function getLogger(): winston.Logger { + return winston.createLogger({ + level: process.env.LOG_LEVEL ?? "info", + format: combine(splat(), errors({ stack: true }), timestamp(), json()), + transports: [new winston.transports.Console()], + }); +} From 91ddcf1165b7313bda59b894a0e78f9cd7b3da67 Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:26:48 -0500 Subject: [PATCH 03/10] switched to winston for logging --- src/ThumbnailApi.ts | 18 +++++++++++------- test/unit/ThumbnailApi.test.ts | 10 ++++------ 2 files changed, 15 insertions(+), 13 deletions(-) diff --git a/src/ThumbnailApi.ts b/src/ThumbnailApi.ts index 8445a3b..370dd14 100644 --- a/src/ThumbnailApi.ts +++ b/src/ThumbnailApi.ts @@ -4,12 +4,15 @@ import { DplaApi } from "./DplaApi"; import { ThumbnailStorage } from "./ThumbnailStorage"; import { ThumbnailCacheQueue } from "./ThumbnailCacheQueue"; import { ResponseHelper } from "./ResponseHelper"; +import { getLogger } from "./logger"; +import { Logger } from "winston"; const LONG_CACHE_TIME: number = 60 * 60 * 24 * 30; // 30 days in seconds const SHORT_CACHE_TIME = 60 * 60; // 1 hr in seconds const PATH_PATTERN = /^\/thumb\/([a-f0-9]{32})$/; export class ThumbnailApi { + logger: Logger; dplaApi: DplaApi; thumbnailStorage: ThumbnailStorage; thumbnailCacheQueue: ThumbnailCacheQueue; @@ -21,6 +24,7 @@ export class ThumbnailApi { thumbnailCacheQueue: ThumbnailCacheQueue, responseHelper: ResponseHelper, ) { + this.logger = getLogger(); this.dplaApi = dplaApi; this.thumbnailStorage = thumbnailStorage; this.thumbnailCacheQueue = thumbnailCacheQueue; @@ -31,8 +35,7 @@ export class ThumbnailApi { const itemId: string | undefined = this.getItemId(req.path); if (!itemId) { - const error = new Error("Bad item ID."); - this.sendError(res, "id not found", 400, error); + this.sendError(res, "ID not found", 400); return; } @@ -60,8 +63,7 @@ export class ThumbnailApi { } if (imageUrl === undefined) { - const error = new Error("No image URL found."); - this.sendError(expressResponse, itemId, 404, error); + this.sendError(expressResponse, itemId, 404); return; } @@ -70,7 +72,7 @@ export class ThumbnailApi { this.thumbnailCacheQueue .queueToThumbnailCache(itemId, imageUrl) .catch((error: unknown) => { - console.error("SQS error for %s", itemId, error); + this.logger.error("SQS error for %s", itemId, error); }); // we only want the cache to have the proxied image from the contributor @@ -151,7 +153,7 @@ export class ThumbnailApi { expressResponse, ); } else { - const error = new Error("Response had no body."); + const error = new Error("Upstream response had no body."); this.sendError(expressResponse, itemId, 502, error); } } @@ -173,7 +175,9 @@ export class ThumbnailApi { code: number, error?: Error, ): void { - console.error("Sending %s for %s:", code, itemId, error); + if (error) { + this.logger.error("Sending %s for %s:", code, itemId, error); + } res.sendStatus(code); res.end(); } diff --git a/test/unit/ThumbnailApi.test.ts b/test/unit/ThumbnailApi.test.ts index 84c0981..1058510 100644 --- a/test/unit/ThumbnailApi.test.ts +++ b/test/unit/ThumbnailApi.test.ts @@ -50,8 +50,9 @@ describe("ThumbnailApi", () => { expect(thumbnailApi.getItemId(input)).toBe(output); }); + //todo test("sendError", () => { - const consoleSpy = jest.spyOn(console, "error").mockImplementation(); + thumbnailApi.logger.configure({ silent: true }); const mockResponse = new ExpressResponse(); const itemId = "12345"; const code = 6789; @@ -62,10 +63,8 @@ describe("ThumbnailApi", () => { code, error, ); - expect(consoleSpy).toHaveBeenCalledTimes(1); expect(mockResponse.sendStatus).toHaveBeenCalledWith(code); expect(mockResponse.end).toHaveBeenCalledTimes(1); - consoleSpy.mockRestore(); }); }); @@ -323,8 +322,8 @@ describe("ThumbnailApi async tests", () => { expect(sendError).toHaveBeenCalled(); }); + //todo test("thumbnailCacheQueue failed", async () => { - const consoleSpy = jest.spyOn(console, "error").mockImplementation(); const thumbnailCacheQueue = new ThumbnailCacheQueue( "", mockS3Client as unknown as SQSClient, @@ -342,6 +341,7 @@ describe("ThumbnailApi async tests", () => { thumbnailCacheQueue as unknown as ThumbnailCacheQueue, responseHelper, ); + thumbnailApiFailingCacheQueue.logger.configure({ silent: true }); await thumbnailApiFailingCacheQueue.proxyItemFromContributor( itemId, @@ -349,8 +349,6 @@ describe("ThumbnailApi async tests", () => { ); expect(queueToThumbnailCache).toHaveBeenCalled(); - expect(consoleSpy).toHaveBeenCalledTimes(1); - consoleSpy.mockRestore(); }); test("upstream failed", async () => { From 4b5cc7c97fb4f09c38789ab00f663070f650a2bc Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:26:56 -0500 Subject: [PATCH 04/10] switched to winston for logging --- src/ResponseHelper.ts | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/ResponseHelper.ts b/src/ResponseHelper.ts index 34cd823..e1adfa1 100644 --- a/src/ResponseHelper.ts +++ b/src/ResponseHelper.ts @@ -1,5 +1,8 @@ import { Readable } from "stream"; import express from "express"; +import { getLogger } from "./logger"; + +const logger = getLogger(); export class ResponseHelper { FETCH_TIMEOUT = 10 * 1000; // 10 seconds; @@ -8,7 +11,7 @@ export class ResponseHelper { try { Readable.fromWeb(body).pipe(expressResponse); } catch { - console.error("Failed to pipe response from upstream."); + logger.error("Failed to pipe response from upstream."); } return Promise.resolve(); } From 1ac9796888846dcf7cff5a34f0e9e35fc1f1d7e4 Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:28:49 -0500 Subject: [PATCH 05/10] logging + handlers + cluster fixes - switched to winston for logging - added morgan for access logging - made /health never 304 - uncaughtException handler - unhandledRejection handler - respawning crashed worker fix --- src/app.ts | 47 ++++++++++++++++++++++++++++++++++++++--------- 1 file changed, 38 insertions(+), 9 deletions(-) diff --git a/src/app.ts b/src/app.ts index ee53a8f..bc3e1dd 100644 --- a/src/app.ts +++ b/src/app.ts @@ -1,16 +1,19 @@ import "./instrumentation.js"; //IMPORTANT: keep this first +import morgan from "morgan"; import * as Sentry from "@sentry/node"; import express, { Express } from "express"; import { S3Client } from "@aws-sdk/client-s3"; import { SQSClient } from "@aws-sdk/client-sqs"; import { ThumbnailApi } from "./ThumbnailApi.js"; import { default as cluster, Worker } from "node:cluster"; -import { cpus } from "node:os"; +import { availableParallelism } from "node:os"; import { DplaApi } from "./DplaApi"; import { ThumbnailStorage } from "./ThumbnailStorage"; import { ThumbnailCacheQueue } from "./ThumbnailCacheQueue"; import { ResponseHelper } from "./ResponseHelper"; +import { getLogger } from "./logger"; +const logger = getLogger(); // How long we wait for a request from a socket const REQUEST_TIMEOUT = 3000; // 3 secs @@ -20,7 +23,7 @@ const RESPONSE_TIMEOUT = 10000; // 10 seconds start(); function start() { - const numCPUs = Number(process.env.PS_COUNT) || cpus().length; + const numCPUs = Number(process.env.PS_COUNT) || availableParallelism(); const mustFork = process.env.MUST_FORK === "true" || process.env.NODE_ENV === "production"; @@ -47,6 +50,13 @@ function doWorker() { } const app: Express = express(); + app.use( + morgan(":method :url :status :res[content-length] - :response-time ms", { + stream: { + write: (message: string) => logger.info(message.trim()), + }, + }), + ); const s3Client = new S3Client(awsOptions); const sqsClient = new SQSClient(awsOptions); @@ -72,7 +82,7 @@ function doWorker() { try { await thumbnailApi.handle(req, res); } catch (error) { - console.error("Error fetching thumb:", error); + logger.error("Unexpected Error fetching thumb:", error); } }; @@ -80,25 +90,30 @@ function doWorker() { handler(req, res) .then(() => Promise.resolve()) .catch((reason: unknown) => { - console.error("Caught error from handler: %s", reason); + logger.error("Caught error from handler: %s", reason); }); }); app.get("/health", (_req: express.Request, res: express.Response): void => { - res.sendStatus(200).end(); + const healthcheck = { + message: "OK", + uptime: process.uptime(), + timestamp: Date.now(), + }; + res.status(200).send(healthcheck).end(); }); Sentry.setupExpressErrorHandler(app); const server = app.listen(port, (): void => { - console.log(`Server is listening on ${String(port)}`); + logger.info(`Server is listening on ${String(port)}`); }); // how long the server waits before the client needs to finish sending the request server.requestTimeout = REQUEST_TIMEOUT; const handleExit: NodeJS.SignalsListener = (signal: NodeJS.Signals) => { - console.log("Received %s. Shutting down.", signal); + logger.info("Received %s. Shutting down.", signal); server.close(() => { process.exit(0); }); @@ -107,21 +122,35 @@ function doWorker() { process.on("SIGINT", () => { handleExit("SIGINT"); }); + process.on("SIGQUIT", () => { handleExit("SIGQUIT"); }); + process.on("SIGTERM", () => { handleExit("SIGTERM"); }); + + process.on("uncaughtException", (err: unknown) => { + logger.error("Uncaught exception. Shutting down.", err); + process.exit(1); + }); + + process.on("unhandledRejection", (err) => { + logger.error(err); + process.exit(1); + }); } function doFork(numCPUs: number): void { cluster .on("exit", (worker: Worker): void => { - console.log(`worker ${String(worker.process.pid)} died`); + logger.info(`Worker ${String(worker.process.pid)} died`); + logger.info("Initiating replacement worker."); + cluster.fork(); }) .on("online", (worker: Worker): void => { - console.log(`worker ${String(worker.process.pid)} online`); + logger.info(`worker ${String(worker.process.pid)} online`); }); for (let i = 0; i < numCPUs; i++) { cluster.fork(); From 0b79bf71c73157fd8e7f687c82cb345b42dca0f0 Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sat, 4 Jan 2025 16:58:48 -0500 Subject: [PATCH 06/10] Disables npm run echoing command output. --- Dockerfile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Dockerfile b/Dockerfile index ab91e94..0e75067 100644 --- a/Dockerfile +++ b/Dockerfile @@ -15,4 +15,4 @@ HEALTHCHECK CMD ["curl", "-f", "http://localhost:3000/health"] RUN npm run clean \ && npm ci --ignore-scripts \ && npm run build -CMD ["npm", "run", "start"] +CMD ["npm", "run", "start", "--s"] From 897ecb4163395c6788445763f77ffccd5f8e8292 Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sun, 5 Jan 2025 17:01:58 -0500 Subject: [PATCH 07/10] Fixed silent flag for npm. --- Dockerfile | 2 +- 1 file changed, 1 insertion(+), 1 deletion(-) diff --git a/Dockerfile b/Dockerfile index 0e75067..db61cb4 100644 --- a/Dockerfile +++ b/Dockerfile @@ -15,4 +15,4 @@ HEALTHCHECK CMD ["curl", "-f", "http://localhost:3000/health"] RUN npm run clean \ && npm ci --ignore-scripts \ && npm run build -CMD ["npm", "run", "start", "--s"] +CMD ["npm", "run", "start", "-s"] From 322ef70845bee3f17d516aac3b7ee5ba9ca2d83b Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sun, 5 Jan 2025 17:02:25 -0500 Subject: [PATCH 08/10] Added sbom and provenance flags --- .github/workflows/ecr-staging.yml | 2 ++ .github/workflows/ecr.yml | 2 ++ 2 files changed, 4 insertions(+) diff --git a/.github/workflows/ecr-staging.yml b/.github/workflows/ecr-staging.yml index 4ca0223..5d286c5 100644 --- a/.github/workflows/ecr-staging.yml +++ b/.github/workflows/ecr-staging.yml @@ -73,4 +73,6 @@ jobs: -t $ECR_REGISTRY/$ECR_REPOSITORY:$BRANCH_NAME \ -t $ECR_REGISTRY/$ECR_REPOSITORY:$IMAGE_TAG \ --platform linux/amd64,linux/arm64 . \ + --sbom=true \ + --provenance=true \ --push \ No newline at end of file diff --git a/.github/workflows/ecr.yml b/.github/workflows/ecr.yml index 3097eb7..d96fbe5 100644 --- a/.github/workflows/ecr.yml +++ b/.github/workflows/ecr.yml @@ -73,4 +73,6 @@ jobs: -t $ECR_REGISTRY/$ECR_REPOSITORY:$BRANCH_NAME \ -t $ECR_REGISTRY/$ECR_REPOSITORY:$IMAGE_TAG \ --platform linux/amd64,linux/arm64 . \ + --sbom=true \ + --provenance=true \ --push \ No newline at end of file From 7a375e1f4796479255e5eec2b2ce0184953c180d Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sun, 5 Jan 2025 17:02:51 -0500 Subject: [PATCH 09/10] test for logger --- test/unit/logger.test.ts | 13 +++++++++++++ 1 file changed, 13 insertions(+) create mode 100644 test/unit/logger.test.ts diff --git a/test/unit/logger.test.ts b/test/unit/logger.test.ts new file mode 100644 index 0000000..daf7cb5 --- /dev/null +++ b/test/unit/logger.test.ts @@ -0,0 +1,13 @@ +import { getLogger } from "../../src/logger"; + +describe("logger", () => { + test("Uses info if no level is set", () => { + const logger = getLogger(); + expect(logger.level).toBe("info"); + }); + test("Can log at another level with LOG_LEVEL", () => { + process.env.LOG_LEVEL = "error"; + const logger = getLogger(); + expect(logger.level).toBe("error"); + }); +}); From 9512583f1818eeac80c9e8ada0c5644f4dcff25b Mon Sep 17 00:00:00 2001 From: Michael Della Bitta Date: Sun, 5 Jan 2025 17:05:16 -0500 Subject: [PATCH 10/10] factored out app.ts to main.ts and ExpressSetup.ts. Added tests. --- package.json | 3 +- src/ExpressSetup.ts | 124 ++++++++++++++++++++++++++ src/app.ts | 158 --------------------------------- src/main.ts | 111 +++++++++++++++++++++++ test/unit/ExpressSetup.test.ts | 112 +++++++++++++++++++++++ test/unit/index.test.ts | 133 +++++++++++++++++++++++++++ 6 files changed, 481 insertions(+), 160 deletions(-) create mode 100644 src/ExpressSetup.ts delete mode 100644 src/app.ts create mode 100644 src/main.ts create mode 100644 test/unit/ExpressSetup.test.ts create mode 100644 test/unit/index.test.ts diff --git a/package.json b/package.json index a6def94..16f7f8b 100644 --- a/package.json +++ b/package.json @@ -5,11 +5,10 @@ "scripts": { "build": "tsc", "clean": "rm -r dist thumbnail-api.zip 2> /dev/null ; exit 0", - "start": "node dist/src/app.js", + "start": "node dist/src/main.js", "lint": "npx eslint", "format": "prettier --ignore-path .gitignore --write \"**/*.+(js|ts|json)\"", "test": "jest test/unit", - "zip": "zip -r thumbnail-api.zip dist node_modules package-lock.json package.json", "sentry:sourcemaps": "sentry-cli sourcemaps inject --org dpla --project thumbnail-api ./dist && sentry-cli sourcemaps upload --org dpla --project thumbnail-api ./dist" }, "dependencies": { diff --git a/src/ExpressSetup.ts b/src/ExpressSetup.ts new file mode 100644 index 0000000..de08f39 --- /dev/null +++ b/src/ExpressSetup.ts @@ -0,0 +1,124 @@ +import * as Sentry from "@sentry/node"; +import morgan from "morgan"; +import { Logger } from "winston"; +import express, { Express } from "express"; +import * as Http from "node:http"; +import { ThumbnailApi } from "./ThumbnailApi"; +import { Server } from "node:http"; + +// How long we wait for a request from a socket +const REQUEST_TIMEOUT = 3000; // 3 secs + +// How long we wait on piping a response before we give up +const RESPONSE_TIMEOUT = 10000; // 10 seconds + +export class ExpressSetup { + app: Express; + logger: Logger; + + constructor(app: Express, logger: Logger) { + this.app = app; + this.logger = logger; + } + + sentry() { + Sentry.setupExpressErrorHandler(this.app); + } + + morgan() { + this.app.use( + morgan(":method :url :status :res[content-length] - :response-time ms", { + stream: { + write: (message: string) => this.logger.info(message.trim()), + }, + }), + ); + } + + exit(retVal: number) { + process.exit(retVal); + } + + handleExit(reason: string, server: Server, retVal: number) { + this.logger.info("Received %s. Shutting down.", reason); + server.close(() => { + this.exit(retVal); + }); + } + + registerHandlers(server: Http.Server) { + process.on("SIGINT", () => { + this.handleExit("SIGINT", server, 0); + }); + + process.on("SIGQUIT", () => { + this.handleExit("SIGQUIT", server, 0); + }); + + process.on("SIGTERM", () => { + this.handleExit("SIGTERM", server, 0); + }); + + process.on("uncaughtException", (err: unknown, origin: string) => { + this.handleExit( + "uncaughtException: " + String(err) + ": " + origin, + server, + 1, + ); + }); + + process.on("unhandledRejection", (err: unknown, origin: string) => { + this.handleExit( + "unhandledRejection: " + String(err) + ": " + origin, + server, + 1, + ); + }); + } + + setRequestTimeout(server: Http.Server) { + server.requestTimeout = REQUEST_TIMEOUT; + } + + server(port: number): Http.Server { + return this.app.listen(port, (): void => { + this.logger.info(`Server is listening on ${String(port)}`); + }); + } + + routes(thumbnailApi: ThumbnailApi) { + // next two methods are like this to make + // eslint happy about the async get handler + const handler = async (req: express.Request, res: express.Response) => { + res.setTimeout(RESPONSE_TIMEOUT, () => { + res.status(504); + res.send("Gateway Timeout"); + }); + try { + await thumbnailApi.handle(req, res); + } catch (error) { + this.logger.error("Unexpected Error fetching thumb:", error); + } + }; + + this.app.get("/thumb/*", (req: express.Request, res: express.Response) => { + handler(req, res) + .then(() => Promise.resolve()) + .catch((reason: unknown) => { + this.logger.error("Caught error from handler: %s", reason); + }); + }); + + this.app.get( + "/health", + (_req: express.Request, res: express.Response): void => { + const healthcheck = { + message: "OK", + uptime: process.uptime(), + timestamp: Date.now(), + }; + res.status(200).send(healthcheck).end(); + }, + ); + } +} diff --git a/src/app.ts b/src/app.ts deleted file mode 100644 index bc3e1dd..0000000 --- a/src/app.ts +++ /dev/null @@ -1,158 +0,0 @@ -import "./instrumentation.js"; //IMPORTANT: keep this first -import morgan from "morgan"; -import * as Sentry from "@sentry/node"; -import express, { Express } from "express"; -import { S3Client } from "@aws-sdk/client-s3"; -import { SQSClient } from "@aws-sdk/client-sqs"; -import { ThumbnailApi } from "./ThumbnailApi.js"; -import { default as cluster, Worker } from "node:cluster"; -import { availableParallelism } from "node:os"; -import { DplaApi } from "./DplaApi"; -import { ThumbnailStorage } from "./ThumbnailStorage"; -import { ThumbnailCacheQueue } from "./ThumbnailCacheQueue"; -import { ResponseHelper } from "./ResponseHelper"; -import { getLogger } from "./logger"; - -const logger = getLogger(); -// How long we wait for a request from a socket -const REQUEST_TIMEOUT = 3000; // 3 secs - -// How long we wait on piping a response before we give up -const RESPONSE_TIMEOUT = 10000; // 10 seconds - -start(); - -function start() { - const numCPUs = Number(process.env.PS_COUNT) || availableParallelism(); - const mustFork = - process.env.MUST_FORK === "true" || process.env.NODE_ENV === "production"; - - if (cluster.isPrimary && mustFork) { - doFork(numCPUs); - } else { - doWorker(); - } -} - -function doWorker() { - const port = process.env.PORT ?? 3000; - const awsOptions = { region: process.env.REGION ?? "us-east-1" }; - const bucket = process.env.BUCKET ?? "dpla-thumbnails"; - const sqsUrl = - process.env.SQS_URL ?? - "https://sqs.us-east-1.amazonaws.com/283408157088/thumbp-image"; - - const dplaApiUrl = process.env.DPLA_API_URL ?? "https://api.dp.la"; - const dplaApiKey = process.env.DPLA_API_KEY; - - if (!dplaApiKey) { - throw new Error("Env variable DPLA_API_KEY not set."); - } - - const app: Express = express(); - app.use( - morgan(":method :url :status :res[content-length] - :response-time ms", { - stream: { - write: (message: string) => logger.info(message.trim()), - }, - }), - ); - const s3Client = new S3Client(awsOptions); - const sqsClient = new SQSClient(awsOptions); - - const dplaApi = new DplaApi(dplaApiUrl, dplaApiKey); - const thumbnailStorage = new ThumbnailStorage(s3Client, bucket); - const thumbnailCacheQueue = new ThumbnailCacheQueue(sqsUrl, sqsClient); - const responseHelper = new ResponseHelper(); - - const thumbnailApi: ThumbnailApi = new ThumbnailApi( - dplaApi, - thumbnailStorage, - thumbnailCacheQueue, - responseHelper, - ); - - // next two methods are like this to make - // eslint happy about the async get handler - const handler = async (req: express.Request, res: express.Response) => { - res.setTimeout(RESPONSE_TIMEOUT, () => { - res.status(504); - res.send("Gateway Timeout"); - }); - try { - await thumbnailApi.handle(req, res); - } catch (error) { - logger.error("Unexpected Error fetching thumb:", error); - } - }; - - app.get("/thumb/*", (req: express.Request, res: express.Response) => { - handler(req, res) - .then(() => Promise.resolve()) - .catch((reason: unknown) => { - logger.error("Caught error from handler: %s", reason); - }); - }); - - app.get("/health", (_req: express.Request, res: express.Response): void => { - const healthcheck = { - message: "OK", - uptime: process.uptime(), - timestamp: Date.now(), - }; - res.status(200).send(healthcheck).end(); - }); - - Sentry.setupExpressErrorHandler(app); - - const server = app.listen(port, (): void => { - logger.info(`Server is listening on ${String(port)}`); - }); - - // how long the server waits before the client needs to finish sending the request - server.requestTimeout = REQUEST_TIMEOUT; - - const handleExit: NodeJS.SignalsListener = (signal: NodeJS.Signals) => { - logger.info("Received %s. Shutting down.", signal); - server.close(() => { - process.exit(0); - }); - }; - - process.on("SIGINT", () => { - handleExit("SIGINT"); - }); - - process.on("SIGQUIT", () => { - handleExit("SIGQUIT"); - }); - - process.on("SIGTERM", () => { - handleExit("SIGTERM"); - }); - - process.on("uncaughtException", (err: unknown) => { - logger.error("Uncaught exception. Shutting down.", err); - process.exit(1); - }); - - process.on("unhandledRejection", (err) => { - logger.error(err); - process.exit(1); - }); -} - -function doFork(numCPUs: number): void { - cluster - .on("exit", (worker: Worker): void => { - logger.info(`Worker ${String(worker.process.pid)} died`); - logger.info("Initiating replacement worker."); - cluster.fork(); - }) - .on("online", (worker: Worker): void => { - logger.info(`worker ${String(worker.process.pid)} online`); - }); - for (let i = 0; i < numCPUs; i++) { - cluster.fork(); - } -} diff --git a/src/main.ts b/src/main.ts new file mode 100644 index 0000000..743ef90 --- /dev/null +++ b/src/main.ts @@ -0,0 +1,111 @@ +import "./instrumentation"; //IMPORTANT: keep this first + +import express from "express"; +import { default as cluster, Worker } from "node:cluster"; +import { availableParallelism } from "node:os"; +import { getLogger } from "./logger"; +import { ExpressSetup } from "./ExpressSetup"; +import { ThumbnailApi } from "./ThumbnailApi"; +import { S3Client } from "@aws-sdk/client-s3"; +import { SQSClient } from "@aws-sdk/client-sqs"; +import { DplaApi } from "./DplaApi"; +import { ThumbnailStorage } from "./ThumbnailStorage"; +import { ResponseHelper } from "./ResponseHelper"; +import { ThumbnailCacheQueue } from "./ThumbnailCacheQueue"; +import { Logger } from "winston"; + +export class Main { + logger: Logger; + + constructor() { + this.logger = getLogger(); + } + + start() { + if (this.isPrimary() && this.mustFork()) { + this.doFork(this.psCount()); + } else { + const app = express(); + app.disable("x-powered-by"); + const expressSetup = new ExpressSetup(app, this.logger); + this.doWorker(expressSetup); + } + } + + doWorker(expressSetup: ExpressSetup) { + expressSetup.sentry(); + expressSetup.morgan(); + expressSetup.routes(this.buildThumbnailApi()); + const server = expressSetup.server(this.getPort()); + expressSetup.registerHandlers(server); + expressSetup.setRequestTimeout(server); + } + + buildThumbnailApi() { + const dplaApiKey = process.env.DPLA_API_KEY; + + if (!dplaApiKey) { + throw new Error("Env variable DPLA_API_KEY not set."); + } + + const awsRegion = process.env.REGION ?? "us-east-1"; + const bucket = process.env.BUCKET ?? "dpla-thumbnails"; + const sqsUrl = + process.env.SQS_URL ?? + "https://sqs.us-east-1.amazonaws.com/283408157088/thumbp-image"; + const dplaApiUrl = process.env.DPLA_API_URL ?? "https://api.dp.la"; + + const awsOptions = { region: awsRegion }; + const s3Client = new S3Client(awsOptions); + const sqsClient = new SQSClient(awsOptions); + const dplaApi = new DplaApi(dplaApiUrl, dplaApiKey); + const thumbnailStorage = new ThumbnailStorage(s3Client, bucket); + const thumbnailCacheQueue = new ThumbnailCacheQueue(sqsUrl, sqsClient); + const responseHelper = new ResponseHelper(); + + return new ThumbnailApi( + dplaApi, + thumbnailStorage, + thumbnailCacheQueue, + responseHelper, + ); + } + + doFork(childrenCount: number): void { + cluster + .on("exit", (worker: Worker): void => { + this.logger.info(`Worker ${String(worker.process.pid)} died`); + this.logger.info("Initiating replacement worker."); + cluster.fork(); + }) + .on("online", (worker: Worker): void => { + this.logger.info(`worker ${String(worker.process.pid)} online`); + }); + for (let i = 0; i < childrenCount; i++) { + cluster.fork(); + } + } + + getPort(): number { + const portString = process.env.PORT ?? "3000"; + return Number.parseInt(portString); + } + + psCount() { + return Number(process.env.PS_COUNT) || availableParallelism(); + } + + mustFork() { + return ( + process.env.MUST_FORK === "true" || process.env.NODE_ENV === "production" + ); + } + + isPrimary() { + return cluster.isPrimary; + } +} + +if (require.main === module) { + new Main().start(); +} diff --git a/test/unit/ExpressSetup.test.ts b/test/unit/ExpressSetup.test.ts new file mode 100644 index 0000000..da63590 --- /dev/null +++ b/test/unit/ExpressSetup.test.ts @@ -0,0 +1,112 @@ +import { getLogger } from "../../src/logger"; +import { Express as MockExpress } from "jest-express/lib/express"; +import { Express } from "express"; +import { ExpressSetup } from "../../src/ExpressSetup"; +import { Server } from "node:http"; +import { ThumbnailApi } from "../../src/ThumbnailApi"; +import * as Sentry from "@sentry/node"; + +import { jest } from "@jest/globals"; + +describe("ExpressSetup", () => { + let expressSetup: ExpressSetup; + let express: MockExpress; + + beforeEach(() => { + const logger = getLogger(); + logger.configure({ silent: true }); + express = new MockExpress(); + expressSetup = new ExpressSetup(express as unknown as Express, logger); + }); + + test("morgan installs morgan middleware", () => { + expressSetup.morgan(); + expect(express.use).toHaveBeenCalled(); + }); + + test("sentry installs sentry middleware", () => { + const sentrySpy = jest.spyOn(Sentry, "setupExpressErrorHandler"); + expressSetup.sentry(); + expect(sentrySpy).toHaveBeenCalledWith(express); + }); + + test("registerHandlers registers all the right handlers.", () => { + const server = new Server(); + const mockHandleExit = jest.fn( + (reason: string, server: Server, retVal: number) => { + expect(reason).toBeDefined(); + expect(server).toBe(server); + expect(retVal).toBeDefined(); + }, + ); + expressSetup.handleExit = mockHandleExit; + expect(process.listeners("SIGINT").length).toBe(0); + expect(process.listeners("SIGQUIT").length).toBe(0); + expect(process.listeners("SIGTERM").length).toBe(0); + expect(process.listeners("uncaughtException").length).toBe(0); + expect(process.listeners("unhandledRejection").length).toBe(0); + expressSetup.registerHandlers(server); + expect(process.listeners("SIGINT").length).toBe(1); + expect(process.listeners("SIGQUIT").length).toBe(1); + expect(process.listeners("SIGTERM").length).toBe(1); + expect(process.listeners("uncaughtException").length).toBe(1); + expect(process.listeners("unhandledRejection").length).toBe(1); + + process.listeners("SIGINT")[0]("SIGINT"); + process.listeners("SIGQUIT")[0]("SIGQUIT"); + process.listeners("SIGTERM")[0]("SIGTERM"); + process.listeners("uncaughtException")[0]( + new Error("foo"), + "uncaughtException", + ); + process.listeners("unhandledRejection")[0]( + new Error("foo"), + Promise.resolve(), + ); + expect(mockHandleExit).toHaveBeenCalledTimes(5); + }); + + test("handleExit", () => { + const fakeExit = jest.fn((retVal: number) => { + expect(retVal).toBe(128); + }); + expressSetup.exit = fakeExit; + + const fakeServer = new Server(); + const fakeClose = jest.fn((callback: (err?: Error) => void) => { + callback(); + return fakeServer; + }); + fakeServer.close = fakeClose; + expressSetup.handleExit("foo", fakeServer, 128); + expect(fakeClose).toHaveBeenCalled(); + expect(fakeExit).toHaveBeenCalled(); + }); + + test("setRequestTimeout", () => { + const fakeServer = new Server(); + expressSetup.setRequestTimeout(fakeServer); + expect(fakeServer.requestTimeout).toBe(3000); + }); + + test("server", () => { + const fakeServer = new Server(); + const listen = jest.fn((port, callback: () => void) => { + expect(callback).toBeDefined(); + callback(); + expect(port).toBe(4567); + return fakeServer; + }); + express.listen = listen; + const server = expressSetup.server(4567); + expect(listen).toHaveBeenCalled(); + expect(server).toBe(fakeServer); + }); + + test("routes", () => { + const fakeThumbnailApi = {} as unknown as ThumbnailApi; + expressSetup.routes(fakeThumbnailApi); + expect(express.get).toHaveBeenCalledWith("/thumb/*", expect.anything()); + expect(express.get).toHaveBeenCalledWith("/health", expect.anything()); + }); +}); diff --git a/test/unit/index.test.ts b/test/unit/index.test.ts new file mode 100644 index 0000000..a7f8b55 --- /dev/null +++ b/test/unit/index.test.ts @@ -0,0 +1,133 @@ +import { ExpressSetup } from "../../src/ExpressSetup"; +import { Main } from "../../src/main"; +import { Server } from "node:http"; +import { ThumbnailApi } from "../../src/ThumbnailApi"; +import cluster from "node:cluster"; +import { availableParallelism } from "node:os"; + +describe("index", () => { + let main: Main; + + beforeEach(() => { + main = new Main(); + main.logger.configure({ silent: true }); + }); + + test("buildThumbnailApi dies if DPLA_API_KEY isn't set", () => { + expect(() => { + main.buildThumbnailApi(); + }).toThrow("Env variable DPLA_API_KEY not set."); + }); + + test("App runs if DPLA_API_KEY is set", () => { + process.env.DPLA_API_KEY = "12345"; + const api = main.buildThumbnailApi(); + expect(api).toBeDefined(); + }); + + test("Start forks when isPrimary", () => { + main.isPrimary = jest.fn(() => true); + main.mustFork = jest.fn(() => true); + const doFork = jest.fn(); + main.doFork = doFork; + main.start(); + expect(doFork).toHaveBeenCalled(); + }); + + test("Start builds worker when not primary", () => { + main.isPrimary = jest.fn(() => false); + const doWorker = jest.fn(); + main.doWorker = doWorker; + main.start(); + expect(doWorker).toHaveBeenCalled(); + }); + + test("doWorker calls the appropriate methods on ExpressWorker", () => { + const fakeServer = {} as unknown as Server; + const server = jest.fn((port: number) => { + expect(port).toBe(3000); + return fakeServer; + }); + const sentry = jest.fn(); + const morgan = jest.fn(); + const routes = jest.fn(); + const registerHandlers = jest.fn(); + const setRequestTimeout = jest.fn(); + const fakeBuildThumbnailApi = {} as unknown as ThumbnailApi; + const buildThumbnailApi = jest.fn(() => fakeBuildThumbnailApi); + main.buildThumbnailApi = buildThumbnailApi; + const expressSetup = { + sentry, + morgan, + server, + routes, + registerHandlers, + setRequestTimeout, + } as unknown as ExpressSetup; + + main.doWorker(expressSetup); + expect(sentry).toHaveBeenCalled(); + expect(morgan).toHaveBeenCalled(); + expect(routes).toHaveBeenCalledWith(fakeBuildThumbnailApi); + expect(buildThumbnailApi).toHaveBeenCalled(); + expect(registerHandlers).toHaveBeenCalledWith(fakeServer); + expect(setRequestTimeout).toHaveBeenCalledWith(fakeServer); + }); + + test("doFork calls cluster.fork", () => { + const mockFork = jest.fn(); + cluster.fork = mockFork; + main.doFork(3); + expect(mockFork).toHaveBeenCalledTimes(3); + }); + + test("getPort returns 3000 by default", () => { + const port = main.getPort(); + expect(port).toBe(3000); + }); + + test("getPort is configurable with PORT env variable", () => { + process.env.PORT = "4000"; + const port = main.getPort(); + expect(port).toBe(4000); + }); + + test("psCount returns avialableParallelism by default", () => { + const count = availableParallelism(); + expect(main.psCount()).toBe(count); + }); + + test("psCount is configurable with PS_COUNT env variable", () => { + process.env.PS_COUNT = "42"; + const count = main.psCount(); + expect(count).toBe(42); + }); + + test("mustFork returns false by default", () => { + const mustFork = main.mustFork(); + expect(mustFork).toBe(false); + }); + + test("mustFork is configurable with MUST_FORK", () => { + process.env.MUST_FORK = "true"; + const mustFork = main.mustFork(); + expect(mustFork).toBe(true); + process.env.MUST_FORK = "false"; + const mustFork2 = main.mustFork(); + expect(mustFork2).toBe(false); + }); + + test("mustFork is configurable with NODE_ENV", () => { + process.env.NODE_ENV = "production"; + const mustFork = main.mustFork(); + expect(mustFork).toBe(true); + process.env.NODE_ENV = "not-production"; + const mustFork2 = main.mustFork(); + expect(mustFork2).toBe(false); + }); + + test("isPrimary returns true if this is the main process", () => { + const isPrimary = main.isPrimary(); + expect(isPrimary).toBe(true); + }); +});