Add logging documentation and integrate Python logging with IRIS; implement LogManager and update logging methods in _Common class

Author: grongierisc

docs/logging.md

@@ -0,0 +1,73 @@
+# Logging
+
+InterSystems IRIS Interoperability framework implements its own logging system. The Python API provides a way to use Python's logging module integrated with IRIS logging.
+
+## Basic Usage
+
+The logging system is available through the component base class. You can access it via the `logger` property or use the convenience methods:
+
+```python
+def on_init(self):
+    # Using convenience methods
+    self.log_info("Component initialized")
+    self.log_error("An error occurred")
+    self.log_warning("Warning message")
+    self.log_alert("Critical alert")
+    self.trace("Debug trace message")
+
+    # Using logger property
+    self.logger.info("Info via logger")
+    self.logger.error("Error via logger")
+```
+
+## Console Logging
+
+You can direct logs to the console instead of IRIS in two ways:
+
+1. Set the component-wide setting:
+```python
+def on_init(self):
+    self.log_to_console = True
+    self.log_info("This will go to console")
+```
+
+2. Per-message console logging:
+```python
+def on_message(self, request):
+    # Log specific message to console
+    self.log_info("Debug info", to_console=True)
+    
+    # Other logs still go to IRIS
+    self.log_info("Production info")
+```
+
+## Log Levels
+
+The following log levels are available:
+
+- `trace()` - Debug level logging (maps to IRIS LogTrace)
+- `log_info()` - Information messages (maps to IRIS LogInfo) 
+- `log_warning()` - Warning messages (maps to IRIS LogWarning)
+- `log_error()` - Error messages (maps to IRIS LogError)
+- `log_alert()` - Critical/Alert messages (maps to IRIS LogAlert)
+- `log_assert()` - Assert messages (maps to IRIS LogAssert)
+
+## Integration with IRIS
+
+The Python logging is automatically mapped to the appropriate IRIS logging methods:
+
+- Python `DEBUG` → IRIS `LogTrace`
+- Python `INFO` → IRIS `LogInfo`
+- Python `WARNING` → IRIS `LogWarning` 
+- Python `ERROR` → IRIS `LogError`
+- Python `CRITICAL` → IRIS `LogAlert`
+
+## Legacy Methods
+
+The following methods are deprecated but maintained for backwards compatibility:
+
+- `LOGINFO()` - Use `log_info()` instead
+- `LOGALERT()` - Use `log_alert()` instead
+- `LOGWARNING()` - Use `log_warning()` instead
+- `LOGERROR()` - Use `log_error()` instead
+- `LOGASSERT()` - Use `log_assert()` instead

mkdocs.yml

@@ -13,6 +13,7 @@ nav:
     - Command Line Interface: command-line.md
     - Python API: python-api.md
   - DTL Support: dtl.md
+  - Logging: logging.md
   - Reference:
     - Examples: example.md
     - Useful Links: useful-links.md

src/iop/_common.py

@@ -4,6 +4,8 @@
 import iris
 import traceback
 from typing import Any, ClassVar, Dict, List, Optional, Tuple, Type
+from iop._log_manager import LogManager
+import logging
 
 class _Common(metaclass=abc.ABCMeta):
     """Base class that defines common methods for all component types.
@@ -15,6 +17,7 @@ class _Common(metaclass=abc.ABCMeta):
     INFO_URL: ClassVar[str]
     ICON_URL: ClassVar[str]
     iris_handle: Any = None
+    log_to_console: bool = False
 
     def on_init(self) -> None:
         """Initialize component when started.
@@ -245,56 +248,67 @@ def _log(self) -> Tuple[str, Optional[str]]:
         current_class = self.__class__.__name__
         current_method = None
         try:
-            frame = traceback.extract_stack()[-3]
+            frame = traceback.extract_stack()[-4]
             current_method = frame.name
         except:
             pass
         return current_class, current_method
-    
-    def trace(self, message: str) -> None:
+
+    @property
+    def logger(self) -> logging.Logger:
+        """Get a logger instance for this component.
+        
+        Returns:
+            Logger configured for IRIS integration
+        """
+        class_name, method_name = self._log()
+        return LogManager.get_logger(class_name, method_name, self.log_to_console)
+
+    def trace(self, message: str, to_console: Optional[bool] = None) -> None:
         """Write trace log entry.
         
         Args:
             message: Message to log
+            to_console: If True, log to console instead of IRIS
         """
-        current_class, current_method = self._log()
-        iris.cls("Ens.Util.Log").LogTrace(current_class, current_method, message,1)
+        self.logger.debug(message, extra={'to_console': to_console})
+
 
-    def log_info(self, message: str) -> None:
+    def log_info(self, message: str, to_console: Optional[bool] = None) -> None:
         """Write info log entry.
         
         Args:
             message: Message to log
+            to_console: If True, log to console instead of IRIS
         """
-        current_class, current_method = self._log()
-        iris.cls("Ens.Util.Log").LogInfo(current_class, current_method, message)
+        self.logger.info(message, extra={'to_console': to_console})
 
-    def log_alert(self, message: str) -> None:
-        """Write a log entry of type "alert". Log entries can be viewed in the management portal.
+    def log_alert(self, message: str, to_console: Optional[bool] = None) -> None:
+        """Write alert log entry.
         
-        Parameters:
-        message: a string that is written to the log.
+        Args:
+            message: Message to log
+            to_console: If True, log to console instead of IRIS
         """
-        current_class, current_method = self._log()
-        iris.cls("Ens.Util.Log").LogAlert(current_class, current_method, message)
+        self.logger.critical(message, extra={'to_console': to_console})
 
-    def log_warning(self, message: str) -> None:
-        """Write a log entry of type "warning". Log entries can be viewed in the management portal.
+    def log_warning(self, message: str, to_console: Optional[bool] = None) -> None:
+        """Write warning log entry.
         
-        Parameters:
-        message: a string that is written to the log.
+        Args:
+            message: Message to log
+            to_console: If True, log to console instead of IRIS
         """
