Merge pull request #4687 from Tyriar/tracing

Add trace log level, @traceCall decorator and use in webgl

addons/xterm-addon-webgl/src/GlyphRenderer.ts

@@ -11,6 +11,8 @@ import { IRasterizedGlyph, IRenderDimensions, ITextureAtlas } from 'browser/rend
 import { Disposable, toDisposable } from 'common/Lifecycle';
 import { throwIfFalsy } from 'browser/renderer/shared/RendererUtils';
 import { TextureAtlas } from 'browser/renderer/shared/TextureAtlas';
+import { ILogService } from 'common/services/Services';
+import { traceCall } from 'common/services/LogService';
 
 interface IVertices {
   attributes: Float32Array;
@@ -212,6 +214,7 @@ export class GlyphRenderer extends Disposable {
     return this._atlas ? this._atlas.beginFrame() : true;
   }
 
+  @traceCall
   public updateCell(x: number, y: number, code: number, bg: number, fg: number, ext: number, chars: string, lastBg: number): void {
     // Since this function is called for every cell (`rows*cols`), it must be very optimized. It
     // should not instantiate any variables unless a new glyph is drawn to the cache where the

addons/xterm-addon-webgl/src/WebglAddon.ts

@@ -8,9 +8,10 @@ import { ITerminal } from 'browser/Types';
 import { EventEmitter, forwardEvent } from 'common/EventEmitter';
 import { Disposable, toDisposable } from 'common/Lifecycle';
 import { getSafariVersion, isSafari } from 'common/Platform';
-import { ICoreService, IDecorationService, IOptionsService } from 'common/services/Services';
+import { ICoreService, IDecorationService, ILogService, IOptionsService } from 'common/services/Services';
 import { ITerminalAddon, Terminal } from 'xterm';
 import { WebglRenderer } from './WebglRenderer';
+import { setTraceLogger } from 'common/services/LogService';
 
 export class WebglAddon extends Disposable implements ITerminalAddon {
   private _terminal?: Terminal;
@@ -51,8 +52,13 @@ export class WebglAddon extends Disposable implements ITerminalAddon {
     const charSizeService: ICharSizeService = unsafeCore._charSizeService;
     const coreBrowserService: ICoreBrowserService = unsafeCore._coreBrowserService;
     const decorationService: IDecorationService = unsafeCore._decorationService;
+    const logService: ILogService = unsafeCore._logService;
     const themeService: IThemeService = unsafeCore._themeService;
 
+    // Set trace logger just in case it hasn't been yet which could happen when the addon is
+    // bundled separately to the core module
+    setTraceLogger(logService);
+
     this._renderer = this.register(new WebglRenderer(
       terminal,
       characterJoinerService,

addons/xterm-addon-webgl/src/WebglRenderer.ts

@@ -17,7 +17,7 @@ import { CellData } from 'common/buffer/CellData';
 import { Attributes, Content, NULL_CELL_CHAR, NULL_CELL_CODE } from 'common/buffer/Constants';
 import { EventEmitter, forwardEvent } from 'common/EventEmitter';
 import { Disposable, getDisposeArrayDisposable, toDisposable } from 'common/Lifecycle';
-import { ICoreService, IDecorationService, IOptionsService } from 'common/services/Services';
+import { ICoreService, IDecorationService, ILogService, IOptionsService } from 'common/services/Services';
 import { CharData, IBufferLine, ICellData } from 'common/Types';
 import { IDisposable, Terminal } from 'xterm';
 import { GlyphRenderer } from './GlyphRenderer';
@@ -27,6 +27,7 @@ import { LinkRenderLayer } from './renderLayer/LinkRenderLayer';
 import { IRenderLayer } from './renderLayer/Types';
 import { COMBINED_CHAR_BIT_MASK, RenderModel, RENDER_MODEL_BG_OFFSET, RENDER_MODEL_EXT_OFFSET, RENDER_MODEL_FG_OFFSET, RENDER_MODEL_INDICIES_PER_CELL } from './RenderModel';
 import { IWebGL2RenderingContext } from './Types';
+import { traceCall } from 'common/services/LogService';
 
 export class WebglRenderer extends Disposable implements IRenderer {
   private _renderLayers: IRenderLayer[];
@@ -323,6 +324,7 @@ export class WebglRenderer extends Disposable implements IRenderer {
     return false;
   }
 
+  @traceCall
   public renderRows(start: number, end: number): void {
     if (!this._isAttached) {
       if (this._coreBrowserService.window.document.body.contains(this._core.screenElement!) && this._charSizeService.width && this._charSizeService.height) {

addons/xterm-addon-webgl/src/tsconfig.json

@@ -21,6 +21,7 @@
     },
     "strict": true,
     "downlevelIteration": true,
+    "experimentalDecorators": true,
     "types": [
       "../../../node_modules/@types/mocha"
     ]

demo/client.ts

@@ -424,7 +424,7 @@ function initOptions(term: TerminalType): void {
     fontFamily: null,
     fontWeight: ['normal', 'bold', '100', '200', '300', '400', '500', '600', '700', '800', '900'],
     fontWeightBold: ['normal', 'bold', '100', '200', '300', '400', '500', '600', '700', '800', '900'],
-    logLevel: ['debug', 'info', 'warn', 'error', 'off'],
+    logLevel: ['trace', 'debug', 'info', 'warn', 'error', 'off'],
     theme: ['default', 'xtermjs', 'sapphire', 'light'],
     wordSeparator: null
   };
@@ -1227,7 +1227,7 @@ Test BG-colored Erase (BCE):
   for all cells to the right.
 
  def   41   42   43   44   45   46   47\x1b[47m
-\x1b[m     \x1b[41m     \x1b[42m     \x1b[43m     \x1b[44m     \x1b[45m     \x1b[46m     \x1b[47m     
+\x1b[m     \x1b[41m     \x1b[42m     \x1b[43m     \x1b[44m     \x1b[45m     \x1b[46m     \x1b[47m
 \x1b[m\x1b[5X\x1b[41m\x1b[5C\x1b[5X\x1b[42m\x1b[5C\x1b[5X\x1b[43m\x1b[5C\x1b[5X\x1b[44m\x1b[5C\x1b[5X\x1b[45m\x1b[5C\x1b[5X\x1b[46m\x1b[5C\x1b[5X\x1b[47m\x1b[5C\x1b[5X\x1b[m
 `;
   term.write(data.split('\n').join('\r\n'));
@@ -1263,7 +1263,7 @@ function initImageAddonExposed(): void {
       term.write('\r\n');
       term.write(new Uint8Array(buffer));
     });
-  
+
   const iip_demo = (url: string) => () => fetch(url)
   .then(resp => resp.arrayBuffer())
   .then(buffer => {

src/browser/renderer/shared/TextureAtlas.ts

@@ -16,6 +16,7 @@ import { IdleTaskQueue } from 'common/TaskQueue';
 import { IBoundingBox, ICharAtlasConfig, IRasterizedGlyph, IRequestRedrawEvent, ITextureAtlas } from 'browser/renderer/shared/Types';
 import { EventEmitter } from 'common/EventEmitter';
 import { IColorContrastCache } from 'browser/Types';
+import { traceCall } from 'common/services/LogService';
 
 /**
  * A shared object which is used to draw nothing for a particular cell.
@@ -425,6 +426,7 @@ export class TextureAtlas implements ITextureAtlas {
     return this._config.colors.contrastCache;
   }
 
+  @traceCall
   private _drawToCache(codeOrChars: number | string, bg: number, fg: number, ext: number, restrictToCellHeight: boolean = false): IRasterizedGlyph {
     const chars = typeof codeOrChars === 'number' ? String.fromCharCode(codeOrChars) : codeOrChars;
 

src/common/TestUtils.test.ts

@@ -104,6 +104,7 @@ export class MockCoreService implements ICoreService {
 export class MockLogService implements ILogService {
   public serviceBrand: any;
   public logLevel = LogLevelEnum.DEBUG;
+  public trace(message: any, ...optionalParams: any[]): void { }
   public debug(message: any, ...optionalParams: any[]): void { }
   public info(message: any, ...optionalParams: any[]): void { }
   public warn(message: any, ...optionalParams: any[]): void { }

src/common/services/LogService.ts

@@ -21,6 +21,7 @@ interface IConsole {
 declare const console: IConsole;
 
 const optionsKeyToLogLevel: { [key: string]: LogLevelEnum } = {
+  trace: LogLevelEnum.TRACE,
   debug: LogLevelEnum.DEBUG,
   info: LogLevelEnum.INFO,
   warn: LogLevelEnum.WARN,
@@ -42,6 +43,9 @@ export class LogService extends Disposable implements ILogService {
     super();
     this._updateLogLevel();
     this.register(this._optionsService.onSpecificOptionChange('logLevel', () => this._updateLogLevel()));
+
+    // For trace logging, assume the latest created log service is valid
+    traceLogger = this;
   }
 
   private _updateLogLevel(): void {
@@ -61,6 +65,12 @@ export class LogService extends Disposable implements ILogService {
     type.call(console, (this._optionsService.options.logger ? '' : LOG_PREFIX) + message, ...optionalParams);
   }
 
+  public trace(message: string, ...optionalParams: any[]): void {
+    if (this._logLevel <= LogLevelEnum.TRACE) {
+      this._log(this._optionsService.options.logger?.trace.bind(this._optionsService.options.logger) ?? console.log, message, optionalParams);
+    }
+  }
+
   public debug(message: string, ...optionalParams: any[]): void {
     if (this._logLevel <= LogLevelEnum.DEBUG) {
       this._log(this._optionsService.options.logger?.debug.bind(this._optionsService.options.logger) ?? console.log, message, optionalParams);
@@ -85,3 +95,30 @@ export class LogService extends Disposable implements ILogService {
     }
   }
 }
+
+let traceLogger: ILogService;
+export function setTraceLogger(logger: ILogService): void {
+  traceLogger = logger;
+}
+
+/**
+ * A decorator that can be used to automatically log trace calls to the decorated function.
+ */
+export function traceCall(_target: any, key: string, descriptor: any): any {
+  if (typeof descriptor.value !== 'function') {
+    throw new Error('not supported');
+  }
+  const fnKey = 'value';
+  const fn = descriptor.value;
+  descriptor[fnKey] = function (...args: any[]) {
+    // Early exit
+    if (traceLogger.logLevel !== LogLevelEnum.TRACE) {
+      return fn.apply(this, args);
+    }
+
+    traceLogger.trace(`GlyphRenderer#${fn.name}(${args.map(e => JSON.stringify(e)).join(', ')})`);
+    const result = fn.apply(this, args);
+    traceLogger.trace(`GlyphRenderer#${fn.name} return`, result);
+    return result;
+  };
+}

src/common/services/Services.ts

@@ -142,11 +142,12 @@ export interface IInstantiationService {
 }
 
 export enum LogLevelEnum {
-  DEBUG = 0,
-  INFO = 1,
-  WARN = 2,
-  ERROR = 3,
-  OFF = 4
+  TRACE = 0,
+  DEBUG = 1,
+  INFO = 2,
+  WARN = 3,
+  ERROR = 4,
+  OFF = 5
 }
 
 export const ILogService = createDecorator<ILogService>('LogService');
@@ -155,6 +156,7 @@ export interface ILogService {
 
   readonly logLevel: LogLevelEnum;
 
+  trace(message: any, ...optionalParams: any[]): void;
   debug(message: any, ...optionalParams: any[]): void;
   info(message: any, ...optionalParams: any[]): void;
   warn(message: any, ...optionalParams: any[]): void;
@@ -201,7 +203,7 @@ export interface IOptionsService {
 }
 
 export type FontWeight = 'normal' | 'bold' | '100' | '200' | '300' | '400' | '500' | '600' | '700' | '800' | '900' | number;
-export type LogLevel = 'debug' | 'info' | 'warn' | 'error' | 'off';
+export type LogLevel = 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'off';
 
 export interface ITerminalOptions {
   allowProposedApi?: boolean;

typings/xterm-headless.d.ts

@@ -11,7 +11,7 @@ declare module 'xterm-headless' {
   /**
    * A string representing log level.
    */
-  export type LogLevel = 'debug' | 'info' | 'warn' | 'error' | 'off';
+  export type LogLevel = 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'off';
 
   /**
    * An object containing options for the terminal.
@@ -100,11 +100,12 @@ declare module 'xterm-headless' {
      * What log level to use, this will log for all levels below and including
      * what is set:
      *
-     * 1. debug
-     * 2. info (default)
-     * 3. warn
-     * 4. error
-     * 5. off
+     * 1. trace
+     * 2. debug
+     * 3. info (default)
+     * 4. warn
+     * 5. error
+     * 6. off
      */
     logLevel?: LogLevel;
 
@@ -314,9 +315,14 @@ declare module 'xterm-headless' {
    * A replacement logger for `console`.
    */
   export interface ILogger {
+    /**
+     * Log a trace message, this will only be called if
+     * {@link ITerminalOptions.logLevel} is set to trace.
+     */
+    trace(message: string, ...args: any[]): void;
     /**
      * Log a debug message, this will only be called if
-     * {@link ITerminalOptions.logLevel} is set to debug.
+     * {@link ITerminalOptions.logLevel} is set to debug or below.
      */
     debug(message: string, ...args: any[]): void;
     /**

typings/xterm.d.ts

@@ -18,7 +18,7 @@ declare module 'xterm' {
   /**
    * A string representing log level.
    */
-  export type LogLevel = 'debug' | 'info' | 'warn' | 'error' | 'off';
+  export type LogLevel = 'trace' | 'debug' | 'info' | 'warn' | 'error' | 'off';
 
   /**
    * An object containing options for the terminal.
@@ -158,11 +158,12 @@ declare module 'xterm' {
      * What log level to use, this will log for all levels below and including
      * what is set:
      *
-     * 1. debug
-     * 2. info (default)
-     * 3. warn
-     * 4. error
-     * 5. off
+     * 1. trace
+     * 2. debug
+     * 3. info (default)
+     * 4. warn
+     * 5. error
+     * 6. off
      */
     logLevel?: LogLevel;
 
@@ -391,9 +392,14 @@ declare module 'xterm' {
    * A replacement logger for `console`.
    */
   export interface ILogger {
+    /**
+     * Log a trace message, this will only be called if
+     * {@link ITerminalOptions.logLevel} is set to trace.
+     */
+    trace(message: string, ...args: any[]): void;
     /**
      * Log a debug message, this will only be called if
-     * {@link ITerminalOptions.logLevel} is set to debug.
+     * {@link ITerminalOptions.logLevel} is set to debug or below.
      */
     debug(message: string, ...args: any[]): void;
     /**