Clarification around when state of environment is evaluated for instance? Request to evaluate on instance creation

[mattmazzola]

Hi, I hoped to ask a question that would help clarify some confusion I'm seeing in other related issues about the debug logs from the instances not being enabled thus logs not appearing when users expect it should be enabled.

It seems this is often an order of operations issue. People expect the environment variables to be evaluated when an instance is created, but based on the responses to other issues, it seems the variables are evaluated when the module is imported which is causing the confusion. Example #750

The reason I had come across this is because I was trying to get get dotenv to work with this package debug. I think these are two very common solution and could work together more easily.

Common expectation (DOES NOT LOG)

import debug from 'debug'
import dotenv from 'dotenv'

dotenv.config()

console.log(`DEBUG=${process.env.DEBUG}`)

const debugInfo = debug('info')
debugInfo('Expect this to be logged')

Output:

node .

DEBUG=*

You can see it does work if the environment variables is set BEFORE the process is started in the output below

$env:DEBUG='*'; node .

DEBUG=*
  info Expect this to be logged +0ms

From my understanding the reason this doesn't work is because the environment state is evaluated when the module is imported. And in the example the environment variables are only set after dotenv.config() is called.
This means all instances created by the debug will be disabled event if DEBUG=* is set. This is very confusing.

Order of operations

1. debug imported (DEBUG is not set)
2. dotenv.config() called, DEBUG is set
3. debug instance created (but thinks DEBUG is unset so instance is disabled)

Questions:

1. Is this explanation correct?
2. Is it possible to re-evaluate the environment when the instance is created rather than only once on import?
3. If so, how do you achieve this? and can it be set as a default behavior?

I saw there is some mention of ability to do this manually as seen here const debugInstance = debug('someInstance', {reloadEnv: true}) from this comment #750 (comment)
However, I was not able to get it to work and it's also not in the typescript definitions.

I don't know what the reason would be for the single evaluation on import, but I was thinking this would actually be a good default option as it aligns with expectation and only those users very concerned about performance would opt if there is some significant penalty.

I create a repo with reproduction here if there is a way to fix it:
https://github.com/mattmazzola/debugtest

[Qix-]

It seems this is often an order of operations issue.

Correct. Let it be clear (not as a criticism of the question, which I appreciate being asked) - order of operations in the sense it is applied here is common throughout software engineering. You cannot expect the order of operations to be completely arbitrary with the same result. This seems to be a common misconception with some of the more "confused" requests I get here.

I think these are two very common solution and could work together more easily.

There's absolutely no reason these modules cannot work together. They're both incredibly simple, and it takes a very simple understanding of environment variables to figure out why certain orders of operation work and which do not. The vast majority of support tickets sent here w.r.t. dotenv have been a misunderstanding on the user's part, for this very reason.

Common expectation (DOES NOT LOG)

