Merge lp:~javier.collado/utah/bug1161855 into lp:utah

[Javier Collado]

This branch adds the ability to set failure patterns in the syslog
implementation so that the server stops if one of those patterns is found (not
only on timeout).

This is good not only to stop as soon as possible, but also to make sure that
an error code is return by the server process when a problem happens.

I've tested this with both desktop/server images and also introducing a problem
in the late/success_command to make sure the error was detected.

[Max Brustkern (nuclearbob)]

Looks good to me, but I haven't tested it yet. I guess maybe a latecommand designed to fail would be the best thing for that?

[Andy Doan (doanac)]

well done. just add a test for test_rsyslog.py and I'm +1.

I'm a little jealous - I'd started a similar fix but it was uglier than this :)

[lp:~javier.collado/utah/bug1161855]

846. By Javier Collado on 2013-03-29

Merged changes to remove temporary files downloaded based on URL (LP: #1101186)

These changes entail moving the cleanup and the process running code outside of
the Machine class to their own classes.

[Javier Collado (javier.collado)]

A test case to make sure the fail_pattern works has been added and the
documentation has been updated.

Regarding testing, what I've done is test the pattern that is used to detect
problem in the late/success_command. However, I haven't been able to test the
ones for installation failures (either in ubiquity or in d-i). I could send a
message that matches those patterns to syslog, but that won't test that those
messages are really printed for a broken image (when I stumble upon one I'll
take a look at the syslog to check how the error message is written).

review: Needs Resubmitting

[lp:~javier.collado/utah/bug1161855]

850. By Javier Collado on 2013-03-29

Added test case to verify fail_patttern

851. By Javier Collado on 2013-03-29

Updated documentation

[Javier Collado (javier.collado)]

Rebased changes to fix conflict in debian/changelog

[Andy Doan (doanac)]

review: Approve

=== modified file 'debian/changelog'
--- debian/changelog	2013-03-29 15:55:46 +0000
+++ debian/changelog	2013-03-29 17:11:22 +0000
@@ -2,6 +2,7 @@
 
   * Return error code on unhandled error (LP: #1160857)
   * Remove temporary files downloaded based on URL (LP: #1101186)
+  * Stop server on installation failure (LP: #1161855)
 
  -- Javier Collado <[e-mail]>  Wed, 27 Mar 2013 13:00:47 +0100
 

=== modified file 'docs/source/reference.rst'
--- docs/source/reference.rst	2013-03-28 17:51:50 +0000
+++ docs/source/reference.rst	2013-03-29 17:11:22 +0000
@@ -97,15 +97,18 @@
 
 .. automodule:: utah.provisioning
 
+.. automodule:: utah.provisioning.exceptions
+   :members:
+
 .. automodule:: utah.provisioning.provisioning
    :members:
 
+.. automodule:: utah.provisioning.rsyslog
+   :members:
+
 .. automodule:: utah.provisioning.ssh
    :members:
 
-.. automodule:: utah.provisioning.exceptions
-   :members:
-
 ``utah.provisioning.baremetal``
 -------------------------------
 

=== modified file 'tests/test_rsyslog.py'
--- tests/test_rsyslog.py	2013-03-14 20:23:09 +0000
+++ tests/test_rsyslog.py	2013-03-29 17:11:22 +0000
@@ -20,6 +20,7 @@
 import threading
 import unittest
 
+from utah.exceptions import UTAHException
 from utah.provisioning.rsyslog import RSyslog
 
 
@@ -71,6 +72,27 @@
         threading.Thread(target=self.producer, args=(r.port, messages)).start()
         r.wait_for_install(steps)
 
+    def test_fail_pattern(self):
+        """Exception is raised on fail_pattern match."""
+        steps = [
+            {
+                "message": "test_late_command_failure",
+                "pattern": "finished",
+                "fail_pattern": "failure",
+                "timeout": 120,
+            },
+        ]
+
+        messages = [
+            'started',
+            'failure',
+            'finished',
+        ]
+
+        r = RSyslog('utah-test', '/tmp')
+        threading.Thread(target=self.producer, args=(r.port, messages)).start()
+        self.assertRaises(UTAHException, r.wait_for_install, steps)
+
     def test_future(self):
         """
         test to make sure we can handle missing a message and understanding

=== modified file 'utah/config.py'
--- utah/config.py	2013-03-18 16:44:36 +0000
+++ utah/config.py	2013-03-29 17:11:22 +0000
@@ -174,7 +174,15 @@
                 '.*finish-install: umount',
                 '.*rsyslogd:.*exiting on signal 15.',  # a catch-all
             ],
-            "timeout": 3600
+            'fail_pattern': [
+                # ubiquity/failure_command
+                '.*utah: Installation failure detected',
+                # ubiquity/success_command and d-i/late_command failures
+                '.*utah: Late command failure detected',
+                # d-i installation failure
+                '.*exited with status [^0]',
+            ],
+            'timeout': 3600,
         },
     ],
     boot_steps=[

=== modified file 'utah/provisioning/rsyslog.py'
--- utah/provisioning/rsyslog.py	2013-03-05 21:02:47 +0000
+++ utah/provisioning/rsyslog.py	2013-03-29 17:11:22 +0000
@@ -13,6 +13,8 @@
 # You should have received a copy of the GNU General Public License along
 # with this program.  If not, see <http://www.gnu.org/licenses/>.
 
+"""rsyslog processing and monitoring."""
+
 import logging
 import os
 import re
@@ -25,11 +27,20 @@
 
 
 class RSyslog(object):
+
+    """Listen to rsyslog messages and process them.
+
+    :param hostname: Host where the syslog is coming from.
+    :type hostname: str
+    :param logpath: Base directory where log files are created.
+    :type logpath: str
+    :param usefile:
+        allows class to ``tail`` a file rather than act as an rsyslogd server
+    :type usefile: str | None
+
+    """
+
     def __init__(self, hostname, logpath, usefile=None):
-        """
-        :param usefile: allows class to "tail" a file rather than act as an
-        rsyslogd server
-        """
         self._host = hostname
         self._logpath = logpath
 
@@ -54,16 +65,27 @@
 
     @property
     def port(self):
+        """Return UDP port number used to listen for syslog messages."""
         return self._port
 
     def wait_for_install(self, steps, booted_callback=None):
-        """
+        """Monitor rsyslog messages during the installation.
+
         Works through each step in the steps array to find messages in the
-        syslog indicating what part of the install we are in. Steps is an
-        array of:
+        syslog indicating what part of the install we are in.
+
+        :param steps: Set of steps that the installation will go through.
+        :type steps: list
+        :param booted_callback:
+            function to be called once the system has been booted
+        :type booted_callback: callable | None
+
+        An example of a valid steps argument would be as follows::
+
             {
               "message": "system started",
               "pattern": ".*log source = /proc/kmsg started",
+              "fail_pattern": ".*exited with status [^0]",
               "timeout": 1000,
               "booted": false
             },
@@ -75,19 +97,33 @@
               "timeout": 1000,
               "booted": false
             }
-        "pattern" can an array or string
-        "booted" is optional, but can be used to indicate that the system is
-        fully operational. This can be used in conjunction with the
-        "booted_callback" function.
+
+        where:
+
+            - ``pattern`` can an array or string.
+            - ``booted`` is optional, but can be used to indicate that the
+              system is fully operational. This can be used in conjunction with
+              the ``booted_callback`` function.
+
+        .. seealso:: :meth:`wait_for_booted`
+
         """
         logfile = '{}/{}-install.log'.format(self._logpath, self._host)
         callbacks = {'booted': booted_callback}
         self._wait_for_steps(steps, logfile, callbacks)
 
     def wait_for_booted(self, steps):
-        """
-        Works the same as the wait_for_install function but takes in steps
-        that determine a system has booted after the install has completed.
+        """Monitor rsyslog during boot up.
+
+        Works the same as the :meth:`wait_for_install` method but takes in
+        steps that determine a system has booted after the install has
+        completed.
+
+        :param steps: Set of steps that the boot up will go through.
+        :type steps: list
+
+        .. seealso:: :meth:`wait_for_install`
+
         """
         logfile = '{}/{}-boot.log'.format(self._logpath, self._host)
         callbacks = {}
@@ -99,14 +135,21 @@
             while x < len(steps):
                 message = steps[x]['message']
                 pattern = steps[x]['pattern']
+                fail_pattern = steps[x].get('fail_pattern', [])
                 timeout = steps[x]['timeout']
 
                 if not isinstance(pattern, list):
                     pattern = [pattern]
+                if not isinstance(fail_pattern, list):
+                    fail_pattern = [fail_pattern]
+                pattern.extend(fail_pattern)
                 future_pats = self._future_patterns(steps, x)
                 pattern.extend(future_pats)
                 self.logger.info('Waiting %ds for: %s', timeout, message)
                 match = self._wait_for(f, pattern, message, timeout)
+                if match in fail_pattern:
+                    raise UTAHException('Failure pattern found: {}'
+                                        .format(match))
                 if match in future_pats:
                     msg = 'Expected pattern missed, matched future pattern: %s'
                     self.logger.warn(msg, match)
@@ -135,11 +178,14 @@
 
     @staticmethod
     def _fast_forward(steps, pattern, callbacks):
-        """
-        Looks through each item in the steps array to find the index of the
-        given pattern. It will return that index so that the wait_for code
-        knows where to continue from. It will also alert the booted_callback
-        function if that was one of the steps that was missed.
+        """Figure out what should be the next step.
+
+        Look through each item in the steps array to find the index of the
+        given pattern. It will return that index so that the ``wait_for`` code
+        knows where to continue from. It will also alert the
+        ``booted_callback`` function if that was one of the steps that was
+        missed.
+
         """
         x = 0
         while x < len(steps):