Merge ~johnsca/juju-wait:bug/1680963-settle-retry into juju-wait:master

[Cory Johns]

Juju will automatically retry failed hooks with a cool-off period to account for transient errors. Some charms unfortunately (and perhaps unknowingly) rely on this behavior. This option allows juju-wait to be a bit more forgiving before reporting failure.

[Cory Johns (johnsca)]

I went with number of retries rather than a time-frame because it seemed easier than trying to account for hook run times (failure could be due to a download that times out on the order of minutes) or controller load.

It's possible to turn off automatic retries via the model-config, and if this option is used on a model where the automatic retries aren't happening, it could end up blocking indefinitely. But I'm not sure that case is worth investing effort in handling rather than just leaving it up to the user to not ask for contradictory things.

[Stuart Bishop (stub)]

This certainly shouldn't be the default (which it isn't), as the case described is exactly the sort of failure that juju-wait should be reporting as an error so it can be fixed. While it could be useful for deploy scripts, it would be a mistake to enable this on CI or test environments - if a charm recovers from an error state it does not mean it will always recover, and ignoring these bugs is ignoring tech debt that will likely need to be repaid at deployment time.

I'm flagging this as NEEDS FIX, as we need to emit a warning if retry behaviour is triggered, explaining that the charm failed but we are attempting to continue anyway. At no point should relying on retry behaviour be considered normal, and it should be clearly pointed out at every stage that a bug has been detected when a charm hits an error state. Retry behaviour was added to Juju purely so users could work with crap charms; it was not added to make crap charms acceptable or the status quo. If we want to change this policy and best practice, we should do it with our eyes open rather than let things slide until the decision has been made for us.

review: Needs Fixing

[Stuart Bishop (stub)]

(juju-deployer may need a similar update if it is in use, as I think it will still fail if a unit happens to be in an error state when it polls the status)

[Cory Johns (johnsca)]

I agree that this generally encourages not fixing bugs in charms, but we need this functionality for conjure-up as there are an unfortunate number of cases where some of the older charms used by some bundles will go into an error state very briefly which causes conjure-up to fail even though the deployment eventually settles out to fine. +100 to never allowing it in CI.

diff --git a/juju_wait/__init__.py b/juju_wait/__init__.py
index e6d8945..876ef9c 100755
--- a/juju_wait/__init__.py
+++ b/juju_wait/__init__.py
@@ -105,6 +105,14 @@ def juju_exe():
     return juju
 
 
+def juju(*args):
+    # Older juju versions don't support --utc, so force UTC timestamps
+    # using the environment variable.
+    env = os.environ.copy()
+    env['TZ'] = 'UTC'
+    return run_or_die([juju_exe()] + args, env=env)
+
+
 def juju_run(unit, cmd, timeout=None):
     if timeout is None:
         timeout = 6 * 60 * 60
@@ -207,6 +215,10 @@ def wait_cmd(args=sys.argv[1:]):
     parser.add_argument('-t', '--max_wait', dest='max_wait',
                         help='Maximum time to wait for readiness (seconds)',
                         action='store', default=None)
+    parser.add_argument('-r', '--retry_errors', dest='retry_errors',
+                        action='store', default=0, type=int, metavar='N',
+                        help='Allow Juju to retry errors N times '
+                        'before failing')
     parser.add_argument('--version', default=False, action='store_true')
     args = parser.parse_args(args)
 
@@ -231,9 +243,17 @@ def wait_cmd(args=sys.argv[1:]):
     else:
         max_wait = None
 
+    if args.retry_errors:
+        if juju('version').startswith('1.'):
+            logging.warning('Ignoring --retry_errors on Juju 1.x')
+            args.retry_errors = 0
+        elif juju('model-config', 'automatically-retry-hooks') != 'True':
+            logging.warning('Ignoring --retry_errors when retries disabled')
+            args.retry_errors = 0
+
     # Begin watching and waiting
     try:
-        wait(log, args.wait_for_workload, max_wait)
+        wait(log, args.wait_for_workload, max_wait, args.retry_errors)
         return 0
     except JujuWaitException as x:
         return x.args[0]
@@ -248,7 +268,21 @@ def reset_logging():
                 'logging-config=juju=WARNING;unit=INFO'])
 
 
-def wait(log=None, wait_for_workload=False, max_wait=None):
+def get_error_repeat_count(uname):
+    """Determine the number of times the most recent workload status was
+    repeated.
+    """
+    status_log = juju('show-status-log', uname, '--days=1')
+    status_log = [l.split('\t')
+                  for l in status_log.splitlines()
+                  if 'juju-unit' in l and 'executing' not in l]
+    for i, status in enumerate(reversed(status_log)):
+        if status[2].strip() not in WORKLOAD_ERROR_STATES:
+            return i
+    return len(status_log)
+
+
+def wait(log=None, wait_for_workload=False, max_wait=None, retry_errors=0):
     # Note that wait_for_workload is only useful as a workaround for
     # broken setups. It is impossible for a charm to report that it has
     # completed setup, because a charm has no information about units
@@ -359,10 +393,14 @@ def wait(log=None, wait_for_workload=False, max_wait=None):
 
             # Fail and raise if workload state is ever in error
             if current in WORKLOAD_ERROR_STATES and wait_for_workload:
-                logging.error('{} failed: workload status is '
-                              '{}'.format(uname, current))
-                ready = False
-                raise JujuWaitException(1)
+                if get_error_repeat_count(uname) < retry_errors:
+                    logging.warning('{} failure ignored, '
+                                    'will be retried'.format(uname))
+                else:
+                    logging.error('{} failed: workload status is '
+                                  '{}'.format(uname, current))
+                    ready = False
+                    raise JujuWaitException(1)
 
         for uname, astatus in sorted(agent_status.items()):
             if not ('current' in astatus and 'since' in astatus):