Stage 3: Send OS messages to remote syslog server

Details:

* Changed the config file format to expand the definition of
  syslogs. It can now specify host, port number, port type, and facility.

* Used Python loggers with SyslogHandler handler class to send
  the OS messages to the configured syslog servers.

* Changed some of the data structures to keep information about the
  Python loggers.

Signed-off-by: Andreas Maier <maiera@de.ibm.com>

README.rst

@@ -32,20 +32,23 @@ IBM Z HMC OS Message Forwarder
     :alt: Test coverage (master)
 
 The **IBM Z HMC OS Message Forwarder** connects to the console of operating
-systems and forwards the OS messages on the console to a remote syslog server.
+systems running in LPARs on Z systems and forwards the messages written by the
+operating system to its console to a remote syslog server.
 
-The forwarder attempts to stay up as much as possible, for example it performs
-automatic session renewals with the HMC if the logon session expires, and it
-survives HMC reboots and automatically picks up message forwarding at the
-right message sequence number once the HMC come back up.
+The Z systems can be in classic or DPM operatonal mode.
+
+.. # The forwarder attempts to stay up as much as possible, for example it performs
+.. # automatic session renewals with the HMC if the logon session expires, and it
+.. # survives HMC reboots and automatically picks up message forwarding at the
+.. # right message sequence number once the HMC come back up.
 
 .. _IBM Z: https://www.ibm.com/it-infrastructure/z
 
 Documentation
 -------------
 
-* `Documentation`_
-* `Change log`_
+* `Documentation`_ (not yet)
+* `Change log`_ (not yet)
 
 .. _Documentation: https://zhmc-os-forwarder.readthedocs.io/en/stable/
 .. _Change log: https://zhmc-os-forwarder.readthedocs.io/en/stable/changes.html
@@ -67,7 +70,7 @@ Quickstart
   Download the `example config file`_ as ``config.yaml`` and edit that copy
   according to your environment.
 
-  For details, see `forwarder config file`_.
+.. # For details, see `forwarder config file`_.
 
 .. _forwarder config file: https://zhmc-os-forwarder.readthedocs.io/en/stable/usage.html#hmc-credentials-file
 .. _example config file: examples/config_example.yaml
@@ -78,6 +81,17 @@ Quickstart
 
       $ zhmc_os_forwarder -c config.yaml
 
+Limitations
+-----------
+
+At this point, the forwarder has several limitations. All of them are intended
+to be resolved in future releases.
+
+* The forwarder does not recover from HMC restart or connection loss
+* Restarting the forwarder will send again all OS messages the HMC has buffered
+* New and deleted partitions in DPM mode are not automatically detected.
+* No documentation
+
 Reporting issues
 ----------------
 

examples/config_example.yaml

@@ -7,9 +7,15 @@ hmc:
   verify_cert: false
 
 forwarding:
+  # Each item in this list is a forwarding definition that specifies which
+  # LPARs on which CPCs should forward their OS messages to which set of
+  # remote syslog servers.
   - syslogs:
-     - server: 10.11.12.14
+     - host: 10.11.12.14
+       port: 514
+       port_type: udp
+       facility: user
     cpcs:
-      - cpc: MYCPC
+      - cpc: MYCPC    # Can be a regular expression
         partitions:
-          - partition: ".*"
+          - partition: ".*"    # Can be a regular expression

zhmc_os_forwarder/forwarded_lpars.py

@@ -27,11 +27,11 @@ class ForwardedLparInfo:
     Info for a single forwarded LPAR
     """
 
-    def __init__(self, lpar, syslog_servers=None, topic=None):
+    def __init__(self, lpar, syslogs=None, topic=None):
         self.lpar = lpar
-        if not syslog_servers:
-            syslog_servers = []
-        self.syslog_servers = syslog_servers
+        if not syslogs:
+            syslogs = []
+        self.syslogs = syslogs
         self.topic = topic
 
 
@@ -87,11 +87,11 @@ def add_if_matching(self, lpar):
         Returns:
             bool: Indicates whether the LPAR was added.
         """
