diff --git a/CountItems/CountManager.js b/CountItems/CountManager.js index f1f17130..3871dc89 100644 --- a/CountItems/CountManager.js +++ b/CountItems/CountManager.js @@ -2,6 +2,7 @@ const async = require('async'); const { once } = require('arsenal').jsutil; const { validStorageMetricLevels } = require('./utils/constants'); const { consolidateDataMetrics } = require('./utils/utils'); +const monitoring = require('../utils/monitoring'); class CountManager { constructor(params) { @@ -35,6 +36,7 @@ class CountManager { return done(new Error('emptyWorkerList')); } const id = this.workerList.shift(); + const processingStartTime = process.hrtime.bigint(); return this.workers[id].count(bucketInfo, (err, res) => { this.log.info('processing a bucket', { method: 'CountManager::_setupQueue', @@ -44,6 +46,8 @@ class CountManager { if (err) { return done(err); } + const processingDuration = Number(process.hrtime.bigint() - processingStartTime) / 1e9; + monitoring.bucketProcessingDuration.observe(processingDuration); this._consolidateData(res); this.workerList.push(id); return done(); @@ -53,6 +57,7 @@ class CountManager { } _consolidateData(results) { + const startTime = process.hrtime.bigint(); if (!results) { return; } @@ -111,6 +116,8 @@ class CountManager { } else { this.dataMetrics = results.dataMetrics; } + const consolidationDurationInS = Number(process.hrtime.bigint() - startTime) / 1e9; + monitoring.consolidationDuration.observe(consolidationDurationInS); } setup(callback) { diff --git a/CountItems/CountMaster.js b/CountItems/CountMaster.js index 2ccefbe0..875a5832 100644 --- a/CountItems/CountMaster.js +++ b/CountItems/CountMaster.js @@ -58,7 +58,7 @@ class CountMaster { }); return this.stop(null, () => callback(err)); } - return this.stop(null, () => callback()); + return callback(); }); } } diff --git a/CountItems/CountWorker.js b/CountItems/CountWorker.js index 41fc9ec0..b3093ff4 100644 --- a/CountItems/CountWorker.js +++ b/CountItems/CountWorker.js @@ -1,6 +1,7 @@ const assert = require('assert'); const async = require('async'); const { BucketInfo } = require('arsenal').models; +const monitoring = require('../utils/monitoring'); class CountWorker { constructor(params) { @@ -35,7 +36,10 @@ class CountWorker { return async.waterfall([ next => this.client._getIsTransient(bucketInfo, this.log, next), (isTransient, next) => this.client.getObjectMDStats(bucketName, bucketInfo, isTransient, this.log, next), - ], callback); + ], (err, results) => { + monitoring.bucketsCount.inc({ status: err ? 'error' : 'success' }); + callback(err, results); + }); } clientTeardown(callback) { diff --git a/CountItems/masterProcess.js b/CountItems/masterProcess.js index 35888508..0c9f824d 100644 --- a/CountItems/masterProcess.js +++ b/CountItems/masterProcess.js @@ -1,4 +1,5 @@ const werelogs = require('werelogs'); +const { network } = require('arsenal'); const { reshapeExceptionError } = require('arsenal').errorUtils; const S3UtilsMongoClient = require('../utils/S3UtilsMongoClient'); @@ -7,6 +8,9 @@ const CountManager = require('./CountManager'); const createMongoParams = require('../utils/createMongoParams'); const createWorkers = require('./utils/createWorkers'); +const WebServer = network.http.server; +const monitoring = require('../utils/monitoring'); + const logLevel = Number.parseInt(process.env.DEBUG, 10) === 1 ? 'debug' : 'info'; @@ -15,9 +19,20 @@ const loggerConfig = { dump: 'error', }; +let waitingForPromScraping = false; + werelogs.configure(loggerConfig); const log = new werelogs.Logger('S3Utils::CountItems::Master'); +function tryParseInt(s, defaultValue) { + const v = Number.parseInt(s, 10); + return v > 0 ? v : defaultValue; +} + +const prometheusPollingPeriod = tryParseInt(process.env.PROMETHEUS_POLLING_PERIOD, 30); + +const prometheusPollingAttempts = tryParseInt(process.env.PROMETHEUS_POLLING_ATTEMPTS, 5); + const numWorkers = process.env.NUM_WORKERS && !Number.isNaN(process.env.NUM_WORKERS) ? Number.parseInt(process.env.NUM_WORKERS, 10) : 4; @@ -37,6 +52,17 @@ const countMaster = new CountMaster({ client: new S3UtilsMongoClient(createMongoParams(log)), }); +const metricServer = new WebServer(8003, log).onRequest((req, res) => monitoring.metricsHandler( + () => { + if (waitingForPromScraping === true) { + countMaster.stop(null, () => process.exit(1)); + } + }, + req, + res, +)); +metricServer.start(); + const handleSignal = sig => countMaster.stop(sig, () => process.exit(0)); process.on('SIGINT', handleSignal); process.on('SIGHUP', handleSignal); @@ -53,5 +79,8 @@ countMaster.start(err => { if (err) { process.exit(1); } - process.exit(0); + waitingForPromScraping = true; + setTimeout(() => { + countMaster.stop(null, () => process.exit(0)); + }, prometheusPollingAttempts * prometheusPollingPeriod * 1000 * 4); }); diff --git a/package.json b/package.json index 908064a6..5e92136b 100644 --- a/package.json +++ b/package.json @@ -1,6 +1,6 @@ { "name": "s3utils", - "version": "1.14.6", + "version": "1.14.7", "engines": { "node": ">= 16" }, @@ -57,6 +57,7 @@ "eslint-plugin-import": "^2.20.1", "eslint-plugin-jest": "^23.6.0", "jest": "^23.6.0", - "mongodb-memory-server": "^8.10.2" + "mongodb-memory-server": "^8.10.2", + "sinon": "^17.0.1" } } diff --git a/tests/functional/countItems.js b/tests/functional/countItems.js index cbb01726..81c0d6e9 100644 --- a/tests/functional/countItems.js +++ b/tests/functional/countItems.js @@ -3,8 +3,8 @@ const async = require('async'); const werelogs = require('werelogs'); const { BucketInfo, ObjectMD } = require('arsenal').models; const { constants } = require('arsenal'); +const sinon = require('sinon'); const S3UtilsMongoClient = require('../../utils/S3UtilsMongoClient'); - const CountMaster = require('../../CountItems/CountMaster'); const CountManager = require('../../CountItems/CountManager'); const createMongoParams = require('../../utils/createMongoParams'); @@ -190,6 +190,7 @@ jest.setTimeout(120000); describe('CountItems', () => { const oldEnv = process.env; let client; + let setTimeoutSpy; beforeAll(done => { process.env = oldEnv; @@ -209,9 +210,12 @@ describe('CountItems', () => { next => client.setup(next), next => populateMongo(client, next), ], done); + setTimeoutSpy = jest.spyOn(global, 'setTimeout'); + setTimeoutSpy.mockImplementation((callback, delay) => callback()); }); afterAll(done => { + setTimeoutSpy.mockRestore(); async.series([ next => client.db.dropDatabase().then(() => next()).catch(() => next()), next => client.close(next), diff --git a/utils/S3UtilsMongoClient.js b/utils/S3UtilsMongoClient.js index 6d669aa7..ab7b3689 100644 --- a/utils/S3UtilsMongoClient.js +++ b/utils/S3UtilsMongoClient.js @@ -5,6 +5,7 @@ const { errors, constants } = require('arsenal'); const async = require('async'); const { validStorageMetricLevels } = require('../CountItems/utils/constants'); const getLocationConfig = require('./locationConfig'); +const monitoring = require('./monitoring'); const METASTORE = '__metastore'; const INFOSTORE = '__infostore'; @@ -150,6 +151,7 @@ class S3UtilsMongoClient extends MongoClientInterface { entry: res, error, }); + monitoring.objectsCount.inc({ status: 'error' }); return; } @@ -159,6 +161,7 @@ class S3UtilsMongoClient extends MongoClientInterface { method: 'getObjectMDStats', entry: res, }); + monitoring.objectsCount.inc({ status: 'skipped' }); return; } @@ -231,6 +234,7 @@ class S3UtilsMongoClient extends MongoClientInterface { collRes.account[account].locations[location].deleteMarkerCount += res.value.isDeleteMarker ? 1 : 0; }); }); + monitoring.objectsCount.inc({ status: 'success' }); processed++; }, err => { diff --git a/utils/monitoring.js b/utils/monitoring.js new file mode 100644 index 00000000..be086635 --- /dev/null +++ b/utils/monitoring.js @@ -0,0 +1,88 @@ +const { errors } = require('arsenal'); +const promClient = require('prom-client'); +const { Registry } = require('prom-client'); +const { http } = require('httpagent'); +const CountMaster = require('../CountItems/CountMaster'); + +const aggregatorRegistry = new promClient.AggregatorRegistry(); +const { collectDefaultMetrics } = promClient; + + +// Histogram of the bucket processing duration, by the utilization service. +const bucketProcessingDuration = new promClient.Histogram({ + name: 's3_countitems_bucket_listing_duration_seconds', + help: 'Bucket processing duration', + buckets: [1, 10, 60, 600, 3600, 18000, 36000], +}); + +const consolidationDuration = new promClient.Histogram({ + name: 's3_countitems_bucket_merge_duration_seconds', + help: 'Duration of metrics consolidation in seconds', + buckets: [0.01, 0.05, 0.1, 0.2, 0.5, 1, 2, 5, 10], +}); + +const bucketsCount = new promClient.Counter({ + name: 's3_countitems_total_buckets_count', + help: 'Total number of buckets processed', + labelNames: ['status'], +}); + +const objectsCount = new promClient.Counter({ + name: 's3_countitems_total_objects_count', + help: 'Total number of objects processed', + labelNames: ['status'], +}); + +/** + * @param {http.ServerResponse} res - http response object + * @param {Error | errors.ArsenalError} error - Error + * @return {void} + */ +function _writeResponse(res, error) { + let statusCode = 500; + if (error instanceof errors.ArsenalError && Number.isInteger(error.code)) { + statusCode = error.code; + } + res.writeHead(statusCode, { 'Content-Type': 'application/json' }); + res.end(); +} + +/** + * @param {function} onScraped - callback to call when metrics are scraped + * @param {http.IncomingMessage} req - http request object + * @param {http.ServerResponse} res - http response object + * @return {void} + */ +async function metricsHandler(onScraped, req, res) { + if (req.method !== 'GET' || req.url !== '/metrics') { + return _writeResponse(res, errors.MethodNotAllowed); + } + try { + const [registerMetrics, clusterMetrics] = await Promise.all([ + promClient.register.metrics(), + aggregatorRegistry.clusterMetrics(), + ]); + const promMetrics = `${registerMetrics}\n${clusterMetrics}`; + const contentLen = Buffer.byteLength(promMetrics, 'utf8'); + return res.writeHead(200, { + 'content-length': contentLen, + 'content-type': promClient.register.contentType, + }).end(promMetrics); + } catch (ex) { + return _writeResponse(res, ex); + } finally { + if (onScraped) { + onScraped(); + } + } +} + +module.exports = { + client: promClient, + collectDefaultMetrics, + metricsHandler, + bucketProcessingDuration, + consolidationDuration, + bucketsCount, + objectsCount, +}; diff --git a/yarn.lock b/yarn.lock index bfd9536c..eb0bc56b 100644 --- a/yarn.lock +++ b/yarn.lock @@ -1037,6 +1037,27 @@ dependencies: type-detect "4.0.8" +"@sinonjs/commons@^2.0.0": + version "2.0.0" + resolved "https://registry.yarnpkg.com/@sinonjs/commons/-/commons-2.0.0.tgz#fd4ca5b063554307e8327b4564bd56d3b73924a3" + integrity sha512-uLa0j859mMrg2slwQYdO/AkrOfmH+X6LTVmNTS9CqexuE2IvVORIkSpJLqePAbEnKJ77aMmCwr1NUZ57120Xcg== + dependencies: + type-detect "4.0.8" + +"@sinonjs/commons@^3.0.0": + version "3.0.1" + resolved "https://registry.yarnpkg.com/@sinonjs/commons/-/commons-3.0.1.tgz#1029357e44ca901a615585f6d27738dbc89084cd" + integrity sha512-K3mCHKQ9sVh8o1C9cxkwxaOmXoAMlDxC1mYyHrjqOWEcBjYr76t96zL2zlj5dUGZ3HSw240X1qgH3Mjf1yJWpQ== + dependencies: + type-detect "4.0.8" + +"@sinonjs/fake-timers@^11.2.2": + version "11.2.2" + resolved "https://registry.yarnpkg.com/@sinonjs/fake-timers/-/fake-timers-11.2.2.tgz#50063cc3574f4a27bd8453180a04171c85cc9699" + integrity sha512-G2piCSxQ7oWOxwGSAyFHfPIsyeJGXYtc6mFbnFA+kRXkiEnTl8c/8jul2S329iFBnDI9HGoeWWAZvuvOkZccgw== + dependencies: + "@sinonjs/commons" "^3.0.0" + "@sinonjs/fake-timers@^9.1.2": version "9.1.2" resolved "https://registry.yarnpkg.com/@sinonjs/fake-timers/-/fake-timers-9.1.2.tgz#4eaab737fab77332ab132d396a3c0d364bd0ea8c" @@ -1044,6 +1065,20 @@ dependencies: "@sinonjs/commons" "^1.7.0" +"@sinonjs/samsam@^8.0.0": + version "8.0.0" + resolved "https://registry.yarnpkg.com/@sinonjs/samsam/-/samsam-8.0.0.tgz#0d488c91efb3fa1442e26abea81759dfc8b5ac60" + integrity sha512-Bp8KUVlLp8ibJZrnvq2foVhP0IVX2CIprMJPK0vqGqgrDa0OHVKeZyBykqskkrdxV6yKBPmGasO8LVjAKR3Gew== + dependencies: + "@sinonjs/commons" "^2.0.0" + lodash.get "^4.4.2" + type-detect "^4.0.8" + +"@sinonjs/text-encoding@^0.7.2": + version "0.7.2" + resolved "https://registry.yarnpkg.com/@sinonjs/text-encoding/-/text-encoding-0.7.2.tgz#5981a8db18b56ba38ef0efb7d995b12aa7b51918" + integrity sha512-sXXKG+uL9IrKqViTtao2Ws6dy0znu9sOaP1di/jKGW1M6VssO8vlpXCQcpZ+jisQ1tTFAC5Jo/EOzFbggBagFQ== + "@socket.io/component-emitter@~3.1.0": version "3.1.0" resolved "https://registry.yarnpkg.com/@socket.io/component-emitter/-/component-emitter-3.1.0.tgz#96116f2a912e0c02817345b3c10751069920d553" @@ -2745,6 +2780,11 @@ diff@^3.2.0: resolved "https://registry.yarnpkg.com/diff/-/diff-3.5.0.tgz#800c0dd1e0a8bfbc95835c202ad220fe317e5a12" integrity sha512-A46qtFgd+g7pDZinpnwiRJtxbC1hpgf0uzP3iG89scHk0AUC7A1TGxf5OiiOUv/JMZR8GOt8hL900hV0bOy5xA== +diff@^5.1.0: + version "5.2.0" + resolved "https://registry.yarnpkg.com/diff/-/diff-5.2.0.tgz#26ded047cd1179b78b9537d5ef725503ce1ae531" + integrity sha512-uIFDxqpRZGZ6ThOk84hEfqWoHx2devRFvpTZcTHur85vImfaxUbTW9Ryh4CpCuDnToOP1CEtXKIgytHBPVff5A== + diskusage@^1.1.1: version "1.1.3" resolved "https://registry.yarnpkg.com/diskusage/-/diskusage-1.1.3.tgz#680d7dbf1b679168a195c9240eb3552cbd2c067b" @@ -5209,6 +5249,11 @@ jsprim@1.4.2, jsprim@^1.2.2: json-schema "0.4.0" verror "1.10.0" +just-extend@^6.2.0: + version "6.2.0" + resolved "https://registry.yarnpkg.com/just-extend/-/just-extend-6.2.0.tgz#b816abfb3d67ee860482e7401564672558163947" + integrity sha512-cYofQu2Xpom82S6qD778jBDpwvvy39s1l/hrYij2u9AMdQcGRpaBu6kY4mVhuno5kJVi1DAz4aiphA2WI1/OAw== + jwa@^1.4.1: version "1.4.1" resolved "https://registry.yarnpkg.com/jwa/-/jwa-1.4.1.tgz#743c32985cb9e98655530d53641b66c8645b039a" @@ -5552,6 +5597,11 @@ lodash.flatten@^4.4.0: resolved "https://registry.yarnpkg.com/lodash.flatten/-/lodash.flatten-4.4.0.tgz#f31c22225a9632d2bbf8e4addbef240aa765a61f" integrity sha1-8xwiIlqWMtK7+OSt2+8kCqdlph8= +lodash.get@^4.4.2: + version "4.4.2" + resolved "https://registry.yarnpkg.com/lodash.get/-/lodash.get-4.4.2.tgz#2d177f652fa31e939b4438d5341499dfa3825e99" + integrity sha512-z+Uw/vLuy6gQe8cfaFWD7p0wVv8fJl3mbzXh33RS+0oW2wvUqiRXiQ69gLWSLpgB5/6sU+r6BlQR0MBILadqTQ== + lodash.includes@^4.3.0: version "4.3.0" resolved "https://registry.yarnpkg.com/lodash.includes/-/lodash.includes-4.3.0.tgz#60bb98a87cb923c68ca1e51325483314849f553f" @@ -6195,6 +6245,17 @@ new-find-package-json@^2.0.0: dependencies: debug "^4.3.4" +nise@^5.1.5: + version "5.1.9" + resolved "https://registry.yarnpkg.com/nise/-/nise-5.1.9.tgz#0cb73b5e4499d738231a473cd89bd8afbb618139" + integrity sha512-qOnoujW4SV6e40dYxJOb3uvuoPHtmLzIk4TFo+j0jPJoC+5Z9xja5qH5JZobEPsa8+YYphMrOSwnrshEhG2qww== + dependencies: + "@sinonjs/commons" "^3.0.0" + "@sinonjs/fake-timers" "^11.2.2" + "@sinonjs/text-encoding" "^0.7.2" + just-extend "^6.2.0" + path-to-regexp "^6.2.1" + node-fetch@^2.6.7: version "2.6.7" resolved "https://registry.yarnpkg.com/node-fetch/-/node-fetch-2.6.7.tgz#24de9fba827e3b4ae44dc8b20256a379160052ad" @@ -6705,6 +6766,11 @@ path-to-regexp@0.1.7: resolved "https://registry.yarnpkg.com/path-to-regexp/-/path-to-regexp-0.1.7.tgz#df604178005f522f15eb4490e7247a1bfaa67f8c" integrity sha512-5DFkuoqlv1uYQKxy8omFBeJPQcdoE07Kv2sferDCrAq1ohOU+MSDswDIbnx3YAM60qIOnYa53wBhXW0EbMonrQ== +path-to-regexp@^6.2.1: + version "6.2.2" + resolved "https://registry.yarnpkg.com/path-to-regexp/-/path-to-regexp-6.2.2.tgz#324377a83e5049cbecadc5554d6a63a9a4866b36" + integrity sha512-GQX3SSMokngb36+whdpRXE+3f9V8UzyAorlYvOGx87ufGHehNTn5lCxrKtLyZ4Yl/wEKnNnr98ZzOwwDZV5ogw== + path-type@^1.0.0: version "1.1.0" resolved "https://registry.yarnpkg.com/path-type/-/path-type-1.1.0.tgz#59c44f7ee491da704da415da5a4070ba4f8fe441" @@ -7514,6 +7580,18 @@ simple-glob@^0.2.0: lodash.flatten "^4.4.0" lodash.union "^4.6.0" +sinon@^17.0.1: + version "17.0.1" + resolved "https://registry.yarnpkg.com/sinon/-/sinon-17.0.1.tgz#26b8ef719261bf8df43f925924cccc96748e407a" + integrity sha512-wmwE19Lie0MLT+ZYNpDymasPHUKTaZHUH/pKEubRXIzySv9Atnlw+BUMGCzWgV7b7wO+Hw6f1TEOr0IUnmU8/g== + dependencies: + "@sinonjs/commons" "^3.0.0" + "@sinonjs/fake-timers" "^11.2.2" + "@sinonjs/samsam" "^8.0.0" + diff "^5.1.0" + nise "^5.1.5" + supports-color "^7.2.0" + sisteransi@^0.1.1: version "0.1.1" resolved "https://registry.yarnpkg.com/sisteransi/-/sisteransi-0.1.1.tgz#5431447d5f7d1675aac667ccd0b865a4994cb3ce" @@ -7983,7 +8061,7 @@ supports-color@^5.3.0: dependencies: has-flag "^3.0.0" -supports-color@^7.1.0: +supports-color@^7.1.0, supports-color@^7.2.0: version "7.2.0" resolved "https://registry.yarnpkg.com/supports-color/-/supports-color-7.2.0.tgz#1b7dcdcb32b8138801b3e478ba6a51caa89648da" integrity sha512-qpCAvRl9stuOHveKsn7HncJRvv501qIacKzQlO/+Lwxc9+0q2wLyv4Dfvt80/DPn2pqOBsJdDiogXGR9+OvwRw== @@ -8241,7 +8319,7 @@ type-check@~0.3.2: dependencies: prelude-ls "~1.1.2" -type-detect@4.0.8: +type-detect@4.0.8, type-detect@^4.0.8: version "4.0.8" resolved "https://registry.yarnpkg.com/type-detect/-/type-detect-4.0.8.tgz#7646fb5f18871cfbb7749e69bd39a6388eb7450c" integrity sha512-0fr/mIH1dlO+x7TlcMy+bIDqKPsw/70tVyeHW787goQjhmqaZe10uwLujubK9q9Lg6Fiho1KUKDYz0Z7k7g5/g==