Merge lp:~javier.collado/utah/retry-timeout into lp:utah

[Javier Collado]

This branch moves the different time.sleep calls in methods like `pingcheck`
and `sshcheck` to the `retry` function that is already wrapping them.

Before this change `retry` called the callable passed as argument as soon as a
retriable exception was caught and was the responsibiliy of the callable to
call `time.sleep` if needed. With this change, the `retry` takes care of that
and uses a default value from the configuration file so that callables only
need to take care of raising an exception when they fail.

[Max Brustkern (nuclearbob)]

I see some merge conflicts. It seems weird that this and the rsyslog branch have been getting them lately. I wonder if there's been a change in launchpad that's causing this.

[Max Brustkern (nuclearbob)]

The actual changes look sound. I think at some point when we overhaul config, we can address the circular import problem.

[Andy Doan (doanac)]

these are real merge conflicts. minus those, i like the changes.

[lp:~javier.collado/utah/retry-timeout]

832. By Javier Collado on 2013-03-14

Merged changes to fix battery behavior with regard to logging

Source branch: lp:~javier.collado/utah/battery-measurements-logging

[Javier Collado (javier.collado)]

I've rebased the changes and the merge conflicts are not fixed.

I've run a test and everything worked fine, but I believe the code wasn't
really exercised because rsyslog implementation does a good work in monitoring
the reboot after the installation so the first ping command doesn't fail in VMs
as it used to do in the past.

Anyway, since I tested already before the rebasing, I don't expect any
problem.

[Max Brustkern (nuclearbob)]

Looks reasonable to me, if you're already tested.

review: Approve

=== modified file 'utah/client/runner.py'
--- utah/client/runner.py	2013-03-11 09:17:54 +0000
+++ utah/client/runner.py	2013-03-14 17:40:27 +0000
@@ -31,7 +31,6 @@
 import stat
 import urllib
 import jsonschema
-import time
 
 from utah.client.common import (
     MASTER_RUNLIST,
@@ -472,8 +471,6 @@
                 if (isinstance(vcs_handler, BzrHandler) and
                         result['returncode'] == 3 and
                         'Unable to handle http code 502' in result['stderr']):
-                    # Separate every retry attempt with a timeout of 3 seconds
-                    time.sleep(3)
                     raise UTAHException('Launchpad temporary error detected',
                                         retry=True)
                 return result

=== modified file 'utah/config.py'
--- utah/config.py	2013-03-12 16:10:49 +0000
+++ utah/config.py	2013-03-14 17:40:27 +0000
@@ -186,7 +186,10 @@
             'pattern': '.*NetworkManager',
             'timeout': 180,
         }
-    ]
+    ],
+
+    # default timeout between retry attempts
+    retry_timeout=3,
 )
 
 # These depend on the local user/path, and need to be filtered out

=== modified file 'utah/exceptions.py'
--- utah/exceptions.py	2012-12-03 14:02:18 +0000
+++ utah/exceptions.py	2013-03-14 17:40:27 +0000
@@ -24,8 +24,5 @@
     Support retry argument, but default to False.
     """
     def __init__(self, *args, **kw):
-        try:
-            self.retry = kw.pop('retry')
-        except KeyError:
-            self.retry = False
+        self.retry = kw.pop('retry', False)
         super(UTAHException, self).__init__(*args, **kw)

=== modified file 'utah/provisioning/baremetal/bamboofeeder.py'
--- utah/provisioning/baremetal/bamboofeeder.py	2013-03-05 21:01:23 +0000
+++ utah/provisioning/baremetal/bamboofeeder.py	2013-03-14 17:40:27 +0000
@@ -275,7 +275,8 @@
 
         self.rsyslog.wait_for_install(config.install_steps)
         self.rsyslog.wait_for_booted(config.boot_steps)
-        retry(self.sshcheck, config.checktimeout, logmethod=self.logger.info)
+        retry(self.sshcheck, logmethod=self.logger.info,
+              retry_timeout=config.checktimeout)
 
         self.provisioned = True
         self.active = True

=== modified file 'utah/provisioning/baremetal/cobbler.py'
--- utah/provisioning/baremetal/cobbler.py	2013-03-05 21:01:23 +0000
+++ utah/provisioning/baremetal/cobbler.py	2013-03-14 17:40:27 +0000
@@ -21,7 +21,6 @@
 import pipes
 import subprocess
 import tempfile
-import time
 
 from utah import config
 from utah.provisioning.baremetal.exceptions import UTAHBMProvisioningException
@@ -198,7 +197,8 @@
         if self.installtype == 'desktop':
             self._removenfs()
 
-        retry(self.sshcheck, config.checktimeout, logmethod=self.logger.info)
+        retry(self.sshcheck, logmethod=self.logger.info,
+              retry_timeout=config.checktimeout)
 
         self.provisioned = True
         self.active = True

=== modified file 'utah/provisioning/provisioning.py'
--- utah/provisioning/provisioning.py	2013-03-05 21:03:09 +0000
+++ utah/provisioning/provisioning.py	2013-03-14 17:40:27 +0000
@@ -28,7 +28,6 @@
 import shutil
 import subprocess
 import sys
-import time
 import urllib
 import uuid
 
@@ -310,16 +309,9 @@
         if not self.active:
             self._start()
 
-    def pingcheck(self, timeout=config.checktimeout):
+    def pingcheck(self):
         """Check network connectivity using ping.
 
