Use custom scripts for logging debug messages

Default "GLib.log_structured" method is painfully slow and time provided by it is not very accurate. It also slows down program execution even when G_MESSAGES_DEBUG env is not set. Use custom debug scripts for faster and more accurate messages logging instead.

clapper_src/debug.js

@@ -1,4 +1,25 @@
 const { GLib } = imports.gi;
+const { Debug } = imports.extras.debug;
+const { Ink } = imports.extras.ink;
+
+const G_DEBUG_ENV = GLib.getenv('G_MESSAGES_DEBUG');
+
+const clapperDebugger = new Debug.Debugger('Clapper', {
+    name_printer: new Ink.Printer({
+        font: Ink.Font.BOLD,
+        color: Ink.Color.MAGENTA
+    }),
+    time_printer: new Ink.Printer({
+        color: Ink.Color.ORANGE
+    }),
+    high_precision: true,
+});
+clapperDebugger.enabled = (
+    clapperDebugger.enabled
+    || G_DEBUG_ENV != null
+    && G_DEBUG_ENV.includes('Clapper')
+);
+const clapperDebug = clapperDebugger.debug;
 
 function debug(msg, levelName)
 {
@@ -8,6 +29,10 @@ function debug(msg, levelName)
         levelName = 'LEVEL_CRITICAL';
         msg = msg.message;
     }