Right. Why would it? dotenv loads a file (or whatever) into process.env. debug uses process.env upon inclusion to determine the currently defined environment variables and thus which DEBUG namespaces are enabled. Why would debug magically decide to re-parse the string (which isn't free to do) each time it's included?

Further, the very nature of "each time it's included" doesn't make sense - Node.js has a require() cache that pre-empts re-imports before they happen. This is why some modules prefer to Object.defineProperties() their module.exports objects to enforce per-package pollution safety. In most cases it isn't necessary as relying on package caching isn't exactly recommended, thus the Node.js team (or whomever manages the "commonjs" module format) hasn't opted for this behavior to be the norm.

From my understanding the reason this doesn't work is because the environment state is evaluated when the module is imported.

Correct. debug is already a performance suck; referring to object keys and performing string parses is not free, and doing so each time a new debug instance is created (especially given how some people use debug, e.g. #740) would otherwise bog down processes due to a trivial debugging library -- even if the namespace is not actually enabled for output.

This means all instances created by the debug will be disabled event if DEBUG=* is set. This is very confusing.

This is where I lost you. Why is this confusing? process.env is simply a Javascript object initially comprised of the values from the C runtime's environ variable. It's a pretty standard mechanism across platforms. If you define an environment prior to starting a process, then it will be present upon a process entering its int main() entry point (as is the case with all current Node.js runtimes). If not, you're welcome to modify it at runtime, but it's no different than any other object - if you try to reference an environment variable before it's defined, then you'll get undefined. This is simply how Javascript works.

dotenv is not magic. All it does is reads a file at runtime (see above) and modifies process.env at runtime, wherever it is first included. If you try to refer to a variable that is declared in a dotenv-compatible config file before you actually tell dotenv to load the environment variables, you're going to get undefined if it wasn't already declared in the environment. It's really not more complicated than that.

Is this explanation correct?

Yep, you've pretty much debugged it entirely given the preceding steps.

Is it possible to re-evaluate the environment when the instance is created rather than only once on import?

Of course it's possible. It's also a needless performance hit. The general assumption is that the environment variable(s) do not change much when a program starts. Since Node.js began as a simple POSIX system call wrapper with a Javascript engine, I don't see how this should be any different even today.

If so, how do you achieve this? and can it be set as a default behavior?

Force debug out of the require() cache and make it read the process.env again. Alternatively, modify the enabled namespaces at runtime yourself (refer to README for how to do this).

And no, it makes little sense making this the default behavior.

I saw there is some mention of ability to do this manually as seen here

That was a feature suggestion, one that I am very starkly against. Nowhere was it indicated this is a current feature.

I don't know what the reason would be for the single evaluation on import,

Performance, and the fact most programs do not modify environment during runtime. Programming isn't "anything goes". You need to understand the order in which you do things.

but I was thinking this would actually be a good default option as it aligns with expectation

Sorry, but I fully disagree that it "aligns with expectation". I would expect most systems developers would disagree, too. Of course it's allowed and possible and even useful at times, but rarely relied upon.

and only those users very concerned about performance would opt if there is some significant penalty.

Performance is always a concern. This is why systems engineers tend not to take web development seriously in the first place, if I may be so bold (disclaimer: that is my own observation - other maintainers of debug are free to dissent).

I create a repo with reproduction here if there is a way to fix it:

Sorry to seem harsh, but there's nothing to fix here.

---

Going to close this as it's a question - feel free to follow up and I'd be happy to respond.

Thanks!

[mattmazzola]

Ok, thanks for explanation. It at least confirms my understanding.

There's absolutely no reason these modules cannot work together.

Great! Is there an example available that uses imports and both those packages similar to the linked repo?

I understand to satisfy the order, we would want the import debug to occur after the dotenv.config() so that it would be parsing env vars on inclusion AFTER the DEBUG is set by dotenv but it doesn't compile with this modification. Also, I think that would be rather unconventional and I'm not sure if the compilation process forces imports to be at the top of files. I suppose a dynamic import could work, but that would be very awkward and high refactor cost for using the library

You mentioned:

Force debug out of the require() cache and make it read the process.env again.

What is the equivalent when using import style?

In other words, what would I need to change in https://github.com/mattmazzola/debugtest/blob/master/src/index.ts to make it log Expect this to be logged

Why would debug magically decide to re-parse the string (which isn't free to do) each time it's included?

I didn't mean to re-parse each time it's included, I meant to reparse when an instance is created. You seem much more aware of the lower levels of language and performance concerns so you may see this as "magic" or "anything goes" but I feel because the developer called a function they expects something to happen so it is deterministic.

Such as const workerDebug = debug('worker') would evaluate the DEBUG string here. You said this IS a possible significant performance issue so I understand why it's not the default.

I fully disagree [with adding option to reload]

I can see why it would be bad for default now, but I thought for more casual/hobby usage where people want to see logs of different components of their applications but aren't worried about performance this would be useful.

The general assumption is that the environment variable(s) do not change much when a program starts.

Agreed. I think there is a solution to simply defer evaluation until the first instance is created. Then we get the best of both worlds. Evaluate/Parsed only once for performance AND the developer easily change the order of what it happens by changing when statements are executed instead of worrying about require/import dependency graph.

Is something like this possible?

import debug from 'debug'
import dotenv from 'dotenv'

dotenv.config()

const workerA = debug('worker:a') // ENV evaluated here and cached
const workerB = debug('worker:b') // no penalty because it's cached