-        syslog_servers = self.config.get_syslog_servers(lpar)
-        if syslog_servers:
+        syslogs = self.config.get_syslogs(lpar)
+        if syslogs:
             if lpar.uri not in self.forwarded_lpar_infos:
                 self.forwarded_lpar_infos[lpar.uri] = ForwardedLparInfo(lpar)
-            self.forwarded_lpar_infos[lpar.uri].syslog_servers = syslog_servers
+            self.forwarded_lpar_infos[lpar.uri].syslogs = syslogs
             return True
         return False
 
@@ -121,9 +121,9 @@ def is_forwarding(self, lpar):
         """
         return lpar.uri in self.forwarded_lpar_infos
 
-    def get_syslog_servers(self, lpar):
+    def get_syslogs(self, lpar):
         """
-        Get the syslog servers for a forwarded LPAR.
+        Get the syslogs from the forwarder config for a forwarded LPAR.
 
         If the LPAR is not currently forwarded, returns None.
 
@@ -132,10 +132,10 @@ def get_syslog_servers(self, lpar):
             resource object or as a URI string.
 
         Returns:
-          list of str: The syslog servers for the LPAR, or None.
+          list of ConfigSyslogInfo: The syslogs for the LPAR, or None.
         """
         try:
             lpar_info = self.forwarded_lpar_infos[lpar.uri]
         except KeyError:
             return None
-        return lpar_info.syslog_servers
+        return lpar_info.syslogs

zhmc_os_forwarder/forwarder_config.py

@@ -22,6 +22,10 @@
 
 from collections import namedtuple
 
+# Default syslog properties, if not specified in forwarder config
+DEFAULT_SYSLOG_PORT = 514
+DEFAULT_SYSLOG_PORT_TYPE = 'tcp'
+DEFAULT_SYSLOG_FACILITY = 'user'
 
 # Info for a single CPC pattern in the forwarder config
 ConfigCpcInfo = namedtuple(
@@ -39,11 +43,25 @@
     'ConfigLparInfo',
     [
         'lpar_pattern',         # string: Compiled pattern for LPAR name
-        'syslog_servers',       # List of strings: Syslog servers for the LPAR
+        'syslogs',              # list of ConfigSyslogInfo: Syslogs for the LPAR
     ]
 )
 
 
+# pylint: disable=too-few-public-methods
+class ConfigSyslogInfo:
+    """
+    Info for a single syslog in the forwarder config
+    """
+
+    def __init__(self, host, port, port_type, facility):
+        self.host = host  # string: Syslog IP address or hostname
+        self.port = port  # int: Syslog port number
+        self.port_type = port_type  # int: Syslog port type ('tcp', 'udp')
+        self.facility = facility  # string: Syslog facility (e.g. 'user')
+        self.logger = None  # logging.Logger: Python logger for syslog
+
+
 class ForwarderConfig:
     """
     A data structure to keep the forwarder config in an optimized way.
@@ -75,16 +93,23 @@ def __init__(self, config_data, config_filename):
         #             - partition: "dal1-.*"
 
         for fwd_item in forwarding:
-            syslog_servers = []
-            for sls_item in fwd_item['syslogs']:
-                syslog_servers.append(sls_item['server'])
+            syslogs = []
+            for sl_item in fwd_item['syslogs']:
+                sl_host = sl_item['host']
+                sl_port = sl_item.get('port', DEFAULT_SYSLOG_PORT)
+                sl_port_type = sl_item.get('port_type',
+                                           DEFAULT_SYSLOG_PORT_TYPE)
+                sl_facility = sl_item.get('facility', DEFAULT_SYSLOG_FACILITY)
+                syslog_info = ConfigSyslogInfo(
+                    sl_host, sl_port, sl_port_type, sl_facility)
+                syslogs.append(syslog_info)
             for cpc_item in fwd_item['cpcs']:
                 cpc_pattern = re.compile('^{}$'.format(cpc_item['cpc']))
                 cpc_info = ConfigCpcInfo(cpc_pattern, [])
                 for lpar_item in cpc_item['partitions']:
                     lpar_pattern = re.compile(
                         '^{}$'.format(lpar_item['partition']))
