CT-2022: Fix --quiet and DBT_ENABLE_LEGACY_LOGGER during initialization

[peterallenwebb]

resolves #6847

Description

Checks the values of --quiet and --enable-legacy-logger after the cli and env parameters are parsed, but before the user profile is parsed. This way, the value of those parameters can be respected even for events which are fired during profile parsing.

Checklist

• I have read the contributing guide and understand what's expected of me
• I have signed the CLA
• I have run this code in development and it appears to resolve the stated issue
• This PR includes tests, or tests are not required/relevant for this PR
• I have opened an issue to add/update docs, or docs changes are not required/relevant for this PR
• I have run changie new to create a changelog entry

[github-actions]

Thank you for your pull request! We could not find a changelog entry for this change. For details on how to document a change, see the contributing guide.

[aranke]

Can we add a test to prevent these regressions?

[peterallenwebb]

@aranke I'm glad you prodded me to write a test, because once I started on that I realized that I could not reproduce the original issue on main, and that in fact we do not (as far as I could see after searching for 10-15 minutes) have any code paths which would potentially fire non-error events before the call to setup_event_logger() in requires.py.

I'm curious whether you think it's worth merging the code under review at all. It would protect us from regressions to the desired behavior if anyone were to ever fire events before log initialization in the future, but that's the only advantage I can imagine. In the meantime it's hard to create a test which would fail without the fix under review.

[jtcohen6]

we do not (as far as I could see after searching for 10-15 minutes) have any code paths which would potentially fire non-error events before the call to setup_event_logger() in requires.py

@peterallenwebb The original regression report in #6749 was for the MissingProfileTarget event.

Repro case:

1. Define a profile in profiles.yml that has a target named default, and doesn't have target: default in it
2. Use that profile (profile field in dbt_project.yml)
3. dbt run

FWIW, this seems to "just work" on the main branch, even without this change:

$ dbt run
17:55:10  Running with dbt=1.5.0-b1
17:55:10  target not specified in profile 'garage-postgres', using 'default'
17:55:10  Unable to do partial parsing because profile has changed
17:55:11  Found 0 models, 0 tests, 0 snapshots, 0 analyses, 298 macros, 0 operations, 1 seed file, 0 sources, 0 exposures, 0 metrics, 0 groups
17:55:11
17:55:11  Nothing to do. Try checking your model configs and model specification args
$ dbt --quiet run

I'm not sure exactly how, but: I was under the impression that Flags read user_config, and therefore the profiles.yml, and therefore would raise this info-level message, before setup_event_logger is called. But it looks like it's going down a different codepath — read_profile instead of render_profile.

[peterallenwebb]

@jtcohen6 I was under the same impression you were.

What's happening is that preflight() (triggered by the @requires.profile decorator on the click command) completes before the profile is completely analyzed. While profiles.yml is loaded during Flags.__init__, it is not analyzed or validated in any depth. Later, load_profile() (triggered by the @requires.profile decorator) loads the profile again, this time performing validation which may fire the MissingProfileTarget warning.

So, we don't need to do anything to resolve the original issue on main.

The only question is whether it is worth it to keep this fix in place, just in case someone adds non-error events to the Flag generation code, or any other code which they might execute between command line parsing and log configuration. I am leaning toward no at the moment, since it adds complexity, but happy to let you make the call.

[jtcohen6]

Thanks for digging in to confirm!

The only question is whether it is worth it to keep this fix in place, just in case someone adds non-error events to the Flag generation code, or any other code which they might execute between command line parsing and log configuration. I am leaning toward no at the moment, since it adds complexity, but happy to let you make the call.

I agree with "no."

In the medium term, we should stop reading profiles.yml at all during app initialization (including Flags), by moving UserConfig to its own separate file.

I called out in #6207 (comment) that we shouldn't do any more-complex logging while initializing configs:

If we can locate dbt_config.yml, and there's an error while reading it, it's always an error. We immediately raise the error and stop.

Basically: Logging is not allowed until we have an initialized app, including a fully initialized & configured logger. That codepath should be incredibly clear, and if anything goes wrong during that initialization, it's a show-stopping error.

[peterallenwebb]

Closing based on the consensus that this is already fixed on main, and no further work is warranted.