Simplify logging behavior

[eccabay]

Closes #1174 - design doc here

[codecov]

Codecov Report

Merging #2645 (8e3ac71) into main (4dffcfa) will decrease coverage by 0.1%.
The diff coverage is 100.0%.

@@           Coverage Diff           @@
##            main   #2645     +/-   ##
=======================================
- Coverage   99.9%   99.9%   -0.0%     
=======================================
  Files        301     301             
  Lines      27851   27751    -100     
=======================================
- Hits       27802   27702    -100     
  Misses        49      49             

Impacted Files	Coverage Δ
evalml/data_checks/no_variance_data_check.py	100.0% <ø> (ø)
...nts/transformers/preprocessing/text_transformer.py	100.0% <ø> (ø)
evalml/utils/logger.py	100.0% <ø> (ø)
evalml/automl/automl_search.py	99.9% <100.0%> (+0.1%)	⬆️
evalml/automl/callbacks.py	100.0% <100.0%> (ø)
...derstanding/prediction_explanations/_algorithms.py	99.0% <100.0%> (ø)
evalml/objectives/sensitivity_low_alert.py	100.0% <100.0%> (ø)
evalml/pipelines/component_graph.py	99.8% <100.0%> (+0.1%)	⬆️
evalml/pipelines/components/component_base.py	100.0% <100.0%> (ø)
evalml/pipelines/components/utils.py	100.0% <100.0%> (ø)
... and 9 more

---

Continue to review full report at Codecov.

Legend - Click here to learn more
Δ = absolute <relative> (impact), ø = not affected, ? = missing data
Powered by Codecov. Last update 4dffcfa...8e3ac71. Read the comment docs.

[dsherry]

Warning: missing parentheses to invoke the methods here

I'm surprised our lint didn't catch this! I wonder if there's a way / file an issue to have lint fail if we try to invoke a non-property as a property. Tagging @angela97lin since she's been messing with linting / style recently

[angela97lin]

That's a really good question @dsherry! I'm not sure I've run into anything that would have caught this--probably tricky to do since calling this without the paraentheses still returns the method and is "valid" 🤔 . Will keep an eye out though!

[dsherry]

What would happen if we deleted _deactivate_logger entirely from this PR?

[eccabay]

Deleting _deactivate_logger would mean we can no longer run AutoML search with verbose=False after running with verbose=True, since our get_logger function (run when verbose is True) modifies the same logger that's grabbed by logging.getLogger when verbose is False.

Just now in reading your comments I had a thought - it doesn't have to be the case that the logger obtained when verbose is True vs when verbose is False have the same name. Instead, we could create another sub-logger for when verbose is True (like I did with pipeline.describe() and others) so that it would maintain any user-configured logging behavior without needing to be reset with _deactivate_logger at the end of each method that uses it. This would also resolve your question above about setting the logging level back to logging.WARNING in _deactivate_logger, as that would no longer be necessary. Thoughts?

out of date

[bchen1116]

Left a question and a few nits, but this was great work!

[bchen1116]

Not sure why this is happening, but seems like I get warnings about high variance when I set verbose to False, but I don't get the same warning when verbose is True:

Would you know why this is happening?

[eccabay]

The warning is still there in both cases, it just appears in different ways! When verbose=False, the default logging is used, so warnings and higher are printed in the default format of red highlighting. When verbose=True, we override the default formatting settings, so while warnings are still printed to stdout (along with all the info level information), they are no longer highlighted in red.

You can see the same warning in the verbose=True case where the report of the Decision Tree cv scores are.

[chukarsten]

This is a great PR. I like what's going on here and the simplicity of it.

I think the one thing we should address before merge is the testing strategy. Does it make sense to test this feature by running a variety of tests with verbose on and off? I think this is OK for tests that don't drastically increase the test runtime by much (don't run automl.search). What are your thoughts on keeping the tests as written before this PR, but adding verbose=True to all of them, then have just a single test that verifies that nothing is logged when verbose=False. It seems that if verbose=False, a single test should capture that entirely.

Let me know your thoughts. If you don't want to do that, I think it would be sufficient to show the runtime of the tests isn't drastically affected!

Another nice to have would be if you could silence the dask/cfengine stuff in the docs. Out of scope, so feel free to tell me to pound sand.

[chukarsten]

Ok, do we need to run this test for both verbosities if we're not checking for anything different?

[chukarsten]

Same question here, except I think now we're also going to pay a penalty of running search. I worry that all the parametrization of verbosity doesn't really provide much testing benefit while increasing the runtime of tests.

[chukarsten]

I think this test makes sense and can test both verbosities without much penalty in runtime.

[eccabay]

@chukarsten thanks for the testing suggestions! I took another look at the tests with parameterizations of verbose values, and I agree, a lot of them weren't necessary. I've filtered through them, according to a few criteria:

• Any tests that didn't change behavior whether verbose was True or False (i.e. the message logged was either warning or error level) don't need parameterization. If they pass when verbose is False, they will pass when verbose is True by definition.
• I removed some redundant tests, i.e. testing verbose/not in methods that other tests already covered. For example, parameterizing verbose=[True, False] in test_pipeline_limits made sure the distinction between the values worked correctly in both __init__ and search. Therefore, we didn't need to parameterize verbose in test_automl_drop_unknown_columns, since the logging differences there only occur in __init__.

At this point, every test that includes @pytest.mark.parametrize("verbose", [True, False]) should be testing something unique with respect to the verbose flag's functionality and behavior.