Merge lp:~veebers/juju-ci-tools/record_timing_actions into lp:juju-ci-tools

[Christopher Lee]

Enable collection of timing data for bootstrap, kill/destroy controller and deploy.

Enable collection of timing data for bootstrap, kill/destroy controller and deploy.

Timing collection for bootstrap and kill/destroy controller are collected without any need for any intervention from a test author.
deploy on the other hand needs to make a change where instead of:
  client.deploy(...)
  client.wait_for_started()
Instead:
  _, deploy_complete = client.deploy(...)
  client.wait_for(deploy_complete)

The resulting timing data looks like: http://paste.ubuntu.com/24265304/

[Aaron Bentley (abentley)]

It seems strange CommandComplete objects for synchronous operations. I think we only need that for asynchronous ones. Why do you want this?

review: Needs Information

[Christopher Lee (veebers)]

The CommandComplete objects for synchronous operations are so the end time gets completed. It possible we could explicitly do that without using a CommandComplete object, but as noted inline I wanted to keep return patterns consistent.

[Aaron Bentley (abentley)]

I think return pattern consistency makes calling code ugly, and does not have an obvious advantage. I think there are three types of methods that should have different return patterns.

1. Output queries like get_status. These should return an object representing the
   subprocess's stdout.
2. Synchronous operations like bootstrap and kill_controller. These may return an object
   representing the outcome of the operation.
   So far, only destroy_controller, backup, and run have this, and each return value is
   different, so I'm hesitant to generalize further.
3. Asynchronous operations. These should return an object that supports wait_for so the caller
   can wait until the operation completes. They cannot return an object representing the
   outcome of the operation, because it has not completed when they return.

I can't see significant benefits in making 2 and 3 consistent. We don't treat juju operations as interchangeable. bootstrap, destroy-controller, and kill-controller in particular should rarely be seen in user code, because BootstrapManager handles them.

[Aaron Bentley (abentley)]

Oh, I forgot to mention bootstrap's WaitAgentsStarted. Bootstrap is one of the few operations we already have reasonable timings for, and they are based on the time it takes the juju command to run. When bootstrap is complete, the controller should be ready for use.

[lp:~veebers/juju-ci-tools/record_timing_actions]

1966. By Christopher Lee on 2017-04-05

Don't actually return non-needed CommandComplete objects.

[Aaron Bentley (abentley)]

Thank you for making synchronous operations return simply their retval.

Why do you want deploy to return (0, CommandComplete)? It will always be zero. If the exit status were not zero, subprocess.CalledProcessError would be raised. The same is true of all async commands.

[Aaron Bentley (abentley)]

Oh, and do you want to do something with CommandTime on exception? Or are you happy just letting the end time never be set as an indication that the command should be ignored?

[Christopher Lee (veebers)]

I'm happy with leaving it, if an exception occurred it's unlikely that the command actually completed and thus that time should be ignored.
Although I am interested what your suggestion would have been for handling that exception in regards to CommandTime.

Regarding deploy returning (0, CommandComplete) I just replaced what was originally there which was to return what self.juju(...) returned. You make a good point. I can change this if we desire it, but I would do it in a separate MP.

[Aaron Bentley (abentley)]

I don't know what the right exception handling option is. I think leaving it as is would be fine, but I thought it was worth mentioning. I would record the end time and mark it failed, but I just know someone would accidentally combine the failed operations with the successful ones and muddy the data. Maybe there could be a different list with only failed operations. But I can't see much interest in how long operations take to fail, so deleting them might make more sense.

I concede that returning retvar is consistent with the previous version. I guess I tend to return a callee's return value when I'm writing a thin wrapper. Still, I think it would be worth changing in the future.

review: Approve

=== modified file 'jujupy/client.py'
--- jujupy/client.py	2017-04-05 04:20:57 +0000
+++ jujupy/client.py	2017-04-05 04:20:58 +0000
@@ -1451,6 +1451,22 @@
         raise VersionsNotUpdated(model_name, status)
 
 
