Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Overhaul Pyomo logging configuration #1797

Merged
merged 18 commits into from
Jan 27, 2021

Conversation

jsiirola
Copy link
Member

Fixes #1760

Summary/Motivation:

The original Pyomo logging configuration was heavily geared around the pyomo script and did not conform to the general behavior expected by users. For example, calling logging.basicConfig() was effectively ignored by the Pyomo loggers. This PR does an overhaul of the Pyomo logger configuration to more closely follow the accepted (and expected) Python logging behavior. In particular, the bulk of the logic is now implemented through Formatter and Filter objects (allowing users to reuse the formatting in their own Handlers), and the Pyomo default logging will defers to a root logger if the user / calling environment created one.

This also creates a standardized is_debug_set function (in pyomo.common.log) to replace our use of if __debug__ and logger.isEnabledFor(logging.DEBUG). The old idiom would generate debugging log records when the root logger was left in "NOTSET" (which is the case not what the core Pyomo log configuration does not explicitly set a level). The new function preserves the old behavior (of only emitting DEBUG log records when the user explicitly set a debugging level) by only returning True if the effective level is in NOTSET < level <= DEBUG.

  • Note to reviewers: I am not completely thrilled with the name of this function and am soliciting alternative suggestions.

This should be fully-backwards compatible with the existing logging setup (in that existing scripts that log correctly should continue to log in the same manner).

Changes proposed in this PR:

  • Overhaul the Pyomo logger to move the bulk of the formatting (and line wrapping) logic into a proper Formatter class.
  • Rely on a Filter class to defer to a root level logger (if configured)
  • Overhaul the logging configuration in the scripting interface to more robustly restore the logging state after the command exits
  • define a standardized is_debug_set function (and propagate throughout code base)
  • Deprecate the LogHandler class and configure_loggers function

Legal Acknowledgement

By contributing to this software project, I have read the contribution guide and agree to the following terms and conditions for my contribution:

  1. I agree my contributions are submitted under the BSD license.
  2. I represent I am authorized to make the contributions and grant the license. If my employer has rights to intellectual property that includes these contributions, I represent that I have received permission to make contributions and grant the required license on behalf of that employer.

@codecov
Copy link

codecov bot commented Jan 26, 2021

Codecov Report

Merging #1797 (caac114) into master (da709cd) will decrease coverage by 0.43%.
The diff coverage is 89.83%.

Impacted file tree graph

@@            Coverage Diff             @@
##           master    #1797      +/-   ##
==========================================
- Coverage   75.14%   74.71%   -0.44%     
==========================================
  Files         638      638              
  Lines       91904    92030     +126     
==========================================
- Hits        69065    68760     -305     
- Misses      22839    23270     +431     
Impacted Files Coverage Δ
pyomo/bilevel/plugins/transform.py 79.10% <ø> (-0.61%) ⬇️
pyomo/core/base/alias.py 0.00% <0.00%> (ø)
pyomo/pysp/util/misc.py 59.87% <ø> (+0.18%) ⬆️
pyomo/contrib/gdpopt/util.py 93.72% <33.33%> (ø)
pyomo/core/base/PyomoModel.py 78.94% <57.14%> (+0.08%) ⬆️
pyomo/scripting/util.py 56.02% <76.38%> (+0.69%) ⬆️
pyomo/network/decomposition.py 90.61% <85.71%> (+0.06%) ⬆️
pyomo/core/base/block.py 90.77% <87.50%> (+0.02%) ⬆️
pyomo/common/log.py 96.00% <95.00%> (-1.90%) ⬇️
pyomo/contrib/fme/fourier_motzkin_elimination.py 97.35% <100.00%> (-0.34%) ⬇️
... and 43 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 da709cd...caac114. Read the comment docs.

Copy link
Member

@blnicho blnicho left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I found a couple typos but otherwise I think this looks fine

pyomo/common/log.py Outdated Show resolved Hide resolved
pyomo/common/log.py Outdated Show resolved Hide resolved
Copy link
Member Author

@jsiirola jsiirola left a comment

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

Resolved @blnicho comments.

pyomo/common/log.py Outdated Show resolved Hide resolved
pyomo/common/log.py Outdated Show resolved Hide resolved
@blnicho blnicho requested a review from mrmundt January 26, 2021 19:41
@@ -727,33 +727,24 @@ def test_inf_bounds_on_expr(self):
self.assertEqual(lb, None)
self.assertEqual(ub, None)

@unittest.skip('This test passes locally, but not on travis or appveyor. I will add an issue.')
Copy link
Contributor

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

I'm guessing this is a sneaky bug fix?

Copy link
Member Author

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

It is actually a fix to the implementation of the test (leveraging the LoggingIntercept context manager resolves portability problems)

@blnicho blnicho merged commit 1f4174a into Pyomo:master Jan 27, 2021
@jsiirola jsiirola deleted the log-formatter-update branch January 29, 2021 16:38
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

Successfully merging this pull request may close these issues.

"pyomo" Logger Sends Logs To Stdout Irrespective of User's Logging Config
3 participants