Repository: natcap/invest
Pull request #642 (2021-09-13 17:39:19)

Resolve merge conflict in PR #640
# Description
This PR resolves the merge conflict in PR #640, merging the changes from PR #636 into `release/3.10`.

# Checklist
- [x] Updated HISTORY.rst (if these changes are user-facing) (just a merge conflict)

- [x] Updated the user's guide (if needed) (not needed)



Patch:
diff --git a/HISTORY.rst b/HISTORY.rst
index 0e840e379..1ba496619 100644
--- a/HISTORY.rst
+++ b/HISTORY.rst
@@ -79,6 +79,10 @@ Unreleased Changes (3.9.1)
       could have been computed by previous runs.
     * Validation now returns a more helpful message when a spatial input has
       no projection defined.
+    * Added some logging to ``natcap.invest.utils._log_gdal_errors`` to aid in
+      debugging some hard-to-reproduce GDAL logging errors that occasionally
+      cause InVEST models to crash.  If GDAL calls ``_log_gdal_errors`` with an
+      incorrect set of arguments, this is now logged.
 * Carbon
     * Fixed a bug where, if rate change and discount rate were set to 0, the
       valuation results were in $/year rather than $, too small by a factor of
diff --git a/requirements-docs.yml b/requirements-docs.yml
index ebe9244d9..27a46b115 100644
--- a/requirements-docs.yml
+++ b/requirements-docs.yml
@@ -2,15 +2,15 @@
 # ---------------------
 # This file records the packages needed to build on readthedocs.org.
 # It assumes that the natcap.invest package is being
-# installed to the readthedocs virtualenv separately.  
+# installed to the readthedocs virtualenv separately.
 channels:
 - conda-forge
 - defaults
 dependencies:
 - chardet>=3.0.4
 - Cython
-- Flask
 - GDAL>=3.1.2,<3.3.0
+- Flask
 - numpy>=1.11.0,!=1.16.0
 - pandas>=1.0,<1.2.0
 - pip
diff --git a/src/natcap/invest/ui/sdr.py b/src/natcap/invest/ui/sdr.py
index 26bc44733..71d01f1c1 100644
--- a/src/natcap/invest/ui/sdr.py
+++ b/src/natcap/invest/ui/sdr.py
@@ -149,6 +149,7 @@ class SDR(model.InVESTModel):
             self.k_param.args_key: self.k_param.value(),
             self.ic_0_param.args_key: self.ic_0_param.value(),
             self.sdr_max.args_key: self.sdr_max.value(),
+            self.l_max.args_key: self.l_max.value(),
         }
 
         return args
diff --git a/src/natcap/invest/utils.py b/src/natcap/invest/utils.py
index 09e7c02f2..c81db41f5 100644
--- a/src/natcap/invest/utils.py
+++ b/src/natcap/invest/utils.py
@@ -18,6 +18,7 @@ import pygeoprocessing
 
 
 LOGGER = logging.getLogger(__name__)
