Why do I have to configure the log in every typescript file?

Question

Why do I have to configure the log in every typescript file?

JobaDiniz opened this issue a year ago · 12 comments

A bit of a noob question, but I have to do the following in every .ts file that I have. If one file does not do log.enableAll() no log is collected for that file.

import log from 'loglevel';
import logPrefix from 'loglevel-plugin-prefix';

logPrefix.reg(log);
logPrefix.apply(log, { template: '[%t] %l %n:' });
log.enableAll();
const logger = log.getLogger('DefaultUiAutomationWorker');

Why is that?

Answer 1 · 2023-11-30T13:36:14.000Z

No idea I'm afraid! In general, you should only need to apply plugins once - the exported log constant is a variable shared across the entire process. If that's not happening, it must be due to a detail of how this plugin setup or your runtime environment work.

Answer 2 · 2023-11-30T13:55:39.000Z

I think support for typescript needs to be improved.

I think the issue I mentioned has something to do with https://stackoverflow.com/a/56984941/1830639

Answer 3 · 2023-11-30T14:01:45.000Z

This is nothing to do with TypeScript. TypeScript works at compile time, and that question above mostly revolves around types.

This is something that's happening in your runtime environment, where all the TypeScript has already been removed - everything is JavaScript at this stage.

It might be due to some detail of the JavaScript that your TS is generating, although I'm not sure exactly how. You should be able to look at the JS output directly and see exactly what JavaScript is actually being generated & run.

Answer 4 · 2023-12-14T20:04:33.000Z

@JobaDiniz is your problem that:

Nothing is logging in modules without this configuration code?
Levels that are off by default (anything less than warn, e.g. logger.info()) don’t work without this configuration code?
Loggers don’t use the prefix you’ve set without this configuration code?

I can’t reproduce (1), but (2) and (3) are probably caused by the issue of when you do the configuration. Here’s a simple reproduction (in JS, not TypeScript, but TypeScript should not make a difference here): https://gist.github.com/Mr0grog/0683970ae216da0dee76adba4be14fb7

The core issue here is that loglevel has to set up everything about log levels and formatting ahead of time, and you can’t change the level (which enableAll() does) or the actual logging implementation, a.k.a. the “method factory” (which the plugin does) on the root logger and have it affect child loggers that have already been created. So if all code’s main module starts by importing other modules, then configures the root logger, all the other modules’ loggers will have already been created, and won’t be affected by the configuration code in the main module.

I would say there are two good ways to deal with this:

Have a central module in your program that configures and provides access to loglevel. So in the gist I linked, you might add a module named logging.js with content like:
```
import log from 'loglevel';
import logPrefix from 'loglevel-plugin-prefix';

// Configure loglevel:
logPrefix.reg(log);
logPrefix.apply(log, { template: '[%t] %l %n:' });
log.enableAll();

export default log;
```
…And then in all your other modules, you should import that instead of importing loglevel or any plugins or anything:
```
// module-a.js
import log from './logging.js';

const logger = log.getLogger('ModuleA');
```
The downside here is that your main module can’t dynamically choose how to configure logging; all that has to happen in logging.js. For example, a CLI program that takes some arguments that adjust the format is harder to build with this pattern.
In your main module, do all your config, etc. and then load the rest of your code dynamically, like the comment in the gist I linked suggests. The downside here is that you have to be much more careful about how you load different modules in your code.

@pimterry Hi, I haven’t been here in years! I think there are changes that could be made here so that someone doesn’t have to do the above workarounds, if you think it’s worthwhile:

Logger instances need to keep track of whether their logging level has ever been explicitly set (either from a persisted level or a call to setLevel() and not setDefaultLevel() (the separation between defaultLevel and currentLevel doesn’t look like it’s quite clean enough for that today).
Calling someLogger.setLevel() should find all the logger’s child loggers, then a) set their default level (and current level if the level has never explicitly been set — see above) and b) ensure replaceLoggingMethods(currentLevel) is called on them. (Maybe add a public rebuildLogger() method that does this, so plugins can call it after changing the methodFactory?)

Side Q: are you still dedicated to ensuring someLogger.warn() shows the line number where it was called in the browser console? It ceases to work very meaningfully with most plugins (or if not in a browser), and dropping that requirement makes solving these issues less complex.

Answer 5 · 2023-12-14T20:17:07.000Z

Re: rebuildLogger() I forgot about #82, which is largely the same thing (except it doesn’t reach down and call itself on any child loggers, which would need to happen for this).

Answer 6 · 2023-12-15T09:51:55.000Z

So if all code’s main module starts by importing other modules, then configures the root logger, all the other modules’ loggers will have already been created, and won’t be affected by the configuration code in the main module.

Yes, that was the issue!
I changed the code so the main file configures the log, and made sure to create loggers inside classes (and not on top of the file)

Answer 7 · 2023-12-18T17:18:28.000Z

Nice work @Mr0grog! That makes a lot of sense, thanks for digging into this.

are you still dedicated to ensuring someLogger.warn() shows the line number where it was called in the browser console?

Yes, definitely. That's one of the main reasons this library exists - because that's the main footgun in just building a wrapper around console.log by yourself, and it can be very annoying when trying to quickly trace down browser logging. I understand that plugins break it, but I'm keen to provide a base where that works correctly out of the box.

