From 6a41ea779cce385dd18864003ff80f528fae1664 Mon Sep 17 00:00:00 2001 From: Alain Pitiot Date: Wed, 23 Dec 2020 15:14:33 +0100 Subject: [PATCH] put in place throttling of log messages, to be activated soon --- js/core/Logger.js | 141 ++++++++++++++++++++++++++++++++++++++------ js/core/PsychoJS.js | 13 ++-- js/core/Window.js | 6 +- js/visual/Slider.js | 2 +- 4 files changed, 134 insertions(+), 28 deletions(-) diff --git a/js/core/Logger.js b/js/core/Logger.js index 1015dca..1c57dd7 100644 --- a/js/core/Logger.js +++ b/js/core/Logger.js @@ -9,8 +9,8 @@ import * as util from '../util/Util'; -import {MonotonicClock} from '../util/Clock'; -import {ExperimentHandler} from '../data/ExperimentHandler'; +import {MonotonicClock} from '../util'; +import {ExperimentHandler} from '../data'; /** @@ -44,6 +44,28 @@ export class Logger // server logger: this._serverLogs = []; this._serverLevel = Logger.ServerLevel.WARNING; + this._serverLevelValue = this._getValue(this._serverLevel); + + // throttling of server logs + this._throttling = { + // period of time (in seconds) over which we consider the number of logged messages: + window: 1, + // threshold (i.e. number of messages over the throttling window) at which point + // we start throttling: + threshold: 20, + // throttling factor: 10 -> only 1 in 10 messages is logged + factor: 10, + // minimum duration (in seconds) of throttling + minimumDuration: 2, + // time at which throttling started: + startOfThrottling: 0, + // whether or not we are currently throttling: + isThrottling: false, + // throttling message index: + index: 0, + // whether or not the designer has already been warned: + designerWasWarned: false + }; } @@ -58,6 +80,7 @@ export class Logger setLevel(serverLevel) { this._serverLevel = serverLevel; + this._serverLevelValue = this._getValue(this._serverLevel); } @@ -106,18 +129,106 @@ export class Logger */ log(msg, level, time, obj) { + // only log if the level is higher or equal to the previously defined server level: + const levelValue = this._getValue(level); + if (levelValue < this._serverLevelValue) + { + return; + } + if (typeof time === 'undefined') { time = MonotonicClock.getReferenceTime(); } + /* [coming soon] + // check whether we need to throttle: + if (this._throttle(time)) + { + return; + } + */ + this._serverLogs.push({ msg, level, time, obj: util.toString(obj) }); + } + + + /** + * Check whether or not a log messages must be throttled. + * + * @name module:core.Logger#_throttle + * @protected + * + * @param {number} time - the time of the latest log message + * @return {boolean} whether or not to log the message + */ + _throttle(time) + { + // if more messages than this._throttling.threshold have been logged between + // time and the start of the throttling window, we need to throttle: + if (this._serverLogs.length > this._throttling.threshold) + { + const timeAtStartThrottlingWindow = this._serverLogs[this._serverLogs.length - 1 - this._throttling.threshold].time; + if (time - timeAtStartThrottlingWindow < this._throttling.window) + { + // warn the designer if we are not already throttling: + if (!this._throttling.isThrottling) + { + const msg = `

[time= ${time.toFixed(3)}] More than ${this._throttling.threshold} messages were logged in the past ${this._throttling.window}s.

` + + `

We are now throttling: only 1 in ${this._throttling.factor} messages will be logged.

` + + `

You may want to change your experiment's logging level. Please see psychopy.org/api/logging.html for details.

`; + + // console warning: + this._psychoJS.logger.warn(msg); + + // in PILOTING mode and locally, we also warn the experimenter with a dialog box, + // but only once: + if (!this._throttling.designerWasWarned && + (this._psychoJS.getEnvironment() === ExperimentHandler.Environment.LOCAL || + this._psychoJS.config.experiment.status === 'PILOTING')) + { + this._throttling.designerWasWarned = true; + + this._psychoJS.gui.dialog({ + warning: msg, + showOK: true + }); + } + + this._throttling.isThrottling = true; + this._throttling.startOfThrottling = time; + this._throttling.index = 0; + } + + ++ this._throttling.index; + if (this._throttling.index < this._throttling.factor) + { + // no logging + return true; + } + else + { + this._throttling.index = 0; + } + } + else + { + if (this._throttling.isThrottling && + (time - this._throttling.startOfThrottling) > this._throttling.minimumDuration) + { + this._psychoJS.logger.info(`[time= ${time.toFixed(3)}] Log messages are not throttled any longer.`); + this._throttling.isThrottling = false; + } + } + } + + return false; } @@ -140,28 +251,20 @@ export class Logger this._psychoJS.logger.info('[PsychoJS] Flush server logs.'); - // server level value: - const serverLevelValue = this._getValue(this._serverLevel); - - // prepare formatted logs: + // prepare the formatted logs: let formattedLogs = ''; for (const log of this._serverLogs) { - // we add the log message only if its level is >= _serverLevel - const levelValue = this._getValue(log.level); - if (levelValue >= serverLevelValue) + let formattedLog = util.toString(log.time) + + '\t' + Symbol.keyFor(log.level) + + '\t' + log.msg; + if (log.obj !== 'undefined') { - let formattedLog = util.toString(log.time) + - '\t' + Symbol.keyFor(log.level) + - '\t' + log.msg; - if (log.obj !== 'undefined') - { - formattedLog += '\t' + log.obj; - } - formattedLog += '\n'; - - formattedLogs += formattedLog; + formattedLog += '\t' + log.obj; } + formattedLog += '\n'; + + formattedLogs += formattedLog; } // send logs to the server or display them in the console: diff --git a/js/core/PsychoJS.js b/js/core/PsychoJS.js index b98fb0b..ce5910f 100644 --- a/js/core/PsychoJS.js +++ b/js/core/PsychoJS.js @@ -353,8 +353,8 @@ export class PsychoJS window.addEventListener('beforeunload', this.beforeunloadCallback); - // when the user closes the tab or browser, we attempt to close the session, optionally save the results, - // and release the WebGL context + // when the user closes the tab or browser, we attempt to close the session, + // optionally save the results, and release the WebGL context // note: we communicate with the server using the Beacon API const self = this; window.addEventListener('unload', (event) => @@ -546,7 +546,10 @@ export class PsychoJS */ async _configure(configURL, name) { - const response = {origin: 'PsychoJS.configure', context: 'when configuring PsychoJS for the experiment'}; + const response = { + origin: 'PsychoJS.configure', + context: 'when configuring PsychoJS for the experiment' + }; try { @@ -559,8 +562,8 @@ export class PsychoJS const serverResponse = await this._serverManager.getConfiguration(configURL); this._config = serverResponse.config; - // legacy experiments had a psychoJsManager block instead of a pavlovia block, and the URL - // pointed to https://pavlovia.org/server + // legacy experiments had a psychoJsManager block instead of a pavlovia block, + // and the URL pointed to https://pavlovia.org/server if ('psychoJsManager' in this._config) { delete this._config.psychoJsManager; diff --git a/js/core/Window.js b/js/core/Window.js index de6ba7b..01c9959 100644 --- a/js/core/Window.js +++ b/js/core/Window.js @@ -7,9 +7,9 @@ * @license Distributed under the terms of the MIT License */ -import {Color} from '../util/Color'; -import {PsychObject} from '../util/PsychObject'; -import {MonotonicClock} from '../util/Clock'; +import {Color} from '../util'; +import {PsychObject} from '../util'; +import {MonotonicClock} from '../util'; import {Logger} from "./Logger"; /** diff --git a/js/visual/Slider.js b/js/visual/Slider.js index 8485a70..6e540e6 100644 --- a/js/visual/Slider.js +++ b/js/visual/Slider.js @@ -423,7 +423,7 @@ export class Slider extends util.mix(VisualStim).with(ColorMixin, WindowMixin) { const tickPositionIndex = Math.round( l / (this._labels.length - 1) * (this._ticks.length - 1) ); this._labelPositions_px[l] = this._tickPositions_px[tickPositionIndex]; - const labelBounds = PIXI.TextMetrics.measureText(this._labels[l], labelTextStyle); + const labelBounds = PIXI.TextMetrics.measureText(this._labels[l].toString(), labelTextStyle); // horizontal slider: if (this._isHorizontal())