restify/bin/report-latency

#!/usr/bin/env node
// -*- mode: js -*-

var fs = require('fs');
var path = require('path');
var spawn = require('child_process').spawn;
var readline = require('readline');
var sprintf = require('util').format;

var nopt = require('nopt');


///--- Globals

var BUCKETS = {};
var REQUEST_IDS = {};

var OPTS = {
    'average': Boolean,
    'help': Boolean,
    'end': Date,
    'max-latency': Number,
    'max-requests': Number,
    'output': String,
    'percentile': [Number, Array],
    'period': Number,
    'requests': Boolean,
    'start': Date
};

var SHORT_OPTS = {
    'a': ['--average'],
    'h': ['--help'],
    'i': ['--period'],
    'e': ['--end'],
    'l': ['--max-latency'],
    'n': ['--max-requests'],
    'o': ['--output'],
    'p': ['--percentile'],
    'r': ['--requests'],
    's': ['--start']
};


///--- Functions

function percentile(p, vals) {
    p = parseInt(p, 10);
    return vals[(Math.round(((p / 100) * vals.length) + 1 / 2) - 1)].latency;
}


function report(buckets, output) {
    Object.keys(buckets).sort(function (a, b) {
        return parseInt(a, 10) - parseInt(b, 10);
    }).forEach(function (k) {
            var avg = 0;
            var perc = [];
            var req = buckets[k].length;
            var sum = 0;
            var t = Math.round(buckets[k]._time);

            buckets[k] = buckets[k].sort(function (a, b) {
                return a.latency - b.latency;
            });

            buckets[k].forEach(function (v) {
                sum += v.latency;
            });

            if (sum > 0 && req > 0) {
                if (output.average)
                    output.average.push([t, Math.round(sum / req)]);
                if (output.requests)
                    output.requests.push([t, buckets[k].length]);
                Object.keys(output.percentile).forEach(function (p) {
                    var _p = percentile(p, buckets[k]);
                    output.percentile[p].push([t, _p]);
                });
            }
        });

    return output;
}


function usage(code, message) {
    var str = '';
    Object.keys(SHORT_OPTS).forEach(function (k) {
        if (!Array.isArray(SHORT_OPTS[k]))
            return;

        var opt = SHORT_OPTS[k][0].replace('--', '');
        var type = OPTS[opt].name || 'string';
        if (type && type === 'boolean')
            type = '';
        type = type.toLowerCase();

        str += ' [--' + opt + ' ' + type + ']';
    });
    str += ' [file ...]';

    if (message)
        console.error(message);

    console.error('usage: ' + path.basename(process.argv[1]) + str);
    process.exit(code);
}


///--- Mainline

var parsed;

try {
    parsed = nopt(OPTS, SHORT_OPTS, process.argv, 2);
} catch (e) {
    usage(1, e.toString());
}

if (parsed.help)
    usage(0);
if (!parsed.average && !parsed.percentile)
    usage(1, '--average or --percentile required');
if (parsed.argv.remain.length < 1)
    usage(1, 'log file required');

var config = {
    average: parsed.average || false,
    maxLatency: parsed['max-latency'] || 1000,
    maxRequests: parsed['max-requests'] || 10000,
    percentile: parsed.percentile || [],
    period: parsed.period || 60,
    requests: parsed.requests || false,
    start: parsed.start ? (parsed.start.getTime() / 1000) : 0,
    end: parsed.end ? (parsed.end.getTime() / 1000) : Number.MAX_VALUE
};

var buckets = {};

var done = 0;
parsed.argv.remain.forEach(function (f) {
    var stream = readline.createInterface({
        input: fs.createReadStream(f),
        output: null
    })
    stream.on('line', function (l) {
        var record;
        var t = -1;

        try {
            record = JSON.parse(l);
        } catch (e) {
        }

        if (!record)
            return;

        var t = -1;
        if (record.time)
            t = (new Date(record.time).getTime() / 1000);

        if (record._audit !== true ||
            REQUEST_IDS[record.req_id] ||
            t < config.start ||
            t > config.end) {

            console.error('Skipping %s', l);
        }

        REQUEST_IDS[record.req_id] = true;
        record.time = t;

        var b = Math.round(record.time / config.period) + '';
        if (!buckets[b])
            buckets[b] = [];

        buckets[b].push(record);
        buckets[b]._time = record.time // good enough
    });

    stream.on('end', function () {
        if (++done === parsed.argv.remain.length) {
            console.error('Generating report...');

            var output = {
                average: config.average ? [] : false,
                requests: config.requests ? [] : false,
                percentile: {}
            };
            config.percentile.forEach(function (p) {
                output.percentile[p] = [];
            });

            output = report(buckets, output);
            var finalOutput = [];
            if (output.average) {
                finalOutput.push({
                    name: 'avg',
                    values: output.average
                });
            }
            if (output.requests) {
                finalOutput.push({
                    name: 'n',
                    values: output.requests
                });
            }
            Object.keys(output.percentile).forEach(function (k) {
                finalOutput.push({
                    name: 'p' + k,
                    values: output.percentile[k]
                });
            });

            console.log(JSON.stringify(finalOutput));
        }
    });
});