Fix ordering bug procesing updates.

Occasionally, out of order notifications received from a resize operation
would incorrectly produce a verification error, because the launched_at time
is changed several times during the operation.
Fix this to keep the last chronological launched_at time in the operation,
not the last received.

Also fix nondeterministic multiprocessing bug that was occasionally causing
unittests to hang.

Change-Id: Iba8b0bbd0cb8b2b063335ca9ab0ad95cf127087a

stacktach/views.py

@@ -5,9 +5,9 @@
 # to you under the Apache License, Version 2.0 (the
 # "License"); you may not use this file except in compliance
 # with the License.  You may obtain a copy of the License at
-# 
+#
 #   http://www.apache.org/licenses/LICENSE-2.0
-# 
+#
 # Unless required by applicable law or agreed to in writing,
 # software distributed under the License is distributed on an
 # "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
@@ -239,7 +239,9 @@ def _process_usage_for_updates(raw, notification):
                      INSTANCE_EVENT['resize_finish_end'],
                      INSTANCE_EVENT['resize_revert_end'],
                      INSTANCE_EVENT['rescue_end']]:
-        usage.launched_at = utils.str_time_to_unix(notification.launched_at)
+        new_launched_at = utils.str_time_to_unix(notification.launched_at)
+        if not usage.launched_at or usage.launched_at < new_launched_at:
+            usage.launched_at = new_launched_at
         if usage.instance_type_id is None:
             usage.instance_type_id = notification.instance_type_id
         if usage.instance_flavor_id is None:

tests/unit/test_base_verifier.py

@@ -43,7 +43,7 @@ class BaseVerifierTestCase(StacktachBaseTestCase):
     def test_should_create_verifier_with_reconciler(self):
         config = make_verifier_config(False)
         rec = self.mox.CreateMockAnything()
-        verifier = base_verifier.Verifier(config, pool=None, reconciler=rec)
+        verifier = base_verifier.Verifier(config, pool=self.pool, reconciler=rec)
         self.assertEqual(verifier.reconciler, rec)
 
     def test_clean_results_full(self):

tests/unit/test_stacktach.py

@@ -5,9 +5,9 @@
 # to you under the Apache License, Version 2.0 (the
 # "License"); you may not use this file except in compliance
 # with the License.  You may obtain a copy of the License at
-# 
+#
 #   http://www.apache.org/licenses/LICENSE-2.0
-# 
+#
 # Unless required by applicable law or agreed to in writing,
 # software distributed under the License is distributed on an
 # "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY
@@ -33,6 +33,8 @@ from utils import REQUEST_ID_1
 from utils import TENANT_ID_1
 from utils import INSTANCE_TYPE_ID_1
 from utils import DUMMY_TIME
+from utils import EARLIER_DUMMY_TIME
+from utils import LATER_DUMMY_TIME
 from utils import INSTANCE_TYPE_ID_2
 from stacktach import stacklog, models
 from stacktach import notification
@@ -681,6 +683,63 @@ class StacktachUsageParsingTestCase(StacktachBaseTestCase):
 
         self.assertEqual(usage.instance_type_id, INSTANCE_TYPE_ID_1)
         self.assertEqual(usage.instance_flavor_id, INSTANCE_FLAVOR_ID_1)
+        self.assertEqual(usage.launched_at, utils.decimal_utc(DUMMY_TIME))
+        self.assertEquals(usage.tenant, TENANT_ID_1)
+        self.assertEquals(usage.os_architecture, OS_ARCH_1)
+        self.assertEquals(usage.os_version, OS_VERSION_1)
+        self.assertEquals(usage.os_distro, OS_DISTRO_1)
+        self.assertEquals(usage.rax_options, RAX_OPTIONS_1)
+
+        self.mox.VerifyAll()
+
+    def test_process_usage_for_updates_finish_resize_end_earlier_update(self):
+        notification = self._create_mock_notification()
+        raw = self.mox.CreateMockAnything()
+        raw.event = 'compute.instance.finish_resize.end'
+
+        usage = self.mox.CreateMockAnything()
+        usage.launched_at = utils.decimal_utc(EARLIER_DUMMY_TIME)
+        usage.instance_type_id = INSTANCE_TYPE_ID_2
+        usage.instance_flavor_id = INSTANCE_FLAVOR_ID_2
+        views.STACKDB.get_or_create_instance_usage(instance=INSTANCE_ID_1,
+                                                   request_id=REQUEST_ID_1) \
+            .AndReturn((usage, True))
+        views.STACKDB.save(usage)
+        self.mox.ReplayAll()
+
+        views._process_usage_for_updates(raw, notification)
+
+        self.assertEqual(usage.instance_type_id, INSTANCE_TYPE_ID_1)
+        self.assertEqual(usage.instance_flavor_id, INSTANCE_FLAVOR_ID_1)
+        self.assertEqual(usage.launched_at, utils.decimal_utc(DUMMY_TIME))
+        self.assertEquals(usage.tenant, TENANT_ID_1)
+        self.assertEquals(usage.os_architecture, OS_ARCH_1)
+        self.assertEquals(usage.os_version, OS_VERSION_1)
+        self.assertEquals(usage.os_distro, OS_DISTRO_1)
+        self.assertEquals(usage.rax_options, RAX_OPTIONS_1)
+
+        self.mox.VerifyAll()
+
+    def test_process_usage_for_updates_finish_resize_end_later_update(self):
+        notification = self._create_mock_notification()
+        raw = self.mox.CreateMockAnything()
+        raw.event = 'compute.instance.finish_resize.end'
+
+        usage = self.mox.CreateMockAnything()
+        usage.launched_at = utils.decimal_utc(LATER_DUMMY_TIME)
+        usage.instance_type_id = INSTANCE_TYPE_ID_2
+        usage.instance_flavor_id = INSTANCE_FLAVOR_ID_2
+        views.STACKDB.get_or_create_instance_usage(instance=INSTANCE_ID_1,
+                                                   request_id=REQUEST_ID_1) \
+            .AndReturn((usage, True))
+        views.STACKDB.save(usage)
+        self.mox.ReplayAll()
+
+        views._process_usage_for_updates(raw, notification)
+
+        self.assertEqual(usage.instance_type_id, INSTANCE_TYPE_ID_1)
+        self.assertEqual(usage.instance_flavor_id, INSTANCE_FLAVOR_ID_1)
+        self.assertEqual(usage.launched_at, utils.decimal_utc(LATER_DUMMY_TIME))
         self.assertEquals(usage.tenant, TENANT_ID_1)
         self.assertEquals(usage.os_architecture, OS_ARCH_1)
         self.assertEquals(usage.os_version, OS_VERSION_1)

tests/unit/utils.py

@@ -33,7 +33,10 @@ INSTANCE_FLAVOR_ID_2 = "performance2-120"
 INSTANCE_TYPE_ID_1 = "12345"
 INSTANCE_TYPE_ID_2 = '54321'
 
+one_hr = datetime.timedelta(hours=1)
 DUMMY_TIME = datetime.datetime.utcnow()
+EARLIER_DUMMY_TIME = DUMMY_TIME - one_hr
+LATER_DUMMY_TIME = DUMMY_TIME + one_hr
 DECIMAL_DUMMY_TIME = dt.dt_to_decimal(DUMMY_TIME)
 
 MESSAGE_ID_1 = "4444dddd-29a2-43f2-9ba1-ccb3e53ab6c8"