fix: default logging

[jessie-ross]

SUMMARY

This PR makes default logging work as expected:

• Fixes duplicate logging.
• Allows DEBUG level logging in production.
• Makes logging respect LOG_LEVEL and LOG_FORMAT in config.
• Sets the LOG_LEVEL to INFO to match what we currently hardcode (theoretically a breaking change.)

I'm not sure what the initial goals were but by default we are logging DEBUG level everything but superset, which is set to INFO level (without regard to LOG_LEVEL,) and logging superset a second time without regard to the LOG_FORMAT config setting. This doesn't seem desirable for anybody.

This change makes default logging work as expected.

Resolves https://github.com/apache/superset/issues/21646 I think also resolves https://github.com/apache/superset/issues/4785

Cause of duplicate logging:

Python loggers output via handlers, the issue is we are adding handlers twice, once here:

https://github.com/apache/superset/blob/c0f8dfc7f99a0e83a8c9b3c083288c76f50aa662/superset/utils/logging_configurator.py#L50

And unintuitively also when we call logging.basicConfig() which by default adds a StreamHandler on root:

https://github.com/apache/superset/blob/c0f8dfc7f99a0e83a8c9b3c083288c76f50aa662/superset/utils/logging_configurator.py#L55

Minimum reproduction of the bug:

>>> import logging
>>> # No need to set BasicConfig, as logging.lastResort will be used by default
>>> logging.basicConfig()
>>> logging.warning('test')
WARNING:root:test
>>> sublogger = logging.getLogger('sublogger')
>>> sublogger.addHandler(logging.StreamHandler())
>>> sublogger.warning('test')
test
WARNING:sublogger:test
>>>

TESTING INSTRUCTIONS

Inspect startup log messages, trigger a log if need be.

ADDITIONAL INFORMATION

• [x] Has associated issue:
  • https://github.com/apache/superset/issues/21646
  • https://github.com/apache/superset/issues/4785
• [ ] Required feature flags:
• [ ] Changes UI
• [ ] Includes DB Migration (follow approval process in SIP-59)
  • [ ] Migration is atomic, supports rollback & is backwards-compatible
  • [ ] Confirm DB migration upgrade and downgrade tested
  • [ ] Runtime estimates and downtime expectations provided
• [ ] Introduces new feature or API
• [ ] Removes existing feature or API

[jessie-ross]

@dpgaspar Just a friendly reminder this PR is waiting for review

[jessie-ross]

Looks like the default log level was changed in https://github.com/apache/superset/pull/28134, so there should hopefully be no more points of contention.

[mistercrunch]

Looks like the changes from my PR aren't into this PR (more specifically this line for instance https://github.com/apache/superset/pull/28134/files#diff-c99ae4b2b09b756ab2189a99a9685229f9d12633fc2616c368ea869770f603bfR849), mind rebasing?

[jessie-ross]

@mistercrunch Thanks for the quick review! I've rebased and addressed your comments.

[rusackas]

Re-running CI 🤞

[codecov[bot]]

Codecov Report

All modified and coverable lines are covered by tests :white_check_mark:

Project coverage is 83.75%. Comparing base (76d897e) to head (34007cc). Report is 1094 commits behind head on master.

Additional details and impacted files

@@             Coverage Diff             @@
##           master   #27777       +/-   ##
===========================================
+ Coverage   60.48%   83.75%   +23.26%     
===========================================
  Files        1931      518     -1413     
  Lines       76236    37617    -38619     
  Branches     8568        0     -8568     
===========================================
- Hits        46114    31505    -14609     
+ Misses      28017     6112    -21905     
+ Partials     2105        0     -2105     

Flag	Coverage Δ
hive	48.90% <ø> (-0.27%)	:arrow_down:
javascript	?
mysql	77.29% <ø> (?)
postgres	77.40% <ø> (?)
presto	53.50% <ø> (-0.30%)	:arrow_down:
python	83.75% <ø> (+20.26%)	:arrow_up:
sqlite	76.85% <ø> (?)
unit	59.20% <ø> (+1.57%)	:arrow_up:

Flags with carried forward coverage won't be shown. Click here to find out more.

:umbrella: View full report in Codecov by Sentry.
:loudspeaker: Have feedback on the report? Share it here.