diff --git a/.release b/.release index 28d4da95f2febc7f9e326f85992595249dc86cde..159363b523554e5e4d3309b437f0a849c92efd69 100644 --- a/.release +++ b/.release @@ -1,2 +1,2 @@ -release=0.5.3 -tag=lmcbaseclasses-0.5.3 +release=0.5.4 +tag=lmcbaseclasses-0.5.4 diff --git a/README.md b/README.md index 1d8fe917ddc0174d5ad4e877751ad7f4a6e82ed5..cd8bc1314002d87e95ddb86444bfd61b4722a0be 100644 --- a/README.md +++ b/README.md @@ -25,10 +25,13 @@ The lmc-base-classe repository contains set of eight classes as mentioned in SKA ## Version History -#### (unreleased) +#### 0.5.4 - Remove `ObsState` command from SKACapability, SKAObsDevice and SKASubarray Pogo XMI files. It should not have been included - the `obsState` attribute provides this information. The command was not in the Python - files, so no change to usage. It only affects future Pogo code generation. + files, so no change to usage. It only affects future Pogo code generation. +- Add new logging target, `"tango::logger"`, that forwards Python logs to the Tango Logging Service. This + is enabled by default in code, but could be overridden by existing Tango Database device properties. +- Maximum number of logging targets increased from 3 to 4. #### 0.5.3 - Setting `loggingTargets` attribute to empty list no longer raises exception. @@ -170,12 +173,22 @@ logs include a tag field with the Tango device name. This is useful when search for logs in tools like Kibana. For example, `tango-device=ska_mid/tm_leaf_node/d0004`. This should work even for multiple devices from a single device server. +In addition, the `SKABaseDevice`'s default `loggingTargets` are configured to send all +logs to the [Tango Logging Service](https://tango-controls.readthedocs.io/en/latest/development/device-api/device-server-writing.html#the-tango-logging-service) +(TLS) as well. The sections below explain the Tango device attributes and properties +related to this. + ### Tango device controls for logging levels and targets The logging level and additional logging targets are controlled by two attributes. These attributes are initialised from two device properties on startup. An extract of the definitions from the base class is shown below. +As mentioned above, note that the `LoggingTargetsDefault` includes `"tango::logger"` which +means Python logs are forwarded to the Tango Logging Service as well. This can be overridden +in the Tango database, however disabling the `"tango::logger"` target is strongly discouraged, +as other devices in the telescope or test infrastructure may rely on this. + ```python class SKABaseDevice(Device): @@ -190,7 +203,7 @@ class SKABaseDevice(Device): ) LoggingTargetsDefault = device_property( - dtype='DevVarStringArray', default_value=[] + dtype='DevVarStringArray', default_value=["tango::logger"] ) # ---------- @@ -207,7 +220,7 @@ class SKABaseDevice(Device): loggingTargets = attribute( dtype=('str',), access=AttrWriteType.READ_WRITE, - max_dim_x=3, + max_dim_x=4, doc="Logging targets for this device, excluding ska_logging defaults" " - initialises to LoggingTargetsDefault on startup", ) @@ -239,10 +252,11 @@ is set, we internally update the TLS logging level as well. ### Additional logging targets -Note that the the `loggingTargets` attribute says "excluding ska_logging defaults". -If you want to forward logs to other targets, then you could use this attribute. It is an -empty list by default, since we only want the logging to stdout that is already provided -by the ska_logging library. +Note that the `loggingTargets` attribute says "excluding ska_logging defaults". +Even when empty, you will still have the logging to stdout that is already provided +by the ska_logging library. If you want to forward logs to other targets, then you can use +this attribute. Since we also want logging to TLS, it should include the `"tango::logger"` +item by default. The format and usage of this attribute is not that intuitive, but it was not expected to be used much, and was kept similar to the existing SKA control system guidelines proposal. @@ -266,22 +280,28 @@ proxy.loggingTargets = new_targets proxy.loggingTargets = [] ``` -Currently there are three types of targets implemented: +Currently there are four types of targets implemented: - `console` - `file` - `syslog` +- `tango` +#### console target If you were to set the `proxy.loggingTargets = ["console::cout"]` you would get all the logs to stdout duplicated. Once for ska_logging root logger, and once for the additional console logger you just added. For the "console" option it doesn't matter -what text comes after the `::` - we always use stdout. +what text comes after the `::` - we always use stdout. While it may not seem useful +now, the option is kept in case the ska_logging default configuration changes, and no +longer outputs to stdout. -For file output, provide the path after the `::`. If the path is ommitted, then a +#### file target +For file output, provide the path after the `::`. If the path is omitted, then a file is created in the device server's current directory, with a name based on the the Tango name. E.g., "my/test/device" would get the file "my_test_device.log". Currently, we using a `logging.handlers.RotatingFileHandler` with a 1 MB limit and just 2 backups. This could be modified in future. +#### syslog target For syslog, the syslog target address details must be provided after the `::` as a URL. The following types are supported: - File, `file://<path>` @@ -295,38 +315,52 @@ The following types are supported: Example of usage: `proxy.loggingTargets = ["syslog::udp://server.domain:514"]`. +#### tango target +All Python logs can be forwarded to the Tango Logging Service by adding the `"tango::logger"` +target. This will use the device's log4tango logger object to emit logs into TLS. The +TLS targets still need to be added in the usual way. Typically, using the `add_logging_target` +method from an instance of a `tango.DeviceProxy` object. + +#### multiple targets If you want file and syslog targets, you could do something like: `proxy.loggingTargets = ["file::/tmp/my.log", "syslog::udp://server.domain:514"]`. -**Note:** There is a limit of 3 additional handlers. That the maximum length +**Note:** There is a limit of 4 additional handlers. That is the maximum length of the spectrum attribute. We could change this if there is a reasonable use case for it. ### Can I still send logs to the Tango Logging Service? -Not really. In `SKABaseDevice._init_logging` we monkey patch the Tango Logging Service (TLS) +Yes. In `SKABaseDevice._init_logging` we monkey patch the log4tango logger methods `debug_stream`, `error_stream`, etc. to point the Python logger methods like `logger.debug`, `logger.error`, etc. This means that logs are no longer forwarded -to the Tango Logging Service. - -In future, we could add a new target that allows the logs to be forwarded to TLS. -That would be something like `"tls::my/log/consumer"`. +to the Tango Logging Service automatically. However, by including a `"tango::logger"` +item in the `loggingTarget` attribute, the Python logs are sent to TLS. -Although, you might get some logs from the admin device, since we cannot override its -behaviour from the Python layer. PyTango is wrapper around the C++ Tango library, and -the admin device is implemented in C++. - -The `tango.DeviceProxy` also has some built in logging control methods which you should -avoid as they only apply to the Tango Logging Service: +The `tango.DeviceProxy` also has some built in logging control methods that only apply +to the Tango Logging Service: - `DeviceProxy.add_logging_target` + - Can be used to add a log consumer device. + - Can be used to log to file (in the TLS format). + - Should not be used to turn on console logging, as that will result in duplicate logs. - `DeviceProxy.remove_logging_target` + - Can be used to remove any TLS logging target. - `DeviceProxy.set_logging_level` + - Should not be used as it only applies to TLS. The Python logger level will be out + of sync. Rather use the device attribute `loggingLevel` which sets both. + +### Where are the logs from the admin device (dserver)? + +PyTango is wrapper around the C++ Tango library, and the admin device is implemented in C++. +The admin device does not inherit from the SKABaseDevice and we cannot override its behaviour +from the Python layer. Its logs can only be seen by configuring the TLS appropriately. ### What code should I write to log from my device? You should always use the `self.logger` object within methods. This instance of the logger is the only one that knows the Tango device name. You can also use the PyTango -decorators like `DebugIt`, since the monkey patching redirects them to that same logger. +[logging decorators](https://pytango.readthedocs.io/en/stable/server_api/logging.html#logging-decorators) +like `DebugIt`, since the monkey patching redirects them to that same logger. ```python class MyDevice(SKABaseDevice): @@ -334,7 +368,7 @@ class MyDevice(SKABaseDevice): someone = "you" self.logger.info("I have a message for %s", someone) - @tango.DebugIt() + @tango.DebugIt(show_args=True, show_ret=True) def my_handler(self): # great, entry and exit of this method is automatically logged # at debug level! diff --git a/src/ska/base/base_device.py b/src/ska/base/base_device.py index 1886c1ee22edec105853ef5020350247363093bd..effa193670c5acd1f7adde2632dabf5612252300 100644 --- a/src/ska/base/base_device.py +++ b/src/ska/base/base_device.py @@ -67,6 +67,64 @@ class _Log4TangoLoggingLevel(enum.IntEnum): DEBUG = 600 +_PYTHON_TO_TANGO_LOGGING_LEVEL = { + logging.CRITICAL: _Log4TangoLoggingLevel.FATAL, + logging.ERROR: _Log4TangoLoggingLevel.ERROR, + logging.WARNING: _Log4TangoLoggingLevel.WARN, + logging.INFO: _Log4TangoLoggingLevel.INFO, + logging.DEBUG: _Log4TangoLoggingLevel.DEBUG, +} + +_LMC_TO_TANGO_LOGGING_LEVEL = { + LoggingLevel.OFF: _Log4TangoLoggingLevel.OFF, + LoggingLevel.FATAL: _Log4TangoLoggingLevel.FATAL, + LoggingLevel.ERROR: _Log4TangoLoggingLevel.ERROR, + LoggingLevel.WARNING: _Log4TangoLoggingLevel.WARN, + LoggingLevel.INFO: _Log4TangoLoggingLevel.INFO, + LoggingLevel.DEBUG: _Log4TangoLoggingLevel.DEBUG, +} + +_LMC_TO_PYTHON_LOGGING_LEVEL = { + LoggingLevel.OFF: logging.CRITICAL, # there is no "off" + LoggingLevel.FATAL: logging.CRITICAL, + LoggingLevel.ERROR: logging.ERROR, + LoggingLevel.WARNING: logging.WARNING, + LoggingLevel.INFO: logging.INFO, + LoggingLevel.DEBUG: logging.DEBUG, +} + + +class TangoLoggingServiceHandler(logging.Handler): + """Handler that emit logs via Tango device's logger to TLS.""" + + def __init__(self, tango_logger): + super().__init__() + self.tango_logger = tango_logger + + def emit(self, record): + try: + msg = self.format(record) + tango_level = _PYTHON_TO_TANGO_LOGGING_LEVEL[record.levelno] + self.acquire() + try: + self.tango_logger.log(tango_level, msg) + finally: + self.release() + except Exception: + self.handleError(record) + + def __repr__(self): + python_level = logging.getLevelName(self.level) + if self.tango_logger: + tango_level = _Log4TangoLoggingLevel(self.tango_logger.get_level()).name + name = self.tango_logger.get_name() + else: + tango_level = "UNKNOWN" + name = "!No Tango logger!" + return '<{} {} (Python {}, Tango {})>'.format( + self.__class__.__name__, name, python_level, tango_level) + + class LoggingUtils: """Utility functions to aid logger configuration. @@ -93,7 +151,9 @@ class LoggingUtils: default_target_names = { "console": "cout", "file": "{}.log".format(device_name.replace("/", "_")), - "syslog": None} + "syslog": None, + "tango": "logger", + } valid_targets = [] if targets: @@ -185,12 +245,17 @@ class LoggingUtils: return address, socktype @staticmethod - def create_logging_handler(target): - """Create a Python log handler based on the target type (console, file, syslog) + def create_logging_handler(target, tango_logger=None): + """Create a Python log handler based on the target type (console, file, syslog, tango) + + :param target: + Logging target for logger, <type>::<name> - :param target: Logging target for logger, <type>::<name> + :param tango_logger: + Instance of tango.Logger, optional. Only required if creating + a target of type "tango". - :return: StreamHandler, RotatingFileHandler, or SysLogHandler + :return: StreamHandler, RotatingFileHandler, SysLogHandler, or TangoLoggingServiceHandler :raises: LoggingTargetError for invalid target string """ @@ -211,6 +276,11 @@ class LoggingUtils: address=address, facility=logging.handlers.SysLogHandler.LOG_SYSLOG, socktype=socktype) + elif target_type == "tango": + if tango_logger: + handler = TangoLoggingServiceHandler(tango_logger) + else: + raise LoggingTargetError("Missing tango_logger instance for 'tango' target type") else: raise LoggingTargetError( "Invalid target type requested: '{}' in '{}'".format(target_type, target)) @@ -230,7 +300,7 @@ class LoggingUtils: logger.removeHandler(handler) for target in targets: if target in added_targets: - handler = LoggingUtils.create_logging_handler(target) + handler = LoggingUtils.create_logging_handler(target, logger.tango_logger) logger.addHandler(handler) logger.info('Logging targets set to %s', targets) @@ -293,13 +363,17 @@ class SKABaseDevice(Device): self.logger.addFilter(TangoDeviceTagsFilter()) + # before setting targets, give Python logger a reference to the log4tango logger + # to support the TangoLoggingServiceHandler target option + self.logger.tango_logger = self.get_logger() + # initialise using defaults in device properties self._logging_level = None self.write_loggingLevel(self.LoggingLevelDefault) self.write_loggingTargets(self.LoggingTargetsDefault) self.logger.debug('Logger initialised') - # Monkey patch TANGO Logging System streams so they go to the Python + # monkey patch TANGO Logging Service streams so they go to the Python # logger instead self.debug_stream = self.logger.debug self.info_stream = self.logger.info @@ -326,7 +400,7 @@ class SKABaseDevice(Device): ) LoggingTargetsDefault = device_property( - dtype='DevVarStringArray', default_value=[] + dtype='DevVarStringArray', default_value=["tango::logger"] ) # ---------- @@ -353,7 +427,7 @@ class SKABaseDevice(Device): loggingTargets = attribute( dtype=('str',), access=AttrWriteType.READ_WRITE, - max_dim_x=3, + max_dim_x=4, doc="Logging targets for this device, excluding ska_logging defaults" " - initialises to LoggingTargetsDefault on startup", ) @@ -500,31 +574,17 @@ class SKABaseDevice(Device): :return: None. """ - self._logging_level = LoggingLevel(value) - tango_logger = self.get_logger() - if self._logging_level == LoggingLevel.OFF: - self.logger.setLevel(logging.CRITICAL) # not allowed to be "off" - tango_logger.set_level(_Log4TangoLoggingLevel.OFF) - elif self._logging_level == LoggingLevel.FATAL: - self.logger.setLevel(logging.CRITICAL) - tango_logger.set_level(_Log4TangoLoggingLevel.FATAL) - elif self._logging_level == LoggingLevel.ERROR: - self.logger.setLevel(logging.ERROR) - tango_logger.set_level(_Log4TangoLoggingLevel.ERROR) - elif self._logging_level == LoggingLevel.WARNING: - self.logger.setLevel(logging.WARNING) - tango_logger.set_level(_Log4TangoLoggingLevel.WARN) - elif self._logging_level == LoggingLevel.INFO: - self.logger.setLevel(logging.INFO) - tango_logger.set_level(_Log4TangoLoggingLevel.INFO) - elif self._logging_level == LoggingLevel.DEBUG: - self.logger.setLevel(logging.DEBUG) - tango_logger.set_level(_Log4TangoLoggingLevel.DEBUG) - else: + try: + lmc_logging_level = LoggingLevel(value) + except ValueError: raise LoggingLevelError( - "Invalid level - {} - must be between {} and {}".format( - self._logging_level, LoggingLevel.OFF, LoggingLevel.DEBUG)) - self.logger.info('Logging level set to %s on Python and Tango loggers', self._logging_level) + "Invalid level - {} - must be one of {} ".format( + value, [v for v in LoggingLevel.__members__.values()])) + + self._logging_level = lmc_logging_level + self.logger.setLevel(_LMC_TO_PYTHON_LOGGING_LEVEL[lmc_logging_level]) + self.logger.tango_logger.set_level(_LMC_TO_TANGO_LOGGING_LEVEL[lmc_logging_level]) + self.logger.info('Logging level set to %s on Python and Tango loggers', lmc_logging_level) # PROTECTED REGION END # // SKABaseDevice.loggingLevel_write def read_loggingTargets(self): @@ -655,7 +715,6 @@ class SKABaseDevice(Device): self._test_mode = value # PROTECTED REGION END # // SKABaseDevice.testMode_write - # -------- # Commands # -------- @@ -703,5 +762,6 @@ def main(args=None, **kwargs): return run((SKABaseDevice,), args=args, **kwargs) # PROTECTED REGION END # // SKABaseDevice.main + if __name__ == '__main__': main() diff --git a/src/ska/base/release.py b/src/ska/base/release.py index c73a1b82254042b1245f868a3cc2b808b0861564..7ec0d525f8fca6ebf0d17f91571b76091239fc6e 100644 --- a/src/ska/base/release.py +++ b/src/ska/base/release.py @@ -7,7 +7,7 @@ """Release information for lmc-base-classes Python Package""" name = """lmcbaseclasses""" -version = "0.5.3" +version = "0.5.4" version_info = version.split(".") description = """A set of generic base devices for SKA Telescope.""" author = "SKA India and SARAO" diff --git a/tests/test_base_device.py b/tests/test_base_device.py index 2f48f882df37fddb7768d5696c5e4913b7d989a8..d220092b03409b966a7c9483b888fb67d36bbf71 100644 --- a/tests/test_base_device.py +++ b/tests/test_base_device.py @@ -17,6 +17,7 @@ import pytest # PROTECTED REGION ID(SKABaseDevice.test_additional_imports) ENABLED START # import logging import socket +import tango from unittest import mock from tango import DevFailed, DevState @@ -24,14 +25,87 @@ from ska.base.control_model import ( AdminMode, ControlMode, HealthState, LoggingLevel, SimulationMode, TestMode ) from ska.base.base_device import ( + _Log4TangoLoggingLevel, + _PYTHON_TO_TANGO_LOGGING_LEVEL, LoggingUtils, LoggingTargetError, + TangoLoggingServiceHandler, ) # PROTECTED REGION END # // SKABaseDevice.test_additional_imports # Device test case # PROTECTED REGION ID(SKABaseDevice.test_SKABaseDevice_decorators) ENABLED START # +class TestTangoLoggingServiceHandler: + + @pytest.fixture() + def tls_handler(self): + self.tango_logger = mock.MagicMock(spec=tango.Logger) + # setup methods used for handler __repr__ + self.tango_logger.get_name.return_value = "unit/test/dev" + self.tango_logger.get_level.return_value = _Log4TangoLoggingLevel.DEBUG + return TangoLoggingServiceHandler(self.tango_logger) + + @pytest.fixture(params=[ + logging.DEBUG, + logging.INFO, + logging.WARN, + logging.ERROR, + logging.CRITICAL, + ]) + def python_log_level(self, request): + return request.param + + def test_emit_message_at_correct_level(self, tls_handler, python_log_level): + # arrange + record = logging.LogRecord('test', python_log_level, '', 1, 'message', (), None) + # act + tls_handler.emit(record) + # assert + expected_tango_level = _PYTHON_TO_TANGO_LOGGING_LEVEL[python_log_level] + expected_calls = [mock.call(expected_tango_level, mock.ANY)] + assert self.tango_logger.log.call_args_list == expected_calls + + def test_emit_message_is_formatted(self, tls_handler): + # arrange + record = logging.LogRecord('test', logging.INFO, '', 1, 'message %s', ('param',), None) + + def format_stub(log_record): + return "LOG: " + log_record.getMessage() + + tls_handler.format = format_stub + # act + tls_handler.emit(record) + # assert + expected_tango_level = _PYTHON_TO_TANGO_LOGGING_LEVEL[logging.INFO] + expected_message = "LOG: message param" + expected_calls = [mock.call(expected_tango_level, expected_message)] + assert self.tango_logger.log.call_args_list == expected_calls + + def test_emit_exception_error_handled(self, tls_handler): + # arrange + record = logging.LogRecord('test', logging.INFO, '', 1, 'message', (), None) + + def cause_exception(*args, **kwargs): + raise RuntimeError("Testing") + + self.tango_logger.log.side_effect = cause_exception + tls_handler.handleError = mock.MagicMock() + # act + tls_handler.emit(record) + # assert + assert tls_handler.handleError.call_args_list == [mock.call(record)] + + def test_repr_normal(self, tls_handler): + expected = '<TangoLoggingServiceHandler unit/test/dev (Python NOTSET, Tango DEBUG)>' + assert repr(tls_handler) == expected + + def test_repr_tango_logger_none(self, tls_handler): + tls_handler.tango_logger = None + expected = '<TangoLoggingServiceHandler !No Tango logger! (Python NOTSET, Tango UNKNOWN)>' + assert repr(tls_handler) == expected + + class TestLoggingUtils: @pytest.fixture(params=[ (None, []), @@ -47,6 +121,10 @@ class TestLoggingUtils: (["syslog::some/path"], ["syslog::some/path"]), (["syslog::file://some/path"], ["syslog::file://some/path"]), (["syslog::protocol://somehost:1234"], ["syslog::protocol://somehost:1234"]), + (["tango"], ["tango::logger"]), + (["tango::"], ["tango::logger"]), + (["tango::logger"], ["tango::logger"]), + (["tango::anything"], ["tango::anything"]), (["console", "file"], ["console::cout", "file::my_dev_name.log"]), ]) def good_logging_targets(self, request): @@ -54,7 +132,6 @@ class TestLoggingUtils: dev_name = "my/dev/name" return targets_in, dev_name, expected - @pytest.fixture(params=[ ["invalid"], ["invalid", "console"], @@ -119,6 +196,7 @@ class TestLoggingUtils: with pytest.raises(LoggingTargetError): LoggingUtils.get_syslog_address_and_socktype(bad_syslog_url) + @mock.patch('ska.base.base_device.TangoLoggingServiceHandler') @mock.patch('logging.handlers.SysLogHandler') @mock.patch('logging.handlers.RotatingFileHandler') @mock.patch('logging.StreamHandler') @@ -127,7 +205,8 @@ class TestLoggingUtils: mock_get_formatter, mock_stream_handler, mock_file_handler, - mock_syslog_handler): + mock_syslog_handler, + mock_tango_handler): # Expect formatter be created using `get_default_formatter(tags=True)` # Use some mocks to check this. mock_formatter = mock.MagicMock() @@ -137,6 +216,7 @@ class TestLoggingUtils: return mock_formatter mock_get_formatter.side_effect = get_formatter_if_tags_enabled + mock_tango_logger = mock.MagicMock(spec=tango.Logger) handler = LoggingUtils.create_logging_handler("console::cout") assert handler == mock_stream_handler() @@ -165,16 +245,25 @@ class TestLoggingUtils: assert handler == mock_syslog_handler() handler.setFormatter.assert_called_once_with(mock_formatter) + handler = LoggingUtils.create_logging_handler("tango::logger", mock_tango_logger) + mock_tango_handler.assert_called_once_with(mock_tango_logger) + assert handler == mock_tango_handler() + handler.setFormatter.assert_called_once_with(mock_formatter) + with pytest.raises(LoggingTargetError): LoggingUtils.create_logging_handler("invalid::target") with pytest.raises(LoggingTargetError): LoggingUtils.create_logging_handler("invalid") + with pytest.raises(LoggingTargetError): + LoggingUtils.create_logging_handler("tango::logger", tango_logger=None) + def test_update_logging_handlers(self): logger = logging.getLogger('testing') + logger.tango_logger = mock.MagicMock(spec=tango.Logger) - def null_creator(target): + def null_creator(target, tango_logger): handler = logging.NullHandler() handler.name = target return handler @@ -188,7 +277,7 @@ class TestLoggingUtils: new_targets = ["console::cout"] LoggingUtils.update_logging_handlers(new_targets, logger) assert len(logger.handlers) == 1 - mocked_creator.assert_called_once_with("console::cout") + mocked_creator.assert_called_once_with("console::cout", logger.tango_logger) # test same handler is retained for same request old_handler = logger.handlers[0] @@ -200,25 +289,26 @@ class TestLoggingUtils: mocked_creator.assert_not_called() # test other valid target types - new_targets = ["console::cout", "file::/tmp/dummy", "syslog::some/address"] + new_targets = [ + "console::cout", "file::/tmp/dummy", "syslog::some/address", "tango::logger"] mocked_creator.reset_mock() LoggingUtils.update_logging_handlers(new_targets, logger) - assert len(logger.handlers) == 3 - assert mocked_creator.call_count == 2 + assert len(logger.handlers) == 4 + assert mocked_creator.call_count == 3 mocked_creator.assert_has_calls( - [mock.call("file::/tmp/dummy"), - mock.call("syslog::some/address")], + [mock.call("file::/tmp/dummy", logger.tango_logger), + mock.call("syslog::some/address", logger.tango_logger), + mock.call("tango::logger", logger.tango_logger)], any_order=True, ) - # test clearing of 1 handler + # test clearing of 2 handlers new_targets = ["console::cout", "syslog::some/address"] mocked_creator.reset_mock() LoggingUtils.update_logging_handlers(new_targets, logger) assert len(logger.handlers) == 2 mocked_creator.assert_not_called() - # test clearing all handlers new_targets = [] mocked_creator.reset_mock() @@ -340,21 +430,23 @@ class TestSKABaseDevice(object): def test_loggingTargets(self, tango_context): """Test for loggingTargets""" # PROTECTED REGION ID(SKABaseDevice.test_loggingTargets) ENABLED START # - assert tango_context.device.loggingTargets == tuple() + # tango logging target must be enabled by default + assert tango_context.device.loggingTargets == ("tango::logger", ) with mock.patch("ska.base.base_device.LoggingUtils.create_logging_handler") as mocked_creator: - def null_creator(target): + def null_creator(target, tango_logger): handler = logging.NullHandler() handler.name = target + assert isinstance(tango_logger, tango.Logger) return handler mocked_creator.side_effect = null_creator - # test adding console target + # test console target tango_context.device.loggingTargets = ["console::cout"] assert tango_context.device.loggingTargets == ("console::cout", ) - mocked_creator.assert_called_once_with("console::cout") + mocked_creator.assert_called_once_with("console::cout", mock.ANY) # test adding file and syslog targets (already have console) mocked_creator.reset_mock() @@ -364,10 +456,17 @@ class TestSKABaseDevice(object): "console::cout", "file::/tmp/dummy", "syslog::udp://localhost:514") assert mocked_creator.call_count == 2 mocked_creator.assert_has_calls( - [mock.call("file::/tmp/dummy"), - mock.call("syslog::udp://localhost:514")], + [mock.call("file::/tmp/dummy", mock.ANY), + mock.call("syslog::udp://localhost:514", mock.ANY)], any_order=True) + # test adding tango logging again, now that mock is active + # (it wasn't active when device was initialised) + mocked_creator.reset_mock() + tango_context.device.loggingTargets = ["tango::logger"] + assert tango_context.device.loggingTargets == ("tango::logger",) + mocked_creator.assert_called_once_with("tango::logger", mock.ANY) + # test clearing all targets (note: PyTango returns None for empty spectrum attribute) tango_context.device.loggingTargets = [] assert tango_context.device.loggingTargets is None