+_OSGEO_LOGGER = logging.getLogger('osgeo')
 LOG_FMT = (
     "%(asctime)s "
     "(%(name)s) "
@@ -44,6 +45,60 @@ GDAL_ERROR_LEVELS = {
 DEFAULT_OSR_AXIS_MAPPING_STRATEGY = osr.OAMS_TRADITIONAL_GIS_ORDER
 
 
+def _log_gdal_errors(*args, **kwargs):
+    """Log error messages to osgeo.
+
+    All error messages are logged with reasonable ``logging`` levels based
+    on the GDAL error level.
+
+    Note:
+        This function is designed to accept any number of positional and
+        keyword arguments because of some odd forums questions where this
+        function was being called with an unexpected number of arguments.
+        With this catch-all function signature, we can at least guarantee
+        that in the off chance this function is called with the wrong
+        parameters, we can at least log what happened.  See the issue at
+        https://github.com/natcap/invest/issues/630 for details.
+
+    Args:
+        err_level (int): The GDAL error level (e.g. ``gdal.CE_Failure``)
+        err_no (int): The GDAL error number.  For a full listing of error
+            codes, see: http://www.gdal.org/cpl__error_8h.html
+        err_msg (string): The error string.
+
+    Returns:
+        ``None``
+    """
+    if len(args) + len(kwargs) != 3:
+        LOGGER.error(
+            '_log_gdal_errors was called with an incorrect number of '
+            f'arguments.  args: {args}, kwargs: {kwargs}')
+
+    try:
+        gdal_args = {}
+        for index, key in enumerate(('err_level', 'err_no', 'err_msg')):
+            try:
+                parameter = args[index]
+            except IndexError:
+                parameter = kwargs[key]
+            gdal_args[key] = parameter
+    except KeyError as missing_key:
+        LOGGER.exception(
+            f'_log_gdal_errors called without the argument {missing_key}. '
+            f'Called with args: {args}, kwargs: {kwargs}')
+
+        # Returning from the function because we don't have enough
+        # information to call the ``osgeo_logger`` in the way we intended.
+        return
+
+    err_level = gdal_args['err_level']
+    err_no = gdal_args['err_no']
+    err_msg = gdal_args['err_msg'].replace('\n', '')
+    _OSGEO_LOGGER.log(
+        level=GDAL_ERROR_LEVELS[err_level],
+        msg=f'[errno {err_no}] {err_msg}')
+
+
 @contextlib.contextmanager
 def capture_gdal_logging():
     """Context manager for logging GDAL errors with python logging.
@@ -58,28 +113,6 @@ def capture_gdal_logging():
     Returns:
         ``None``
     """
-    osgeo_logger = logging.getLogger('osgeo')
-
-    def _log_gdal_errors(err_level, err_no, err_msg):
-        """Log error messages to osgeo.
-
-        All error messages are logged with reasonable ``logging`` levels based
-        on the GDAL error level.
-
-        Args:
-            err_level (int): The GDAL error level (e.g. ``gdal.CE_Failure``)
-            err_no (int): The GDAL error number.  For a full listing of error
-                codes, see: http://www.gdal.org/cpl__error_8h.html
-            err_msg (string): The error string.
-
-        Returns:
-            ``None``
-        """
-        osgeo_logger.log(
-            level=GDAL_ERROR_LEVELS[err_level],
-            msg='[errno {err}] {msg}'.format(
-                err=err_no, msg=err_msg.replace('\n', ' ')))
-
     gdal.PushErrorHandler(_log_gdal_errors)
     try:
         yield


Test patch:
diff --git a/tests/test_utils.py b/tests/test_utils.py
index c06408c03..5409e72fd 100644
--- a/tests/test_utils.py
+++ b/tests/test_utils.py
@@ -5,11 +5,13 @@ import os
 import tempfile
 import shutil
 import logging
+import logging.handlers
 import threading
 import warnings
 import re
 import glob
 import textwrap
+import queue
 
 import numpy
 from osgeo import gdal
@@ -457,6 +459,50 @@ class GDALWarningsLoggingTests(unittest.TestCase):
 
         self.assertEqual(len(messages), 1)
 
+    def test_log_gdal_errors_bad_n_args(self):
+        """utils: test error capture when number of args != 3."""
+        from natcap.invest import utils
+
+        log_queue = queue.Queue()
+        log_queue_handler = logging.handlers.QueueHandler(log_queue)
+        utils.LOGGER.addHandler(log_queue_handler)
+
+        try:
+            # 1 parameter, expected 3
+            utils._log_gdal_errors('foo')
+        finally:
+            utils.LOGGER.removeHandler(log_queue_handler)
+
+        record = log_queue.get()
+        self.assertEqual(record.name, 'natcap.invest.utils')
+        self.assertEqual(record.levelno, logging.ERROR)
+        self.assertIn(
+            '_log_gdal_errors was called with an incorrect number',
+            record.msg)
+
+    def test_log_gdal_errors_missing_param(self):
+        """utils: test error when specific parameters missing."""
+        from natcap.invest import utils
+
+        log_queue = queue.Queue()
+        log_queue_handler = logging.handlers.QueueHandler(log_queue)
+        utils.LOGGER.addHandler(log_queue_handler)
+
+        try:
+            # Missing third parameter, "err_msg"
+            utils._log_gdal_errors(
+                gdal.CE_Failure, 123,
+                bad_param='bad param')  # param obviously bad
+        finally:
+            utils.LOGGER.removeHandler(log_queue_handler)
+
+        record = log_queue.get()
+        self.assertEqual(record.name, 'natcap.invest.utils')
+        self.assertEqual(record.levelno, logging.ERROR)
+        self.assertIn(
+            "_log_gdal_errors called without the argument 'err_msg'",
+            record.msg)
+
 
 class PrepareWorkspaceTests(unittest.TestCase):
     """Test Prepare Workspace."""
@@ -1436,8 +1482,7 @@ class ReclassifyRasterOpTests(unittest.TestCase):
         origin = (1180000, 690000)
         raster_path = os.path.join(self.workspace_dir, 'tmp_raster.tif')
 
-        array = numpy.array(
-            [[1, 1, 1], [2, 2, 2], [3, 3, 3]], dtype=numpy.int32)
+        array = numpy.array([[1,1,1], [2,2,2], [3,3,3]], dtype=numpy.int32)
 
         pygeoprocessing.numpy_array_to_raster(
             array, -1, (1, -1), origin, projection_wkt, raster_path)