feat(core): allow overriding global logging options on per-query basis

[SpencerKaiser]

Changing debugMode or disabling logging for specific queries

If you'd like to disable logging or change the debug mode on a per-query basis, you can leverage FindOptions.logging and its enabled or debugMode property:

// MikroORM.init({ debug: true });
const author = await em.findOne(Author, { id: 1 }, { logging: { enabled: false } });
// Overrides config and displays no logger output
// ...
// MikroORM.init({ debug: false });
const author = await em.findOne(Author, { id: 1 }, { logging: { enabled: true } });
// Overrides config and displays logger output
// ...
// MikroORM.init({ debug: ['query-labels'] });
const author = await em.findOne(Author, { id: 1 }, { logging: { debugMode: ['query'] } });
// Overrides config and displays logger output for query

Closes #4223

[B4nan]

that was fast! i just added a comment how this could work to the issue

[B4nan]

btw i am rebasing the v6 branch now, so you might wanna recreate the PR once i am done

[SpencerKaiser]

@B4nan sounds good; just don't update this branch and I'll just reset everything and force pull when it's ready

Also I just realized failures kinda make this weird... should isDisabled prevent a failed query from printing?? Feels like it should still print otherwise you may not be aware of a potential issue ☹️ maybe instead of isDisabled, something like disableWhen: boolean | 'on-success'?

Edit: How about this?

isEnabled(namespace: LoggerNamespace, context?: LogContext) {
  if (context?.isDisabled !== undefined && context.isDisabled !== false) {
    if (context.isDisabled === true) {
      // Disable for ALL
      return false;
    } else if (context.isDisabled === 'on-success'
      && context.level
      && !['warning', 'error'].includes(context.level)) {
      // Disable only on success and the level was NOT an error state
      return false;
    }
  }

  return !!this.debugMode && (!Array.isArray(this.debugMode) || this.debugMode.includes(namespace));
}

[codecov]

Codecov Report

Patch coverage: 100.00% and project coverage change: +0.24 🎉

Comparison is base (188ba57) 99.43% compared to head (6f24775) 99.67%.

❗ Current head 6f24775 differs from pull request most recent head 0a27886. Consider uploading reports for the commit 0a27886 to get more accurate results

Additional details and impacted files

@@            Coverage Diff             @@
##               v6    #4273      +/-   ##
==========================================
+ Coverage   99.43%   99.67%   +0.24%     
==========================================
  Files         219      219              
  Lines       14457    14504      +47     
  Branches     3314     3324      +10     
==========================================
+ Hits        14375    14457      +82     
+ Misses         81       46      -35     
  Partials        1        1              

Impacted Files	Coverage Δ
packages/core/src/drivers/IDatabaseDriver.ts	100.00% <ø> (ø)
packages/core/src/logging/DefaultLogger.ts	100.00% <100.00%> (ø)
packages/core/src/logging/SimpleLogger.ts	100.00% <100.00%> (ø)
packages/knex/src/AbstractSqlConnection.ts	100.00% <100.00%> (ø)
packages/knex/src/AbstractSqlDriver.ts	99.82% <100.00%> (ø)
packages/knex/src/query/QueryBuilder.ts	99.54% <100.00%> (ø)
packages/mongodb/src/MongoConnection.ts	100.00% <100.00%> (ø)

... and 29 files with indirect coverage changes

☔ View full report in Codecov by Sentry.
📢 Do you have feedback about the report comment? Let us know in this issue.

[B4nan]

I don't think we want to print failed queries when global logging is disabled, but for the local override it could be a good thing.

I care more about the API in FindOptions, and there I would like the logging option (or something else, feel free to suggest, but not isDisabled), that can override in both ways (true/false).

edit: looking at the implementation, I guess it could be just enabled: boolean inside the logger context option, or we could have dedicated FindOptions.debug as it is kind of a local counterpart to the global debug option

[SpencerKaiser]

I'd be game to replace loggerContext inside FindOptions with just logging... is that what you're proposing? If so, I'm on board... I think it's more generic and less characters 😄 it'd also help clean up the types and make it obvious that that type is for options within find options (and later others).

Re: enabled - I personally think it's kind of weird to have an optional that turns something on because then it's unclear what the default is. I think your idea of the local debug is a good one... you're basically suggesting a mirror of the relevant arguments from the init call?

[B4nan]