I'm broadly open to other improvements that don't break that constraint, but this library is quite small, focused & mature now (first release was more than 11 years ago!) and so maintainability & avoiding breakage for existing users is a higher priority than dramatic changes at this stage.

Because of that, changing the default behaviour around all this is problematic. That said, adding a new method such as rebuildLogger() would work fine. Providing functionality like that to apply changes to a logger & all its children as you describe is a good idea, makes a lot of sense, PRs welcome.

Answer 8 · 2023-12-18T18:04:23.000Z

are you still dedicated to ensuring someLogger.warn() shows the line number where it was called in the browser console?

Yes, definitely. That's one of the main reasons this library exists…

👍

changing the default behaviour around all this is problematic. That said, adding a new method such as rebuildLogger() would work fine.

Just for clarity, do you mean the default behaviour of keeping default functionality where loglevel.warn() etc. are the actual console.warn() functions so they print the right line numbers, or the idea of automatically rebuilding all child loggers?

Totally hear you on the former. For the latter, that makes sense — my feel is that this would be appropriate for a minor release, e.g. 1.9, but I can definitely imagine people un-knowingly relying on the current behavior and getting caught by surprise if previously instantiated child loggers got rebuilt, and you wanted to wait until 2.0 for that (seems like there are a lot of ideas there, but it ran out of steam in #119?).

Anyway, I think I may have overcommitted myself on other projects for the rest of December, but I can try and take a cut at this by early January if you’d like:

Add a rebuildLogger() method that rebuilds the current logger and its children (I think it should do both, but if you feel strongly we could add an optional argument that controls whether to do the children which I think should default to true).
Also add a setMethodFactory() method that updates a logger’s factory and calls rebuildLogger()?

If we are doing (1) above, I think it makes sense to do this, too, but it seems like there are some open questions around whether setMethodFactory() should wrap or replace the current factory, and in #117 on whether that should or should not affect child loggers.

Answer 9 · 2023-12-18T20:49:12.000Z

changing the default behaviour around all this is problematic. That said, adding a new method such as rebuildLogger() would work fine.

Just for clarity, do you mean the default behaviour of keeping default functionality where loglevel.warn() etc. are the actual console.warn() functions so they print the right line numbers, or the idea of automatically rebuilding all child loggers?

I'm saying that automatically rebuilding child loggers is problematic. That is definitely a breaking change, since existing logging code would start behaving differently in potentially problematic ways. I'd strongly prefer to avoid doing breaking changes like that at this stage.

Adding rebuildLogger() and then gently encouraging people to migrate towards that would be totally fine though. The current code says to update the log level with setLevel(getLevel()) (or similar) after enabling plugins - we could just update that documentation to rebuildLogger() and that would solve this issue for all new code, and provide an easy fix for any existing code that runs into this.

(We might want to bikeshed the name, but I think the concept is clear: apply the current level & plugins to this logger and all existing children)

The trick is finding a way to provide a nice solution that provides a clean new API to avoid this problem, but with minimal impact to the rest of the existing code & users. This package is installed on npm 7.5 million times per week so the impact of breaking anything is absolutely huge, and this package really isn't my main focus nowadays so I'm quite keen to prioritise stability here.

Answer 10 · 2023-12-18T21:18:48.000Z

The trick is finding a way to provide a nice solution that provides a clean new API to avoid this problem, but with minimal impact to the rest of the existing code & users.

Oh, for sure. And I don't think that will be an issue.

I was more trying to get at whether you felt automatically updating child loggers is more like fixing a longstanding bug (minor release, e.g. 1.9, since obviously issues like this come about because it’s how people expected it to work), or a disruptive change (major release). I think answer to that is now clear! (Too disruptive!)

👍

Answer 11 · 2024-01-05T22:09:39.000Z

Posted a first cut at solving this in #189.

Answer 12 · 2024-01-25T23:50:16.000Z

Circling back here for @JobaDiniz and anyone else reading this thread…

In v1.9.0 (just released), there is a log.rebuild() function you can call to update all existing loggers with the appropriate level and logging implementation (e.g. if you install a plugin like loglevel-plugin-prefix), so you can call that instead of being extra careful about the order in which you do things as described in my first comment above: #187 (comment)

So you can now have code like:

// file: module-a.js
import log from 'loglevel';

const logger = log.getLogger('ModuleA');

export function logFromA() {
  logger.warn('Warn from A!');
  logger.info('Info from A!');
}

// file: module-b.js
import log from 'loglevel';

const logger = log.getLogger('ModuleB');

export function logFromB() {
  logger.warn('Warn from B!');
  logger.info('Info from B!');
}

// file: index.js
import log from 'loglevel';
import logPrefix from 'loglevel-plugin-prefix';
import { logFromA } from './module-a.js';
import { logFromB } from './module-b.js';

// You can run the following config code anytime, even if the loggers in the
// other modules have already been set up.
logPrefix.reg(log);
logPrefix.apply(log, { template: '[%t] %l %n:' });
log.enableAll();
log.rebuild();  // ← This is new, it will make the following log calls work like you expect!

log.warn('Warn at root!');
log.info('Info at root!');
logFromA();
logFromB();