perftest/jscrund.js (663 lines of code) (raw):

/* Copyright (c) 2013, Oracle and/or its affiliates. All rights reserved. This program is free software; you can redistribute it and/or modify it under the terms of the GNU General Public License as published by the Free Software Foundation; version 2 of the License. This program is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License for more details. You should have received a copy of the GNU General Public License along with this program; if not, write to the Free Software Foundation, Inc., 51 Franklin St, Fifth Floor, Boston, MA 02110-1301 USA */ 'use strict'; /*global JSCRUND */ global.JSCRUND = {}; // Modules: JSCRUND.mynode = require("database-jones"); JSCRUND.unified_debug = require("unified_debug"); JSCRUND.udebug = JSCRUND.unified_debug.getLogger("jscrund.js"); JSCRUND.stats = require(JSCRUND.mynode.api.stats); // Backends: JSCRUND.mysqljs = require('./jscrund_mysqljs'); JSCRUND.errors = []; var DEBUG, DETAIL; var path = require("path"), fs = require("fs"); // webkit-devtools-agent allows you to profile the process from a Chrome browser try { require('webkit-devtools-agent'); } catch(e) { }; function usage() { var msg = "" + "Usage: node jscrund [options]\n" + " --help:\n" + " -h : Print help (this message)\n" + " -A : Run \"A\" tests (default)\n" + " -B : Run \"B\" tests\n" + " --varchar=size\n" + " : Specify varchar size in B tests (default 10)\n" + " --adapter=ndb\n" + " -n : Use ndb adapter (default)\n" + " --adapter=mysql\n" + " -m : Use mysql adapter\n" + " --spi : Run tests using DBServiceProvider SPI \n" + " --adapter=sql\n" + " -f : Use felix sql driver (not mysql-js api)\n" + " --adapter=null\n" + " : Use null driver\n" + " --log : Write log file\n" + " --detail: Enable detail debug output\n" + " --debug :\n" + " -d : Enable debug output\n" + " -df=file: Enable debug output only from source file <file>\n" + " -i <n> : Specify number of iterations per test (default 4000)\n" + " --delay=<m>,<n>\n" + " : Delay <m> seconds after first iteration and <n> seconds before exiting\n" + " --modes :\n" + " --mode : Specify modes to run (default indy,each,bulk)\n" + " --tests :\n" + " --test : Specify tests to run (default persist,find,remove)\n" + " -r <n> : Repeat tests #n times (default 1, n<0: forever)\n" + " --trace :\n" + " -t : Enable trace output\n" + " --set prop=value: set connection property prop to value\n" + " -E <name> \n" + " --deployment=<name>\n: use deplyment <name> from jones_deployments.js\n" ; console.log(msg); process.exit(1); } //handle command line arguments function parse_command_line(options) { var i, val, values, pair, m, n; for(i = 2; i < process.argv.length ; i++) { val = process.argv[i]; switch (val) { case '--help': case '-h': options.exit = true; break; case '-A': options.doClass = "A"; break; case '-B': options.doClass = "B"; break; case '-n': options.adapter = "ndb"; break; case '-m': options.adapter = "mysql"; break; case '-f': options.adapter = "sql"; break; case '-i': var iterList = process.argv[++i]; options.iterations = iterList.split('\,'); for(m = 0 ; m < options.iterations.length; ++m) { n = options.iterations[m] if (isNaN(n)) { console.log('iterations value ',n,' is not allowed'); options.exit = true; } } break; case '-r': options.nRuns = parseInt(process.argv[++i]); if (isNaN(options.nRuns)) { console.log('runs value is not allowed:', process.argv[i]); options.exit = true; } break; case '-E': options.deployment = process.argv[++i]; break; case '--stats': options.stats = true; break; case '--debug': case '-d': JSCRUND.unified_debug.on(); JSCRUND.unified_debug.level_debug(); options.printStackTraces = true; break; case '--detail': JSCRUND.unified_debug.on(); JSCRUND.unified_debug.level_detail(); options.printStackTraces = true; break; case '--trace': case '-t': options.printStackTraces = true; break; case '--log': options.log = true; break; case '--spi': options.spi = true; break; case '--set': i++; // next argument pair = process.argv[i].split('='); if(pair.length === 2) { if(isFinite(parseInt(pair[1]))) { pair[1] = parseInt(pair[1]) } if(DEBUG) JSCRUND.udebug.log("Setting global:", pair[0], "=", pair[1]); options.setProp[pair[0]] = pair[1]; } else { console.log("Invalid --set option " + process.argv[i]); options.exit = true; } break; default: values = val.split('='); if (values.length === 2) { switch (values[0]) { case '--count': options.count = values[1]; break; case '--adapter': options.adapter = values[1]; break; case '--mode': case '--modes': options.modes = values[1]; options.modeNames = options.modes.split('\,'); // validate mode names for (m = 0; m < options.modeNames.length; ++m) { switch (options.modeNames[m]) { case 'indy': case 'each': case 'bulk': break; default: console.log('Invalid mode ' + options.modeNames[m]); options.exit = true; } } break; case '--test': case '--tests': options.tests = values[1]; options.testNames = options.tests.split('\,'); // validate test names for (var t = 0; t < options.testNames.length; ++t) { switch (options.testNames[t]) { case 'persist': case 'find': case 'remove': case 'setVarchar': case 'clearVarchar': break; default: console.log('Invalid test ' + options.testNames[t]); options.exit = true; } } break; case '-df': unified_debug.on(); unified_debug.set_file_level(values[1], 5); break; case '--delay': var delays = values[1].split(','); options.delay_pre = delays[0]; options.delay_post = delays[1]; break; case '--varchar': options.B_varchar_size = values[1]; break; case '--deployment': options.deployment = values[1]; break; default: console.log('Invalid option ' + val); options.exit = true; } } else { console.log('Invalid option ' + val); options.exit = true; } } } } /** Timer functions for crund. Multiple timers can be used simultaneously, * as long as each timer is created via new Timer(). * start() starts the timer. * stop() stops the timer and writes results. * mode is the mode of operation (indy, each, or bulk) * operation is the operation (e.g. persist, find, delete) * numberOfIterations is the number of iterations of each operation */ function Timer() { } Timer.prototype.start = function(mode, operation, numberOfIterations) { //console.log('lib.Timer.start', mode, operation, 'iterations:', numberOfIterations); this.mode = mode; this.operation = operation; this.numberOfIterations = numberOfIterations; this.current = Date.now(); }; Timer.prototype.stop = function() { function pad(str, count, onRight) { while (str.length < count) str = (onRight ? str + ' ' : ' ' + str); return str; } function rpad(num, str) { return pad(str, num, true); } function lpad(num, str) { return pad(str, num, false); } this.interval = Date.now() - this.current; this.average = this.interval / this.numberOfIterations; var ops = Math.round(this.numberOfIterations * 1000 / this.interval); console.log(rpad(18, this.mode + ' ' + this.operation), ' time: ' + lpad(4, this.interval.toString()) + 'ms', ' avg latency: ' + lpad(4, this.average.toFixed(3)) + 'ms', ' ops/s: ' + lpad(4, ops.toString())); }; /** Error reporter */ function appendError(error) { JSCRUND.errors.push(error); if ((options.printStackTraces) && typeof(error.stack) !== 'undefined') { JSCRUND.errors.push(error.stack); } }; function verifyObject(that) { for (var prop in this) { // only verify immediate properties, not inherited ones if (this.hasOwnProperty(prop)) { // only compare value, not type, since long numbers mapped to string //if (this[prop] !== that[prop]) if (this[prop] != that[prop]) appendError('Error: data mismatch for property ' + this.constructor.name + '.' + prop + ' expected: ' + JSON.stringify(this[prop]) + ' actual: ' + JSON.stringify(that[prop])); } } }; /** Constructor for domain object for A mapped to table a. */ function A() { } A.prototype.init = function(i) { this.id = i; this.cint = -i; this.clong = -i; this.cfloat = -i; this.cdouble = -i; }; A.prototype.verify = verifyObject; /** Constructor for domain object for B mapped to table b. */ function B() { } B.prototype.init = function(i) { this.id = i; this.cint = -i; this.clong = -i; this.cfloat = -i; this.cdouble = -i; }; B.prototype.setVarchar = function(len) { this.cvarchar_def = ___; }; B.prototype.verify = verifyObject; /** Result Logging */ function currentDateString() { function zpad(s) { return (s.length == 1) ? "0" + s : s; } var d = new Date(); var yy = d.getFullYear(); var mm = zpad("" + (d.getMonth() + 1)); var dd = zpad("" + d.getDate()); var hh = zpad("" + d.getHours()); var mn = zpad("" + d.getMinutes()); var sc = zpad("" + d.getSeconds()); return ("" + yy + mm + dd + "_" + hh + mn + sc); }; function ResultLog(enabled) { this.enabled = enabled; if(enabled) { this.name = "log_" + currentDateString() + ".txt"; this.fd = fs.openSync(this.name, 'a'); } else { this.name = "[none]"; this.message = ""; } } ResultLog.prototype.write = function(message) { if(this.enabled) { var buffer = Buffer.from(message); fs.writeSync(this.fd, buffer, 0, buffer.length); } else { this.message += message; } }; ResultLog.prototype.close = function() { if(this.enabled) { fs.closeSync(this.fd); } else { console.log(this.message); } }; /** Options are set up based on command line. * Properties are set up based on options. */ function main() { var config_file_exists = false; /* Default options: */ var options = { 'doClass' : 'A', 'adapter' : 'ndb', 'database': 'jscrund', 'modes': 'indy,each,bulk', 'tests': null, 'iterations': [4000], 'stats': false, 'spi': false, 'log': false, 'nRuns': 1, 'setProp' : {}, 'delay_pre' : 0, 'delay_post' : 0, 'B_varchar_size' : 10, 'deployment' : 'test' }; /* Options from config file */ try { var config_file = require("./jscrund.config"); config_file_exists = true; for(var i in config_file.options) { if(config_file.options.hasOwnProperty(i)) { options[i] = config_file.options[i]; } } } catch(e) { if (e.message.indexOf('Cannot find module') === -1) { console.log(e); console.log(e.name, 'reading jscrund.config:', e.message, '\nPlease correct this error and try again.\n'); process.exit(0); } } /* Options from command line */ parse_command_line(options); if (options.exit) { usage(); process.exit(0); } /* Global udebug level; may have been set by options */ DEBUG = JSCRUND.udebug.is_debug(); DETAIL = JSCRUND.udebug.is_detail(); /* Create the string value for varchar tests */ if(options.B_varchar_size > 0) { options.B_varchar_value = ""; for(var i = 0 ; i < options.B_varchar_size ; i++) { options.B_varchar_value += String.fromCharCode(48 + (i % 64)); } } /* Fetch the backend implementation */ if(options.spi) { JSCRUND.spiAdapter = require('./jscrund_dbspi'); JSCRUND.implementation = new JSCRUND.spiAdapter.implementation(); } else if(options.adapter == 'sql') { JSCRUND.sqlAdapter = require('./jscrund_sql'); JSCRUND.implementation = new JSCRUND.sqlAdapter.implementation(); } else if(options.adapter == 'null') { JSCRUND.nullAdapter = require('./jscrund_null'); JSCRUND.implementation = new JSCRUND.nullAdapter.implementation(); } else { JSCRUND.implementation = new JSCRUND.mysqljs.implementation(); } /* Get connection properties */ var properties; if(typeof JSCRUND.implementation.getConnectionProperties === 'function') { properties = JSCRUND.implementation.getConnectionProperties(); } else { properties = new JSCRUND.mynode.ConnectionProperties(options.adapter, options.deployment); } /* Then mix in properties from the command line */ properties.database = options.database; for(i in options.setProp) { if(options.setProp.hasOwnProperty(i)) { properties[i] = options.setProp[i]; } } /* Finally store the complete properties object in the options */ options.properties = properties; /* Force GC is available if node is run with the --expose-gc option */ options.use_gc = ( typeof global.gc === 'function' ); var logFile = new ResultLog(options.log); new JSCRUND.mynode.TableMapping("a").applyToClass(A); new JSCRUND.mynode.TableMapping("b").applyToClass(B); options.annotations = [ A, B ]; var generateAllParameters = function(numberOfParameters) { var result = []; for (var i = 0; i < numberOfParameters; ++i) { result[i] = generateParameters(i); } return result; }; var generateParameters = function(i) { return {'key': generateKey(i), 'object': generateObject(i)}; }; var generateKey = function(i) { return i; }; var generateObject = function(i) { var result; if(options.doClass == "A") { result = new A(); } else if(options.doClass == "B") { result = new B(); } else { assert(false); } result.init(i); return result; }; // mainTestLoop (-r 10) // batchSizeLoop (-i 1,10,100) // ModeLoop (--modes=indy,each) // TestsLoop (--tests=persist,remove) var runTests = function(options) { var timer = new Timer(); var modeNames = options.modes.split('\,'); var modeNumber = 0; var mode; var modeName; var testNames; var testNumber = 0; var operation; var testName; var key; var object; var numberOfBatchLoops = options.iterations.length; var batchLoopNumber = 0; var numberOfIterations; var iteration; var nRun = 0; var nRuns = (options.nRuns < 0 ? Infinity : options.nRuns); var nReport = 0; var operationsDoneCallback; var testsDoneCallback; var resultStats = []; var parameters; /* Which tests to run */ if(options.tests) { // Explicit test names testNames = options.tests.split('\,'); } else { switch(options.doClass) { case 'B': testNames = [ 'persist', 'setVarchar', 'find', 'clearVarchar', 'remove' ]; break; case 'A': default: testNames = [ 'persist', 'find', 'remove' ]; break; }; } /** Recursively call the operation numberOfIterations times in autocommit mode * and then call the operationsDoneCallback */ var indyOperationsLoop = function(err) { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.indyOperationsLoop iteration:', iteration, 'err:', err); // check result if (err) { appendError(err); } // call implementation operation if (iteration < numberOfIterations) { operation.apply(JSCRUND.implementation, [parameters[iteration], indyOperationsLoop]); iteration++; } else { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.indyOperationsLoop iteration:', iteration, 'complete.'); timer.stop(); resultStats.push({ name: testName + "," + modeName, time: timer.interval }); setImmediate(operationsDoneCallback); } }; /** Call indyOperationsLoop for all of the tests in testNames */ var indyTestsLoop = function() { testName = testNames[testNumber]; operation = JSCRUND.implementation[testName]; operationsDoneCallback = indyTestsLoop; if (testNumber < testNames.length) { if(options.use_gc) global.gc(); // Full GC between tests testNumber++; if(DETAIL) JSCRUND.udebug.log_detail('jscrund.indyTestsLoop', testNumber, 'of', testNames.length, ':', testName); iteration = 0; timer.start(modeName, testName, numberOfIterations); setImmediate(indyOperationsLoop, null); } else { // done with all indy tests // stop timer and report setImmediate(testsDoneCallback); } }; /** Finish the each operations loop after commit. */ var eachCommitDoneCallback = function(err) { // check result if (err) { appendError(err); } timer.stop(); resultStats.push({ name: testName + "," + modeName, time: timer.interval }); setImmediate(operationsDoneCallback); }; /** Call the operation numberOfIterations times within a transaction * and then call the operationsDoneCallback */ var eachOperationsLoop = function(err) { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.eachOperationsLoop iteration:', iteration, 'err:', err); // check result if (err) { appendError(err); } // call implementation operation if (iteration < numberOfIterations) { operation.apply(JSCRUND.implementation, [parameters[iteration], eachOperationsLoop]); iteration++; } else { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.eachOperationLoop iteration:', iteration, 'complete.'); JSCRUND.implementation.commit(eachCommitDoneCallback); } }; /** Call eachOperationsLoop for all of the tests in testNames */ var eachTestsLoop = function() { testName = testNames[testNumber]; operation = JSCRUND.implementation[testName]; operationsDoneCallback = eachTestsLoop; if (testNumber < testNames.length) { if(options.use_gc) global.gc(); // Full GC between tests testNumber++; if(DETAIL) JSCRUND.udebug.log_detail('jscrund.eachTestsLoop', testNumber, 'of', testNames.length, ':', testName); iteration = 0; timer.start(modeName, testName, numberOfIterations); JSCRUND.implementation.begin(function(err) { setImmediate(eachOperationsLoop, null); }); } else { // done with all each tests // stop timer and report testsDoneCallback(); } }; /** Check the results of a bulk execute. */ var bulkCheckBatchCallback = function(err) { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.bulkCheckBatchCallback', err); // check result if (err) { appendError(err); } timer.stop(); resultStats.push({ name: testName + "," + modeName, time: timer.interval }); setImmediate(bulkTestsLoop); }; /** Check the results of a bulk operation. It will be executed * numberOfIterations times per test. */ var bulkCheckOperationCallback = function(err) { if(DETAIL) JSCRUND.udebug.log_detail('jscrund.bulkCheckOperationCallback', err); if (err) { appendError(err); } }; /** Construct one batch and execute it for all of the tests in testNames */ var bulkTestsLoop = function() { testName = testNames[testNumber]; operation = JSCRUND.implementation[testName]; operationsDoneCallback = bulkTestsLoop; if (testNumber < testNames.length) { if(options.use_gc) global.gc(); // Full GC between tests testNumber++; if(DETAIL) JSCRUND.udebug.log_detail('jscrund.bulkTestsLoop', testNumber, 'of', testNames.length, ':', testName); timer.start(modeName, testName, numberOfIterations); JSCRUND.implementation.createBatch(function(err) { for (iteration = 0; iteration < numberOfIterations; ++iteration) { operation.apply(JSCRUND.implementation, [parameters[iteration], bulkCheckOperationCallback]); } JSCRUND.implementation.executeBatch(bulkCheckBatchCallback); }); } else { // done with all bulk tests testsDoneCallback(); } }; /** Run all modes specified in --modes: default is indy, each, bulk. * */ var modeLoop = function() { modeName = modeNames[modeNumber]; mode = modes[modeNumber]; testNumber = 0; if (modeNumber < modes.length) { modeNumber++; console.log('\njscrund.modeLoop ', modeName, "[ size",numberOfIterations,"]"); mode.apply(runTests); } else { if (JSCRUND.errors.length !== 0) { console.log(JSCRUND.errors); } report(); batchSizeLoop(); } }; function report() { var opNames, opTimes, r, adapter; adapter = options.adapter + (options.spi ? "(spi)" : ""); opNames = "rtime[ms]," + adapter + '\t'; opTimes = "" + numberOfIterations + '\t'; while (r = resultStats.shift()) { opNames += r.name + '\t'; opTimes += r.time + '\t'; } if(! nReport++) { logFile.write(opNames + '\n'); } logFile.write(opTimes + '\n'); } /** Iterate over batch sizes */ function batchSizeLoop() { if(batchLoopNumber < numberOfBatchLoops) { numberOfIterations = options.iterations[batchLoopNumber]; batchLoopNumber++; parameters = generateAllParameters(numberOfIterations); modeNumber = 0; setImmediate(modeLoop); } else { mainTestLoop(); } } /** Run test with all modes. */ var mainTestLoop = function() { if (nRun++ >= nRuns) { console.log('\ndone: ' + nRuns + ' runs.'); console.log("\nappending results to file: " + logFile.name); logFile.close(); if (options.stats) { JSCRUND.stats.peek(); } JSCRUND.implementation.close(function(err) { if(options.delay_post > 0) { console.log("Delaying", options.delay_post, "seconds"); setTimeout(process.exit, 1000 * options.delay_post); } else { process.exit(err ? 1 : 0); } }); } else { console.log('\nRun #' + nRun + ' of ' + nRuns); batchLoopNumber = 0; if(nRun === 2 && (options.delay_pre > 0)) { console.log("Waiting", options.delay_pre, "seconds..."); setTimeout(batchSizeLoop, 1000 * options.delay_pre); options.delay_pre = 0; } else { batchSizeLoop(); } } }; // runTests starts here var modeTable = { 'indy': indyTestsLoop, 'each': eachTestsLoop, 'bulk': bulkTestsLoop }; var modes = []; for (var m = 0; m < modeNames.length; ++m) { modes.push(modeTable[modeNames[m]]); } console.log('running tests with options:\n', options); JSCRUND.implementation.initialize(options, function(err) { // initialization complete if (err) { console.log('Error initializing JSCRUND.implementation:', err); process.exit(1); } else { testsDoneCallback = modeLoop; mainTestLoop(); } }); }; // create database JSCRUND.metadataManager = require("jones-ndb").getDBMetadataManager(properties); JSCRUND.metadataManager.runSQL(path.join(__dirname, "./create.sql"), function(err) { if (err) { console.log('Error creating tables.', err); process.exit(1); } // if database create successful, run tests runTests(options); }); } main();