Skip to content

Commit

Permalink
feat: Log once utilities for easy logging in loops
Browse files Browse the repository at this point in the history
  • Loading branch information
eonarheim committed Jan 20, 2024
1 parent ff73735 commit 2bbc25a
Show file tree
Hide file tree
Showing 12 changed files with 147 additions and 51 deletions.
6 changes: 6 additions & 0 deletions CHANGELOG.md
Original file line number Diff line number Diff line change
Expand Up @@ -17,6 +17,12 @@ This project adheres to [Semantic Versioning](http://semver.org/).

### Added

- Added the ability to log a message once to all log levels
* `debugOnce`
* `infoOnce`
* `warnOnce`
* `errorOnce`
* `fatalOnce`
- Added ability to load additional images into `ex.Material`s!
```typescript
const noise = new ex.ImageSource('./noise.avif');
Expand Down
7 changes: 2 additions & 5 deletions src/engine/Graphics/Context/ExcaliburGraphicsContextWebGL.ts
Original file line number Diff line number Diff line change
Expand Up @@ -290,14 +290,11 @@ export class ExcaliburGraphicsContextWebGL implements ExcaliburGraphicsContext {
this._isDrawLifecycle = false;
}

private _alreadyWarnedDrawLifecycle = false;

public draw<TRenderer extends RendererPlugin>(rendererName: TRenderer['type'], ...args: Parameters<TRenderer['draw']>) {
if (!this._isDrawLifecycle && !this._alreadyWarnedDrawLifecycle) {
this._logger.warn(
if (!this._isDrawLifecycle) {
this._logger.warnOnce(
`Attempting to draw outside the the drawing lifecycle (preDraw/postDraw) is not supported and is a source of bugs/errors.\n` +
`If you want to do custom drawing, use Actor.graphics, or any onPreDraw or onPostDraw handler.`);
this._alreadyWarnedDrawLifecycle = true;
}

const renderer = this._renderers.get(rendererName);
Expand Down
2 changes: 2 additions & 0 deletions src/engine/Graphics/Context/material.ts
Original file line number Diff line number Diff line change
Expand Up @@ -213,6 +213,8 @@ export class Material {
let textureSlot = startingTextureSlot;
for (const [textureName, image] of this._images.entries()) {
if (!image.isLoaded()) {
this._logger.warnOnce(`Image named ${textureName} in material ${this.name} not loaded, nothing will be uploaded to the shader.` +
` Did you forget to add this to a loader? https://excaliburjs.com/docs/loaders/`);
continue;
} // skip unloaded images, maybe warn
const texture = this._loadImageSource(image);
Expand Down
14 changes: 5 additions & 9 deletions src/engine/Graphics/Sprite.ts
Original file line number Diff line number Diff line change
Expand Up @@ -91,7 +91,6 @@ export class Sprite extends Graphic {
super._preDraw(ex, x, y);
}

