Skip to content

bpo-37857: Invalidate cache when log level changed directly#15286

Closed
zaneb wants to merge 5 commits intopython:masterfrom
zaneb:fix-issue-37857
Closed

bpo-37857: Invalidate cache when log level changed directly#15286
zaneb wants to merge 5 commits intopython:masterfrom
zaneb:fix-issue-37857

Conversation

@zaneb
Copy link
Contributor

@zaneb zaneb commented Aug 14, 2019

bpo-37857

While the logging level of a Logger should really be changed only by calling the setLevel() method, there exists code in the wild that changes it by setting the public level attribute directly. Prior to
Python 3.7, this worked correctly.

The addition of caching to Logger.isEnabledFor() by the fix for bpo-30962, #2752, means that direct changes to the level now leave the cache in a state inconsistent with the Logger - an extraordinarily difficult thing to debug.

Make level a property that invalidates the cache when set. This ensures that existing application code will continue to work as it did with previous versions of Python.

https://bugs.python.org/issue37857

While the logging level of a Logger should really be changed only by
calling the setLevel() method, there exists code in the wild that
changes it by setting the public 'level' attribute directly. Prior to
Python 3.7, this worked correctly.

The addition of caching to Logger.isEnabledFor() by the fix for bpo-30962,
78c18a9, means that direct changes to
the level now leave the cache in a state inconsistent with the Logger -
an extraordinarily difficult thing to debug.

Make 'level' a property that invalidates the cache when set. This
ensures that existing application code will continue to work as it did
with previous versions of Python.
Copy link
Contributor

@epicfaace epicfaace left a comment

Choose a reason for hiding this comment

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

Looks good!

@vsajip
Copy link
Member

vsajip commented Sep 9, 2019

Please see my comments on the issue.

@zaneb
Copy link
Contributor Author

zaneb commented Sep 9, 2019

@vsajip what if we added a DeprecationWarning to the setter? That would help people find and fix their old code, and avoid encouraging more folks to try using the wrong interface.

@avylove
Copy link
Contributor

avylove commented Sep 20, 2019

I'm not sure if this is needed or not, but there are a couple things I don't like about the approach. Primarily because it's inconstant. I would suggest changing all level references to _level and leave self.manager._clear_cache() in setLevel() since that is the documented interface.

Since Logger.level is not documented, simply switching to Logger._level will not break the published API. However, those accessing Logger.level would not get a failure, they would simply create a new attribute called level and continue to operate at the previous level. This pretty similar to the state we have now.

I think a reasonable compromise might be to change self.level to self._level and make level a read-only property. That would raise AttributeError: can't set attribute when someone tried to set it directly. The traceback should make it obvious this is referring to level. @vsajip, does this seem workable? If this isn't a sufficient error, a non-functioning setter could be introduced that raises a more descriptive exception.

One could argue a deprecation period is needed and a setter could be used to do that. I wouldn't object to that, but I also would argue it isn't needed since it's not documented and already doesn't work in 3.7+. If you did want to introduce a functioning setter for level, it should be independent of the rest of the code, i.e. if you delete it, everything else still works. Basically, the setter would simply call setLevel().

Never set the level attribute directly.
Don't try to set the level attribute directly; use the setLevel()
method.
The level attribute of a Logger instance should never be set directly;
the setLevel() method should be used instead. Deprecate the setter to
warn anyone with code doing it incorrectly to change it.
@avylove
Copy link
Contributor

avylove commented Sep 22, 2019

You're still using level in getEffectiveLevel() rather than _level. This inadvertently makes getEffectiveLevel() slower by requiring an additional method call. Since it's part of the same class, it should use _level.

Although getEffectiveLevel() is only called from isEnabledFor() in the
slow path when there is a cache miss, using the new _level attribute
directly means that the change to make the level attribute a property is
be completely performance neutral for the stdlib code itself. (User code
accessing the level propertly directly will still be slightly slower.)
@csabella
Copy link
Contributor

Based on the discussion on the bug tracker, it looks like @vsajip wasn't in favor of this change. I'm going to close this PR for now with the understanding that it can be revived if this becomes the path forward in the future. Thank you.

@csabella csabella closed this Jun 12, 2020
@zaneb
Copy link
Contributor Author

zaneb commented Jun 15, 2020

Based on the discussion on the bug tracker, it looks like @vsajip wasn't in favor of this change.

I did make the changes suggested by @avylove to address those concerns, but @vsajip has not commented on them.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment

Projects

None yet

Development

Successfully merging this pull request may close these issues.

7 participants