diff --git a/.travis.yml b/.travis.yml index 4e2d515cb..74a71a24d 100644 --- a/.travis.yml +++ b/.travis.yml @@ -30,6 +30,7 @@ matrix: - python: 3.6 env: - PROJ_NETWORK=ON + - PROJ_DEBUG=3 - python: 3.6 env: - PROJSYNC=ALL diff --git a/docs/advanced_examples.rst b/docs/advanced_examples.rst index a669fdc35..06aece339 100644 --- a/docs/advanced_examples.rst +++ b/docs/advanced_examples.rst @@ -180,3 +180,42 @@ Here is an example where enabling the global context can help: codes = pyproj.get_codes("EPSG", pyproj.enums.PJType.PROJECTED_CRS, False) crs_list = [pyproj.CRS.from_epsg(code) for code in codes] + + +Debugging Internal PROJ: +------------------------ + +.. versionadded:: 3.0.0 + +To get more debugging information from the internal PROJ code: + +1. Set the `PROJ_DEBUG `__ + environment variable to the desired level. + +2. Activate logging in `pyproj` with the devel `DEBUG`: + + More information available here: https://docs.python.org/3/howto/logging.html + + Here are examples to get started. + + Add handler to the `pyproj` logger: + + .. code-block:: python + + import logging + + console_handler = logging.StreamHandler() + formatter = logging.Formatter("%(levelname)s:%(message)s") + console_handler.setFormatter(formatter) + logger = logging.getLogger("pyproj") + logger.addHandler(console_handler) + logger.setLevel(logging.DEBUG) + + + Activate default logging config: + + .. code-block:: python + + import logging + + logging.basicConfig(format="%(levelname)s:%(message)s", level=logging.DEBUG) diff --git a/docs/history.rst b/docs/history.rst index fed56c99f..419288fc1 100644 --- a/docs/history.rst +++ b/docs/history.rst @@ -23,6 +23,7 @@ Change Log * ENH: Add support for temporal CRS CF coordinate system (issue #672) * BUG: Fix handling of polygon holes when calculating area in Geod (pull #686) * ENH: Added :ref:`network` (#675, #691, #695) +* ENH: Added support for debugging internal PROJ (pull #696) 2.6.1 ~~~~~ diff --git a/pyproj/_datadir.pyx b/pyproj/_datadir.pyx index 094017475..1d820e534 100644 --- a/pyproj/_datadir.pyx +++ b/pyproj/_datadir.pyx @@ -1,3 +1,4 @@ +import logging import os import warnings from distutils.util import strtobool @@ -7,6 +8,10 @@ from libc.stdlib cimport free, malloc from pyproj.compat import cstrencode, pystrdecode from pyproj.exceptions import DataDirError, ProjError +# for logging the internal PROJ messages +# https://docs.python.org/3/howto/logging.html#configuring-logging-for-a-library +_LOGGER = logging.getLogger("pyproj") +_LOGGER.addHandler(logging.NullHandler()) # default to False is the safest mode # as it supports multithreading _USE_GLOBAL_CONTEXT = strtobool(os.environ.get("PYPROJ_GLOBAL_CONTEXT", "OFF")) @@ -70,12 +75,23 @@ def get_user_data_dir(create=False): return pystrdecode(proj_context_get_user_writable_directory(NULL, bool(create))) -cdef void pyproj_log_function(void *user_data, int level, const char *error_msg): +cdef void pyproj_log_function(void *user_data, int level, const char *error_msg) nogil: """ Log function for catching PROJ errors. """ + # from pyproj perspective, everything from PROJ is for debugging. + # The verbosity should be managed via the + # PROJ_DEBUG environment variable. if level == PJ_LOG_ERROR: - ProjError.internal_proj_error = pystrdecode(error_msg) + with gil: + ProjError.internal_proj_error = pystrdecode(error_msg) + _LOGGER.debug(f"PROJ_ERROR: {ProjError.internal_proj_error}") + elif level == PJ_LOG_DEBUG: + with gil: + _LOGGER.debug(f"PROJ_DEBUG: {pystrdecode(error_msg)}") + elif level == PJ_LOG_TRACE: + with gil: + _LOGGER.debug(f"PROJ_TRACE: {pystrdecode(error_msg)}") cdef void set_context_data_dir(PJ_CONTEXT* context) except *: diff --git a/test/test_datadir.py b/test/test_datadir.py index 18d56849f..5fa4a505b 100644 --- a/test/test_datadir.py +++ b/test/test_datadir.py @@ -1,3 +1,4 @@ +import logging import os from contextlib import contextmanager @@ -5,7 +6,7 @@ from mock import patch import pyproj._datadir -from pyproj import CRS, get_codes, set_use_global_context +from pyproj import CRS, Transformer, get_codes, set_use_global_context from pyproj._datadir import _pyproj_global_context_initialize from pyproj.datadir import ( DataDirError, @@ -15,6 +16,7 @@ set_data_dir, ) from pyproj.enums import PJType +from pyproj.exceptions import CRSError from test.conftest import proj_env @@ -30,6 +32,23 @@ def proj_context_env(): pyproj._datadir._USE_GLOBAL_CONTEXT = context +@contextmanager +def proj_logging_env(): + """ + Ensure handler is added and then removed at end. + """ + console_handler = logging.StreamHandler() + formatter = logging.Formatter("%(threadName)s:%(levelname)s:%(message)s") + console_handler.setFormatter(formatter) + logger = logging.getLogger("pyproj") + logger.addHandler(console_handler) + logger.setLevel(logging.DEBUG) + try: + yield + finally: + logger.removeHandler(console_handler) + + def create_projdb(tmpdir): with open(os.path.join(tmpdir, "proj.db"), "w") as pjdb: pjdb.write("DUMMY proj.db") @@ -227,3 +246,36 @@ def test_set_use_global_context__off(): with proj_context_env(): set_use_global_context(False) assert pyproj._datadir._USE_GLOBAL_CONTEXT is False + + +def test_proj_debug_logging(capsys): + with proj_logging_env(): + with pytest.warns(FutureWarning): + transformer = Transformer.from_proj("+init=epsg:4326", "+init=epsg:27700") + transformer.transform(100000, 100000) + captured = capsys.readouterr() + if os.environ.get("PROJ_DEBUG") == "3": + assert "PROJ_TRACE" in captured.err + assert "PROJ_DEBUG" in captured.err + elif os.environ.get("PROJ_DEBUG") == "2": + assert "PROJ_TRACE" not in captured.err + assert "PROJ_DEBUG" in captured.err + else: + assert captured.err == "" + + +def test_proj_debug_logging__error(capsys): + with proj_logging_env(), pytest.raises(CRSError): + CRS("INVALID STRING") + captured = capsys.readouterr() + if os.environ.get("PROJ_DEBUG") == "3": + assert "PROJ_TRACE" in captured.err + assert "PROJ_DEBUG" in captured.err + assert "PROJ_ERROR" in captured.err + elif os.environ.get("PROJ_DEBUG") == "2": + assert "PROJ_TRACE" not in captured.err + assert "PROJ_DEBUG" in captured.err + assert "PROJ_ERROR" in captured.err + else: + assert captured.err == "" + assert captured.out == ""