-                    lpar_info = ConfigLparInfo(lpar_pattern, syslog_servers)
+                    lpar_info = ConfigLparInfo(lpar_pattern, syslogs)
                     cpc_info.lpar_infos.append(lpar_info)
                 self.config_cpc_infos.append(cpc_info)
 
@@ -99,9 +124,9 @@ def __repr__(self):
                 "config_cpc_infos={s.config_cpc_infos!r}"
                 ")".format(s=self))
 
-    def get_syslog_servers(self, lpar):
+    def get_syslogs(self, lpar):
         """
-        Get the syslog servers for an LPAR if it matches the forwarder config.
+        Get the syslogs for an LPAR if it matches the forwarder config.
 
         If it does not match the forwarder config, None is returned.
 
@@ -110,13 +135,13 @@ def get_syslog_servers(self, lpar):
             resource object.
 
         Returns:
-          list of string: List of syslog servers if matching, or None
+          list of ConfigSyslogInfo: List of syslogs if matching, or None
           otherwise.
         """
         cpc = lpar.manager.parent
         for cpc_info in self.config_cpc_infos:
             if cpc_info.cpc_pattern.match(cpc.name):
                 for lpar_info in cpc_info.lpar_infos:
                     if lpar_info.lpar_pattern.match(lpar.name):
-                        return lpar_info.syslog_servers
+                        return lpar_info.syslogs
         return None

zhmc_os_forwarder/forwarder_server.py

@@ -20,6 +20,7 @@
 
 import os
 import logging
+import socket
 from threading import Thread, Event
 
 import zhmcclient
@@ -107,15 +108,17 @@ def startup(self):
             cpc = lpar.manager.parent
             added = self.forwarded_lpars.add_if_matching(lpar)
             if added:
-                print("LPAR {p!r} on CPC {c!r} will be forwarded".
-                      format(p=lpar.name, c=cpc.name))
+                logprint(logging.INFO, PRINT_V,
+                         "LPAR {p!r} on CPC {c!r} will be forwarded".
+                         format(p=lpar.name, c=cpc.name))
 
         self.receiver = zhmcclient.NotificationReceiver(
-            self.session.object_topic,
+            [],  # self.session.object_topic to get notifications to ignore
             hmc_data['host'],
             hmc_data['userid'],
             hmc_data['password'])
 
+        logger_id = 0  # ID number used in Python logger name
         for lpar_info in self.forwarded_lpars.forwarded_lpar_infos.values():
             lpar = lpar_info.lpar
             cpc = lpar.manager.parent
@@ -163,8 +166,47 @@ def startup(self):
             self.receiver.subscribe(os_topic)
             lpar_info.topic = os_topic
 
+            # Prepare sending to syslogs by creating Python loggers
+            for syslog in self.forwarded_lpars.get_syslogs(lpar):
+                try:
+                    logger = self._create_logger(syslog, logger_id)
+                except ConnectionError as exc:
+                    logprint(logging.WARNING, PRINT_ALWAYS,
+                             "Warning: Skipping syslog server: {}".format(exc))
+                    continue
+                logger_id += 1
+                syslog.logger = logger
+
         self._start()
 