+class WaitAgentsStarted(BaseCondition):
+
+    def __init__(self, timeout=1200):
+        super(WaitAgentsStarted, self).__init__(timeout)
+
+    def iter_blocking_state(self, status):
+        states = Status.check_agents_started(status)
+
+        if states is not None:
+            for state, item in states.items():
+                yield item[0], state
+
+    def do_raise(self, model_name, status):
+        raise AgentsNotStarted(model_name, status)
+
+
 class CommandTime:
     """Store timing details for a juju command."""
 
@@ -1946,7 +1962,9 @@
                 upload_tools, config_filename, bootstrap_series, credential,
                 auto_upgrade, metadata_source, no_gui, agent_version)
             self.update_user_name()
-            self.juju('bootstrap', args, include_e=False)
+            retvar, ct = self.juju('bootstrap', args, include_e=False)
+            ct.actual_completion()
+            return retvar
 
     @contextmanager
     def bootstrap_async(self, upload_tools=False, bootstrap_series=None,
@@ -1989,7 +2007,9 @@
         retvar, ct = self.juju(
             'kill-controller', (self.env.controller.name, '-y'),
             include_e=False, check=check, timeout=get_teardown_timeout(self))
-        return retvar, CommandComplete(NoopCondition(), ct)
+        # Already satisfied as this is a sync, operation.
+        ct.actual_completion()
+        return retvar
 
     def destroy_controller(self, all_models=False):
         """Destroy a controller and its models. Soft kill option.
@@ -2005,7 +2025,9 @@
         retvar, ct = self.juju(
             'destroy-controller', args, include_e=False,
             timeout=get_teardown_timeout(self))
-        return retvar, CommandComplete(NoopCondition(), ct)
+        # Already satisfied as this is a sync, operation.
+        ct.actual_completion()
+        return retvar
 
     def tear_down(self):
         """Tear down the client as cleanly as possible.
@@ -2016,7 +2038,7 @@
             self.destroy_controller(all_models=True)
         except subprocess.CalledProcessError:
             logging.warning('tear_down destroy-controller failed')
-            retval, _ = self.kill_controller()
+            retval = self.kill_controller()
             message = 'tear_down kill-controller result={}'.format(retval)
             if retval == 0:
                 logging.info(message)
@@ -2243,7 +2265,7 @@
         if alias is not None:
             args.extend([alias])
         retvar, ct = self.juju('deploy', tuple(args))
-        return CommandComplete(NoopCondition(), ct)
+        return retvar, CommandComplete(WaitAgentsStarted(), ct)
 
     def attach(self, service, resource):
         args = (service, resource)

=== modified file 'jujupy/tests/test_client.py'
--- jujupy/tests/test_client.py	2017-04-05 04:20:57 +0000
+++ jujupy/tests/test_client.py	2017-04-05 04:20:58 +0000
@@ -661,7 +661,7 @@
 
     def test_bootstrap_maas(self):
         env = JujuData('maas', {'type': 'foo', 'region': 'asdf'})
-        with patch.object(ModelClient, 'juju') as mock:
+        with patch_juju_call(ModelClient) as mock:
             client = ModelClient(env, '2.0-zeta1', None)
             with patch.object(client.env, 'maas', lambda: True):
                 with observable_temp_file() as config_file:
@@ -679,7 +679,7 @@
         # Disable space constraint with environment variable
         os.environ['JUJU_CI_SPACELESSNESS'] = "1"
         env = JujuData('maas', {'type': 'foo', 'region': 'asdf'})
-        with patch.object(ModelClient, 'juju') as mock:
+        with patch_juju_call(ModelClient) as mock:
             client = ModelClient(env, '2.0-zeta1', None)
             with patch.object(client.env, 'maas', lambda: True):
                 with observable_temp_file() as config_file:
@@ -695,13 +695,13 @@
     def test_bootstrap_joyent(self):
         env = JujuData('joyent', {
             'type': 'joyent', 'sdc-url': 'https://foo.api.joyentcloud.com'})
-        with patch.object(ModelClient, 'juju', autospec=True) as mock:
-            client = ModelClient(env, '2.0-zeta1', None)
+        client = ModelClient(env, '2.0-zeta1', None)
+        with patch_juju_call(client) as mock:
             with patch.object(client.env, 'joyent', lambda: True):
                 with observable_temp_file() as config_file:
                     client.bootstrap()
             mock.assert_called_once_with(
-                client, 'bootstrap', (
+                'bootstrap', (
                     '--constraints', 'mem=2G cpu-cores=1',
                     'joyent/foo', 'joyent',
                     '--config', config_file.name,
@@ -711,7 +711,7 @@
     def test_bootstrap(self):
         env = JujuData('foo', {'type': 'bar', 'region': 'baz'})
         with observable_temp_file() as config_file:
-            with patch.object(ModelClient, 'juju') as mock:
+            with patch_juju_call(ModelClient) as mock:
                 client = ModelClient(env, '2.0-zeta1', None)
                 client.bootstrap()
                 mock.assert_called_with(

=== modified file 'jujupy/tests/test_version_client.py'
--- jujupy/tests/test_version_client.py	2017-04-05 04:20:57 +0000
+++ jujupy/tests/test_version_client.py	2017-04-05 04:20:58 +0000
@@ -381,7 +381,7 @@
     def test_bootstrap(self):
         env = JujuData('foo', {'type': 'bar', 'region': 'baz'})
         with observable_temp_file() as config_file:
-            with patch.object(ModelClientRC, 'juju') as mock:
+            with patch_juju_call(ModelClientRC) as mock:
                 client = ModelClientRC(env, '2.0-zeta1', None)
                 client.bootstrap()
                 mock.assert_called_with(
@@ -481,7 +481,7 @@
 
     def test_bootstrap_maas(self):
         env = SimpleEnvironment('maas')
-        with patch.object(EnvJujuClient1X, 'juju') as mock:
+        with patch_juju_call(EnvJujuClient1X) as mock:
             client = EnvJujuClient1X(env, None, None)
             with patch.object(client.env, 'maas', lambda: True):
                 client.bootstrap()
@@ -489,12 +489,12 @@
 
     def test_bootstrap_joyent(self):
         env = SimpleEnvironment('joyent')
-        with patch.object(EnvJujuClient1X, 'juju', autospec=True) as mock:
+        with patch_juju_call(EnvJujuClient1X) as mock:
             client = EnvJujuClient1X(env, None, None)
             with patch.object(client.env, 'joyent', lambda: True):
                 client.bootstrap()
         mock.assert_called_once_with(
-            client, 'bootstrap', ('--constraints', 'mem=2G cpu-cores=1'))
+                'bootstrap', ('--constraints', 'mem=2G cpu-cores=1'))
 
     def test_bootstrap(self):
         env = SimpleEnvironment('foo')

=== modified file 'jujupy/version_client.py'
--- jujupy/version_client.py	2017-04-05 04:20:57 +0000
+++ jujupy/version_client.py	2017-04-05 04:20:58 +0000
@@ -454,7 +454,8 @@
         """Bootstrap a controller."""
         self._check_bootstrap()
         args = self.get_bootstrap_args(upload_tools, bootstrap_series)
-        self.juju('bootstrap', args)
+        retvar, ct = self.juju('bootstrap', args)
+        ct.actual_completion()
 
     @contextmanager
     def bootstrap_async(self, upload_tools=False):

=== modified file 'tests/test_deploy_stack.py'
--- tests/test_deploy_stack.py	2017-04-05 04:20:57 +0000
+++ tests/test_deploy_stack.py	2017-04-05 04:20:58 +0000
@@ -70,7 +70,10 @@
     Machine,
     )
 
-from jujupy.client import CommandTime
+from jujupy.client import (
+    NoopCondition,
+    CommandTime,
+)
 from jujupy.configuration import (
     get_environments_path,
     get_jenv_path,