Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 1 | import os |
| 2 | import imp |
| 3 | import inspect |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 4 | import time |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 5 | import sys |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 6 | import traceback |
| 7 | import commands |
| 8 | import threading |
| 9 | import json |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 10 | import pdb |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 11 | import pprint |
| 12 | |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 13 | |
| 14 | from datetime import datetime |
| 15 | from collections import defaultdict |
| 16 | from core.models import * |
| 17 | from django.db.models import F, Q |
Scott Baker | c7ca655 | 2014-09-05 14:48:38 -0700 | [diff] [blame] | 18 | from django.db import connection |
Scott Baker | 8bbc77c | 2015-06-22 10:56:16 -0700 | [diff] [blame] | 19 | from django.db import reset_queries |
Tony Mack | 387a73f | 2013-09-18 07:59:14 -0400 | [diff] [blame] | 20 | #from openstack.manager import OpenStackManager |
| 21 | from openstack.driver import OpenStackDriver |
Scott Baker | f154cc2 | 2016-01-14 16:07:32 -0800 | [diff] [blame] | 22 | from xos.logger import Logger, logging, logger |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 23 | #from timeout import timeout |
Scott Baker | 76a840e | 2015-02-11 21:38:09 -0800 | [diff] [blame] | 24 | from xos.config import Config, XOS_DIR |
Sapan Bhatia | 003e84c | 2016-01-15 11:05:52 -0500 | [diff] [blame^] | 25 | from synchronizers.base.steps import * |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 26 | from syncstep import SyncStep |
Sapan Bhatia | 45cbbc3 | 2014-03-11 17:48:30 -0400 | [diff] [blame] | 27 | from toposort import toposort |
Sapan Bhatia | 003e84c | 2016-01-15 11:05:52 -0500 | [diff] [blame^] | 28 | from synchronizers.base.error_mapper import * |
Sapan Bhatia | cb6f8d6 | 2015-01-17 01:03:52 +0000 | [diff] [blame] | 29 | from openstack_observer.openstacksyncstep import OpenStackSyncStep |
Sapan Bhatia | 67ea0d7 | 2016-01-14 11:41:38 -0500 | [diff] [blame] | 30 | from synchronizers.base.steps.sync_object import SyncObject |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 31 | |
| 32 | # Load app models |
| 33 | |
Sapan Bhatia | 193dc34 | 2015-11-03 15:35:54 -0500 | [diff] [blame] | 34 | try: |
Sapan Bhatia | 891e018 | 2015-11-18 18:20:46 +0100 | [diff] [blame] | 35 | app_module_names = Config().observer_applist.split(',') |
Sapan Bhatia | 193dc34 | 2015-11-03 15:35:54 -0500 | [diff] [blame] | 36 | except AttributeError: |
| 37 | app_module_names = [] |
| 38 | |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 39 | if (type(app_module_names)!=list): |
| 40 | app_module_names=[app_module_names] |
| 41 | |
| 42 | app_modules = [] |
| 43 | |
| 44 | for m in app_module_names: |
| 45 | model_path = m+'.models' |
| 46 | module = __import__(model_path,fromlist=[m]) |
| 47 | app_modules.append(module) |
Sapan Bhatia | cb6f8d6 | 2015-01-17 01:03:52 +0000 | [diff] [blame] | 48 | |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 49 | |
Sapan Bhatia | 13c7f11 | 2013-09-02 14:19:35 -0400 | [diff] [blame] | 50 | debug_mode = False |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 51 | |
Sapan Bhatia | cb6f8d6 | 2015-01-17 01:03:52 +0000 | [diff] [blame] | 52 | class bcolors: |
| 53 | HEADER = '\033[95m' |
| 54 | OKBLUE = '\033[94m' |
| 55 | OKGREEN = '\033[92m' |
| 56 | WARNING = '\033[93m' |
| 57 | FAIL = '\033[91m' |
| 58 | ENDC = '\033[0m' |
| 59 | BOLD = '\033[1m' |
| 60 | UNDERLINE = '\033[4m' |
| 61 | |
Andy Bavier | 04111b7 | 2013-10-22 16:47:10 -0400 | [diff] [blame] | 62 | logger = Logger(level=logging.INFO) |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 63 | |
Sapan Bhatia | 13c7f11 | 2013-09-02 14:19:35 -0400 | [diff] [blame] | 64 | class StepNotReady(Exception): |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 65 | pass |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 66 | |
Scott Baker | 7771f41 | 2014-01-02 16:36:41 -0800 | [diff] [blame] | 67 | class NoOpDriver: |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 68 | def __init__(self): |
| 69 | self.enabled = True |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 70 | self.dependency_graph = None |
| 71 | |
| 72 | STEP_STATUS_WORKING=1 |
| 73 | STEP_STATUS_OK=2 |
| 74 | STEP_STATUS_KO=3 |
| 75 | |
| 76 | def invert_graph(g): |
| 77 | ig = {} |
| 78 | for k,v in g.items(): |
| 79 | for v0 in v: |
| 80 | try: |
| 81 | ig[v0].append(k) |
| 82 | except: |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 83 | ig[v0]=[k] |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 84 | return ig |
Scott Baker | 7771f41 | 2014-01-02 16:36:41 -0800 | [diff] [blame] | 85 | |
Scott Baker | 286a78f | 2015-02-18 16:13:48 -0800 | [diff] [blame] | 86 | class XOSObserver: |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 87 | sync_steps = [] |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 88 | |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 89 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 90 | def __init__(self): |
| 91 | # The Condition object that gets signalled by Feefie events |
| 92 | self.step_lookup = {} |
| 93 | self.load_sync_step_modules() |
| 94 | self.load_sync_steps() |
| 95 | self.event_cond = threading.Condition() |
Scott Baker | 7771f41 | 2014-01-02 16:36:41 -0800 | [diff] [blame] | 96 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 97 | self.driver_kind = getattr(Config(), "observer_driver", "openstack") |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 98 | self.observer_name = getattr(Config(), "observer_name", "") |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 99 | if self.driver_kind=="openstack": |
| 100 | self.driver = OpenStackDriver() |
| 101 | else: |
| 102 | self.driver = NoOpDriver() |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 103 | |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 104 | def consolePrint(self, what): |
| 105 | if getattr(Config(), "observer_console_print", True): |
| 106 | print what |
| 107 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 108 | def wait_for_event(self, timeout): |
| 109 | self.event_cond.acquire() |
| 110 | self.event_cond.wait(timeout) |
| 111 | self.event_cond.release() |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 112 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 113 | def wake_up(self): |
| 114 | logger.info('Wake up routine called. Event cond %r'%self.event_cond) |
| 115 | self.event_cond.acquire() |
| 116 | self.event_cond.notify() |
| 117 | self.event_cond.release() |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 118 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 119 | def load_sync_step_modules(self, step_dir=None): |
| 120 | if step_dir is None: |
| 121 | if hasattr(Config(), "observer_steps_dir"): |
| 122 | step_dir = Config().observer_steps_dir |
| 123 | else: |
Scott Baker | d9e0123 | 2015-02-04 16:59:45 -0800 | [diff] [blame] | 124 | step_dir = XOS_DIR + "/observer/steps" |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 125 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 126 | for fn in os.listdir(step_dir): |
| 127 | pathname = os.path.join(step_dir,fn) |
| 128 | if os.path.isfile(pathname) and fn.endswith(".py") and (fn!="__init__.py"): |
| 129 | module = imp.load_source(fn[:-3],pathname) |
| 130 | for classname in dir(module): |
| 131 | c = getattr(module, classname, None) |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 132 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 133 | # make sure 'c' is a descendent of SyncStep and has a |
| 134 | # provides field (this eliminates the abstract base classes |
| 135 | # since they don't have a provides) |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 136 | |
Sapan Bhatia | 43c7f8c | 2015-01-17 01:04:10 +0000 | [diff] [blame] | 137 | if inspect.isclass(c) and (issubclass(c, SyncStep) or issubclass(c,OpenStackSyncStep)) and hasattr(c,"provides") and (c not in self.sync_steps): |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 138 | self.sync_steps.append(c) |
| 139 | logger.info('loaded sync steps: %s' % ",".join([x.__name__ for x in self.sync_steps])) |
Scott Baker | 45fb7a1 | 2013-12-31 00:56:19 -0800 | [diff] [blame] | 140 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 141 | def load_sync_steps(self): |
| 142 | dep_path = Config().observer_dependency_graph |
| 143 | logger.info('Loading model dependency graph from %s' % dep_path) |
| 144 | try: |
| 145 | # This contains dependencies between records, not sync steps |
| 146 | self.model_dependency_graph = json.loads(open(dep_path).read()) |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 147 | for left,lst in self.model_dependency_graph.items(): |
| 148 | new_lst = [] |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 149 | for k in lst: |
| 150 | try: |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 151 | tup = (k,k.lower()) |
| 152 | new_lst.append(tup) |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 153 | deps = self.model_dependency_graph[k] |
| 154 | except: |
| 155 | self.model_dependency_graph[k] = [] |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 156 | |
| 157 | self.model_dependency_graph[left] = new_lst |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 158 | except Exception,e: |
| 159 | raise e |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 160 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 161 | try: |
| 162 | backend_path = Config().observer_pl_dependency_graph |
| 163 | logger.info('Loading backend dependency graph from %s' % backend_path) |
| 164 | # This contains dependencies between backend records |
| 165 | self.backend_dependency_graph = json.loads(open(backend_path).read()) |
Sapan Bhatia | 0926e65 | 2015-01-29 20:51:13 +0000 | [diff] [blame] | 166 | for k,v in self.backend_dependency_graph.items(): |
| 167 | try: |
| 168 | self.model_dependency_graph[k].extend(v) |
| 169 | except KeyError: |
| 170 | self.model_dependency_graphp[k] = v |
| 171 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 172 | except Exception,e: |
| 173 | logger.info('Backend dependency graph not loaded') |
| 174 | # We can work without a backend graph |
| 175 | self.backend_dependency_graph = {} |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 176 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 177 | provides_dict = {} |
| 178 | for s in self.sync_steps: |
| 179 | self.step_lookup[s.__name__] = s |
| 180 | for m in s.provides: |
| 181 | try: |
| 182 | provides_dict[m.__name__].append(s.__name__) |
| 183 | except KeyError: |
| 184 | provides_dict[m.__name__]=[s.__name__] |
Sapan Bhatia | 04c94ad | 2013-09-02 18:00:28 -0400 | [diff] [blame] | 185 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 186 | step_graph = {} |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 187 | phantom_steps = [] |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 188 | for k,v in self.model_dependency_graph.items(): |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 189 | try: |
| 190 | for source in provides_dict[k]: |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 191 | if (not v): |
| 192 | step_graph[source] = [] |
| 193 | |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 194 | for m,_ in v: |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 195 | try: |
| 196 | for dest in provides_dict[m]: |
| 197 | # no deps, pass |
| 198 | try: |
| 199 | if (dest not in step_graph[source]): |
| 200 | step_graph[source].append(dest) |
| 201 | except: |
| 202 | step_graph[source]=[dest] |
| 203 | except KeyError: |
Sapan Bhatia | 3bf42b8 | 2015-09-10 11:07:32 -0400 | [diff] [blame] | 204 | if (not provides_dict.has_key(m)): |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 205 | try: |
| 206 | step_graph[source]+=['#%s'%m] |
| 207 | except: |
| 208 | step_graph[source]=['#%s'%m] |
| 209 | |
| 210 | phantom_steps+=['#%s'%m] |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 211 | pass |
| 212 | |
| 213 | except KeyError: |
| 214 | pass |
| 215 | # no dependencies, pass |
| 216 | |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 217 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 218 | self.dependency_graph = step_graph |
| 219 | self.deletion_dependency_graph = invert_graph(step_graph) |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 220 | |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 221 | pp = pprint.PrettyPrinter(indent=4) |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 222 | logger.info(pp.pformat(step_graph)) |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 223 | self.ordered_steps = toposort(self.dependency_graph, phantom_steps+map(lambda s:s.__name__,self.sync_steps)) |
| 224 | self.ordered_steps = [i for i in self.ordered_steps if i!='SyncObject'] |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 225 | |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 226 | logger.info("Order of steps=%s" % self.ordered_steps) |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 227 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 228 | self.load_run_times() |
| 229 | |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 230 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 231 | def check_duration(self, step, duration): |
| 232 | try: |
| 233 | if (duration > step.deadline): |
| 234 | logger.info('Sync step %s missed deadline, took %.2f seconds'%(step.name,duration)) |
| 235 | except AttributeError: |
| 236 | # S doesn't have a deadline |
| 237 | pass |
Sapan Bhatia | 24836f1 | 2013-08-27 10:16:05 -0400 | [diff] [blame] | 238 | |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 239 | def update_run_time(self, step, deletion): |
| 240 | if (not deletion): |
| 241 | self.last_run_times[step.__name__]=time.time() |
| 242 | else: |
| 243 | self.last_deletion_run_times[step.__name__]=time.time() |
Sapan Bhatia | 13c7f11 | 2013-09-02 14:19:35 -0400 | [diff] [blame] | 244 | |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 245 | |
| 246 | def check_schedule(self, step, deletion): |
| 247 | last_run_times = self.last_run_times if not deletion else self.last_deletion_run_times |
| 248 | |
| 249 | time_since_last_run = time.time() - last_run_times.get(step.__name__, 0) |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 250 | try: |
| 251 | if (time_since_last_run < step.requested_interval): |
| 252 | raise StepNotReady |
| 253 | except AttributeError: |
| 254 | logger.info('Step %s does not have requested_interval set'%step.__name__) |
| 255 | raise StepNotReady |
| 256 | |
| 257 | def load_run_times(self): |
| 258 | try: |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 259 | jrun_times = open('/tmp/%sobserver_run_times'%self.observer_name).read() |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 260 | self.last_run_times = json.loads(jrun_times) |
| 261 | except: |
| 262 | self.last_run_times={} |
| 263 | for e in self.ordered_steps: |
| 264 | self.last_run_times[e]=0 |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 265 | try: |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 266 | jrun_times = open('/tmp/%sobserver_deletion_run_times'%self.observer_name).read() |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 267 | self.last_deletion_run_times = json.loads(jrun_times) |
| 268 | except: |
| 269 | self.last_deletion_run_times={} |
| 270 | for e in self.ordered_steps: |
| 271 | self.last_deletion_run_times[e]=0 |
| 272 | |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 273 | def lookup_step_class(self,s): |
| 274 | if ('#' in s): |
| 275 | return SyncObject |
| 276 | else: |
| 277 | step = self.step_lookup[s] |
| 278 | return step |
| 279 | |
Sapan Bhatia | 3bf42b8 | 2015-09-10 11:07:32 -0400 | [diff] [blame] | 280 | def lookup_step(self,s): |
| 281 | if ('#' in s): |
| 282 | objname = s[1:] |
| 283 | so = SyncObject() |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 284 | |
| 285 | try: |
| 286 | obj = globals()[objname] |
| 287 | except: |
| 288 | for m in app_modules: |
| 289 | if (hasattr(m,objname)): |
| 290 | obj = getattr(m,objname) |
| 291 | |
| 292 | so.provides=[obj] |
| 293 | so.observes=[obj] |
Sapan Bhatia | 3bf42b8 | 2015-09-10 11:07:32 -0400 | [diff] [blame] | 294 | step = so |
| 295 | else: |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 296 | step_class = self.step_lookup[s] |
| 297 | step = step_class(driver=self.driver,error_map=self.error_mapper) |
Sapan Bhatia | 3bf42b8 | 2015-09-10 11:07:32 -0400 | [diff] [blame] | 298 | return step |
| 299 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 300 | def save_run_times(self): |
| 301 | run_times = json.dumps(self.last_run_times) |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 302 | open('/tmp/%sobserver_run_times'%self.observer_name,'w').write(run_times) |
Sapan Bhatia | 36938ca | 2013-09-02 14:35:24 -0400 | [diff] [blame] | 303 | |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 304 | deletion_run_times = json.dumps(self.last_deletion_run_times) |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 305 | open('/tmp/%sobserver_deletion_run_times'%self.observer_name,'w').write(deletion_run_times) |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 306 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 307 | def check_class_dependency(self, step, failed_steps): |
| 308 | step.dependenices = [] |
| 309 | for obj in step.provides: |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 310 | lst = self.model_dependency_graph.get(obj.__name__, []) |
| 311 | nlst = map(lambda(a,b):b,lst) |
| 312 | step.dependenices.extend(nlst) |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 313 | for failed_step in failed_steps: |
| 314 | if (failed_step in step.dependencies): |
| 315 | raise StepNotReady |
| 316 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 317 | def sync(self, S, deletion): |
Scott Baker | c7ca655 | 2014-09-05 14:48:38 -0700 | [diff] [blame] | 318 | try: |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 319 | step = self.lookup_step_class(S) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 320 | start_time=time.time() |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 321 | |
Scott Baker | c9e1862 | 2015-03-09 16:25:11 -0700 | [diff] [blame] | 322 | logger.info("Starting to work on step %s, deletion=%s" % (step.__name__, str(deletion))) |
Scott Baker | f0db81c | 2015-03-31 15:06:55 -0700 | [diff] [blame] | 323 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 324 | dependency_graph = self.dependency_graph if not deletion else self.deletion_dependency_graph |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 325 | step_conditions = self.step_conditions# if not deletion else self.deletion_step_conditions |
| 326 | step_status = self.step_status# if not deletion else self.deletion_step_status |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 327 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 328 | # Wait for step dependencies to be met |
| 329 | try: |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 330 | deps = dependency_graph[S] |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 331 | has_deps = True |
| 332 | except KeyError: |
| 333 | has_deps = False |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 334 | |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 335 | go = True |
Sapan Bhatia | 475c597 | 2014-11-05 10:32:41 -0500 | [diff] [blame] | 336 | |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 337 | failed_dep = None |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 338 | if (has_deps): |
| 339 | for d in deps: |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 340 | if d==step.__name__: |
| 341 | logger.info(" step %s self-wait skipped" % step.__name__) |
Sapan Bhatia | 475c597 | 2014-11-05 10:32:41 -0500 | [diff] [blame] | 342 | go = True |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 343 | continue |
| 344 | |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 345 | cond = step_conditions[d] |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 346 | cond.acquire() |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 347 | if (step_status[d] is STEP_STATUS_WORKING): |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 348 | logger.info(" step %s wait on dep %s" % (step.__name__, d)) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 349 | cond.wait() |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 350 | elif step_status[d] == STEP_STATUS_OK: |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 351 | go = True |
| 352 | else: |
| 353 | go = False |
| 354 | failed_dep = d |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 355 | cond.release() |
Sapan Bhatia | 6b6c218 | 2015-01-27 03:58:11 +0000 | [diff] [blame] | 356 | if (not go): |
| 357 | break |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 358 | else: |
| 359 | go = True |
| 360 | |
| 361 | if (not go): |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 362 | self.consolePrint(bcolors.FAIL + "Step %r skipped on %r" % (step,failed_dep) + bcolors.ENDC) |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 363 | # SMBAKER: sync_step was not defined here, so I changed |
| 364 | # this from 'sync_step' to 'step'. Verify. |
| 365 | self.failed_steps.append(step) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 366 | my_status = STEP_STATUS_KO |
| 367 | else: |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 368 | sync_step = self.lookup_step(S) |
Sapan Bhatia | 709bebd | 2015-02-08 06:35:36 +0000 | [diff] [blame] | 369 | sync_step. __name__= step.__name__ |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 370 | sync_step.dependencies = [] |
| 371 | try: |
| 372 | mlist = sync_step.provides |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 373 | |
Sapan Bhatia | f51edea | 2015-11-03 13:53:11 -0500 | [diff] [blame] | 374 | try: |
| 375 | for m in mlist: |
| 376 | lst = self.model_dependency_graph[m.__name__] |
| 377 | nlst = map(lambda(a,b):b,lst) |
| 378 | sync_step.dependencies.extend(nlst) |
| 379 | except Exception,e: |
| 380 | raise e |
| 381 | |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 382 | except KeyError: |
| 383 | pass |
| 384 | sync_step.debug_mode = debug_mode |
| 385 | |
| 386 | should_run = False |
| 387 | try: |
| 388 | # Various checks that decide whether |
| 389 | # this step runs or not |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 390 | self.check_class_dependency(sync_step, self.failed_steps) # dont run Slices if Sites failed |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 391 | self.check_schedule(sync_step, deletion) # dont run sync_network_routes if time since last run < 1 hour |
| 392 | should_run = True |
| 393 | except StepNotReady: |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 394 | logger.info('Step not ready: %s'%sync_step.__name__) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 395 | self.failed_steps.append(sync_step) |
| 396 | my_status = STEP_STATUS_KO |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 397 | except Exception,e: |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 398 | logger.error('%r' % e) |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 399 | logger.log_exc("sync step failed: %r. Deletion: %r"%(sync_step,deletion)) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 400 | self.failed_steps.append(sync_step) |
| 401 | my_status = STEP_STATUS_KO |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 402 | |
| 403 | if (should_run): |
| 404 | try: |
| 405 | duration=time.time() - start_time |
| 406 | |
Scott Baker | 1d45f66 | 2015-08-21 16:41:47 -0700 | [diff] [blame] | 407 | logger.info('Executing step %s, deletion=%s' % (sync_step.__name__, deletion)) |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 408 | |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 409 | self.consolePrint(bcolors.OKBLUE + "Executing step %s" % sync_step.__name__ + bcolors.ENDC) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 410 | failed_objects = sync_step(failed=list(self.failed_step_objects), deletion=deletion) |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 411 | |
| 412 | self.check_duration(sync_step, duration) |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 413 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 414 | if failed_objects: |
| 415 | self.failed_step_objects.update(failed_objects) |
| 416 | |
Scott Baker | 1d45f66 | 2015-08-21 16:41:47 -0700 | [diff] [blame] | 417 | logger.info("Step %r succeeded" % sync_step.__name__) |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 418 | self.consolePrint(bcolors.OKGREEN + "Step %r succeeded" % sync_step.__name__ + bcolors.ENDC) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 419 | my_status = STEP_STATUS_OK |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 420 | self.update_run_time(sync_step,deletion) |
| 421 | except Exception,e: |
Scott Baker | f4da790 | 2015-09-17 21:37:44 -0700 | [diff] [blame] | 422 | self.consolePrint(bcolors.FAIL + "Model step %r failed" % (sync_step.__name__) + bcolors.ENDC) |
Scott Baker | 1d45f66 | 2015-08-21 16:41:47 -0700 | [diff] [blame] | 423 | logger.error('Model step %r failed. This seems like a misconfiguration or bug: %r. This error will not be relayed to the user!' % (sync_step.__name__, e)) |
Sapan Bhatia | 51f4893 | 2014-08-25 04:17:12 -0400 | [diff] [blame] | 424 | logger.log_exc(e) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 425 | self.failed_steps.append(S) |
| 426 | my_status = STEP_STATUS_KO |
| 427 | else: |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 428 | logger.info("Step %r succeeded due to non-run" % step) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 429 | my_status = STEP_STATUS_OK |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 430 | |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 431 | try: |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 432 | my_cond = step_conditions[S] |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 433 | my_cond.acquire() |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 434 | step_status[S]=my_status |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 435 | my_cond.notify_all() |
| 436 | my_cond.release() |
| 437 | except KeyError,e: |
Scott Baker | adc7317 | 2014-09-04 10:36:51 -0700 | [diff] [blame] | 438 | logger.info('Step %r is a leaf' % step) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 439 | pass |
Scott Baker | c7ca655 | 2014-09-05 14:48:38 -0700 | [diff] [blame] | 440 | finally: |
Scott Baker | 8bbc77c | 2015-06-22 10:56:16 -0700 | [diff] [blame] | 441 | try: |
| 442 | reset_queries() |
| 443 | except: |
| 444 | # this shouldn't happen, but in case it does, catch it... |
| 445 | logger.log_exc("exception in reset_queries") |
| 446 | |
Scott Baker | c7ca655 | 2014-09-05 14:48:38 -0700 | [diff] [blame] | 447 | connection.close() |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 448 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 449 | def run(self): |
| 450 | if not self.driver.enabled: |
| 451 | return |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 452 | |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 453 | if (self.driver_kind=="openstack") and (not self.driver.has_openstack): |
| 454 | return |
| 455 | |
| 456 | while True: |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 457 | logger.info('Waiting for event') |
| 458 | self.wait_for_event(timeout=5) |
| 459 | logger.info('Observer woke up') |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 460 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 461 | self.run_once() |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 462 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 463 | def run_once(self): |
| 464 | try: |
| 465 | loop_start = time.time() |
| 466 | error_map_file = getattr(Config(), "error_map_path", XOS_DIR + "/error_map.txt") |
| 467 | self.error_mapper = ErrorMapper(error_map_file) |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 468 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 469 | # Two passes. One for sync, the other for deletion. |
| 470 | for deletion in [False,True]: |
| 471 | # Set of individual objects within steps that failed |
| 472 | self.failed_step_objects = set() |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 473 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 474 | # Set up conditions and step status |
| 475 | # This is needed for steps to run in parallel |
| 476 | # while obeying dependencies. |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 477 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 478 | providers = set() |
| 479 | dependency_graph = self.dependency_graph if not deletion else self.deletion_dependency_graph |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 480 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 481 | for v in dependency_graph.values(): |
| 482 | if (v): |
| 483 | providers.update(v) |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 484 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 485 | self.step_conditions = {} |
| 486 | self.step_status = {} |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 487 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 488 | for p in list(providers): |
| 489 | self.step_conditions[p] = threading.Condition() |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 490 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 491 | self.step_status[p] = STEP_STATUS_WORKING |
Sapan Bhatia | 47944b3 | 2015-03-04 10:21:06 -0500 | [diff] [blame] | 492 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 493 | self.failed_steps = [] |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 494 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 495 | threads = [] |
| 496 | logger.info('Deletion=%r...'%deletion) |
| 497 | schedule = self.ordered_steps if not deletion else reversed(self.ordered_steps) |
Sapan Bhatia | ab202a6 | 2014-09-03 11:30:21 -0400 | [diff] [blame] | 498 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 499 | for S in schedule: |
| 500 | thread = threading.Thread(target=self.sync, args=(S, deletion)) |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 501 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 502 | logger.info('Deletion=%r...'%deletion) |
| 503 | threads.append(thread) |
Sapan Bhatia | f73664b | 2014-04-28 13:07:18 -0400 | [diff] [blame] | 504 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 505 | # Start threads |
| 506 | for t in threads: |
| 507 | t.start() |
Scott Baker | 8bbc77c | 2015-06-22 10:56:16 -0700 | [diff] [blame] | 508 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 509 | # another spot to clean up debug state |
| 510 | try: |
| 511 | reset_queries() |
| 512 | except: |
| 513 | # this shouldn't happen, but in case it does, catch it... |
| 514 | logger.log_exc("exception in reset_queries") |
Sapan Bhatia | 285decb | 2014-04-30 00:31:44 -0400 | [diff] [blame] | 515 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 516 | # Wait for all threads to finish before continuing with the run loop |
| 517 | for t in threads: |
| 518 | t.join() |
Scott Baker | 8bbc77c | 2015-06-22 10:56:16 -0700 | [diff] [blame] | 519 | |
Scott Baker | e611f0a | 2015-09-17 16:58:36 -0700 | [diff] [blame] | 520 | self.save_run_times() |
| 521 | |
| 522 | loop_end = time.time() |
| 523 | open('/tmp/%sobserver_last_run'%self.observer_name,'w').write(json.dumps({'last_run': loop_end, 'last_duration':loop_end - loop_start})) |
| 524 | except Exception, e: |
| 525 | logger.error('Core error. This seems like a misconfiguration or bug: %r. This error will not be relayed to the user!' % e) |
| 526 | logger.log_exc("Exception in observer run loop") |
| 527 | traceback.print_exc() |