Repository: aristanetworks/anta
Pull request #981 (2024-12-24 15:56:53)

test: idempotency of setup logger
# Description

Great news everyone - it is now MUCH faster to run the tests.. Locally it means 9s vs 74s for my machine.

The issue was that we were adding too many RichHandler when calling CliRunner multiple times...

**NOTE:** Logging need some more love.

# Checklist:

<!-- Delete not relevant items !-->

- [x] My code follows the style guidelines of this project
- [x] I have performed a self-review of my code
- [x] I have run pre-commit for code linting and typing (`pre-commit run`)
- [x] I have made corresponding changes to the documentation
- [x] I have added tests that prove my fix is effective or that my feature works
- [x] New and existing unit tests pass locally with my changes (`tox -e testenv`)


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [88.9% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


codspeed-hq[bot]: ## [CodSpeed Performance Report](https://codspeed.io/aristanetworks/anta/branches/gmuloc%3Aremove-many-handlers)

### Merging #981 will **not alter performance**

<sub>Comparing <code>gmuloc:remove-many-handlers</code> (b17dde6) with <code>main</code> (2a0bf6c)</sub>



### Summary

`✅ 22` untouched benchmarks  




sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [88.9% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


gmuloc: > Maybe do the same logic for the FileHandler?

maybe don't call the funciton multiple time with the same file? :p
mtache: > > Maybe do the same logic for the FileHandler?
> 
> maybe don't call the function multiple times with the same file? :p

This point of view is also valid for RichHandler, nevertheless we are making it idempotent.
I think this function should behave in a similar way for RichHandler and FileHandler (and it should have been idempotent from day 1).

From our unit test issue, if I write unit tests with a file as env var and I use CliRunner, I would log multiple times in the same file.
gmuloc: > > > Maybe do the same logic for the FileHandler?
> > 
> > 
> > maybe don't call the function multiple times with the same file? :p
> 
> This point of view is also valid for RichHandler, nevertheless we are making it idempotent. I think this function should behave in a similar way for RichHandler and FileHandler (and it should have been idempotent from day 1).

Agreed

> 
> From our unit test issue, if I write unit tests with a file as env var and I use CliRunner, I would log multiple times in the same file.

Thats really a unit test problem


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


mtache: NB for later:
we should not modify the root logger but an anta logger. Right way to implement that would be to delete all handlers of the anta logger at the beginning of the function.
We used root logger to have logs from other libraries, maybe we could modify specific loggers (httpx, asyncio) instead when in ANTA_DEBUG mode.
sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)


sonarqubecloud[bot]: ## [![Quality Gate Passed](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/checks/QualityGateBadge/qg-passed-20px.png 'Quality Gate Passed')](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981) **Quality Gate passed**  
Issues  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 New issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/accepted-16px.png '') [0 Accepted issues](https://sonarcloud.io/project/issues?id=aristanetworks_anta&pullRequest=981&issueStatuses=ACCEPTED)

Measures  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0 Security Hotspots](https://sonarcloud.io/project/security_hotspots?id=aristanetworks_anta&pullRequest=981&issueStatuses=OPEN,CONFIRMED&sinceLeakPeriod=true)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [100.0% Coverage on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_coverage&view=list)  
![](https://sonarsource.github.io/sonarcloud-github-static-resources/v2/common/passed-16px.png '') [0.0% Duplication on New Code](https://sonarcloud.io/component_measures?id=aristanetworks_anta&pullRequest=981&metric=new_duplicated_lines_density&view=list)  
  
[See analysis details on SonarQube Cloud](https://sonarcloud.io/dashboard?id=aristanetworks_anta&pullRequest=981)



Patch:
diff --git a/anta/logger.py b/anta/logger.py
index 167b821b..e6d04287 100644
--- a/anta/logger.py
+++ b/anta/logger.py
@@ -9,15 +9,13 @@ import logging
 import traceback
 from datetime import timedelta
 from enum import Enum
-from typing import TYPE_CHECKING, Literal
+from pathlib import Path
+from typing import Literal
 
 from rich.logging import RichHandler
 
 from anta import __DEBUG__
 
-if TYPE_CHECKING:
-    from pathlib import Path
-
 logger = logging.getLogger(__name__)
 
 
@@ -69,27 +67,59 @@ def setup_logging(level: LogLevel = Log.INFO, file: Path | None = None) -> None:
         # httpx as well
         logging.getLogger("httpx").setLevel(logging.WARNING)
 
-    # Add RichHandler for stdout
-    rich_handler = RichHandler(markup=True, rich_tracebacks=True, tracebacks_show_locals=False)
-    # Show Python module in stdout at DEBUG level
-    fmt_string = "[grey58]\\[%(name)s][/grey58] %(message)s" if loglevel == logging.DEBUG else "%(message)s"
-    formatter = logging.Formatter(fmt=fmt_string, datefmt="[%X]")
-    rich_handler.setFormatter(formatter)
-    root.addHandler(rich_handler)
-    # Add FileHandler if file is provided
-    if file:
+    # Add RichHandler for stdout if not already present
+    _maybe_add_rich_handler(loglevel, root)
+
+    # Add FileHandler if file is provided and same File Handler is not already present
+    if file and not _get_file_handler(root, file):
         file_handler = logging.FileHandler(file)
         formatter = logging.Formatter("%(asctime)s - %(name)s - %(levelname)s - %(message)s")
         file_handler.setFormatter(formatter)
         root.addHandler(file_handler)
         # If level is DEBUG and file is provided, do not send DEBUG level to stdout
-        if loglevel == logging.DEBUG:
+        if loglevel == logging.DEBUG and (rich_handler := _get_rich_handler(root)) is not None:
             rich_handler.setLevel(logging.INFO)
 
     if __DEBUG__:
         logger.debug("ANTA Debug Mode enabled")
 
 
+def _get_file_handler(logger_instance: logging.Logger, file: Path) -> logging.FileHandler | None:
+    """Return the FileHandler if present."""
+    return (
+        next(
+            (
+                handler
+                for handler in logger_instance.handlers
+                if isinstance(handler, logging.FileHandler) and str(Path(handler.baseFilename).resolve()) == str(file.resolve())
+            ),
+            None,
+        )
+        if logger_instance.hasHandlers()
+        else None
+    )
+
+
+def _get_rich_handler(logger_instance: logging.Logger) -> logging.Handler | None:
+    """Return the ANTA Rich Handler."""
+    return next((handler for handler in logger_instance.handlers if handler.get_name() == "ANTA_RICH_HANDLER"), None) if logger_instance.hasHandlers() else None
+
+
+def _maybe_add_rich_handler(loglevel: int, logger_instance: logging.Logger) -> None:
+    """Add RichHandler for stdout if not already present."""
+    if _get_rich_handler(logger_instance) is not None:
+        # Nothing to do.
+        return
+
+    anta_rich_handler = RichHandler(markup=True, rich_tracebacks=True, tracebacks_show_locals=False)
+    anta_rich_handler.set_name("ANTA_RICH_HANDLER")
+    # Show Python module in stdout at DEBUG level
+    fmt_string = "[grey58]\\[%(name)s][/grey58] %(message)s" if loglevel == logging.DEBUG else "%(message)s"
+    formatter = logging.Formatter(fmt=fmt_string, datefmt="[%X]")
+    anta_rich_handler.setFormatter(formatter)
+    logger_instance.addHandler(anta_rich_handler)
+
+
 def format_td(seconds: float, digits: int = 3) -> str:
     """Return a formatted string from a float number representing seconds and a number of digits."""
     isec, fsec = divmod(round(seconds * 10**digits), 10**digits)


Test patch:
diff --git a/tests/units/test_logger.py b/tests/units/test_logger.py
index d2693200..a8f0bc79 100644
--- a/tests/units/test_logger.py
+++ b/tests/units/test_logger.py
@@ -6,11 +6,54 @@
 from __future__ import annotations
 
 import logging
+from pathlib import Path
 from unittest.mock import patch
 
 import pytest
 
-from anta.logger import anta_log_exception, exc_to_str, tb_to_str
+from anta.logger import Log, LogLevel, _get_file_handler, _get_rich_handler, anta_log_exception, exc_to_str, setup_logging, tb_to_str
+
+
+@pytest.mark.parametrize(
+    ("level", "path", "debug_value"),
+    [
+        pytest.param(Log.INFO, None, False, id="INFO no file"),
+        pytest.param(Log.DEBUG, None, False, id="DEBUG no file"),
+        pytest.param(Log.INFO, Path("/tmp/file.log"), False, id="INFO file"),
+        pytest.param(Log.DEBUG, Path("/tmp/file.log"), False, id="DEBUG file"),
+        pytest.param(Log.INFO, None, True, id="INFO no file __DEBUG__ set"),
+        pytest.param(Log.DEBUG, None, True, id="INFO no file __DEBUG__ set"),
+    ],
+)
+def test_setup_logging(level: LogLevel, path: Path | None, debug_value: bool) -> None:
+    """Test setup_logging."""
+    # Clean up any logger on root
+    root = logging.getLogger()
+    if root.hasHandlers():
+        root.handlers = []
+
+    with patch("anta.logger.__DEBUG__", new=debug_value):
+        setup_logging(level, path)
+
+    rich_handler = _get_rich_handler(root)
+    assert rich_handler is not None
+
+    # When __DEBUG__ is True, the log level is overwritten to DEBUG
+    if debug_value:
+        assert root.level == logging.DEBUG
+        if path is not None:
+            assert rich_handler.level == logging.INFO
+
+    if path is not None:
+        assert _get_file_handler(root, path) is not None
+        expected_handlers = 2
+    else:
+        expected_handlers = 1
+    assert len(root.handlers) == expected_handlers
+
+    # Check idempotency
+    setup_logging(level, path)
+    assert len(root.handlers) == expected_handlers
 
 
 @pytest.mark.parametrize(