Re: enabled - I personally think it's kind of weird to have an optional that turns something on because then it's unclear what the default is.

the whole point of this feature is to override the global value - so its irrelevant what the default is

and yes, i was thinking about a dedicated option in FindOptions from the beginning. both logging and debug sounds good to me

[B4nan]

What a painful rebase, made two super small mistakes and it has cost me an additional hour of debugging 🤦 But it should be ready now.

[SpencerKaiser]

@B4nan oof, sorry man... well it should be trivial for me to fix the branch and re-push. I'll do it first thing tomorrow and read through the comments from this evening that I missed.

[B4nan]

one code style thing + no need for else if when you return

Suggested change

	} else if (context.isDisabled === 'on-success'
	&& context.level
	&& !['warning', 'error'].includes(context.level)) {
	// Disable only on success and the level was NOT an error state
	return false;
	}
	}
	if (
	context.isDisabled === 'on-success' &&
	context.level &&
	!['warning', 'error'].includes(context.level)
	) {
	// Disable only on success and the level was NOT an error state
	return false;
	}

btw i am not completely sold on the idea of the on-success value. if a query fails, it will result in error which has the query inside the error message already, i think we dont need to enforce it here when logging is disabled. try it in a real app to see, iirc it works this way.

that's also the reason why i was asking for some integration tests, to see how it will actually work for users

[SpencerKaiser]

Oh sorry, I didn't think you'd re-review after I resolved the merge stuff... I had some of that stuff locally but just wanted to fix the branch after the rebase. here's what I'm planning:

enabled will act as a master override; if disabled no logs will be output. Period.

If debugMode is set, it'll be used instead of what the logger was initialized with as a local override.

Sound good?

[SpencerKaiser]

Soooooooo I started to update the docs and realized the debugMode flag really doesn't make sense because right now only .find and .findOne support the new options. Should we remove that until we're able to add it to the other entity manager methods?

[B4nan]

for me this is about the find methods mainly, i'd keep it, you need to be able to set what to log (query or query + query params), right?

i guess the flush method should support this too somehow

[SpencerKaiser]

Just pushed the changes; let me know what you'd like to do. My recommendation is to pull the debugMode for now and add it back later when it's actually relevant

[SpencerKaiser]

Yea eventually I'd love for this to be added to update, flush, and persistAndFlush... that was something I hoped to work on next. If you're good with it as is, I can update the docs just not totally sure how 😬

[B4nan]

Before v6 branch gets merged to master, those docs are not deployed anywhere, so we can have something in progress there, not a huge deal.

I'd like to merge it within a few weeks, let's say around half of may.

[SpencerKaiser]

@B4nan this is ready to go unless you want an integration test; happy to write one, just can't figure out where they live (aside from the issue tests)

[B4nan]

They live everywhere :] I'd say more than 90% of the tests are integration tests. I usually use the tests/features folder these days, and moving the regression tests there too when they are about a specific feature.

[SpencerKaiser]

Is there a feature you think most closely relates to this? Should I just use the logger.test.ts file?

Do you have a good example of a simple integration test I could use as a baseline?

[B4nan]

All (or most of) the issue tests are integration test examples - they init the ORM and use the EM API.

I would create a new folder tests/features/logging or something like that, and move the logger.test.ts file there. I don't mind if the additional tests would go inside it or to a new file.

I'd like to see a test that has debug: false (so the default) globally and does few queries, some of them will override this via FindOptions, and the logs will be mocked and asserted. Many existing tests are already doing this, there is a mockLogger helper you can search for to see some examples. Then the same but with enabled logging globally and disabled locally.

[SpencerKaiser]

@B4nan I made an integration test but it isn't working as expected... can you take a look and tell me why you think it isn't working? I added that console in there to help with testing; if I set debug: true on the init, it captures all the discovery stuff, but it isn't writing anything when I query ☹️

[B4nan]

Why didn't you just copy the approach with the existing mockLogger helper?

I think your problem is that you only adjust the debug option in the config, but the logger is already created and you are not changing its cached value. This is handled in the mockLogger helper.

Or maybe its not problem with the test, but the implementation, I can take a closer look later this week if you want.

[SpencerKaiser]

@B4nan great catches, sorry for the sloppiness on those 😬 should be ready again

[B4nan]

the flag is logging.enabled, this still sounds a bit like it should be FindOptions.enabled

otherwise it looks good

[SpencerKaiser]

How about the new version?