diff --git a/app/ProcessCpuProfiler.ts b/app/ProcessCpuProfiler.ts new file mode 100644 index 0000000000000000000000000000000000000000..31bbf45117b8a38b3b5a6e447f1896025738a2a2 --- /dev/null +++ b/app/ProcessCpuProfiler.ts @@ -0,0 +1,72 @@ +const SAMPLING_PERIOD = 150 // milliseconds +const MAX_SAMPLES_DISTANCE = 20 * 1000000 // seconds + +function getMicrosecondsTime() { + const [ seconds, nanoseconds ] = process.hrtime() + return seconds * 1000000 + nanoseconds / 1000 +} + +interface CpuUsage { + user: number + system:number +} + +interface CpuUsageAt { + usage:number + at:number // microseconds timestamp + elapsed:number // microseconds elapsed for this result +} + +export class ProcessCpuProfiler { + + private cumulatedUsage: CpuUsage + private startedAt:number // microseconds timestamp + private samples:CpuUsageAt[] = [] + + constructor(samplingPeriod = SAMPLING_PERIOD) { + // Initial state + const start = getMicrosecondsTime() + this.startedAt = start + this.cumulatedUsage = process.cpuUsage() + this.samples.push({ usage: 0, at: start, elapsed: 1 }) + // Periodic sample + setInterval(() => { + const newSampleAt = getMicrosecondsTime() + const newUsage:CpuUsage = process.cpuUsage() + const elapsed = newSampleAt - this.lastSampleAt + const userDiff = newUsage.user - this.cumulatedUsage.user + const usagePercent = userDiff / elapsed // The percent of time consumed by the process since last sample + this.samples.push({ usage: usagePercent, at: newSampleAt, elapsed }) + while(this.samplesDistance > MAX_SAMPLES_DISTANCE) { + this.samples.shift() + } + this.cumulatedUsage = newUsage + // console.log('Time elapsed: %s microseconds, = %s %CPU', elapsed, (usagePercent*100).toFixed(2)) + }, samplingPeriod) + } + + private get lastSampleAt() { + return this.samples[this.samples.length - 1].at + } + + private get samplesDistance() { + return this.samples[this.samples.length - 1].at - this.samples[0].at + } + + cpuUsageOverLastMilliseconds(elapsedMilliseconds:number) { + return this.cpuUsageOverLastX(elapsedMilliseconds * 1000) + } + + private cpuUsageOverLastX(nbMicrosecondsElapsed:number) { + return this.getSamplesResult(getMicrosecondsTime() - nbMicrosecondsElapsed) + } + + private getSamplesResult(minTimestamp:number) { + const matchingSamples = this.samples.filter(s => s.at >= minTimestamp - SAMPLING_PERIOD * 1000) + const cumulativeElapsed = matchingSamples.reduce((sum, s) => sum + s.elapsed, 0) + return matchingSamples.reduce((cumulated, percent) => { + const weight = percent.elapsed / cumulativeElapsed + return cumulated + percent.usage * weight + }, 0) + } +} \ No newline at end of file diff --git a/app/modules/prover/lib/blockProver.ts b/app/modules/prover/lib/blockProver.ts index 9cd215d98d478a456857b52f9f5c5388e1afa153..ccafd0717a18bf15ef74be23f33abae1c1a40f06 100644 --- a/app/modules/prover/lib/blockProver.ts +++ b/app/modules/prover/lib/blockProver.ts @@ -44,6 +44,9 @@ export class WorkerFarm { }) } + get nbWorkers() { + return this.theEngine.getNbWorkers() + } changeCPU(cpu:any) { return this.theEngine.setConf({ cpu }) @@ -175,7 +178,6 @@ export class BlockProver { const start = Date.now(); let result = await powFarm.askNewProof({ newPoW: { - turnDuration: os.arch().match(/arm/) ? CommonConstants.POW_TURN_DURATION_ARM : CommonConstants.POW_TURN_DURATION_PC, conf: { cpu: this.conf.cpu, prefix: this.conf.prefix, @@ -194,10 +196,10 @@ export class BlockProver { throw 'Proof-of-work computation canceled because block received'; } else { const proof = result.block; - const testsCount = result.testsCount; + const testsCount = result.testsCount * powFarm.nbWorkers const duration = (Date.now() - start); - const testsPerSecond = (testsCount / (duration / 1000)).toFixed(2); - this.logger.info('Done: #%s, %s in %ss (%s tests, ~%s tests/s)', block.number, proof.hash, (duration / 1000).toFixed(2), testsCount, testsPerSecond); + const testsPerSecond = testsCount / (duration / 1000) + this.logger.info('Done: #%s, %s in %ss (~%s tests, ~%s tests/s, using %s cores, CPU %s%)', block.number, proof.hash, (duration / 1000).toFixed(2), testsCount, testsPerSecond.toFixed(2), powFarm.nbWorkers, Math.floor(100*this.conf.cpu)) this.logger.info('FOUND proof-of-work with %s leading zeros followed by [0-' + highMark + ']!', nbZeros); return BlockDTO.fromJSONObject(proof) } diff --git a/app/modules/prover/lib/engine.ts b/app/modules/prover/lib/engine.ts index a71afa1d114a7811083b12c529ade226ead8921f..c4d8fee91e4cb4f608aeac163122274c86b22b6a 100644 --- a/app/modules/prover/lib/engine.ts +++ b/app/modules/prover/lib/engine.ts @@ -25,6 +25,10 @@ export class PowEngine { this.id = this.cluster.clusterId } + getNbWorkers() { + return this.cluster.nbWorkers + } + forceInit() { return this.cluster.initCluster() } @@ -42,10 +46,11 @@ export class PowEngine { return await this.cluster.proveByWorkers(stuff) } + cancel() { + return this.cluster.cancelWork() + } + setConf(value:any) { - if (os.arch().match(/arm/) && value.cpu !== undefined) { - value.cpu /= 2; // Don't know exactly why is ARM so much saturated by PoW, so let's divide by 2 - } return this.cluster.changeConf(value) } diff --git a/app/modules/prover/lib/powCluster.ts b/app/modules/prover/lib/powCluster.ts index 4d4820777cb9b279aebea2d09680d1be0b3aab1f..140c887a5fa311e5d6ce1aec8f77d4fcb66c5052 100644 --- a/app/modules/prover/lib/powCluster.ts +++ b/app/modules/prover/lib/powCluster.ts @@ -195,7 +195,6 @@ export class Master { highMark: stuff.newPoW.highMark, pair: _.clone(stuff.newPoW.pair), forcedTime: stuff.newPoW.forcedTime, - turnDuration: stuff.newPoW.turnDuration, conf: { medianTimeBlocks: stuff.newPoW.conf.medianTimeBlocks, avgGenTime: stuff.newPoW.conf.avgGenTime, diff --git a/app/modules/prover/lib/proof.ts b/app/modules/prover/lib/proof.ts index 9b15c0be5aaff08b078c5dd495dbb0432be983ea..02927aac80c5750b1a23c391480d98ae257358c4 100644 --- a/app/modules/prover/lib/proof.ts +++ b/app/modules/prover/lib/proof.ts @@ -6,15 +6,11 @@ import {ProverConstants} from "./constants" import {KeyGen} from "../../../lib/common-libs/crypto/keyring" import {dos2unix} from "../../../lib/common-libs/dos2unix" import {rawer} from "../../../lib/common-libs/index" +import {ProcessCpuProfiler} from "../../../ProcessCpuProfiler" const moment = require('moment'); const querablep = require('querablep'); -const PAUSES_PER_TURN = 5; - -// This value can be changed -let TURN_DURATION_IN_MILLISEC = 100; - let computing = querablep(Promise.resolve(null)); let askedStop = false; @@ -90,7 +86,6 @@ function beginNewProofOfWork(stuff:any) { prefix *= 100 * ProverConstants.NONCE_RANGE } const highMark = stuff.highMark; - const turnDuration = stuff.turnDuration || TURN_DURATION_IN_MILLISEC let sigFunc = null; if (signatureFunc && lastSecret === pair.sec) { sigFunc = signatureFunc; @@ -108,13 +103,17 @@ function beginNewProofOfWork(stuff:any) { let testsCount = 0; let found = false; - let score = 0; let turn = 0; + const profiler = new ProcessCpuProfiler(100) + let cpuUsage = profiler.cpuUsageOverLastMilliseconds(1) + // We limit the number of tests according to CPU usage + let testsPerRound = 1 + let turnDuration = 20 // We initially goes quickly to the max speed = 50 reevaluations per second (1000 / 20) while (!found && !askedStop) { /***************** - * A TURN + * A TURN ~ 100ms ****************/ await Promise.race([ @@ -125,26 +124,9 @@ function beginNewProofOfWork(stuff:any) { // II. Process the turn's PoW (async () => { - /***************** - * A TURN OF POW ~= 100ms by default - * -------------------- - * - * The concept of "turn" is required to limit the CPU usage. - * We need a time reference to have the speed = nb tests / period of time. - * Here we have: - * - * - speed = testsCount / turn - * - * We have taken 1 turn = 100ms to control the CPU usage after 100ms of PoW. This means that during the - * very first 100ms of the PoW, CPU usage = 100%. Then it becomes controlled to the %CPU set. - ****************/ - // Prove let i = 0; const thisTurn = turn; - const pausePeriod = score ? score / PAUSES_PER_TURN : 10; // number of pauses per turn - // We limit the number of tests according to CPU usage - const testsPerRound = score ? Math.floor(score * currentCPU) : 1000 * 1000 * 1000 // Time is updated regularly during the proof block.time = getBlockTime(block, conf, forcedTime) @@ -196,7 +178,7 @@ function beginNewProofOfWork(stuff:any) { if (!found && !askedStop) { i++; testsCount++; - if (i % pausePeriod === 0) { + if (i % testsPerRound === 0) { await countDown(0); // Very low pause, just the time to process eventual end of the turn } } @@ -208,12 +190,24 @@ function beginNewProofOfWork(stuff:any) { if (!found) { // CPU speed recording - if (turn > 0 && !score) { - score = testsCount; + if (turn > 0) { + const oldTestsPerRound = testsPerRound + cpuUsage = profiler.cpuUsageOverLastMilliseconds(turnDuration) + if (cpuUsage > currentCPU + 0.005 || cpuUsage < currentCPU - 0.005) { + let powVariationFactor + // powVariationFactor = currentCPU / (cpuUsage || 0.01) / 5 // divide by 2 to avoid extreme responses + if (currentCPU > cpuUsage) { + powVariationFactor = 1.01 + testsPerRound = Math.max(1, Math.ceil(testsPerRound * powVariationFactor)) + } else { + powVariationFactor = 0.99 + testsPerRound = Math.max(1, Math.floor(testsPerRound * powVariationFactor)) + } + } } /***************** - * UNLOAD CPU CHARGE + * UNLOAD CPU CHARGE FOR THIS TURN ****************/ // We wait for a maximum time of `turnDuration`. // This will trigger the end of the turn by the concurrent race I. During that time, the proof.js script @@ -226,6 +220,9 @@ function beginNewProofOfWork(stuff:any) { // Next turn turn++ + + turnDuration += 1 + turnDuration = Math.min(turnDuration, 1000) // Max 1 second per turn } /*****************