X-Git-Url: https://wannabe.guru.org/gitweb/?a=blobdiff_plain;f=executors.py;h=d5049a264317c2f764d2068e7108a65d858f7cb2;hb=eb9e6df32ed696158bf34dba6464277b648f5c74;hp=2b2f0252ce326fd34800080735f5324f91bfc315;hpb=3bc4daf1edc121cd633429187392227f2fa61885;p=python_utils.git diff --git a/executors.py b/executors.py index 2b2f025..d5049a2 100644 --- a/executors.py +++ b/executors.py @@ -17,14 +17,14 @@ import time from typing import Any, Callable, Dict, List, Optional, Set import cloudpickle # type: ignore +from overrides import overrides from ansi import bg, fg, underline, reset import argparse_utils import config -import exec_utils +from exec_utils import run_silently, cmd_in_background from decorator_utils import singleton -import histogram -import string_utils +import histogram as hist logger = logging.getLogger(__name__) @@ -62,43 +62,22 @@ parser.add_argument( RSYNC = 'rsync -q --no-motd -W --ignore-existing --timeout=60 --size-only -z' SSH = 'ssh -oForwardX11=no' -HIST = histogram.SimpleHistogram( - histogram.SimpleHistogram.n_evenly_spaced_buckets( - int(0), int(500), 25 - ) -) - - -def run_local_bundle(fun, *args, **kwargs): - logger.debug(f"Running local bundle at {fun.__name__}") - start = time.time() - result = fun(*args, **kwargs) - end = time.time() - duration = end - start - logger.debug(f"{fun.__name__} finished; used {duration:.1f}s") - HIST.add_item(duration) - return result - - -def run_cloud_pickle(pickle): - fun, args, kwargs = cloudpickle.loads(pickle) - logger.debug(f"Running pickled bundle at {fun.__name__}") - start = time.time() - result = fun(*args, **kwargs) - end = time.time() - duration = end - start - logger.debug(f"{fun.__name__} finished; used {duration:.1f}s") - return result def make_cloud_pickle(fun, *args, **kwargs): - logger.info(f"Making cloudpickled bundle at {fun.__name__}") + logger.debug(f"Making cloudpickled bundle at {fun.__name__}") return cloudpickle.dumps((fun, args, kwargs)) class BaseExecutor(ABC): - def __init__(self): - pass + def __init__(self, *, title=''): + self.title = title + self.task_count = 0 + self.histogram = hist.SimpleHistogram( + hist.SimpleHistogram.n_evenly_spaced_buckets( + int(0), int(500), 50 + ) + ) @abstractmethod def submit(self, @@ -112,6 +91,10 @@ class BaseExecutor(ABC): wait: bool = True) -> None: pass + def adjust_task_count(self, delta: int) -> None: + self.task_count += delta + logger.debug(f'Executor current task count is {self.task_count}') + class ThreadExecutor(BaseExecutor): def __init__(self, @@ -127,29 +110,38 @@ class ThreadExecutor(BaseExecutor): max_workers=workers, thread_name_prefix="thread_executor_helper" ) - self.job_count = 0 + def run_local_bundle(self, fun, *args, **kwargs): + logger.debug(f"Running local bundle at {fun.__name__}") + start = time.time() + result = fun(*args, **kwargs) + end = time.time() + self.adjust_task_count(-1) + duration = end - start + logger.debug(f"{fun.__name__} finished; used {duration:.1f}s") + self.histogram.add_item(duration) + return result + + @overrides def submit(self, function: Callable, *args, **kwargs) -> fut.Future: - self.job_count += 1 - logger.debug( - f'Submitted work to threadpool; there are now {self.job_count} items.' - ) + self.adjust_task_count(+1) newargs = [] newargs.append(function) for arg in args: newargs.append(arg) return self._thread_pool_executor.submit( - run_local_bundle, + self.run_local_bundle, *newargs, **kwargs) + @overrides def shutdown(self, wait = True) -> None: - logger.debug("Shutting down threadpool executor.") - print(HIST) + logger.debug(f'Shutting down threadpool executor {self.title}') + print(self.histogram) self._thread_pool_executor.shutdown(wait) @@ -166,24 +158,43 @@ class ProcessExecutor(BaseExecutor): self._process_executor = fut.ProcessPoolExecutor( max_workers=workers, ) - self.job_count = 0 + def run_cloud_pickle(self, pickle): + fun, args, kwargs = cloudpickle.loads(pickle) + logger.debug(f"Running pickled bundle at {fun.__name__}") + result = fun(*args, **kwargs) + self.adjust_task_count(-1) + return result + + @overrides def submit(self, function: Callable, *args, **kwargs) -> fut.Future: - # Bundle it up before submitting because pickle sucks. + start = time.time() + self.adjust_task_count(+1) pickle = make_cloud_pickle(function, *args, **kwargs) - self.job_count += 1 - logger.debug( - f'Submitting work to processpool executor; there are now {self.job_count} items.' + result = self._process_executor.submit( + self.run_cloud_pickle, + pickle ) - return self._process_executor.submit(run_cloud_pickle, pickle) + result.add_done_callback( + lambda _: self.histogram.add_item( + time.time() - start + ) + ) + return result + @overrides def shutdown(self, wait=True) -> None: - logger.debug('Shutting down processpool executor') - print(HIST) + logger.debug(f'Shutting down processpool executor {self.title}') self._process_executor.shutdown(wait) + print(self.histogram) + + def __getstate__(self): + state = self.__dict__.copy() + state['_process_executor'] = None + return state @dataclass @@ -204,6 +215,7 @@ class RemoteWorkerRecord: class BundleDetails: pickled_code: bytes uuid: str + fname: str worker: Optional[RemoteWorkerRecord] username: Optional[str] machine: Optional[str] @@ -469,6 +481,7 @@ class RemoteExecutor(BaseExecutor): policy: RemoteWorkerSelectionPolicy) -> None: super().__init__() self.workers = workers + self.policy = policy self.worker_count = 0 for worker in self.workers: self.worker_count += worker.count @@ -476,7 +489,6 @@ class RemoteExecutor(BaseExecutor): msg = f"We need somewhere to schedule work; count was {self.worker_count}" logger.critical(msg) raise Exception(msg) - self.policy = policy self.policy.register_worker_pool(self.workers) self.cv = threading.Condition() self._helper_executor = fut.ThreadPoolExecutor( @@ -486,7 +498,7 @@ 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 endpoints.' + f'Creating remote processpool with {self.worker_count} remote worker threads.' ) def is_worker_available(self) -> bool: @@ -566,6 +578,7 @@ class RemoteExecutor(BaseExecutor): def launch(self, bundle: BundleDetails) -> Any: """Find a worker for bundle or block until one is available.""" + self.adjust_task_count(+1) uuid = bundle.uuid hostname = bundle.hostname avoid_machine = None @@ -579,6 +592,7 @@ 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'Running bundle {uuid} on {worker}...') @@ -588,31 +602,31 @@ class RemoteExecutor(BaseExecutor): return self.post_launch_work(bundle) except Exception as e: logger.exception(e) - logger.info(f"Bundle {uuid} seems to have failed?!") + logger.info(f"{uuid}/{fname}: bundle seems to have failed?!") if bundle.failure_count < config.config['executors_max_bundle_failures']: return self.launch(bundle) else: - logger.info(f"Bundle {uuid} is poison, giving up on it.") + logger.info(f"{uuid}/{fname}: bundle is poison, giving up on it.") return None # Send input to machine if it's not local. if hostname not in machine: cmd = f'{RSYNC} {bundle.code_file} {username}@{machine}:{bundle.code_file}' - logger.info(f"Copying work to {worker} via {cmd}") - exec_utils.run_silently(cmd) + logger.info(f"{uuid}/{fname}: Copying work to {worker} via {cmd}") + run_silently(cmd) # Do it. cmd = (f'{SSH} {bundle.username}@{bundle.machine} ' - f'"source remote-execution/bin/activate &&' + 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}"') - p = exec_utils.cmd_in_background(cmd, silent=True) + p = cmd_in_background(cmd, silent=True) bundle.pid = pid = p.pid - logger.info(f"Running {cmd} in the background as process {pid}") + logger.info(f"{uuid}/{fname}: Start training on {worker} via {cmd} (background pid {pid})") while True: try: - p.wait(timeout=0.5) + p.wait(timeout=0.25) except subprocess.TimeoutExpired: self.heartbeat() @@ -623,7 +637,7 @@ class RemoteExecutor(BaseExecutor): break else: logger.debug( - f"{pid}/{bundle.uuid} has finished its work normally." + f"{uuid}/{fname}: pid {pid} has finished its work normally." ) break @@ -631,10 +645,10 @@ class RemoteExecutor(BaseExecutor): return self.post_launch_work(bundle) except Exception as e: logger.exception(e) - logger.info(f"Bundle {uuid} seems to have failed?!") + logger.info(f"{uuid}: Bundle seems to have failed?!") if bundle.failure_count < config.config['executors_max_bundle_failures']: return self.launch(bundle) - logger.info(f"Bundle {uuid} is poison, giving up on it.") + logger.info(f"{uuid}: Bundle is poison, giving up on it.") return None def post_launch_work(self, bundle: BundleDetails) -> Any: @@ -645,47 +659,43 @@ 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 # remote machine. + bundle.end_ts = time.time() if not was_cancelled: assert bundle.machine is not None if bundle.hostname not in bundle.machine: cmd = f'{RSYNC} {username}@{machine}:{result_file} {result_file} 2>/dev/null' logger.info( - f"Fetching results from {username}@{machine} via {cmd}" + f"{uuid}/{fname}: Fetching results from {username}@{machine} via {cmd}" ) try: - exec_utils.run_silently(cmd) + run_silently(cmd) except subprocess.CalledProcessError: - pass - exec_utils.run_silently(f'{SSH} {username}@{machine}' - f' "/bin/rm -f {code_file} {result_file}"') - bundle.end_ts = time.time() + logger.critical(f'Failed to copy {username}@{machine}:{result_file}!') + run_silently(f'{SSH} {username}@{machine}' + f' "/bin/rm -f {code_file} {result_file}"') + dur = bundle.end_ts - bundle.start_ts + self.histogram.add_item(dur) assert bundle.worker is not None self.status.record_release_worker_already_locked( bundle.worker, bundle.uuid, was_cancelled ) - if not was_cancelled: - dur = bundle.end_ts - bundle.start_ts - HIST.add_item(dur) - - # Original or not, the results should be back on the local - # machine. Are they? - if not os.path.exists(result_file): - msg = f'{result_file} unexpectedly missing, wtf?!' - logger.critical(msg) - bundle.failure_count += 1 - self.release_worker(bundle.worker) - raise Exception(msg) # Only the original worker should unpickle the file contents - # though since it's the only one whose result matters. + # though since it's the only one whose result matters. The + # original is also the only job that may delete result_file + # from disk. Note that the original may have been cancelled + # if one of the backups finished first; it still must read the + # result from disk. if is_original: - logger.debug(f"Unpickling {result_file}.") + logger.debug(f"{uuid}/{fname}: Unpickling {result_file}.") try: with open(f'{result_file}', 'rb') as rb: serialized = rb.read() @@ -706,30 +716,32 @@ class RemoteExecutor(BaseExecutor): if bundle.backup_bundles is not None: for backup in bundle.backup_bundles: logger.debug( - f'Notifying backup {backup.uuid} that it is cancelled' + f'{uuid}/{fname}: Notifying backup {backup.uuid} that it\'s cancelled' ) backup.is_cancelled.set() - # This is a backup. + # This is a backup job. else: # Backup results don't matter, they just need to leave the - # result file in the right place for their original to - # read later. + # result file in the right place for their originals to + # read/unpickle later. result = None # Tell the original to stop if we finished first. if not was_cancelled: logger.debug( - f'Notifying original {bundle.src_bundle.uuid} that it is cancelled' + f'{uuid}/{fname}: Notifying original {bundle.src_bundle.uuid} that it\'s cancelled' ) bundle.src_bundle.is_cancelled.set() assert bundle.worker is not None self.release_worker(bundle.worker) + self.adjust_task_count(-1) return result - def create_original_bundle(self, pickle): - uuid = string_utils.generate_uuid(as_hex=True) + def create_original_bundle(self, pickle, fname: str): + from string_utils import generate_uuid + uuid = generate_uuid(as_hex=True) code_file = f'/tmp/{uuid}.code.bin' result_file = f'/tmp/{uuid}.result.bin' @@ -740,6 +752,7 @@ class RemoteExecutor(BaseExecutor): bundle = BundleDetails( pickled_code = pickle, uuid = uuid, + fname = fname, worker = None, username = None, machine = None, @@ -758,7 +771,7 @@ class RemoteExecutor(BaseExecutor): failure_count = 0, ) self.status.record_bundle_details(bundle) - logger.debug(f'Created original bundle {uuid}') + logger.debug(f'{uuid}/{fname}: Created original bundle') return bundle def create_backup_bundle(self, src_bundle: BundleDetails): @@ -769,6 +782,7 @@ class RemoteExecutor(BaseExecutor): backup_bundle = BundleDetails( pickled_code = src_bundle.pickled_code, uuid = uuid, + fname = src_bundle.fname, worker = None, username = None, machine = None, @@ -788,7 +802,7 @@ class RemoteExecutor(BaseExecutor): ) src_bundle.backup_bundles.append(backup_bundle) self.status.record_bundle_details_already_locked(backup_bundle) - logger.debug(f'Created backup bundle {uuid}') + logger.debug(f'{uuid}/{src_bundle.fname}: Created backup bundle') return backup_bundle def schedule_backup_for_bundle(self, @@ -796,7 +810,7 @@ class RemoteExecutor(BaseExecutor): assert self.status.lock.locked() backup_bundle = self.create_backup_bundle(src_bundle) logger.debug( - f'Scheduling backup bundle {backup_bundle.uuid} for execution' + f'{backup_bundle.uuid}/{backup_bundle.fname}: Scheduling backup for execution...' ) self._helper_executor.submit(self.launch, backup_bundle) @@ -804,21 +818,21 @@ class RemoteExecutor(BaseExecutor): # they will move the result_file to this machine and let # the original pick them up and unpickle them. + @overrides def submit(self, function: Callable, *args, **kwargs) -> fut.Future: pickle = make_cloud_pickle(function, *args, **kwargs) - bundle = self.create_original_bundle(pickle) + bundle = self.create_original_bundle(pickle, function.__name__) self.total_bundles_submitted += 1 - logger.debug( - f'Submitted work to remote executor; {self.total_bundles_submitted} items now submitted' - ) return self._helper_executor.submit(self.launch, bundle) + @overrides def shutdown(self, wait=True) -> None: self._helper_executor.shutdown(wait) - print(HIST) + logging.debug(f'Shutting down RemoteExecutor {self.title}') + print(self.histogram) @singleton @@ -881,7 +895,7 @@ class DefaultExecutors(object): RemoteWorkerRecord( username = 'scott', machine = 'meerkat.cabin', - weight = 7, + weight = 5, count = 2, ), )