103 date parsing warning (#104)

* filter pandas warnings; improve logger

* more logging issues

* update logs

* Update test_cache.py

* Update log.py

Author: rweigel

hapiclient/hapitime.py

@@ -1,6 +1,7 @@
 """Functions for manipulating HAPI times (restricted ISO 8601 strings)."""
 import re
 import time
+import warnings
 
 import pandas
 import isodate
@@ -268,7 +269,9 @@ def hapitime2datetime(Time, **kwargs):
         if pandas_major_version < 2:
             Time = pandas.to_datetime(Time, infer_datetime_format=True).tz_convert(tzinfo).to_pydatetime()
         else:
-            Time = pandas.to_datetime(Time).tz_convert(tzinfo).to_pydatetime()
+            with warnings.catch_warnings():
+                warnings.filterwarnings('ignore', message='Could not infer format')
+                Time = pandas.to_datetime(Time).tz_convert(tzinfo).to_pydatetime()
         if reshape:
             Time = np.reshape(Time, shape)
         toc = time.time() - tic

hapiclient/log.py

@@ -5,9 +5,14 @@
 _INTERNAL_HANDLER_ATTR = "_hapiclient_internal_handler"
 _INTERNAL_LEVEL_ATTR = "_hapiclient_internal_level"
 
-# Disable propagation by default so hapiclient logs don't bubble up
-# to root logger (e.g., pytest's logger). Can be re-enabled by user.
-_logger.propagate = False
+# Per Python library best practices, add a NullHandler and leave propagation
+# enabled so the application controls output. When running under pytest,
+# disable propagation to prevent hapiclient INFO messages from leaking into
+# pytest's captured log output.
+import sys as _sys
+_logger.addHandler(_logging.NullHandler())
+_logger.propagate = "pytest" not in _sys.modules
+del _sys
 
 
 def configure_logging(logging):
@@ -21,21 +26,23 @@ def configure_logging(logging):
     has_user_handlers = any(
         not getattr(handler, _INTERNAL_HANDLER_ATTR, False)
         for handler in _logger.handlers
-    )
+    ) or bool(_logging.root.handlers)
 
     if logging is True:
         _logger.setLevel(_logging.INFO)
         setattr(_logger, _INTERNAL_LEVEL_ATTR, _logging.INFO)
-        _logger.propagate = False
+        _logger.propagate = False  # use our own handler when logging=True
         _has_internal = any(getattr(h, _INTERNAL_HANDLER_ATTR, False) for h in _logger.handlers)
         if not _has_internal:
             import sys
             _handler = _logging.StreamHandler(sys.stdout)
             _handler.setFormatter(_logging.Formatter("%(message)s"))
             setattr(_handler, _INTERNAL_HANDLER_ATTR, True)
             _logger.addHandler(_handler)
+
     if logging is False:
         if has_user_level or has_user_handlers:
+            _logger.propagate = True  # ensure messages reach the user-configured handler
             #from .util import warning
             if has_user_handlers:
                 pass
@@ -55,5 +62,7 @@ def log(msg, opts=None):
     # opts is not used but kept for backward compatibility
     import sys
 
-    pre = sys._getframe(1).f_code.co_name + '(): '
-    _logger.info("hapiclient." + pre + msg)
+    frame = sys._getframe(1)
+    module = frame.f_globals.get('__name__', 'hapiclient').split('.')[0]
+    pre = frame.f_code.co_name + '(): '
+    _logger.info(module + "." + pre + msg)

hapiclient/util.py

@@ -104,80 +104,65 @@ def unicode_error_message(name):
     return msg
 
 
-def warning_test():
-    """For testing warning function."""
-
-    # Should show warnings in order and only HAPIWarning {1,2} should
-    # have a different format
-    from warnings import warn
-
-    warn('Normal warning 1')
-    warn('Normal warning 2')
-
-    warning('HAPI Warning 1')
-    warning('HAPI Warning 2')
-
-    warn('Normal warning 3')
-    warn('Normal warning 4')
+class HAPIWarning(Warning):
+    pass
 
 
 def warning(*args):
     """Display a short warning message.
 
     warning(message) raises a warning of type HAPIWarning and displays
-    "Warning: " + message. Use for warnings when a full stack trace is not
+    "HAPIWarning: " + message. Use for warnings when a full stack trace is not
     needed.
     """
 
+    import logging
     import warnings
-    from os import path
-    from sys import stderr
-    from inspect import stack
+    import platform
 
     message = args[0]
-    if len(args) > 1:
-        fname = args[1]
-    else:
-        fname = stack()[1][1]
 
-    #line = stack()[1][2]
+    if logging.getLogger("hapiclient").level == logging.DEBUG:
+        warnings.warn(message, stacklevel=2)
+        return
 
-    fname = path.basename(fname)
+    _prefix = "\x1b[31mHAPIWarning:\x1b[0m "
+    if platform.system() == 'Windows' and pythonshell() == 'shell':
+        _prefix = "HAPIWarning: "
 
-    def prefix():
-        import platform
-        prefix = "\x1b[31mHAPIWarning:\x1b[0m "
-        if platform.system() == 'Windows' and pythonshell() == 'shell':
-            prefix = "HAPIWarning: "
+    _orig_formatwarning = warnings.formatwarning
 
-        return prefix
+    def _formatwarning(msg, category, filename, lineno, line=None):
+        if issubclass(category, HAPIWarning):
+            return _prefix + str(msg) + "\n"
+        return _orig_formatwarning(msg, category, filename, lineno, line)
 
