feat: Improved VISA device error messages (#370)

* refactor: Remove traceback-with-variables as a project dependency. If users would like to keep that functionality, they will need to activate the package themselves. * feat: Added better exception messages when VISA connection attempts fail. Also added the exception information to the log file. * refactor: Removed outdated comment * test: Updated the test to handle the new, verbose error messages. Also switched pre-commit hook for verifying the Python data types to only run when source files change. * feat: Updated the error messages which occur when VISA communication fails (write/query) to be more concise on the console while still maintaining the verbosity needed for debugging in the log file. * test: Ignore some logging functionality for coverage purposes * feat: Added the device name and alias to the error message for VISA communication issues * feat: Add a configuration option to enable/disable logging uncaught exceptions * docs: Update notes in changelog * refactor: Update a few error messages to indicate the method they occurred in * docs: Update API documentation
tektronix · Jan 17, 2025 · 3e0b22d · 3e0b22d
1 parent be72562
commit 3e0b22d
Show file tree

Hide file tree

Showing 13 changed files with 309 additions and 36 deletions.
diff --git a/.pre-commit-config.yaml b/.pre-commit-config.yaml
@@ -113,6 +113,7 @@ repos:
         name: pyright-verifytypes
         entry: pyright
         language: system
+        files: ^src/
         types: [python]
         pass_filenames: false
         args: [--verifytypes, tm_devices, --ignoreexternal]

diff --git a/CHANGELOG.md b/CHANGELOG.md
@@ -18,6 +18,20 @@ Valid subsections within a version are:
 
 Things to be included in the next release go here.
 
+### Removed
+
+- Removed the `traceback-with-variables` package as a dependency. If users would like to maintain the functionality, they will need to install this package separately and activate it within their code.
+
+### Added
+
+- Added a new configuration option `log_uncaught_exceptions` to enable/disable logging uncaught exceptions in the log file that is created. The default behavior is to enable logging uncaught exceptions to the log file.
+
+### Changed
+
+- Updated the error messages when VISA connections fail so that the messages are more informative (they now include the device type, resource expression, and VISA backend) and are logged to the main log file.
+- Updated the error messages which occur when VISA communication fails (write/query) to be more concise on the console while still maintaining the verbosity needed for debugging in the log file.
+- Updated the VISA communication error messages to include the device name and alias for faster identification when debugging.
+
 ---
 
 ## v3.0.0 (2025-01-13)

diff --git a/docs/basic_usage.md b/docs/basic_usage.md
@@ -64,7 +64,9 @@ outside the Python code for ease of automation
 The amount of console output and logging saved to the log file can be customized as needed. This
 configuration can be done in the Python code itself as demonstrated here, or by using the
 [config file](configuration.md#config-options) or
-[environment variable](configuration.md#environment-variable).
+[environment variable](configuration.md#environment-variable). See the
+[`configure_logging()` API documentation][tm_devices.helpers.logging.configure_logging] for more
+details about logging configuration.
 
 !!! important
     If any configuration is performed in the Python code prior to instantiating the

diff --git a/docs/configuration.md b/docs/configuration.md
@@ -235,6 +235,7 @@ options:
   log_file_name: tm_devices_<timestamp>.log
   log_colored_output: false
   log_pyvisa_messages: false
+  log_uncaught_exceptions: true
 ```
 
 These are all `false` by default if not defined, set to `true` to modify the
@@ -288,6 +289,11 @@ runtime behavior configuration.
     - This config option is used to enable or disable logging of PyVISA messages within the
         configured log file. The default value of this config option is false. See the
         [`configure_logging()`][tm_devices.helpers.logging.configure_logging] function for more information.
+- `log_uncaught_exceptions`
+    - This config option is used to enable or disable logging uncaught exceptions in the log file. The
+        default value of this config option is true. Setting the `log_file_level` parameter
+        to "NONE" will disable this feature regardless of the value of `log_uncaught_exceptions`. See the
+        [`configure_logging()`][tm_devices.helpers.logging.configure_logging] function for more information.
 
 ### Sample Config File
 
@@ -355,6 +361,7 @@ options:
   log_file_name: custom_logfile.log    # customize the log file name
   log_colored_output: false
   log_pyvisa_messages: true  # log PyVISA messages in the log file
+  log_uncaught_exceptions: true
 ```
 
 #### TOML
@@ -436,6 +443,7 @@ log_file_directory = "./logs"
 log_file_name = "custom_logfile.log" # customize the log file name
 log_colored_output = false
 log_pyvisa_messages = true           # log PyVISA messages in the log file
+log_uncaught_exceptions = true
 ```
 
 ---

diff --git a/examples/miscellaneous/customize_logging.py b/examples/miscellaneous/customize_logging.py
@@ -11,6 +11,7 @@
     log_file_directory="./log_files",  # save the log file in the "./log_files" directory
     log_file_name="custom_log_filename.log",  # customize the filename
     log_pyvisa_messages=True,  # include all the pyvisa debug messages in the same log file
+    log_uncaught_exceptions=True,  # log uncaught exceptions (this is the default behavior)
 )
 
 with DeviceManager(verbose=False) as dm:

diff --git a/pyproject.toml b/pyproject.toml
@@ -93,7 +93,6 @@ pyyaml = "^6.0"
 requests = "^2.31.0"
 tomli = "^2.0.1"
 tomli-w = "^1.0.0"
-traceback-with-variables = "^2.0.4"
 typing-extensions = "^4.10.0"
 tzlocal = "^5.2"
 urllib3 = "^2.0"

diff --git a/src/tm_devices/device_manager.py b/src/tm_devices/device_manager.py
@@ -57,11 +57,6 @@
 
     from pyvisa_py.protocols.rpc import RPCError  # pyright: ignore[reportMissingTypeStubs]
 
-# pylint: disable=unused-import,wrong-import-order
-# noinspection PyUnresolvedReferences
-from traceback_with_variables import (  # pyright: ignore[reportMissingTypeStubs]
-    activate_by_import,  # noqa: F401  # pyright: ignore[reportUnusedImport]
-)
 
 if TYPE_CHECKING:
     from pyvisa.resources import MessageBasedResource

diff --git a/src/tm_devices/driver_mixins/device_control/pi_control.py b/src/tm_devices/driver_mixins/device_control/pi_control.py
@@ -353,7 +353,11 @@ def query(  # pylint: disable=arguments-differ
                 response = response.replace('"', "")
         except (visa.VisaIOError, socket.error) as error:
             pi_cmd_repr = f" for {query!r} " if self._verbose and verbose else " "
-            msg = f"The query{pi_cmd_repr}failed with the following message: {error!r}"
+            msg = (
+                f"The query of {self._name_and_alias}{pi_cmd_repr}"
+                f"failed with the following message: {error!r}"
+            )
+            _logger.error(msg)  # noqa: TRY400
             raise visa.Error(msg) from error
 
         _logger.log(
@@ -365,9 +369,10 @@ def query(  # pylint: disable=arguments-differ
 
         if not allow_empty and not response:
             pi_cmd_repr = (
-                f" for the following query: {query!r} " if self._verbose and verbose else ""
+                f" for the following query: {query!r}" if self._verbose and verbose else ""
             )
-            msg = f"An empty string was returned{pi_cmd_repr}"
+            msg = f"An empty string was returned from {self._name_and_alias}{pi_cmd_repr}"
+            _logger.error(msg)
             raise SystemError(msg)
 
         return response
@@ -397,7 +402,11 @@ def query_binary(self, query: str, verbose: bool = True) -> Sequence[float]:
             response = self._visa_resource.query_binary_values(query)  # pyright: ignore[reportUnknownMemberType]
         except (visa.VisaIOError, socket.error) as error:
             pi_cmd_repr = f" for {query!r} " if self._verbose and verbose else " "
-            msg = f"The query{pi_cmd_repr}failed with the following message: {error!r}"
+            msg = (
+                f"The binary query of {self._name_and_alias}{pi_cmd_repr}"
+                f"failed with the following message: {error!r}"
+            )
+            _logger.error(msg)  # noqa: TRY400
             raise visa.Error(msg) from error
 
         _logger.log(
@@ -409,9 +418,10 @@ def query_binary(self, query: str, verbose: bool = True) -> Sequence[float]:
 
         if not response:
             pi_cmd_repr = (
-                f" for the following query: {query!r} " if self._verbose and verbose else ""
+                f" for the following binary query: {query!r}" if self._verbose and verbose else ""
             )
-            msg = f"An empty string was returned{pi_cmd_repr}"
+            msg = f"An empty string was returned from {self._name_and_alias}{pi_cmd_repr}"
+            _logger.error(msg)
             raise SystemError(msg)
 
         return response
@@ -527,7 +537,11 @@ def query_raw_binary(self, query: str, verbose: bool = True) -> bytes:
             response = self.read_raw()
         except (visa.VisaIOError, socket.error) as error:
             pi_cmd_repr = f" for {query!r} " if self._verbose and verbose else " "
-            msg = f"The query{pi_cmd_repr}failed with the following message: {error!r}"
+            msg = (
+                f"The raw binary query of {self._name_and_alias}{pi_cmd_repr}"
+                f"failed with the following message: {error!r}"
+            )
+            _logger.error(msg)  # noqa: TRY400
             raise visa.Error(msg) from error
 
         _logger.log(
@@ -539,9 +553,12 @@ def query_raw_binary(self, query: str, verbose: bool = True) -> bytes:
 
         if not response.strip():
             pi_cmd_repr = (
-                f" for the following query: {query!r} " if self._verbose and verbose else ""
+                f" for the following raw binary query: {query!r}"
+                if self._verbose and verbose
+                else ""
             )
-            msg = f"An empty string was returned{pi_cmd_repr}"
+            msg = f"An empty string was returned from {self._name_and_alias}{pi_cmd_repr}"
+            _logger.error(msg)
             raise SystemError(msg)
 
         return response
@@ -858,12 +875,20 @@ def write(self, command: str, opc: bool = False, verbose: bool = True) -> None:
             self._visa_resource.write(command)
         except (visa.VisaIOError, socket.error) as error:
             pi_cmd_repr = f" for {command!r} " if self._verbose and verbose else " "
-            msg = f"The write{pi_cmd_repr}failed with the following message: {error!r}"
+            msg = (
+                f"The write to {self._name_and_alias}{pi_cmd_repr}"
+                f"failed with the following message: {error!r}"
+            )
+            _logger.error(msg)  # noqa: TRY400
             raise visa.Error(msg) from error
 
         if opc and (result := self.ieee_cmds.opc()) != "1":
             pi_cmd_repr = f" {command!r}" if self._verbose and verbose else " the command"
-            msg = f"After issuing{pi_cmd_repr}, OPC returned incorrect data: {result!r}"
+            msg = (
+                f"After issuing{pi_cmd_repr} to {self._name_and_alias}, "
+                f"OPC returned incorrect data: {result!r}"
+            )
+            _logger.error(msg)
             raise SystemError(msg)
 
     def write_raw(self, command: bytes, verbose: bool = True) -> None:
@@ -887,7 +912,11 @@ def write_raw(self, command: bytes, verbose: bool = True) -> None:
             self._visa_resource.write_raw(command)
         except (visa.VisaIOError, socket.error) as error:
             pi_cmd_repr = f" for {command!r} " if self._verbose and verbose else " "
-            msg = f"The raw write{pi_cmd_repr}failed with the following message: {error!r}"
+            msg = (
+                f"The raw write to {self._name_and_alias}"
+                f"{pi_cmd_repr}failed with the following message: {error!r}"
+            )
+            _logger.error(msg)  # noqa: TRY400
             raise visa.Error(msg) from error
 
     ################################################################################################

diff --git a/src/tm_devices/helpers/constants_and_dataclasses.py b/src/tm_devices/helpers/constants_and_dataclasses.py
@@ -494,6 +494,17 @@ class DMConfigOptions(AsDictionaryMixin):
     Defaults to False. See the [`configure_logging()`][tm_devices.helpers.logging.configure_logging]
     function for more information and default values.
     """
+    log_uncaught_exceptions: Optional[bool] = None
+    """Whether to log uncaught exceptions to the log file with full tracebacks.
+
+    This behavior also reduces the traceback size of exceptions in the console. Setting
+    [`log_file_level`][tm_devices.helpers.constants_and_dataclasses.DMConfigOptions.log_file_level]
+    to `"NONE"` will disable this feature regardless of the value of
+    [`log_uncaught_exceptions`][tm_devices.helpers.constants_and_dataclasses.DMConfigOptions.log_uncaught_exceptions].
+
+    Defaults to True. See the [`configure_logging()`][tm_devices.helpers.logging.configure_logging]
+    function for more information and default values.
+    """
 
     def __post_init__(self) -> None:
         """Validate data after creation.

diff --git a/src/tm_devices/helpers/functions.py b/src/tm_devices/helpers/functions.py
@@ -178,8 +178,6 @@ def check_for_update(package_name: str = PACKAGE_NAME, index_name: str = "pypi")
         installed_version = importlib.metadata.version(package_name)
 
         # Get the version from the index
-        # This code mirrors code found in scripts/pypi_latest_version.py.
-        # If this code is updated, the script should be updated too.
         url = f"https://{index_name}.org/pypi/{package_name}/json"
         response = requests.get(url, timeout=10)
         releases = json.loads(response.text)["releases"]
@@ -302,15 +300,18 @@ def create_visa_connection(
     visa_library: str,
     *,
     retry_connection: bool = False,
+    second_connection_attempt_delay: int = 60,
 ) -> MessageBasedResource:
     """Create a VISA resource.
 
     Args:
         device_config_entry: The device config entry.
         visa_library: A string containing the VISA library to use to create a ResourceManager.
         retry_connection: Boolean indicating if a second connection attempt should be made. If True,
-            two attempts are made to establish a VISA connection, with a 60-second delay in between
-            each attempt.
+            two attempts are made to establish a VISA connection, with a configurable delay in
+            between each attempt.
+        second_connection_attempt_delay: The number of seconds to wait in between the first and
+            second connection attempts when `retry_connection=True`.
 
     Returns:
         A VISA resource that can be passed into the device driver.
@@ -341,26 +342,70 @@ def create_visa_connection(
     # The broad except is because pyvisa_py can throw a base exception in the tcpip.py file
     except Exception as error_1:
         if not retry_connection:
-            message = f"Unable to establish a VISA connection to {resource_expression}"
-            raise ConnectionError(message) from error_1
-        time.sleep(60)  # wait 60 seconds and try again
+            error_message = (
+                f"Unable to establish a VISA connection to the "
+                f"{device_config_entry.device_type.value}"
+                f"{(' with the alias '+repr(device_config_entry.alias)) if device_config_entry.alias else ''}"  # noqa: E501
+                f" using the resource expression '{resource_expression}'"
+                f" and the {repr(visa_library) if visa_library else 'default'} VISA library"
+            )
+            _logger.error(error_message)  # noqa: TRY400
+            _logger.error(  # noqa: TRY400
+                "1st exception: %s.%s: %s",
+                error_1.__class__.__module__,
+                error_1.__class__.__qualname__,
+                error_1,
+            )
+            raise ConnectionError(error_message) from error_1
+        _logger.debug(
+            "Initial connection attempt failed, waiting %d second(s) "
+            "before re-attempting to create the VISA connection",
+            second_connection_attempt_delay,
+        )
+        time.sleep(second_connection_attempt_delay)
         try:
             # noinspection PyTypeChecker
             visa_object: MessageBasedResource = visa.ResourceManager(  # pyright: ignore[reportAssignmentType]
                 visa_library
             ).open_resource(resource_expression)
         # The broad except is because pyvisa_py can throw a base exception in the tcpip.py file
         except Exception as error_2:
-            message = f"Unable to establish a VISA connection to {resource_expression}\n\n"
+            error_message = (
+                f"Unable to establish a VISA connection (after two tries) to the "
+                f"{device_config_entry.device_type.value}"
+                f"{(' with the alias '+repr(device_config_entry.alias)) if device_config_entry.alias else ''}"  # noqa: E501
+                f" using the resource expression '{resource_expression}'"
+                f" and the {repr(visa_library) if visa_library else 'default'} VISA library"
+            )
+            _logger.error(error_message)  # noqa: TRY400
+            _logger.error(  # noqa: TRY400
+                "1st exception: %s.%s: %s",
+                error_1.__class__.__module__,
+                error_1.__class__.__qualname__,
+                error_1,
+            )
+            _logger.error(  # noqa: TRY400
+                "2nd exception: %s.%s: %s:",
+                error_2.__class__.__module__,
+                error_2.__class__.__qualname__,
+                error_2,
+            )
+            ping_message = ""
+            ping_output = ""
             if device_config_entry.connection_type in {
                 ConnectionTypes.TCPIP,
                 ConnectionTypes.SOCKET,
             }:
-                message += (
-                    f"This is the current ping output for the device at "
-                    f"{device_config_entry.address}:\n{ping_address(device_config_entry.address)}"
+                ping_output = (
+                    ping_address(device_config_entry.address)
+                    or "\nno response returned or unable to find device\n"
+                )
+                ping_message = (
+                    f"\n\nThis is the current ping output for the device at "
+                    f"{device_config_entry.address}:\n"
                 )
-            raise ConnectionError(message) from error_2
+                _logger.debug("%s%s", ping_message.lstrip(), ping_output)
+            raise ConnectionError(error_message + ping_message + ping_output) from error_2
 
     return _configure_visa_object(visa_object, device_config_entry, visa_library)