diff --git a/.gitmodules b/.gitmodules index 676c50053a5..0c8bd3cb2b1 100644 --- a/.gitmodules +++ b/.gitmodules @@ -1,3 +1,3 @@ [submodule "packages/xsnap/moddable"] path = packages/xsnap/moddable - url = https://github.com/Moddable-OpenSource/moddable.git + url = https://github.com/agoric-labs/moddable.git diff --git a/packages/xsnap/api.js b/packages/xsnap/api.js index d00f16a8831..0276ecd8073 100644 --- a/packages/xsnap/api.js +++ b/packages/xsnap/api.js @@ -3,7 +3,7 @@ /** The version identifier for our meter type. * TODO Bump this whenever there's a change to metering semantics. */ -export const METER_TYPE = 'xs-meter-2'; +export const METER_TYPE = 'xs-meter-6'; export const ExitCode = { E_UNKNOWN_ERROR: -1, diff --git a/packages/xsnap/moddable b/packages/xsnap/moddable index 1502614759b..13156549086 160000 --- a/packages/xsnap/moddable +++ b/packages/xsnap/moddable @@ -1 +1 @@ -Subproject commit 1502614759bbee368833c600222406b1808fb972 +Subproject commit 1315654908666be016a8d1f4af509835b3446235 diff --git a/packages/xsnap/src/xsnap.c b/packages/xsnap/src/xsnap.c index 4a1016e301f..277bec2c213 100644 --- a/packages/xsnap/src/xsnap.c +++ b/packages/xsnap/src/xsnap.c @@ -59,6 +59,7 @@ static void fx_gc(xsMachine* the); // static void fx_isPromiseJobQueueEmpty(xsMachine* the); static void fx_markTimer(txMachine* the, void* it, txMarkRoot markRoot); static void fx_print(xsMachine* the); +static void fx_performance_now(xsMachine* the); static void fx_setImmediate(txMachine* the); // static void fx_setInterval(txMachine* the); // static void fx_setTimeout(txMachine* the); @@ -73,20 +74,21 @@ static void fxRunLoop(txMachine* the); static int fxReadNetString(FILE *inStream, char** dest, size_t* len); static char* fxReadNetStringError(int code); -static int fxWriteOkay(FILE* outStream, xsUnsignedValue meterIndex, txSize allocatedSpace, char* buf, size_t len); +static int fxWriteOkay(FILE* outStream, xsUnsignedValue meterIndex, txMachine *the, char* buf, size_t len); static int fxWriteNetString(FILE* outStream, char* prefix, char* buf, size_t len); static char* fxWriteNetStringError(int code); // The order of the callbacks materially affects how they are introduced to // code that runs from a snapshot, so must be consistent in the face of // upgrade. -#define mxSnapshotCallbackCount 5 +#define mxSnapshotCallbackCount 6 txCallback gxSnapshotCallbacks[mxSnapshotCallbackCount] = { fx_issueCommand, // 0 fx_Array_prototype_meter, // 1 fx_print, // 2 fx_setImmediate, // 3 fx_gc, // 4 + fx_performance_now, // 5 // fx_evalScript, // fx_isPromiseJobQueueEmpty, // fx_setInterval, @@ -298,10 +300,10 @@ ExitCode main(int argc, char* argv[]) } } xsCreation _creation = { - 1 * 1024 * 1024, /* initialChunkSize */ - 512 * 1024, /* incrementalChunkSize */ - 16 * 1024, /* initialHeapCount */ - 256 * 1024, /* incrementalHeapCount */ + 32 * 1024 * 1024, /* initialChunkSize */ + 4 * 1024 * 1024, /* incrementalChunkSize */ + 256 * 1024, /* initialHeapCount */ + 128 * 1024, /* incrementalHeapCount */ 4096, /* stackCount */ 32000, /* keyCount */ 1993, /* nameModulo */ @@ -430,7 +432,7 @@ ExitCode main(int argc, char* argv[]) } } // fprintf(stderr, "response of %d bytes\n", responseLength); - writeError = fxWriteOkay(toParent, meterIndex, the->allocatedSpace, response, responseLength); + writeError = fxWriteOkay(toParent, meterIndex, the, response, responseLength); } } xsEndHost(machine); @@ -466,7 +468,7 @@ ExitCode main(int argc, char* argv[]) fxRunLoop(machine); meterIndex = xsEndCrank(machine); if (error == 0) { - int writeError = fxWriteOkay(toParent, meterIndex, machine->allocatedSpace, "", 0); + int writeError = fxWriteOkay(toParent, meterIndex, machine, "", 0); if (writeError != 0) { fprintf(stderr, "%s\n", fxWriteNetStringError(writeError)); c_exit(E_IO_ERROR); @@ -496,7 +498,7 @@ ExitCode main(int argc, char* argv[]) c_exit(E_IO_ERROR); } if (snapshot.error == 0) { - int writeError = fxWriteOkay(toParent, meterIndex, machine->allocatedSpace, "", 0); + int writeError = fxWriteOkay(toParent, meterIndex, machine, "", 0); if (writeError != 0) { fprintf(stderr, "%s\n", fxWriteNetStringError(writeError)); c_exit(E_IO_ERROR); @@ -552,6 +554,12 @@ void fxBuildAgent(xsMachine* the) // slot = fxNextHostFunctionProperty(the, slot, fx_setInterval, 1, xsID("setInterval"), XS_DONT_ENUM_FLAG); // slot = fxNextHostFunctionProperty(the, slot, fx_setTimeout, 1, xsID("setTimeout"), XS_DONT_ENUM_FLAG); + mxPush(mxObjectPrototype); + txSlot* performance = fxLastProperty(the, fxNewObjectInstance(the)); + fxNextHostFunctionProperty(the, performance, fx_performance_now, 1, xsID("now"), XS_DONT_ENUM_FLAG); + slot = fxNextSlotProperty(the, slot, the->stack, xsID("performance"), XS_DONT_ENUM_FLAG); + mxPop(); + // mxPush(mxObjectPrototype); // fxNextHostFunctionProperty(the, fxLastProperty(the, fxNewObjectInstance(the)), fx_print, 1, xsID("log"), XS_DONT_ENUM_FLAG); // slot = fxNextSlotProperty(the, slot, the->stack, xsID("console"), XS_DONT_ENUM_FLAG); @@ -1075,11 +1083,15 @@ void fxCreateMachinePlatform(txMachine* the) the->promiseJobs = 0; the->timerJobs = NULL; + // Original 10x strategy: // SLOGFILE=out.slog agoric start local-chain // jq -s '.|.[]|.dr[2].allocate' < out.slog|grep -v null|sort -u | sort -nr - int MB = 1024 * 1024; - int measured_max = 30 * MB; - the->allocationLimit = 10 * measured_max; + // int MB = 1024 * 1024; + // int measured_max = 30 * MB; + // the->allocationLimit = 10 * measured_max; + + size_t GB = 1024 * 1024 * 1024; + the->allocationLimit = 2 * GB; } void fxDeleteMachinePlatform(txMachine* the) @@ -1398,12 +1410,30 @@ static char* fxReadNetStringError(int code) } } -static int fxWriteOkay(FILE* outStream, xsUnsignedValue meterIndex, txSize allocatedSpace, char* buf, size_t length) +static int fxWriteOkay(FILE* outStream, xsUnsignedValue meterIndex, txMachine *the, char* buf, size_t length) { - // large enough for 2 64bit numbers, with a spare 64 bit word - char prefix[sizeof ".[12345678901234567890,12345678901234567890]\1" + 8]; + char fmt[] = ("." // OK + "{" + "\"compute\":%u," + "\"allocate\":%u," + "\"allocateChunksCalls\":%u," + "\"allocateSlotsCalls\":%u," + "\"garbageCollectionCount\":%u," + "\"mapSetAddCount\":%u," + "\"mapSetRemoveCount\":%u," + "\"maxBucketSize\":%u}" + "\1" // separate meter info from result + ); + char numeral64[] = "12345678901234567890"; // big enough for 64bit numeral + char prefix[8 + sizeof fmt + 8 * sizeof numeral64]; + // TODO: fxCollect counter // Prepend the meter usage to the reply. - snprintf(prefix, sizeof(prefix) - 1, ".[%u,%u]\1", meterIndex, allocatedSpace); + snprintf(prefix, sizeof(prefix) - 1, fmt, + meterIndex, the->allocatedSpace, + the->allocateChunksCallCount, the->allocateSlotsCallCount, + the->garbageCollectionCount, + the->mapSetAddCount, the->mapSetRemoveCount, + the->maxBucketSize); return fxWriteNetString(outStream, prefix, buf, length); } @@ -1483,6 +1513,7 @@ void* fxAllocateChunks(txMachine* the, txSize theSize) { // fprintf(stderr, "fxAllocateChunks(%lu)\n", theSize); adjustSpaceMeter(the, theSize); + the->allocateChunksCallCount += 1; return c_malloc(theSize); } @@ -1498,6 +1529,7 @@ txSlot* fxAllocateSlots(txMachine* the, txSize theCount) { // fprintf(stderr, "fxAllocateSlots(%u) * %d = %ld\n", theCount, sizeof(txSlot), theCount * sizeof(txSlot)); adjustSpaceMeter(the, theCount * sizeof(txSlot)); + the->allocateSlotsCallCount += 1; return (txSlot*)c_malloc(theCount * sizeof(txSlot)); } @@ -1506,6 +1538,14 @@ void fxFreeSlots(txMachine* the, void* theSlots) c_free(theSlots); } +void fx_performance_now(txMachine *the) +{ + c_timeval tv; + c_gettimeofday(&tv, NULL); + mxResult->kind = XS_NUMBER_KIND; + mxResult->value.number = (double)(tv.tv_sec * 1000.0) + ((double)(tv.tv_usec) / 1000.0); +} + // Local Variables: // tab-width: 4 diff --git a/packages/xsnap/src/xsnap.h b/packages/xsnap/src/xsnap.h index c1db61d6272..be95b6dc6cd 100644 --- a/packages/xsnap/src/xsnap.h +++ b/packages/xsnap/src/xsnap.h @@ -67,8 +67,14 @@ #endif #define mxMachinePlatform \ txSocket connection; \ - txSize allocationLimit; \ - txSize allocatedSpace; \ + size_t allocationLimit; \ + size_t allocatedSpace; \ + txUnsigned allocateChunksCallCount; \ + txUnsigned allocateSlotsCallCount; \ + txUnsigned garbageCollectionCount; \ + txUnsigned mapSetAddCount; \ + txUnsigned mapSetRemoveCount; \ + txUnsigned maxBucketSize; \ int promiseJobs; \ void* timerJobs; \ void* waiterCondition; \ diff --git a/packages/xsnap/src/xsnap.js b/packages/xsnap/src/xsnap.js index ffe2e2c9574..0d9ddd49d37 100644 --- a/packages/xsnap/src/xsnap.js +++ b/packages/xsnap/src/xsnap.js @@ -169,19 +169,18 @@ export function xsnap(options) { xsnapProcess.kill(); throw new Error('xsnap protocol error: received empty message'); } else if (message[0] === OK) { - let compute = null; - let allocate = null; + let meterInfo = { compute: null, allocate: null }; const meterSeparator = message.indexOf(OK_SEPARATOR, 1); if (meterSeparator >= 0) { // The message is `.meterdata\1reply`. const meterData = message.slice(1, meterSeparator); - // We parse the meter data as JSON, expecting an array of two numbers. - [compute, allocate] = JSON.parse(decoder.decode(meterData)); + // We parse the meter data as JSON + meterInfo = JSON.parse(decoder.decode(meterData)); + // assert(typeof meterInfo === 'object'); } const meterUsage = { meterType: METER_TYPE, - allocate, - compute, + ...meterInfo, }; // console.log('have meterUsage', meterUsage); return { diff --git a/packages/xsnap/test/test-xs-perf.js b/packages/xsnap/test/test-xs-perf.js new file mode 100644 index 00000000000..ff442e72887 --- /dev/null +++ b/packages/xsnap/test/test-xs-perf.js @@ -0,0 +1,56 @@ +// eslint-disable-next-line import/no-extraneous-dependencies +import test from 'ava'; +import { xsnap } from '../src/xsnap'; +import { options } from './test-xsnap'; + +test('meter details', async t => { + const opts = options(); + const vat = xsnap(opts); + t.teardown(() => vat.terminate()); + const result = await vat.evaluate(` + let m = new Map(); + let s1 = new Set(); + for (ix = 0; ix < 20000; ix++) { + m.set(ix, 'garbage'); + s1.add(ix); + } + for (ix = 0; ix < 20000; ix++) { + m.delete(ix); + s1.delete(ix); + } + `); + const { + meterUsage: { meterType, ...meters }, + } = result; + t.log(meters); + const { entries, fromEntries } = Object; + t.deepEqual( + { + compute: 'number', + allocate: 'number', + allocateChunksCalls: 'number', + allocateSlotsCalls: 'number', + garbageCollectionCount: 'number', + mapSetAddCount: 'number', + mapSetRemoveCount: 'number', + maxBucketSize: 'number', + }, + fromEntries(entries(meters).map(([p, v]) => [p, typeof v])), + ); + t.is(meterType, 'xs-meter-6'); +}); + +test('high resolution timer', async t => { + const opts = options(); + const vat = xsnap(opts); + t.teardown(() => vat.terminate()); + await vat.evaluate(` + const send = it => issueCommand(ArrayBuffer.fromString(JSON.stringify(it))); + + const t = performance.now(); + send(t); + `); + const [milliseconds] = opts.messages.map(JSON.parse); + t.log({ milliseconds, date: new Date(milliseconds) }); + t.is('number', typeof milliseconds); +}); diff --git a/packages/xsnap/test/test-xsnap.js b/packages/xsnap/test/test-xsnap.js index 11109cd583f..04bf4d7d0ec 100644 --- a/packages/xsnap/test/test-xsnap.js +++ b/packages/xsnap/test/test-xsnap.js @@ -19,7 +19,7 @@ const xsnapOptions = { stdout: 'inherit', }; -function options() { +export function options() { const messages = []; async function handleCommand(message) { messages.push(decoder.decode(message));