Skip to content

Enable showing DeprecationWarning in debug_on and add unit test #1554

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

Merged
merged 8 commits into from
Mar 4, 2021
Merged
Show file tree
Hide file tree
Changes from all commits
Commits
File filter

Filter by extension

Filter by extension

Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
50 changes: 50 additions & 0 deletions satpy/tests/test_utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -17,9 +17,14 @@
# satpy. If not, see <http://www.gnu.org/licenses/>.
"""Testing of utils."""

import logging
import unittest
import warnings
from unittest import mock

import pytest
from numpy import sqrt

from satpy.utils import angle2xyz, lonlat2xyz, xyz2angle, xyz2lonlat, proj_units_to_meters, get_satpos


Expand Down Expand Up @@ -307,3 +312,48 @@ def test_specific_check_satpy(self):
checked_fake = True
self.assertTrue(checked_fake, "Did not find __fake module "
"mentioned in checks")


def test_debug_on(caplog):
"""Test that debug_on is working as expected."""
from satpy.utils import debug_on, debug_off, debug

def depwarn():
logger = logging.getLogger("satpy.silly")
logger.debug("But now it's just got SILLY.")
warnings.warn("Stop that! It's SILLY.", DeprecationWarning)
warnings.filterwarnings("ignore", category=DeprecationWarning)
debug_on(False)
filts_before = warnings.filters.copy()
# test that logging on, but deprecation warnings still off
with caplog.at_level(logging.DEBUG):
depwarn()
assert warnings.filters == filts_before
assert "But now it's just got SILLY." in caplog.text
debug_on(True)
# test that logging on and deprecation warnings on
with pytest.warns(DeprecationWarning):
depwarn()
assert warnings.filters != filts_before
debug_off() # other tests assume debugging is off
# test that filters were reset
assert warnings.filters == filts_before
with debug():
assert warnings.filters != filts_before
assert warnings.filters == filts_before


def test_logging_on_and_off(caplog):
"""Test that switching logging on and off works."""
from satpy.utils import logging_on, logging_off
logger = logging.getLogger("satpy.silly")
logging_on()
with caplog.at_level(logging.WARNING):
logger.debug("I'd like to leave the army please, sir.")
logger.warning("Stop that! It's SILLY.")
assert "Stop that! It's SILLY" in caplog.text
assert "I'd like to leave the army please, sir." not in caplog.text
logging_off()
with caplog.at_level(logging.DEBUG):
logger.warning("You've got a nice army base here, Colonel.")
assert "You've got a nice army base here, Colonel." not in caplog.text
72 changes: 70 additions & 2 deletions satpy/utils.py
Original file line number Diff line number Diff line change
Expand Up @@ -21,6 +21,7 @@
import logging
import os
import warnings
import contextlib
from typing import Mapping

import numpy as np
Expand All @@ -43,16 +44,83 @@ def ensure_dir(filename):
os.makedirs(directory)


def debug_on():
"""Turn debugging logging on."""
def debug_on(deprecation_warnings=True):
"""Turn debugging logging on.

Sets up a StreamHandler to to `sys.stderr` at debug level for all
loggers, such that all debug messages (and log messages with higher
severity) are logged to the standard error stream.

By default, since Satpy 0.26, this also enables the global visibility
of deprecation warnings. This can be suppressed by passing a false
value.

Args:
deprecation_warnings (Optional[bool]): Switch on deprecation warnings.
Defaults to True.

Returns:
None
"""
logging_on(logging.DEBUG)
if deprecation_warnings:
deprecation_warnings_on()


def debug_off():
"""Turn debugging logging off.

This disables both debugging logging and the global visibility of
deprecation warnings.
"""
logging_off()
deprecation_warnings_off()


@contextlib.contextmanager
def debug(deprecation_warnings=True):
"""Context manager to temporarily set debugging on.

Example::

>>> with satpy.utils.debug():
... code_here()

Args:
deprecation_warnings (Optional[bool]): Switch on deprecation warnings.
Defaults to True.
"""
debug_on(deprecation_warnings=deprecation_warnings)
yield
debug_off()


def trace_on():
"""Turn trace logging on."""
logging_on(TRACE_LEVEL)


class _WarningManager:
"""Class to handle switching warnings on and off."""

filt = None


_warning_manager = _WarningManager()
Comment on lines +103 to +109
Copy link
Member

Choose a reason for hiding this comment

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

do we really need a class here? would it work with just a module variable, eg _warning_filter?

Copy link
Member Author

Choose a reason for hiding this comment

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

That would have to be a global variable. I personally hate global variables. I find them confusing, error-prone, and hard to test.

Copy link
Member

Choose a reason for hiding this comment

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

In a way, isn't _warning_manager also a global variable? Yes, it's a class instance, but everything in Python is a class instance.

Copy link
Member Author

Choose a reason for hiding this comment

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

In a way yes, and in a way no. There is no global keyword, and I'm not changing somebody else's namespace; rather, I'm just changing the state of a mutable object that happens to be in the module namespace. The difference is subtle and in this case largely semantic, but if somebody did have the idea to use their own reference to _warning_manager (hopefully for testing purposes) it would be affected by changes, unlike a global variable which would be a name bound to a new object.

Copy link
Member

Choose a reason for hiding this comment

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

ok, I get your point.

Now, looking at the bigger picture, why use a class at all and not just a constant?
When doing warnings.filterwarnings("default", category=DeprecationWarning), the last filter becomes in principle ('default', None, DeprecationWarning, None, 0) (I say in principle because there could be a race condition, or are warning filters thread-safe?).
So we could have _deprecation_warning_filter = ('default', None, DeprecationWarning, None, 0) at the module level and use that in deprecation_warnings_off.
Or are you worried that the filter syntax will change in certain circumstances?

Copy link
Member Author

Choose a reason for hiding this comment

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

I don't believe it's thread safe, let's just hope people don't rely on debug_on()...debug_off() to work reliably in threaded code.

Copy link
Member

Choose a reason for hiding this comment

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

about thread-safety:

The catch_warnings manager works by replacing and then later restoring the module’s showwarning() function and internal list of filter specifications. This means the context manager is modifying global state and therefore is not thread-safe.

(last lines in https://docs.python.org/3/library/warnings.html)

Copy link
Member

@mraspaud mraspaud Feb 25, 2021

Choose a reason for hiding this comment

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

Ok, I'm not thrilled with the current solution, but for lack of a better option, I say we leave it as it is.
@pnuu @djhoese any more comments on this?
Otherwise I'll merge this tonight.

Copy link
Member

Choose a reason for hiding this comment

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

No further comments from me 👍

Copy link
Member Author

Choose a reason for hiding this comment

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

I'm not thrilled with the Python 'warnings' module, so there is no solution that I would be thrilled with.



def deprecation_warnings_on():
"""Switch on deprecation warnings."""
warnings.filterwarnings("default", category=DeprecationWarning)
_warning_manager.filt = warnings.filters[0]


def deprecation_warnings_off():
"""Switch off deprecation warnings."""
if _warning_manager.filt in warnings.filters:
warnings.filters.remove(_warning_manager.filt)


def logging_on(level=logging.WARNING):
"""Turn logging on."""
global _is_logging_on
Expand Down