Version 1.1.0: restructure Handler to better match output types

Author: simonrob

README.md

@@ -21,7 +21,15 @@ Please note that if `is_supported()` returns `False` then none of the module's o
 
 
 ## Usage
-Pyoslog currently provides the following methods:
+
+```python
+import pyoslog
+if pyoslog.is_supported():
+    pyoslog.log('This is an OS_LOG_TYPE_DEFAULT message via pyoslog')
+```
+
+### Available methods
+Pyoslog provides the following methods from Apple's [unified logging header](https://opensource.apple.com/source/xnu/xnu-3789.21.4/libkern/os/log.h.auto.html):
 - [`os_log_create`](https://developer.apple.com/documentation/os/1643744-os_log_create)
 - [`os_log_type_enabled`](https://developer.apple.com/documentation/os/1643749-os_log_type_enabled) (and [`info`](https://developer.apple.com/documentation/os/os_log_info_enabled)/[`debug`](https://developer.apple.com/documentation/os/os_log_debug_enabled) variants)
 - [`os_log_with_type`](https://developer.apple.com/documentation/os/os_log_with_type)
@@ -73,16 +81,14 @@ Use the pyoslog `Handler` to direct messages to pyoslog:
 
 ```python
 import logging, pyoslog
-logger = logging.getLogger('My app name')
-logger.setLevel(logging.DEBUG)
 handler = pyoslog.Handler()
 handler.setSubsystem('org.example.your-app', 'filter-category')
+logger = logging.getLogger()
 logger.addHandler(handler)
-logger.debug('message')
+logger.error('message')
 ```
 
-To configure the Handler's output type, use `handler.setLevel` with a level from the logging module.
-These are mapped internally to the `OS_LOG_TYPE` values – for example, `handler.setLevel(logging.DEBUG)` will configure the Handler to output messages of type `OS_LOG_TYPE_DEBUG`.
+Logger levels are mapped internally to the `OS_LOG_TYPE_*` values – for example, `logger.debug('message')` will generate a message of type `OS_LOG_TYPE_DEBUG`.
 
 ### Receiving log messages
 Logs can be viewed using Console.app or the `log` command.
@@ -107,7 +113,7 @@ The pyoslog module handles this for you – there is no need to `del` or release
 
 
 ## Limitations
-As noted above, while the macOS `os_log` API allows use of a format string with many methods, this name is required to be a C string literal.
+As noted above, while the macOS `os_log` API allows use of a format string with many methods, this parameter is required to be a C string literal.
 As a result, pyoslog hardcodes all format strings to `"%{public}s"`.
 
 

build.sh

@@ -2,7 +2,7 @@
 set -Eeuo pipefail
 
 # this build script is quite forceful about setup - make sure not to mess up the system python
-PYTHON_VENV=$(python -c "import sys; sys.stdout.write('1') if hasattr(sys, 'real_prefix') or sys.base_prefix != sys.prefix else sys.stdout.write('0')")
+PYTHON_VENV=$(python3 -c "import sys; sys.stdout.write('1') if hasattr(sys, 'real_prefix') or sys.base_prefix != sys.prefix else sys.stdout.write('0')")
 if [ "$PYTHON_VENV" == 0 ]; then
   echo 'Warning: not running in a Python virtual environment. Please either activate a venv or edit the script to confirm this action'
   exit 1

docs/reference.rst

@@ -56,3 +56,4 @@ Handler
 
 .. autoclass:: pyoslog.Handler
     :members:
+    :exclude-members: emit

pyoslog/__version__.py

@@ -1,5 +1,5 @@
 __title__ = 'pyoslog'
-__version__ = '1.0.1'
+__version__ = '1.1.0'
 __description__ = 'Send messages to the macOS unified logging system (os_log)'
 __author__ = 'Simon Robinson'
 __author_email__ = '[email protected]'

pyoslog/handler.py

@@ -1,5 +1,4 @@
 import logging
-from typing import Union
 
 from .core import *
 
@@ -8,39 +7,36 @@
 
 
 class Handler(logging.Handler):
-    """This logging Handler simply forwards all messages to pyoslog"""
+    """This logging Handler forwards all messages to pyoslog. The logging level (set as normal via :py:func:`setLevel`)
+    is converted to the matching pyoslog.OS_LOG_TYPE_* type, and messages outputted to the unified log."""
 
     def __init__(self) -> None:
         """Initialise a Handler instance, logging to OS_LOG_DEFAULT at OS_LOG_TYPE_DEFAULT"""
         logging.Handler.__init__(self)
-
         self._log_object = OS_LOG_DEFAULT
-        self._log_type = OS_LOG_TYPE_DEFAULT
-
-    def setLevel(self, level: Union[int, str]) -> None:
-        """Sets the log level, mapping logging.<level> to pyoslog.OS_LOG_TYPE_<equivalent level>."""
-        super().setLevel(level)  # normalises level Union[int, str] to int
-
-        pyoslog_type = OS_LOG_TYPE_DEFAULT  # logging.NOTSET or unmatched value
-
-        if self.level >= logging.CRITICAL:
-            pyoslog_type = OS_LOG_TYPE_FAULT
-        elif self.level >= logging.ERROR:
-            pyoslog_type = OS_LOG_TYPE_ERROR
-        elif self.level >= logging.WARNING:
-            pyoslog_type = OS_LOG_TYPE_DEFAULT
-        elif self.level >= logging.INFO:
-            pyoslog_type = OS_LOG_TYPE_INFO
-        elif self.level >= logging.DEBUG:
-            pyoslog_type = OS_LOG_TYPE_DEBUG
-
-        self._log_type = pyoslog_type
 
+    @staticmethod
+    def _get_pyoslog_type(level: int) -> int:
+        if level >= logging.CRITICAL:
+            return OS_LOG_TYPE_FAULT
+        elif level >= logging.ERROR:
+            return OS_LOG_TYPE_ERROR
+        elif level >= logging.WARNING:
+            return OS_LOG_TYPE_DEFAULT
+        elif level >= logging.INFO:
+            return OS_LOG_TYPE_INFO
+        elif level >= logging.DEBUG:
+            return OS_LOG_TYPE_DEBUG
+
+        return OS_LOG_TYPE_DEFAULT  # logging.NOTSET
+
+    # named to match logging class norms rather than PEP 8 recommendations
     # noinspection PyPep8Naming
     def setSubsystem(self, subsystem: str, category: str = 'default') -> None:
-        """Sets the subsystem (in reverse DNS notation), and optionally a category to allow further filtering."""
+        """Sets the subsystem (typically reverse DNS notation), and optionally a category to allow further filtering."""
         self._log_object = os_log_create(subsystem, category)
 
     def emit(self, record: logging.LogRecord) -> None:
-        """Emit a record, sending its contents to pyoslog."""
-        os_log_with_type(self._log_object, self._log_type, self.format(record))
+        """Emit a record, sending its contents to pyoslog at a matching level to our own. (note: excluded from built
+        documentation as this method is not intended to be called directly.)"""
+        os_log_with_type(self._log_object, Handler._get_pyoslog_type(record.levelno), self.format(record))

tests/test_handler.py

@@ -32,38 +32,80 @@ def setUp(self):
 
         self.handler = pyoslog.Handler()
         self.assertEqual(self.handler._log_object, pyoslog.OS_LOG_DEFAULT)
-        self.assertEqual(self.handler._log_type, pyoslog.OS_LOG_TYPE_DEFAULT)
+        self.assertEqual(self.handler.level, logging.NOTSET)
+
+        # far more thorough testing is in test_setup.py (setSubsystem essentially duplicates os_log_create)
+        self.handler.setSubsystem(pyoslog_test_globals.LOG_SUBSYSTEM, pyoslog_test_globals.LOG_CATEGORY)
+        self.assertIsInstance(self.handler._log_object, pyoslog_core.os_log_t)
+        self.assertEqual(str(self.handler._log_object), '<os_log_t (%s:%s)>' % (pyoslog_test_globals.LOG_SUBSYSTEM,
+                                                                                pyoslog_test_globals.LOG_CATEGORY))
+
+        self.logger = logging.getLogger('Pyoslog test logger')
+        self.logger.addHandler(self.handler)
+
+        # so that we don't receive framework messages (e.g., 'PlugIn CFBundle 0x122f9cf90 </System/Library/Frameworks/
+        # OSLog.framework> (framework, loaded) is now unscheduled for unloading')
+        self.logger.setLevel(logging.DEBUG)
 
         # noinspection PyUnresolvedReferences
         log_scope = OSLog.OSLogStoreScope(OSLog.OSLogStoreCurrentProcessIdentifier)
         # noinspection PyUnresolvedReferences
         self.log_store, error = OSLog.OSLogStore.storeWithScope_error_(log_scope, None)
         self.assertIsNone(error)
 
-    def test_setLevel(self):
-        for invalid_type in [None, [], (0, 1, 2), {'key': 'value'}]:
-            self.assertRaises(TypeError, self.handler.setLevel, invalid_type)
+    def test_emit(self):
+        logging_methods = [
+            (self.logger.debug, pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_DEBUG),
+            (self.logger.info, pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_INFO),
+            (self.logger.warning, pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_DEFAULT),
+            (self.logger.error, pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_ERROR),
+            (self.logger.critical, pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_FAULT)
+        ]
+        for log_method, log_type in logging_methods:
+            sent_message = 'Handler message via %s / 0x%x (%s)' % (log_method, log_type.value, log_type)
+            log_method(sent_message)
+            received_message = pyoslog_test_globals.get_latest_log_message(self.log_store)
+
+            # see test_logging.py for further details about this approach
+            if pyoslog.os_log_type_enabled(self.handler._log_object, log_type.value):
+                self.assertEqual(pyoslog_test_globals.oslog_level_to_type(received_message.level()), log_type)
+                self.assertEqual(received_message.subsystem(), pyoslog_test_globals.LOG_SUBSYSTEM)
+                self.assertEqual(received_message.category(), pyoslog_test_globals.LOG_CATEGORY)
+                self.assertEqual(received_message.composedMessage(), sent_message)
+            else:
+                print('Skipped: custom log object Handler tests with disabled type 0x%x (%s)' % (
+                    log_type.value, log_type))
 
-        for level in [logging.NOTSET, logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL]:
-            self.handler.setLevel(level)
-            self.assertEqual(self.handler._log_type, pyoslog_test_globals.logging_level_to_type(level))
+        sent_message = 'Handler message via logger.exception()'
+        self.logger.exception(sent_message, exc_info=False)  # intended to only be called from an exception
+        received_message = pyoslog_test_globals.get_latest_log_message(self.log_store)
+        self.assertEqual(pyoslog_test_globals.oslog_level_to_type(received_message.level()),
+                         pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_ERROR)
+        self.assertEqual(received_message.subsystem(), pyoslog_test_globals.LOG_SUBSYSTEM)
+        self.assertEqual(received_message.category(), pyoslog_test_globals.LOG_CATEGORY)
+        self.assertEqual(received_message.composedMessage(), sent_message)
 
-            self.handler.setLevel(level + 5)  # the logging module allows any positive integers, default 0-50
-            self.assertEqual(self.handler._log_type, pyoslog_test_globals.logging_level_to_type(level))
+        # logging.NOTSET should map to OS_LOG_TYPE_DEFAULT (but we don't test output as explained above)
+        self.assertEqual(self.handler._get_pyoslog_type(logging.NOTSET),
+                         pyoslog_test_globals.TestLogTypes.OS_LOG_TYPE_DEFAULT)
 
-    def test_setSubsystem(self):
-        # far more thorough testing is in test_setup.py (setSubsystem essentially duplicates os_log_create)
-        self.handler.setSubsystem(pyoslog_test_globals.LOG_SUBSYSTEM, pyoslog_test_globals.LOG_CATEGORY)
-        self.assertIsInstance(self.handler._log_object, pyoslog_core.os_log_t)
-        self.assertEqual(str(self.handler._log_object), '<os_log_t (%s:%s)>' % (pyoslog_test_globals.LOG_SUBSYSTEM,
-                                                                                pyoslog_test_globals.LOG_CATEGORY))
+        logging_levels = [logging.DEBUG, logging.INFO, logging.WARNING, logging.ERROR, logging.CRITICAL]
+        for log_level in logging_levels:
+            expected_type = pyoslog_test_globals.logging_level_to_type(log_level)
+            sent_message = 'Handler message via logger.log() at level %d / 0x%x (%s)' % (
+                log_level, expected_type.value, expected_type)
+            self.logger.log(log_level, sent_message)
+            received_message = pyoslog_test_globals.get_latest_log_message(self.log_store)
 
-    def test_emit(self):
-        # far more thorough testing is in test_logging.py (emit essentially duplicates os_log_with_type)
-        sent_record = logging.LogRecord('test', logging.DEBUG, '', 0, 'Handler log message', None, None)
-        self.handler.emit(sent_record)
-        received_message = pyoslog_test_globals.get_latest_log_message(self.log_store)
-        self.assertEqual(received_message.composedMessage(), sent_record.message)
+            # see test_logging.py for further details about this approach
+            if pyoslog.os_log_type_enabled(self.handler._log_object, expected_type.value):
+                self.assertEqual(pyoslog_test_globals.oslog_level_to_type(received_message.level()), expected_type)
+                self.assertEqual(received_message.subsystem(), pyoslog_test_globals.LOG_SUBSYSTEM)
+                self.assertEqual(received_message.category(), pyoslog_test_globals.LOG_CATEGORY)
+                self.assertEqual(received_message.composedMessage(), sent_message)
+            else:
+                print('Skipped: custom log object Handler tests with disabled type 0x%x (%s)' % (
+                    expected_type.value, expected_type))
 
 
 if __name__ == '__main__':