tslog icon indicating copy to clipboard operation
tslog copied to clipboard

Bug: Built-in formatting/interpolation subverted/unusable

Open dever23b opened this issue 3 years ago • 2 comments

Describe the bug The ability to log messages with interpolation is subverted by the processing of the arguments array supplied to the log-level methods (silly, debug, info, etc)

To Reproduce Steps to reproduce the behavior:

import { Logger } from 'tslog';

const log: Logger = new Logger();
const foo: string = bar;
log.info('Foo %s', foo);

Output

Foo %s bar

Expected behavior The two arguments supplied to log.info are passed together to (node:)util.formatWithOptions method to be properly formatted

Foo bar

Additional context A review of LoggerWithoutCallSite.ts seems to indicate that there may have been an attempt to support formatted log entries. The logging code, specifically printPrettyLog, references (node:)util's formatWithOptions method, which can be used to support interpolation on formatted(/printf-style) log entries. Indeed, if the arguments were passed directly to util.format, they would display as intended.

The LoggerWithoutCallSite.prettyPrintLog method separates the arguments, however, and inhibits the ability for util.format to work properly. prettyPrintLog performs a forEach on the arguments array, and then calls an intermediary that eventually passes each argument individually to util.format. By separating the argument, util.format is not given access to the parameters associated with a format string and therefore prints the format string as-is, without the intended interpolation:

// provided with all of the arguments
util.format('Foo %s', foo); // Foo bar
// vs what TSLog does, effectively
util.format('Foo %s'); // Foo %s
util.format(foo); // bar

I'm not sure if it would result in a breaking change, but my initial impression is that this could potentially be resolved by adjusting printPrettyLog such that it pre-processes the arguments array to sanitize it as necessary, and then passes the full array to util.formatWithOptions or util.inspectWithOptions.

Node.js Version e.g. 16.16.0

OS incl. Version e.g. Docker-ized Node container on Linux

Thanks for your time and very helpful utility

dever23b avatar Aug 18 '22 04:08 dever23b

Thank you very much for your bug report. Unfortunately, that would be quite a big rewrite indeed.

However, I am working on the next major version 4.0 and this would be definitely going to be something I'll consider when developing.

terehov avatar Aug 23 '22 14:08 terehov

@terehov Thanks for responding. I'm still learning how to work with Git and I haven't even endeavored to play with GitHub yet, so forgive me for not doing a proper PR (I'm just not on that level yet, sorry!). I'm still quite the amateur with Git, and really only know how to use it to the extent that I can save and re-access commits to prevent me from losing code when I accidentally create regressions.

That being said, I wrote a custom class last night to get around the issues I was having here and in #146 (thanks again for your work over there too). My class is just a basic "superclass" (for lack of a more appropriate word) that stores an instance of Logger and some custom methods I wrote to manipulate/preprocess the data being sent to your class. I was able to get formatted strings working for the project I'm working on, and it wasn't a huge undertaking. The resolution here may not require a huge rewrite! If you are interested, I would be happy to try to figure out how to share my work with you for your review/inspiration. Please be forewarned: nothing I write here should be misconstrued to suggest that I am any sort of expert on the matter. I just threw some stuff together as an "adapter" of sorts, to make my existing project code compatible with your project.

Basically, my equivalent of _handleLog calls a method that:

  • iterates through all of the supplied arguments
  • extracts any format/param combinations it can detect
  • replaces the collection of args with the output of util.formatWithOptions
  • then passes the resultant argument array to your log-level methods for normal processing

My code has to contend with not being part of your project, nor extending it, so it is inherently more complicated/"round-about" than a simple/direct implementation. I believe it would be significantly less complex to implement the basic logic of my code directly into your class than what was necessary for me to achieve the same result.

dever23b avatar Aug 23 '22 21:08 dever23b

I've been working on a new, completely rewritten version (4.0), which support interpolation. Give it a go and let me know if that solves your problem:

  • npm i tslog@next

  • and run it with node --enable-source-maps or for TypeScript node --enable-source-maps --experimental-specifier-resolution=node --no-warnings --loader ts-node/esm

Example:

const logger = new Logger();
logger.fatal("test1 %s test3", "test2");

terehov avatar Sep 29 '22 10:09 terehov

V4 is released now, so I'm going to close this issue. Feel free to open a new one if V4 didn't solve it for you.

Here are the docs: tslog.js.org

terehov avatar Nov 15 '22 18:11 terehov