+    @staticmethod
+    def _create_logger(syslog, logger_id):
+        facility_code = logging.handlers.SysLogHandler.facility_names[
+            syslog.facility]
+        if syslog.port_type == 'tcp':
+            # Newer syslog protocols, e.g. rsyslog
+            socktype = socket.SOCK_STREAM
+        else:
+            assert syslog.port_type == 'udp'
+            # Older syslog protocols, e.g. BSD
+            socktype = socket.SOCK_DGRAM
+        try:
+            handler = logging.handlers.SysLogHandler(
+                (syslog.host, syslog.port), facility_code,
+                socktype=socktype)
+        except Exception as exc:
+            raise ConnectionError(
+                "Cannot create log handler for syslog server at "
+                "{host}, port {port}/{port_type}: {msg}".
+                format(host=syslog.host, port=syslog.port,
+                       port_type=syslog.port_type, msg=str(exc)))
+        handler.setFormatter(logging.Formatter('%(message)s'))
+        logger_name = 'zhmcosfwd_syslog_{}'.format(logger_id)
+        logger = logging.getLogger(logger_name)
+        logger.addHandler(handler)
+        logger.setLevel(logging.INFO)
+        return logger
+
     def shutdown(self):
         """
         Stop the forwarder thread and clean up the forwarder server.
@@ -235,7 +277,7 @@ def run(self):
         """
         The method running as the forwarder server thread.
         """
-        logprint(logging.INFO, PRINT_ALWAYS,
+        logprint(logging.INFO, PRINT_V,
                  "Entering forwarder thread")
         while True:
 
@@ -254,7 +296,7 @@ def run(self):
                 logprint(logging.ERROR, PRINT_ALWAYS,
                          "Receiving notifications again")
 
-        logprint(logging.INFO, PRINT_ALWAYS,
+        logprint(logging.INFO, PRINT_V,
                  "Leaving forwarder thread")
 
     def handle_notification(self, headers, message):
@@ -266,22 +308,11 @@ def handle_notification(self, headers, message):
             for msg_info in message['os-messages']:
                 lpar_uri = headers['object-uri']
                 lpar_infos = self.forwarded_lpars.forwarded_lpar_infos
-                try:
-                    lpar_info = lpar_infos[lpar_uri]
-                    lpar = lpar_info.lpar
-                    cpc = lpar.manager.parent
-                    lpar_name = lpar.name
-                    cpc_name = cpc.name
-                except KeyError:
-                    lpar_name = headers['name']  # short name
-                    cpc_name = 'unknown'
+                lpar_info = lpar_infos[lpar_uri]
+                lpar = lpar_info.lpar
                 seq_no = msg_info['sequence-number']
                 msg_txt = msg_info['message-text'].strip('\n')
-
-                # TODO: At this point, we only display the OS message
-                print("OS message: CPC={c} LPAR={p} seq={s:06d}: {m}".
-                      format(c=cpc_name, p=lpar_name, s=seq_no, m=msg_txt))
-
+                self.send_to_syslogs(lpar, seq_no, msg_txt)
         else:
             dest = headers['destination']
             sub_id = headers['subscription']
@@ -292,3 +323,24 @@ def handle_notification(self, headers, message):
                      "(subscription: {s}, destination: {d})".
                      format(nt=noti_type, c=obj_class, n=obj_name, s=sub_id,
                             d=dest))
+
+    def send_to_syslogs(self, lpar, seq_no, msg_txt):
+        """
+        Send a single OS message to the configured syslogs for its LPAR.
+        """
+        cpc = lpar.manager.parent
+        for syslog in self.forwarded_lpars.get_syslogs(lpar):
+            if syslog.logger:
+                syslog_txt = ('{c} {p} {s}: {m}'.
+                              format(c=cpc.name, p=lpar.name, s=seq_no,
+                                     m=msg_txt))
+                try:
+                    syslog.logger.info(syslog_txt)
+                # pylint: disable=broad-exception-caught
+                except Exception as exc:
+                    logprint(logging.WARNING, PRINT_ALWAYS,
+                             "Warning: Cannot send seq_no {s} from LPAR {p!r} "
+                             "on CPC {c!r} to syslog host {h}: {m}".
+                             format(s=seq_no, p=lpar.name, c=cpc.name,
+                                    h=syslog.host, m=exc))
+                    continue