Add logging to find_dotenv and load_dotenv

This commit will add logger messages to `find_dotenv` and `load_dotenv`.
A utilities module will be added, and the `fastenv` logger will be used.
Successes will be logged at the `logging.INFO` level, and errors will be
logged at the `logging.ERROR` level. Unit tests will be updated to check
that log messages have the correct contents and log level.

docs/dotenv.md

@@ -151,7 +151,7 @@ Let's update the `example.py` script to not only load `.env`, but also dump it b
 
 Try running `python example.py` again, then opening `.env.dump` in a text editor. The new `.env.dump` file should have the same contents as the original `.env` file.
 
-## Exceptions
+## Exceptions and logging
 
 !!!tip "Handling exceptions"
 
@@ -161,7 +161,8 @@ Try running `python example.py` again, then opening `.env.dump` in a text editor
 
     If exceptions are encountered, `fastenv.load_dotenv(raise_exceptions=False)` will return an empty `DotEnv()` instance, `fastenv.dotenv_values(raise_exceptions=False)` will return an empty dictionary, and `fastenv.dump_dotenv(raise_exceptions=False)` will simply return the path to the destination file.
 
+!!!tip "Logging"
 
-    Python's default behavior is to raise exceptions, and fastenv follows this convention, with its default `raise_exceptions=True`. However, it may be preferable in some cases to fail silently instead of raising an exception. In these cases, `raise_exceptions=False` can be used. If exceptions are encountered, `fastenv.load_dotenv(raise_exceptions=False)` will return an empty `DotEnv()` instance, and `fastenv.dump_dotenv(raise_exceptions=False)` will simply return the path to the destination file.
+    fastenv will provide a small amount of [logging](https://docs.python.org/3/library/logging.html) when loading or dumping _.env_ files. Successes will be logged at the `logging.INFO` level, and errors will be logged at the `logging.ERROR` level.
 
-    If exceptions are encountered, `fastenv.load_dotenv(raise_exceptions=False)` will return an empty `DotEnv()` instance, and `fastenv.dump_dotenv(raise_exceptions=False)` will simply return the path to the destination file that was provided.
+    If you're managing your loggers individually in a logging configuration file, all fastenv logging uses the `"fastenv"` logger. Logging can be disabled by adding `{"loggers": {"fastenv": {"propagate": False}}}` to a logging configuration dictionary.

fastenv/dotenv.py

@@ -141,6 +141,8 @@ async def load_dotenv(
     raise_exceptions: bool = True,
 ) -> DotEnv:
     """Load environment variables from a file into a `DotEnv` model."""
+    from fastenv.utilities import logger
+
     try:
         import anyio
 
@@ -155,16 +157,19 @@ async def load_dotenv(
             contents = await f.read()
         dotenv = DotEnv(str(contents))
         dotenv.source = dotenv_source
+        logger.info(f"fastenv loaded {len(dotenv)} variables from {dotenv_source}")
         return dotenv
 
     except ImportError as e:
+        error_message = (
+            "AnyIO is required to load environment variables from a file. Install"
+            " with `poetry add fastenv -E files` or `pip install fastenv[files]`."
+        )
+        logger.error(f"fastenv error: {e.__class__.__qualname__} {error_message}")
         if raise_exceptions:
-            error_message = (
-                "AnyIO is required to load environment variables from a file. Install"
-                " with `poetry add fastenv -E files` or `pip install fastenv[files]`."
-            )
             raise ImportError(error_message) from e
-    except Exception:
+    except Exception as e:
+        logger.error(f"fastenv error: {e.__class__.__qualname__} {e}")
         if raise_exceptions:
             raise
 
@@ -198,21 +203,26 @@ async def dump_dotenv(
     raise_exceptions: bool = True,
 ) -> pathlib.Path:
     """Dump a `DotEnv` model to a file."""
+    from fastenv.utilities import logger
+
     try:
         import anyio
 
         # TODO: `pathlib.Path.write_text` https://github.com/agronholm/anyio/pull/327
         async with await anyio.open_file(destination, "w", encoding=encoding) as f:
             await f.write(str(source))  # type: ignore[arg-type]
+        logger.info(f"fastenv dumped to {destination}")
 
     except ImportError as e:
+        error_message = (
+            "AnyIO is required to dump environment variables to a file. Install "
+            "with `poetry add fastenv -E files` or `pip install fastenv[files]`."
+        )
+        logger.error(f"fastenv error: {e.__class__.__qualname__} {error_message}")
         if raise_exceptions:
-            error_message = (
-                "AnyIO is required to dump environment variables to a file. Install "
-                "with `poetry add fastenv -E files` or `pip install fastenv[files]`."
-            )
             raise ImportError(error_message) from e
-    except Exception:
+    except Exception as e:
+        logger.error(f"fastenv error: {e.__class__.__qualname__} {e}")
         if raise_exceptions:
             raise
     # TODO: async `pathlib.Path` https://github.com/agronholm/anyio/pull/327

fastenv/utilities.py

@@ -0,0 +1,3 @@
+import logging
+
+logger = logging.getLogger("fastenv")

tests/test_dotenv.py

@@ -620,6 +620,7 @@ async def test_find_and_load_dotenv_with_file_in_sub_dir(
         directory above and `find_source=True` finds and loads the file.
         """
         environ = mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         fastenv.dotenv.os.chdir(env_file_child_dir)
         dotenv = await fastenv.dotenv.load_dotenv(env_file, find_source=True)
         assert fastenv.dotenv.pathlib.Path.cwd() == env_file_child_dir
@@ -631,6 +632,9 @@ async def test_find_and_load_dotenv_with_file_in_sub_dir(
         assert fastenv.dotenv.os.getenv(output_key) == output_value
         assert len(dotenv) == len(dotenv_args)
         assert dotenv.source == env_file
+        logger.info.assert_called_once_with(
+            f"fastenv loaded {len(dotenv_args)} variables from {env_file}"
+        )
 
     @pytest.mark.anyio
     async def test_find_and_load_dotenv_with_file_not_found_and_raise(
@@ -640,11 +644,15 @@ async def test_find_and_load_dotenv_with_file_not_found_and_raise(
         name of a source file that does not exist raises `FileNotFoundError`.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         with pytest.raises(FileNotFoundError) as e:
             await fastenv.dotenv.load_dotenv(
                 ".env.nofile", find_source=True, raise_exceptions=True
             )
         assert ".env.nofile" in str(e.value)
+        logger.error.assert_called_once_with(
+            f"fastenv error: FileNotFoundError {e.value}"
+        )
 
     @pytest.mark.anyio
     async def test_find_and_load_dotenv_with_file_not_found_no_raise(
@@ -655,10 +663,12 @@ async def test_find_and_load_dotenv_with_file_not_found_no_raise(
         does not exist returns an empty `DotEnv` instance.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         dotenv = await fastenv.dotenv.load_dotenv(
             ".env.nofile", find_source=True, raise_exceptions=False
         )
         assert len(dotenv) == 0
+        assert "FileNotFoundError" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     @pytest.mark.parametrize("input_arg, output_key, output_value", dotenv_args)
@@ -674,6 +684,7 @@ async def test_load_dotenv_file(
         to a dotenv file returns a `DotEnv` instance.
         """
         environ = mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         dotenv = await fastenv.dotenv.load_dotenv(env_file, raise_exceptions=True)
         assert isinstance(dotenv, fastenv.dotenv.DotEnv)
         assert dotenv(output_key) == output_value
@@ -683,6 +694,9 @@ async def test_load_dotenv_file(
         assert fastenv.dotenv.os.getenv(output_key) == output_value
         assert len(dotenv) == len(dotenv_args)
         assert dotenv.source == env_file
+        logger.info.assert_called_once_with(
+            f"fastenv loaded {len(dotenv_args)} variables from {env_file}"
+        )
 
     @pytest.mark.anyio
     async def test_load_dotenv_empty_file(
@@ -692,11 +706,15 @@ async def test_load_dotenv_empty_file(
         to an empty file returns an empty `DotEnv` instance.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         dotenv = await fastenv.dotenv.load_dotenv(env_file_empty, raise_exceptions=True)
         assert isinstance(dotenv, fastenv.dotenv.DotEnv)
         assert dotenv.source == env_file_empty
         assert dotenv.source.is_file()
         assert len(dotenv) == 0
+        logger.info.assert_called_once_with(
+            f"fastenv loaded 0 variables from {env_file_empty}"
+        )
 
     @pytest.mark.anyio
     async def test_load_dotenv_incorrect_path_no_raise(
@@ -706,10 +724,12 @@ async def test_load_dotenv_incorrect_path_no_raise(
         `raise_exceptions=False` returns an empty `DotEnv` instance.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         dotenv = await fastenv.dotenv.load_dotenv("/not/a/file", raise_exceptions=False)
         assert isinstance(dotenv, fastenv.dotenv.DotEnv)
         assert not dotenv.source
         assert len(dotenv) == 0
+        assert "FileNotFoundError" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     async def test_load_dotenv_incorrect_path_with_raise(
@@ -719,8 +739,10 @@ async def test_load_dotenv_incorrect_path_with_raise(
         `raise_exceptions=True` raises an exception.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         with pytest.raises(FileNotFoundError):
             await fastenv.dotenv.load_dotenv("/not/a/file", raise_exceptions=True)
+        assert "FileNotFoundError" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     async def test_load_dotenv_import_error(
@@ -729,9 +751,11 @@ async def test_load_dotenv_import_error(
         """Assert that calling `load_dotenv` without AnyIO raises `ImportError`."""
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
         mocker.patch("anyio.open_file", side_effect=ModuleNotFoundError)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         with pytest.raises(ImportError) as e:
             await fastenv.dotenv.load_dotenv(env_file_empty, raise_exceptions=True)
         assert "AnyIO is required" in str(e.value)
+        assert "AnyIO is required" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     async def test_dotenv_values_with_dotenv_instance(
@@ -776,13 +800,17 @@ async def test_dotenv_values_with_env_file_path(
         `DotEnv` instance into a dictionary as expected.
         """
         environ = mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         result = await fastenv.dotenv.dotenv_values(env_file)
         assert isinstance(result, dict)
         assert result[output_key] == output_value
         assert environ[output_key] == output_value
         assert environ.get(output_key) == output_value
         assert fastenv.dotenv.os.getenv(output_key) == output_value
         assert len(result) == len(dotenv_args)
+        logger.info.assert_called_once_with(
+            f"fastenv loaded {len(dotenv_args)} variables from {env_file}"
+        )
 
     @pytest.mark.anyio
     async def test_dump_dotenv_incorrect_path_no_raise(
@@ -792,12 +820,14 @@ async def test_dump_dotenv_incorrect_path_no_raise(
         and `raise_exceptions=False` returns a `pathlib.Path` instance.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         source = fastenv.dotenv.DotEnv()
         destination = fastenv.dotenv.pathlib.Path("s3:https://mybucket/.env")
         result = await fastenv.dotenv.dump_dotenv(
             source, destination, raise_exceptions=False
         )
         assert isinstance(result, fastenv.dotenv.pathlib.Path)
+        assert "FileNotFoundError" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     async def test_dump_dotenv_incorrect_path_with_raise(
@@ -807,23 +837,27 @@ async def test_dump_dotenv_incorrect_path_with_raise(
         and `raise_exceptions=True` raises an exception.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         source = fastenv.dotenv.DotEnv()
         destination = "s3:https://mybucket/.env"
         with pytest.raises(FileNotFoundError):
             await fastenv.dotenv.dump_dotenv(source, destination, raise_exceptions=True)
+        assert "FileNotFoundError" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     async def test_dump_dotenv_import_error(
         self, env_file_empty: fastenv.dotenv.pathlib.Path, mocker: MockerFixture
     ) -> None:
         """Assert that calling `dump_dotenv` without AnyIO raises `ImportError`."""
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        mocker.patch("anyio.open_file", side_effect=ModuleNotFoundError)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         source = fastenv.dotenv.DotEnv()
         destination = env_file_empty
-        mocker.patch("anyio.open_file", side_effect=ModuleNotFoundError)
         with pytest.raises(ImportError) as e:
             await fastenv.dotenv.dump_dotenv(source, destination, raise_exceptions=True)
         assert "AnyIO is required" in str(e.value)
+        assert "AnyIO is required" in logger.error.call_args.args[0]
 
     @pytest.mark.anyio
     @pytest.mark.parametrize("input_arg, output_key, output_value", dotenv_args)
@@ -840,6 +874,7 @@ async def test_load_and_dump_dotenv_file(
         that the resultant `DotEnv` instance contains the expected contents.
         """
         mocker.patch.dict(fastenv.dotenv.os.environ, clear=True)
+        logger = mocker.patch("fastenv.utilities.logger", autospec=True)
         source = await fastenv.dotenv.load_dotenv(env_file)
         destination = env_file.parent / ".env.dumped"
         dump = await fastenv.dotenv.dump_dotenv(str(source), destination)
@@ -848,3 +883,12 @@ async def test_load_and_dump_dotenv_file(
         assert dotenv[output_key] == output_value
         assert len(dotenv) == len(dotenv_args)
         assert dotenv.source == destination
+        assert logger.info.call_count == 3
+        logger.info.assert_has_calls(
+            calls=[
+                mocker.call(
+                    f"fastenv loaded {len(dotenv_args)} variables from {env_file}"
+                ),
+                mocker.call(f"fastenv dumped to {destination}"),
+            ]
+        )