-        :param timeout: Amount of time in seconds to sleep after a failure
-        :type timeout: int
-        :raises: UTAHProvisioningException
-
-        If there's a network connectivity failure, then sleep ``timeout``
-        seconds and raise a retriable exception.
-
         .. seealso:: :func:`utah.retry.retry`, :meth:`pingpoll`
 
         """
@@ -328,12 +320,6 @@
             self._runargs(['ping', '-c1', '-w5', self.name])['returncode']
         if returncode != 0:
             err = 'Ping returned {0}'.format(returncode)
-
-            if timeout > 0:
-                self.logger.info('Sleeping {timeout} seconds'
-                                 .format(timeout=timeout))
-                time.sleep(timeout)
-
             raise UTAHProvisioningException(err, retry=True)
 
     def pingpoll(self,
@@ -345,8 +331,8 @@
             timeout = self.boottimeout
         if logmethod is None:
             logmethod = self.logger.debug
-        utah.timeout.timeout(timeout, retry, self.pingcheck, checktimeout,
-                             logmethod=logmethod)
+        utah.timeout.timeout(timeout, retry, self.pingcheck,
+                             logmethod=logmethod, retry_timeout=checktimeout)
 
     def getutahdeb(self, deb):
         """

=== modified file 'utah/provisioning/ssh.py'
--- utah/provisioning/ssh.py	2013-03-07 21:55:56 +0000
+++ utah/provisioning/ssh.py	2013-03-14 17:40:27 +0000
@@ -238,16 +238,9 @@
 
         super(SSHMixin, self).destroy(*args, **kw)
 
-    def sshcheck(self, timeout=config.checktimeout):
+    def sshcheck(self):
         """Check if the machine is available via ssh.
 
-        :param timeout: Amount of time in seconds to sleep after a failure
-        :type timeout: int
-        :raises: UTAHProvisioningException
-
-        If there's a network connectivity failure, then sleep ``timeout``
-        seconds and raise a retriable exception.
-
         .. seealso:: :func:`utah.retry.retry`, :meth:`sshpoll`
 
         """
@@ -257,11 +250,6 @@
                                     username=config.user,
                                     key_filename=config.sshprivatekey)
         except socket.error as err:
-            if timeout > 0:
-                self.ssh_logger.info('Sleeping {timeout} seconds'
-                                     .format(timeout=timeout))
-                time.sleep(timeout)
-
             raise UTAHProvisioningException(str(err), retry=True)
 
     def sshpoll(self, timeout=None,
@@ -273,8 +261,8 @@
             timeout = self.boottimeout
         if logmethod is None:
             logmethod = self.ssh_logger.debug
-        utah.timeout.timeout(timeout, retry, self.sshcheck, checktimeout,
-                             logmethod=logmethod)
+        utah.timeout.timeout(timeout, retry, self.sshcheck,
+                             logmethod=logmethod, retry_timeout=checktimeout)
 
     def activecheck(self):
         """

=== modified file 'utah/retry.py'
--- utah/retry.py	2013-02-06 10:53:54 +0000
+++ utah/retry.py	2013-03-14 17:40:27 +0000
@@ -17,6 +17,7 @@
 Provide a retry loop that exits on success or an unretryable exception.
 """
 import sys
+import time
 
 from utah.exceptions import UTAHException
 from utah.commandstr import commandstr
@@ -36,18 +37,24 @@
         Keyword arguments to be passed to the callable.
 
         .. note::
-            If a keyword argument named ``logmethod`` is found, it will be
-            extracted (i.e. it won't be passed to the callable) and used to log
-            every retry attempt (using ``sys.stderr`` by default).
+            There are a few keywords that are consumed by ``retry`` and not
+            passed to the callable:
+              * ``logmethod``: Preferred log method for every retry attempt
+                (``sys.stderr`` by default)
+              * ``retry_timeout``: Timeout in seconds between each retry
+                attempt
+
     :returns: The value returned by the callable.
 
     .. seealso:: :func:`utah.timeout.timeout`
 
     """
-    try:
-        logmethod = kw.pop('logmethod')
-    except KeyError:
-        logmethod = sys.stderr.write
+    # The following import is in the function body to avoid a cycle:
+    # utah.config -> utah.url -> utah.retry -> utah.config
+    from utah import config
+
+    logmethod = kw.pop('logmethod', sys.stderr.write)
+    retry_timeout = kw.pop('retry_timeout', config.retry_timeout)
     retval = False
     while True:
         try:
@@ -57,8 +64,11 @@
             try:
                 if err.retry:
                     if logmethod is not None:
-                        logmethod('Caught ' + str(err) + ', retrying '
-                                  + commandstr(command, *args, **kw))
+                        logmethod('Caught {}, retrying {} in {} seconds'
+                                  .format(err,
+                                          commandstr(command, *args, **kw),
+                                          retry_timeout))
+                        time.sleep(retry_timeout)
                 else:
                     raise AttributeError
             except AttributeError:

=== modified file 'utah/url.py'
--- utah/url.py	2013-02-06 10:07:52 +0000
+++ utah/url.py	2013-03-14 17:40:27 +0000
@@ -24,7 +24,6 @@
 import urllib2
 import tempfile
 import logging
-import time
 from urlparse import urlparse
 from argparse import ArgumentTypeError
 
@@ -226,8 +225,6 @@
             try:
                 cmd.run(tmp_dir, url)
             except bzrlib.errors.InvalidHttpResponse as exception:
-                # Separate every retry attempt with a timeout of 3 seconds
-                time.sleep(3)
                 raise UTAHException(exception.path, exception.msg, retry=True)
 
         try: