From 4c44a76cbcfc77ae1c70e904a3927188cb9f07e5 Mon Sep 17 00:00:00 2001 From: JosepSampe Date: Wed, 23 Sep 2026 11:24:03 +0200 Subject: [PATCH 1/5] Fix races and lost state in monitoring, multiprocessing and worker - Storage monitor: keep a finished call whose init mark is not listed yet for the next poll, instead of dropping its worker token - Monitor: guard status application and token release with a shared lock, so two threads cannot both return a token for one chunk or put a finished call back to running - RLock: only the owning thread (pid, thread id) may re-enter - Condition: a timed-out wait removes its handle from the notify list, or takes a notify that arrived just after the timeout - SemLock: refresh the Redis expiry on acquire and release, since a released lock was recreated with no TTL - JobRunner: report an unpickleable exception with its traceback as text; the traceback object itself cannot be pickled - Handler: close the JobRunner pipe explicitly, even if the finish event fails - Tests: regression test for each fix; the fake Redis now deletes empty lists like real Redis does; the telemetry test fakes now have the state flags real futures have --- .../monitoring/backends/storage/storage.py | 8 +- lithops/monitoring/monitor.py | 48 +++++-- lithops/multiprocessing/synchronize.py | 64 ++++++++-- lithops/tests/mp_fakeredis.py | 42 +++++- lithops/tests/test_monitor.py | 120 ++++++++++++++++++ lithops/tests/test_multiprocessing.py | 87 +++++++++++++ lithops/tests/test_telemetry.py | 6 +- lithops/tests/test_worker.py | 80 +++++++++++- lithops/worker/handler.py | 26 +++- lithops/worker/jobrunner.py | 15 ++- 10 files changed, 453 insertions(+), 43 deletions(-) diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py index 90dfec162..ca7974202 100644 --- a/lithops/monitoring/backends/storage/storage.py +++ b/lithops/monitoring/backends/storage/storage.py @@ -217,10 +217,16 @@ def _generate_tokens(self, callids_running, callids_done): for call_id, worker_id in running_new: self.callids_running_worker[call_id] = worker_id + # A completion whose init mark is not in this listing yet has no + # worker to charge it to. Leaving it out of the processed set means + # the next listing, which may carry the init, still counts it. + # Marking it processed here drops the token for good + attributed = set() for callid_done in done_new: worker_id = self.callids_running_worker.get(callid_done) if worker_id is None: continue + attributed.add(callid_done) self.callids_done_worker.setdefault(worker_id, set()).add( callid_done ) @@ -244,7 +250,7 @@ def _generate_tokens(self, callids_running, callids_done): self.token_bucket_q.put('#') self.callids_running_processed.update(running_new) - self.callids_done_processed.update(done_new) + self.callids_done_processed.update(attributed) def _poll_and_process_job_status(self): """ diff --git a/lithops/monitoring/monitor.py b/lithops/monitoring/monitor.py index 195370285..58922b15b 100644 --- a/lithops/monitoring/monitor.py +++ b/lithops/monitoring/monitor.py @@ -149,6 +149,11 @@ def __init__(self, executor_id, # read from the monitor thread. One lock covers the set, the index # that finds a future by its call id, and the set of live job ids self._futures_lock = threading.RLock() + # State changes and token accounting run on the monitor thread and + # on the thread that submits a job (it applies statuses that arrived + # early). One lock, re-entrant because applying one status can + # reveal the futures whose own statuses were held + self._apply_lock = threading.RLock() self.futures = set() self._futures_by_id = {} self._timeout_query_failures = {} @@ -329,8 +334,14 @@ def _mark_running(self, future, call_status): service that redelivers a status, or a storage sweep that reads one the channel already delivered, therefore counts once """ - future._set_running(call_status) - self.telemetry.on_call_started(future, call_status) + with self._apply_lock: + # Checked again under the lock. The caller checked too, but an + # __end__ on the other thread can land between that check and + # here, and this write would put the call back to running + if _is_started(future): + return + future._set_running(call_status) + self.telemetry.on_call_started(future, call_status) def _mark_ready(self, future, call_status, outcome=None): """ @@ -340,8 +351,11 @@ def _mark_ready(self, future, call_status, outcome=None): Measured after the transition, so that the timestamp the future records for the arrival of the status is part of what is measured """ - future._set_ready(call_status) - self.telemetry.on_call_finished(future, call_status, outcome) + with self._apply_lock: + if _is_finished(future): + return + future._set_ready(call_status) + self.telemetry.on_call_finished(future, call_status, outcome) def _all_ready(self): """ @@ -631,16 +645,22 @@ def _generate_tokens(self, call_status): call_id = _status_id(call_status) worker_id = call_status['activation_id'] - done_for_worker = self.callids_done_worker.setdefault(worker_id, set()) - done_for_worker.add(call_id) - - if ( - worker_id not in self.workers_done - and len(done_for_worker) >= chunksize - ): - self.workers_done.add(worker_id) - if self.should_run: - self.token_bucket_q.put('#') + # The two threads that apply statuses both get here. The read of + # the count and the decision to hand a token back have to be one + # step, or each of them hands one back + with self._apply_lock: + done_for_worker = self.callids_done_worker.setdefault( + worker_id, set() + ) + done_for_worker.add(call_id) + + if ( + worker_id not in self.workers_done + and len(done_for_worker) >= chunksize + ): + self.workers_done.add(worker_id) + if self.should_run: + self.token_bucket_q.put('#') def _apply_status_message(self, call_status): """ diff --git a/lithops/multiprocessing/synchronize.py b/lithops/multiprocessing/synchronize.py index 73f80f885..81401cd2c 100644 --- a/lithops/multiprocessing/synchronize.py +++ b/lithops/multiprocessing/synchronize.py @@ -9,6 +9,7 @@ # Modifications Copyright (c) 2020 Cloudlab URV # +import os import threading import math import time @@ -128,17 +129,19 @@ def acquire(self, block=True, timeout=None): """ if not block or (timeout is not None and timeout <= 0): logger.debug('Requested non-blocking acquire for lock %s', self._name) - return self._client.lpop(self._name) is not None - - if timeout is None: + acquired = self._client.lpop(self._name) is not None + elif timeout is None: logger.debug('Requested blocking acquire for lock %s', self._name) self._client.blpop([self._name]) - return True - - logger.debug( - 'Requested acquire for lock %s within %s s', self._name, timeout - ) - return _blpop(self._client, self._name, timeout) is not None + acquired = True + else: + logger.debug( + 'Requested acquire for lock %s within %s s', self._name, timeout + ) + acquired = _blpop(self._client, self._name, timeout) is not None + if acquired: + self._refresh_expiry() + return acquired def release(self): logger.debug('Requested release for lock %s', self._name) @@ -149,6 +152,20 @@ def release(self): # What the standard library raises for a lock that was not held # and for a bounded semaphore released more often than acquired raise ValueError('semaphore or lock released too many times') + self._refresh_expiry() + + def _refresh_expiry(self): + """ + Pushes the key's deadline out again. + + Redis deletes a list once its last token is taken, expiry and all, + and the release script recreates it with none: without this a lock + used once never expires. A semaphore with tokens left keeps its + key, and the deadline set at creation would take those tokens + """ + self._client.expire( + self._name, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME) + ) def __repr__(self): try: @@ -230,34 +247,46 @@ class RLock(Lock): def __init__(self): super().__init__() self._count = 0 + self._owner = None def __setstate__(self, state): super().__setstate__(state) self._count = 0 + self._owner = None + + def _holder(self): + """The process and thread that may re-enter without a new token""" + return (os.getpid(), threading.get_ident()) def acquire(self, block=True, timeout=None): - if self.owned: + holder = self._holder() + # owned is one flag for the whole object. Another thread in this + # process would see it and walk in beside the holder + if self._owner == holder: self._count += 1 return True res = super().acquire(block, timeout) if res: self._count = 1 + self._owner = holder return res def release(self): - if not self.owned: + if self._owner != self._holder(): # The wording the standard library uses raise AssertionError( 'attempt to release recursive lock not owned by thread' ) self._count -= 1 if self._count == 0: + self._owner = None super().release() def _release_save(self): """Release all acquisitions while a condition waits.""" count = self._count self._count = 0 + self._owner = None super().release() return count @@ -336,9 +365,20 @@ def wait(self, timeout=None): notified = self._client.lpop(wait_handle) is not None else: notified = _blpop(self._client, wait_handle, timeout) is not None - self._client.expire(wait_handle, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) finally: self._acquire_restore(state) + if not notified: + # A notify that won the race already took our handle off the + # list and pushed a token. Take that token. Otherwise take + # ourselves off the list: the next notify pops the oldest + # handle, and a waiter that has gone spends that wakeup + if self._client.lpop(wait_handle) is not None: + notified = True + else: + self._client.lrem(self._notify_handle, 1, wait_handle) + self._client.expire( + wait_handle, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME) + ) # Whether a notify arrived, rather than the timeout expiring, which # is what the standard library returns and callers branch on return notified diff --git a/lithops/tests/mp_fakeredis.py b/lithops/tests/mp_fakeredis.py index 73654c3b5..86c5c8226 100644 --- a/lithops/tests/mp_fakeredis.py +++ b/lithops/tests/mp_fakeredis.py @@ -148,13 +148,21 @@ def lpush(self, key, *values): self._cond.notify_all() return len(items) + def _drop_if_empty(self, key): + """The server deletes a list, and its expiry, once it is empty""" + if key in self.lists and not self.lists[key]: + del self.lists[key] + self.expiries.pop(key, None) + def lpop(self, key): key = _key(key) with self._cond: items = self.lists.get(key) if not items: return None - return items.pop(0) + item = items.pop(0) + self._drop_if_empty(key) + return item def blpop(self, keys, timeout=0): """Blocks until one of the keys has an element, as the server does""" @@ -167,7 +175,9 @@ def blpop(self, keys, timeout=0): for key in keys: items = self.lists.get(key) if items: - return key, items.pop(0) + item = items.pop(0) + self._drop_if_empty(key) + return key, item remaining = None if end is None else end - time.monotonic() if remaining is not None and remaining <= 0: return None @@ -177,6 +187,34 @@ def llen(self, key): key = _key(key) return len(self.lists.get(key, [])) + def lrem(self, key, count, value): + """Removes up to ``count`` occurrences of ``value``. Zero removes all""" + key = _key(key) + value = _to_bytes(value) + with self._cond: + items = self.lists.get(key) + if not items: + return 0 + removed = 0 + if count >= 0: + kept = [] + for item in items: + if item == value and (count == 0 or removed < count): + removed += 1 + continue + kept.append(item) + else: + kept = [] + for item in reversed(items): + if item == value and removed < -count: + removed += 1 + continue + kept.append(item) + kept.reverse() + self.lists[key] = kept + self._drop_if_empty(key) + return removed + def lrange(self, key, start, end): key = _key(key) items = self.lists.get(key, []) diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index 028bc8981..ce30e16ea 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -831,6 +831,23 @@ def test_generate_tokens_waits_for_full_chunk_then_does_not_repeat(self): monitor._generate_tokens(running, all_done) assert monitor.token_bucket_q.empty() + def test_generate_tokens_emits_when_done_is_listed_before_running(self): + """ + A listing can return the status object before the init mark: the + init write failed, or the list is not read-after-write consistent. + Treating that completion as already accounted leaves the worker + token unissued, and the calls still queued never start + """ + monitor = self._storage(chunksize=1) + monitor.present_jobs.add('M000') + done = {('sess-0', 'M000', '00000')} + monitor._generate_tokens(set(), done) + assert monitor.token_bucket_q.empty() + + running = {(('sess-0', 'M000', '00000'), 'w1')} + monitor._generate_tokens(running, done) + assert monitor.token_bucket_q.get_nowait() == '#' + def test_generate_tokens_one_per_worker(self): monitor = self._storage(chunksize=1) running = { @@ -1508,6 +1525,109 @@ def test_a_redelivered_end_frees_one_token_not_two(self): monitor._apply_status_message(dict(second)) assert tokens.qsize() == 1 + def test_two_threads_finishing_one_chunk_release_one_token(self): + """ + The submitter thread applies a status that was held, while the + monitor thread applies the one that just arrived. Both can see the + chunk cross its size and each hand a token back + """ + tokens = queue.Queue() + monitor = self._monitor(tokens=tokens, chunksize={'M000': 2}) + monitor.add_futures([ + FakeFuture('M000', invoked=True, call_id='00000'), + FakeFuture('M000', invoked=True, call_id='00001'), + ]) + + class StaleMembership(set): + """ + Reports the membership it saw, then waits. Both threads can + observe "not done yet" before either records the worker + """ + + def __contains__(self, item): + found = super().__contains__(item) + time.sleep(0.05) + return found + + monitor.workers_done = StaleMembership() + start = threading.Barrier(2) + errors = [] + + def apply(call_id): + try: + start.wait(timeout=2) + payload, _raw = _status( + call_id=call_id, kind='__end__', chunksize=2 + ) + payload['activation_id'] = 'w1' + monitor._generate_tokens(payload) + except Exception as exc: # noqa: BLE001 - recorded, not handled + errors.append(exc) + + threads = [ + threading.Thread(target=apply, args=('00000',)), + threading.Thread(target=apply, args=('00001',)), + ] + for thread in threads: + thread.start() + for thread in threads: + thread.join(timeout=5) + + assert not errors + assert all(not thread.is_alive() for thread in threads) + assert tokens.qsize() == 1 + + def test_an_init_cannot_overwrite_an_end_applied_at_the_same_time(self): + """ + The check that a future is not finished and the write that marks it + running are separate. An __init__ that passes the check can land + after the __end__ and put a finished call back to running + """ + monitor = self._monitor() + entered_running = threading.Event() + + class SlowRunning(FakeFuture): + def _set_running(self, call_status): + entered_running.set() + time.sleep(0.05) + self.ready = False + super()._set_running(call_status) + + future = SlowRunning('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + init, _raw = _status(kind='__init__') + end, _raw = _status(kind='__end__') + errors = [] + + def apply_init(): + try: + monitor._apply_status_message(init) + except Exception as exc: # noqa: BLE001 - recorded, not handled + errors.append(exc) + + def apply_end(): + try: + # Only once the init has passed its "not started" check and + # is inside the transition, so the end cannot simply win + # the race by running first + assert entered_running.wait(timeout=2) + monitor._apply_status_message(end) + except Exception as exc: # noqa: BLE001 - recorded, not handled + errors.append(exc) + + threads = [ + threading.Thread(target=apply_init), + threading.Thread(target=apply_end), + ] + for thread in threads: + thread.start() + for thread in threads: + thread.join(timeout=5) + + assert not errors + assert future.ready is True + assert future.running is False + def test_a_status_of_a_tracked_future_is_never_held(self): """ A second __init__ of a call that is already running used to be held diff --git a/lithops/tests/test_multiprocessing.py b/lithops/tests/test_multiprocessing.py index b9a77fe9e..f6656af5b 100644 --- a/lithops/tests/test_multiprocessing.py +++ b/lithops/tests/test_multiprocessing.py @@ -1081,6 +1081,36 @@ def test_a_condition_survives_being_pickled(self, redis): restored = pickle.loads(pickle.dumps(cond)) assert restored._notify_handle == cond._notify_handle + def test_a_timed_out_wait_does_not_consume_the_next_notify(self, redis): + """ + A waiter that gives up has to leave the notify list. The next + notify pops the oldest handle, and a dead one spends that wakeup + on a list nobody is blocked on + """ + from lithops.multiprocessing import Condition + + cond = Condition() + with cond: + assert cond.wait(timeout=0.05) is False + assert redis.llen(cond._notify_handle) == 0 + + woken = threading.Event() + + def waiter(): + with cond: + if cond.wait(timeout=2): + woken.set() + + thread = threading.Thread(target=waiter) + thread.start() + deadline = time.monotonic() + 2 + while time.monotonic() < deadline and redis.llen(cond._notify_handle) == 0: + time.sleep(0.01) + with cond: + cond.notify() + thread.join(timeout=2) + assert woken.is_set() + def _notify(cond): with cond: @@ -1514,6 +1544,29 @@ def test_releasing_an_rlock_that_is_not_held_raises(self, redis): with pytest.raises(AssertionError, match='not owned'): RLock().release() + def test_another_thread_cannot_reenter_an_rlock(self, redis): + """ + Re-entry is the thread that already holds the lock, not whichever + thread in the process looks at it. A second thread that walks in + shares the critical section with the holder + """ + from lithops.multiprocessing import RLock + + lock = RLock() + assert lock.acquire() is True + other = {} + + def try_acquire(): + other['got'] = lock.acquire(timeout=0.2) + + thread = threading.Thread(target=try_acquire) + thread.start() + thread.join(timeout=2) + try: + assert other['got'] is False + finally: + lock.release() + def test_a_bounded_semaphore_rejects_an_extra_release(self, redis): """ A bounded semaphore that silently swallows an over-release is not @@ -1541,6 +1594,40 @@ def test_releasing_a_lock_that_was_never_held_raises(self, redis): with pytest.raises(ValueError, match='released too many times'): Lock().release() + def test_a_released_lock_keeps_an_expiry(self, redis): + """ + Taking the only token empties the list, and Redis deletes an empty + list together with its expiry. The release pushes the token into a + new key that has none, so every lock used once stayed on the server + for ever + """ + from lithops.multiprocessing import Lock + from lithops.multiprocessing import config as mp_config + + lock = Lock() + lock.acquire() + assert lock._name not in redis.lists + lock.release() + assert redis.expiries.get(lock._name) == mp_config.get_parameter( + mp_config.REDIS_EXPIRY_TIME + ) + + def test_acquire_refreshes_the_expiry_of_a_semaphore(self, redis): + """ + A semaphore with tokens left keeps its key while some are taken. + Its expiry, set once at creation, has to move with use, or a + semaphore in use past it loses the tokens still in the list + """ + from lithops.multiprocessing import Semaphore + from lithops.multiprocessing import config as mp_config + + sem = Semaphore(2) + redis.expire(sem._name, 10) + assert sem.acquire() is True + assert redis.expiries[sem._name] == mp_config.get_parameter( + mp_config.REDIS_EXPIRY_TIME + ) + class TestBlpopTimeoutFallback: """ diff --git a/lithops/tests/test_telemetry.py b/lithops/tests/test_telemetry.py index f3ef63eef..b0b49e24f 100644 --- a/lithops/tests/test_telemetry.py +++ b/lithops/tests/test_telemetry.py @@ -94,6 +94,10 @@ def _future(**attrs): runtime_memory=512, _host_status_done_tstamp=None, _status_query_count=3, + running=False, + ready=False, + success=False, + done=False, ) defaults.update(attrs) return SimpleNamespace(**defaults) @@ -788,7 +792,7 @@ def test_an_unattached_monitor_is_safe(self): ) assert monitor.telemetry is NOOP - future = MagicMock() + future = MagicMock(running=True, ready=False, success=False, done=False) monitor._mark_ready(future, {}) future._set_ready.assert_called_once() diff --git a/lithops/tests/test_worker.py b/lithops/tests/test_worker.py index b57a723dd..953a562cb 100644 --- a/lithops/tests/test_worker.py +++ b/lithops/tests/test_worker.py @@ -102,6 +102,17 @@ def _boom(x): raise ValueError('nope') +class _UnpickleableError(Exception): + """An exception instance cloudpickle cannot round-trip""" + + def __reduce__(self): + raise TypeError('cannot pickle') + + +def _raise_unpickleable(x): + raise _UnpickleableError('lost') + + def _obj_fn(obj): return 1 @@ -452,11 +463,15 @@ def test_keeps_existing_activation_id(self, tmp_path, monkeypatch): class TestRunTask: - def _patch_run(self, task, jrp, handler_conn, stats_text=None): + def _patch_run(self, task, jrp, handler_conn, stats_text=None, + jobrunner_conn=None, status=None): + if jobrunner_conn is None: + jobrunner_conn = MagicMock() if stats_text is not None: with open(task.stats_file, 'w') as f: f.write(stats_text) - status = MagicMock() + if status is None: + status = MagicMock() cpu = {'usage': [1], 'system': 0.1, 'user': 0.2} net = {'sent': 3, 'recv': 4} mem = {'rss': 5, 'vms': 6, 'uss': 7} @@ -465,7 +480,7 @@ def _patch_run(self, task, jrp, handler_conn, stats_text=None): monitor.get_network_io.return_value = net monitor.get_memory_info.return_value = mem ctx = MagicMock() - ctx.Pipe.return_value = (handler_conn, MagicMock()) + ctx.Pipe.return_value = (handler_conn, jobrunner_conn) ctx.Process.return_value = jrp with patch('lithops.worker.handler.setup_lithops_logger'): with patch( @@ -641,6 +656,51 @@ def test_does_not_mutate_extra_env_with_session_id(self, tmp_path): assert SESSION_ID_ENV not in extra assert 'LITHOPS_CONFIG' not in extra + def test_closes_both_ends_of_the_jobrunner_pipe(self, tmp_path): + """ + One worker process runs every call of its chunk. The pipe opened + for each JobRunner is closed when the call ends, not left to the + garbage collector + """ + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'job_stats.txt') + (tmp_path / 'execution.log').write_bytes(b'log') + jrp = MagicMock() + jrp.is_alive.return_value = False + handler_conn = MagicMock() + handler_conn.poll.return_value = True + jobrunner_conn = MagicMock() + self._patch_run(task, jrp, handler_conn, jobrunner_conn=jobrunner_conn) + handler_conn.close.assert_called_once() + jobrunner_conn.close.assert_called_once() + + def test_closes_the_pipe_when_the_finish_event_fails(self, tmp_path): + """ + Reporting the finish goes over the network and can raise. The pipe + is closed all the same + """ + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'job_stats.txt') + (tmp_path / 'execution.log').write_bytes(b'log') + jrp = MagicMock() + jrp.is_alive.return_value = False + handler_conn = MagicMock() + handler_conn.poll.return_value = True + jobrunner_conn = MagicMock() + status = MagicMock() + status.send_finish_event.side_effect = ConnectionError('broker gone') + with pytest.raises(ConnectionError): + self._patch_run( + task, jrp, handler_conn, + jobrunner_conn=jobrunner_conn, status=status, + ) + handler_conn.close.assert_called_once() + jobrunner_conn.close.assert_called_once() + class TestJobRunnerDeathReason: """ @@ -1227,6 +1287,20 @@ def test_run_exception_records_exc_info(self): assert 'exc_info' in text jr.jobrunner_conn.send.assert_called_with('Finished') + def test_an_unpickleable_exception_is_still_reported(self): + """ + The fallback for an exception that will not pickle has to pickle. + Putting the traceback object in that payload raises again, run() + dies, and the call is reported as a success with no result + """ + jr = self._runner(_raise_unpickleable, {'x': 1}) + jr.run() + text = open(self.stats).read() + assert 'exception True' in text + assert 'exc_pickle_fail True' in text + assert 'exc_info' in text + jr.jobrunner_conn.send.assert_called_with('Finished') + def test_fill_optional_args_id_and_storage(self): jr = self._runner(_echo, {'x': 1}, call_id='00007') data = {'x': 1} diff --git a/lithops/worker/handler.py b/lithops/worker/handler.py index c3d66df03..ecc9cc6b7 100644 --- a/lithops/worker/handler.py +++ b/lithops/worker/handler.py @@ -514,6 +514,8 @@ def run_task(task: SimpleNamespace) -> None: ) job_interrupted = False + handler_conn = None + jobrunner_conn = None try: handler_conn, jobrunner_conn = _MP_CTX.Pipe() @@ -589,10 +591,24 @@ def run_task(task: SimpleNamespace) -> None: for key in injected_env: os.environ.pop(key, None) - # An interrupted job is not reported: the client is gone anyway - if not job_interrupted: - call_status.add('worker_end_tstamp', time.time()) - _add_logs(call_status, task) - call_status.send_finish_event() + try: + # An interrupted job is not reported: the client is gone anyway + if not job_interrupted: + call_status.add('worker_end_tstamp', time.time()) + _add_logs(call_status, task) + call_status.send_finish_event() + finally: + # One worker process runs every call of the chunk, each with a + # pipe of its own. Closed here rather than whenever the garbage + # collector reaches them, which a reference cycle can delay + for conn in (handler_conn, jobrunner_conn): + if conn is None: + continue + try: + conn.close() + except Exception: + logger.debug( + 'Could not close a JobRunner pipe', exc_info=True + ) logger.info("Finished") diff --git a/lithops/worker/jobrunner.py b/lithops/worker/jobrunner.py index 5ec190c7d..dc4501ddf 100644 --- a/lithops/worker/jobrunner.py +++ b/lithops/worker/jobrunner.py @@ -320,14 +320,19 @@ def _write_exception(self) -> None: except Exception as pickle_exception: # Shockingly often, modules like subprocess don't properly call # the base Exception.__init__, which results in them being - # unpickleable. Report the pieces that do pickle instead of - # losing the exception altogether + # unpickleable. The traceback object holds that same exception, + # so it does not pickle either. The text of the stack is what + # the client can keep self.stats.write("exc_pickle_fail", True) + message = str(exc_value) + frames = ''.join(traceback.format_tb(exc_traceback)) + if frames: + message = f'{message}\n{frames}' pickled_exc = pickle.dumps({ 'exc_type': str(exc_type), - 'exc_value': str(exc_value), - 'exc_traceback': exc_traceback, - 'pickle_exception': pickle_exception, + 'exc_value': message, + 'exc_traceback': None, + 'pickle_exception': str(pickle_exception), }) pickle.loads(pickled_exc) From 9ee7837f83a190c6ac762ad9ebaff4bb14e18248 Mon Sep 17 00:00:00 2001 From: JosepSampe Date: Wed, 23 Sep 2026 20:25:46 +0200 Subject: [PATCH 2/5] Update multiprocessing --- CHANGELOG.md | 27 +- lithops/executors.py | 45 +- lithops/future.py | 10 +- lithops/invokers.py | 35 + lithops/localhost/config.py | 15 +- lithops/monitoring/backends/aws_sqs/status.py | 33 +- .../monitoring/backends/azure_queue/status.py | 13 +- .../monitoring/backends/gcp_pubsub/status.py | 49 +- .../monitoring/backends/rabbitmq/rabbitmq.py | 23 +- .../monitoring/backends/rabbitmq/status.py | 16 +- lithops/monitoring/backends/redis/status.py | 16 +- .../monitoring/backends/storage/storage.py | 52 +- lithops/monitoring/job_monitor.py | 15 +- lithops/monitoring/monitor.py | 144 +++- lithops/monitoring/status.py | 179 ++++- lithops/multiprocessing/connection.py | 47 +- lithops/multiprocessing/managers.py | 66 +- lithops/multiprocessing/pool.py | 190 +++-- lithops/multiprocessing/process.py | 13 +- lithops/multiprocessing/queues.py | 20 +- lithops/multiprocessing/sharedctypes.py | 31 +- lithops/multiprocessing/synchronize.py | 20 +- lithops/multiprocessing/util.py | 103 ++- lithops/tests/mp_fakeredis.py | 66 +- lithops/tests/test_executors.py | 89 ++- lithops/tests/test_future.py | 42 ++ lithops/tests/test_invokers.py | 31 + lithops/tests/test_localhost.py | 30 + lithops/tests/test_monitor.py | 713 +++++++++++++++++- lithops/tests/test_multiprocessing.py | 448 ++++++++++- lithops/tests/test_standalone.py | 5 + lithops/tests/test_worker.py | 101 ++- lithops/worker/handler.py | 15 +- lithops/worker/jobrunner.py | 6 +- 34 files changed, 2406 insertions(+), 302 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 36e35c17e..2f41a2826 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -19,6 +19,11 @@ - [Core] Stopping an executor now waits for the invocations already in flight instead of returning while its invoker threads still run. - [Monitoring] Reorganised job monitoring as pluggable backends: the message backends now delete their queue on cleanup instead of on every `stop()`, so a later `map()` can reuse it, and the storage backend lists only the prefixes of the jobs it still watches. - [Monitoring] Status lines (Pending/Running/Done) are now logged every 30s instead of on every activation. +- [Monitoring] The RabbitMQ queue is no longer auto-deleted when its consumer goes away. It is deleted on cleanup, and expires after 24 hours unused if the client dies first. +- [Monitoring] A status message too big for the service (Azure Queue 64 KiB, SQS 256 KiB) leaves the task log out, and the rest of the status is then read from storage if it still does not fit. The logs of nested executors are not kept by the client either. +- [Core] `wait()` with a zero or negative `timeout` now raises `TimeoutError` right away if there are calls left, instead of waiting for ever, and only ends the jobs it waited on. +- [Core] A plain list or tuple of futures passed as `iterdata`, or as the data of `call_async()`, is now a chain: the function receives their results, not the `ResponseFuture` objects. +- [Worker] A function that raises `SystemExit` or `KeyboardInterrupt` now has it reported as its exception and re-raised by the client, as `concurrent.futures` does. - [Multiprocessing] Manager proxies now follow the standard library API more closely, and `Manager()` returns a started manager instead of the class itself. - [Multiprocessing] Shared objects now refresh their expiry when read, not only when written, and connection polling backs off from 1ms instead of waiting a fixed 100ms. - [Multiprocessing] `imap()` and `imap_unordered()` now default to the configured chunksize. @@ -35,6 +40,10 @@ - [Core] Fixed executor IDs repeating in a process whose environment is reset between executors. - [Core] Fixed `wait()` watching futures of another executor with a monitor that never sees them, leaving behind the monitors it started, and raising `TypeError` from `signal.alarm()` on a fractional timeout. - [Core] Fixed `result()` returning `None` instead of re-raising when the call had already failed. +- [Core] Fixed `wait()` deleting a job's temporary data as soon as one of its calls was done, losing the results of the others still in storage. +- [Core] Fixed a failed or timed-out `wait()` deleting the data and dropping the queued calls of every job of the executor instead of the ones it waited on, and ignoring `clean_jobs`. +- [Core] Fixed `get_result()` raising `TypeError` when given a single future. +- [Core] Fixed a function's `sys.exit()` code being lost on the client, which then exited with status 0. - [Core] Fixed module inspection crashing on a function whose `__module__` is `None`, and `SerializeIndependent` appending `lithops` to the preinstalled module list on every job. - [Core] Fixed a hand-built `FuturesList` raising `AttributeError` instead of creating its executor, and pickling one detaching it from the executor it has. - [Core] Fixed `find_free_port()` setting `SO_REUSEADDR` after the bind. @@ -47,6 +56,12 @@ - [Job] Fixed the last byte of an object being left out of its partitions, and folder markers being counted as objects, returning empty partitions. - [Monitoring] Fixed a lost status message or an unread stored status turning into a bogus timeout, hanging `wait()` for ever, or one storage error being enough to declare a timeout. - [Monitoring] Fixed a nested executor publishing statuses to a queue nobody declares, and failed RabbitMQ publishes being dropped with nothing in the log. +- [Monitoring] Fixed the first statuses of a `map()` issued after a `wait()` being lost: RabbitMQ had deleted the queue, and the SQS, Pub/Sub and Azure long poll of the stopped monitor swallowed them, leaving the calls to the storage sweep. +- [Monitoring] Fixed worker tokens leaking on the last, partial chunk of a job, on a timed-out call, on a call listed as done before its start mark, and on the final storage sweep, which could leave a later `map()` waiting for ever with a small `max_workers`. +- [Monitoring] Fixed two threads applying statuses at once handing back two tokens for one worker, or putting a finished call back to running. +- [Monitoring] Fixed the remote invoker deleting its queue while its calls still published to it, which retried every status five times and recreated queues and topics from the workers. +- [Monitoring] Fixed Azure Queue statuses over 64 KiB, such as those carrying a long log, always failing, and Pub/Sub making an admin request per call. +- [Monitoring] Fixed the statuses of nested executors piling up in the client, logs included, until 100k of them. - [Redis] Fixed `put_object()` rejecting file-like objects, which made `upload_file()` always fail, and `head_object()` reporting every key as missing on Redis 7 and up, where the `DEBUG OBJECT` command it relied on is disabled. - [Redis] Fixed `list_objects()` returning the object bodies instead of their keys and sizes and not skipping keys whose value is gone, `head_bucket()` returning a bool instead of the bucket metadata, and `delete_objects()` raising on an empty list. - [Redis] Fixed the `bytes=L-` form of the `Range` argument raising `ValueError` and `bytes=-N` returning a single byte instead of the last N, and a ranged read of a missing key returning an empty result instead of raising. @@ -68,12 +83,20 @@ - [Multiprocessing] Fixed a closed `Pool` leaving the monitor and invoker threads of its executor running, and the remote log feed keeping the interpreter alive at exit. - [Multiprocessing] Fixed `AsyncResult.get()` raising the builtin `TimeoutError` instead of `multiprocessing.TimeoutError`. - [Multiprocessing] Fixed `current_process()` in a worker creating an executor and a Redis client just to read a name, and `set_parameter()` rewriting the defaults it falls back to. +- [Multiprocessing] Fixed a `Pool` result that timed out or failed breaking the pool: it marked the calls failed and deleted the data of the other pending results. +- [Multiprocessing] Fixed `Pool` callbacks only running from `get()`, and again on every `get()`, instead of once when the task completes. +- [Multiprocessing] Fixed `Queue.get_nowait()` and `get(timeout=...)` blocking for ever when another consumer took the last item. +- [Multiprocessing] Fixed `Process.join(timeout)` raising and marking the process failed instead of returning. +- [Multiprocessing] Fixed shared objects being deleted in use after an hour, when their reference count expired, and pipe and queue messages never expiring. +- [Multiprocessing] Fixed another thread re-entering an `RLock` held by a different thread, a timed-out `Condition.wait()` taking the next `notify()`, and locks losing their expiry after the first release. +- [Multiprocessing] Fixed extending or repeating a shared list past about 8000 items failing, `Listener.close()` closing the shared Redis client, and an out-of-range `Array` index raising `TypeError`. +- [Multiprocessing] Added the `n` argument of `Condition.notify()`. - [Localhost] Fixed the v2 job manager spinning a full core: on a job cleared mid-task that left a latch closed, and while an invocation was queueing. - [Localhost] Fixed a partial `clear()` tearing down the consumers, tasks and latches of other jobs. - [Localhost] Fixed a task starting after `stop()`, leaving a process nobody kills, and two concurrent `invoke()` calls clearing each other's in-progress flag. - [Localhost] Fixed the v2 container being removed while other jobs were still running in it. - [Localhost] Fixed v1 and v2 sharing one runner file, so a job could run under the other version's runner, and the runner exiting with success on an unknown command or a crash. -- [Localhost] Fixed a container image whose name starts with `python`, such as `python:3.12`, being run as a local interpreter. +- [Localhost] Fixed a container image whose name starts with `python`, such as `python:3.12`, being run as a local interpreter, without taking free-threaded, debug or `pythonw` interpreters for images. - [Standalone] Fixed a dict race that killed the budget keeper and left the VM running. - [Standalone] Fixed a file descriptor leak of the runner log, one per task. - [Standalone] Fixed the worker `/stop` endpoint iterating the process map while it changed, and `cancel_job_process()` raising on an emptied queue or a job with no queue. @@ -84,6 +107,8 @@ - [Storage] Fixed `delete_cloudobjects()` deleting the keys of one bucket from another when the objects spanned several, and deleting part of the list before rejecting a foreign object. - [Storage] Fixed `CloudFileProxy.listdir()` returning nothing for its default argument. - [Worker] Fixed the remote invoker returning before its invocations in flight were done. +- [Worker] Fixed an exception that does not pickle being reported as a success with no result, and `sys.exit()` in a function crashing `get_result()` with a `KeyError`. +- [Worker] Fixed timeouts and out-of-memory kills showing an internal traceback, and a failed start report leaving the function running while the call was reported failed. - [Worker] Fixed the function process being aborted on macOS from the second call on, by setting Apple's fork-safety flag, and one killed by the OOM killer, or by any signal, being reported as a missing result. - [Worker] Fixed the non-Unix worker pool sharing one task object across its calls, mixing up their ids, data and logs, by spawning a process per worker. - [Azure] Fixed the `az` CLI calls deadlocking when a command filled the stderr pipe. diff --git a/lithops/executors.py b/lithops/executors.py index b0d33d932..22958c953 100644 --- a/lithops/executors.py +++ b/lithops/executors.py @@ -103,6 +103,15 @@ def _missing_plotting_extra(method_name: str) -> ModuleNotFoundError: ) +def _output_settled(future) -> bool: + """ + Whether nothing is left to read from storage for this call: its result + was downloaded or it produced none, it failed, or it handed back + futures of its own + """ + return future.done or future.futures + + def _group_futures_by_job( futures: List[Any] ) -> List[Tuple[str, str, List[Any], List[Any]]]: @@ -449,7 +458,7 @@ def _cleanup_jobs(self, futures, exception=None, force=False): self.compute_handler.clear(present_jobs) else: self.compute_handler.clear(present_jobs, exception=exception) - self.clean(clean_cloudobjects=False, force=force) + self.clean(fs=futures, clean_cloudobjects=False, force=force) def _stop_monitor_if_idle(self, extra_fs=None): """ @@ -769,12 +778,17 @@ def wait( self._cleanup_jobs(futures) except (KeyboardInterrupt, Exception) as e: - self.invoker.stop(wait=True) + if isinstance(e, KeyboardInterrupt): + self.invoker.stop(wait=True) + else: + # Only the jobs waited on end here. Another job of this + # executor may still have calls queued for a free worker + self.invoker.discard_pending({f.job_key for f in futures}) self.job_monitor.remove(futures) for future in futures: future._set_exception() self._stop_monitor_if_idle(futures) - if self.data_cleaner: + if do_clean: self._cleanup_jobs(futures, exception=e, force=True) raise @@ -808,7 +822,7 @@ def get_result( :return: The result of the future/s """ pending_to_read = ( - len(fs) if fs + len(self._as_future_list(fs)) if fs else sum(1 for f in self.futures if not f._read and not f.futures) ) @@ -961,11 +975,24 @@ def clean( }) futures = self._as_future_list(fs or self.futures) - present_jobs = { - create_job_key(f.executor_id, f.job_id) - for f in futures - if (f.executor_id.count('-') == 1 and f.done) or force - } + if force: + present_jobs = { + create_job_key(f.executor_id, f.job_id) for f in futures + } + else: + # A job's data is one prefix, so it goes only once no call of + # the job, including the ones not passed here, still has a + # result to read from it + unread_jobs = { + create_job_key(f.executor_id, f.job_id) + for f in list(self.futures) + list(futures) + if not _output_settled(f) + } + present_jobs = { + create_job_key(f.executor_id, f.job_id) + for f in futures + if f.executor_id.count('-') == 1 and f.done + } - unread_jobs jobs_to_clean = present_jobs - self.cleaned_jobs if jobs_to_clean: diff --git a/lithops/future.py b/lithops/future.py index 4cd6261a6..a564a152e 100644 --- a/lithops/future.py +++ b/lithops/future.py @@ -277,6 +277,14 @@ def _raise_call_exception(self, throw_except): except Exception: pass fn_exc.args = (fn_exc.args[1],) + # tblib rebuilds a SystemExit from its args and leaves code at + # None, which would end the client with status 0 whatever the + # function passed to sys.exit() + if isinstance(fn_exc, SystemExit) and fn_exc.code is None \ + and fn_exc.args: + fn_exc.code = ( + fn_exc.args[0] if len(fn_exc.args) == 1 else fn_exc.args + ) else: fn_exctype = Exception fn_exc = Exception(self._exception['exc_value']) @@ -452,7 +460,7 @@ def status( if 'new_futures' in self._call_status and not self._new_futures: self._resolve_new_futures() - elif self._call_status['func_result_size'] == 0: + elif self._call_status.get('func_result_size', 0) == 0: self._produce_output = False if 'result' in self._call_status: diff --git a/lithops/invokers.py b/lithops/invokers.py index c7ef97d1c..388c26e4e 100644 --- a/lithops/invokers.py +++ b/lithops/invokers.py @@ -309,6 +309,13 @@ def stop(self, wait: bool = False): """ pass + def discard_pending(self, job_keys): + """ + Drops the calls of the given jobs not invoked yet. Only an invoker + that queues calls has any + """ + pass + class BatchInvoker(Invoker): """ @@ -540,6 +547,30 @@ def _invoke_job_remote(self, job): return raise Exception('Unable to spawn remote invoker') + def _empty_token_bucket(self): + while True: + try: + self.job_monitor.token_bucket_q.get(block=False) + except queue.Empty: + return + + def discard_pending(self, job_keys): + """ + Drops the calls of the given jobs that are still waiting for a + worker, leaving the queued calls of every other job in place + """ + kept = [] + while True: + try: + item = self.pending_calls_q.get(block=False) + except queue.Empty: + break + job, _ = item + if job is None or job.job_key not in job_keys: + kept.append(item) + for item in kept: + self.pending_calls_q.put(item) + def _drain_token_bucket(self): """ Takes back the tokens left over by previous jobs, one per worker that @@ -595,6 +626,10 @@ def _invoke_job(self, job): prefix = log_prefix(job.executor_id, job.job_id) if not self.should_run: + # Tokens a monitor handed back after the stop belong to workers + # this restart no longer counts, and would each invoke one more + # worker than max_workers allows + self._empty_token_bucket() self.running_workers = 0 self.should_run = True self._start_async_invokers() diff --git a/lithops/localhost/config.py b/lithops/localhost/config.py index 22422a08d..3cae0ef0c 100644 --- a/lithops/localhost/config.py +++ b/lithops/localhost/config.py @@ -30,12 +30,10 @@ LOCALHOST_EXECUTION_TIMEOUT = 3600 _WINDOWS_PATH = re.compile(r'^(?:[A-Za-z]:[\\/]|\\\\)') -# Interpreters like python, python3, python3.12, python.exe — not docker tags -# such as python:3.12. -_PYTHON_INTERPRETER = re.compile( - r'^python(\d+(\.\d+)*)?(\.exe)?$', - re.IGNORECASE, -) +# Interpreters like python3.12, python3.13t, python3-intel64 or pythonw.exe. +# Docker tags and repositories such as python:3.12 or registry/python always +# carry a ':' or a '/', which an interpreter name never does. +_PYTHON_INTERPRETER = re.compile(r'^python[^:/\\]*$', re.IGNORECASE) class LocalhostEnvironment(Enum): @@ -53,7 +51,10 @@ def get_environment(runtime_name: str) -> LocalhostEnvironment: if ( runtime_name.startswith('/') or _WINDOWS_PATH.match(runtime_name) is not None - or _PYTHON_INTERPRETER.match(basename) is not None + or ( + '/' not in runtime_name + and _PYTHON_INTERPRETER.match(basename) is not None + ) ): return LocalhostEnvironment.DEFAULT return LocalhostEnvironment.CONTAINER diff --git a/lithops/monitoring/backends/aws_sqs/status.py b/lithops/monitoring/backends/aws_sqs/status.py index 4adfe845a..dcef8abb8 100644 --- a/lithops/monitoring/backends/aws_sqs/status.py +++ b/lithops/monitoring/backends/aws_sqs/status.py @@ -12,15 +12,11 @@ # limitations under the License. # -import logging from functools import cached_property from lithops.monitoring.backends.aws_sqs import aws_sqs as sqs_backend -from lithops.monitoring.monitor import is_named_error from lithops.monitoring.status import MessageCallStatus -logger = logging.getLogger(__name__) - class SqsCallStatus(MessageCallStatus): """ @@ -29,6 +25,7 @@ class SqsCallStatus(MessageCallStatus): """ service_name = 'SQS' + MAX_MESSAGE_SIZE = 256 * 1024 def __init__(self, job, internal_storage): super().__init__(job, internal_storage) @@ -51,23 +48,14 @@ def _queue_url(self, name): """ The URL of a queue by name, looked up once per call. - The monitor of the executor created the queue before any worker was - invoked, so this normally just resolves it; it is created here only - when it is really not there, which is what a status published to an - executor further up the chain can run into + The monitor that reads the queue created it before any worker was + invoked. One that is not there belongs to a reader that is gone, and + creating it again would leave a queue nobody deletes """ url = self._urls.get(name) if url: return url - try: - url = self.client.get_queue_url(QueueName=name)['QueueUrl'] - except Exception as exc: - if not is_named_error( - exc, 'QueueDoesNotExist', 'NonExistentQueue' - ): - raise - logger.debug(f'The SQS queue {name} is not there; creating it') - url = self.client.create_queue(QueueName=name)['QueueUrl'] + url = self.client.get_queue_url(QueueName=name)['QueueUrl'] self._urls[name] = url return url @@ -75,9 +63,8 @@ def close(self) -> None: self._urls.clear() super().close() - def _publish(self, payload: str) -> None: - for name in self._targets(): - self.client.send_message( - QueueUrl=self._queue_url(name), - MessageBody=payload, - ) + def _publish_to(self, target: str, payload: str) -> None: + self.client.send_message( + QueueUrl=self._queue_url(target), + MessageBody=payload, + ) diff --git a/lithops/monitoring/backends/azure_queue/status.py b/lithops/monitoring/backends/azure_queue/status.py index 84c3b482d..9e5e6b4da 100644 --- a/lithops/monitoring/backends/azure_queue/status.py +++ b/lithops/monitoring/backends/azure_queue/status.py @@ -27,6 +27,11 @@ class AzureQueueCallStatus(MessageCallStatus): """ service_name = 'Azure Queue' + #: The service takes 64 KiB per message, measured once the SDK has + #: encoded it: XML-escaped text by default, base64 when the queue client + #: is configured so, which is 4/3 of the text. Three quarters of the + #: limit fits either way + MAX_MESSAGE_SIZE = 48 * 1024 def __init__(self, job, internal_storage): super().__init__(job, internal_storage) @@ -47,9 +52,6 @@ def service(self): ), ) - def _targets(self): - return [azure_queue_name(name) for name in super()._targets()] - def _queue(self, name): name = azure_queue_name(name) client = self._queues.get(name) @@ -71,6 +73,5 @@ def close(self) -> None: self._queues.clear() super().close() - def _publish(self, payload: str) -> None: - for name in self._targets(): - self._queue(name).send_message(payload) + def _publish_to(self, target: str, payload: str) -> None: + self._queue(target).send_message(payload) diff --git a/lithops/monitoring/backends/gcp_pubsub/status.py b/lithops/monitoring/backends/gcp_pubsub/status.py index 8baa153ce..e88bbba25 100644 --- a/lithops/monitoring/backends/gcp_pubsub/status.py +++ b/lithops/monitoring/backends/gcp_pubsub/status.py @@ -12,16 +12,12 @@ # limitations under the License. # -import logging from functools import cached_property from lithops.monitoring.backends.gcp_pubsub import gcp_pubsub as pubsub_backend from lithops.monitoring.backends.gcp_pubsub.gcp_pubsub import _topic_path -from lithops.monitoring.monitor import is_named_error from lithops.monitoring.status import MessageCallStatus -logger = logging.getLogger(__name__) - class GcpPubsubCallStatus(MessageCallStatus): """ @@ -30,13 +26,13 @@ class GcpPubsubCallStatus(MessageCallStatus): """ service_name = 'Pub/Sub' + MAX_MESSAGE_SIZE = 10 * 1000 * 1000 def __init__(self, job, internal_storage): super().__init__(job, internal_storage) self.project = ( self.config.get('gcp_pubsub') or {} ).get('project_name') - self._topics = set() @cached_property def publisher(self): @@ -54,38 +50,11 @@ def build(): return self.obtain_client('publisher', build) - def _ensure_topic(self, name): - """ - The path of a topic, created if it is not there. - - The monitor of the executor created the topic before any worker was - invoked, so AlreadyExists is the normal answer here; anything else - is a real failure and is left for _send() to retry and report - """ - path = _topic_path(self.project, name) - if path in self._topics: - return path - try: - self.publisher.create_topic(name=path) - except Exception as exc: - if not is_named_error(exc, 'AlreadyExists', 'PermissionDenied'): - raise - if is_named_error(exc, 'PermissionDenied'): - # A worker that may publish but not create topics is fine, - # as long as the topic is already there - logger.debug( - f'Not allowed to create the Pub/Sub topic {name}; ' - 'assuming it exists' - ) - self._topics.add(path) - return path - - def close(self) -> None: - self._topics.clear() - super().close() - - def _publish(self, payload: str) -> None: - data = payload.encode('utf-8') - for name in self._targets(): - future = self.publisher.publish(self._ensure_topic(name), data) - future.result(timeout=10) + def _publish_to(self, target: str, payload: str) -> None: + # The monitor that reads the topic created it before any worker was + # invoked. One that is not there belongs to a reader that is gone, + # and the NotFound is what tells the caller so + future = self.publisher.publish( + _topic_path(self.project, target), payload.encode('utf-8') + ) + future.result(timeout=10) diff --git a/lithops/monitoring/backends/rabbitmq/rabbitmq.py b/lithops/monitoring/backends/rabbitmq/rabbitmq.py index a3b0a083e..ba07678a0 100644 --- a/lithops/monitoring/backends/rabbitmq/rabbitmq.py +++ b/lithops/monitoring/backends/rabbitmq/rabbitmq.py @@ -37,6 +37,11 @@ class RabbitmqMonitor(PollingMessageMonitor): cost a round trip per message. """ + #: How long the broker keeps the queue once nothing consumes from or + #: declares it, in seconds. cleanup() deletes it; this is only for a + #: client that died before getting there + QUEUE_EXPIRES = 24 * 3600 + def __init__( self, executor_id, @@ -70,22 +75,30 @@ def __init__( def _create_resources(self): """ - Opens the connection and declares the queue the workers publish to + Opens the connection and declares the queue the workers publish to. + + Not an auto-delete queue: the broker would delete it as soon as a + stopped monitor cancels its consumer, and whatever the workers still + running publish before the next monitor declares it again would be + dropped. cleanup() deletes it instead """ logger.debug( f'{log_prefix(self.executor_id)} - Creating RabbitMQ queue {self.queue}' ) self.connection = pika.BlockingConnection(self.pikaparams) channel = self.connection.channel() - channel.queue_declare(queue=self.queue, auto_delete=True) + channel.queue_declare( + queue=self.queue, + auto_delete=False, + arguments={'x-expires': self.QUEUE_EXPIRES * 1000}, + ) channel.close() def _consume(self, timeout): """ Returns the consumer generator, opening it on the first call and - after a connection has been lost. The queue is declared again on - the way, since an auto-delete queue is gone once its last consumer - has left + after a connection has been lost, in which case the queue is + declared again on the way """ if self.consumer is None: if self.connection is None or self.connection.is_closed: diff --git a/lithops/monitoring/backends/rabbitmq/status.py b/lithops/monitoring/backends/rabbitmq/status.py index c6fa5d808..0f936d0ef 100644 --- a/lithops/monitoring/backends/rabbitmq/status.py +++ b/lithops/monitoring/backends/rabbitmq/status.py @@ -95,15 +95,15 @@ def close(self) -> None: self._drop_channel() self._amqp = None - def _publish(self, payload: str) -> None: + def _publish_to(self, target: str, payload: str) -> None: + # Through the default exchange, which drops a message for a queue + # that is not there rather than creating it try: - channel = self._channel() - for queue in self._targets(): - channel.basic_publish( - exchange='', - routing_key=queue, - body=payload - ) + self._channel().basic_publish( + exchange='', + routing_key=target, + body=payload + ) except Exception: # The connection is broken, or was never opened. Dropped here so # that the retry of _send(), and the next call of this worker, diff --git a/lithops/monitoring/backends/redis/status.py b/lithops/monitoring/backends/redis/status.py index 02c5dd1b9..d5daaad96 100644 --- a/lithops/monitoring/backends/redis/status.py +++ b/lithops/monitoring/backends/redis/status.py @@ -28,6 +28,11 @@ class RedisCallStatus(MessageCallStatus): service_name = 'Redis' + #: How long a list that only best-effort publishes feed outlives the + #: last of them. A push onto a list that was deleted creates it again, + #: and nothing would come back to delete that one + BEST_EFFORT_TTL = 3600 + @cached_property def client(self): """ @@ -41,6 +46,11 @@ def client(self): lambda: redis_backend.redis_client(self.config.get('redis') or {}), ) - def _publish(self, payload: str) -> None: - for queue in self._targets(): - self.client.rpush(queue, payload) + def _publish_to(self, target: str, payload: str) -> None: + self.client.rpush(target, payload) + + def _publish_best_effort(self, target: str, payload: str) -> None: + pipe = self.client.pipeline() + pipe.rpush(target, payload) + pipe.expire(target, self.BEST_EFFORT_TTL) + pipe.execute() diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py index ca7974202..f61bfd665 100644 --- a/lithops/monitoring/backends/storage/storage.py +++ b/lithops/monitoring/backends/storage/storage.py @@ -23,6 +23,7 @@ _future_id, _is_finished, _is_started, + _status_id, ) from lithops.utils import log_prefix @@ -80,6 +81,7 @@ def __init__( self.callids_done_processed_status = set() self._ready_pool = None self._last_blind_sweep = time.time() + self._final_sweep = False @classmethod def prepare_config(cls, config, internal_storage): @@ -206,7 +208,7 @@ def _generate_tokens(self, callids_running, callids_done): Hands a token back to the invoker for every worker that finished the whole chunk of calls it was given """ - if not self.generate_tokens or not self.should_run: + if not self.generate_tokens or not self._releases_tokens(): return running_new = ( @@ -234,6 +236,20 @@ def _generate_tokens(self, callids_running, callids_done): # can be looked up without picking a call id back out of the set self.worker_job.setdefault(worker_id, callid_done[1]) + self._release_free_workers() + + self.callids_running_processed.update(running_new) + self.callids_done_processed.update(attributed) + + def _release_free_workers(self): + """ + Hands a token back for every worker whose calls are all done. + + A listing carries no status, so how many calls a worker was given + is worked out from any one of them: the invoker hands the calls out + in consecutive chunks from call 0, so the chunk a call falls in, and + the number of calls of the job, say how long that chunk is + """ present_jobs = self.present_jobs for worker_id, done_calls in self.callids_done_worker.items(): if worker_id in self.workers_done: @@ -242,15 +258,38 @@ def _generate_tokens(self, callids_running, callids_done): if job_id is None or job_id not in present_jobs: continue chunksize = self.job_chunksize.get(job_id) - if chunksize is None or len(done_calls) < chunksize: + if chunksize is None: + continue + worker_calls = self._worker_calls( + *next(iter(done_calls)), chunksize + ) + if len(done_calls) < worker_calls: continue self.workers_done.add(worker_id) - if not self.should_run: + if not self._releases_tokens(): break self.token_bucket_q.put('#') - self.callids_running_processed.update(running_new) - self.callids_done_processed.update(attributed) + def _releases_tokens(self): + """ + Whether a worker found free is handed back to the invoker. The final + sweep runs once the monitor is stopped and still counts: a worker it + finds free belongs to a job no later monitor watches, and its token + would otherwise be gone for the rest of the session + """ + return self.should_run or self._final_sweep + + def _release_timed_out_worker(self, call_status): + worker_id = call_status.get('activation_id') + if not self.generate_tokens or worker_id is None: + return + if call_status['executor_id'] != self.executor_id: + return + self.callids_done_worker.setdefault(worker_id, set()).add( + _status_id(call_status) + ) + self.worker_job.setdefault(worker_id, call_status['job_id']) + self._release_free_workers() def _poll_and_process_job_status(self): """ @@ -304,6 +343,7 @@ def run(self): # One last sweep, so that statuses written between the final poll # and the stop are not lost. The storage may already be gone + self._final_sweep = True try: self._poll_and_process_job_status() except Exception as e: @@ -311,6 +351,8 @@ def run(self): f'{log_prefix(self.executor_id)} - The final status sweep ' f'did not go through: {e}' ) + finally: + self._final_sweep = False self._print_status_log(force=True) self._shutdown_ready_pool() diff --git a/lithops/monitoring/job_monitor.py b/lithops/monitoring/job_monitor.py index 0fdf6d719..5e056d741 100644 --- a/lithops/monitoring/job_monitor.py +++ b/lithops/monitoring/job_monitor.py @@ -62,6 +62,7 @@ def __init__( self.token_bucket_q = queue.Queue() self.monitor = None self.job_chunksize = {} + self.job_total_calls = {} # Metrics are produced from the statuses the monitor reads, so the # telemetry of the executor is resolved here and handed to every @@ -79,7 +80,10 @@ def start(self, fs, job_id=None, chunksize=None, generate_tokens=False): """ if job_id: self.job_chunksize[job_id] = chunksize + self.job_total_calls[job_id] = len(fs) + # A monitor prepare() just built has not started yet, and is the one + # the workers of this job already report to if not self.monitor or self._thread_finished(): self._spawn_monitor(generate_tokens) elif generate_tokens: @@ -94,8 +98,13 @@ def prepare(self): """ Creates backend resources (queues, keys) before workers are invoked, so the first status is not published into nowhere. + + A monitor a wait() stopped is replaced here too, and not in start(), + which runs once the workers are already reporting: its thread may + still be in a read that takes the first statuses of the new job to + the grave, and RabbitMQ may already have deleted its queue """ - if self.monitor is None: + if self.monitor is None or self._thread_finished(): self._spawn_monitor(generate_tokens=False) def _spawn_monitor(self, generate_tokens): @@ -103,6 +112,7 @@ def _spawn_monitor(self, generate_tokens): # thread is waited for first: two threads reading the same queue # would split the statuses between them, and the one on its way out # takes what it reads to the grave + previous = self.monitor self._join_monitor() monitor_config = self.MonitorClass.prepare_config( self.config, self.internal_storage @@ -120,9 +130,12 @@ def _spawn_monitor(self, generate_tokens): generate_tokens=generate_tokens, config=monitor_config ) + self.monitor.job_total_calls = self.job_total_calls # Attached before the caller adds any future, so that no status # can reach the monitor while it is still pointing at the no-op self.monitor.attach_telemetry(self.telemetry) + if previous is not None: + self.monitor.adopt_held_status(previous) def _thread_finished(self): """ diff --git a/lithops/monitoring/monitor.py b/lithops/monitoring/monitor.py index 58922b15b..f562a66e1 100644 --- a/lithops/monitoring/monitor.py +++ b/lithops/monitoring/monitor.py @@ -24,6 +24,11 @@ from tblib import pickling_support +from lithops.monitoring.status import ( + LOGS_FIELD, + PARTIAL_STATUS_KEY, + chunk_call_count, +) from lithops.telemetry import NOOP as NOOP_TELEMETRY from lithops.telemetry.metrics import OUTCOME_CHAINED, OUTCOME_TIMEOUT from lithops.utils import _future_id, log_prefix, monitoring_queue_name @@ -106,6 +111,12 @@ class Monitor(threading.Thread): #: How many statuses that arrived before their future may be held MAX_HELD_STATUS = 100_000 + #: How long a held status may wait for its future beyond the longest + #: execution timeout of the tracked futures. The future of a nested call + #: comes to light in the status of the call that returned it, which + #: finishes within its own execution timeout or is timed out + HELD_STATUS_SLACK = 300 + #: Where the metrics of every call go. A class attribute, so that a #: monitor nobody attached telemetry to is safe rather than broken, #: and so that a backend that forgets to call super().__init__() does @@ -140,6 +151,9 @@ def __init__(self, executor_id, self._stopped = threading.Event() self.token_bucket_q = token_bucket_q self.job_chunksize = job_chunksize + # Calls per job of this executor, which tells the size of the last + # chunk of a job. Filled in by JobMonitor, which shares its own + self.job_total_calls = {} self.generate_tokens = generate_tokens self.config = config self.daemon = True @@ -167,6 +181,7 @@ def __init__(self, executor_id, self._held_lock = threading.Lock() self._held_overflow_logged = False self._held_may_match = False + self._max_execution_timeout = 0 # When a status last arrived. A channel that is delivering has # nothing for the storage sweep to recover self._last_message_tstamp = time.time() @@ -244,6 +259,12 @@ def add_futures(self, fs): self.present_jobs = self.present_jobs | { future.job_id for future in fs } + self._max_execution_timeout = max( + [self._max_execution_timeout] + [ + getattr(future, 'execution_timeout', None) or 0 + for future in fs + ] + ) def remove_futures(self, fs): """ @@ -316,6 +337,37 @@ def cleanup(self): self._cleaned = True self._delete_resources() + def adopt_held_status(self, other): + """ + Takes over the statuses another monitor of the same queue was holding + for futures it did not track yet. Called on the monitor that replaces + it, before any future is added, so they are not lost with the old one + """ + with other._held_lock: + held, other._held_status = other._held_status, {} + if not held: + return + with self._held_lock: + self._held_status = {**held, **self._held_status} + self._held_may_match = True + + def _worker_calls(self, executor_id, job_id, call_id, chunksize): + """ + How many calls the worker that ran ``call_id`` was given, which is + the chunksize but for the last chunk of a job whose size is known + """ + total_calls = None + if executor_id == self.executor_id: + total_calls = self.job_total_calls.get(job_id) + return chunk_call_count(call_id, chunksize, total_calls) + + def _release_timed_out_worker(self, call_status): + """ + Counts a call that was timed out as done for the token bucket, so + that a worker that never reported back still hands its token back + once every other call of its chunk is done + """ + def attach_telemetry(self, telemetry): """ Points the monitor at the telemetry of its executor. Called by @@ -463,6 +515,7 @@ def _future_timeout_checker(self, futures=None): 'worker_end_tstamp': time.time(), } self._mark_ready(fut, call_status, OUTCOME_TIMEOUT) + self._release_timed_out_worker(call_status) def _print_status_log(self, force=False): """ @@ -528,16 +581,35 @@ def _hold_status(self, call_status): the status that tells this monitor the nested futures exist. A message is read once, so dropping it here would leave a future running for ever. Held by call id, so an __end__ supersedes the - __init__ of the same call + __init__ of the same call. + + A worker that waits on an executor of its own sends every status of + it here, most of which never match a future of this one. They are + held without their logs, which are most of their size and which the + future can do without, and they give way once too old to match """ + held = dict(call_status) + held.pop(LOGS_FIELD, None) + status_id = _status_id(held) + now = time.time() with self._held_lock: - self._held_status[_status_id(call_status)] = call_status + # Taken out first, so that the dict stays in order of arrival + # and the first key is always the oldest + self._held_status.pop(status_id, None) + self._held_status[status_id] = (now, held) self._held_may_match = True + + oldest = now - self._max_execution_timeout - self.HELD_STATUS_SLACK + while self._held_status: + first = next(iter(self._held_status)) + if self._held_status[first][0] >= oldest: + break + del self._held_status[first] + if len(self._held_status) <= self.MAX_HELD_STATUS: return # A status whose future never shows up would be held for the - # whole life of the executor, so the oldest ones give way. A - # dict keeps insertion order, so the first key is the oldest + # whole life of the executor, so the oldest ones give way while len(self._held_status) > self.MAX_HELD_STATUS: del self._held_status[next(iter(self._held_status))] if not self._held_overflow_logged: @@ -564,7 +636,7 @@ def _take_held_status(self): future = self.future_by_id(future_id) if future is None: continue - call_status = self._held_status.pop(future_id) + _tstamp, call_status = self._held_status.pop(future_id) if not _is_finished(future): ready.append(call_status) return tuple(ready) @@ -636,14 +708,21 @@ def _generate_tokens(self, call_status): """ if not self.generate_tokens or not self.should_run: return - - chunksize = call_status.get('chunksize') - if chunksize is None: - chunksize = self.job_chunksize.get(call_status['job_id']) - if chunksize is None: + # The statuses of a nested executor come this way too, and its + # workers were never counted by the invoker of this one + if call_status['executor_id'] != self.executor_id: return call_id = _status_id(call_status) + worker_calls = call_status.get('worker_calls') + if worker_calls is None: + chunksize = call_status.get('chunksize') + if chunksize is None: + chunksize = self.job_chunksize.get(call_status['job_id']) + if chunksize is None: + return + worker_calls = self._worker_calls(*call_id, chunksize) + worker_id = call_status['activation_id'] # The two threads that apply statuses both get here. The read of # the count and the decision to hand a token back have to be one @@ -656,7 +735,7 @@ def _generate_tokens(self, call_status): if ( worker_id not in self.workers_done - and len(done_for_worker) >= chunksize + and len(done_for_worker) >= worker_calls ): self.workers_done.add(worker_id) if self.should_run: @@ -674,11 +753,54 @@ def _apply_status_message(self, call_status): if not self._tag_future_as_running(call_status): self._hold_status(call_status) elif call_status['type'] == '__end__': + if call_status.get(PARTIAL_STATUS_KEY): + call_status = self._complete_partial_status(call_status) + if call_status is None: + return if self._tag_future_as_ready(call_status): self._generate_tokens(call_status) else: self._hold_status(call_status) + def _complete_partial_status(self, call_status): + """ + Swaps a status whose message left out what did not fit for the full + one the worker wrote to the storage before sending it. + + Only for a future that is tracked and not finished: one that is not + tracked yet is held, and comes back here once it is. Returns None + when the storage copy cannot be read; the call is then left running, + for the storage sweep or the timeout checker to pick up + """ + future = self.future_by_id(_status_id(call_status)) + if future is None or _is_finished(future): + return call_status + + stored = None + if self.internal_storage is not None: + try: + stored = self.internal_storage.get_call_status( + *_status_id(call_status) + ) + future._status_query_count += 1 + except Exception: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not read the ' + f'status of call {call_status["call_id"]} from the storage', + exc_info=True, + ) + if stored: + return stored + + # As an __init__, since that is all the future can be told + if not _is_started(future): + self._mark_running(future, dict(call_status, type='__init__')) + return None + + def _release_timed_out_worker(self, call_status): + if call_status.get('activation_id') is not None: + self._generate_tokens(call_status) + def _apply_recovered_status(self, future, call_status): if not super()._apply_recovered_status(future, call_status): return False diff --git a/lithops/monitoring/status.py b/lithops/monitoring/status.py index 1e62d6f94..91e1e7ce0 100644 --- a/lithops/monitoring/status.py +++ b/lithops/monitoring/status.py @@ -28,11 +28,30 @@ from lithops.utils import ( CURRENT_PY_VERSION, monitoring_queue_name, + remote_invoker_queue_name, sizeof_fmt, ) logger = logging.getLogger(__name__) +#: Set on a status message that left out fields the client cannot do without, +#: because the message service would not take them. The client reads the +#: full status back from the storage copy, written before the message +PARTIAL_STATUS_KEY = 'partial_status' + +#: Fields a message leaves out, in this order, when it does not fit. The logs +#: go first and alone, since the client can do without them; the rest carry +#: the outcome of the call, and dropping them makes the message partial +LOGS_FIELD = 'logs' +STORAGE_ONLY_FIELDS = ('result', 'exc_info', 'new_futures') + +_PROBE_ID = 'probe' +#: What the queue of a remote invoker adds to the queue of the executor it +#: invokes for +_REMOTE_INVOKER_SUFFIX = remote_invoker_queue_name(_PROBE_ID)[ + len(monitoring_queue_name(_PROBE_ID)): +] + #: Set to 0 to build a client per call instead of keeping one for the #: process. The escape hatch for a runtime where a client that outlives the #: call does not survive the fork of the next one @@ -43,6 +62,33 @@ _ATEXIT_REGISTERED = False +def is_remote_invoker_queue(name: str) -> bool: + """ + Whether a queue of the monitoring chain belongs to a remote invoker. + + The remote invoker deletes its queue once every chunk is invoked, long + before the calls finish, so publishing there is best effort + """ + return name.endswith(_REMOTE_INVOKER_SUFFIX) + + +def chunk_call_count(call_id: str, chunksize: int, total_calls: int = None): + """ + How many calls the worker that runs ``call_id`` was given. + + The invoker hands the calls out in consecutive chunks of ``chunksize`` + starting at call 0, so every chunk is full but the last one of the job. + Without the total, the chunksize is the best there is + """ + if not chunksize or not total_calls: + return chunksize + try: + first = int(call_id) // chunksize * chunksize + except (TypeError, ValueError): + return chunksize + return max(1, min(chunksize, total_calls - first)) + + def reuse_clients() -> bool: """ Whether one client serves every call of this process. @@ -141,7 +187,12 @@ def __init__(self, job: SimpleNamespace, internal_storage): 'call_id': job.call_id, 'job_id': job.job_id, 'executor_id': job.executor_id, - 'chunksize': job.chunksize + 'chunksize': job.chunksize, + # What frees the worker for the token bucket of the invoker: the + # last chunk of a job is usually shorter than the chunksize + 'worker_calls': chunk_call_count( + job.call_id, job.chunksize, getattr(job, 'total_calls', None) + ), } is_warm = os.environ.get('WARM_CONTAINER', '').lower() in { @@ -201,7 +252,7 @@ class MessageCallStatus(StorageCallStatus): which reaches the client faster, and falls back to Object Storage at the end. - Subclasses implement :meth:`_publish`. + Subclasses implement :meth:`_publish_to`. """ MAX_ATTEMPTS = 5 @@ -209,6 +260,10 @@ class MessageCallStatus(StorageCallStatus): MAX_RETRY_SLEEP = 5 service_name = 'message service' + #: Largest status the service takes in one message, in bytes of the + #: serialized JSON. None when there is no practical limit + MAX_MESSAGE_SIZE = None + def __init__(self, job: SimpleNamespace, internal_storage): super().__init__(job, internal_storage) # Clients this object built for itself, which nothing else uses and @@ -265,38 +320,100 @@ def _send(self) -> None: The storage copy is what the client reads back when the message is lost, which a message service that delivers at most once can do; see - MessageMonitor._storage_sweep() + MessageMonitor._storage_sweep(). A partial message sends the client + there right away, so in that case the copy is written first + """ + payload, partial = self._message_payload() + store = self.status['type'] == '__end__' + + if store and partial: + super()._send() + self._publish_to_chain(payload) + if store and not partial: + super()._send() + + def _message_payload(self): + """ + The status as the message carries it, and whether it is partial. + + The worker puts the logs of the call in its last status, and those + alone go past what Azure Queue takes in a message. They are left + out first, since the client can do without them; if the message is + still too big, so is what the storage copy holds anyway """ - dmpd_response_status = json.dumps(self.status) + payload = json.dumps(self.status) + limit = self.MAX_MESSAGE_SIZE + if limit is None or len(payload.encode('utf-8')) <= limit: + return payload, False + + status = dict(self.status) + status.pop(LOGS_FIELD, None) + payload = json.dumps(status) + if len(payload.encode('utf-8')) <= limit: + return payload, False + + for key in STORAGE_ONLY_FIELDS: + status.pop(key, None) + status[PARTIAL_STATUS_KEY] = True + logger.info( + f'The execution status does not fit in a {self.service_name} ' + 'message; the client reads it from the storage' + ) + return json.dumps(status), True + + def _publish_to_chain(self, payload: str) -> None: + """ + Publishes the status to every queue of the chain, each one on its own. + + The queues of the executors are retried: a status lost there leaves + the client with a call that finishes only through the storage sweep, + or, for a nested future, only at its execution timeout. The queue of + a remote invoker is tried once: the invoker deletes it as soon as + every chunk is invoked, and retrying there would only resend the + status to the queues that already have it + """ + targets = self._targets() + pending = [t for t in targets if not is_remote_invoker_queue(t)] exc = None for attempt in range(self.MAX_ATTEMPTS): - try: - self._publish(dmpd_response_status) - logger.info( - f"Execution status sent to {self.service_name} - " - f"Size: {sizeof_fmt(len(dmpd_response_status))}" - ) - exc = None + failed = [] + for target in pending: + try: + self._publish_to(target, payload) + except Exception as e: + exc = e + failed.append(target) + pending = failed + if not pending or attempt == self.MAX_ATTEMPTS - 1: break - except Exception as e: - exc = e - if attempt == self.MAX_ATTEMPTS - 1: - break - # Backed off, so that the attempts span a broker hiccup - # instead of being spent within the same second - time.sleep(min( - self.RETRY_SLEEP * (2 ** attempt), self.MAX_RETRY_SLEEP - )) - - if exc is not None: + # Backed off, so that the attempts span a broker hiccup + # instead of being spent within the same second + time.sleep(min( + self.RETRY_SLEEP * (2 ** attempt), self.MAX_RETRY_SLEEP + )) + + if pending: logger.error( f"Could not send the execution status to {self.service_name} " f"after {self.MAX_ATTEMPTS} attempts: {exc}" ) + else: + logger.info( + f"Execution status sent to {self.service_name} - " + f"Size: {sizeof_fmt(len(payload))}" + ) - if self.status['type'] == '__end__': - super()._send() + for target in targets: + if not is_remote_invoker_queue(target): + continue + try: + self._publish_best_effort(target, payload) + except Exception as e: + logger.debug( + f'Could not send the execution status to {target}, ' + f'which may be gone already: {e}' + ) def _targets(self) -> list: """ @@ -350,5 +467,17 @@ def _release_cached(self, *names: str) -> None: self._own_clients.discard(name) _release_client(client, self.service_name) - def _publish(self, payload: str) -> None: + def _publish_to(self, target: str, payload: str) -> None: + """ + Publishes a status to one queue of the chain. It must not create the + queue: the monitor that reads it did, and one that is not there + belongs to a reader that is gone + """ raise NotImplementedError + + def _publish_best_effort(self, target: str, payload: str) -> None: + """ + Publishes a status to a queue that may have been deleted already. + Override when a publish to a queue that is gone would bring it back + """ + self._publish_to(target, payload) diff --git a/lithops/multiprocessing/connection.py b/lithops/multiprocessing/connection.py index 9d7fffacd..a4c2a8e97 100644 --- a/lithops/multiprocessing/connection.py +++ b/lithops/multiprocessing/connection.py @@ -25,6 +25,7 @@ from . import util from . import config as mp_config from .errors import BufferTooShort +from .synchronize import _blpop from queue import Queue logger = logging.getLogger(__name__) @@ -280,6 +281,9 @@ class _RedisConnection(_ConnectionBase): """ _write = None _read = None + #: The reference of the queue this connection carries, if any, whose + #: counter is refreshed along with the list on every write + _ref = None def __init__(self, handle, readable=True, writable=True): super().__init__(handle, readable, writable) @@ -326,11 +330,6 @@ def __setstate__(self, state): def __len__(self): return self._client.llen(self._handle) - def _set_expiry(self, key): - logger.debug('Set key %s expiry time', key) - self._client.expire(key, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) - self._set_expiry = lambda key: None - def _close(self, _close=None): # Only the subscription belongs to this connection. The client is the # one every shared object of the process talks through, so closing it @@ -340,13 +339,41 @@ def _close(self, _close=None): self._pubsub = None def _listwrite(self, handle, buf): - self._set_expiry(handle) - return self._client.rpush(handle, buf) + # The expiry goes after the push, on every write: EXPIRE does nothing + # on a list that does not exist yet, and Redis deletes the list, + # expiry and all, whenever the reader drains it + pipeline = self._client.pipeline() + pipeline.rpush(handle, buf) + pipeline.expire(handle, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + if self._ref is not None: + self._ref.refresh(pipeline) + return pipeline.execute()[0] def _listread(self, handle): _, v = self._client.blpop([handle]) return v + def recv_bytes_within(self, timeout): + """ + The next message, waiting at most ``timeout`` seconds for one, or + None if none came. Zero or less does not wait at all. + + On a list, looking and taking are one step. With several readers, + poll() followed by a read let two of them see the same last message, + and the one that lost the race blocked in BLPOP for ever + """ + self._check_closed() + self._check_readable() + if self._pubsub is not None: + # A subscriber is the only reader of its messages + if not self._poll(max(timeout, 0)): + return None + return self._read(self._handle) + if timeout <= 0: + return self._client.lpop(self._handle) + popped = _blpop(self._client, self._handle, timeout) + return None if popped is None else popped[1] + def _channelwrite(self, handle, buf): return self._client.publish(handle, buf) @@ -649,13 +676,13 @@ def accept(self): return c def close(self): + # Only the subscription belongs to the listener. The client is the + # one the whole process shares, and closing it broke every other + # connection, blocking reads on other threads included try: self._pubsub.close() self._pubsub = None self._gen = None - if hasattr(self._client, 'close'): - self._client.close() - self._client = None finally: unlink = self._unlink if unlink is not None: diff --git a/lithops/multiprocessing/managers.py b/lithops/multiprocessing/managers.py index 50e38892e..46102e326 100644 --- a/lithops/multiprocessing/managers.py +++ b/lithops/multiprocessing/managers.py @@ -290,7 +290,7 @@ def _init_obj(self, obj): else: shared = obj.__shared__ - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() for attr_name in shared: attr = getattr(obj, attr_name) attr_bin = self._pickler.dumps(attr) @@ -364,7 +364,7 @@ def _call(self, *args, **kwargs): else: shared = self._shared_object.__shared__ - pipeline = self._proxy._client.pipeline() + pipeline = self._proxy._ref.pipeline() for attr_name in shared: attr = getattr(self._shared_object, attr_name) attr_bin = self._proxy._pickler.dumps(attr) @@ -402,13 +402,15 @@ class ListProxy(BaseProxy): # KEYS[2] - key to extend with # ARGV[1] - number of repetitions # A = A + B * C + # Pushed a thousand values at a time: unpack() puts every value on the + # Lua stack, which holds about 8000, so a longer list raised + # "too many results to unpack" LUA_EXTEND_LIST_SCRIPT = """ local values = redis.call('LRANGE', KEYS[2], 0, -1) - if #values == 0 then - return - else - for i=1,tonumber(ARGV[1]) do - redis.call('RPUSH', KEYS[1], unpack(values)) + local n = #values + for i=1,tonumber(ARGV[1]) do + for j=1,n,1000 do + redis.call('RPUSH', KEYS[1], unpack(values, j, math.min(j + 999, n))) end end """ @@ -449,6 +451,7 @@ def apply(pipe): self._oid, *[self._pickler.dumps(v) for v in new_items] ) pipe.expire(self._oid, self._expiry()) + self._ref.refresh(pipe) self._client.transaction(apply, self._oid) return answer['value'] @@ -458,7 +461,7 @@ def __setitem__(self, i, obj): idx = i.__index__() serialized = self._pickler.dumps(obj) try: - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.lset(self._oid, idx, serialized) pipeline.expire(self._oid, self._expiry()) pipeline.execute() @@ -484,7 +487,7 @@ def change(items): def __getitem__(self, i): if isinstance(i, int) or hasattr(i, '__index__'): idx = i.__index__() - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.lindex(self._oid, idx) pipeline.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) serialized, _ = pipeline.execute() @@ -501,7 +504,7 @@ def __getitem__(self, i): return self.tolist()[i] if start is None: return [] - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.lrange(self._oid, start, end) pipeline.expire(self._oid, self._expiry()) serialized, _ = pipeline.execute() @@ -523,7 +526,7 @@ def extend(self, iterable): values = [self._pickler.dumps(obj) for obj in iterable] if not values: return - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.rpush(self._oid, *values) pipeline.expire(self._oid, self._expiry()) pipeline.execute() @@ -536,18 +539,20 @@ def _extend_same_type(self, listproxy, repeat=1): # proxy -- ListProxy(other), a deepcopy, an in-place multiply -- # got a key that never expired, while one built from a plain list # got one that did - self._client.expire(self._oid, self._expiry()) + pipeline = self._ref.pipeline() + pipeline.expire(self._oid, self._expiry()) + pipeline.execute() def append(self, obj): serialized = self._pickler.dumps(obj) - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.rpush(self._oid, serialized) pipeline.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) pipeline.execute() def pop(self, index=None): if index is None: - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.rpop(self._oid) pipeline.expire(self._oid, self._expiry()) serialized, _ = pipeline.execute() @@ -625,7 +630,7 @@ def __imul__(self, n): return self def __len__(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.llen(self._oid) pipeline.expire(self._oid, self._expiry()) length, _ = pipeline.execute() @@ -659,7 +664,7 @@ def change(items): self._mutate(change) def tolist(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.lrange(self._oid, 0, -1) pipeline.expire(self._oid, self._expiry()) serialized, _ = pipeline.execute() @@ -710,13 +715,13 @@ def _referent(self): def __setitem__(self, k, v): serialized = self._pickler.dumps(v) - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hset(self._oid, self._field(k), serialized) pipeline.expire(self._oid, self._expiry()) pipeline.execute() def __getitem__(self, k): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hget(self._oid, self._field(k)) pipeline.expire(self._oid, self._expiry()) serialized, _ = pipeline.execute() @@ -726,7 +731,7 @@ def __getitem__(self, k): return self._pickler.loads(serialized) def __delitem__(self, k): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hdel(self._oid, self._field(k)) pipeline.expire(self._oid, self._expiry()) res, _ = pipeline.execute() @@ -735,14 +740,14 @@ def __delitem__(self, k): raise KeyError(k) def __contains__(self, k): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hexists(self._oid, self._field(k)) pipeline.expire(self._oid, self._expiry()) exists, _ = pipeline.execute() return bool(exists) def __len__(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hlen(self._oid) pipeline.expire(self._oid, self._expiry()) length, _ = pipeline.execute() @@ -770,7 +775,7 @@ def pop(self, k, *args): 'pop expected at most 2 arguments, got {}'.format(1 + len(args)) ) field = self._field(k) - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hget(self._oid, field) pipeline.hdel(self._oid, field) pipeline.expire(self._oid, self._expiry()) @@ -804,13 +809,14 @@ def apply(pipe): pipe.multi() pipe.hdel(self._oid, field) pipe.expire(self._oid, self._expiry()) + self._ref.refresh(pipe) self._client.transaction(apply, self._oid) return answer['value'] def setdefault(self, k, default=None): serialized = self._pickler.dumps(default) - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hsetnx(self._oid, self._field(k), serialized) # Every other writer refreshes the expiry. A dict only ever written # through setdefault used to get a key that outlived the job @@ -843,20 +849,20 @@ def update(self, *args, **kwargs): if items: # One pipelined HSET rather than the deprecated HMSET and a # separate round trip for the expiry - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hset(self._oid, mapping=items) pipeline.expire(self._oid, self._expiry()) pipeline.execute() def keys(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hkeys(self._oid) pipeline.expire(self._oid, self._expiry()) fields, _ = pipeline.execute() return [self._pickler.loads(k) for k in fields] def values(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hvals(self._oid) pipeline.expire(self._oid, self._expiry()) values, _ = pipeline.execute() @@ -876,7 +882,7 @@ def copy(self): return self.todict() def todict(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.hgetall(self._oid) pipeline.expire(self._oid, self._expiry()) raw_dict, _ = pipeline.execute() @@ -932,7 +938,7 @@ def _referent(self): return self.get() def get(self): - pipeline = self._client.pipeline() + pipeline = self._ref.pipeline() pipeline.get(self._oid) # Read without refreshing, a value that is polled and never written # disappears once REDIS_EXPIRY_TIME is up, mid-job @@ -944,7 +950,9 @@ def get(self): def set(self, value): serialized = self._pickler.dumps(value) - self._client.set(self._oid, serialized, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline = self._ref.pipeline() + pipeline.set(self._oid, serialized, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline.execute() value = property(get, set) diff --git a/lithops/multiprocessing/pool.py b/lithops/multiprocessing/pool.py index f014693d6..c3985095a 100644 --- a/lithops/multiprocessing/pool.py +++ b/lithops/multiprocessing/pool.py @@ -14,6 +14,8 @@ # import itertools import logging +import threading +import time from lithops import FunctionExecutor @@ -40,6 +42,13 @@ job_counter = itertools.count() +#: How often the thread that runs the callbacks of a result looks at calls +#: still running: it starts here and doubles up to the cap +HANDLER_MIN_SLEEP = 0.05 +HANDLER_MAX_SLEEP = 1.0 +#: How often that thread reads the status of a call from storage itself +HANDLER_STORAGE_CHECK = 10.0 + # # Class representing a process pool @@ -75,6 +84,15 @@ def __init__(self, processes=None, initializer=None, initargs=None, maxtasksperc self._processes = self._executor.invoker.max_workers self._remote_logger, self._logger_stream = util.setup_log_streaming(self._executor) + self._terminated = threading.Event() + self._handlers = [] + + def _track(self, result): + """Keeps the callback thread of a result for join() to wait on""" + if result._handler is not None: + self._handlers = [t for t in self._handlers if t.is_alive()] + self._handlers.append(result._handler) + return result def apply(self, func, args=(), kwds={}): """ @@ -153,9 +171,10 @@ def apply_async(self, func, args=(), kwds={}, callback=None, error_callback=None 'op': 'apply'}, extra_env=extra_env) - result = ApplyResult(self._executor, [futures], callback, error_callback) + result = ApplyResult(self._executor, [futures], callback, error_callback, + cancelled=self._terminated) - return result + return self._track(result) def map_async(self, func, iterable, chunksize=None, callback=None, error_callback=None): """ @@ -192,9 +211,10 @@ def _map_async(self, func, iterable, chunksize=None, callback=None, error_callba extra_args=extra_args, extra_env=extra_env) - result = MapResult(self._executor, futures, callback, error_callback) + result = MapResult(self._executor, futures, callback, error_callback, + cancelled=self._terminated) - return result + return self._track(result) def __reduce__(self): raise NotImplementedError('pool objects cannot be passed between processes or pickled') @@ -207,6 +227,7 @@ def close(self): def terminate(self): logger.debug('terminating pool') self._state = TERMINATE + self._terminated.set() self._release() def join(self): @@ -214,6 +235,12 @@ def join(self): if self._state not in (CLOSE, TERMINATE): raise ValueError('Pool is still running') if self._state == CLOSE: + # The callbacks read the results through the executor, which + # _release() gives back, and the standard library's join() does + # not return before they have run either + for handler in self._handlers: + handler.join() + self._handlers = [] self._wait_for_calls() self._release() @@ -286,7 +313,7 @@ class ThreadPool(Pool): class ApplyResult(object): - def __init__(self, executor, futures, callback, error_callback): + def __init__(self, executor, futures, callback, error_callback, cancelled=None): self._job = next(job_counter) self._futures = futures self._executor = executor @@ -294,8 +321,20 @@ def __init__(self, executor, futures, callback, error_callback): self._error_callback = error_callback self._value = None self._exception = None + self._collected = False + self._cancelled = cancelled if cancelled is not None else threading.Event() + # As in the standard library, the callbacks run once, as soon as the + # calls finish, whether or not anybody ever calls get() + self._event = None + self._handler = None + if callback is not None or error_callback is not None: + self._event = threading.Event() + self._handler = threading.Thread(target=self._handle, daemon=True) + self._handler.start() def ready(self): + if self._handler is not None: + return self._event.is_set() # A call whose status has arrived is finished as far as the caller is # concerned; `done` only turns true once its result was downloaded return all( @@ -312,55 +351,123 @@ def wait(self, timeout=None): Waits for the calls, reporting nothing, as in the standard library. A wait that timed out leaves the result there to be fetched later """ + if self._handler is not None: + self._event.wait(timeout) + return try: - self._executor.wait(self._futures, download_results=False, timeout=timeout) + self._wait(timeout, download_results=False) except Exception: logger.debug('Timed out waiting for the pool results', exc_info=True) - def _get_values(self, timeout=None): + def _wait(self, timeout, download_results): + try: + util.wait_futures(self._executor, self._futures, + download_results=download_results, timeout=timeout) + except TimeoutError as exc: + # Lithops reports it as the builtin, which is an OSError and so + # not what `except multiprocessing.TimeoutError` catches + raise ProcessTimeoutError(str(exc)) from exc + + def _collect(self): """ - The value of every call, in order. + Reads the value of every call, or the exception of the first one that + failed, from calls that have finished. Read from the futures rather than through get_result(), which unwraps a lone result depending on what the executor was last asked to do. A map in between would otherwise change the shape of this result, and a call that returns a list of its own is indistinguishable either way """ + storage = self._executor.internal_storage try: - self._executor.wait( - self._futures, download_results=True, timeout=timeout - ) - except TimeoutError as exc: - # Lithops reports it as the builtin, which is an OSError and so - # not what `except multiprocessing.TimeoutError` catches - raise ProcessTimeoutError(str(exc)) from exc + values = [fut.result(internal_storage=storage) for fut in self._futures] except Exception as exc: - # The call raised, and wait() re-raises it while downloading the - # results. The standard library hands that to error_callback - # before letting get() raise it - self._fail(exc) - raise - values = [] - for fut in self._futures: - try: - values.append(fut.result()) - except Exception as exc: - self._fail(exc) - raise - util.export_execution_details(self._futures, self._executor) - return values + self._exception = exc + else: + self._value = self._unwrap(values) + util.export_execution_details(self._futures, self._executor) + self._collected = True - def _fail(self, exc): - """Records the failure of a call and reports it to error_callback""" - self._exception = exc - if self._error_callback is not None: - self._error_callback(exc) + def _unwrap(self, values): + """The value of the single call this result stands for""" + return values[0] + + def _handle(self): + """ + Collects the result once the calls finish and runs the callback or + the error_callback, which is what the result handler thread of the + standard library does. + + The calls are polled one at a time rather than through lithops.wait, + which cancels the process-wide SIGALRM as it returns: that alarm is + what bounds a get(timeout) the main thread may be running meanwhile + """ + try: + if not self._wait_in_thread(): + return + self._collect() + except Exception as exc: + self._exception = exc + try: + # terminate() drops the callbacks of what had not finished + if self._cancelled.is_set(): + return + if self._exception is None: + if self._callback is not None: + self._callback(self._value) + elif self._error_callback is not None: + self._error_callback(self._exception) + except Exception: + logger.exception('Error in the callback of a pool result') + finally: + self._event.set() + + def _wait_in_thread(self): + """ + Waits for every call to finish. False if the pool was terminated. + + The job monitor of the executor marks a call ready as soon as its + status arrives, and applying that status reads nothing from storage. + Storage itself is only asked every HANDLER_STORAGE_CHECK seconds, in + case the monitor is not watching the call: one request per result + and poll would add up to hundreds a second for a pool with that many + results pending + """ + storage = self._executor.internal_storage + delay = HANDLER_MIN_SLEEP + last_check = time.monotonic() + for fut in self._futures: + while not (fut.success or fut.done): + if self._cancelled.is_set(): + return False + now = time.monotonic() + if fut.ready or now - last_check >= HANDLER_STORAGE_CHECK: + if not fut.ready: + last_check = now + found = fut.status(throw_except=False, + internal_storage=storage, + check_only=True) + # A status read from storage is only recorded by that + # call; the next one applies it + if found is not None and not (fut.success or fut.done): + fut.status(throw_except=False, + internal_storage=storage, check_only=True) + if not (fut.success or fut.done): + time.sleep(delay) + delay = min(delay * 2, HANDLER_MAX_SLEEP) + return True def get(self, timeout=None): - """The value of the single call this result stands for""" - self._value = self._get_values(timeout)[0] - if self._callback is not None: - self._callback(self._value) + if self._handler is not None: + if not self._event.wait(timeout): + raise ProcessTimeoutError( + 'Timeout of {} seconds exceeded waiting for the result'.format(timeout) + ) + elif not self._collected: + self._wait(timeout, download_results=True) + self._collect() + if self._exception is not None: + raise self._exception return self._value @@ -373,12 +480,9 @@ def get(self, timeout=None): class MapResult(ApplyResult): - def get(self, timeout=None): + def _unwrap(self, values): """The list of values, one per item of the iterable""" - self._value = self._get_values(timeout) - if self._callback is not None: - self._callback(self._value) - return self._value + return values # diff --git a/lithops/multiprocessing/process.py b/lithops/multiprocessing/process.py index 32287f186..12227eace 100644 --- a/lithops/multiprocessing/process.py +++ b/lithops/multiprocessing/process.py @@ -241,14 +241,23 @@ def close(self): def join(self, timeout=None): """ - Wait until child process terminates + Wait until child process terminates. + + A timeout that runs out returns None and leaves the process running, + as in the standard library, so it can be joined again. A process + whose target raised re-raises it here """ assert self._parent_pid == os.getpid(), 'can only join a child process' assert self._pid, 'can only join a started process' + try: + util.wait_futures(self._executor, [self._future], timeout=timeout) + except TimeoutError: + return None + exception = None try: - self._executor.wait(fs=[self._future], timeout=timeout) + self._future.status(internal_storage=self._executor.internal_storage) except Exception as e: exception = e finally: diff --git a/lithops/multiprocessing/queues.py b/lithops/multiprocessing/queues.py index 9f008b02b..cea24dc78 100644 --- a/lithops/multiprocessing/queues.py +++ b/lithops/multiprocessing/queues.py @@ -62,6 +62,7 @@ def _after_fork(self): self._send_bytes = self._writer.send_bytes self._recv_bytes = self._reader.recv_bytes self._poll = self._reader.poll + self._writer._ref = self._ref def put(self, obj, block=True, timeout=None): """ @@ -91,12 +92,9 @@ def get(self, block=True, timeout=None): if block and timeout is None: res = self._recv_bytes() else: - if block: - if not self._poll(timeout): - raise Empty - elif not self._poll(): + res = self._reader.recv_bytes_within(timeout if block else 0) + if res is None: raise Empty - res = self._recv_bytes() return cloudpickle.loads(res) @@ -148,6 +146,11 @@ def __init__(self): self._ref = util.RemoteReference(referenced=[self._reader._handle, self._reader._subhandle], client=self._reader._client) self._poll = self._reader.poll + self._writer._ref = self._ref + + def __setstate__(self, state): + self.__dict__.update(state) + self._writer._ref = self._ref def put(self, obj, block=True, timeout=None): assert not self._closed @@ -158,12 +161,9 @@ def get(self, block=True, timeout=None): if block and timeout is None: res = self._reader.recv_bytes() else: - if block: - if not self._poll(timeout): - raise Empty - elif not self._poll(): + res = self._reader.recv_bytes_within(timeout if block else 0) + if res is None: raise Empty - res = self._reader.recv_bytes() return cloudpickle.loads(res) diff --git a/lithops/multiprocessing/sharedctypes.py b/lithops/multiprocessing/sharedctypes.py index 7b0d7ea0d..6c863b7ce 100644 --- a/lithops/multiprocessing/sharedctypes.py +++ b/lithops/multiprocessing/sharedctypes.py @@ -12,6 +12,7 @@ import ctypes import cloudpickle import logging +import redis from . import util from . import get_context @@ -73,7 +74,9 @@ def __setattr__(self, key, value): if key == 'value': obj = cloudpickle.dumps(value) logger.debug('Set raw value %s of size %i B', self._oid, len(obj)) - self._client.set(self._oid, obj, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline = self._ref.pipeline() + pipeline.set(self._oid, obj, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline.execute() else: super().__setattr__(key, value) @@ -132,10 +135,13 @@ def __getitem__(self, i): stop -= 1 logger.debug('Requested get list slice from %i to %i', start, stop) objl = self._client.lrange(self._oid, start, stop) - self._client.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + self._refresh_expiry() return [cloudpickle.loads(obj) for obj in objl] else: obj = self._client.lindex(self._oid, i) + if obj is None: + # LINDEX answers nil past either end, as ctypes raises + raise IndexError('invalid index') logger.debug('Requested get list index %i of size %i B', i, len(obj)) return cloudpickle.loads(obj) @@ -151,8 +157,17 @@ def __setitem__(self, i, value): else: obj = cloudpickle.dumps(value) logger.debug('Requested set list index %i of size %i B', i, len(obj)) - self._client.lset(self._oid, i, obj) - self._client.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + try: + self._client.lset(self._oid, i, obj) + except redis.exceptions.ResponseError: + # LSET refuses an index past either end + raise IndexError('invalid index') + self._refresh_expiry() + + def _refresh_expiry(self): + pipeline = self._ref.pipeline() + pipeline.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline.execute() class SynchronizedArrayProxy(RawArrayProxy, SynchronizedSharedCTypeProxy): @@ -173,7 +188,7 @@ def __setattr__(self, key, value): obj = cloudpickle.dumps(elem) logger.debug('Requested set string index %i of size %i B', i, len(obj)) self._client.lset(self._oid, i, obj) - self._client.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + self._refresh_expiry() else: super().__setattr__(key, value) @@ -189,11 +204,13 @@ def __getitem__(self, i): stop -= 1 # lrange is inclusive on both ends logger.debug('Requested get string slice from %i to %i', start, stop) objl = self._client.lrange(self._oid, start, stop) - self._client.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + self._refresh_expiry() return bytes([cloudpickle.loads(obj) for obj in objl]) else: obj = self._client.lindex(self._oid, i) - self._client.expire(self._oid, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + if obj is None: + raise IndexError('invalid index') + self._refresh_expiry() return bytes([cloudpickle.loads(obj)]) diff --git a/lithops/multiprocessing/synchronize.py b/lithops/multiprocessing/synchronize.py index 81401cd2c..78ad5707f 100644 --- a/lithops/multiprocessing/synchronize.py +++ b/lithops/multiprocessing/synchronize.py @@ -163,9 +163,11 @@ def _refresh_expiry(self): used once never expires. A semaphore with tokens left keeps its key, and the deadline set at creation would take those tokens """ - self._client.expire( + pipeline = self._ref.pipeline() + pipeline.expire( self._name, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME) ) + pipeline.execute() def __repr__(self): try: @@ -383,12 +385,14 @@ def wait(self, timeout=None): # is what the standard library returns and callers branch on return notified - def notify(self): + def notify(self, n=1): assert self._lock.owned logger.debug('Notify condition %s', self._notify_handle) - wait_handle = self._client.lpop(self._notify_handle) - if wait_handle is not None: + for _ in range(n): + wait_handle = self._client.lpop(self._notify_handle) + if wait_handle is None: + break res = self._client.rpush(wait_handle, '') if not res: @@ -494,7 +498,9 @@ def _state(self): @_state.setter def _state(self, value): - self._client.set(self._state_handle, value, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline = self._ref.pipeline() + pipeline.set(self._state_handle, value, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline.execute() @property def _count(self): @@ -502,4 +508,6 @@ def _count(self): @_count.setter def _count(self, value): - self._client.set(self._count_handle, value, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline = self._ref.pipeline() + pipeline.set(self._count_handle, value, ex=mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + pipeline.execute() diff --git a/lithops/multiprocessing/util.py b/lithops/multiprocessing/util.py index aaf8d850c..5616c0330 100644 --- a/lithops/multiprocessing/util.py +++ b/lithops/multiprocessing/util.py @@ -21,6 +21,7 @@ import json import socket from lithops.config import load_config +from lithops.wait import wait as lithops_wait from . import config as mp_config @@ -118,6 +119,26 @@ def get_network_ip(): # class RemoteReference: + # KEYS[1] - reference counter + # KEYS[2..n] - keys of the shared object, the counter among them + # ARGV[1] - expiry time + # Gives back one reference and deletes the object once none is left. + # A counter that is gone -- it expired, or the object was already + # collected -- says nothing about who still holds the object, so it is + # left alone rather than decremented to -1 and taken for the last owner + LUA_DECREF_SCRIPT = """ + if redis.call('exists', KEYS[1]) == 0 then + return nil + end + local count = redis.call('decr', KEYS[1]) + if count <= 0 then + redis.call('del', unpack(KEYS)) + else + redis.call('expire', KEYS[1], ARGV[1]) + end + return count + """ + def __init__(self, referenced, managed=False, client=None): if isinstance(referenced, str): referenced = [referenced] @@ -191,11 +212,27 @@ def incref(self): def decref(self): if not self.managed: - pipeline = self._client.pipeline() - pipeline.decr(self._rck, 1) - pipeline.expire(self._rck, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) - counter, _ = pipeline.execute() - return int(counter) + counter = self._release(self._client, self._rck, self._referenced) + return None if counter is None else int(counter) + + def refresh(self, pipeline=None): + """ + Pushes the counter's deadline out along with the object's. + + The counter is only written when an owner comes or goes, while the + object's keys are refreshed on every use, so an object in use for + longer than REDIS_EXPIRY_TIME lost its counter. Queued on + ``pipeline`` when one is given. Returns whether anything was sent + """ + if self.managed: + return False + target = self._client if pipeline is None else pipeline + target.expire(self._rck, mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)) + return True + + def pipeline(self): + """A pipeline of the object's client that also refreshes the counter""" + return _RefreshingPipeline(self._client.pipeline(), self) def refcount(self): count = self._client.get(self._rck) @@ -215,9 +252,59 @@ def _finalize(client, rck, referenced): zero is what says nobody is left; it used to have to go negative, which is one owner too many """ - count = int(client.decr(rck, 1)) - if count <= 0 and len(referenced) > 0: - client.delete(*referenced) + RemoteReference._release(client, rck, referenced) + + @staticmethod + def _release(client, rck, referenced): + script = client.register_script(RemoteReference.LUA_DECREF_SCRIPT) + return script(keys=[rck] + list(referenced), + args=[mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME)], + client=client) + + +class _RefreshingPipeline: + """ + A pipeline that refreshes the reference counter of the object as it runs. + + The counter's EXPIRE is queued last and its reply dropped, so callers + unpack the replies of the commands they queued, as before + """ + + def __init__(self, pipeline, ref): + self._pipeline = pipeline + self._ref = ref + + def __getattr__(self, name): + return getattr(self._pipeline, name) + + def execute(self): + queued = self._ref.refresh(self._pipeline) + results = self._pipeline.execute() + return results[:-1] if queued else results + + +def wait_futures(executor, futures, download_results=False, timeout=None): + """ + Waits for some calls of ``executor``, leaving them and the executor as + they are. + + FunctionExecutor.wait() takes any exception, a timeout included, as the + end of the job: it stops the invoker, marks the futures failed and + deletes the job data, so a pool result or a process that was only waited + on with a timeout could never be waited on again. A call that raised is + not reported here either; reading its status or result raises it. + + Runs out with the builtin TimeoutError, from the SIGALRM lithops.wait + arms, so a timeout only works from the main thread + """ + lithops_wait( + fs=futures, + internal_storage=executor.internal_storage, + job_monitor=executor._monitor_of(futures), + download_results=download_results, + throw_except=False, + timeout=timeout, + ) # diff --git a/lithops/tests/mp_fakeredis.py b/lithops/tests/mp_fakeredis.py index 86c5c8226..1144e3f58 100644 --- a/lithops/tests/mp_fakeredis.py +++ b/lithops/tests/mp_fakeredis.py @@ -26,6 +26,8 @@ import threading import time +from redis.exceptions import ResponseError + def _to_bytes(value): """What the server stores: every value becomes bytes""" @@ -86,15 +88,33 @@ def keys(self, pattern='*'): def _record(self, name, *args): self.commands.append((name,) + args) + def advance(self, seconds): + """ + Lets ``seconds`` go by: every expiry counts down, and a key whose + expiry runs out is deleted, as the server does + """ + with self._cond: + for key, ttl in list(self.expiries.items()): + ttl -= seconds + if ttl <= 0: + self.strings.pop(key, None) + self.lists.pop(key, None) + del self.expiries[key] + else: + self.expiries[key] = ttl + # -- strings ----------------------------------------------------------- def set(self, key, value, ex=None): + """Without ``ex``, SET drops whatever expiry the key had""" key = _key(key) self._record('set', key) with self._cond: self.strings[key] = _to_bytes(value) if ex is not None: self.expiries[key] = ex + else: + self.expiries.pop(key, None) return True def get(self, key): @@ -231,10 +251,13 @@ def lindex(self, key, index): return None def lset(self, key, index, value): + """The server refuses a missing key and an index past either end""" key = _key(key) - items = self.lists.setdefault(key, []) - while len(items) <= index: - items.append(b'') + items = self.lists.get(key) + if items is None: + raise ResponseError('no such key') + if not -len(items) <= index < len(items): + raise ResponseError('index out of range') items[index] = _to_bytes(value) return True @@ -251,9 +274,16 @@ def pubsub(self): def register_script(self, script): """ - The only script the package registers is the capped release of - SemLock, reimplemented here rather than running Lua + The scripts the package registers, reimplemented here rather than + running Lua: the capped release of SemLock and the release of a + remote reference. Any other one cannot be run """ + from lithops.multiprocessing.synchronize import SemLock + from lithops.multiprocessing.util import RemoteReference + if script == SemLock.LUA_RELEASE_SCRIPT: + return FakeSemLockRelease(self) + if script == RemoteReference.LUA_DECREF_SCRIPT: + return FakeDecref(self) return FakeScript(self) # -- pipelines --------------------------------------------------------- @@ -280,6 +310,12 @@ class FakeScript: def __init__(self, server): self._server = server + def __call__(self, keys, args, client=None): + raise NotImplementedError('the fake server cannot run this script') + + +class FakeSemLockRelease(FakeScript): + def __call__(self, keys, args, client=None): server = client if client is not None else self._server name = _key(keys[0]) @@ -295,6 +331,26 @@ def __call__(self, keys, args, client=None): return current + 1 +class FakeDecref(FakeScript): + """ + Decrements a reference counter that exists, deleting the object once it + reaches zero and refreshing the counter otherwise + """ + + def __call__(self, keys, args, client=None): + server = client if client is not None else self._server + counter = _key(keys[0]) + with server._cond: + if counter not in server.strings: + return None + count = server.incr(counter, -1) + if count <= 0: + server.delete(*keys) + else: + server.expiries[counter] = int(args[0]) + return count + + class FakePubSub: def __init__(self, server): self._server = server diff --git a/lithops/tests/test_executors.py b/lithops/tests/test_executors.py index 5968b87f7..f85209e93 100644 --- a/lithops/tests/test_executors.py +++ b/lithops/tests/test_executors.py @@ -216,7 +216,9 @@ def test_cleanup_jobs_omits_exception_kwarg_on_success(self): with patch.object(executor, 'clean') as clean: executor._cleanup_jobs([future]) executor.compute_handler.clear.assert_called_once_with({future.job_key}) - clean.assert_called_once_with(clean_cloudobjects=False, force=False) + clean.assert_called_once_with( + fs=[future], clean_cloudobjects=False, force=False + ) def test_cleanup_jobs_passes_exception_and_force(self): executor = _bare_executor() @@ -227,7 +229,35 @@ def test_cleanup_jobs_passes_exception_and_force(self): executor.compute_handler.clear.assert_called_once_with( {future.job_key}, exception=error ) - clean.assert_called_once_with(clean_cloudobjects=False, force=True) + clean.assert_called_once_with( + fs=[future], clean_cloudobjects=False, force=True + ) + + def test_clean_keeps_a_job_with_results_still_to_read(self): + """ + One job is one storage prefix. A call whose small result came back + inside its status is done, while its sibling's result still waits in + storage: deleting the prefix then loses it, and a later get_result() + fails with 'Unable to get the result' + """ + read = FakeFuture(executor_id='abc-0', job_id='M000', done=True) + unread = FakeFuture( + executor_id='abc-0', job_id='M000', done=False, success=True + ) + executor = _bare_executor( + cleaned_jobs=set(), executor_id='abc-0', futures=[read, unread] + ) + with patch('lithops.executors._dump_cleaner_data') as dump, \ + patch('lithops.executors.sp.Popen'): + executor.clean(fs=[read, unread], clean_cloudobjects=False) + dump.assert_not_called() + assert executor.cleaned_jobs == set() + + unread.done = True + with patch('lithops.executors._dump_cleaner_data') as dump, \ + patch('lithops.executors.sp.Popen'): + executor.clean(fs=[read, unread], clean_cloudobjects=False) + assert create_job_key('abc-0', 'M000') in executor.cleaned_jobs def test_clean_does_not_wrap_futures_list(self): future = FakeFuture(executor_id='abc-0', job_id='M000', done=True) @@ -417,7 +447,11 @@ def test_a_failure_at_exit_does_not_stop_the_remaining_hooks(self): clean.assert_called_once() @patch('lithops.executors.wait', side_effect=RuntimeError('boom')) - def test_wait_exception_stops_invoker_and_reraises(self, mock_wait): + def test_wait_exception_drops_its_queued_calls_and_reraises(self, mock_wait): + """ + Stopping the invoker used to drop the queued calls of every job of + the executor, so another job still running never got its workers + """ future = FakeFuture() executor = _bare_executor(data_cleaner=True) @@ -425,12 +459,59 @@ def test_wait_exception_stops_invoker_and_reraises(self, mock_wait): with pytest.raises(RuntimeError, match='boom'): executor.wait([future], show_progressbar=False) - executor.invoker.stop.assert_called_once() + executor.invoker.stop.assert_not_called() + executor.invoker.discard_pending.assert_called_once_with( + {future.job_key} + ) executor.job_monitor.remove.assert_called_once() assert future._exception_set is True assert cleanup.call_args.kwargs['force'] is True assert isinstance(cleanup.call_args.kwargs['exception'], RuntimeError) + @patch('lithops.executors.wait', side_effect=TimeoutError('late')) + def test_a_failed_wait_only_cleans_the_jobs_it_waited_on(self, mock_wait): + """ + A timeout waiting on one job used to delete the data of every job + of the executor, including one still running that nobody waited on + """ + waited = FakeFuture(executor_id='abc-0', job_id='M000') + other = FakeFuture( + executor_id='abc-0', job_id='M001', job_key='abc-0/M001' + ) + executor = _bare_executor( + data_cleaner=True, executor_id='abc-0', futures=[waited, other] + ) + with patch('lithops.executors._dump_cleaner_data') as dump, \ + patch('lithops.executors.sp.Popen'): + with pytest.raises(TimeoutError): + executor.wait([waited], show_progressbar=False) + cleaned = dump.call_args[0][0]['jobs_to_clean'] + assert cleaned == {create_job_key('abc-0', 'M000')} + + @patch('lithops.executors.wait', side_effect=KeyboardInterrupt) + def test_ctrl_c_in_wait_stops_every_invocation(self, mock_wait): + executor = _bare_executor() + with pytest.raises(KeyboardInterrupt): + executor.wait([FakeFuture()], show_progressbar=False) + executor.invoker.stop.assert_called_once_with(wait=True) + + @patch('lithops.executors.wait', side_effect=TimeoutError('late')) + def test_a_failed_wait_honours_clean_jobs(self, mock_wait): + future = FakeFuture() + executor = _bare_executor(data_cleaner=True) + with patch.object(executor, '_cleanup_jobs') as cleanup: + with pytest.raises(TimeoutError): + executor.wait([future], show_progressbar=False, + clean_jobs=False) + cleanup.assert_not_called() + + def test_get_result_takes_a_single_future(self): + """The signature takes a ResponseFuture, which has no len()""" + future = FakeFuture(_result=42) + executor = _bare_executor(last_call='call_async', futures=[future]) + with patch.object(executor, 'wait', return_value=([future], [])): + assert executor.get_result(future) == 42 + def test_get_result_unwraps_single_non_map_result(self): future = FakeFuture(_result=42) executor = _bare_executor(last_call='call_async', futures=[future]) diff --git a/lithops/tests/test_future.py b/lithops/tests/test_future.py index 9f245eaef..a72b8924f 100644 --- a/lithops/tests/test_future.py +++ b/lithops/tests/test_future.py @@ -14,6 +14,7 @@ import base64 import pickle +import sys import zlib from types import SimpleNamespace from unittest.mock import MagicMock, patch @@ -318,6 +319,47 @@ def test_handler_exception_strips_marker_argument(self): future.status(internal_storage=storage) assert future._handler_exception is True + def test_a_status_without_result_size_does_not_crash(self): + """ + A worker that died before writing its function stats sends a + finished status with no func_result_size. Reading it used to raise + KeyError in the wait thread pool, which crashed get_result() even + with throw_except=False + """ + future = _future() + future._set_invoked() + storage = MagicMock() + storage.get_storage_config.return_value = STORAGE_CONFIG + status = _end_status() + del status['func_result_size'] + storage.get_call_status.return_value = status + future.status(internal_storage=storage, throw_except=False) + assert future.done + assert future.result(internal_storage=storage) is None + + def test_a_remote_sys_exit_keeps_its_exit_code(self): + """ + tblib, which the worker installs, rebuilds a SystemExit with code + None. Re-raised on the client, sys.exit(3) in the function would + end the client program with status 0 + """ + from tblib import pickling_support + pickling_support.install() + try: + sys.exit(3) + except SystemExit: + exc_info = sys.exc_info() + future = _future() + future._set_invoked() + storage = MagicMock() + storage.get_storage_config.return_value = STORAGE_CONFIG + storage.get_call_status.return_value = _end_status( + exception=True, exc_info=_encode(exc_info), + ) + with pytest.raises(SystemExit) as raised: + future.status(internal_storage=storage) + assert raised.value.code == 3 + def test_pickle_fail_wraps_exception_dict(self): future = _future() future._set_invoked() diff --git a/lithops/tests/test_invokers.py b/lithops/tests/test_invokers.py index 20a076f64..cafbbdb89 100644 --- a/lithops/tests/test_invokers.py +++ b/lithops/tests/test_invokers.py @@ -317,6 +317,37 @@ def test_drain_token_bucket_consumes_until_zero(self): assert inv.running_workers == 0 assert inv.job_monitor.token_bucket_q.qsize() == 1 + def test_discard_pending_keeps_the_calls_of_other_jobs(self): + inv = self._faas() + failed = _job(chunksize=2) + failed.job_key = 'sess-0/M000' + other = _job(chunksize=2) + other.job_key = 'sess-0/M001' + inv._queue_call_ranges(failed, range(4)) + inv._queue_call_ranges(other, range(3)) + inv.discard_pending({'sess-0/M000'}) + left = [] + while not inv.pending_calls_q.empty(): + left.append(inv.pending_calls_q.get()[0]) + assert left == [other, other] + + def test_a_restart_forgets_tokens_handed_back_after_the_stop(self): + """ + A monitor's final sweep can hand tokens back after the invoker + stopped. The restart counts no running worker, so each of those + tokens would invoke one worker beyond max_workers + """ + inv = self._faas() + inv.max_workers = 1 + inv.ASYNC_INVOKERS = 1 + for _ in range(3): + inv.job_monitor.token_bucket_q.put('#') + with patch.object(inv, '_async_invoker_loop'), \ + patch.object(inv, '_invoke_direct'): + inv.compute_handler = MagicMock() + inv._invoke_job(_job(chunksize=1, total_calls=2)) + assert inv.job_monitor.token_bucket_q.qsize() == 1 + def test_queue_call_ranges_chunks_ids(self): inv = self._faas() job = _job(chunksize=2) diff --git a/lithops/tests/test_localhost.py b/lithops/tests/test_localhost.py index b7c1dd8a6..ba8ed702d 100644 --- a/lithops/tests/test_localhost.py +++ b/lithops/tests/test_localhost.py @@ -104,6 +104,36 @@ def test_environment_python_tagged_image_is_container(self): localhost_config.LocalhostEnvironment.CONTAINER ) + def test_environment_default_for_every_interpreter_basename(self): + # The default runtime is basename(sys.executable), which is not + # always a plain pythonX.Y: free-threaded and debug builds, the + # python.org macOS installer and Windows GUI interpreters all have + # suffixes of their own, and none of them is a docker image + for runtime in ( + 'python3.13t', + 'python3.14t', + 'python3.12d', + 'python3-intel64', + 'pythonw', + 'pythonw.exe', + 'Python.exe', + ): + assert localhost_config.get_environment(runtime) is ( + localhost_config.LocalhostEnvironment.DEFAULT + ), runtime + + def test_environment_container_for_python_images(self): + for runtime in ( + 'python:3.12', + 'python:3.12-slim', + 'registry/python', + 'registry.example.com:5000/python', + 'docker.io/library/python:3.12', + ): + assert localhost_config.get_environment(runtime) is ( + localhost_config.LocalhostEnvironment.CONTAINER + ), runtime + def test_environment_enum_values(self): assert localhost_config.LocalhostEnvironment.DEFAULT.value == 'default' assert localhost_config.LocalhostEnvironment.CONTAINER.value == 'container' diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index ce30e16ea..f87cc5cd4 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -848,6 +848,23 @@ def test_generate_tokens_emits_when_done_is_listed_before_running(self): monitor._generate_tokens(running, done) assert monitor.token_bucket_q.get_nowait() == '#' + def test_the_final_sweep_hands_back_the_workers_it_finds_free(self): + """ + wait() stops the monitor once its futures are done, which the blind + sweep can find before the listing credits their worker. The sweep + run() makes after the stop is then the last chance for that token: + the next monitor does not watch this job + """ + monitor = self._storage(chunksize=1) + monitor.present_jobs.add('M000') + monitor.internal_storage.get_job_status.return_value = ( + {(('sess-0', 'M000', '00000'), 'w1')}, + {('sess-0', 'M000', '00000')}, + ) + monitor.should_run = False + monitor.run() + assert monitor.token_bucket_q.get_nowait() == '#' + def test_generate_tokens_one_per_worker(self): monitor = self._storage(chunksize=1) running = { @@ -1883,7 +1900,7 @@ class Fake(MessageCallStatus): RETRY_SLEEP = 0 closed = 0 - def _publish(self, payload): + def _publish_to(self, target, payload): publish(payload) def close(self): @@ -1899,7 +1916,7 @@ class Plain(MessageCallStatus): service_name = 'plain' RETRY_SLEEP = 0 - def _publish(self, payload): + def _publish_to(self, target, payload): publish(payload) return Plain @@ -2153,6 +2170,224 @@ def test_no_client_is_built_before_the_first_status(self): cls(self._job(name), MagicMock()) assert build.call_count == 0, name + def _chain_status_cls(self, published, fails): + from lithops.monitoring.status import MessageCallStatus + + class Chain(MessageCallStatus): + service_name = 'chain' + RETRY_SLEEP = 0 + + def _publish_to(self, target, payload): + published.append(target) + if fails(target): + raise ConnectionError(f'{target} is not there') + + return Chain + + def test_a_remote_invoker_queue_that_is_gone_is_tried_once(self): + """ + The remote invoker deletes its queue as soon as every chunk is + invoked, long before the calls finish. Every status then went + through five attempts with back-off, each one sending it to the + client's queue again + """ + invoker_queue = remote_invoker_queue_name('sess-0') + job = self._job() + job.monitoring_queues = ['lithops-sess-0', invoker_queue] + published = [] + cls = self._chain_status_cls( + published, lambda target: target == invoker_queue + ) + with patch('lithops.monitoring.status.time.sleep') as sleep, \ + patch('lithops.monitoring.status.logger') as log: + cls(job, MagicMock()).send_finish_event() + + assert published == ['lithops-sess-0', invoker_queue] + sleep.assert_not_called() + log.error.assert_not_called() + + def test_only_the_queue_that_failed_is_retried(self): + """ + A nested call reports to its parent's queue as well, which is the + only way the parent learns of the futures it is handed back, so + that one is retried; the queues that took the status do not get it + a second time + """ + job = self._job() + job.monitoring_queues = ['lithops-parent', 'lithops-sess-0'] + published = [] + failures = iter([True]) + cls = self._chain_status_cls( + published, + lambda target: target == 'lithops-parent' + and next(failures, False), + ) + cls(job, MagicMock()).send_init_event() + + assert published == [ + 'lithops-parent', 'lithops-sess-0', 'lithops-parent' + ] + + def test_redis_does_not_bring_back_a_deleted_invoker_list_for_good(self): + """ + An RPUSH onto a list that was deleted creates it again, and nothing + would ever delete that one + """ + from lithops.monitoring.backends.redis.status import RedisCallStatus + from lithops.tests.mp_fakeredis import FakeRedis + + client = FakeRedis() + invoker_queue = remote_invoker_queue_name('sess-0') + job = self._job('redis') + job.monitoring_queues = ['lithops-sess-0', invoker_queue] + with _client(redis_backend, 'redis_client', client): + RedisCallStatus(job, MagicMock()).send_init_event() + + assert client.llen(invoker_queue) == 1 + client.advance(RedisCallStatus.BEST_EFFORT_TTL) + assert client.llen(invoker_queue) == 0 + assert client.llen('lithops-sess-0') == 1 + + def test_sqs_never_creates_a_queue_from_the_worker(self): + """ + Creating the queue of a remote invoker that is gone left an orphan + queue behind, one per executor, that nothing deletes + """ + from lithops.monitoring.backends.aws_sqs.status import SqsCallStatus + + class QueueDoesNotExist(Exception): + pass + + invoker_queue = remote_invoker_queue_name('sess-0') + + def queue_url(QueueName): + if QueueName == invoker_queue: + raise QueueDoesNotExist(QueueName) + return {'QueueUrl': f'https://sqs/{QueueName}'} + + client = MagicMock() + client.get_queue_url.side_effect = queue_url + job = self._job('aws_sqs') + job.monitoring_queues = ['lithops-sess-0', invoker_queue] + with _client(sqs_backend, 'sqs_client', client), \ + patch('lithops.monitoring.status.time.sleep') as sleep: + SqsCallStatus(job, MagicMock()).send_init_event() + + client.create_queue.assert_not_called() + sleep.assert_not_called() + urls = [ + c.kwargs['QueueUrl'] for c in client.send_message.call_args_list + ] + assert urls == ['https://sqs/lithops-sess-0'] + + def test_pubsub_makes_no_admin_request_per_call(self): + """ + Every call used to ask for the creation of every topic of its chain, + which the monitor had already created, before publishing to it + """ + from lithops.monitoring.backends.gcp_pubsub.status import ( + GcpPubsubCallStatus, + ) + + publisher = MagicMock() + job = self._job('gcp_pubsub') + job.config['gcp_pubsub'] = {'project_name': 'proj'} + with patch.object( + pubsub_backend, 'pubsub_clients', + return_value=(publisher, MagicMock()), + ): + for call_id in ('00000', '00001', '00002'): + job.call_id = call_id + status = GcpPubsubCallStatus(job, MagicMock()) + status.send_init_event() + status.send_finish_event() + + publisher.create_topic.assert_not_called() + topics = {c.args[0] for c in publisher.publish.call_args_list} + assert topics == {'projects/proj/topics/lithops-sess-0'} + assert publisher.publish.call_count == 6 + + def _azure_status(self, storage, events=None): + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + + queue_client = MagicMock() + service = MagicMock() + service.get_queue_client.return_value = queue_client + if events is not None: + storage.put_data.side_effect = \ + lambda key, data: events.append('storage') + queue_client.send_message.side_effect = \ + lambda body: events.append('message') + with _client(azure_backend, 'queue_service', service): + status = AzureQueueCallStatus(self._job('azure_queue'), storage) + status.service + return status, queue_client + + def test_azure_leaves_the_logs_out_of_a_status_that_does_not_fit(self): + """ + The worker puts the logs of the call in its last status, and a + chatty function takes that past the 64 KiB Azure Queue takes: the + __end__ failed five times and only reached the client through the + storage sweep, a minute later + """ + from lithops.monitoring.status import PARTIAL_STATUS_KEY + + storage = MagicMock() + status, queue_client = self._azure_status(storage) + logs = 'x' * 100_000 + status.add('logs', logs) + status.send_finish_event() + + queue_client.send_message.assert_called_once() + body = queue_client.send_message.call_args.args[0] + assert len(body.encode('utf-8')) <= status.MAX_MESSAGE_SIZE + message = json.loads(body) + assert 'logs' not in message + assert PARTIAL_STATUS_KEY not in message + assert message['type'] == '__end__' + stored = json.loads(storage.put_data.call_args.args[1]) + assert stored['logs'] == logs + + def test_a_status_that_still_does_not_fit_is_sent_partial(self): + """ + What is left once the logs are out can still be too big, a large + traceback for one. The message then only tells the client to read + the storage copy, which has to be there before the message is + """ + from lithops.monitoring.status import PARTIAL_STATUS_KEY + + storage = MagicMock() + events = [] + status, queue_client = self._azure_status(storage, events) + status.add('exception', True) + status.add('exc_info', 'x' * 100_000) + status.send_finish_event() + + assert events == ['storage', 'message'] + message = json.loads(queue_client.send_message.call_args.args[0]) + assert message[PARTIAL_STATUS_KEY] is True + assert 'exc_info' not in message + assert message['exception'] is True + assert message['call_id'] == '00000' + stored = json.loads(storage.put_data.call_args.args[1]) + assert stored['exc_info'] == 'x' * 100_000 + + def test_the_worker_reports_how_many_calls_its_chunk_has(self): + """ + The last chunk of a job is usually shorter than the chunksize, and + the worker that runs it has to say so, or the client waits for + calls that do not exist before handing its token back + """ + cls = self._status_cls(lambda payload: None) + job = self._job() + job.chunksize = 3 + job.total_calls = 10 + for call_id, expected in (('00000', 3), ('00005', 3), ('00009', 1)): + job.call_id = call_id + assert cls(job, MagicMock()).status['worker_calls'] == expected + class TestRedisMonitor: @@ -2208,8 +2443,7 @@ def test_call_status_publishes_to_every_queue_in_the_chain(self): ) with _client(redis_backend, 'redis_client', client): status = RedisCallStatus(job, MagicMock()) - status.status['type'] = '__init__' - status._publish('{"type": "__init__"}') + status.send_init_event() assert client.llen('lithops-parent') == 1 assert client.llen('lithops-sess-0') == 1 @@ -2418,7 +2652,7 @@ def test_call_status_sends_to_every_queue_in_the_chain(self): ) with _client(sqs_backend, 'sqs_client', client): status = SqsCallStatus(job, MagicMock()) - status._publish('{"type": "__init__"}') + status.send_init_event() urls = [c.kwargs['QueueUrl'] for c in client.send_message.call_args_list] assert urls == ['https://sqs/parent', 'https://sqs/own'] @@ -2525,14 +2759,14 @@ def test_call_status_publishes_to_every_topic_in_the_chain(self): return_value=(publisher, MagicMock()), ): status = GcpPubsubCallStatus(job, MagicMock()) - status._publish('{"type": "__init__"}') + status.send_init_event() topics = [c.args[0] for c in publisher.publish.call_args_list] assert topics == [ 'projects/proj/topics/lithops-parent', 'projects/proj/topics/lithops-sess-0', ] for call in publisher.publish.call_args_list: - assert call.args[1] == b'{"type": "__init__"}' + assert json.loads(call.args[1])['type'] == '__init__' class TestAzureQueueMonitor: @@ -2616,9 +2850,11 @@ def test_call_status_sends_to_every_queue_in_the_chain(self): ) with _client(azure_backend, 'queue_service', service): status = AzureQueueCallStatus(job, MagicMock()) - status._publish('{"type": "__init__"}') - parent.send_message.assert_called_once_with('{"type": "__init__"}') - own.send_message.assert_called_once_with('{"type": "__init__"}') + status.send_init_event() + for queue_client in (parent, own): + queue_client.send_message.assert_called_once() + body = queue_client.send_message.call_args.args[0] + assert json.loads(body)['type'] == '__init__' class TestAzureQueueNames: @@ -2678,12 +2914,467 @@ def test_the_monitor_and_the_workers_agree_on_the_name(self): ) with _client(azure_backend, 'queue_service', service): status = AzureQueueCallStatus(job, MagicMock()) - assert status._targets() == [monitor.queue] + assert [ + azure_queue_name(name) for name in status._targets() + ] == [monitor.queue] assert monitor.queue == azure_queue_name( monitoring_queue_name('SESS-0') ) +def _wait_for(predicate, timeout=5): + deadline = time.time() + timeout + while not predicate() and time.time() < deadline: + time.sleep(0.01) + return predicate() + + +class TestTheNextMapAfterAWait: + """ + A wait() whose futures are all done stops the monitor, and the next map() + is invoked before start() is called for it. Whatever the first workers of + that map report in between has to reach the monitor that tracks them + """ + + def _job_monitor(self, cls, config=None): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + job_monitor = JobMonitor('sess-0', storage, config=config) + if cls is not None: + job_monitor.MonitorClass = cls + return job_monitor + + def test_the_first_statuses_of_the_next_map_are_not_lost(self): + """ + SQS, Pub/Sub and Azure Queue block in a read that stop() cannot cut + short. The monitor the wait() stopped used to be replaced in + start(), so its last read took the first statuses of the next map, + held them for futures it did not track and went away with them + """ + broker = queue.Queue() + + class LongPoll(PollingMessageMonitor): + backend_name = 'long-poll' + POLL_TIMEOUT = 0.5 + STORAGE_SWEEP_INTERVAL = 0 + + def _receive_messages(self, timeout): + try: + yield broker.get(timeout=timeout) + except queue.Empty: + return + + job_monitor = self._job_monitor(LongPoll) + with patch.object(LongPoll, 'prepare_config', return_value={}): + try: + job_monitor.prepare() + first = FakeFuture('M000', invoked=True) + job_monitor.start([first], job_id='M000', chunksize=1) + broker.put(_status(kind='__end__')[1]) + assert _wait_for(lambda: first.ready) + job_monitor.stop() + stopped = job_monitor.monitor + + job_monitor.prepare() + assert job_monitor.monitor is not stopped + assert not stopped.is_alive() + + # The workers of the next map report before start() + end, _raw = _status(kind='__end__') + end['job_id'] = 'M001' + broker.put(json.dumps(end)) + second = FakeFuture('M001', invoked=True) + job_monitor.start([second], job_id='M001', chunksize=1) + assert _wait_for(lambda: second.ready) + assert not stopped._held_status + finally: + job_monitor.cleanup() + + def test_rabbitmq_declares_the_queue_again_before_the_next_map(self): + """ + Cancelling the consumer of an auto-delete queue deletes it, so the + statuses published before start() declared it again were dropped + by the broker. The queue is declared before the workers are + invoked, and is no longer auto-delete + """ + config = { + 'lithops': {'monitoring': 'rabbitmq'}, + 'rabbitmq': {'amqp_url': 'amqp://guest@localhost'}, + } + pika = rabbitmq_backend.pika + with patch.object(pika, 'URLParameters'), \ + patch.object(pika, 'BlockingConnection') as connection: + job_monitor = self._job_monitor(None, config) + declare = connection.return_value.channel.return_value \ + .queue_declare + job_monitor.prepare() + assert declare.call_count == 1 + job_monitor.stop() + + job_monitor.prepare() + assert declare.call_count == 2 + assert declare.call_args.kwargs['queue'] == 'lithops-sess-0' + assert declare.call_args.kwargs['auto_delete'] is False + assert declare.call_args.kwargs['arguments']['x-expires'] > 0 + + def test_a_status_the_stopped_monitor_held_is_handed_over(self): + class Idle(PollingMessageMonitor): + backend_name = 'idle' + + def _receive_messages(self, timeout): + return [] + + job_monitor = self._job_monitor(Idle) + with patch.object(Idle, 'prepare_config', return_value={}): + try: + job_monitor.prepare() + stopped = job_monitor.monitor + # Read by the last poll of the monitor before it stopped + end, _raw = _status(kind='__end__') + end['job_id'] = 'M001' + stopped._apply_status_message(end) + job_monitor.stop() + + future = FakeFuture('M001', invoked=True) + job_monitor.start([future], job_id='M001', chunksize=1) + assert job_monitor.monitor is not stopped + assert future.ready is True + finally: + job_monitor.cleanup() + + +class TestPartialStatusMessages: + """ + A status that did not fit in a message arrives without what the client + needs to finish the call, and the full one is in the storage + """ + + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + def _partial(self): + from lithops.monitoring.status import PARTIAL_STATUS_KEY + payload, _raw = _status(kind='__end__') + payload.update({'exception': True, PARTIAL_STATUS_KEY: True}) + return payload + + def test_the_full_status_is_read_from_the_storage(self): + """ + Applied as it came, the future would re-raise from an exc_info that + is not there + """ + storage = MagicMock() + full, _raw = _status(kind='__end__') + full.update({'exception': True, 'exc_info': 'pickled traceback'}) + storage.get_call_status.return_value = full + monitor = self.FakePoll('sess-0', storage, queue.Queue(), {}, False, {}) + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + + monitor._apply_status_message(self._partial()) + + assert future.ready is True + assert future._call_status['exc_info'] == 'pickled traceback' + storage.get_call_status.assert_called_once_with( + 'sess-0', 'M000', '00000' + ) + + def test_a_partial_status_that_arrived_early_is_completed_later(self): + storage = MagicMock() + full, _raw = _status(kind='__end__') + full['result'] = 'inline result' + storage.get_call_status.return_value = full + monitor = self.FakePoll('sess-0', storage, queue.Queue(), {}, False, {}) + + monitor._apply_status_message(self._partial()) + storage.get_call_status.assert_not_called() + + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + assert future.ready is True + assert future._call_status['result'] == 'inline result' + + def test_without_the_storage_copy_the_call_is_left_running(self): + """ + For the storage sweep or the timeout checker to finish, rather than + finished with a status the future cannot read + """ + storage = MagicMock() + storage.get_call_status.return_value = None + monitor = self.FakePoll('sess-0', storage, queue.Queue(), {}, False, {}) + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + + monitor._apply_status_message(self._partial()) + + assert future.ready is False + assert future.running is True + assert future._call_status['type'] == '__init__' + + +class TestTokensOfTheLastChunk: + """ + The last chunk of a job is usually shorter than the chunksize: 10 calls + in chunks of 3 leave a last worker with 1. A token held back for it is + a worker the invoker counts as busy for ever, and once they add up to + max_workers every chunk still queued waits for good + """ + + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + def _futures(self, total=10): + return [ + FakeFuture('M000', invoked=True, call_id=f'{i:05d}') + for i in range(total) + ] + + def test_the_worker_of_the_last_chunk_frees_its_token(self): + tokens = queue.Queue() + monitor = self.FakePoll('sess-0', None, tokens, {'M000': 3}, True, {}) + monitor.add_futures(self._futures()) + end, _raw = _status(call_id='00009', kind='__end__', chunksize=3) + end.update({'activation_id': 'w4', 'worker_calls': 1}) + + monitor._apply_status_message(end) + + assert tokens.qsize() == 1 + + def test_the_size_of_the_job_frees_it_when_the_worker_does_not_say(self): + """ + A status from a worker that does not report the size of its chunk + is sized from the number of calls of the job, which the invoker + hands the monitor along with its futures + """ + class NotStarted(self.FakePoll): + def start(self): + pass + + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + job_monitor = JobMonitor('sess-0', storage) + job_monitor.MonitorClass = NotStarted + with patch.object(NotStarted, 'prepare_config', return_value={}): + job_monitor.start( + self._futures(), job_id='M000', chunksize=3, + generate_tokens=True, + ) + monitor = job_monitor.monitor + end, _raw = _status(call_id='00009', kind='__end__', chunksize=3) + end['activation_id'] = 'w4' + + monitor._apply_status_message(end) + + assert job_monitor.token_bucket_q.get_nowait() == '#' + assert monitor.job_total_calls == {'M000': 10} + + def test_a_full_chunk_still_waits_for_all_its_calls(self): + tokens = queue.Queue() + monitor = self.FakePoll('sess-0', None, tokens, {'M000': 3}, True, {}) + monitor.job_total_calls = {'M000': 10} + monitor.add_futures(self._futures()) + for call_id in ('00006', '00007'): + end, _raw = _status(call_id=call_id, kind='__end__', chunksize=3) + end['activation_id'] = 'w3' + monitor._apply_status_message(end) + assert tokens.qsize() == 0 + end, _raw = _status(call_id='00008', kind='__end__', chunksize=3) + end['activation_id'] = 'w3' + monitor._apply_status_message(end) + assert tokens.qsize() == 1 + + def test_the_storage_monitor_frees_the_worker_of_the_last_chunk(self): + tokens = queue.Queue() + monitor = StorageMonitor( + 'sess-0', MagicMock(), tokens, {'M000': 3}, True, + {'monitoring_interval': 1}, + ) + monitor.job_total_calls = {'M000': 10} + monitor.add_futures(self._futures()) + last = ('sess-0', 'M000', '00009') + + monitor._generate_tokens({(last, 'w4')}, {last}) + + assert tokens.get_nowait() == '#' + assert tokens.empty() + + def test_a_timed_out_call_hands_its_token_back(self): + """ + A worker that never reports back, because it was killed at the + execution timeout, gave no token back either + """ + tokens = queue.Queue() + monitor = self.FakePoll('sess-0', None, tokens, {'M000': 1}, True, {}) + future = FakeFuture( + 'M000', running=True, execution_timeout=1, activation_id='w1' + ) + future._call_status = {'worker_start_tstamp': time.time() - 100} + monitor.add_futures([future]) + + monitor._future_timeout_checker() + + assert future.ready is True + assert tokens.qsize() == 1 + # The worker was not dead after all, and its __end__ turns up late + end, _raw = _status(kind='__end__') + end['activation_id'] = 'w1' + monitor._apply_status_message(end) + assert tokens.qsize() == 1 + + def test_the_storage_monitor_hands_back_the_token_of_a_timed_out_call( + self, + ): + tokens = queue.Queue() + storage = MagicMock() + storage.get_call_status.return_value = None + monitor = StorageMonitor( + 'sess-0', storage, tokens, {'M000': 2}, True, + {'monitoring_interval': 1}, + ) + first = FakeFuture('M000', invoked=True, call_id='00000') + second = FakeFuture( + 'M000', running=True, call_id='00001', execution_timeout=1, + activation_id='w1', + ) + second._call_status = {'worker_start_tstamp': time.time() - 100} + monitor.add_futures([first, second]) + ids = [('sess-0', 'M000', '00000'), ('sess-0', 'M000', '00001')] + monitor.present_jobs = {'M000'} + + # Both calls started in w1; only the first one ever finished + monitor._generate_tokens({(i, 'w1') for i in ids}, {ids[0]}) + assert tokens.empty() + + monitor._future_timeout_checker([second]) + + assert second.ready is True + assert tokens.get_nowait() == '#' + assert tokens.empty() + + def test_a_nested_status_frees_no_token_of_this_executor(self): + tokens = queue.Queue() + monitor = self.FakePoll('sess-0', None, tokens, {'M000': 1}, True, {}) + nested_id = 'sess-0-A000-00000-1' + monitor.add_futures([ + FakeFuture('M000', invoked=True, executor_id=nested_id) + ]) + end, _raw = _status(kind='__end__') + end['executor_id'] = nested_id + + monitor._apply_status_message(end) + + assert tokens.qsize() == 0 + + +class TestNestedStatusesHeldByTheClient: + """ + A worker that waits on an executor of its own publishes every status of + it to the queue of the client as well, logs and all, and the client + holds them for futures it may never track + """ + + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + NESTED = 'sess-0-A000-00000-1' + + def _nested_end(self, call_id='00000', **extra): + payload, _raw = _status(call_id=call_id, kind='__end__') + payload['executor_id'] = self.NESTED + payload.update(extra) + return payload + + def _monitor(self): + monitor = self.FakePoll('sess-0', None, queue.Queue(), {}, False, {}) + monitor.add_futures([ + FakeFuture('A000', running=True, execution_timeout=60) + ]) + return monitor + + def test_a_status_is_held_without_its_logs(self): + monitor = self._monitor() + monitor._apply_status_message( + self._nested_end(logs='x' * 100_000, result='nested result') + ) + + ((_arrived, held),) = monitor._held_status.values() + assert 'logs' not in held + + # ...and still finishes the nested future once it is handed back + nested = FakeFuture('M000', running=True, executor_id=self.NESTED) + monitor.add_futures([nested]) + assert nested.ready is True + assert nested._call_status['result'] == 'nested result' + + def test_a_status_too_old_to_match_gives_way(self, monkeypatch): + """ + The future of a nested call comes to light in the status of the call + that returned it, which finishes within its execution timeout + """ + now = [1000.0] + monkeypatch.setattr( + 'lithops.monitoring.monitor.time.time', lambda: now[0] + ) + monitor = self._monitor() + monitor._apply_status_message(self._nested_end('00000')) + + now[0] += 60 + monitor.HELD_STATUS_SLACK + 1 + monitor._apply_status_message(self._nested_end('00001')) + + assert list(monitor._held_status) == [ + (self.NESTED, 'M000', '00001') + ] + + def test_a_status_within_the_execution_timeout_is_kept(self, monkeypatch): + now = [1000.0] + monkeypatch.setattr( + 'lithops.monitoring.monitor.time.time', lambda: now[0] + ) + monitor = self._monitor() + monitor._apply_status_message(self._nested_end('00000')) + now[0] += 60 + monitor._apply_status_message(self._nested_end('00001')) + + nested = FakeFuture( + 'M000', running=True, executor_id=self.NESTED, call_id='00000' + ) + monitor.add_futures([nested]) + assert nested.ready is True + + def test_a_repeated_status_moves_to_the_back_of_the_line( + self, monkeypatch, + ): + """ + The oldest status is the first one held, which a second status of + the same call must not leave at the front with a new arrival time + """ + now = [1000.0] + monkeypatch.setattr( + 'lithops.monitoring.monitor.time.time', lambda: now[0] + ) + monitor = self._monitor() + init = self._nested_end('00000') + init['type'] = '__init__' + monitor._apply_status_message(init) + monitor._apply_status_message(self._nested_end('00001')) + now[0] += 30 + monitor._apply_status_message(self._nested_end('00000')) + + assert list(monitor._held_status) == [ + (self.NESTED, 'M000', '00001'), + (self.NESTED, 'M000', '00000'), + ] + + def _localhost_redis(): try: import redis diff --git a/lithops/tests/test_multiprocessing.py b/lithops/tests/test_multiprocessing.py index f6656af5b..cf72567e0 100644 --- a/lithops/tests/test_multiprocessing.py +++ b/lithops/tests/test_multiprocessing.py @@ -127,21 +127,68 @@ def real_redis(): class FakeFuture: - def __init__(self, value=None, error=False): + """ + A call. Finished unless built ``running``, in which case it finishes + when finish() says so, or when something waits on it without a timeout + """ + + def __init__(self, value=None, error=False, exception=None, running=False): self.executor_id = 'sess-0' self.job_id = 'A000' self.call_id = '00000' - self.done = True - self.error = error - self.success = not error - self.ready = True self.stats = {'worker_exec_time': 0.5} self._value = value + self._exception = exception + self._fails = error or exception is not None + self.done = self.error = self.success = self.ready = False + if not running: + self.finish() + + def finish(self): + self.done = self.ready = True + self.error = self._fails + self.success = not self._fails + + def _set_exception(self): + """ + What FunctionExecutor.wait() does to the futures it gives up on: done, + with no status and no result + """ + self.done = True + self.ready = self.success = self.error = False + self._value = self._exception = None + + def status(self, throw_except=True, internal_storage=None, check_only=False): + if not (self.done or self.success): + assert check_only, 'a real future would block here' + return None + if self.error and throw_except and self._exception is not None: + raise self._exception + return {} def result(self, throw_except=True, internal_storage=None): + self.status(throw_except=throw_except) return self._value +def _fake_wait(futures, timeout=None, throw_except=True, **kwargs): + """ + lithops.wait.wait on fake futures: the calls still running finish while + it waits, unless it was given a timeout, which then runs out + """ + running = [f for f in futures if not (f.success or f.done)] + if running and timeout is not None: + raise TimeoutError( + 'Timeout of {} seconds exceeded waiting for function ' + 'activations to finish'.format(timeout) + ) + for fut in running: + fut.finish() + for fut in futures: + fut.status(throw_except=throw_except) + return list(futures), [] + + class FakeExecutor: """Stand-in for lithops.FunctionExecutor, recording what it was given""" @@ -149,10 +196,15 @@ def __init__(self, **kwargs): self.kwargs = kwargs self.executor_id = 'sess-0' self.invoker = type('I', (), {'max_workers': 7})() + # What lithops.wait.wait is handed, which the fake one reads the + # executor back from + self.internal_storage = types.SimpleNamespace(executor=self) self.futures = [] + self.next_futures = [] self.call_async_calls = [] self.map_calls = [] self.wait_calls = [] + self.lithops_wait_calls = [] self.get_result_calls = [] self.exited = False self.results = None @@ -161,11 +213,18 @@ def __init__(self, **kwargs): def call_async(self, func, data, **kwargs): self.call_async_calls.append((func, data, kwargs)) - return FakeFuture(self._next_value()) + future = self.next_futures.pop(0) if self.next_futures else FakeFuture(self._next_value()) + self.futures.append(future) + return future def map(self, func, iterdata, **kwargs): self.map_calls.append((func, list(iterdata), kwargs)) - return [FakeFuture(self._next_value()) for _ in iterdata] + futures = [FakeFuture(self._next_value()) for _ in iterdata] + self.futures.extend(futures) + return futures + + def _monitor_of(self, futures): + return None def _next_value(self): """Hands out `results` one call at a time, in order""" @@ -175,11 +234,25 @@ def _next_value(self): self._result_index += 1 return value - def wait(self, fs=None, **kwargs): - self.wait_calls.append((fs, kwargs)) - if self.wait_error is not None: - raise self.wait_error - return list(fs or []), [] + def wait(self, fs=None, throw_except=True, timeout=None, **kwargs): + """ + FunctionExecutor.wait(), which takes any exception as the end of the + job: it marks the futures it waited on failed and force-cleans the + data of every job of the executor, results not read yet included + """ + self.wait_calls.append((fs, dict(kwargs, throw_except=throw_except, timeout=timeout))) + futures = list(fs or self.futures) + try: + if self.wait_error is not None: + raise self.wait_error + return _fake_wait(futures, timeout=timeout, throw_except=throw_except) + except Exception: + for fut in futures: + fut._set_exception() + for fut in self.futures: + if not fut.done: + fut._set_exception() + raise def get_result(self, fs=None, **kwargs): self.get_result_calls.append((fs, kwargs)) @@ -191,6 +264,18 @@ def __exit__(self, exc_type, exc_value, traceback): self.exited = True +def _fake_lithops_wait(fs, internal_storage, job_monitor=None, download_results=False, + throw_except=True, timeout=None, **kwargs): + """lithops.wait.wait, for the futures of a FakeExecutor""" + executor = internal_storage.executor + executor.lithops_wait_calls.append((fs, dict( + kwargs, download_results=download_results, throw_except=throw_except, timeout=timeout, + ))) + if executor.wait_error is not None: + raise executor.wait_error + return _fake_wait(fs, timeout=timeout, throw_except=throw_except) + + @pytest.fixture def executor(monkeypatch): """Every FunctionExecutor the package builds becomes the same fake""" @@ -203,6 +288,7 @@ def factory(**kwargs): monkeypatch.setattr('lithops.multiprocessing.pool.FunctionExecutor', factory) monkeypatch.setattr('lithops.multiprocessing.process.FunctionExecutor', factory) + monkeypatch.setattr(mp_util, 'lithops_wait', _fake_lithops_wait) return built @@ -296,6 +382,53 @@ def test_a_reference_must_be_a_key_or_a_list_of_keys(self, redis): with pytest.raises(TypeError, match='referenced must be'): mp_util.RemoteReference(42, client=redis) + def test_an_expired_counter_does_not_take_the_object_with_it(self, redis): + """ + Once the counter had expired, the next owner to go away decremented + it to -1, took itself for the last one and deleted the object under + everybody still using it + """ + from lithops.multiprocessing import Lock + lock = Lock() + in_worker = pickle.loads(pickle.dumps(lock)) + # What the server does once the counter's expiry runs out + redis.delete(lock._ref._rck) + del in_worker + gc.collect() + assert lock.acquire(block=False) is True + + def test_the_counter_lives_as_long_as_the_object_is_used(self, redis): + """ + The object's keys are refreshed on every use but the counter only + when an owner came or went, so a lock in use for longer than + REDIS_EXPIRY_TIME lost its count, and the owners going away could no + longer tell when the last one had + """ + from lithops.multiprocessing import Lock + mp_config.set_parameter(mp_config.REDIS_EXPIRY_TIME, 10) + lock = Lock() + in_worker = pickle.loads(pickle.dumps(lock)) + for _ in range(10): + redis.advance(4) + with in_worker: + pass + assert lock._ref.refcount() == 2 + del in_worker + gc.collect() + assert lock._ref.refcount() == 1 + assert lock.acquire(block=False) is True + + def test_a_queue_in_use_keeps_its_counter(self, redis): + from lithops.multiprocessing import Queue + mp_config.set_parameter(mp_config.REDIS_EXPIRY_TIME, 10) + queue = Queue() + in_worker = pickle.loads(pickle.dumps(queue)) + for n in range(10): + redis.advance(4) + in_worker.put(n) + assert queue.get() == n + assert queue._ref.refcount() == 2 + class TestContext: @@ -487,6 +620,45 @@ def test_a_pool_gives_its_executor_back(self, executor): pass assert executor[0].exited + def test_close_and_join_run_the_callbacks(self, executor): + """ + The standard library idiom: submit with a callback, close(), join(), + and read what the callbacks collected. They used to run only from + get(), so nothing was collected, and every get() ran them again + """ + from lithops.multiprocessing import Pool + pool = Pool(processes=2) + executor[0].results = [3, 5] + collected = [] + + def slow_append(value): + time.sleep(0.2) + collected.append(value) + + applied = pool.apply_async(abs, (-3,), callback=slow_append) + mapped = pool.map_async(abs, [-5], callback=slow_append) + pool.close() + pool.join() + assert sorted(collected, key=repr) == [3, [5]] + assert applied.get() == 3 + assert mapped.get() == [5] + assert len(collected) == 2 + + def test_close_and_join_run_the_error_callback(self, executor): + from lithops.multiprocessing import Pool + pool = Pool(processes=1) + error = ValueError('bad input') + executor[0].next_futures.append(FakeFuture(exception=error)) + errors = [] + result = pool.apply_async(int, ('x',), error_callback=errors.append) + pool.close() + pool.join() + assert errors == [error] + for _ in range(2): + with pytest.raises(ValueError, match='bad input'): + result.get() + assert errors == [error] + class TestApplyResult: @@ -558,7 +730,7 @@ def test_the_shape_of_a_result_does_not_depend_on_later_calls(self, executor): def test_wait_forwards_the_timeout(self, executor): result = self._result(FakeExecutor()) result.wait(timeout=5) - assert result._executor.wait_calls[0][1]['timeout'] == 5 + assert result._executor.lithops_wait_calls[0][1]['timeout'] == 5 def test_a_timeout_raises_the_multiprocessing_error(self, executor): """ @@ -584,6 +756,52 @@ def test_a_wait_that_timed_out_does_not_poison_get(self, executor): fake.wait_error = None assert result.get() == 7 + def test_a_get_that_timed_out_leaves_the_call_to_finish(self, executor): + """ + FunctionExecutor.wait() takes a timeout as the end of the job and + marks the call failed: the result then said it was ready, and the + get() made once the call had finished came back with None + """ + from lithops.multiprocessing import Pool, TimeoutError as MpTimeoutError + pool = Pool(processes=1) + running = FakeFuture(42, running=True) + executor[0].next_futures.append(running) + result = pool.apply_async(abs, (-42,)) + with pytest.raises(MpTimeoutError): + result.get(timeout=5) + assert result.ready() is False + running.finish() + assert result.ready() is True + assert result.get() == 42 + + def test_a_call_that_fails_leaves_the_other_results_alone(self, executor): + """ + FunctionExecutor.wait() force-cleans the data of every job of the + executor when a call raises, so the results still on their way were + lost along with the one that failed + """ + from lithops.multiprocessing import Pool + pool = Pool(processes=2) + other_call = FakeFuture(7, running=True) + executor[0].next_futures += [FakeFuture(exception=ValueError('bad input')), other_call] + failing = pool.apply_async(int, ('x',)) + other = pool.apply_async(abs, (-7,)) + with pytest.raises(ValueError, match='bad input'): + failing.get() + assert other.ready() is False + other_call.finish() + assert other.get() == 7 + + def test_the_callback_runs_once_whatever_get_is_called(self, executor): + from lithops.multiprocessing import Pool + pool = Pool(processes=1) + executor[0].results = [4] + seen = [] + result = pool.apply_async(abs, (-4,), callback=seen.append) + assert result.get(timeout=5) == 4 + assert result.get() == 4 + assert seen == [4] + class TestIMapIterator: @@ -718,14 +936,42 @@ def test_join_waits_for_the_call(self, executor, redis): proc = Process(target=_double, args=(1,)) proc.start() proc.join() - assert executor[0].wait_calls + assert executor[0].lithops_wait_calls def test_join_forwards_the_timeout(self, executor, redis): from lithops.multiprocessing import Process proc = Process(target=_double, args=(1,)) proc.start() proc.join(timeout=5) - assert executor[0].wait_calls[0][1].get('timeout') == 5 + assert executor[0].lithops_wait_calls[0][1].get('timeout') == 5 + + def test_join_with_a_timeout_leaves_a_running_process_alone(self, executor, redis, monkeypatch): + """ + The standard library's join(timeout) returns None once the timeout + is up, and the process carries on. FunctionExecutor.wait() took the + timeout as the end of the job instead: join() raised TimeoutError + and the call was marked failed, so the next join() had nothing left + to wait for + """ + from lithops.multiprocessing import Process + running = FakeFuture(42, running=True) + monkeypatch.setattr(FakeExecutor, 'call_async', lambda self, func, data, **kwargs: running) + proc = Process(target=_double, args=(21,)) + proc.start() + assert proc.join(timeout=5) is None + assert not running.done + assert proc.join() is None + assert running.done and not running.error + assert [kwargs['timeout'] for _, kwargs in executor[0].lithops_wait_calls] == [5, None] + + def test_join_raises_what_the_target_raised(self, executor, redis, monkeypatch): + from lithops.multiprocessing import Process + failed = FakeFuture(exception=ValueError('bad input')) + monkeypatch.setattr(FakeExecutor, 'call_async', lambda self, func, data, **kwargs: failed) + proc = Process(target=_double, args=('x',)) + proc.start() + with pytest.raises(ValueError, match='bad input'): + proc.join() def test_the_unsupported_api_says_so(self, executor, redis): from lithops.multiprocessing import Process @@ -821,6 +1067,49 @@ def test_a_queue_survives_being_pickled(self, redis): assert queue.get() == 'from the worker' assert restored._maxsize == 3 + @pytest.mark.parametrize('queue_type', ['Queue', 'SimpleQueue']) + @pytest.mark.parametrize('get', [ + pytest.param(lambda q: q.get_nowait(), id='get_nowait'), + pytest.param(lambda q: q.get(timeout=0.5), id='get_with_timeout'), + ]) + def test_a_get_that_loses_the_last_item_to_another_consumer_does_not_block( + self, redis, monkeypatch, queue_type, get): + """ + Two consumers could both see the last item before either took it, + and the one that lost the race blocked in BLPOP for ever instead of + raising Empty. Here the other consumer, a worker holding a copy of + the queue, takes the item right after this one has looked + """ + import lithops.multiprocessing as mp + from queue import Empty + queue = getattr(mp, queue_type)() + in_worker = pickle.loads(pickle.dumps(queue)) + queue.put('last') + + taken_by_worker = [] + llen = redis.llen + + def worker_takes_it_after_a_look(key): + length = llen(key) + if length and not taken_by_worker: + taken_by_worker.append(in_worker.get()) + return length + + monkeypatch.setattr(redis, 'llen', worker_takes_it_after_a_look) + outcome = [] + + def consume(): + try: + outcome.append(get(queue)) + except Empty: + outcome.append(Empty) + + consumer = threading.Thread(target=consume, daemon=True) + consumer.start() + consumer.join(2) + assert not consumer.is_alive(), 'the get blocked' + assert (outcome + taken_by_worker).count('last') == 1 + class TestSimpleQueue: @@ -962,6 +1251,38 @@ def test_closing_one_end_leaves_the_shared_client_usable(self, redis): other_left.send('still working') assert other_right.recv() == 'still working' + def test_closing_a_listener_leaves_the_shared_client_usable(self, redis): + """ + The listener closed the process-wide client as well as its own + subscription, which broke every other connection of the process + """ + from lithops.multiprocessing import Pipe + from lithops.multiprocessing.connection import Listener + left, right = Pipe() + listener = Listener(('127.0.0.1', 6000)) + listener.close() + assert redis.closed is False + left.send('still working') + assert right.recv() == 'still working' + Pipe() + + def test_the_message_list_of_a_pipe_expires(self, redis): + """ + The expiry was set once, before the first push, when the list did + not exist yet and EXPIRE does nothing: the messages of a pipe that + was dropped half read stayed in Redis for ever. Redis also deletes + the list, expiry and all, every time the reader drains it + """ + from lithops.multiprocessing import Pipe + expiry = mp_config.get_parameter(mp_config.REDIS_EXPIRY_TIME) + left, right = Pipe() + left.send('first') + assert redis.expiries.get(right._handle) == expiry + assert right.recv() == 'first' + assert right._handle not in redis.expiries + left.send('second') + assert redis.expiries.get(right._handle) == expiry + class TestSemLock: @@ -1081,6 +1402,38 @@ def test_a_condition_survives_being_pickled(self, redis): restored = pickle.loads(pickle.dumps(cond)) assert restored._notify_handle == cond._notify_handle + def test_notify_wakes_as_many_waiters_as_asked(self, redis): + """threading.Condition.notify(n) wakes up to n waiters""" + from lithops.multiprocessing import Condition + cond = Condition() + woken = [] + + def waiter(name): + with cond: + if cond.wait(timeout=5): + woken.append(name) + + waiters = [threading.Thread(target=waiter, args=(n,), daemon=True) for n in range(3)] + for thread in waiters: + thread.start() + deadline = time.monotonic() + 5 + while redis.llen(cond._notify_handle) < 3 and time.monotonic() < deadline: + time.sleep(0.01) + + with cond: + cond.notify(2) + deadline = time.monotonic() + 5 + while len(woken) < 2 and time.monotonic() < deadline: + time.sleep(0.01) + time.sleep(0.1) + assert len(woken) == 2 + + with cond: + cond.notify() + for thread in waiters: + thread.join(5) + assert sorted(woken) == [0, 1, 2] + def test_a_timed_out_wait_does_not_consume_the_next_notify(self, redis): """ A waiter that gives up has to leave the notify list. The next @@ -1222,6 +1575,39 @@ def test_the_typecode_table_covers_the_standard_codes(self): assert sharedctypes.typecode_to_type['i'] is ctypes.c_int assert sharedctypes.typecode_to_type['d'] is ctypes.c_double + def test_indexing_past_either_end_raises_index_error(self, redis): + """ + What a ctypes array raises, and what code that walks an array by + index until IndexError relies on. It used to be a TypeError from + taking the length of the nil LINDEX answers with + """ + from lithops.multiprocessing import Array, RawArray + native = (ctypes.c_int * 3)(1, 2, 3) + for shared in (RawArray('i', [1, 2, 3]), Array('i', [1, 2, 3])): + assert shared[-1] == native[-1] == 3 + for index in (3, -4): + with pytest.raises(IndexError): + native[index] + with pytest.raises(IndexError): + shared[index] + with pytest.raises(IndexError): + native[index] = 0 + with pytest.raises(IndexError): + shared[index] = 0 + with pytest.raises(IndexError): + Array('c', b'abc')[3] + + def test_a_value_in_use_keeps_its_reference_count(self, redis): + """The count lives as long as the value is written, which refreshes it""" + from lithops.multiprocessing import Value + mp_config.set_parameter(mp_config.REDIS_EXPIRY_TIME, 10) + value = Value('i', 0) + in_worker = pickle.loads(pickle.dumps(value)) + for n in range(10): + redis.advance(4) + in_worker.value = n + assert value._ref.refcount() == 2 + class TestPackageSurface: @@ -2075,6 +2461,38 @@ def test_multiplying_in_place(self, real_redis): proxy *= 2 assert proxy.tolist() == [1, 2, 1, 2] + def test_a_long_list_can_be_repeated_copied_and_extended_with(self, real_redis): + """ + The server-side extend unpacked every value onto the Lua stack, which + holds about 8000, so past that l *= n, copying a list and extending + one with another raised "too many results to unpack" + """ + plain = list(range(10000)) + proxy = self._list(plain) + proxy *= 2 + assert len(proxy) == 20000 + assert self._list(proxy).tolist() == plain * 2 + other = self._list([-1]) + other.extend(proxy) + assert len(other) == 20001 + assert proxy.copy_proxy()[-1] == plain[-1] + + def test_using_a_list_refreshes_its_reference_count(self, real_redis): + """ + The object's keys are refreshed on every use, and the count has to + live as long as they do: an owner going away after it had expired + took the list with it + """ + proxy = self._list([1]) + rck = proxy._ref._rck + real_redis.expire(rck, 5) + proxy.append(2) + assert real_redis.ttl(rck) > 5 + real_redis.expire(rck, 5) + proxy.insert(0, 0) + assert real_redis.ttl(rck) > 5 + assert proxy.tolist() == [0, 1, 2] + def test_a_list_built_from_another_proxy_gets_an_expiry(self, real_redis): """The Lua extend only RPUSHed, so the key never expired""" source = self._list([1, 2]) diff --git a/lithops/tests/test_standalone.py b/lithops/tests/test_standalone.py index 586db67a4..f52e22308 100644 --- a/lithops/tests/test_standalone.py +++ b/lithops/tests/test_standalone.py @@ -137,6 +137,11 @@ def test_container_runtime_detects_docker_tags(self): assert is_container_runtime('python:3.12') is True assert is_container_runtime('lithops/python:3.12') is True + def test_container_runtime_keeps_suffixed_interpreters_native(self): + for runtime in ('python3.13t', 'python3.12d', 'python3-intel64'): + assert is_container_runtime(runtime) is False, runtime + assert is_container_runtime('registry/python') is True + def test_worker_setup_script_uses_native_python(self): script = get_worker_setup_script( {'backend': 'vm', 'runtime': 'python3', 'use_gpu': False, 'vm': {}}, diff --git a/lithops/tests/test_worker.py b/lithops/tests/test_worker.py index 953a562cb..519316ab6 100644 --- a/lithops/tests/test_worker.py +++ b/lithops/tests/test_worker.py @@ -102,6 +102,14 @@ def _boom(x): raise ValueError('nope') +def _exits(x): + sys.exit(3) + + +def _interrupted(x): + raise KeyboardInterrupt() + + class _UnpickleableError(Exception): """An exception instance cloudpickle cannot round-trip""" @@ -555,11 +563,73 @@ def _run_without_completion(self, task, exitcode): conn.poll.return_value = False return self._patch_run(task, jrp, conn) - def _exc_of(self, status): + def _exc_info_of(self, status): pickled = { c.args[0]: c.args[1] for c in status.add.call_args_list }['exc_info'] - return pickle.loads(ast.literal_eval(pickled))[0] + return pickle.loads(ast.literal_eval(pickled)) + + def _exc_of(self, status): + return self._exc_info_of(status)[0] + + def test_worker_failures_carry_the_handler_marker(self, tmp_path): + """ + The client drops the traceback of an exception whose first argument + is 'HANDLER' and prints its message on one line. Without the marker + a timed out call prints a traceback into the handler instead + """ + task = _task(execution_timeout=7) + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'missing.txt') + jrp = MagicMock() + jrp.is_alive.return_value = True + timeout = self._exc_info_of(self._patch_run(task, jrp, MagicMock())) + assert timeout[0] is TimeoutError + assert timeout[1].args == ( + 'HANDLER', + 'Function exceeded maximum time of 7 seconds and was killed', + ) + + exitcodes = [3] + if is_unix_system(): + exitcodes.append(-signal.SIGKILL) + for exitcode in exitcodes: + exc = self._exc_info_of( + self._run_without_completion(task, exitcode) + )[1] + assert exc.args[0] == 'HANDLER', exitcode + assert exc.args[1] == handler_module._jobrunner_death_reason( + exitcode + ) + + def test_a_failed_start_report_still_waits_for_the_function( + self, tmp_path + ): + """ + The init event is sent once the JobRunner runs. When sending it + fails, say the status object cannot be written to storage, the call + used to be reported as failed while the JobRunner kept running, + never joined, next to the following task of the worker + """ + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'job_stats.txt') + jrp = MagicMock() + jrp.is_alive.return_value = False + conn = MagicMock() + conn.poll.return_value = True + status = MagicMock() + status.send_init_event.side_effect = OSError('No space left on device') + self._patch_run( + task, jrp, conn, 'func_result_size 0\n', status=status + ) + jrp.join.assert_called_once_with(task.execution_timeout) + added = {c.args[0]: c.args[1] for c in status.add.call_args_list} + assert 'exception' not in added + assert added['func_result_size'] == 0 + status.send_finish_event.assert_called_once() @pytest.mark.skipif( not is_unix_system(), reason='there is no SIGKILL on Windows' @@ -1287,6 +1357,33 @@ def test_run_exception_records_exc_info(self): assert 'exc_info' in text jr.jobrunner_conn.send.assert_called_with('Finished') + def _reported_exception(self): + stats = {} + for line in open(self.stats).read().splitlines(): + key, value = line.split(' ', 1) + stats[key] = value + assert stats.get('exception') == 'True' + return pickle.loads(ast.literal_eval(stats['exc_info']))[1] + + def test_sys_exit_in_the_function_is_reported_as_its_exception(self): + """ + A SystemExit used to escape run(): the call was reported as done + with no func_result_size, and the client crashed on a KeyError + instead of re-raising what the function did + """ + jr = self._runner(_exits, {'x': 1}) + jr.run() + exc = self._reported_exception() + assert isinstance(exc, SystemExit) + assert exc.args == (3,) + jr.jobrunner_conn.send.assert_called_with('Finished') + + def test_keyboard_interrupt_in_the_function_is_reported(self): + jr = self._runner(_interrupted, {'x': 1}) + jr.run() + assert isinstance(self._reported_exception(), KeyboardInterrupt) + jr.jobrunner_conn.send.assert_called_with('Finished') + def test_an_unpickleable_exception_is_still_reported(self): """ The fallback for an exception that will not pickle has to pickle. diff --git a/lithops/worker/handler.py b/lithops/worker/handler.py index ecc9cc6b7..661c4b69b 100644 --- a/lithops/worker/handler.py +++ b/lithops/worker/handler.py @@ -540,8 +540,14 @@ def run_task(task: SimpleNamespace) -> None: # keeps the one-off cost of opening the monitoring client off the # critical path: the first call of a worker pays for a connection # (some 13 ms for AMQP, then kept for the whole process) while the - # function is already running, instead of delaying its start - call_status.send_init_event() + # function is already running, instead of delaying its start. + # The event is informational and the finish event reports the call + # all the same, so failing to send it must not abandon a JobRunner + # that is already running + try: + call_status.send_init_event() + except Exception as e: + logger.warning(f'Could not report the start of the call: {e}') jrp.join(task.execution_timeout) sys_monitor.stop() @@ -557,6 +563,7 @@ def run_task(task: SimpleNamespace) -> None: # cannot be terminated. It is left behind on purpose pass raise TimeoutError( + 'HANDLER', f'Function exceeded maximum time of {task.execution_timeout} ' f'seconds and was killed' ) @@ -575,8 +582,8 @@ def run_task(task: SimpleNamespace) -> None: f'process, which exited with code {exitcode}: {reason}' ) if _SIGKILL is not None and exitcode == -_SIGKILL: - raise MemoryError(reason) - raise RuntimeError(reason) + raise MemoryError('HANDLER', reason) + raise RuntimeError('HANDLER', reason) _add_task_stats(call_status, task.stats_file) diff --git a/lithops/worker/jobrunner.py b/lithops/worker/jobrunner.py index dc4501ddf..7a0dcc1ec 100644 --- a/lithops/worker/jobrunner.py +++ b/lithops/worker/jobrunner.py @@ -392,7 +392,11 @@ def run(self) -> None: ) pending_output = self._write_result(result) - except Exception: + except (Exception, SystemExit, KeyboardInterrupt): + # A sys.exit() or a KeyboardInterrupt raised by the function ends + # the function, not the worker, so it is reported like any other + # exception, as concurrent.futures does. Otherwise the call looks + # successful but has no result and no stats to read it from self._write_exception() finally: From dedd86cec7bcf712d30635759453928f39036000 Mon Sep 17 00:00:00 2001 From: JosepSampe Date: Wed, 23 Sep 2026 20:56:51 +0200 Subject: [PATCH 3/5] Fix multiprocesing --- CHANGELOG.md | 160 +++++------------- lithops/executors.py | 9 +- lithops/invokers.py | 21 ++- .../monitoring/backends/storage/storage.py | 4 +- lithops/monitoring/job_monitor.py | 9 + lithops/monitoring/monitor.py | 26 ++- lithops/multiprocessing/connection.py | 13 ++ lithops/multiprocessing/pool.py | 17 +- lithops/multiprocessing/process.py | 2 + lithops/tests/test_executors.py | 22 ++- lithops/tests/test_invokers.py | 22 +++ lithops/tests/test_monitor.py | 46 +++++ lithops/tests/test_multiprocessing.py | 118 ++++++++++++- 13 files changed, 336 insertions(+), 133 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index 2f41a2826..feda5e0e1 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -3,127 +3,49 @@ ## [v3.7.1.dev0] ### Added - -- [API] Added `lithops.concurrent.futures`, a `concurrent.futures`-compatible executor interface backed by Lithops. -- [Monitoring] Added Redis, AWS SQS, GCP Pub/Sub and Azure Queue Storage monitoring backends. -- [Core] Added `clean_jobs` to `wait()`, to keep the temporary data until the results are read. -- [AWS Batch] Added the `instance_types` config option for EC2/SPOT compute environments. -- [Multiprocessing] Added `timeout` to `acquire()`, and `_getvalue()`, `_callmethod()` and `copy_proxy()` to the manager proxies. -- [Multiprocessing] Added `ThreadPool`, the standard error classes and the module-level helpers (`freeze_support()`, `get_logger()`, `log_to_stderr()`). -- [Telemetry] Added `lithops.telemetry`, which turns the call statuses the monitor reads into 29 Prometheus or OpenTelemetry metrics. -- [Tests] Added a unit test suite for all non-backend modules. - -### Changed - -- [Core] `wait()` now returns two empty lists instead of `None` for empty input and reuses a single thread pool across polls, and `get_result()` deletes the temporary data once the results are in, not during the wait. -- [Core] Stopping an executor now waits for the invocations already in flight instead of returning while its invoker threads still run. -- [Monitoring] Reorganised job monitoring as pluggable backends: the message backends now delete their queue on cleanup instead of on every `stop()`, so a later `map()` can reuse it, and the storage backend lists only the prefixes of the jobs it still watches. -- [Monitoring] Status lines (Pending/Running/Done) are now logged every 30s instead of on every activation. -- [Monitoring] The RabbitMQ queue is no longer auto-deleted when its consumer goes away. It is deleted on cleanup, and expires after 24 hours unused if the client dies first. -- [Monitoring] A status message too big for the service (Azure Queue 64 KiB, SQS 256 KiB) leaves the task log out, and the rest of the status is then read from storage if it still does not fit. The logs of nested executors are not kept by the client either. -- [Core] `wait()` with a zero or negative `timeout` now raises `TimeoutError` right away if there are calls left, instead of waiting for ever, and only ends the jobs it waited on. -- [Core] A plain list or tuple of futures passed as `iterdata`, or as the data of `call_async()`, is now a chain: the function receives their results, not the `ResponseFuture` objects. -- [Worker] A function that raises `SystemExit` or `KeyboardInterrupt` now has it reported as its exception and re-raised by the client, as `concurrent.futures` does. -- [Multiprocessing] Manager proxies now follow the standard library API more closely, and `Manager()` returns a started manager instead of the class itself. -- [Multiprocessing] Shared objects now refresh their expiry when read, not only when written, and connection polling backs off from 1ms instead of waiting a fixed 100ms. -- [Multiprocessing] `imap()` and `imap_unordered()` now default to the configured chunksize. -- [Localhost] A job that ended cleanly is no longer killed on cleanup, so its runner log is kept. -- [Standalone] `docker login` now reads the password from stdin and quotes its arguments. -- [Storage] `CloudFileProxy.walk()` now yields nothing for a missing path, like `os.walk`, and `cloud_open()` raises `ValueError` on an unsupported mode. -- [Worker] Replaced the `multiprocessing` Manager queue of the worker pool with a POSIX pipe, and a failed task or job process now logs its output instead of only its return code. -- [CLI] `job list`, `worker list`, `image delete` and `image list` now reject unknown flags. -- [Joblib] `lithops_args` is now applied to the pool that runs the batches, and the shared-argument upload and download pools are capped at 32 threads. - -### Fixed - -- [Core] Fixed a repeated submission reusing the first serialization of a callable, freezing its captured state and the dependencies of the first runtime it ran on. -- [Core] Fixed executor IDs repeating in a process whose environment is reset between executors. -- [Core] Fixed `wait()` watching futures of another executor with a monitor that never sees them, leaving behind the monitors it started, and raising `TypeError` from `signal.alarm()` on a fractional timeout. -- [Core] Fixed `result()` returning `None` instead of re-raising when the call had already failed. -- [Core] Fixed `wait()` deleting a job's temporary data as soon as one of its calls was done, losing the results of the others still in storage. -- [Core] Fixed a failed or timed-out `wait()` deleting the data and dropping the queued calls of every job of the executor instead of the ones it waited on, and ignoring `clean_jobs`. -- [Core] Fixed `get_result()` raising `TypeError` when given a single future. -- [Core] Fixed a function's `sys.exit()` code being lost on the client, which then exited with status 0. -- [Core] Fixed module inspection crashing on a function whose `__module__` is `None`, and `SerializeIndependent` appending `lithops` to the preinstalled module list on every job. -- [Core] Fixed a hand-built `FuturesList` raising `AttributeError` instead of creating its executor, and pickling one detaching it from the executor it has. -- [Core] Fixed `find_free_port()` setting `SO_REUSEADDR` after the bind. -- [Core] Fixed `chunksize=0` and `execution_timeout=0` falling back to the config value. -- [Core] Fixed a second Ctrl+C after a failed call turning into `Error in sys.excepthook`, and logging at interpreter shutdown raising on an already closed stream. -- [Core] Fixed the function package carrying `.pytest_cache` directories and stale zips, a failed build leaving a partial zip behind, and `runtime_include_function` leaving the process in the build directory when the build failed. -- [Chaining] Fixed a plain list, tuple or slice of futures not being recognised as a chain, leaving its consumed results in `get_result()`, and `extra_args` failing every activation instead of raising at submit time. -- [Concurrent] Fixed `shutdown()` returning before a submission already in progress had been registered. -- [Job] Fixed a glob pattern in the object name raising `TypeError` instead of listing the objects, and a `head_object()` without `content-length` raising a bare `KeyError`. -- [Job] Fixed the last byte of an object being left out of its partitions, and folder markers being counted as objects, returning empty partitions. -- [Monitoring] Fixed a lost status message or an unread stored status turning into a bogus timeout, hanging `wait()` for ever, or one storage error being enough to declare a timeout. -- [Monitoring] Fixed a nested executor publishing statuses to a queue nobody declares, and failed RabbitMQ publishes being dropped with nothing in the log. -- [Monitoring] Fixed the first statuses of a `map()` issued after a `wait()` being lost: RabbitMQ had deleted the queue, and the SQS, Pub/Sub and Azure long poll of the stopped monitor swallowed them, leaving the calls to the storage sweep. -- [Monitoring] Fixed worker tokens leaking on the last, partial chunk of a job, on a timed-out call, on a call listed as done before its start mark, and on the final storage sweep, which could leave a later `map()` waiting for ever with a small `max_workers`. -- [Monitoring] Fixed two threads applying statuses at once handing back two tokens for one worker, or putting a finished call back to running. -- [Monitoring] Fixed the remote invoker deleting its queue while its calls still published to it, which retried every status five times and recreated queues and topics from the workers. -- [Monitoring] Fixed Azure Queue statuses over 64 KiB, such as those carrying a long log, always failing, and Pub/Sub making an admin request per call. -- [Monitoring] Fixed the statuses of nested executors piling up in the client, logs included, until 100k of them. -- [Redis] Fixed `put_object()` rejecting file-like objects, which made `upload_file()` always fail, and `head_object()` reporting every key as missing on Redis 7 and up, where the `DEBUG OBJECT` command it relied on is disabled. -- [Redis] Fixed `list_objects()` returning the object bodies instead of their keys and sizes and not skipping keys whose value is gone, `head_bucket()` returning a bool instead of the bucket metadata, and `delete_objects()` raising on an empty list. -- [Redis] Fixed the `bytes=L-` form of the `Range` argument raising `ValueError` and `bytes=-N` returning a single byte instead of the last N, and a ranged read of a missing key returning an empty result instead of raising. -- [Redis] `list_keys()` now walks the key space one pipelined round trip per level instead of one per directory, which cost a round trip per activation when listing a job. -- [Infinispan] Fixed `list_objects()` failing for the whole bucket when one of its objects was empty, since an empty object was reported as a missing key, and reading every value one after the other, at one round trip per key. -- [Infinispan] Fixed the `bytes=L-` and `bytes=-N` forms of the `Range` argument raising `ValueError`. -- [Infinispan] Fixed `head_bucket()` raising `NotImplementedError`, and `put_object()` ignoring a failed request. -- [Infinispan] Fixed the documented `mech` config key being ignored, so `mech: BASIC` silently authenticated with DIGEST. -- [Multiprocessing] Fixed `error_callback` never being called by `apply_async()`, `map_async()` and `starmap_async()`. -- [Multiprocessing] Fixed a full bounded `Queue` silently discarding what was put on it, which now waits and raises `Full`, and `Queue.empty()` always saying True over a pynng connection. -- [Multiprocessing] Fixed shared list writes being dropped or misplaced through slices, `remove()`, `index()`, `pop()` and `del`, and a slice of a shared array returning one element too many. -- [Multiprocessing] Fixed manager proxies not raising the `KeyError`, `ValueError` and `IndexError` the standard library raises. -- [Multiprocessing] Fixed concurrent updates to a shared object overwriting each other, and a shared object being deleted while on its way to a worker. -- [Multiprocessing] Fixed `Condition.wait()` never reporting a notify, keeping a recursively acquired lock so nobody could notify it, and not giving the lock back after a Redis error. -- [Multiprocessing] Fixed over-releasing a lock or bounded semaphore passing silently, and a re-entrant `RLock` giving back a token it never took. -- [Multiprocessing] Fixed `Value()` and `Array()` ignoring their `lock` argument. -- [Multiprocessing] Fixed `lithops.multiprocessing.context` being shadowed by a context instance, which broke every `mp.context.`. -- [Multiprocessing] Fixed closing one connection closing the Redis client the whole process shares. -- [Multiprocessing] Fixed a closed `Pool` leaving the monitor and invoker threads of its executor running, and the remote log feed keeping the interpreter alive at exit. -- [Multiprocessing] Fixed `AsyncResult.get()` raising the builtin `TimeoutError` instead of `multiprocessing.TimeoutError`. -- [Multiprocessing] Fixed `current_process()` in a worker creating an executor and a Redis client just to read a name, and `set_parameter()` rewriting the defaults it falls back to. -- [Multiprocessing] Fixed a `Pool` result that timed out or failed breaking the pool: it marked the calls failed and deleted the data of the other pending results. -- [Multiprocessing] Fixed `Pool` callbacks only running from `get()`, and again on every `get()`, instead of once when the task completes. -- [Multiprocessing] Fixed `Queue.get_nowait()` and `get(timeout=...)` blocking for ever when another consumer took the last item. -- [Multiprocessing] Fixed `Process.join(timeout)` raising and marking the process failed instead of returning. -- [Multiprocessing] Fixed shared objects being deleted in use after an hour, when their reference count expired, and pipe and queue messages never expiring. -- [Multiprocessing] Fixed another thread re-entering an `RLock` held by a different thread, a timed-out `Condition.wait()` taking the next `notify()`, and locks losing their expiry after the first release. -- [Multiprocessing] Fixed extending or repeating a shared list past about 8000 items failing, `Listener.close()` closing the shared Redis client, and an out-of-range `Array` index raising `TypeError`. -- [Multiprocessing] Added the `n` argument of `Condition.notify()`. -- [Localhost] Fixed the v2 job manager spinning a full core: on a job cleared mid-task that left a latch closed, and while an invocation was queueing. -- [Localhost] Fixed a partial `clear()` tearing down the consumers, tasks and latches of other jobs. -- [Localhost] Fixed a task starting after `stop()`, leaving a process nobody kills, and two concurrent `invoke()` calls clearing each other's in-progress flag. -- [Localhost] Fixed the v2 container being removed while other jobs were still running in it. -- [Localhost] Fixed v1 and v2 sharing one runner file, so a job could run under the other version's runner, and the runner exiting with success on an unknown command or a crash. -- [Localhost] Fixed a container image whose name starts with `python`, such as `python:3.12`, being run as a local interpreter, without taking free-threaded, debug or `pythonw` interpreters for images. -- [Standalone] Fixed a dict race that killed the budget keeper and left the VM running. -- [Standalone] Fixed a file descriptor leak of the runner log, one per task. -- [Standalone] Fixed the worker `/stop` endpoint iterating the process map while it changed, and `cancel_job_process()` raising on an emptied queue or a job with no queue. -- [Standalone] Fixed the master dropping the errors of its parallel worker and job requests, and a failed consume-mode worker setup script passing unnoticed. -- [Standalone] Fixed the SSH client keeping a client that failed to connect, and rejecting every private key that is not RSA. -- [Standalone] Fixed a reuse-mode worker blocking for ever on a stale queue connection instead of taking the next job. -- [Standalone] Fixed the worker service running a `python:*` container image with the local interpreter. -- [Storage] Fixed `delete_cloudobjects()` deleting the keys of one bucket from another when the objects spanned several, and deleting part of the list before rejecting a foreign object. -- [Storage] Fixed `CloudFileProxy.listdir()` returning nothing for its default argument. -- [Worker] Fixed the remote invoker returning before its invocations in flight were done. -- [Worker] Fixed an exception that does not pickle being reported as a success with no result, and `sys.exit()` in a function crashing `get_result()` with a `KeyError`. -- [Worker] Fixed timeouts and out-of-memory kills showing an internal traceback, and a failed start report leaving the function running while the call was reported failed. -- [Worker] Fixed the function process being aborted on macOS from the second call on, by setting Apple's fork-safety flag, and one killed by the OOM killer, or by any signal, being reported as a missing result. -- [Worker] Fixed the non-Unix worker pool sharing one task object across its calls, mixing up their ids, data and logs, by spawning a process per worker. -- [Azure] Fixed the `az` CLI calls deadlocking when a command filled the stderr pipe. -- [Azure Containers] Fixed a deploy racing a provisioning operation already in progress, and a container app left in `Failed` state never being recreated. -- [CLI] Fixed `job list` and `worker list` crashing when there was nothing to list. -- [CLI] Fixed `lithops clean` deleting the local temp directory of the jobs running at the same time on the same machine. -- [Cleaner] Fixed two cleaners racing for the pid file, and the cleaner skipping the requests it was started for. -- [Cleaner] Fixed the cleaner reading a request another process was still writing, and looping forever on one it could not read or classify. -- [Joblib] Fixed the backend being unused with joblib 1.4+, which renamed `apply_async` to `submit`. -- [Joblib] Fixed shared arguments going to the default storage instead of the configured one, a `KeyError` on those over 32KB from a check-then-read on the disk cache, and a race losing one of two proxied in the same call. -- [Joblib] Fixed `lithops[joblib]` missing `redis`, needed to import the backend. -- [IBM] Fixed the COS token manager raising if `ibm_botocore` hides the private expiry attribute. +- [API] `lithops.concurrent.futures`, a stdlib-compatible executor backed by Lithops. +- [Monitoring] Redis, AWS SQS, GCP Pub/Sub and Azure Queue Storage backends. +- [Core] `clean_jobs` on `wait()`, to keep temporary data until results are read. +- [AWS Batch] `instance_types` for EC2/SPOT compute environments. +- [Multiprocessing] `ThreadPool`, stdlib helpers, proxy methods, `acquire(timeout)` and `Condition.notify(n)`. +- [Telemetry] Prometheus and OpenTelemetry metrics from call statuses. +- [Tests] Unit test suite for all non-backend modules. + +### Changed +- [Core] `wait()` returns `[], []` for empty input, reuses one thread pool, and only ends the jobs it waited on. +- [Core] `get_result()` cleans after the results are in; stopping an executor waits for in-flight invocations. +- [Core] A list or tuple of futures as `iterdata` or `call_async()` data is now a chain. +- [Monitoring] Pluggable backends; queues live until cleanup (RabbitMQ expires after 24h); status lines every 30s. +- [Monitoring] Oversized status messages drop logs and fall back to storage. +- [Multiprocessing] Closer stdlib API: started `Manager()`, default `imap` chunksize, expiry refresh on read. +- [Worker] POSIX pipe instead of a Manager queue; `SystemExit`/`KeyboardInterrupt` reported as the function's exception. +- [Localhost] A clean job is no longer killed on cleanup, so its runner log is kept. +- [Standalone] `docker login` reads the password from stdin and quotes its arguments. +- [Storage] `CloudFileProxy.walk()` matches `os.walk` on a missing path; `cloud_open()` rejects an unsupported mode. +- [CLI] `job list`, `worker list`, `image delete` and `image list` reject unknown flags. +- [Joblib] `lithops_args` applied to the batch pool; upload/download pools capped at 32 threads. + +### Fixed +- [Core] Serialization, executor IDs, `FuturesList`, module inspection, `chunksize=0`, packaging, ports, and Ctrl+C/`sys.exit()`. +- [Core] `wait()`/`clean()`/`get_result()` no longer drop unread results, other jobs' calls, or FaaS concurrency after a failure. +- [Chaining] Lists, tuples and slices of futures recognised as a chain; `extra_args` fails at submit time. +- [Concurrent] `shutdown()` waits for an in-progress submit. +- [Job] Object listing, partitions, and `head_object()` without `content-length`. +- [Monitoring] Lost statuses, token leaks, races, nested-executor queues, oversized messages, and remote-invoker cleanup. +- [Redis] `put_object`, `head_object`, `list_objects`/`list_keys`, `delete_objects`, and `Range` reads. +- [Infinispan] `list_objects`, `Range`, `head_bucket`, `put_object`, and the `mech` config key. +- [Multiprocessing] Pool `get()`/`ready()`/`join()`/callbacks, queues, locks, lists, refcounts, and proxy errors. +- [Localhost] Job-manager races, container lifetime, runner files, and `python:*` images taken as interpreters. +- [Standalone] Budget keeper, log FD leak, `/stop`, SSH, reuse-mode queue, and `python:*` images. +- [Storage] `delete_cloudobjects()` across buckets; `CloudFileProxy.listdir()` default. +- [Worker] Remote invoker shutdown, unpickleable exceptions, timeout/OOM reports, macOS fork-safety, and the non-Unix pool. +- [Azure] `az` CLI deadlock; container-app deploy races. +- [CLI] Empty `job`/`worker` lists; `lithops clean` deleting other jobs' local temp. +- [Cleaner] Pid-file races and unreadable requests. +- [Joblib] joblib 1.4+ `submit`, shared-argument storage/cache, and the missing `redis` extra. +- [IBM] COS token manager with `ibm_botocore`. ### Removed - - [Storage] Removed the `infinispan_hotrod` storage backend. ## [v3.7.0] diff --git a/lithops/executors.py b/lithops/executors.py index 22958c953..dc3e9fc5e 100644 --- a/lithops/executors.py +++ b/lithops/executors.py @@ -783,7 +783,10 @@ def wait( else: # Only the jobs waited on end here. Another job of this # executor may still have calls queued for a free worker - self.invoker.discard_pending({f.job_key for f in futures}) + self.invoker.discard_pending( + {f.job_key for f in futures}, + {f.job_id for f in futures}, + ) self.job_monitor.remove(futures) for future in futures: future._set_exception() @@ -975,7 +978,9 @@ def clean( }) futures = self._as_future_list(fs or self.futures) - if force: + if force or on_exit: + # On exit nothing will read the leftover results, so a job + # that still has one unread call would otherwise stay forever present_jobs = { create_job_key(f.executor_id, f.job_id) for f in futures } diff --git a/lithops/invokers.py b/lithops/invokers.py index 388c26e4e..6732cf107 100644 --- a/lithops/invokers.py +++ b/lithops/invokers.py @@ -309,7 +309,7 @@ def stop(self, wait: bool = False): """ pass - def discard_pending(self, job_keys): + def discard_pending(self, job_keys, job_ids=None): """ Drops the calls of the given jobs not invoked yet. Only an invoker that queues calls has any @@ -554,10 +554,15 @@ def _empty_token_bucket(self): except queue.Empty: return - def discard_pending(self, job_keys): + def discard_pending(self, job_keys, job_ids=None): """ Drops the calls of the given jobs that are still waiting for a - worker, leaving the queued calls of every other job in place + worker, leaving the queued calls of every other job in place. + + The monitor also stops tracking those jobs, so their workers will + not hand tokens back. When no other job is still queued, the count + of running workers is forgotten; otherwise a later map() of the + same executor stays capped by workers that never free """ kept = [] while True: @@ -568,8 +573,18 @@ def discard_pending(self, job_keys): job, _ = item if job is None or job.job_key not in job_keys: kept.append(item) + other_jobs = False for item in kept: + job, _ = item + if job is not None: + other_jobs = True self.pending_calls_q.put(item) + if other_jobs: + return + self._empty_token_bucket() + self.running_workers = 0 + if job_ids and self.job_monitor is not None: + self.job_monitor.close_jobs(job_ids) def _drain_token_bucket(self): """ diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py index f61bfd665..187a6f953 100644 --- a/lithops/monitoring/backends/storage/storage.py +++ b/lithops/monitoring/backends/storage/storage.py @@ -255,7 +255,9 @@ def _release_free_workers(self): if worker_id in self.workers_done: continue job_id = self.worker_job.get(worker_id) - if job_id is None or job_id not in present_jobs: + if job_id is None or job_id in self._token_closed_jobs: + continue + if job_id not in present_jobs: continue chunksize = self.job_chunksize.get(job_id) if chunksize is None: diff --git a/lithops/monitoring/job_monitor.py b/lithops/monitoring/job_monitor.py index 5e056d741..7b413a26f 100644 --- a/lithops/monitoring/job_monitor.py +++ b/lithops/monitoring/job_monitor.py @@ -186,6 +186,15 @@ def remove(self, fs): if self.monitor and self.monitor.is_alive(): self.monitor.remove_futures(fs) + def close_jobs(self, job_ids): + """ + The invoker will no longer wait for these jobs. Later statuses of + theirs must not hand another token back: the capacity they held + was already forgotten + """ + if self.monitor is not None: + self.monitor.close_jobs(job_ids) + def stop(self): """ Asks the monitor thread to exit, without waiting for it. diff --git a/lithops/monitoring/monitor.py b/lithops/monitoring/monitor.py index f562a66e1..550750398 100644 --- a/lithops/monitoring/monitor.py +++ b/lithops/monitoring/monitor.py @@ -176,6 +176,11 @@ def __init__(self, executor_id, # vars for _generate_tokens self.workers_done = set() self.callids_done_worker = {} + # Jobs whose capacity the invoker already forgot. A late __end__ + # of theirs must not put another token in the bucket + self._token_closed_jobs = set() + # Jobs wait() dropped, whose workers still have to free a token + self._dropped_jobs = set() # vars for MessageMonitor._hold_status self._held_status = {} self._held_lock = threading.Lock() @@ -277,7 +282,19 @@ def remove_futures(self, fs): future_id = _future_id(future) if self._futures_by_id.get(future_id) is future: del self._futures_by_id[future_id] - self.present_jobs = {future.job_id for future in self.futures} + remaining = {future.job_id for future in self.futures} + self.present_jobs = remaining + self._dropped_jobs.update( + future.job_id for future in fs if future.job_id not in remaining + ) + + def close_jobs(self, job_ids): + """ + Marks jobs whose remaining worker tokens the invoker already + wrote off, so a late status does not hand one back again + """ + with self._apply_lock: + self._token_closed_jobs.update(job_ids) def tracked_futures(self): """ @@ -712,6 +729,8 @@ def _generate_tokens(self, call_status): # workers were never counted by the invoker of this one if call_status['executor_id'] != self.executor_id: return + if call_status.get('job_id') in self._token_closed_jobs: + return call_id = _status_id(call_status) worker_calls = call_status.get('worker_calls') @@ -759,6 +778,11 @@ def _apply_status_message(self, call_status): return if self._tag_future_as_ready(call_status): self._generate_tokens(call_status) + elif call_status.get('job_id') in self._dropped_jobs: + # wait() dropped the futures, but the worker is still + # this executor's and must free its token, unless the + # invoker already wrote the job off + self._generate_tokens(call_status) else: self._hold_status(call_status) diff --git a/lithops/multiprocessing/connection.py b/lithops/multiprocessing/connection.py index a4c2a8e97..70e58c6e5 100644 --- a/lithops/multiprocessing/connection.py +++ b/lithops/multiprocessing/connection.py @@ -268,6 +268,19 @@ def poll(self, timeout=0.0): self._check_readable() return self._poll(timeout) + def recv_bytes_within(self, timeout): + """ + The next message, waiting at most ``timeout`` seconds, or None + if none came. Zero or less does not wait at all. + + Redis overrides this so looking and taking are one step + """ + self._check_closed() + self._check_readable() + if not self._poll(max(timeout, 0)): + return None + return self._recv_bytes() + def __enter__(self): return self diff --git a/lithops/multiprocessing/pool.py b/lithops/multiprocessing/pool.py index c3985095a..24731bc62 100644 --- a/lithops/multiprocessing/pool.py +++ b/lithops/multiprocessing/pool.py @@ -338,7 +338,8 @@ def ready(self): # A call whose status has arrived is finished as far as the caller is # concerned; `done` only turns true once its result was downloaded return all( - fut.success or fut.done or fut.error for fut in self._futures + fut.ready or fut.success or fut.done or fut.error + for fut in self._futures ) def successful(self): @@ -364,6 +365,8 @@ def _wait(self, timeout, download_results): util.wait_futures(self._executor, self._futures, download_results=download_results, timeout=timeout) except TimeoutError as exc: + if timeout is None: + raise # Lithops reports it as the builtin, which is an OSError and so # not what `except multiprocessing.TimeoutError` catches raise ProcessTimeoutError(str(exc)) from exc @@ -403,9 +406,8 @@ def _handle(self): what bounds a get(timeout) the main thread may be running meanwhile """ try: - if not self._wait_in_thread(): - return - self._collect() + if self._wait_in_thread(): + self._collect() except Exception as exc: self._exception = exc try: @@ -464,10 +466,15 @@ def get(self, timeout=None): 'Timeout of {} seconds exceeded waiting for the result'.format(timeout) ) elif not self._collected: - self._wait(timeout, download_results=True) + # Download in _collect, which reraises. wait() with + # download_results=True and throw_except=False would mark a + # missing result as Error and hand None back + self._wait(timeout, download_results=False) self._collect() if self._exception is not None: raise self._exception + if self._cancelled.is_set() and not self._collected: + raise ProcessTimeoutError('the pool was terminated') return self._value diff --git a/lithops/multiprocessing/process.py b/lithops/multiprocessing/process.py index 12227eace..77915e0e3 100644 --- a/lithops/multiprocessing/process.py +++ b/lithops/multiprocessing/process.py @@ -253,6 +253,8 @@ def join(self, timeout=None): try: util.wait_futures(self._executor, [self._future], timeout=timeout) except TimeoutError: + if timeout is None: + raise return None exception = None diff --git a/lithops/tests/test_executors.py b/lithops/tests/test_executors.py index f85209e93..a3b23ca6c 100644 --- a/lithops/tests/test_executors.py +++ b/lithops/tests/test_executors.py @@ -259,6 +259,26 @@ def test_clean_keeps_a_job_with_results_still_to_read(self): executor.clean(fs=[read, unread], clean_cloudobjects=False) assert create_job_key('abc-0', 'M000') in executor.cleaned_jobs + def test_clean_on_exit_deletes_a_job_with_unread_results(self): + """ + After the process exits nothing will read the leftover result, so + keeping the prefix would leak it for the rest of the bucket's life + """ + read = FakeFuture(executor_id='abc-0', job_id='M000', done=True) + unread = FakeFuture( + executor_id='abc-0', job_id='M000', done=False, success=True + ) + executor = _bare_executor( + cleaned_jobs=set(), executor_id='abc-0', futures=[read, unread] + ) + with patch('lithops.executors._dump_cleaner_data') as dump, \ + patch('lithops.executors.sp.Popen'): + executor.clean( + fs=[read, unread], clean_cloudobjects=False, on_exit=True + ) + assert create_job_key('abc-0', 'M000') in executor.cleaned_jobs + dump.assert_called_once() + def test_clean_does_not_wrap_futures_list(self): future = FakeFuture(executor_id='abc-0', job_id='M000', done=True) futures = FuturesList([future]) @@ -461,7 +481,7 @@ def test_wait_exception_drops_its_queued_calls_and_reraises(self, mock_wait): executor.invoker.stop.assert_not_called() executor.invoker.discard_pending.assert_called_once_with( - {future.job_key} + {future.job_key}, {future.job_id} ) executor.job_monitor.remove.assert_called_once() assert future._exception_set is True diff --git a/lithops/tests/test_invokers.py b/lithops/tests/test_invokers.py index cafbbdb89..9e91efea2 100644 --- a/lithops/tests/test_invokers.py +++ b/lithops/tests/test_invokers.py @@ -325,11 +325,33 @@ def test_discard_pending_keeps_the_calls_of_other_jobs(self): other.job_key = 'sess-0/M001' inv._queue_call_ranges(failed, range(4)) inv._queue_call_ranges(other, range(3)) + inv.running_workers = 4 + inv.job_monitor.token_bucket_q.put('#') inv.discard_pending({'sess-0/M000'}) left = [] while not inv.pending_calls_q.empty(): left.append(inv.pending_calls_q.get()[0]) assert left == [other, other] + assert inv.running_workers == 4 + inv.job_monitor.close_jobs.assert_not_called() + + def test_discard_pending_forgets_workers_when_no_other_job_is_queued(self): + """ + wait() also drops those jobs from the monitor, so their workers + never put a token back. Without forgetting them, the next map() + of this executor stays capped by a count that never comes down + """ + inv = self._faas() + inv.running_workers = 4 + inv.job_monitor.token_bucket_q.put('#') + failed = _job(chunksize=1) + failed.job_key = 'sess-0/M000' + inv._queue_call_ranges(failed, range(2)) + inv.discard_pending({'sess-0/M000'}, {'M000'}) + assert inv.running_workers == 0 + assert inv.pending_calls_q.empty() + assert inv.job_monitor.token_bucket_q.empty() + inv.job_monitor.close_jobs.assert_called_once_with({'M000'}) def test_a_restart_forgets_tokens_handed_back_after_the_stop(self): """ diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index f87cc5cd4..18c22c84e 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -1355,6 +1355,52 @@ def _receive_messages(self, timeout): monitor._apply_status_message(second) assert tokens.qsize() == 1 + def test_a_removed_job_still_hands_its_token_back(self): + """ + wait() drops the futures of a failed job so they are no longer + tagged ready. The worker that ran them is still this executor's + and must free its token, or a later map() stays short of workers + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + tokens = queue.Queue() + monitor = FakePoll( + 'sess-0', None, tokens, {'M000': 1}, True, {} + ) + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + monitor.remove_futures([future]) + payload, _raw = _status(kind='__end__') + monitor._apply_status_message(payload) + assert tokens.qsize() == 1 + + def test_a_closed_job_does_not_hand_a_late_token_back(self): + """ + The invoker already forgot this job's workers. A late __end__ + must not put another token in the bucket + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + tokens = queue.Queue() + monitor = FakePoll( + 'sess-0', None, tokens, {'M000': 1}, True, {} + ) + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + monitor.remove_futures([future]) + monitor.close_jobs({'M000'}) + payload, _raw = _status(kind='__end__') + monitor._apply_status_message(payload) + assert tokens.qsize() == 0 + def test_stop_does_not_delete_cleanup_does_once(self): class FakePoll(PollingMessageMonitor): backend_name = 'fake' diff --git a/lithops/tests/test_multiprocessing.py b/lithops/tests/test_multiprocessing.py index cf72567e0..67a07f6e9 100644 --- a/lithops/tests/test_multiprocessing.py +++ b/lithops/tests/test_multiprocessing.py @@ -690,7 +690,8 @@ def test_ready_once_the_call_reported_back(self, executor): fake = FakeExecutor() finished = FakeFuture() finished.done = False - finished.success = True + finished.success = False + finished.ready = True result = self._result(fake, [finished]) assert result.ready() is True @@ -756,6 +757,67 @@ def test_a_wait_that_timed_out_does_not_poison_get(self, executor): fake.wait_error = None assert result.get() == 7 + def test_get_raises_when_the_result_cannot_be_downloaded(self, executor, monkeypatch): + """ + wait(..., download_results=True, throw_except=False) used to mark a + missing output as Error and hand None back, so get() returned None + with successful() False and no exception + """ + from lithops.multiprocessing.pool import ApplyResult + + class MissingOutput: + def __init__(self): + self.success = self.done = self.ready = self.error = False + self._output = None + + def result(self, throw_except=True, internal_storage=None, **kwargs): + if self.done: + return self._output + if not throw_except: + self.error = self.success = self.done = True + return None + raise Exception('Unable to get the result from call 0') + + def status(self, throw_except=True, internal_storage=None, **kwargs): + return {} + + def wait(fs, internal_storage, job_monitor, download_results, + throw_except, timeout): + for item in fs: + if download_results: + item.result( + throw_except=throw_except, + internal_storage=internal_storage, + ) + + monkeypatch.setattr('lithops.multiprocessing.util.lithops_wait', wait) + executor_fake = types.SimpleNamespace(internal_storage=None) + executor_fake._monitor_of = lambda fs: None + result = ApplyResult(executor_fake, [MissingOutput()], None, None) + with pytest.raises(Exception, match='Unable to get the result'): + result.get() + + def test_get_after_terminate_does_not_block_a_callback_result(self, executor): + """ + terminate() used to return from the handler before the event was + set, so get() with a callback blocked forever + """ + from lithops.multiprocessing import TimeoutError as MpTimeoutError + from lithops.multiprocessing.pool import ApplyResult + + pending = FakeFuture(running=True) + cancelled = threading.Event() + cancelled.set() + result = ApplyResult( + FakeExecutor(), [pending], lambda value: None, None, + cancelled=cancelled, + ) + result._handler.join(3) + assert not result._handler.is_alive() + assert result.ready() + with pytest.raises(MpTimeoutError, match='terminated'): + result.get() + def test_a_get_that_timed_out_leaves_the_call_to_finish(self, executor): """ FunctionExecutor.wait() takes a timeout as the end of the job and @@ -964,6 +1026,26 @@ def test_join_with_a_timeout_leaves_a_running_process_alone(self, executor, redi assert running.done and not running.error assert [kwargs['timeout'] for _, kwargs in executor[0].lithops_wait_calls] == [5, None] + def test_join_does_not_treat_a_storage_timeout_as_finished( + self, executor, redis, monkeypatch + ): + """ + socket.timeout is a TimeoutError. join() with no timeout used to + catch it and return, as if the process had finished + """ + from lithops.multiprocessing import Process + running = FakeFuture(running=True) + monkeypatch.setattr( + FakeExecutor, 'call_async', + lambda self, func, data, **kwargs: running, + ) + proc = Process(target=_double, args=(21,)) + proc.start() + executor[0].wait_error = TimeoutError('socket timed out') + with pytest.raises(TimeoutError, match='socket timed out'): + proc.join() + assert not running.done + def test_join_raises_what_the_target_raised(self, executor, redis, monkeypatch): from lithops.multiprocessing import Process failed = FakeFuture(exception=ValueError('bad input')) @@ -1172,6 +1254,40 @@ def test_handle_pairs_are_two_ends_of_one_id(self): assert connection.get_subhandle(a) == b assert connection.get_subhandle(b) == a + def test_recv_bytes_within_returns_none_when_nothing_is_ready(self): + from lithops.multiprocessing.connection import _ConnectionBase + + class Conn(_ConnectionBase): + def _poll(self, timeout): + return False + + def _recv_bytes(self, maxlength=None): + raise AssertionError('must not read') + + def _close(self, _close=None): + self._handle = None + + conn = Conn(1, readable=True, writable=False) + assert conn.recv_bytes_within(0) is None + conn.close() + + def test_recv_bytes_within_reads_when_ready(self): + from lithops.multiprocessing.connection import _ConnectionBase + + class Conn(_ConnectionBase): + def _poll(self, timeout): + return True + + def _recv_bytes(self, maxlength=None): + return b'x' + + def _close(self, _close=None): + self._handle = None + + conn = Conn(1, readable=True, writable=False) + assert conn.recv_bytes_within(1) == b'x' + conn.close() + def test_an_unknown_connection_type_is_rejected(self): from lithops.multiprocessing import connection with pytest.raises(Exception, match='Unknown connection type'): From d1ba15438922f9720a37042d318d2ad11b3cfc31 Mon Sep 17 00:00:00 2001 From: JosepSampe Date: Wed, 23 Sep 2026 21:49:49 +0200 Subject: [PATCH 4/5] Update --- CHANGELOG.md | 2 +- lithops/executors.py | 16 +++++++++++++++- lithops/monitoring/job_monitor.py | 8 ++++---- lithops/tests/test_executors.py | 22 +++++++++++++++------- 4 files changed, 35 insertions(+), 13 deletions(-) diff --git a/CHANGELOG.md b/CHANGELOG.md index feda5e0e1..3a05a826c 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -16,7 +16,7 @@ - [Core] `get_result()` cleans after the results are in; stopping an executor waits for in-flight invocations. - [Core] A list or tuple of futures as `iterdata` or `call_async()` data is now a chain. - [Monitoring] Pluggable backends; queues live until cleanup (RabbitMQ expires after 24h); status lines every 30s. -- [Monitoring] Oversized status messages drop logs and fall back to storage. +- [Monitoring] The job monitor stays up across `map()`/`wait()` of the same executor, so the next job is not delayed by joining and replacing it. - [Multiprocessing] Closer stdlib API: started `Manager()`, default `imap` chunksize, expiry refresh on read. - [Worker] POSIX pipe instead of a Manager queue; `SystemExit`/`KeyboardInterrupt` reported as the function's exception. - [Localhost] A clean job is no longer killed on cleanup, so its runner log is kept. diff --git a/lithops/executors.py b/lithops/executors.py index dc3e9fc5e..73a0393f9 100644 --- a/lithops/executors.py +++ b/lithops/executors.py @@ -460,6 +460,20 @@ def _cleanup_jobs(self, futures, exception=None, force=False): self.compute_handler.clear(present_jobs, exception=exception) self.clean(fs=futures, clean_cloudobjects=False, force=force) + def _release_finished_from_monitor(self, futures): + """ + Drops futures that have already reported back, so the monitor does + not keep listing their prefixes. The thread stays up: the next + map() of this executor adds to it instead of joining a stopped + one and spawning another + """ + finished = [ + f for f in futures + if getattr(f, 'ready', False) or f.success or f.done + ] + if finished: + self.job_monitor.remove(finished) + def _stop_monitor_if_idle(self, extra_fs=None): """ Stops the job monitor once there is no future left to watch, counting @@ -773,7 +787,7 @@ def wait( futures_from_executor_wait=not fs, ) - self._stop_monitor_if_idle(futures) + self._release_finished_from_monitor(futures) if do_clean and return_when == ALL_COMPLETED: self._cleanup_jobs(futures) diff --git a/lithops/monitoring/job_monitor.py b/lithops/monitoring/job_monitor.py index 7b413a26f..a902fbeac 100644 --- a/lithops/monitoring/job_monitor.py +++ b/lithops/monitoring/job_monitor.py @@ -99,10 +99,10 @@ def prepare(self): Creates backend resources (queues, keys) before workers are invoked, so the first status is not published into nowhere. - A monitor a wait() stopped is replaced here too, and not in start(), - which runs once the workers are already reporting: its thread may - still be in a read that takes the first statuses of the new job to - the grave, and RabbitMQ may already have deleted its queue + A monitor a failed wait() or the executor exit stopped is replaced + here, and not in start(), which runs once the workers are already + reporting: its thread may still be in a read that takes the first + statuses of the new job to the grave """ if self.monitor is None or self._thread_finished(): self._spawn_monitor(generate_tokens=False) diff --git a/lithops/tests/test_executors.py b/lithops/tests/test_executors.py index a3b23ca6c..7787ee02b 100644 --- a/lithops/tests/test_executors.py +++ b/lithops/tests/test_executors.py @@ -389,29 +389,37 @@ def test_wait_cleans_when_all_completed(self, mock_wait): assert cleanup.call_args.kwargs.get('exception') is None @patch('lithops.executors.wait') - def test_wait_stops_monitor_when_all_tracked_futures_are_done(self, mock_wait): + def test_wait_keeps_the_monitor_for_the_next_map(self, mock_wait): + """ + The monitor belongs to the executor. Stopping it after every wait() + made the next map() join that thread and spawn another, which is + what made a tight map/wait loop (Cubed) slower, and lost the first + statuses of the new job on a message backend + """ future = FakeFuture(done=True, success=True) executor = _bare_executor(futures=[future]) executor.wait([future], return_when=ALL_COMPLETED, show_progressbar=False) - executor.job_monitor.stop.assert_called_once() + executor.job_monitor.stop.assert_not_called() + executor.job_monitor.remove.assert_called_once_with([future]) @patch('lithops.executors.wait') - def test_wait_stops_monitor_before_cleaning(self, mock_wait): + def test_wait_drops_finished_futures_before_cleaning(self, mock_wait): future = FakeFuture(done=True, success=True) executor = _bare_executor(data_cleaner=True, futures=[future]) order = [] - executor._stop_monitor_if_idle = lambda *a, **k: order.append('stop') + executor._release_finished_from_monitor = lambda *a, **k: order.append('release') executor._cleanup_jobs = lambda *a, **k: order.append('clean') executor.wait([future], return_when=ALL_COMPLETED, show_progressbar=False) - assert order == ['stop', 'clean'] + assert order == ['release', 'clean'] @patch('lithops.executors.wait') - def test_wait_keeps_monitor_when_other_futures_are_pending(self, mock_wait): + def test_wait_does_not_drop_pending_futures_from_the_monitor(self, mock_wait): done = FakeFuture(done=True, success=True) pending = FakeFuture(done=False, success=False) executor = _bare_executor(futures=[done, pending]) - executor.wait([done], return_when=ALL_COMPLETED, show_progressbar=False) + executor.wait([done, pending], return_when=ALL_COMPLETED, show_progressbar=False) executor.job_monitor.stop.assert_not_called() + executor.job_monitor.remove.assert_called_once_with([done]) def test_exit_waits_for_the_invoker_threads(self): """ From b2211fb8edfd38786f74fd5e3e06fed41c2c4a0a Mon Sep 17 00:00:00 2001 From: JosepSampe Date: Wed, 23 Sep 2026 21:57:31 +0200 Subject: [PATCH 5/5] Update --- .../monitoring/backends/storage/storage.py | 9 ++++++++- lithops/storage/storage.py | 12 ++++++++++-- lithops/tests/test_monitor.py | 19 ++++++++++++++++++- lithops/tests/test_storage_layer.py | 12 ++++++++++++ 4 files changed, 48 insertions(+), 4 deletions(-) diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py index 187a6f953..0826cafa5 100644 --- a/lithops/monitoring/backends/storage/storage.py +++ b/lithops/monitoring/backends/storage/storage.py @@ -298,8 +298,15 @@ def _poll_and_process_job_status(self): Reads the job status from storage and applies it to the futures. Returns the call ids that are newly done """ + # Nothing tracked: do not list. An empty job_ids used to list the + # whole executor prefix, which on S3 is a LIST of every leftover + # job key and the function pickle, once per monitoring_interval, + # for as long as the monitor stays up after wait() + job_ids = self.job_ids() + if not job_ids: + return set() status = self.internal_storage.get_job_status( - self.executor_id, job_ids=self.job_ids() + self.executor_id, job_ids=job_ids ) callids_running, callids_done = status new_callids_done = ( diff --git a/lithops/storage/storage.py b/lithops/storage/storage.py index 0151161d3..29d19309d 100644 --- a/lithops/storage/storage.py +++ b/lithops/storage/storage.py @@ -381,8 +381,16 @@ def get_job_status(self, executor_id, job_ids: Optional[Iterable[str]] = None): have finished, as two sets. Listing the prefix of each given job keeps finished jobs out of the - listing; without job_ids the whole executor prefix is listed - """ + listing. ``job_ids=None`` still lists the whole executor prefix, for + callers that do not know the jobs. An empty collection means there + is nothing to watch: no list is issued. An empty set must not fall + through to the executor prefix, because that prefix is also a prefix + of every job key (``executor_id-job_id``) and of the function + pickle, and a LIST of it on object storage is both wide and + expensive + """ + if job_ids is not None and not job_ids: + return set(), set() if job_ids: keys = [] # Copied first: a caller may pass a set that its own threads diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index 18c22c84e..a4a7578d4 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -935,6 +935,7 @@ def test_tag_future_as_ready_queries_only_matching_ids_when_not_near_complete( def test_poll_and_process_returns_new_done_ids_and_tags(self): monitor = self._storage() + monitor.add_futures([FakeFuture('M000', invoked=True, call_id='00000')]) monitor._generate_tokens = MagicMock() monitor._tag_future_as_running = MagicMock() monitor._tag_future_as_ready = MagicMock() @@ -945,13 +946,29 @@ def test_poll_and_process_returns_new_done_ids_and_tags(self): new = monitor._poll_and_process_job_status() assert new == done monitor.internal_storage.get_job_status.assert_called_once_with( - 'sess-0', job_ids=set() + 'sess-0', job_ids={'M000'} ) monitor._generate_tokens.assert_called_once_with(running, done) monitor._tag_future_as_running.assert_called_once_with(running) monitor._tag_future_as_ready.assert_called_once_with(done) monitor._print_status_log.assert_called_once_with() + def test_poll_and_process_does_not_list_storage_when_idle(self): + """ + The monitor stays up after wait() with no futures left. A LIST of + the executor prefix then is a paid object-storage call for nothing + """ + monitor = self._storage() + monitor._generate_tokens = MagicMock() + monitor._tag_future_as_running = MagicMock() + monitor._tag_future_as_ready = MagicMock() + new = monitor._poll_and_process_job_status() + assert new == set() + monitor.internal_storage.get_job_status.assert_not_called() + monitor._generate_tokens.assert_not_called() + monitor._tag_future_as_running.assert_not_called() + monitor._tag_future_as_ready.assert_not_called() + def test_poll_and_process_emits_token_when_chunk_completes(self): monitor = self._storage() future0 = FakeFuture('M000', invoked=True, call_id='00000') diff --git a/lithops/tests/test_storage_layer.py b/lithops/tests/test_storage_layer.py index 1002e9cee..57e26d4e0 100644 --- a/lithops/tests/test_storage_layer.py +++ b/lithops/tests/test_storage_layer.py @@ -264,6 +264,18 @@ def test_get_job_status_lists_per_job_when_job_ids_given(self): 'storage', f'{JOBS_PREFIX}/{create_job_key("sess-0", "M000")}' ) + def test_get_job_status_does_not_list_when_job_ids_is_empty(self): + """ + After wait() drops the finished futures the monitor stays up with + no jobs. Falling through to the executor prefix would LIST every + leftover job and the function pickle on every poll + """ + internal = _bare_internal() + running, done = internal.get_job_status('sess-0', job_ids=set()) + assert running == set() + assert done == set() + internal.storage.list_keys.assert_not_called() + def test_get_call_status_and_output_missing_are_none(self): internal = _bare_internal() internal.storage.get_object.side_effect = StorageNoSuchKeyError('b', 'k')