X-Git-Url: https://wannabe.guru.org/gitweb/?a=blobdiff_plain;f=executors.py;h=c11bd546cc3b1b0afcefff8c3215aab2707db147;hb=ed8fa2b10b0177b15b7423263bdd390efde2f0c8;hp=b16ad92d80a624c466b6d54c5830d5a2f00c8789;hpb=2c54bfde335f3631f045a871c540c9d63c5bb081;p=python_utils.git diff --git a/executors.py b/executors.py index b16ad92..c11bd54 100644 --- a/executors.py +++ b/executors.py @@ -22,8 +22,8 @@ from overrides import overrides from ansi import bg, fg, underline, reset import argparse_utils import config -from exec_utils import run_silently, cmd_in_background from decorator_utils import singleton +from exec_utils import run_silently, cmd_in_background, cmd_with_timeout import histogram as hist logger = logging.getLogger(__name__) @@ -197,6 +197,11 @@ class ProcessExecutor(BaseExecutor): return state +class RemoteExecutorException(Exception): + """Thrown when a bundle cannot be executed despite several retries.""" + pass + + @dataclass class RemoteWorkerRecord: username: str @@ -225,14 +230,42 @@ class BundleDetails: pid: int start_ts: float end_ts: float - too_slow: bool - super_slow: bool + slower_than_local_p95: bool + slower_than_global_p95: bool src_bundle: BundleDetails is_cancelled: threading.Event was_cancelled: bool backup_bundles: Optional[List[BundleDetails]] failure_count: int + def __repr__(self): + uuid = self.uuid + if uuid[-9:-2] == '_backup': + uuid = uuid[:-9] + suffix = f'{uuid[-6:]}_b{self.uuid[-1:]}' + else: + suffix = uuid[-6:] + + colorz = [ + fg('violet red'), + fg('red'), + fg('orange'), + fg('peach orange'), + fg('yellow'), + fg('marigold yellow'), + fg('green yellow'), + fg('tea green'), + fg('cornflower blue'), + fg('turquoise blue'), + fg('tropical blue'), + fg('lavender purple'), + fg('medium purple'), + ] + c = colorz[int(uuid[-2:], 16) % len(colorz)] + fname = self.fname if self.fname is not None else 'nofname' + machine = self.machine if self.machine is not None else 'nomachine' + return f'{c}{suffix}/{fname}/{machine}{reset()}' + class RemoteExecutorStatus: def __init__(self, total_worker_count: int) -> None: @@ -375,32 +408,30 @@ class RemoteExecutorStatus: bundle_uuid, None ) - pid = str(details.pid) if details is not None else "TBD" + pid = str(details.pid) if (details and details.pid != 0) else "TBD" if self.start_per_bundle[bundle_uuid] is not None: sec = ts - self.start_per_bundle[bundle_uuid] - ret += f' (pid={pid}): {bundle_uuid} for {sec:.1f}s so far ' + ret += f' (pid={pid}): {details} for {sec:.1f}s so far ' else: - ret += f' {bundle_uuid} setting up / copying data...' + ret += f' {details} setting up / copying data...' sec = 0.0 if qworker is not None: if sec > qworker[1]: ret += f'{bg("red")}>💻p95{reset()} ' - elif sec > qworker[0]: - ret += f'{fg("red")}>💻p50{reset()} ' - if qall is not None: - if sec > qall[1] * 1.5: - ret += f'{bg("red")}!!!{reset()}' if details is not None: - logger.debug(f'Flagging {details.uuid} for another backup') - details.super_slow = True - elif sec > qall[1]: + details.slower_than_local_p95 = True + else: + if details is not None: + details.slower_than_local_p95 = False + + if qall is not None: + if sec > qall[1]: ret += f'{bg("red")}>∀p95{reset()} ' if details is not None: - logger.debug(f'Flagging {details.uuid} for a backup') - details.too_slow = True - elif sec > qall[0]: - ret += f'{fg("red")}>∀p50{reset()}' + details.slower_than_global_p95 = True + else: + details.slower_than_global_p95 = False ret += '\n' return ret @@ -418,7 +449,6 @@ class RemoteExecutorStatus: class RemoteWorkerSelectionPolicy(ABC): def register_worker_pool(self, workers): - random.seed() self.workers = workers @abstractmethod @@ -434,12 +464,14 @@ class RemoteWorkerSelectionPolicy(ABC): class WeightedRandomRemoteWorkerSelectionPolicy(RemoteWorkerSelectionPolicy): + @overrides def is_worker_available(self) -> bool: for worker in self.workers: if worker.count > 0: return True return False + @overrides def acquire_worker( self, machine_to_avoid = None @@ -466,12 +498,14 @@ class RoundRobinRemoteWorkerSelectionPolicy(RemoteWorkerSelectionPolicy): def __init__(self) -> None: self.index = 0 + @overrides def is_worker_available(self) -> bool: for worker in self.workers: if worker.count > 0: return True return False + @overrides def acquire_worker( self, machine_to_avoid: str = None @@ -508,7 +542,7 @@ class RemoteExecutor(BaseExecutor): if self.worker_count <= 0: msg = f"We need somewhere to schedule work; count was {self.worker_count}" logger.critical(msg) - raise Exception(msg) + raise RemoteExecutorException(msg) self.policy.register_worker_pool(self.workers) self.cv = threading.Condition() logger.debug(f'Creating {self.worker_count} local threads, one per remote worker.') @@ -518,9 +552,8 @@ class RemoteExecutor(BaseExecutor): ) self.status = RemoteExecutorStatus(self.worker_count) self.total_bundles_submitted = 0 - logger.debug( - f'Creating remote processpool with {self.worker_count} remote worker threads.' - ) + self.backup_lock = threading.Lock() + self.last_backup = None def is_worker_available(self) -> bool: return self.policy.is_worker_available() @@ -556,39 +589,86 @@ class RemoteExecutor(BaseExecutor): # Regular progress report self.status.periodic_dump(self.total_bundles_submitted) - # Look for bundles to reschedule + # Look for bundles to reschedule. num_done = len(self.status.finished_bundle_timings) - if num_done > 7 or (num_done > 5 and self.is_worker_available()): - for worker, bundle_uuids in self.status.in_flight_bundles_by_worker.items(): - for uuid in bundle_uuids: - bundle = self.status.bundle_details_by_uuid.get(uuid, None) - if ( - bundle is not None and - bundle.too_slow and - bundle.src_bundle is None and - config.config['executors_schedule_remote_backups'] - ): - self.consider_backup_for_bundle(bundle) - - def consider_backup_for_bundle(self, bundle: BundleDetails) -> None: - assert self.status.lock.locked() - if ( - bundle.too_slow - and len(bundle.backup_bundles) == 0 # one backup per - ): - msg = f"*** Rescheduling {bundle.pid}/{bundle.uuid} ***" - logger.debug(msg) - self.schedule_backup_for_bundle(bundle) - return - elif ( - bundle.super_slow - and len(bundle.backup_bundles) < 2 # two backups in dire situations - and self.status.total_idle() > 4 - ): - msg = f"*** Rescheduling {bundle.pid}/{bundle.uuid} ***" - logger.debug(msg) - self.schedule_backup_for_bundle(bundle) - return + num_idle_workers = self.worker_count - self.task_count + now = time.time() + if ( + config.config['executors_schedule_remote_backups'] + and num_done > 2 + and num_idle_workers > 1 + and (self.last_backup is None or (now - self.last_backup > 1.0)) + and self.backup_lock.acquire(blocking=False) + ): + try: + assert self.backup_lock.locked() + + bundle_to_backup = None + best_score = None + for worker, bundle_uuids in self.status.in_flight_bundles_by_worker.items(): + # Prefer to schedule backups of bundles on slower machines. + base_score = 0 + for record in self.workers: + if worker.machine == record.machine: + base_score = float(record.weight) + base_score = 1.0 / base_score + base_score *= 200.0 + base_score = int(base_score) + break + + for uuid in bundle_uuids: + bundle = self.status.bundle_details_by_uuid.get(uuid, None) + if ( + bundle is not None + and bundle.src_bundle is None + and bundle.backup_bundles is not None + ): + score = base_score + + # Schedule backups of bundles running longer; especially those + # that are unexpectedly slow. + start_ts = self.status.start_per_bundle[uuid] + if start_ts is not None: + runtime = now - start_ts + score += runtime + logger.debug(f'score[{bundle}] => {score} # latency boost') + + if bundle.slower_than_local_p95: + score += runtime / 2 + logger.debug(f'score[{bundle}] => {score} # >worker p95') + + if bundle.slower_than_global_p95: + score += runtime / 2 + logger.debug(f'score[{bundle}] => {score} # >global p95') + + # Prefer backups of bundles that don't have backups already. + backup_count = len(bundle.backup_bundles) + if backup_count == 0: + score *= 2 + elif backup_count == 1: + score /= 2 + elif backup_count == 2: + score /= 8 + else: + score = 0 + logger.debug(f'score[{bundle}] => {score} # {backup_count} dup backup factor') + + if ( + score != 0 + and (best_score is None or score > best_score) + ): + bundle_to_backup = bundle + assert bundle is not None + assert bundle.backup_bundles is not None + assert bundle.src_bundle is None + best_score = score + + if bundle_to_backup is not None: + self.last_backup = now + logger.info(f'=====> SCHEDULING BACKUP {bundle_to_backup} (score={best_score:.1f}) <=====') + self.schedule_backup_for_bundle(bundle_to_backup) + finally: + self.backup_lock.release() def check_if_cancelled(self, bundle: BundleDetails) -> bool: with self.status.lock: @@ -617,9 +697,9 @@ class RemoteExecutor(BaseExecutor): bundle.worker = worker machine = bundle.machine = worker.machine username = bundle.username = worker.username - fname = bundle.fname + self.status.record_acquire_worker(worker, uuid) - logger.debug(f'{uuid}/{fname}: Running bundle on {worker}...') + logger.debug(f'{bundle}: Running bundle on {worker}...') # Before we do any work, make sure the bundle is still viable. if self.check_if_cancelled(bundle): @@ -628,7 +708,7 @@ class RemoteExecutor(BaseExecutor): except Exception as e: logger.exception(e) logger.error( - f'{uuid}/{fname}: bundle says it\'s cancelled upfront but no results?!' + f'{bundle}: bundle says it\'s cancelled upfront but no results?!' ) assert bundle.worker is not None self.status.record_release_worker( @@ -660,14 +740,14 @@ class RemoteExecutor(BaseExecutor): try: cmd = f'{RSYNC} {bundle.code_file} {username}@{machine}:{bundle.code_file}' start_ts = time.time() - logger.info(f"{uuid}/{fname}: Copying work to {worker} via {cmd}.") + logger.info(f"{bundle}: Copying work to {worker} via {cmd}.") run_silently(cmd) xfer_latency = time.time() - start_ts - logger.info(f"{uuid}/{fname}: Copying done in {xfer_latency}s.") + logger.info(f"{bundle}: Copying done to {worker} in {xfer_latency:.1f}s.") except Exception as e: logger.exception(e) logger.error( - f'{uuid}/{fname}: failed to send instructions to worker machine?!?' + f'{bundle}: failed to send instructions to worker machine?!?' ) assert bundle.worker is not None self.status.record_release_worker( @@ -695,16 +775,14 @@ class RemoteExecutor(BaseExecutor): f'"source py39-venv/bin/activate &&' f' /home/scott/lib/python_modules/remote_worker.py' f' --code_file {bundle.code_file} --result_file {bundle.result_file}"') - logger.debug(f'{uuid}/{fname}: Executing {cmd} in the background to kick off work...') + logger.debug(f'{bundle}: Executing {cmd} in the background to kick off work...') p = cmd_in_background(cmd, silent=True) bundle.pid = pid = p.pid - logger.debug(f'{uuid}/{fname}: Local ssh process pid={pid}; remote worker is {machine}.') + logger.debug(f'{bundle}: Local ssh process pid={pid}; remote worker is {machine}.') return self.wait_for_process(p, bundle, 0) def wait_for_process(self, p: subprocess.Popen, bundle: BundleDetails, depth: int) -> Any: - uuid = bundle.uuid machine = bundle.machine - fname = bundle.fname pid = p.pid if depth > 3: logger.error( @@ -730,12 +808,12 @@ class RemoteExecutor(BaseExecutor): self.heartbeat() if self.check_if_cancelled(bundle): logger.info( - f'{uuid}/{fname}: another worker finished bundle, checking it out...' + f'{bundle}: another worker finished bundle, checking it out...' ) break else: logger.info( - f"{uuid}/{fname}: pid {pid} ({machine}) our ssh finished, checking it out..." + f"{bundle}: pid {pid} ({machine}) our ssh finished, checking it out..." ) p = None break @@ -757,10 +835,10 @@ class RemoteExecutor(BaseExecutor): # Otherwise, time for an emergency reschedule. except Exception as e: logger.exception(e) - logger.error(f'{uuid}/{fname}: Something unexpected just happened...') + logger.error(f'{bundle}: Something unexpected just happened...') if p is not None: logger.warning( - f"{uuid}/{fname}: Failed to wrap up \"done\" bundle, re-waiting on active ssh." + f"{bundle}: Failed to wrap up \"done\" bundle, re-waiting on active ssh." ) return self.wait_for_process(p, bundle, depth + 1) else: @@ -781,8 +859,6 @@ class RemoteExecutor(BaseExecutor): machine = bundle.machine result_file = bundle.result_file code_file = bundle.code_file - fname = bundle.fname - uuid = bundle.uuid # Whether original or backup, if we finished first we must # fetch the results if the computation happened on a @@ -793,7 +869,7 @@ class RemoteExecutor(BaseExecutor): if bundle.hostname not in bundle.machine: cmd = f'{RSYNC} {username}@{machine}:{result_file} {result_file} 2>/dev/null' logger.info( - f"{uuid}/{fname}: Fetching results from {username}@{machine} via {cmd}" + f"{bundle}: Fetching results from {username}@{machine} via {cmd}" ) # If either of these throw they are handled in @@ -811,7 +887,7 @@ class RemoteExecutor(BaseExecutor): # if one of the backups finished first; it still must read the # result from disk. if is_original: - logger.debug(f"{uuid}/{fname}: Unpickling {result_file}.") + logger.debug(f"{bundle}: Unpickling {result_file}.") try: with open(f'{result_file}', 'rb') as rb: serialized = rb.read() @@ -843,7 +919,7 @@ class RemoteExecutor(BaseExecutor): if bundle.backup_bundles is not None: for backup in bundle.backup_bundles: logger.debug( - f'{uuid}/{fname}: Notifying backup {backup.uuid} that it\'s cancelled' + f'{bundle}: Notifying backup {backup.uuid} that it\'s cancelled' ) backup.is_cancelled.set() @@ -858,7 +934,7 @@ class RemoteExecutor(BaseExecutor): # Tell the original to stop if we finished first. if not was_cancelled: logger.debug( - f'{uuid}/{fname}: Notifying original {bundle.src_bundle.uuid} we beat them to it.' + f'{bundle}: Notifying original {bundle.src_bundle.uuid} we beat them to it.' ) bundle.src_bundle.is_cancelled.set() @@ -895,8 +971,8 @@ class RemoteExecutor(BaseExecutor): pid = 0, start_ts = time.time(), end_ts = 0.0, - too_slow = False, - super_slow = False, + slower_than_local_p95 = False, + slower_than_global_p95 = False, src_bundle = None, is_cancelled = threading.Event(), was_cancelled = False, @@ -904,7 +980,7 @@ class RemoteExecutor(BaseExecutor): failure_count = 0, ) self.status.record_bundle_details(bundle) - logger.debug(f'{uuid}/{fname}: Created original bundle') + logger.debug(f'{bundle}: Created an original bundle') return bundle def create_backup_bundle(self, src_bundle: BundleDetails): @@ -925,8 +1001,8 @@ class RemoteExecutor(BaseExecutor): pid = 0, start_ts = time.time(), end_ts = 0.0, - too_slow = False, - super_slow = False, + slower_than_local_p95 = False, + slower_than_global_p95 = False, src_bundle = src_bundle, is_cancelled = threading.Event(), was_cancelled = False, @@ -935,12 +1011,13 @@ class RemoteExecutor(BaseExecutor): ) src_bundle.backup_bundles.append(backup_bundle) self.status.record_bundle_details_already_locked(backup_bundle) - logger.debug(f'{uuid}/{src_bundle.fname}: Created backup bundle') + logger.debug(f'{backup_bundle}: Created a backup bundle') return backup_bundle def schedule_backup_for_bundle(self, src_bundle: BundleDetails): assert self.status.lock.locked() + assert src_bundle is not None backup_bundle = self.create_backup_bundle(src_bundle) logger.debug( f'{backup_bundle.uuid}/{backup_bundle.fname}: Scheduling backup for execution...' @@ -952,7 +1029,6 @@ class RemoteExecutor(BaseExecutor): # the original pick them up and unpickle them. def emergency_retry_nasty_bundle(self, bundle: BundleDetails) -> fut.Future: - uuid = bundle.uuid is_original = bundle.src_bundle is None bundle.worker = None avoid_last_machine = bundle.machine @@ -966,18 +1042,18 @@ class RemoteExecutor(BaseExecutor): if bundle.failure_count > retry_limit: logger.error( - f'{uuid}: Tried this bundle too many times already ({retry_limit}x); giving up.' + f'{bundle}: Tried this bundle too many times already ({retry_limit}x); giving up.' ) if is_original: - logger.critical( - f'{uuid}: This is the original of the bundle; results will be incomplete.' + raise RemoteExecutorException( + f'{bundle}: This bundle can\'t be completed despite several backups and retries' ) else: - logger.error(f'{uuid}: At least it\'s only a backup; better luck with the others.') + logger.error(f'{bundle}: At least it\'s only a backup; better luck with the others.') return None else: logger.warning( - f'>>> Emergency rescheduling {uuid} because of unexected errors (wtf?!) <<<' + f'>>> Emergency rescheduling {bundle} because of unexected errors (wtf?!) <<<' ) return self.launch(bundle, avoid_last_machine) @@ -1007,12 +1083,14 @@ class DefaultExecutors(object): def ping(self, host) -> bool: logger.debug(f'RUN> ping -c 1 {host}') - command = ['ping', '-c', '1', host] - return subprocess.call( - command, - stdout=subprocess.DEVNULL, - stderr=subprocess.DEVNULL, - ) == 0 + try: + x = cmd_with_timeout( + f'ping -c 1 {host} >/dev/null 2>/dev/null', + timeout_seconds=1.0 + ) + return x == 0 + except Exception: + return False def thread_pool(self) -> ThreadExecutor: if self.thread_executor is None: @@ -1034,7 +1112,7 @@ class DefaultExecutors(object): RemoteWorkerRecord( username = 'scott', machine = 'cheetah.house', - weight = 12, + weight = 14, count = 4, ), ) @@ -1068,16 +1146,6 @@ class DefaultExecutors(object): count = 2, ), ) - if self.ping('backup.house'): - logger.info('Found backup.house') - pool.append( - RemoteWorkerRecord( - username = 'scott', - machine = 'backup.house', - weight = 1, - count = 4, - ), - ) if self.ping('kiosk.house'): logger.info('Found kiosk.house') pool.append(