Ticket 3240: ZOOM no longer creating putlogs

BlockServer/core/ioc_control.py

@@ -33,39 +33,38 @@ def __init__(self, prefix):
         """
         self._proc = ProcServWrapper(prefix)
 
-    def start_ioc(self, ioc):
-        """Start an IOC.
-
+    def _perform_ioc_control(self, control_function, ioc):
+        """Performs an ioc control operation.
         Args:
-            ioc (string): The name of the IOC
+            control_function: A reference to the function to perform.
+            ioc (str): The ioc to perform the function.
         """
         try:
-            self._proc.start_ioc(ioc)
+            control_function(ioc)
             if ioc != "ALARM":
                 AlarmConfigLoader.restart_alarm_server(self)
         except Exception as err:
-            print_and_log("Could not start IOC %s: %s" % (ioc, str(err)), "MAJOR")
+            print_and_log("Could not perform {} IOC {}: {}".format(control_function.__name__, ioc, str(err)), "MAJOR")
+
+    def start_ioc(self, ioc):
+        """Start an IOC.
+
+        Args:
+            ioc (string): The name of the IOC
+        """
+        self._perform_ioc_control(self._proc.start_ioc, ioc)
 
     def restart_ioc(self, ioc, force=False):
         """Restart an IOC.
 
-        Note: restarting an IOC automatically sets the IOC to auto-restart, so it is neccessary to reapply the
-        previous auto-restart setting
-
         Args:
             ioc (string): The name of the IOC
             force (bool): Force it to restart even if it is an IOC not to stop
         """
         # Check it is okay to stop it
         if not force and ioc.startswith(IOCS_NOT_TO_STOP):
             return
-        try:
-            auto = self._proc.get_autorestart(ioc)
-            self._proc.restart_ioc(ioc)
-            if ioc != "ALARM":
-                AlarmConfigLoader.restart_alarm_server(self)
-        except Exception as err:
-            print_and_log("Could not restart IOC %s: %s" % (ioc, str(err)), "MAJOR")
+        self._perform_ioc_control(self._proc.restart_ioc, ioc)
 
     def stop_ioc(self, ioc, force=False):
         """Stop an IOC.
@@ -77,12 +76,7 @@ def stop_ioc(self, ioc, force=False):
         # Check it is okay to stop it
         if not force and ioc.startswith(IOCS_NOT_TO_STOP):
             return
-        try:
-            self._proc.stop_ioc(ioc)
-            if ioc != "ALARM":
-                AlarmConfigLoader.restart_alarm_server(self)
-        except Exception as err:
-            print_and_log("Could not stop IOC %s: %s" % (ioc, str(err)), "MAJOR")
+        self._perform_ioc_control(self._proc.stop_ioc, ioc)
 
     def get_ioc_status(self, ioc):
         """Get the running status of an IOC.

BlockServer/mocks/mock_procserv_utils.py

@@ -49,13 +49,6 @@ def get_ioc_status(self, ioc):
         else:
             return self.ps_status[ioc.lower()]
 
-    def ioc_exists(self, ioc):
-        try:
-            self.get_ioc_status(ioc)
-            return True
-        except:
-            return False
-
     def get_autorestart(self, ioc):
         return self.autorestart
 

BlockServer/test_modules/test_ioc_control.py

@@ -18,7 +18,7 @@
 from BlockServer.core.ioc_control import IocControl
 from BlockServer.mocks.mock_procserv_utils import MockProcServWrapper
 from server_common.constants import IOCS_NOT_TO_STOP
-from mock import patch
+from mock import patch, MagicMock
 
 
 class TestIocControlSequence(unittest.TestCase):
@@ -94,3 +94,13 @@ def test_GIVEN_reapply_auto_true_WHEN_multiple_ioc_restarts_requested_THEN_ioc_c
         self.assertFalse(self.ic.ioc_restart_pending("TESTIOC"))
         self.ic.restart_iocs(["TESTIOC"], reapply_auto=True)
         self.assertFalse(self.ic.ioc_restart_pending("TESTIOC"))
+
+    @patch("BlockServer.core.ioc_control.AlarmConfigLoader")
+    def test_WHEN_ioc_control_performed_on_alarm_THEN_alarm_server_not_reset(self, alarm_config_loader):
+        self.ic._perform_ioc_control(MagicMock(), "ALARM")
+        alarm_config_loader.restart_alarm_server.assert_not_called()
+
+    @patch("BlockServer.core.ioc_control.AlarmConfigLoader")
+    def test_WHEN_ioc_control_performed_on_other_ioc_THEN_alarm_server_not_reset(self, alarm_config_loader):
+        self.ic._perform_ioc_control(MagicMock(), "OTHER_IOC")
+        alarm_config_loader.restart_alarm_server.assert_called_once()