-    # Custom warning format function
-    def _warning(message, category=UserWarning, filename='', lineno=-1, file=None, line=''):
-        if category.__name__ == "HAPIWarning":
-            stderr.write(prefix() + str(message) + "\n")
-        else:
-            # Use default showwarning function.
-            showwarning_default(message, category=UserWarning,
-                                filename='', lineno=-1,
-                                file=None, line='')
+    warnings.formatwarning = _formatwarning
+    try:
+        warnings.warn(message, HAPIWarning, stacklevel=2)
+    finally:
+        warnings.formatwarning = _orig_formatwarning
 
-        stderr.flush()
 
-        # Reset showwarning function to default
-        warnings.showwarning = showwarning_default
+def warning_test():
+    """For testing warning function."""
 
-    class HAPIWarning(Warning):
-        pass
+    # Should show warnings in order and only HAPIWarning {1,2} should
+    # have a different format
+    from warnings import warn
+
+    warn('Normal warning 1')
+    warn('Normal warning 2')
 
-    # Copy default showwarning function
-    showwarning_default = warnings.showwarning
+    warning('HAPI Warning 1')
+    warning('HAPI Warning 2')
+
+    warn('Normal warning 3')
+    warn('Normal warning 4')
 
-    # Use custom warning function instead of default
-    warnings.showwarning = _warning
 
-    # Raise warning
-    warnings.warn(message, HAPIWarning)
+if __name__ == "__main__":
+    warning_test()
 
 
 class HAPIError(Exception):

misc/hapi_logging_demo.py

@@ -43,13 +43,8 @@ def reset_hapiclient_logging():
   # 2. Log to console using Python's standard logging module
   if 4 <= method <= 6:
     import logging
-    logger = logging.getLogger("hapiclient")
-    logger.setLevel(logging.INFO)
-    handler = logging.StreamHandler()
-    formatter = logging.Formatter("%(asctime)s [%(name)s] %(message)s", datefmt="%Y-%m-%dT%H:%M:%S")
-    formatter.default_msec_format = '%s.%03d'
-    handler.setFormatter(formatter)
-    logger.addHandler(handler)
+
+    logging.basicConfig(level=logging.INFO, format="%(asctime)s [%(name)s] %(message)s", datefmt="%Y-%m-%dT%H:%M:%S")
 
     if method == 4:
       # Use standard logging because defined

test/test_cache.log

@@ -1,5 +1,6 @@
 # See ../README.md for instructions on running tests.
 import shutil
+import pytest
 
 from hapiclient.hapi import hapi
 
@@ -20,6 +21,7 @@
 start = '1970-01-01'
 stop  = '1970-01-01T00:00:03'
 
+
 def test_cache_short():
 
     # Compare read with empty cache with read with hot cache and usecache=True
@@ -36,23 +38,21 @@ def test_cache_short():
     assert compare.equal(data, data2)
 
 
+@pytest.mark.filterwarnings("ignore::hapiclient.util.HAPIWarning")
 def test_cache_error():
 
     from unittest.mock import patch
 
-    import io
-    import contextlib
     import pathlib
     import tempfile
     from hapiclient.util import write_atomic
 
+    from hapiclient.util import HAPIWarning
+
     def assert_warns(fn, expected):
-        buf = io.StringIO()
-        with contextlib.redirect_stderr(buf):
+        import pytest
+        with pytest.warns(HAPIWarning, match=expected):
             result = fn()
-            print(buf.getvalue())
-        msg = f"Expected '{expected}' in stderr: {buf.getvalue()!r}"
-        assert expected in buf.getvalue(), msg
         return result
 
     # Direct calls to write_atomic()

test/test_cache.py

@@ -0,0 +1,5 @@
+test_api()
+test_error_conditions()
+  Checking that hapitime2datetime('1999') throws HAPIError
+  Checking that hapitime2datetime('2001-01-01T00:00:00', allow_missing_Z=False) throws HAPIError
+test_warning_conditions()

test/test_hapitime2datetime.log

@@ -84,6 +84,7 @@ def test_parsing():
 
 def test_error_conditions():
   from hapiclient import HAPIError
+
   logger.info("test_error_conditions()")
 
   Time = "1999"
@@ -96,7 +97,43 @@ def test_error_conditions():
     assert False, "HAPIError not raised for hapitime2datetime(" + str(Time) + ")."
 
 
+  Time = "2001-01-01T00:00:00"
+  logger.info("  Checking that hapitime2datetime('" + str(Time) + "', allow_missing_Z=False) throws HAPIError")
+  try:
+    hapitime2datetime(Time, allow_missing_Z=False)
+  except HAPIError:
+    pass
+  else:
+    assert False, "HAPIError not raised for hapitime2datetime(" + str(Time) + ", allow_missing_Z=False)."
+
+
+def test_warning_conditions():
+
+  import io
+  import logging
+
+  logger.info("test_warning_conditions()")
+
+  stream = io.StringIO()
+  handler = logging.StreamHandler(stream)
+  logger2 = logging.getLogger("hapiclient")
+  logger2.setLevel(logging.DEBUG)
+  logger2.addHandler(handler)
+  logger2.propagate = False
+
+  try:
+    Time = "2001-001T00:00:00Z"
+    hapitime2datetime(Time)
+    output = stream.getvalue()
+    assert "Pandas processing failed with error" in output, \
+        f"Expected 'Pandas processing failed with error' in log output, got:\n{output}"
+  finally:
+    logger2.removeHandler(handler)
+    logger2.propagate = True
+
+
 if __name__ == '__main__':
   test_api()
   test_parsing()
   test_error_conditions()
+  test_warning_conditions()