From 465ab9aeb3b8412ab9ec907888ba09a10b155247 Mon Sep 17 00:00:00 2001 From: Danielv123 Date: Sun, 4 Mar 2018 20:00:55 +0100 Subject: [PATCH] master Added performance and usage logging for prometheus --- master.js | 103 ++++++++++++++++++++++++++++++++++++++++++++++----- package.json | 1 + 2 files changed, 95 insertions(+), 9 deletions(-) diff --git a/master.js b/master.js index e58cb344..524533ed 100644 --- a/master.js +++ b/master.js @@ -63,6 +63,44 @@ app.use(express.static('static')); // mod downloads app.use(express.static(masterModFolder)); +// set up logging software +const prometheusPrefix = "clusterio_"; +const Prometheus = require('prom-client'); +Prometheus.collectDefaultMetrics({ timeout: 10000 }); // collects RAM usage etc every 10 s +const httpRequestDurationMilliseconds = new Prometheus.Histogram({ + name: prometheusPrefix+'http_request_duration_ms', + help: 'Duration of HTTP requests in ms', + labelNames: ['route'], + // buckets for response time from 0.1ms to 500ms + buckets: [0.10, 5, 15, 50, 100, 200, 300, 400, 500] +}); +const endpointHitCounter = new Prometheus.Gauge({ + name: prometheusPrefix+'endpoint_hit_gauge', + help: "How many requests a particular endpoint has gotten", + labelNames: ['route'], +}); +const prometheusConnectedInstancesCounter = new Prometheus.Gauge({ + name: prometheusPrefix+'connected_instaces_gauge', + help: "How many instances are currently connected to this master server", +}); +setInterval(()=>{ + let numberOfActiveSlaves = 0; + for(let instance in slaves){ + if(Date.now() - Number(slaves[instance].time) < 1000 * 30) numberOfActiveSlaves++; + } + prometheusConnectedInstancesCounter.set(numberOfActiveSlaves); +},10000); +/** +Prometheus metrics endpoint. Returns performance and usage metrics in a prometheus readable format. +*/ +app.get('/metrics', (req, res) => { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); + res.set('Content-Type', Prometheus.register.contentType); + res.end(Prometheus.register.metrics()); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); +}); + // set up database var Datastore = require('nedb'); db = {}; @@ -145,6 +183,8 @@ process.on('SIGINT', function () { // world ID management // slaves post here to tell the server they exist app.post("/api/getID", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); // request.body should be an object // {rconPort, rconPassword, serverPort, mac, time} // time us a unix timestamp we can use to check for how long the server has been unresponsive @@ -163,9 +203,12 @@ app.post("/api/getID", function(req,res) { } console.log("Slave registered: " + slaves[req.body.unique].mac + " : " + slaves[req.body.unique].serverPort+" at " + slaves[req.body.unique].publicIP + " with name " + slaves[req.body.unique].instanceName); } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); app.post("/api/editSlaveMeta", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); // request.body should be an object // {instanceID, pass, meta:{x,y,z}} @@ -181,10 +224,13 @@ app.post("/api/editSlaveMeta", function(req,res) { res.send("ERROR: Invalid instanceID or password") } } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); // mod management // should handle uploading and checking if mods are uploaded app.post("/api/checkMod", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); let files = fs.readdirSync(masterModFolder); let found = false; files.forEach(file => { @@ -199,25 +245,31 @@ app.post("/api/checkMod", function(req,res) { res.send("found"); } res.end(); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); app.post("/api/uploadMod", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); if (!req.files) { res.send('No files were uploaded.'); return; } else { console.log(req.files.file); req.files.file.mv('./database/masterMods/'+req.files.file.name, function(err) { - if (err) { - res.status(500).send(err); - } else { - res.send('File uploaded!'); - console.log("Uploaded mod: " + req.files.file.name); - } - }); + if (err) { + res.status(500).send(err); + } else { + res.send('File uploaded!'); + console.log("Uploaded mod: " + req.files.file.name); + } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); + }); } }); // endpoint for getting information about all our slaves app.get("/api/slaves", function(req, res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); res.header("Access-Control-Allow-Origin", "*"); res.header("Access-Control-Allow-Headers", "Origin, X-Requested-With, Content-Type, Accept"); let copyOfSlaves = JSON.parse(JSON.stringify(slaves)); @@ -226,6 +278,7 @@ app.get("/api/slaves", function(req, res) { copyOfSlaves[key].rconPassword = "hidden"; } res.send(copyOfSlaves); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); var recievedItemStatisticsBySlaveID = {}; var sentItemStatisticsBySlaveID = {}; @@ -247,6 +300,8 @@ POST endpoint for storing items in master's inventory. @returns {string} status either "success" or "failure" */ app.post("/api/place", function(req, res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); res.header("Access-Control-Allow-Origin", "*"); res.header("Access-Control-Allow-Headers", "Origin, X-Requested-With, Content-Type, Accept"); let x; @@ -297,6 +352,7 @@ app.post("/api/place", function(req, res) { } else { res.send("failure"); } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); /** POST endpoint to remove items from DB when client orders items. @@ -311,6 +367,8 @@ POST endpoint to remove items from DB when client orders items. */ _doleDivisionFactor = {}; //If the server regularly can't fulfill requests, this number grows until it can. Then it slowly shrinks back down. app.post("/api/remove", function(req, res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); const doleDivisionRetardation = 10; //lower rates will equal more dramatic swings const maxDoleDivision = 250; //a higher cap will divide the store more ways, but will take longer to recover as supplies increase res.header("Access-Control-Allow-Origin", "*"); @@ -361,10 +419,12 @@ app.post("/api/remove", function(req, res) { sentItemStatisticsBySlaveID[object.instanceID] = sentItemStatistics; } res.send({count: object.count, name: object.name}); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); } else { // if we didn't have enough, attempt giving out a smaller amount next time _doleDivisionFactor[object.name] = Math.min(maxDoleDivision, Math.max((_doleDivisionFactor[object.name]||0)||1, 1) * 2); res.send({name:object.name, count:0}); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); //console.log('failure out of ' + object.name + " | " + object.count + " from " + object.instanceID + " ("+object.instanceName+")"); } } @@ -382,8 +442,11 @@ Gives no response @param {number} circuitFrame.time */ app.post("/api/setSignal", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); if(typeof req.body == "object" && req.body.time){ db.signals.insert(req.body); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); // console.log("signal set"); } }); @@ -396,12 +459,15 @@ POST endpoint to read database of circuit signals sent to master @returns {object} circuitFrame */ app.post("/api/readSignal", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); // request.body should be an object // {since:UNIXTIMESTAMP,} // we should send an array of all signals since then db.signals.find({time:{$gte: req.body.since}}, function (err, docs) { // $gte means greater than or equal to, meaning we only get entries newer than the timestamp res.send(docs); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); // console.log(docs); }); }); @@ -415,6 +481,8 @@ GET endpoint to read the masters current inventory of items. */ // endpoint for getting an inventory of what we got app.get("/api/inventory", function(req, res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); res.header("Access-Control-Allow-Origin", "*"); res.header("Access-Control-Allow-Headers", "Origin, X-Requested-With, Content-Type, Accept"); // Check it and send it @@ -425,6 +493,7 @@ app.get("/api/inventory", function(req, res) { } } res.send(JSON.stringify(inventory)); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); /** GET endpoint to read the masters inventory as an object with key:value pairs @@ -435,10 +504,13 @@ GET endpoint to read the masters inventory as an object with key:value pairs @returns {object} JSON {"iron-plate":100, "copper-plate":5} */ app.get("/api/inventoryAsObject", function(req, res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); res.header("Access-Control-Allow-Origin", "*"); res.header("Access-Control-Allow-Headers", "Origin, X-Requested-With, Content-Type, Accept"); // Check it and send it res.send(JSON.stringify(db.items)); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); // post flowstats here for production graphs @@ -455,6 +527,8 @@ course the timeSeries data. @returns {string} failure */ app.post("/api/logStats", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); if(typeof req.body == "object" && req.body.instanceID && req.body.timestamp && req.body.data) { if(Number(req.body.timestamp) != NaN){ req.body.timestamp = Number(req.body.timestamp); @@ -471,6 +545,7 @@ app.post("/api/logStats", function(req,res) { } else { res.send("failure"); } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); // {instanceID: string, fromTime: Date, toTime, Date} /** @@ -484,6 +559,8 @@ graphs and other IO statistics. @returns {object} - with statistics */ app.post("/api/getStats", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); if(typeof req.body == "string"){ req.body = JSON.parse(req.body); } @@ -542,6 +619,7 @@ app.post("/api/getStats", function(req,res) { } } } + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); /** @@ -557,6 +635,8 @@ making up about 92% of the response body weight.) @returns {object[]} timeseries where each entry is a set point in time. */ app.post("/api/getTimelineStats", function(req,res) { + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); console.log(req.body); if(typeof req.body == "object" && req.body.instanceID) { // if not specified, get stats for last 24 hours @@ -595,6 +675,7 @@ app.post("/api/getTimelineStats", function(req,res) { }); res.send(docs); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); }); } }); @@ -607,9 +688,13 @@ GET endpoint. Returns factorio's base locale as a JSON object. @returns {object{}} 2 deep nested object with base game factorio locale as key:value pairs */ app.get("/api/getFactorioLocale", function(req,res){ - getFactorioLocale.asObject(config.factorioDirectory, "en", (err, factorioLocale) => res.send(factorioLocale)); + endpointHitCounter.labels(req.route.path).inc(); + let reqStartTime = Date.now(); + getFactorioLocale.asObject(config.factorioDirectory, "en", (err, factorioLocale) => { + res.send(factorioLocale); + httpRequestDurationMilliseconds.labels(req.route.path).observe(Date.now()-reqStartTime); + }); }); - var server = require("http").Server(app); server.listen(config.masterPort || 8080, function () { console.log("Listening on port %s...", server.address().port); diff --git a/package.json b/package.json index 3e189c73..11e9347c 100644 --- a/package.json +++ b/package.json @@ -43,6 +43,7 @@ "needle": "^1.1.0", "node-factorio-api": "^0.2.2", "node-forge": "^0.7.1", + "prom-client": "^10.2.3", "request": "^2.83.0", "right-pad": "^1.0.1", "rmdir-sync": "^1.0.1",