server_common/loggers/isis_logger.py

@@ -16,42 +16,66 @@
 
 import datetime
 import socket
+from lxml import etree
+import re
 
+IOCLOG_ADDR = ("127.0.0.1", 7004)
+_illegal_xml_chars_RE = re.compile(u'[\x00-\x08\x0b\x0c\x0e-\x1F\uD800-\uDFFF\uFFFE\uFFFF]')
 
-class IsisLogger(object):
-    def __init__(self):
-        super(IsisLogger, self).__init__()
-        self.ioclog_host = "127.0.0.1"
-        self.ioclog_port = 7004
 
+def escape_xml_illegal_chars(text):
+    """Escapes illegal XML unicode characters to their python representation.
+    See https://www.w3.org/TR/xml/#charsets
+    Args:
+        text (str): The text to escape.
+    Returns:
+        str: The corrected string.
+    """
+    return _illegal_xml_chars_RE.sub(lambda match: repr(match.group(0)), text)
+
+
+def create_xml_string(message, severity, src):
+    """Creates the xml string to send to the server.
+
+    Args:
+        message (string): The message to write.
+        severity (string): Gives the severity of the message. Expected severities are MAJOR, MINOR and INFO.
+        src (string): Gives the source of the message
+    """
+    msg_time = datetime.datetime.utcnow()
+    msg_time_str = msg_time.isoformat()
+    if msg_time.utcoffset() is None:
+        msg_time_str += "Z"
+
+    xml_message = etree.Element("message")
+    etree.SubElement(xml_message, "clientName").text = src
+    etree.SubElement(xml_message, "severity").text = severity
+    etree.SubElement(xml_message, "contents").text = etree.CDATA(escape_xml_illegal_chars(message))
+    etree.SubElement(xml_message, "type").text = "ioclog"
+    etree.SubElement(xml_message, "eventTime").text = msg_time_str
+
+    return etree.tostring(xml_message, encoding="utf-8")
+
+
+class IsisLogger(object):
     def write_to_log(self, message, severity="INFO", src="BLOCKSVR"):
         """Writes a message to the IOC log. It is preferable to use print_and_log for easier debugging.
         Args:
-            severity (string, optional): Gives the severity of the message. Expected serverities are MAJOR, MINOR and INFO.
+            message (string): The message to write.
+            severity (string, optional): Gives the severity of the message. Expected severities are MAJOR, MINOR and INFO.
                                         Default severity is INFO
             src (string, optional): Gives the source of the message. Default source is BLOCKSVR
         """
         if severity not in ['INFO', 'MINOR', 'MAJOR', 'FATAL']:
             print("write_to_ioc_log: invalid severity ", severity)
             return
-        msg_time = datetime.datetime.utcnow()
-        msg_time_str = msg_time.isoformat()
-        if msg_time.utcoffset() is None:
-            msg_time_str += "Z"
-
-        xml = "<?xml version=\"1.0\" encoding=\"UTF-8\"?>"
-        xml += "<message>"
-        xml += "<clientName>%s</clientName>" % src
-        xml += "<severity>%s</severity>" % severity
-        xml += "<contents><![CDATA[%s]]></contents>" % message
-        xml += "<type>ioclog</type>"
-        xml += "<eventTime>%s</eventTime>" % msg_time_str
-        xml += "</message>\n"
+
+        xml_string = create_xml_string(message, severity, src)
 
         try:
             sock = socket.socket(socket.AF_INET, socket.SOCK_STREAM)
-            sock.connect((self.ioclog_host, self.ioclog_port))
-            sock.sendall(xml)
+            sock.connect(IOCLOG_ADDR)
+            sock.sendall(xml_string)
         except Exception as err:
             print("Could not send message to IOC log: %s" % err)
         finally:

server_common/test_modules/test_isis_logger.py

@@ -0,0 +1,20 @@
+import unittest
+from server_common.loggers.isis_logger import create_xml_string
+
+
+class TestISISLogger(unittest.TestCase):
+    def test_WHEN_message_contains_invalid_unicode_THEN_xml_contains_string_repr(self):
+        message = u"\u0002"
+
+        xml_string = create_xml_string(message, "INFO", "BS")
+
+        self.assertIn(r"'\x02'", xml_string)
+        self.assertNotIn(message, xml_string)
+
+    def test_WHEN_message_contains_valid_unicode_THEN_xml_contains_unicode(self):
+        message = u"\t"
+
+        xml_string = create_xml_string(message, "INFO", "BS")
+
+        self.assertNotIn(r"'\x09'", xml_string)
+        self.assertIn(message, xml_string)