+
+    if(levelName !== 'LEVEL_CRITICAL')
+        return clapperDebug(msg);
+
     GLib.log_structured(
         'Clapper', GLib.LogLevelFlags[levelName], {
             MESSAGE: msg,

extras/debug/Debug.js

@@ -0,0 +1,183 @@
+const { GLib } = imports.gi;
+
+let ink = { Ink: null };
+try {
+    ink = imports.ink;
+} catch(e) {}
+const { Ink } = ink;
+
+const DEBUG_ENV = GLib.getenv('DEBUG');
+
+var Debugger = class
+{
+    constructor(name, opts)
+    {
+        opts = (opts && typeof opts === 'object')
+            ? opts : {};
+
+        this.name = (name && typeof name === 'string')
+            ? name : 'GJS';
+
+        this.print_state = (opts.print_state)
+            ? true : false;
+
+        this.json_space = (typeof opts.json_space === 'number')
+            ? opts.json_space : 2;
+
+        this.name_printer    = opts.name_printer    || this._getInkPrinter(true);
+        this.message_printer = opts.message_printer || this._getDefaultPrinter();
+        this.time_printer    = opts.time_printer    || this._getInkPrinter();
+        this.high_precision  = opts.high_precision  || false;
+
+        if(typeof opts.color !== 'undefined')
+            this.color = opts.color;
+
+        this._isEnabled = false;
+        this._lastDebug = GLib.get_monotonic_time();
+
+        this.enabled = (typeof opts.enabled !== 'undefined')
+            ? opts.enabled : this._enabledAtStart;
+    }
+
+    get enabled()
+    {
+        return this._isEnabled;
+    }
+
+    set enabled(value)
+    {
+        if(this._isEnabled === value)
+            return;
+
+        this._isEnabled = (value) ? true : false;
+
+        if(!this.print_state)
+            return;
+
+        let state = (this.enabled) ? 'en' : 'dis';
+        this._runDebug(`debug ${state}abled`);
+    }
+
+    get color()
+    {
+        return this.name_printer.color;
+    }
+
+    set color(value)
+    {
+        this.name_printer.color = value;
+        this.time_printer.color = this.name_printer.color;
+    }
+
+    get debug()
+    {
+        return message => this._debug(message);
+    }
+
+    get _enabledAtStart()
+    {
+        if(!DEBUG_ENV)
+            return false;
+
+        let envArr = DEBUG_ENV.split(',');
+
+        return envArr.some(el => {
+            if(el === this.name || el === '*')
+                return true;
+
+            let searchType;
+            let offset = 0;
+
+            if(el.startsWith('*')) {
+                searchType = 'ends';
+            } else if(el.endsWith('*')) {
+                searchType = 'starts';
+                offset = 1;
+            }
+
+            if(!searchType)
+                return false;
+
+            return this.name[searchType + 'With'](
+                el.substring(1 - offset, el.length - offset)
+            );
+        });
+    }
+
+    _getInkPrinter(isBold)
+    {
+        if(!Ink)
+            return this._getDefaultPrinter();
+
+        let printer = new Ink.Printer({
+            color: Ink.colorFromText(this.name)
+        });
+
+        if(isBold)
+            printer.font = Ink.Font.BOLD;
+
+        return printer;
+    }
+
+    _getDefaultPrinter()
+    {
+        return {
+            getPainted: function() {
+                return Object.values(arguments);
+            }
+        };
+    }
+
+    _debug(message)
+    {
+        if(!this.enabled)
+            return;
+
+        this._runDebug(message);
+    }
+
+    _runDebug(message)
+    {
+        switch(typeof message) {
+            case 'string':
+                break;
+            case 'object':
+                if(
+                    message !== null
+                    && (message.constructor === Object
+                    || message.constructor === Array)
+                ) {
+                    message = JSON.stringify(message, null, this.json_space);
+                    break;
+                }
+            default:
+                message = String(message);
+                break;
+        }
+
+        let time = GLib.get_monotonic_time() - this._lastDebug;
+
+        if(!this.high_precision) {
+            time = (time < 1000)
+                ? '+0ms'
+                : (time < 1000000)
+                ? '+' + Math.floor(time / 1000) + 'ms'
+                : '+' + Math.floor(time / 1000000) + 's';
+        }
+        else {
+            time = (time < 1000)
+                ? '+' + time + 'µs'
+                : (time < 1000000)
+                ? '+' + (time / 1000).toFixed(3) + 'ms'
+                : '+' + (time / 1000000).toFixed(3) + 's';
+        }
+
+        printerr(
+            this.name_printer.getPainted(this.name),
+            this.message_printer.getPainted(message),
+            this.time_printer.getPainted(time)
+        );
+
+        this._lastDebug = GLib.get_monotonic_time();
+    }
+}

extras/ink/Ink.js

@@ -0,0 +1,322 @@
+const TERM_ESC = '\x1B[';
+const TERM_RESET = '0m';
+
+var maxTransparency = 128;
+
+var Font = {
+    VARIOUS: null,
+    REGULAR: 0,
+    BOLD: 1,
+    DIM: 2,
+    ITALIC: 3,
+    UNDERLINE: 4,
+    BLINK: 5,
+    REVERSE: 7,
+    HIDDEN: 8,
+    STRIKEOUT: 9,
+};
+
+var Color = {
+    VARIOUS: null,
+    DEFAULT: 39,
+    BLACK: 30,
+    RED: 31,
+    GREEN: 32,
+    YELLOW: 33,
+    BLUE: 34,
+    MAGENTA: 35,
+    CYAN: 36,
+    LIGHT_GRAY: 37,
+    DARK_GRAY: 90,
+    LIGHT_RED: 91,
+    LIGHT_GREEN: 92,
+    LIGHT_YELLOW: 93,
+    LIGHT_BLUE: 94,
+    LIGHT_MAGENTA: 95,
+    LIGHT_CYAN: 96,
+    WHITE: 97,
+    BROWN: colorFrom256(52),
+    LIGHT_BROWN: colorFrom256(130),
+    PINK: colorFrom256(205),
+    LIGHT_PINK: colorFrom256(211),
+    ORANGE: colorFrom256(208),
+    LIGHT_ORANGE: colorFrom256(214),
+    SALMON: colorFrom256(209),
+    LIGHT_SALMON: colorFrom256(216),
+};
+
+function colorFrom256(number)
+{
+    if(typeof number === 'undefined')
+        number = Math.floor(Math.random() * 256) + 1;
+
+    return `38;5;${number || 0}`;
+}
+
+function colorFromRGB(R, G, B, A)
+{
+    if(typeof R === 'undefined') {
+        R = Math.floor(Math.random() * 256);
+        G = Math.floor(Math.random() * 256);
+        B = Math.floor(Math.random() * 256);
+    }
+    else if(typeof G === 'undefined' && Array.isArray(R)) {
+        A = (R.length > 3) ? R[3] : 255;
+        B = (R.length > 2) ? R[2] : 0;
+        G = (R.length > 1) ? R[1] : 0;
+        R = (R.length > 0) ? R[0] : 0;
+    }
+
+    if(_getIsTransparent(A))
+        return Color.DEFAULT;
+
+    R = R || 0;
+    G = G || 0;
+    B = B || 0;
+
+    return `38;2;${R};${G};${B}`;
+}
+
+function colorFromHex(R, G, B, A)
+{
+    if((Array.isArray(R)))
+        R = R.join('');
+
+    let str = (typeof G === 'undefined')
+        ? String(R)
+        : (typeof A !== 'undefined')
+        ? String(R) + String(G) + String(B) + String(A)
+        : (typeof B !== 'undefined')
+        ? String(R) + String(G) + String(B)
+        : String(R) + String(G);
+
+    let offset = (str[0] === '#') ? 1 : 0;
+    let alphaIndex = 6 + offset;
+
+    while(str.length < alphaIndex)
+        str += '0';
+
+    A = (str.length > alphaIndex)
+        ? parseInt(str.substring(alphaIndex, alphaIndex + 2), 16)
+        : 255;
+    str = str.substring(offset, alphaIndex);
+
+    let colorInt = parseInt(str, 16);
+    let u8arr = new Uint8Array(3);
+
+    u8arr[2] = colorInt;
+    u8arr[1] = colorInt >> 8;
+    u8arr[0] = colorInt >> 16;
+
+    return colorFromRGB(u8arr[0], u8arr[1], u8arr[2], A);
+}
+
+function colorFromText(text)
+{
+    let value = _stringToDec(text);
+
+    /* Returns color from 1 to 221 every 10 */
+    return colorFrom256((value % 23) * 10 + 1);
+}
+
+function fontFromText(text)
+{
+    let arr = Object.keys(Font);
+    let value = _stringToDec(text);
+
+    /* Return a font excluding first (null) */
+    return Font[arr[value % (arr.length - 1) + 1]];
+}
+
+function _getIsImage(args)
+{
+    if(args.length !== 1)
+        return false;
+
+    let arg = args[0];
+    let argType = (typeof arg);
+
+    if(argType === 'string' || argType === 'number')
+        return false;
+
+    if(!Array.isArray(arg))
+        return false;
+
+    let depth = 2;
+    while(depth--) {
+        arg = arg[0];
+        if(!Array.isArray(arg))
+            return false;
+    }
+
+    return arg.some(val => val !== 'number');
+}
+
+function _getIsTransparent(A)
+{
+    return (typeof A !== 'undefined' && A <= maxTransparency);
+}
+
+function _stringToDec(str)
+{
+    str = str || '';
+
+    let len = str.length;
+    let total = 0;
+
+    while(len--)
+        total += Number(str.charCodeAt(len).toString(10));
+
+    return total;
+}
+
+var Printer = class
+{
+    constructor(opts)
+    {
+        opts = opts || {};
+
+        const defaults = {
+            font: Font.REGULAR,
+            color: Color.DEFAULT,
+            background: Color.DEFAULT
+        };
+
+        for(let def in defaults) {
+            this[def] = (typeof opts[def] !== 'undefined')
+                ? opts[def] : defaults[def];
+        }
+    }
+
+    print()
+    {
+        (_getIsImage(arguments))
+            ? this._printImage(arguments[0], 'stdout')
+            : print(this._getPaintedArgs(arguments));
+    }
+
+    printerr()
+    {
+        (_getIsImage(arguments))
+            ? this._printImage(arguments[0], 'stderr')
+            : printerr(this._getPaintedArgs(arguments));
+    }
+
+    getPainted()
+    {
+        return (_getIsImage(arguments))
+            ? this._printImage(arguments[0], 'return')
+            : this._getPaintedArgs(arguments);
+    }
+
+    get background()
+    {
+        return this._background;
+    }
+
+    set background(value)
+    {
+        let valueType = (typeof value);
+
+        if(valueType === 'string') {
+            value = (value[2] === ';')
+                ? '4' + value.substring(1)
+                : Number(value);
+        }
+        this._background = (valueType === 'object')
+            ? null
+            : (value < 40 || value >= 90 && value < 100)
+            ? value + 10
+            : value;
+    }
+
+    _getPaintedArgs(args)
+    {
+        let str = '';
+
+        for(let arg of args) {
+            if(Array.isArray(arg))
+                arg = arg.join(',');
+
+            let painted = this._getPaintedString(arg);
+            str += (str.length) ? ' ' + painted : painted;
+        }
+
+        return str;
+    }
+
+    _getPaintedString(text, noReset)
+    {
+        let str = TERM_ESC;
+
+        for(let option of ['font', 'color', '_background']) {
+            let optionType = (typeof this[option]);
+            str += (optionType === 'number' || optionType === 'string')
+                ? this[option]
+                : (option === 'font' && Array.isArray(this[option]))
+                ? this[option].join(';')
+                : (option === 'font')
+                ? fontFromText(text)
+                : colorFromText(text);
+
+            str += (option !== '_background') ? ';' : 'm';
+        }
+        str += text;
+
+        return (noReset)
+            ? str
+            : (str + TERM_ESC + TERM_RESET);
+    }
+
+    _printImage(pixelsArr, output)
+    {
+        let total = '';
+        let prevColor = this.color;
+        let prevBackground = this._background;
+
+        for(let row of pixelsArr) {
+            let paintedLine = '';
+            let block = '  ';
+
+            for(let i = 0; i < row.length; i++) {
+                let pixel = row[i];
+                let nextPixel = (i < row.length - 1) ? row[i + 1] : null;
+
+                if(nextPixel && pixel.every((value, index) =>
+                    value === nextPixel[index]
+                )) {
+                    block += '  ';
+                    continue;
+                }
+                /* Do not use predefined functions here (it would impact performance) */
+                let isTransparent = (pixel.length >= 3) ? _getIsTransparent(pixel[3]) : false;
+                this.color = (isTransparent)
+                    ? Color.DEFAULT
+                    : `38;2;${pixel[0]};${pixel[1]};${pixel[2]}`;
+                this._background = (isTransparent)
+                    ? Color.DEFAULT
+                    : `48;2;${pixel[0]};${pixel[1]};${pixel[2]}`;
+                paintedLine += `${TERM_ESC}0;${this.color};${this._background}m${block}`;
+                block = '  ';
+            }
+            paintedLine += TERM_ESC + TERM_RESET;
+
+            switch(output) {
+                case 'stderr':
+                    printerr(paintedLine);
+                    break;
+                case 'return':
+                    total += paintedLine + '\n';
+                    break;
+                default:
+                    print(paintedLine);
+                    break;
+            }
+        }
+
+        this.color = prevColor;
+        this._background = prevBackground;
+
+        return total;
+    }
+}

meson.build

@@ -21,6 +21,7 @@ subdir('data')
 
 installdir = join_paths(get_option('prefix'), 'share', meson.project_name())
 install_subdir('clapper_src', install_dir : installdir)
+install_subdir('extras', install_dir : installdir)
 install_subdir('css', install_dir : installdir)
 install_subdir('ui', install_dir : installdir)