-        current_class, current_method = self._log()
-        iris.cls("Ens.Util.Log").LogWarning(current_class, current_method, message)
+        self.logger.warning(message, extra={'to_console': to_console})
 
-    def log_error(self, message: str) -> None:
-        """Write a log entry of type "error". Log entries can be viewed in the management portal.
+    def log_error(self, message: str, to_console: Optional[bool] = None) -> None:
+        """Write error log entry.
         
-        Parameters:
-        message: a string that is written to the log.
+        Args:
+            message: Message to log
+            to_console: If True, log to console instead of IRIS
         """
-        current_class, current_method = self._log()
-        iris.cls("Ens.Util.Log").LogError(current_class, current_method, message)
+        self.logger.error(message, extra={'to_console': to_console})
 
     def log_assert(self, message: str) -> None:
         """Write a log entry of type "assert". Log entries can be viewed in the management portal.

src/iop/_log_manager.py

@@ -0,0 +1,81 @@
+import iris
+import logging
+from typing import Optional, Tuple
+
+class LogManager:
+    """Manages logging integration between Python's logging module and IRIS."""
+
+    @staticmethod
+    def get_logger(class_name: str, method_name: Optional[str] = None, console: bool = False) -> logging.Logger:
+        """Get a logger instance configured for IRIS integration.
+        
+        Args:
+            class_name: Name of the class logging the message
+            method_name: Optional name of the method logging the message
+            console: If True, log to the console instead of IRIS
+            
+        Returns:
+            Logger instance configured for IRIS integration
+        """
+        logger = logging.getLogger(f"{class_name}.{method_name}" if method_name else class_name)
+        
+        # Only add handler if none exists
+        if not logger.handlers:
+            handler = IRISLogHandler(class_name, method_name, console)
+            formatter = logging.Formatter('%(message)s')
+            handler.setFormatter(formatter)
+            logger.addHandler(handler)
+            # Set the log level to the lowest level to ensure all messages are sent to IRIS
+            logger.setLevel(logging.DEBUG)
+        
+        return logger
+
+class IRISLogHandler(logging.Handler):
+    """Custom logging handler that routes Python logs to IRIS logging system."""
+
+    def __init__(self, class_name: str, method_name: Optional[str] = None, console: bool = False):
+        """Initialize the handler with context information.
+        
+        Args:
+            class_name: Name of the class logging the message
+            method_name: Optional name of the method logging the message
+            console: If True, log to the console instead of IRIS
+        """
+        super().__init__()
+        self.class_name = class_name
+        self.method_name = method_name
+        self.console = console
+
+    def format(self, record: logging.LogRecord) -> str:
+        """Format the log record into a string.
+        
+        Args:
+            record: The logging record to format
+            
+        Returns:
+            Formatted log message
+        """
+        if self.console:
+            return f"{record}"
+        return record.getMessage()
+
+    def emit(self, record: logging.LogRecord) -> None:
+        """Route the log record to appropriate IRIS logging method.
+        
+        Args:
+            record: The logging record to emit
+        """
+        # Map Python logging levels to IRIS logging methods
+        level_map = {
+            logging.DEBUG: iris.cls("Ens.Util.Log").LogTrace,
+            logging.INFO: iris.cls("Ens.Util.Log").LogInfo,
+            logging.WARNING: iris.cls("Ens.Util.Log").LogWarning,
+            logging.ERROR: iris.cls("Ens.Util.Log").LogError,
+            logging.CRITICAL: iris.cls("Ens.Util.Log").LogAlert,
+        }
+
+        log_func = level_map.get(record.levelno, iris.cls("Ens.Util.Log").LogInfo)
+        if self.console or (hasattr(record, "to_console") and record.to_console):
+            iris.cls("%SYS.System").WriteToConsoleLog(self.format(record),0,0,"IoP.Log")
+        else:
+            log_func(self.class_name, self.method_name, self.format(record))

src/tests/test_iop_commun.py

@@ -38,6 +38,34 @@ def test_is_iris_object_instance():
     result = _Common._is_iris_object_instance(msg)
     assert result == False
 
+def test_log_info_to_console():
+    commun = _Common()
+    commun.log_to_console = True
+    # generate a random string of 10 characters
+    import random, string
+    letters = string.ascii_lowercase
+    random_string = ''.join(random.choice(letters) for i in range(10))
+    commun.log_info(random_string)
+    # check $IRISINSTALLDIR/mgr/messages.log last line
+    with open(os.path.join(os.environ['IRISINSTALLDIR'], 'mgr', 'messages.log'), 'r') as file:
+        lines = file.readlines()
+        last_line = lines[-1]
+        assert random_string in last_line
+
+def test_log_info_to_console_from_method():
+    commun = _Common()
+    # generate a random string of 10 characters
+    import random, string
+    letters = string.ascii_lowercase
+    random_string = ''.join(random.choice(letters) for i in range(10))
+    commun.trace(message=random_string, to_console=True)
+    # check $IRISINSTALLDIR/mgr/messages.log last line
+    with open(os.path.join(os.environ['IRISINSTALLDIR'], 'mgr', 'messages.log'), 'r') as file:
+        lines = file.readlines()
+        last_line = lines[-1]
+        assert random_string in last_line
+
+
 def test_log_info():
     commun = _Common()
     # generate a random string of 10 characters