private _logNotLoadedWarning = false;
public _drawImage(ex: ExcaliburGraphicsContext, x: number, y: number): void {
if (this.image.isLoaded()) {
ex.drawImage(
Expand All @@ -106,14 +105,11 @@ export class Sprite extends Graphic {
this.destSize.height
);
} else {
if (!this._logNotLoadedWarning) {
this._logger.warn(
`ImageSource ${this.image.path}` +
` is not yet loaded and won't be drawn. Please call .load() or include in a Loader.\n\n` +
`Read https://excaliburjs.com/docs/imagesource for more information.`
);
}
this._logNotLoadedWarning = true;
this._logger.warnOnce(
`ImageSource ${this.image.path}` +
` is not yet loaded and won't be drawn. Please call .load() or include in a Loader.\n\n` +
`Read https://excaliburjs.com/docs/imagesource for more information.`
);
}
}

Expand Down
16 changes: 4 additions & 12 deletions src/engine/Graphics/SpriteFont.ts
Original file line number Diff line number Diff line change
Expand Up @@ -53,8 +53,6 @@ export class SpriteFont extends Graphic implements FontRenderer {
this.shadow = shadow ?? this.shadow;
}

private _alreadyWarnedAlphabet = false;
private _alreadyWarnedSpriteSheet = false;
private _getCharacterSprites(text: string): Sprite[] {
const results: Sprite[] = [];
// handle case insensitive
Expand All @@ -68,22 +66,16 @@ export class SpriteFont extends Graphic implements FontRenderer {
let spriteIndex = alphabet.indexOf(letter);
if (spriteIndex === -1) {
spriteIndex = 0;
if (!this._alreadyWarnedAlphabet) {
this._logger.warn(`SpriteFont - Cannot find letter '${letter}' in configured alphabet '${alphabet}'.`);
this._logger.warn('There maybe be more issues in the SpriteFont configuration. No additional warnings will be logged.');
this._alreadyWarnedAlphabet = true;
}
this._logger.warnOnce(`SpriteFont - Cannot find letter '${letter}' in configured alphabet '${alphabet}'.`);
this._logger.warnOnce('There maybe be more issues in the SpriteFont configuration. No additional warnings will be logged.');
}

const letterSprite = this.spriteSheet.sprites[spriteIndex];
if (letterSprite) {
results.push(letterSprite);
} else {
if (!this._alreadyWarnedSpriteSheet) {
this._logger.warn(`SpriteFont - Cannot find sprite for '${letter}' at index '${spriteIndex}' in configured SpriteSheet`);
this._logger.warn('There maybe be more issues in the SpriteFont configuration. No additional warnings will be logged.');
this._alreadyWarnedSpriteSheet = true;
}
this._logger.warnOnce(`SpriteFont - Cannot find sprite for '${letter}' at index '${spriteIndex}' in configured SpriteSheet`);
this._logger.warnOnce('There maybe be more issues in the SpriteFont configuration. No additional warnings will be logged.');
}
}
return results;
Expand Down
6 changes: 2 additions & 4 deletions src/engine/Screen.ts
Original file line number Diff line number Diff line change
Expand Up @@ -454,7 +454,6 @@ export class Screen {
}
}

private _alreadyWarned = false;
public applyResolutionAndViewport() {
this._canvas.width = this.scaledWidth;
this._canvas.height = this.scaledHeight;
Expand All @@ -464,9 +463,8 @@ export class Screen {
width: this.scaledWidth,
height: this.scaledHeight
});
if (!supported && !this._alreadyWarned) {
this._alreadyWarned = true; // warn once
this._logger.warn(
if (!supported) {
this._logger.warnOnce(
`The currently configured resolution (${this.resolution.width}x${this.resolution.height}) and pixel ratio (${this.pixelRatio})` +
' are too large for the platform WebGL implementation, this may work but cause WebGL rendering to behave oddly.' +
' Try reducing the resolution or disabling Hi DPI scaling to avoid this' +
Expand Down
52 changes: 52 additions & 0 deletions src/engine/Util/Log.ts
Original file line number Diff line number Diff line change
Expand Up @@ -78,6 +78,18 @@ export class Logger {
}
}


private _logOnceSet = new Set<any>();
private _logOnce(level: LogLevel, args: any[]): void {
const serialized = level + args.join('+');
if (this._logOnceSet.has(serialized)) {
return;
} else {
this._logOnceSet.add(serialized);
this._log(level, args);
}
}

/**
* Writes a log message at the [[LogLevel.Debug]] level
* @param args Accepts any number of arguments
Expand All @@ -86,6 +98,14 @@ export class Logger {
this._log(LogLevel.Debug, args);
}

/**
* Writes a log message once at the [[LogLevel.Fatal]] level, if it sees the same args again it wont log
* @param args Accepts any number of arguments
*/
public debugOnce(...args: any[]): void {
this._logOnce(LogLevel.Debug, args);
}

/**
* Writes a log message at the [[LogLevel.Info]] level
* @param args Accepts any number of arguments
Expand All @@ -94,6 +114,14 @@ export class Logger {
this._log(LogLevel.Info, args);
}

/**
* Writes a log message once at the [[LogLevel.Info]] level, if it sees the same args again it wont log
* @param args Accepts any number of arguments
*/
public infoOnce(...args: any[]): void {
this._logOnce(LogLevel.Info, args);
}

/**
* Writes a log message at the [[LogLevel.Warn]] level
* @param args Accepts any number of arguments
Expand All @@ -102,6 +130,14 @@ export class Logger {
this._log(LogLevel.Warn, args);
}

/**
* Writes a log message once at the [[LogLevel.Warn]] level, if it sees the same args again it won't log
* @param args Accepts any number of arguments
*/
public warnOnce(...args: any[]): void {
this._logOnce(LogLevel.Warn, args);
}

/**
* Writes a log message at the [[LogLevel.Error]] level
* @param args Accepts any number of arguments
Expand All @@ -110,13 +146,29 @@ export class Logger {
this._log(LogLevel.Error, args);
}

/**
* Writes a log message once at the [[LogLevel.Error]] level, if it sees the same args again it won't log
* @param args Accepts any number of arguments
*/
public errorOnce(...args: any[]): void {
this._logOnce(LogLevel.Error, args);
}

/**
* Writes a log message at the [[LogLevel.Fatal]] level
* @param args Accepts any number of arguments
*/
public fatal(...args: any[]): void {
this._log(LogLevel.Fatal, args);
}

/**
* Writes a log message once at the [[LogLevel.Fatal]] level, if it sees the same args again it won't log
* @param args Accepts any number of arguments
*/
public fatalOnce(...args: any[]): void {
this._logOnce(LogLevel.Fatal, args);
}
}

/**
Expand Down
6 changes: 3 additions & 3 deletions src/spec/ExcaliburGraphicsContextSpec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -466,7 +466,7 @@ describe('The ExcaliburGraphicsContext', () => {

it('will log a warning if you attempt to draw outside the lifecycle', () => {
const logger = ex.Logger.getInstance();
spyOn(logger, 'warn').and.callThrough();
spyOn(logger, 'warnOnce').and.callThrough();

const canvasElement = document.createElement('canvas');
canvasElement.width = 100;
Expand All @@ -479,7 +479,7 @@ describe('The ExcaliburGraphicsContext', () => {
});

sut.drawCircle(ex.vec(0, 0), 10, ex.Color.Blue);
expect(logger.warn).toHaveBeenCalledWith(
expect(logger.warnOnce).toHaveBeenCalledWith(
`Attempting to draw outside the the drawing lifecycle (preDraw/postDraw) is not supported and is a source of bugs/errors.\n`+
`If you want to do custom drawing, use Actor.graphics, or any onPreDraw or onPostDraw handler.`);
});
Expand Down Expand Up @@ -527,7 +527,7 @@ describe('The ExcaliburGraphicsContext', () => {
sut.useDrawSorting = false;

sut.drawLine(ex.vec(0, 0), ex.vec(100, 100), ex.Color.Red, 2);
expect(rectangleRenderer.flush).withContext('rectangle line render not flusehd yet').not.toHaveBeenCalled();
expect(rectangleRenderer.flush).withContext('rectangle line render not flushed yet').not.toHaveBeenCalled();

sut.drawCircle(ex.Vector.Zero, 100, ex.Color.Red, ex.Color.Black, 2);
expect(circleRenderer.flush).withContext('circle is batched not flushed yet').not.toHaveBeenCalled();
Expand Down
56 changes: 56 additions & 0 deletions src/spec/LogSpec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -14,6 +14,7 @@ describe('Logger', () => {
appender = new ex.ConsoleAppender();

logger = ex.Logger.getInstance();
logger.clearAppenders();
logger.addAppender(appender);
spiedAppender = spyOn(appender, 'log');
spiedAppender.and.callThrough();
Expand Down Expand Up @@ -72,30 +73,85 @@ describe('Logger', () => {
expect(spiedConsoleLog).toHaveBeenCalled();
});

it('should call console debug once', () => {
logger.debugOnce('test');
logger.debugOnce('test');
logger.debugOnce('test');
logger.debugOnce('test');
logger.debugOnce('test');
logger.debugOnce('test');

expect(spiedConsoleLog).toHaveBeenCalledTimes(1);
});

it('should call console log for level Info', () => {
logger.info('test');

expect(spiedConsoleLog).toHaveBeenCalled();
});

it('should call console info once', () => {
logger.infoOnce('test');
logger.infoOnce('test');
logger.infoOnce('test');
logger.infoOnce('test');
logger.infoOnce('test');
logger.infoOnce('test');

expect(spiedConsoleLog).toHaveBeenCalledTimes(1);
});

it('should call console warn for level Warn', () => {
logger.warn('test');

expect(spiedConsoleWarn).toHaveBeenCalled();
});

it('should call console warn once', () => {
logger.warnOnce('test');
logger.warnOnce('test');
logger.warnOnce('test');
logger.warnOnce('test');
logger.warnOnce('test');
logger.warnOnce('test');

expect(spiedConsoleWarn).toHaveBeenCalledTimes(1);
});

it('should call console error for level Error', () => {
logger.error('test');

expect(spiedConsoleError).toHaveBeenCalled();
});

it('should call console error once', () => {
logger.errorOnce('test');
logger.errorOnce('test');
logger.errorOnce('test');
logger.errorOnce('test');
logger.errorOnce('test');
logger.errorOnce('test');

expect(spiedConsoleError).toHaveBeenCalledTimes(1);
});

it('should call console error for level Fatal', () => {
logger.fatal('test');

expect(spiedConsoleError).toHaveBeenCalled();
});

it('should call console fatal once', () => {
logger.fatalOnce('test');
logger.fatalOnce('test');
logger.fatalOnce('test');
logger.fatalOnce('test');
logger.fatalOnce('test');
logger.fatalOnce('test');

expect(spiedConsoleError).toHaveBeenCalledTimes(1);
});

it('should format message to console with appropriate level', () => {
logger.info('test');

Expand Down
12 changes: 6 additions & 6 deletions src/spec/ScreenSpec.ts
Original file line number Diff line number Diff line change
Expand Up @@ -660,7 +660,7 @@ describe('A Screen', () => {
sut.applyResolutionAndViewport();

// The camera is always center screen
// The absense of a camera is treated like a camera at (0, 0) in world space
// The absence of a camera is treated like a camera at (0, 0) in world space
expect(sut.screenToWorldCoordinates(ex.vec(400, 300))).toBeVector(ex.vec(0, 0));
expect(sut.screenToWorldCoordinates(ex.vec(0, 0))).toBeVector(ex.vec(-400, -300));
expect(sut.screenToWorldCoordinates(ex.vec(800, 0))).toBeVector(ex.vec(400, -300));
Expand All @@ -679,7 +679,7 @@ describe('A Screen', () => {
sut.applyResolutionAndViewport();

// The camera is always center screen
// The absense of a camera is treated like a camera at (0, 0) in world space
// The absence of a camera is treated like a camera at (0, 0) in world space
expect(sut.worldToScreenCoordinates(ex.vec(0, 0))).toBeVector(ex.vec(400, 300));
expect(sut.worldToScreenCoordinates(ex.vec(-400, -300))).toBeVector(ex.vec(0, 0));
expect(sut.worldToScreenCoordinates(ex.vec(400, -300))).toBeVector(ex.vec(800, 0));
Expand All @@ -706,7 +706,7 @@ describe('A Screen', () => {
camera._initialize({screen: sut, clock: { elapsed: () => 16}} as ex.Engine);

// The camera is always center screen
// The absense of a camera is treated like a camera at (0, 0) in world space
// The absence of a camera is treated like a camera at (0, 0) in world space
expect(sut.screenToWorldCoordinates(ex.vec(400, 300))).toBeVector(ex.vec(400, 300));
expect(sut.screenToWorldCoordinates(ex.vec(0, 0))).toBeVector(ex.vec(200, 150));
expect(sut.screenToWorldCoordinates(ex.vec(800, 0))).toBeVector(ex.vec(600, 150));
Expand All @@ -733,7 +733,7 @@ describe('A Screen', () => {
camera._initialize({screen: sut, clock: { elapsed: () => 16}} as ex.Engine);

// The camera is always center screen
// The absense of a camera is treated like a camera at (0, 0) in world space
// The absence of a camera is treated like a camera at (0, 0) in world space
expect(sut.worldToScreenCoordinates(ex.vec(400, 300))).toBeVector(ex.vec(400, 300));
expect(sut.worldToScreenCoordinates(ex.vec(200, 150))).toBeVector(ex.vec(0, 0));
expect(sut.worldToScreenCoordinates(ex.vec(600, 150))).toBeVector(ex.vec(800, 0));
Expand Down Expand Up @@ -854,7 +854,7 @@ describe('A Screen', () => {

it('will warn if the resolution is too large', () => {
const logger = ex.Logger.getInstance();
spyOn(logger, 'warn');
spyOn(logger, 'warnOnce');

const canvasElement = document.createElement('canvas');
canvasElement.width = 100;
Expand All @@ -879,7 +879,7 @@ describe('A Screen', () => {
sut.resolution = { width: 3000, height: 3000 };
sut.applyResolutionAndViewport();
expect(context.checkIfResolutionSupported).toHaveBeenCalled();
expect(logger.warn).toHaveBeenCalledOnceWith(
expect(logger.warnOnce).toHaveBeenCalledOnceWith(
`The currently configured resolution (${sut.resolution.width}x${sut.resolution.height}) and pixel ratio (${sut.pixelRatio})` +
' are too large for the platform WebGL implementation, this may work but cause WebGL rendering to behave oddly.' +
' Try reducing the resolution or disabling Hi DPI scaling to avoid this' +
Expand Down
Loading

0 comments on commit 2bbc25a

Please sign in to comment.