/**
 * Logger
 *
 * @author Alain Pitiot
 * @version 2021.1.0
 * @copyright (c) 2017-2020 Ilixa Ltd. (http://ilixa.com) (c) 2020 Open Science Tools Ltd. (https://opensciencetools.org)
 * @license Distributed under the terms of the MIT License
 */


import * as util from '../util/Util';
import {MonotonicClock} from '../util';
import {ExperimentHandler} from '../data';


/**
 * <p>This class handles a variety of loggers, e.g. a browser console one (mostly for debugging),
 * a remote one, etc.</p>
 *
 * <p>Note: we use log4javascript for the console logger, and our own for the server logger.</p>
 *
 * @name module:core.Logger
 * @class
 * @param {*} threshold - the logging threshold, e.g. log4javascript.Level.ERROR
 */
export class Logger
{

	constructor(psychoJS, threshold)
	{
		this._psychoJS = psychoJS;

		// browser console logger:
		this.consoleLogger = log4javascript.getLogger('psychojs');

		const appender = new log4javascript.BrowserConsoleAppender();
		appender.setLayout(this._customConsoleLayout());
		appender.setThreshold(threshold);

		this.consoleLogger.addAppender(appender);
		this.consoleLogger.setLevel(threshold);


		// 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
		};
	}



	/**
	 * Change the logging level.
	 *
	 * @name module:core.Logger#setLevel
	 * @public
	 * @param {module:core.Logger.ServerLevel} serverLevel - the new logging level
	 */
	setLevel(serverLevel)
	{
		this._serverLevel = serverLevel;
		this._serverLevelValue = this._getValue(this._serverLevel);
	}



	/**
	 * Log a server message at the EXP level.
	 *
	 * @name module:core.Logger#exp
	 * @public
	 * @param {string} msg - the message to be logged.
	 * @param {number} [time] - the logging time
	 * @param {object} [obj] - the associated object (e.g. a Trial)
	 */
	exp(msg, time, obj)
	{
		this.log(msg, Logger.ServerLevel.EXP, time, obj);
	}



	/**
	 * Log a server message at the DATA level.
	 *
	 * @name module:core.Logger#data
	 * @public
	 * @param {string} msg - the message to be logged.
	 * @param {number} [time] - the logging time
	 * @param {object} [obj] - the associated object (e.g. a Trial)
	 */
	data(msg, time, obj)
	{
		this.log(msg, Logger.ServerLevel.DATA, time, obj);
	}



	/**
	 * Log a server message.
	 *
	 * @name module:core.Logger#log
	 * @public
	 * @param {string} msg - the message to be logged.
	 * @param {module:core.Logger.ServerLevel} level - logging level
	 * @param {number} [time] - the logging time
	 * @param {object} [obj] - the associated object (e.g. a Trial)
	 */
	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 = `<p>[time= ${time.toFixed(3)}] More than ${this._throttling.threshold} messages were logged in the past ${this._throttling.window}s.</p>` +
						`<p>We are now throttling: only 1 in ${this._throttling.factor} messages will be logged.</p>` +
						`<p>You may want to change your experiment's logging level. Please see <a href="https://www.psychopy.org/api/logging.html">psychopy.org/api/logging.html</a> for details.</p>`;

					// 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;
	}



	/**
	 * Flush all server logs to the server.
	 *
	 * <p>Note: the logs are compressed using Pako's zlib algorithm.
	 * See https://github.com/nodeca/pako for details.</p>
	 *
	 * @name module:core.Logger#flush
	 * @public
	 */
	async flush()
	{
		const response = {
			origin: 'Logger.flush',
			context: 'when flushing participant\'s logs for experiment: ' + this._psychoJS.config.experiment.fullpath
		};

		this._psychoJS.logger.info('[PsychoJS] Flush server logs.');

		// prepare the formatted logs:
		let formattedLogs = '';
		for (const log of this._serverLogs)
		{
			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;
		}

		// send logs to the server or display them in the console:
		if (this._psychoJS.getEnvironment() === ExperimentHandler.Environment.SERVER &&
			this._psychoJS.config.experiment.status === 'RUNNING' &&
			!this._psychoJS._serverMsg.has('__pilotToken'))
		{
			// if the pako compression library is present, we compress the logs:
			if (typeof pako !== 'undefined')
			{
				try
				{
					const utf16DeflatedLogs = pako.deflate(formattedLogs, {to: 'string'});
					// const utf16DeflatedLogs = pako.deflate(unescape(encodeURIComponent(formattedLogs)), {to: 'string'});
					const base64DeflatedLogs = btoa(utf16DeflatedLogs);

					return await this._psychoJS.serverManager.uploadLog(base64DeflatedLogs, true);
				}
				catch (error)
				{
					console.error('log compression error:', error);
					throw Object.assign(response, {error: error});
				}
			}
			else
			// the pako compression library is not present, we do not compress the logs:
			{
				return await this._psychoJS.serverManager.uploadLog(formattedLogs, false);
			}
		}
		else
		{
			this._psychoJS.logger.debug('\n' + formattedLogs);
		}
	}



	/**
	 * Create a custom console layout.
	 *
	 * @name module:core.Logger#_customConsoleLayout
	 * @private
	 * @return {*} the custom layout
	 */
	_customConsoleLayout()
	{
		const detectedBrowser = this._psychoJS.browser;

		const customLayout = new log4javascript.PatternLayout("%p %f{1} | %m");
		customLayout.setCustomField('location', function (layout, loggingReference)
		{
			// we throw a fake exception to retrieve the stack trace
			try
			{
				// (0)();
				throw Error('fake exception');
			}
			catch (e)
			{
				const stackEntries = e.stack.replace(/^.*?\n/, '').replace(/(?:\n@:0)?\s+$/m, '').replace(/^\(/gm, '{anon}(').split("\n");

				let relevantEntry;
				if (detectedBrowser === 'Firefox')
				{
					// look for entry immediately after those of log4javascript:
					for (let entry of stackEntries)
					{
						if (entry.indexOf('log4javascript.min.js') <= 0)
						{
							relevantEntry = entry;
							break;
						}
					}

					const buf = relevantEntry.split(':');
					const line = buf[buf.length - 2];
					const file = buf[buf.length - 3].split('/').pop();
					const method = relevantEntry.split('@')[0];

					return method + ' ' + file + ' ' + line;
				}
				else if (detectedBrowser === 'Safari')
				{
					return 'unknown';
				}
				else if (detectedBrowser === 'Chrome')
				{
					relevantEntry = stackEntries.pop();

					let buf = relevantEntry.split(' ');
					let fileLine = buf.pop();
					const method = buf.pop();
					buf = fileLine.split(':');
					buf.pop();
					const line = buf.pop();
					const file = buf.pop().split('/').pop();

					return method + ' ' + file + ' ' + line;
				}
				else
				{
					return 'unknown';
				}
			}
		});

		return customLayout;
	}



	/**
	 * Get the integer value associated with a logging level.
	 *
	 * @name module:core.Logger#_getValue
	 * @protected
	 * @param {module:core.Logger.ServerLevel} level - the logging level
	 * @return {number} - the value associated with the logging level, or 30 is the logging level is unknown.
	 */
	_getValue(level)
	{
		const levelAsString = Symbol.keyFor(level);
		return (levelAsString in Logger._ServerLevelValue) ? Logger._ServerLevelValue[levelAsString] : 30;
	}
}



/**
 * Server logging level.
 *
 * @name module:core.Logger#ServerLevel
 * @enum {Symbol}
 * @readonly
 * @public
 *
 * @note These are similar to PsychoPy's logging levels, as defined in logging.py
 */
Logger.ServerLevel = {
	CRITICAL: Symbol.for('CRITICAL'),
	ERROR: Symbol.for('ERROR'),
	WARNING: Symbol.for('WARNING'),
	DATA: Symbol.for('DATA'),
	EXP: Symbol.for('EXP'),
	INFO: Symbol.for('INFO'),
	DEBUG: Symbol.for('DEBUG'),
	NOTSET: Symbol.for('NOTSET')
};


/**
 * Server logging level values.
 *
 * <p>We use those values to determine whether a log is to be sent to the server or not.</p>
 *
 * @name module:core.Logger#_ServerLevelValue
 * @enum {number}
 * @readonly
 * @protected
 */
Logger._ServerLevelValue = {
	'CRITICAL': 50,
	'ERROR': 40,
	'WARNING': 30,
	'DATA': 25,
	'EXP': 22,
	'INFO': 20,
	'DEBUG': 10,
	'NOTSET': 0
};