diff --git a/CHANGELOG.md b/CHANGELOG.md index bf70b9f95..6256fbe3f 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -4,31 +4,25 @@ ### Added -- [API] Added `lithops.concurrent.futures`, a `concurrent.futures`-compatible executor interface (`submit`, eager `map`, stdlib `wait`/`as_completed`) backed by Lithops. See issue #1427. -- [Docs] Renamed the native executor documentation from "Futures API" to "Core API". +- [API] Added `lithops.concurrent.futures`, a `concurrent.futures`-compatible executor interface backed by Lithops. - [Tests] Added a unit test suite for all non-backend modules (18 files, 876 tests). -- [Core] Added a `log_prefix()` helper for uniform log prefixes across core and backends. -- [Core] Added a cache of serialized functions to avoid re-uploading the same function. -- [Core] Added `ShutdownSafeStreamHandler` to avoid tracebacks when logging on a closed stream. -- [Localhost] Added `localhost/utils.py` with helpers shared by the v1 and v2 backends. -- [AWS Batch] Added `instance_types` config option for EC2/SPOT compute environments. +- [Monitoring] Added Redis, AWS SQS (`aws_sqs`), GCP Pub/Sub (`gcp_pubsub`) and Azure Queue Storage (`azure_queue`) monitoring backends. ### Changed - [Worker] Replaced the `multiprocessing` Manager queue of the worker pool with a POSIX pipe. - [Core] Results under 8KB now travel in the call status instead of a separate storage object. -- [Core] Reorganised all non-backend modules for readability, with no behaviour change. +- [Core] Added a cache of serialized functions to avoid re-uploading the same function. +- [Monitoring] Reorganised job monitoring as pluggable backends. - [Core] `wait()` now returns two empty lists for empty input instead of `None`. -- [Core] `verify_args()` now raises a single message instead of a tuple. -- [Monitoring] The RabbitMQ queues of a call status now travel with the job. - [CLI] `job list`, `worker list`, `image delete` and `image list` now reject unknown flags. -- [CLI] `lithops clean --all` no longer shadows the `all` builtin. -- [CLI] `lithops clean` now empties the local temp directory instead of removing it, and leaves the pending cleaner requests of the other processes alone. +- [CLI] `lithops clean` now empties the local temp directory instead of removing it. - [Storage] `CloudFileProxy.walk()` now yields nothing for a missing path, like `os.walk`. - [Storage] `cloud_open()` now raises `ValueError` on an unsupported mode. - [Joblib] Capped the shared-argument upload and download pools at 32 threads. - [Joblib] `lithops_args` is now applied to the pool that runs the batches. - [Standalone] `docker login` now reads the password from stdin and quotes its arguments. +- [AWS Batch] Allow to set `instance_types` config option for EC2/SPOT compute environments. ### Fixed @@ -36,7 +30,8 @@ - [Chaining] Fixed pickling a `FuturesList` detaching the list being pickled from its executor. - [Chaining] Fixed a list or a slice of futures of a previous job not being recognised as a chain, which failed with an argument binding error instead. - [Chaining] `extra_args` now raises at submit time instead of letting every activation of the chained job fail on a missing argument. -- [Localhost] Fixed a deadlock on a `map` after `wait()` and `get_result()`, caused by stale work queue sentinels. +- [Monitoring] Redis, RabbitMQ and SQS now delete their queues only in ``cleanup()``, and keep the monitor thread until ``stop()``. +- [Monitoring] Status lines (Pending/Running/Done) are logged on start, every 30s, and when the job finishes, not on every activation. - [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. - [Localhost] Fixed the v2 job manager spinning a core while an invocation was queueing. @@ -53,11 +48,11 @@ - [Core] Fixed `find_free_port()` setting `SO_REUSEADDR` after the bind. - [Core] Fixed module inspection crashing on a function whose `__module__` is `None`. - [Core] Fixed a hand-built `FuturesList` raising `AttributeError` instead of creating its executor. -- [Core] Fixed the cleaner skipping requests and two cleaners racing for the pid file. -- [Core] Fixed `lithops clean` deleting the local temp directory of the jobs running at the same time on the same machine. -- [Core] Fixed the cleaner reading a request another process was still writing. -- [Core] Fixed the cleaner looping forever on a request it could not read or classify. -- [Core] Fixed the cleaner lock surviving a killed cleaner and blocking every later one. +- [Cleaner] Fixed the cleaner skipping requests and two cleaners racing for the pid file. +- [Cleaner] Fixed `lithops clean` deleting the local temp directory of the jobs running at the same time on the same machine. +- [Cleaner] Fixed the cleaner reading a request another process was still writing. +- [Cleaner] Fixed the cleaner looping forever on a request it could not read or classify. +- [Cleaner] Fixed the cleaner lock surviving a killed cleaner and blocking every later one. - [Monitoring] Fixed a nested executor publishing statuses to a queue nobody declares. - [Monitoring] Fixed the failed RabbitMQ publishes being dropped with nothing in the log. - [Worker] Fixed the memory monitor reporting a peak of zero where usage cannot be read. diff --git a/config/README.md b/config/README.md index 16b940e15..c1e6c4d13 100644 --- a/config/README.md +++ b/config/README.md @@ -154,7 +154,7 @@ if __name__ == '__main__': | lithops | backend | aws_lambda | no | Compute backend implementation. `localhost` is the default if no config or config file is provided. | | lithops | storage | aws_s3 | no | Storage backend implementation. `localhost` is the default if no config or config file is provided. | | lithops | data_cleaner | True | no | If True, automatically deletes temporary data written to `storage_bucket/lithops.jobs`. | -| lithops | monitoring | storage | no | Monitoring system implementation. Options: **storage** or **rabbitmq**. | +| lithops | monitoring | storage | no | Monitoring backend. Built-in: **storage**, **rabbitmq**, **redis**, **aws_sqs**, **gcp_pubsub**, **azure_queue**. | | lithops | monitoring_interval | 2 | no | Interval in seconds for monitoring checks when using **storage** monitoring. | | lithops | data_limit | 4 | no | Maximum size (in MB) for iterator data chunks. Set to False for unlimited size. | | lithops | execution_timeout | 1800 | no | Maximum execution time in seconds for functions. Functions exceeding this time are terminated. Can also be set per call via the `timeout` parameter. | diff --git a/config/config_template.yaml b/config/config_template.yaml index fa5e0c491..c2d553975 100644 --- a/config/config_template.yaml +++ b/config/config_template.yaml @@ -23,7 +23,7 @@ #backend: aws_lambda # Default: aws_lambda #storage: aws_s3 # Default: aws_s3 #data_cleaner: True # Clean intermediate data after execution. Default: True - #monitoring: storage # One of: storage, rabbitmq. Default: storage + #monitoring: storage # Monitoring backend name. Built-in: storage, rabbitmq, redis, aws_sqs, gcp_pubsub, azure_queue. Default: storage #monitoring_interval: 2 # Polling interval (seconds) when monitoring=storage. Default: 2 #data_limit: 4 # Max iterdata aggregated size (MiB) before using storage. Default: 4 #execution_timeout: 1800 # Per-call timeout in seconds. Default: 1800 @@ -561,6 +561,35 @@ #amqp_url: amqp://:@:/ +# ============================================================================= +# AWS SQS – optional overrides when `lithops.monitoring=aws_sqs`. Credentials +# and region are taken from the `aws` section if this one is empty. +# ============================================================================= +#aws_sqs: + #region: # Mandatory here or under `aws` + #access_key_id: + #secret_access_key: + #session_token: + + +# ============================================================================= +# GCP Pub/Sub – optional overrides when `lithops.monitoring=gcp_pubsub`. +# Project and credentials are taken from the `gcp` section if this one is empty. +# ============================================================================= +#gcp_pubsub: + #project_name: # Mandatory here or under `gcp` + #credentials_path: + + +# ============================================================================= +# Azure Queue Storage – optional overrides when `lithops.monitoring=azure_queue`. +# Account name and key are taken from `azure_storage` if this one is empty. +# ============================================================================= +#azure_queue: + #storage_account_name: + #storage_account_key: + + # ============================================================================= # Prometheus – pushed metrics when `lithops.telemetry=True` # ============================================================================= diff --git a/docs/source/design.rst b/docs/source/design.rst index 5db782428..f72241177 100644 --- a/docs/source/design.rst +++ b/docs/source/design.rst @@ -72,7 +72,7 @@ directly to a module or class in the ``lithops`` package: - Backend-specific dispatch. ``FaaSInvoker`` performs concurrent per-call invocations; ``BatchInvoker`` submits a single batch/job for many tasks. * - ``JobMonitor`` - - ``lithops/monitor.py`` + - ``lithops/monitoring/`` - Tracks completion through either ``StorageMonitor`` (polling) or ``RabbitmqMonitor`` (push notifications). * - ``InternalStorage`` diff --git a/docs/source/monitoring.rst b/docs/source/monitoring.rst index 7247b0978..98eea8c31 100644 --- a/docs/source/monitoring.rst +++ b/docs/source/monitoring.rst @@ -1,36 +1,217 @@ Monitoring ========== -By default, Lithops uses the storage backend to monitor function activations: each function activation stores a file -named *{id}/status.json* in Object Storage when it finishes its execution. This file contains statistics about the -execution, including whether the function activation ran successfully or not. Based on these files, the default -monitoring approach polls the Object Storage every few seconds to determine which function activations have finished -and which have not. +While a job runs, the client has to know which of its function activations have started, which have finished, and +whether each one succeeded. Lithops calls this *monitoring*, and it is what makes ``wait()``, ``get_result()`` and the +progress bar work. -Since this default approach can slow down total application execution time due to the number of requests it has to -make against the object storage, Lithops also integrates a RabbitMQ service to monitor function activations in real time. -With RabbitMQ, the content of the *{id}/status.json* file is sent through a queue. This speeds up total application -execution time since Lithops only needs one connection to the messaging service to monitor all function activations. -We currently support the AMQP protocol. +Monitoring is a *channel*, not a storage provider: it only decides how call statuses travel back to the client. Your +compute and storage backends are unaffected by the choice, and so are your results. -.. note:: The RabbitMQ server has to be accessible from both the client and the functions. For example, it could be deployed in a cloud server with a public IP address and with the AMQP port open (5672). -To enable Lithops to use this service, add the *AMQP_URL* key into the *rabbitmq* section in -the configuration, for example: +How it works +------------ + +Every activation reports twice: once when it starts, and once when it finishes. The final report carries the execution +statistics and whether the call raised an exception. + +Lithops can carry those reports in two ways. + +**Storage polling** (the default). Each activation writes its status into the storage backend the executor already +uses, under a key of its own: + +.. code:: + + lithops.jobs/-//.init # the call started + lithops.jobs/-//status.json # the call finished + +The client lists those keys every couple of seconds to work out what has happened. It needs no extra infrastructure, +which is why it is the default. The cost is that a job with many activations means many requests against the object +storage, and a status is only noticed on the next poll. + +**Message services.** The same status is published to a queue or a topic instead. The client holds one connection and +is notified as each message arrives, so a status shows up as soon as it is sent and the number of activations does not +change how much the client has to ask for. + +.. note:: + A message service has to be reachable **from both the client and the functions**. This is the usual reason a + message backend works locally but not in the cloud, or the other way around. + + +Which one to use +---------------- + +.. list-table:: + :header-rows: 1 + :widths: 18 34 22 26 + + * - ``monitoring`` + - What it needs + - Extra dependency + - Created per executor + * - ``storage`` + - nothing, reuses your storage backend + - none + - nothing + * - ``rabbitmq`` + - a RabbitMQ broker + - none + - one queue + * - ``redis`` + - a Redis server + - ``lithops[redis]`` + - one list + * - ``aws_sqs`` + - an AWS account + - ``lithops[aws]`` + - one queue + * - ``gcp_pubsub`` + - a GCP project + - ``lithops[gcp]`` + - one topic and subscription + * - ``azure_queue`` + - an Azure storage account + - ``lithops[azure]`` + - one queue + +**Start with** ``storage``. It works everywhere and needs nothing set up. Move to a message backend when one of these +actually shows up in your timings: jobs of many thousands of activations, where the storage requests add up; or short +functions, where waiting for the next poll is a noticeable part of the total. + +If you already run one of these services for something else, using it here costs you nothing extra. + + +What to expect +-------------- + +**Your results are never at risk.** Whichever backend is configured, the final status of every call is also written to +the object storage. If a message is lost, Lithops notices and reads the status back from there, so the job still +finishes normally. A message backend is a faster path for the same information, not a different source of truth. + +**Resources are cleaned up on exit.** A message backend creates one queue, topic or list per executor, named after the +executor id. It is created before the first function is invoked and deleted when the executor shuts down — when the +``with`` block ends, or on interpreter exit. A process killed hard enough to skip that leaves the resource behind, and +it has to be removed by hand. + +**Nested executors work.** A function may create a ``FunctionExecutor`` of its own. Its call statuses reach every +executor up the chain, so a client waiting on the outer job still sees the progress of the inner one. + +**A worker retries.** If publishing a status fails, the worker tries again a few times, backing off, before giving up +and logging an error. The status is still in the object storage either way. + + +Configuration +------------- + +Select the backend in the ``lithops`` section of your config file: .. code:: yaml + lithops: + monitoring: storage # storage | rabbitmq | redis | aws_sqs | gcp_pubsub | azure_queue + +or per executor: + +.. code:: python + + fexec = lithops.FunctionExecutor(monitoring='rabbitmq') + +``monitoring_interval`` sets how often the client polls, in seconds. It is used **only by the** ``storage`` **backend**; +message backends are event-driven and ignore it. + +.. code:: yaml + + lithops: + monitoring_interval: 2 + +.. note:: + The default is ``2``, except with the localhost storage backend, where it is ``0.1`` because polling a local + directory is cheap. + +Each backend then reads its own section. Where a matching cloud provider section already exists, it is used as the +default, so you rarely have to repeat credentials. + + +RabbitMQ +~~~~~~~~ + +.. code:: yaml + + lithops: + monitoring: rabbitmq + rabbitmq: - amqp_url: # amqp:// + amqp_url: # amqp://:@:/ + +``amqp_url`` is mandatory. The broker has to be reachable from your functions as well as from the client — for +instance a cloud server with a public IP and the AMQP port (5672) open. + +The same section is used by the Kubernetes backend with ``rabbitmq_executor: True`` and by the Singularity backend. -In addition, activate the monitoring service by setting ``monitoring: rabbitmq`` in the configuration (Lithops section): + +Redis +~~~~~ .. code:: yaml lithops: - monitoring: rabbitmq + monitoring: redis + redis: + host: + #port: 6379 + #username: + #password: -.. code:: python +``host`` is mandatory. This is the same section as the Redis storage backend, so a deployment that already stores data +in Redis needs no new keys. + + +AWS SQS +~~~~~~~ + +.. code:: yaml + + lithops: + monitoring: aws_sqs + + aws: + region: + #access_key_id: + #secret_access_key: + +``region`` is mandatory. Credentials may instead come from the environment or an instance role. Add an ``aws_sqs`` +section only if you need to override what is in ``aws``. + + +GCP Pub/Sub +~~~~~~~~~~~ + +.. code:: yaml + + lithops: + monitoring: gcp_pubsub + + gcp: + project_name: + #credentials_path: + +``project_name`` is mandatory, but it is read from the service account JSON when a credentials file is given. +``credentials_path`` falls back to ``GOOGLE_APPLICATION_CREDENTIALS``. Add a ``gcp_pubsub`` section only if you need to +override what is in ``gcp``. + + +Azure Queue Storage +~~~~~~~~~~~~~~~~~~~ + +.. code:: yaml + + lithops: + monitoring: azure_queue + + azure_storage: + storage_account_name: + storage_account_key: - fexec = lithops.FunctionExecutor(monitoring='rabbitmq') \ No newline at end of file +Both keys are mandatory. Add an ``azure_queue`` section only if you need to override what is in ``azure_storage``. +Azure only accepts lowercase queue names, so Lithops adjusts the name it derives from the executor id. diff --git a/examples/failed_futures.py b/examples/failed_futures.py index 73a89441d..50bb7c9db 100644 --- a/examples/failed_futures.py +++ b/examples/failed_futures.py @@ -1,9 +1,10 @@ """ -Simple Lithops example using the map method. -In this example the map() method will launch one -map function for each entry in 'iterdata'. Finally -it will print the results for each invocation with -fexec.get_result() +Simple Lithops example showing what happens when a function fails. + +Some of the functions below raise an exception. Passing +throw_except=False to get_result() makes Lithops hand back what it has +instead of re-raising, so the successful calls can be told apart from +the failed ones. """ import lithops import time diff --git a/examples/ibmcos_arg.py b/examples/ibmcos_arg.py index 8da0d03ef..b5f99f093 100755 --- a/examples/ibmcos_arg.py +++ b/examples/ibmcos_arg.py @@ -1,6 +1,6 @@ """ Simple Lithops example using the 'ibm_cos' parameter, which is -a ready-to-use ibm_boto3.CLient() instance. +a ready-to-use ibm_boto3.Client() instance. """ import lithops diff --git a/examples/joblib_backend.py b/examples/joblib_backend.py index 87a6f017e..94c2fd12f 100644 --- a/examples/joblib_backend.py +++ b/examples/joblib_backend.py @@ -1,3 +1,10 @@ +""" +Simple Lithops example using the joblib backend. + +Registering Lithops with joblib makes Parallel() run its jobs as cloud +functions, so code already written against joblib needs no changes +beyond the parallel_backend() line. +""" import joblib from joblib import Parallel, delayed from lithops.util.joblib import register_lithops diff --git a/examples/map.py b/examples/map.py index c93eab821..3570fea1c 100644 --- a/examples/map.py +++ b/examples/map.py @@ -18,6 +18,5 @@ def my_map_function(id, x): if __name__ == "__main__": iterdata = [1, 2, 3, 4] fexec = lithops.FunctionExecutor() - fexec.map(my_map_function, range(2)) - fexec.map(my_map_function, range(6)) + fexec.map(my_map_function, iterdata) print(fexec.get_result()) diff --git a/examples/map_cos_prefix.py b/examples/map_cos_prefix.py index d682535f5..d18e4ccb3 100644 --- a/examples/map_cos_prefix.py +++ b/examples/map_cos_prefix.py @@ -11,8 +11,8 @@ one map function for each object. So In this case you will get one result from the each object in the bucket. -In the reduce function there will be always one parameter -from where you can access to the partial results. +The reduce function takes a single parameter, holding the results of +the map functions that fed it. """ import lithops diff --git a/examples/map_internal.py b/examples/map_internal.py index f1867a275..2e8f0d764 100644 --- a/examples/map_internal.py +++ b/examples/map_internal.py @@ -1,6 +1,6 @@ """ -Simple Lithops example using the call_async method. -to spawn an internal map execution. +Simple Lithops example where a single function, invoked with +call_async(), runs a map() of its own from inside the cloud. """ import lithops diff --git a/examples/map_reduce_cos_bucket.py b/examples/map_reduce_cos_bucket.py index 31c7c8b01..aa40db04f 100644 --- a/examples/map_reduce_cos_bucket.py +++ b/examples/map_reduce_cos_bucket.py @@ -16,8 +16,8 @@ launched for all the objects in the Bucket. So In this case you will get just one result from the reduce method. -In the reduce function there will be always one parameter -from where you can access to the partial results. +The reduce function takes a single parameter, holding the results of +the map functions that fed it. """ import lithops diff --git a/examples/map_reduce_cos_key.py b/examples/map_reduce_cos_key.py index 1fb2a1ce8..2923851cb 100644 --- a/examples/map_reduce_cos_key.py +++ b/examples/map_reduce_cos_key.py @@ -19,8 +19,8 @@ partitions of the same object. In this case you will get one result for each object specified in 'iterdata' variable. -In the reduce function there will be always one parameter -from where you can access to the partial results. +The reduce function takes a single parameter, holding the results of +the map functions that fed it. """ import lithops diff --git a/examples/map_reduce_localhost.py b/examples/map_reduce_localhost.py index 5818b674d..7de5026da 100644 --- a/examples/map_reduce_localhost.py +++ b/examples/map_reduce_localhost.py @@ -3,19 +3,15 @@ counts the number of words inside each object specified in 'iterdata' variable. -This example processes some objects which are in a localhost path. - -As in this case you are processing objects from COS, the -map_reduce() method will first launch a partitioner to split -the objects in smaller chunks, thus increasing the parallelism -of the execution and reducing the total time needed to process -the data. After creating the partitions, it will launch one -map function for each partition, and one reducer for all -partitions of the same object. In this case you will get -one result for each object specified in 'iterdata' variable. - -In the reduce function there will be always one parameter -from where you can access to the partial results. +The objects are files in a local directory. + +Lithops first splits each object into smaller chunks, so that more +functions can work on it at once. It then runs one map function per +chunk, and one reduce function per object, which is why you get one +result per entry in 'iterdata'. + +The reduce function takes a single parameter, holding the results of +the map functions that fed it. """ import os @@ -73,5 +69,4 @@ def my_reduce_function(results): fexec = lithops.FunctionExecutor(backend='localhost', storage='localhost', log_level='DEBUG') fexec.map_reduce(my_map_function, iterdata, my_reduce_function, obj_chunk_number=2) - result = fexec.get_result() - print("Done!") + print(fexec.get_result()) diff --git a/examples/map_reduce_url.py b/examples/map_reduce_url.py index cfbe08fec..49e179efa 100644 --- a/examples/map_reduce_url.py +++ b/examples/map_reduce_url.py @@ -3,19 +3,15 @@ counts the number of words inside each object specified in 'iterdata' variable. -This example processes some objects which are in public URLs. - -As in this case you are processing objects from COS, the -map_reduce() method will first launch a partitioner to split -the objects in smaller chunks, thus increasing the parallelism -of the execution and reducing the total time needed to process -the data. After creating the partitions, it will launch one -map function for each partition, and one reducer for all -partitions of the same object. In this case you will get -one result for each object specified in 'iterdata' variable. - -In the reduce function there will be always one parameter -from where you can access to the partial results. +The objects are files behind public URLs. + +Lithops first splits each object into smaller chunks, so that more +functions can work on it at once. It then runs one map function per +chunk, and one reduce function per object, which is why you get one +result per entry in 'iterdata'. + +The reduce function takes a single parameter, holding the results of +the map functions that fed it. """ import lithops @@ -59,5 +55,4 @@ def my_reduce_function(results): if __name__ == "__main__": fexec = lithops.FunctionExecutor(log_level='INFO') fexec.map_reduce(my_map_function, iterdata, my_reduce_function) - result = fexec.get_result() - print("Done!") + print(fexec.get_result()) diff --git a/examples/monitoring.py b/examples/monitoring.py new file mode 100644 index 000000000..2428f4eb4 --- /dev/null +++ b/examples/monitoring.py @@ -0,0 +1,64 @@ +""" +Simple Lithops example showing how the client learns that the functions +have finished, which is what wait() and get_result() rely on. + +By default Lithops polls the storage backend: every function writes its +status there, and the client lists those files every couple of seconds. +That needs nothing extra, but a job with many functions means many +requests against the storage. + +Instead, the status can travel through a message service, which reaches +the client as soon as each function reports. Pick one with the +'monitoring' parameter, or with 'monitoring' in the lithops section of +the config: + + storage the default, no extra service needed + rabbitmq needs an 'amqp_url' in the rabbitmq section + redis needs a 'host' in the redis section + aws_sqs uses the aws section + gcp_pubsub uses the gcp section + azure_queue uses the azure_storage section + +The message service has to be reachable from the client *and* from the +functions. A broker on your laptop works for localhost runs, but a +function in the cloud cannot connect back to it, so a cloud run needs a +broker both sides can see. + +Run this example with the backend you have configured, for instance: + + lithops: + monitoring: redis + + redis: + host: 127.0.0.1 +""" +import lithops +import time + +TOTAL = 10 + +# Whichever message service your config has ready +MESSAGE_BACKEND = 'redis' + + +def my_function(x): + time.sleep(2) + return x + 7 + + +def run(monitoring): + print(f'--- monitoring={monitoring}') + start = time.time() + with lithops.FunctionExecutor(monitoring=monitoring) as fexec: + fexec.map(my_function, range(TOTAL)) + results = fexec.get_result() + assert results == [x + 7 for x in range(TOTAL)] + print(f' {TOTAL} functions done in {time.time() - start:.1f}s') + + +if __name__ == '__main__': + # The default: the client polls the storage backend + run('storage') + + # The same job, with the statuses pushed through a message service + run(MESSAGE_BACKEND) diff --git a/examples/rabbitmq_arg.py b/examples/rabbitmq_arg.py index e442aac03..8e54969f9 100755 --- a/examples/rabbitmq_arg.py +++ b/examples/rabbitmq_arg.py @@ -1,7 +1,7 @@ """ Simple Lithops example using 2 function invocations (writer, reader) with the 'rabbitmq' parameter, which is a pika.BlockingConnection() instance. -RabbitMQ amqp_url must be in configuration to make it working. +The rabbitmq section of the config must have an 'amqp_url'. """ import lithops @@ -24,7 +24,7 @@ def callback(ch, method, properties, body): channel = rabbitmq.channel() channel.queue_declare(queue=queue_name, auto_delete=True) # No effect if the queue already exists - channel.basic_consume(callback, queue=queue_name, no_ack=True) + channel.basic_consume(queue_name, callback, auto_ack=True) channel.start_consuming() rabbitmq.close() diff --git a/examples/remote_invoker.py b/examples/remote_invoker.py new file mode 100644 index 000000000..ced110640 --- /dev/null +++ b/examples/remote_invoker.py @@ -0,0 +1,49 @@ +""" +Simple Lithops example using the remote invoker. + +With 'remote_invoker' enabled the client does not invoke the map() +activations itself. It spawns one cloud function that does the invoking +from inside the cloud, which pays off when a job has many activations and +the client sits on a slow link. + +The feature is a backend setting rather than an API call, so nothing in +the code below is specific to it. Enable it in the config of the compute +backend: + + lithops: + backend: aws_lambda + storage: aws_s3 + + aws_lambda: + remote_invoker: True + +The remote invoker follows the calls of this executor from the cloud, so +it is monitored as well as the client is. With a message monitoring +backend the two watch a queue each: 'lithops-' for the +client and 'lithops--invoker' for the invoker, and every +call reports to both. Worth exercising with, since a queue is the case +where they could otherwise take each other's messages: + + lithops: + monitoring: aws_sqs +""" +import lithops +import time + +TOTAL_ACTIVATIONS = 20 + + +def my_map_function(id, x): + print(f"I'm activation number {id}") + time.sleep(2) + return x + 7 + + +if __name__ == '__main__': + fexec = lithops.FunctionExecutor() + fexec.map(my_map_function, range(TOTAL_ACTIVATIONS)) + results = fexec.get_result() + + print(results) + assert results == [x + 7 for x in range(TOTAL_ACTIVATIONS)] + print(f'{TOTAL_ACTIVATIONS} activations returned the expected results') diff --git a/examples/remote_logging.py b/examples/remote_logging.py index 22a1029a9..0d98bb368 100644 --- a/examples/remote_logging.py +++ b/examples/remote_logging.py @@ -1,3 +1,11 @@ +""" +Simple Lithops example that streams the logs of the functions back while +they are still running. + +Each function writes into a RemoteLogIOBuffer, and the client tails that +stream, so prints from inside the cloud show up locally instead of only +being available once the job is over. +""" import sys import lithops diff --git a/examples/retry.py b/examples/retry.py index c6aac1e43..b140e2875 100644 --- a/examples/retry.py +++ b/examples/retry.py @@ -1,3 +1,12 @@ +""" +Simple Lithops example using RetryingFunctionExecutor to run functions +that fail the first few times. + +Each input is set to fail a given number of times before it succeeds, so +the retries can be seen doing their work. The last input needs more +attempts than retries allows, which is how a call that never succeeds +looks. +""" import lithops from lithops.storage import Storage from lithops import RetryingFunctionExecutor diff --git a/examples/sklearn_job_1.py b/examples/sklearn_job_1.py index 86ef8a33e..a970b8893 100644 --- a/examples/sklearn_job_1.py +++ b/examples/sklearn_job_1.py @@ -1,3 +1,10 @@ +""" +Simple Lithops example running a scikit-learn hyperparameter search on +cloud functions, through the joblib backend. + +RandomizedSearchCV tries many parameter combinations, and each one is an +independent fit, so joblib hands them out as separate functions. +""" import numpy as np import joblib from lithops.util.joblib import register_lithops diff --git a/examples/sklearn_job_2.py b/examples/sklearn_job_2.py index d7aa5f13f..eb9ed9805 100644 --- a/examples/sklearn_job_2.py +++ b/examples/sklearn_job_2.py @@ -1,3 +1,10 @@ +""" +Simple Lithops example running a scikit-learn grid search on cloud +functions, through the joblib backend. + +GridSearchCV fits one model per point of the parameter grid, and joblib +hands each of them to a function. +""" import joblib from lithops.util.joblib import register_lithops from sklearn.datasets import load_digits diff --git a/examples/sklearn_job_3.py b/examples/sklearn_job_3.py index f35238080..568b98f8b 100644 --- a/examples/sklearn_job_3.py +++ b/examples/sklearn_job_3.py @@ -1,3 +1,10 @@ +""" +Simple Lithops example running a scikit-learn Pipeline grid search on +cloud functions, through the joblib backend. + +The whole pipeline is fitted inside each function, so the preprocessing +steps are applied on the same data split as the model they feed. +""" import joblib import pandas as pd from lithops.util.joblib import register_lithops diff --git a/examples/storage_os.py b/examples/storage_os.py index 6f794978e..d53d93f6c 100644 --- a/examples/storage_os.py +++ b/examples/storage_os.py @@ -1,3 +1,11 @@ +""" +Simple Lithops example using the cloud proxy, which makes the storage +backend look like a local filesystem. + +The open() and os imported here write to storage instead of the disk, so +familiar file code works unchanged, and a file written by a function can +be read back by the client. +""" import lithops from lithops.storage.cloud_proxy import open, os @@ -30,7 +38,7 @@ def map_func(x): # Get files that have been created in functions fexec = lithops.FunctionExecutor() fexec.map(map_func, [1, 2, 3, 4]) - res = fexec.get_result() + fexec.get_result() # waits for the functions to write their files with open('test/3.txt', 'r') as f: print(f.read()) diff --git a/examples/wait.py b/examples/wait.py index 971daa8e6..aed1bd91d 100755 --- a/examples/wait.py +++ b/examples/wait.py @@ -1,6 +1,6 @@ """ Simple Lithops example using rabbitmq to wait map function invocations -RabbitMQ amqp_url must be in configuration to make it working. +The rabbitmq section of the config must have an 'amqp_url'. """ import lithops import time diff --git a/lithops/config.py b/lithops/config.py index 68d7605be..f25a2844c 100644 --- a/lithops/config.py +++ b/lithops/config.py @@ -261,9 +261,31 @@ def default_config( for key, value in c.LITHOPS_DEFAULT_CONFIG_KEYS.items(): config_data['lithops'].setdefault(key, value) + _load_monitoring_backend_config(config_data) + return config_data +def _load_monitoring_backend_config(config_data): + """Lets the config module of the monitoring backend fill in its own defaults""" + from lithops.monitoring.backends import ( + import_backend_module, + resolve_backend, + ) + + # Resolved the same way the client and the workers resolve it, so that a + # config with no 'monitoring' key, or an explicit null, still reaches the + # config module of the backend that is going to be used + monitoring = resolve_backend(config_data) + config_data['lithops']['monitoring'] = monitoring + logger.debug(f"Loading Monitoring backend module: {monitoring}") + try: + module = import_backend_module(monitoring, 'config') + except ValueError as exc: + raise Exception(str(exc)) from exc + module.load_config(config_data) + + def default_storage_config(config_file=None, config_data=None, backend=None): """ Builds a Lithops configuration that only holds the storage backend, whose diff --git a/lithops/executors.py b/lithops/executors.py index de6d35f8d..67b5e2770 100644 --- a/lithops/executors.py +++ b/lithops/executors.py @@ -61,7 +61,7 @@ from lithops.standalone import StandaloneHandler from lithops.serverless import ServerlessHandler from lithops.storage.utils import create_job_key, CloudObject -from lithops.monitor import JobMonitor +from lithops.monitoring import JobMonitor logger = logging.getLogger(__name__) @@ -130,8 +130,8 @@ class FunctionExecutor: :param config_file: Path to the lithops config file :param backend: Compute backend to run the functions :param storage: Storage backend to store Lithops data - :param monitoring: Monitoring system implementation. - One of: storage, rabbitmq + :param monitoring: Monitoring backend name. + Built-in: storage, rabbitmq, redis, aws_sqs, gcp_pubsub, azure_queue :param log_level: Log level printing (INFO, DEBUG, ...). Set it to None to hide all logs. If this is param is set, all logging params in config @@ -172,13 +172,11 @@ def __init__( ) self.data_cleaner = self.config['lithops'].get('data_cleaner', True) - if self.data_cleaner and not self.is_lithops_worker: - atexit.register( - self.clean, - clean_cloudobjects=False, - clean_fn=True, - on_exit=True, - ) + if not self.is_lithops_worker: + # Registered whatever data_cleaner says: it decides whether the + # temporary data of the jobs is deleted, not whether the queue, + # topic or subscription this executor created outlives it + atexit.register(self._clean_at_exit) storage_config = extract_storage_config(self.config) self.internal_storage = InternalStorage(storage_config) @@ -215,9 +213,38 @@ def __enter__(self): def __exit__(self, exc_type, exc_value, traceback): """Context manager method.""" self.job_monitor.stop() - self.invoker.stop() + self.job_monitor.cleanup() + self.invoker.stop(wait=True) self.compute_handler.clear() + def _clean_at_exit(self): + """ + Cleans up while the interpreter is shutting down. + + The monitor resources go first and unconditionally: a queue, a topic + or a subscription this executor created is not temporary job data, + and nothing else comes back to delete it. + + Anything raised here is reported by atexit as an ignored exception + and does not stop the remaining hooks, so a Ctrl+C during shutdown + prints one traceback per executor still registered. Swallowing it + keeps that noise down, and there is nothing useful left to do with + an error at this point anyway + """ + try: + self.job_monitor.stop() + self.job_monitor.cleanup() + except BaseException as e: + logger.debug(f'Could not release the job monitor on exit: {e!r}') + + if not self.data_cleaner: + return + + try: + self.clean(clean_cloudobjects=False, clean_fn=True, on_exit=True) + except BaseException as e: + logger.debug(f'Could not clean up on exit: {e!r}') + @staticmethod def _build_config_overwrite(mode, backend, storage, monitoring, kwargs): """ @@ -311,6 +338,11 @@ def _invoke(self, job): """ Invokes a job and tracks its futures in this executor """ + # The queue, topic or key the workers report to has to be there + # before the first of them is invoked, or the first status would be + # published into nowhere. Done here rather than in __init__ so that + # building an executor does not create anything on its own + self.job_monitor.prepare() futures = self.invoker.run_job(job) self.futures.extend(futures) return futures @@ -678,7 +710,8 @@ def wait( timeout: Optional[int] = None, threadpool_size: Optional[int] = THREADPOOL_SIZE, wait_dur_sec: Optional[int] = None, - show_progressbar: Optional[bool] = True + show_progressbar: Optional[bool] = True, + clean_jobs: Optional[bool] = None ) -> Tuple[FuturesList, FuturesList]: """ Wait for the Future instances (possibly created by @@ -704,12 +737,17 @@ def wait( Default 1 second :param show_progressbar: whether or not to show the progress bar. + :param clean_jobs: Delete temporary job data when every + future is done. Default is ``data_cleaner``. ``get_result()`` + passes False so it can log that results are in before it + cleans. :return: `(fs_done, fs_notdone)` where `fs_done` is a list of futures that have completed and `fs_notdone` is a list of futures that have not completed. """ futures = self._as_future_list(fs or self.futures) + do_clean = self.data_cleaner if clean_jobs is None else clean_jobs try: wait( @@ -726,18 +764,18 @@ def wait( futures_from_executor_wait=not fs, ) - if self.data_cleaner and return_when == ALL_COMPLETED: - self._cleanup_jobs(futures) self._stop_monitor_if_idle(futures) + if do_clean and return_when == ALL_COMPLETED: + self._cleanup_jobs(futures) except (KeyboardInterrupt, Exception) as e: - self.invoker.stop() + self.invoker.stop(wait=True) self.job_monitor.remove(futures) for future in futures: future._set_exception() + self._stop_monitor_if_idle(futures) if self.data_cleaner: self._cleanup_jobs(futures, exception=e, force=True) - self._stop_monitor_if_idle(futures) raise fs_done, fs_notdone = _partition_futures(futures, download_results) @@ -786,7 +824,8 @@ def get_result( download_results=True, threadpool_size=threadpool_size, wait_dur_sec=wait_dur_sec, - show_progressbar=show_progressbar + show_progressbar=show_progressbar, + clean_jobs=False, ) result = [] @@ -806,6 +845,9 @@ def get_result( f'{log_prefix(self.executor_id)} - Finished getting results' ) + if self.data_cleaner: + self._cleanup_jobs(self._as_future_list(fs or self.futures)) + if len(result) == 1 and self.last_call != 'map': return result[0] @@ -897,6 +939,10 @@ def clean( if not hasattr(self, 'internal_storage'): return + if on_exit and hasattr(self, 'job_monitor'): + self.job_monitor.stop() + self.job_monitor.cleanup() + storage_config = self.internal_storage.get_storage_config() if cs: diff --git a/lithops/future.py b/lithops/future.py index 17d71c2a5..88f01a615 100644 --- a/lithops/future.py +++ b/lithops/future.py @@ -293,7 +293,14 @@ def _raise_call_exception(self, throw_except): # hook prints the one the function had in the worker instead. Anything # else raised afterwards restores the default hook def exception_hook(exctype, exc, trcbck): - if exctype == fn_exctype and str(exc) == str(fn_exc): + # Ctrl+C and sys.exit() are the interpreter going down, not the + # function failing. Formatting them here reads source files + # through linecache, so a second Ctrl+C lands inside this hook + # and turns into "Error in sys.excepthook" + if issubclass(exctype, (KeyboardInterrupt, SystemExit)): + sys.excepthook = sys.__excepthook__ + sys.__excepthook__(exctype, exc, trcbck) + elif exctype == fn_exctype and str(exc) == str(fn_exc): if self._handler_exception: logger.warning( f'Exception: {fn_exctype.__name__} - {fn_exc}' diff --git a/lithops/localhost/utils.py b/lithops/localhost/utils.py index e62f12325..1b44bc579 100644 --- a/lithops/localhost/utils.py +++ b/lithops/localhost/utils.py @@ -29,6 +29,34 @@ _COPY_IGNORE = shutil.ignore_patterns('__pycache__', '*.pyc', '*.pyo') +# (lithops_location, temp_dir, fingerprint) triples this process has copied +_COPIED_PACKAGES = set() + + +def _source_fingerprint(lithops_location: str) -> tuple: + """ + How many source files the package has and when the newest was written. + + Cheap enough to check on every executor (a stat per file, no reads), and + enough to notice the edits of a development install, where the package + does change under a running process + """ + newest = 0.0 + count = 0 + for dirpath, dirnames, filenames in os.walk(lithops_location): + dirnames[:] = [d for d in dirnames if d != '__pycache__'] + for filename in filenames: + if filename.endswith(('.pyc', '.pyo')): + continue + count += 1 + try: + mtime = os.stat(os.path.join(dirpath, filename)).st_mtime + except OSError: + continue + newest = max(newest, mtime) + return count, newest + + def copy_lithops_package( lithops_location: str, runner_src: str, @@ -42,29 +70,57 @@ def copy_lithops_package( staging directory first, then replace the destination under a file lock so one rmtree cannot delete another copy mid-flight. Bytecode caches are omitted because pytest and other processes rewrite them while we copy. + + Every FunctionExecutor calls this, so the tree is copied once and only + checked afterwards. Repeating it means one copytree of the whole + package per executor, each taking the cross-process lock, which + serialises executors that have nothing to do with each other, and + sessions running side by side. It is copied again if the destination + has gone missing, or if the source changed, which a development + install does under a running process. + + The runner is installed on every call, never skipped, and put in place + with a rename: a plain copy truncates the destination before writing + it, and a task process of another session starting in that window + would exec a half-written file. """ os.makedirs(temp_dir, exist_ok=True) dst_path = os.path.join(temp_dir, 'lithops') lock_path = os.path.join(temp_dir, '.lithops-copy.lock') - staging = tempfile.mkdtemp(prefix='lithops-src-', dir=temp_dir) - try: - shutil.copytree( - lithops_location, - os.path.join(staging, 'lithops'), - ignore=_COPY_IGNORE, - ) - with open(lock_path, 'a') as lock_file: - if fcntl is not None: - fcntl.flock(lock_file.fileno(), fcntl.LOCK_EX) - try: - shutil.rmtree(dst_path, ignore_errors=True) - shutil.move(os.path.join(staging, 'lithops'), dst_path) - finally: + + package_key = ( + lithops_location, temp_dir, _source_fingerprint(lithops_location) + ) + if package_key not in _COPIED_PACKAGES or not os.path.isdir(dst_path): + staging = tempfile.mkdtemp(prefix='lithops-src-', dir=temp_dir) + try: + shutil.copytree( + lithops_location, + os.path.join(staging, 'lithops'), + ignore=_COPY_IGNORE, + ) + with open(lock_path, 'a') as lock_file: if fcntl is not None: - fcntl.flock(lock_file.fileno(), fcntl.LOCK_UN) - shutil.copyfile(runner_src, runner_dst) + fcntl.flock(lock_file.fileno(), fcntl.LOCK_EX) + try: + shutil.rmtree(dst_path, ignore_errors=True) + shutil.move(os.path.join(staging, 'lithops'), dst_path) + finally: + if fcntl is not None: + fcntl.flock(lock_file.fileno(), fcntl.LOCK_UN) + _COPIED_PACKAGES.add(package_key) + finally: + shutil.rmtree(staging, ignore_errors=True) + + # Staged under a name of this process, then renamed over the + # destination, which is atomic on the same filesystem + runner_tmp = f'{runner_dst}.{os.getpid()}.tmp' + try: + shutil.copyfile(runner_src, runner_tmp) + os.replace(runner_tmp, runner_dst) finally: - shutil.rmtree(staging, ignore_errors=True) + if os.path.exists(runner_tmp): + os.remove(runner_tmp) def decode_process_output(data: Optional[object]) -> str: diff --git a/lithops/localhost/v1/localhost.py b/lithops/localhost/v1/localhost.py index ec4a4f116..baa6cc381 100644 --- a/lithops/localhost/v1/localhost.py +++ b/lithops/localhost/v1/localhost.py @@ -58,11 +58,13 @@ logger = logging.getLogger(__name__) -RUNNER_FILE = os.path.join(LITHOPS_TEMP_DIR, 'localhost-runner.py') +RUNNER_FILE = os.path.join(LITHOPS_TEMP_DIR, 'localhost-runner-v1.py') LITHOPS_LOCATION = os.path.dirname(os.path.abspath(lithops.__file__)) -# The local temp dir is mounted on /tmp, so this is where a container sees the -# runner that was copied to RUNNER_FILE -DOCKER_RUNNER_FILE = f'/tmp/{USER_TEMP_DIR}/localhost-runner.py' +# The local temp dir is mounted on /tmp, so this is where a container sees +# the runner that was copied to RUNNER_FILE. The name carries the version: +# v1 and v2 install a different runner, and a job of one started with the +# other's runner fails without saying why +DOCKER_RUNNER_FILE = f'/tmp/{USER_TEMP_DIR}/localhost-runner-v1.py' class LocalhostHandlerV1: @@ -143,7 +145,7 @@ def _run_queued_job( return stdout, stderr = process.communicate() - if process.returncode != 0: + if process.returncode > 0: log_process_failure( logger, f'{log_prefix(executor_id, job_id)} - Job process failed ' @@ -152,6 +154,11 @@ def _run_queued_job( stderr=stderr, log_file=RN_LOG_FILE, ) + elif process.returncode < 0: + logger.debug( + f'{log_prefix(executor_id, job_id)} - Job process exited ' + f'with signal {-process.returncode}' + ) logger.debug(f'{log_prefix(executor_id, job_id)} - Execution finished') def start_manager(self): @@ -211,11 +218,17 @@ def clean(self, **kwargs): def clear(self, job_keys=None, exception=None): """ - Drops the given jobs if they have not started yet and kills them if - they have. Jobs that were not named stay queued + Drops the given jobs if they have not started yet. Running ones + are killed when the job ended in an exception, or when no job is + named and the whole executor is going away; after a successful + wait on a named job they are left to finish so their runner log + stays in the file """ self._drop_queued_jobs(job_keys) - self.env.stop(job_keys) + # See LocalhostHandlerV2.clear(): a named job that ended cleanly + # keeps its runner log, an exception or a shutdown stops the job + if exception is not None or job_keys is None: + self.env.stop(job_keys) if self.job_manager: self.job_queue.put((None, None)) diff --git a/lithops/localhost/v2/localhost.py b/lithops/localhost/v2/localhost.py index 87612b1ca..823a1e342 100644 --- a/lithops/localhost/v2/localhost.py +++ b/lithops/localhost/v2/localhost.py @@ -64,11 +64,13 @@ logger = logging.getLogger(__name__) -RUNNER_FILE = os.path.join(LITHOPS_TEMP_DIR, 'localhost-runner.py') +RUNNER_FILE = os.path.join(LITHOPS_TEMP_DIR, 'localhost-runner-v2.py') LITHOPS_LOCATION = os.path.dirname(os.path.abspath(lithops.__file__)) -# The local temp dir is mounted on /tmp, so this is where a container sees the -# runner that was copied to RUNNER_FILE -DOCKER_RUNNER_FILE = f'/tmp/{USER_TEMP_DIR}/localhost-runner.py' +# The local temp dir is mounted on /tmp, so this is where a container sees +# the runner that was copied to RUNNER_FILE. The name carries the version: +# v1 and v2 install a different runner, and a job of one started with the +# other's runner fails without saying why +DOCKER_RUNNER_FILE = f'/tmp/{USER_TEMP_DIR}/localhost-runner-v2.py' # How long the job manager waits before looking again for the latch of # a job that is being invoked right now MANAGER_IDLE_WAIT = 0.1 @@ -186,12 +188,22 @@ def clean(self, **kwargs): def clear(self, job_keys=None, exception=None): """ - Drops the tasks of the given jobs that have not started yet, kills the - running ones and releases their latches so that the job manager can - finish. Jobs that were not named are left running + Drops the tasks of the given jobs that have not started yet. + Running ones are killed when the job ended in an exception, or + when no job is named and the whole executor is going away; after + a successful wait on a named job they are left to finish so their + runner log stays in the file instead of being dumped as a crash """ self.env.drop_pending_tasks(job_keys) - self.env.stop(job_keys) + # A named job that ended cleanly is left to finish, so its runner + # log stays in the file instead of being dumped as a crash. An + # exception, or the executor shutting down (no job named), stops + # the tasks instead: nobody is waiting on their output any more, + # and waiting for one holds up the shutdown for as long as it runs + if exception is not None or job_keys is None: + self.env.stop(job_keys) + else: + self.env.finish(job_keys) for job_key in list(self.env.jobs.keys()): if job_keys is not None and job_key not in job_keys: @@ -256,7 +268,7 @@ def _run_task_process(self, job_key_call_id: str, cmd: List[str]) -> None: stdout, stderr = process.communicate() - if process.returncode != 0: + if process.returncode > 0: log_process_failure( logger, f"Task process {job_key_call_id} failed with return " @@ -265,6 +277,11 @@ def _run_task_process(self, job_key_call_id: str, cmd: List[str]) -> None: stderr=stderr, log_file=RN_LOG_FILE, ) + elif process.returncode < 0: + logger.debug( + f"Task process {job_key_call_id} exited with signal " + f"{-process.returncode}" + ) self.task_processes.pop(job_key_call_id, None) logger.debug(f"Task process {job_key_call_id} finished") @@ -351,7 +368,14 @@ def stop(self, job_keys=None): unless jobs other than those are still to run """ self._kill_task_processes(job_keys or list(self.jobs.keys())) + self.finish(job_keys) + def finish(self, job_keys=None): + """ + Stops the environment without killing anything, leaving the task + processes of the given jobs to exit on their own. Kept running + when jobs other than those are still to run + """ if job_keys is not None and self._has_jobs_left(job_keys): logger.debug( "Localhost environment left running, it still has jobs to run" diff --git a/lithops/monitor.py b/lithops/monitor.py deleted file mode 100644 index e5ce7c393..000000000 --- a/lithops/monitor.py +++ /dev/null @@ -1,679 +0,0 @@ -# -# Copyright Cloudlab URV 2021 -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# http://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. -# - -import json -import pika -import logging -import time -import lithops -import pickle -import sys -import queue -import threading -import concurrent.futures as cf -from tblib import pickling_support - -from lithops.utils import _future_id, log_prefix, monitoring_queue_name - -pickling_support.install() - -logger = logging.getLogger(__name__) - -LOG_INTERVAL = 30 # Print monitor debug every LOG_INTERVAL seconds - - -def _status_id(call_status): - return ( - call_status['executor_id'], - call_status['job_id'], - call_status['call_id'], - ) - - -def _is_finished(fut): - return fut.ready or fut.success or fut.done - - -def _is_started(fut): - return fut.running or _is_finished(fut) - - -class Monitor(threading.Thread): - """ - Base class of the background threads that follow the futures of an - executor and move them along their states as their status arrives - """ - - def __init__(self, executor_id, - internal_storage, - token_bucket_q, - job_chunksize, - generate_tokens, - config): - - super().__init__() - self.executor_id = executor_id - self.futures = set() - self.internal_storage = internal_storage - self.should_run = True - self.token_bucket_q = token_bucket_q - self.job_chunksize = job_chunksize - self.generate_tokens = generate_tokens - self.config = config - self.daemon = True - - # vars for _generate_tokens - self.workers = {} - self.workers_done = [] - self.callids_done_worker = {} - self.present_jobs = set() - - def add_futures(self, fs): - """ - Extends the current thread list of futures to track - """ - self.futures.update(fs) - self.present_jobs.update(future.job_id for future in fs) - - def remove_futures(self, fs): - """ - Remove from the current thread a list of futures - """ - self._print_status_log() - self.futures.difference_update(fs) - self.present_jobs = {future.job_id for future in self.futures} - - def _all_ready(self): - """ - Checks if all futures are ready, success or done - """ - try: - return all(_is_finished(f) for f in self.futures) - except Exception: - # Other threads add futures to the set while this one iterates - # it. A concurrent update means there is still work to wait for - return False - - def _check_new_futures(self, call_status, f): - """ - Checks if a function returned new futures to track - """ - if 'new_futures' not in call_status: - return False - - f._set_futures(call_status) - self.futures.update(f._new_futures) - logger.debug( - f'{log_prefix(self.executor_id)} - Received {len(f._new_futures)} ' - 'new function Futures to track' - ) - - return True - - def _future_timeout_checker(self, futures): - """ - Checks if running futures exceeded the timeout - """ - current_time = time.time() - futures_running = [f for f in futures if f.running and f._call_status] - for fut in futures_running: - try: - start_tstamp = fut._call_status['worker_start_tstamp'] - fut_timeout = start_tstamp + fut.execution_timeout + 5 - if current_time > fut_timeout: - msg = ( - 'The function exceeded the execution timeout ' - f'of {fut.execution_timeout} seconds.' - ) - raise TimeoutError('HANDLER', msg) - except TimeoutError: - # Raising and catching the error right away is what fills - # sys.exc_info(), so that the client re-raises a real - # traceback for a worker that never reported back - pickled_exception = str(pickle.dumps(sys.exc_info())) - call_status = { - 'type': '__end__', - 'exception': True, - 'exc_info': pickled_exception, - 'executor_id': fut.executor_id, - 'job_id': fut.job_id, - 'call_id': fut.call_id, - 'activation_id': fut.activation_id, - 'worker_start_tstamp': start_tstamp, - 'worker_end_tstamp': time.time(), - } - fut._set_ready(call_status) - - def _print_status_log(self, previous_log=None, log_time=None): - """ - Logs how many calls are pending, running and done, but only when the - counts moved or the job has been silent for LOG_INTERVAL seconds - """ - if not self.futures: - return previous_log, log_time - callids_pending = callids_running = callids_done = 0 - for fut in self.futures: - if fut.invoked: - callids_pending += 1 - if fut.running: - callids_running += 1 - if _is_finished(fut): - callids_done += 1 - counts = (callids_pending, callids_running, callids_done) - still_working = not all(_is_finished(fut) for fut in self.futures) - if counts != previous_log or ( - still_working - and log_time is not None - and log_time > LOG_INTERVAL - ): - logger.debug( - f'{log_prefix(self.executor_id)} - Pending: ' - f'{callids_pending} - Running: {callids_running} - Done: {callids_done}' - ) - log_time = 0 - return counts, log_time - - -class RabbitmqMonitor(Monitor): - """ - Job monitor that learns the status of every call from the messages the - workers publish to a RabbitMQ queue - """ - - SLEEP_TIME = 2 - - def __init__( - self, - executor_id, - internal_storage, - token_bucket_q, - job_chunksize, - generate_tokens, - config - ): - super().__init__( - executor_id, - internal_storage, - token_bucket_q, - job_chunksize, - generate_tokens, - config - ) - - self.rabbit_amqp_url = config.get('amqp_url') - self.queue = monitoring_queue_name(self.executor_id) - self.tag = None - self._create_resources() - - def _create_resources(self): - """ - Creates RabbitMQ queues and exchanges of a given job - """ - logger.debug( - f'{log_prefix(self.executor_id)} - Creating RabbitMQ queue {self.queue}' - ) - - self.pikaparams = pika.URLParameters(self.rabbit_amqp_url) - self.connection = pika.BlockingConnection(self.pikaparams) - channel = self.connection.channel() - channel.queue_declare(queue=self.queue, auto_delete=True) - channel.close() - - def _delete_resources(self): - """ - Deletes RabbitMQ queues and exchanges of a given job. - """ - connection = pika.BlockingConnection(self.pikaparams) - channel = connection.channel() - if self.tag: - channel.basic_cancel(self.tag) - channel.queue_delete(queue=self.queue) - channel.close() - connection.close() - - def stop(self): - """ - Stops the monitor thread - """ - self.should_run = False - self._delete_resources() - - def _tag_future_as_running(self, call_status): - """ - Assigns a call_status to its future - """ - not_running_futures = [ - f for f in self.futures if not _is_started(f) - ] - for f in not_running_futures: - if _future_id(f) == _status_id(call_status): - f._set_running(call_status) - - def _tag_future_as_ready(self, call_status): - """ - Tags a future as ready based on call_status - """ - not_ready_futures = [ - f for f in self.futures if not _is_finished(f) - ] - for f in not_ready_futures: - if _future_id(f) == _status_id(call_status): - if not self._check_new_futures(call_status, f): - f._set_ready(call_status) - - def _generate_tokens(self, call_status): - """ - Hands a token back to the invoker once a whole worker is free - """ - if not self.generate_tokens or not self.should_run: - return - - call_id = _status_id(call_status) - worker_id = call_status['activation_id'] - done_for_worker = self.callids_done_worker.setdefault(worker_id, []) - done_for_worker.append(call_id) - - if ( - worker_id not in self.workers_done - and len(done_for_worker) == call_status['chunksize'] - ): - self.workers_done.append(worker_id) - if self.should_run: - self.token_bucket_q.put('#') - - def _on_message(self, ch, method, properties, body): - """ - Applies one status message to its future, and stops consuming once - there is nothing left to wait for - """ - call_status = json.loads(body.decode("utf-8")) - - if call_status['type'] == '__init__': - self._tag_future_as_running(call_status) - - elif call_status['type'] == '__end__': - self._generate_tokens(call_status) - self._tag_future_as_ready(call_status) - - if self._all_ready() or not self.should_run: - ch.stop_consuming() - ch.close() - - def _watch_timeouts(self): - """ - Logs the job status and expires overdue futures. Runs in its own - thread, as the monitor thread stays blocked on the queue - """ - previous_log = None - log_time = 0 - while self.should_run and not self._all_ready(): - previous_log, log_time = self._print_status_log( - previous_log=previous_log, log_time=log_time - ) - self._future_timeout_checker(self.futures) - time.sleep(self.SLEEP_TIME) - log_time += self.SLEEP_TIME - - def run(self): - """ - Consumes status messages from the queue until every future is done - """ - logger.debug( - f'{log_prefix(self.executor_id)} | Starting RabbitMQ job monitor' - ) - - channel = self.connection.channel() - threading.Thread(target=self._watch_timeouts, daemon=True).start() - - self.tag = channel.basic_consume( - self.queue, self._on_message, auto_ack=True - ) - channel.start_consuming() - self.tag = None - self._print_status_log() - logger.debug( - f'{log_prefix(self.executor_id)} | RabbitMQ job monitor finished' - ) - - -class StorageMonitor(Monitor): - """ - Job monitor that learns the status of every call by polling the storage - backend, where the workers leave their status objects - """ - - THREADPOOL_SIZE = 64 - - def __init__( - self, - executor_id, - internal_storage, - token_bucket_q, - job_chunksize, - generate_tokens, - config - ): - super().__init__( - executor_id, - internal_storage, - token_bucket_q, - job_chunksize, - generate_tokens, - config - ) - - self.monitoring_interval = config['monitoring_interval'] - - # vars for _generate_tokens - self.callids_running_worker = {} - self.callids_running_processed = set() - self.callids_done_processed = set() - - # vars for _mark_status_as_running - self.callids_running_processed_timeout = set() - - # vars for _mark_status_as_ready - self.callids_done_processed_status = set() - self._ready_pool = None - - def stop(self): - """ - Stops the monitor thread - """ - self.should_run = False - - def join(self, timeout=None): - """ - Waits for the monitor thread, and drops the pool it downloads the - statuses with, which outlives the thread on a join that timed out - """ - super().join(timeout) - self._shutdown_ready_pool() - - def _get_ready_pool(self): - if self._ready_pool is None: - self._ready_pool = cf.ThreadPoolExecutor( - max_workers=self.THREADPOOL_SIZE - ) - return self._ready_pool - - def _shutdown_ready_pool(self): - pool = self._ready_pool - if pool is None: - return - self._ready_pool = None - pool.shutdown(wait=False) - - def _tag_future_as_running(self, callids_running): - """ - Mark which futures are in running status based on callids_running - """ - current_time = time.time() - to_process = ( - callids_running - self.callids_running_processed_timeout - ) - pending = { - _future_id(f): f - for f in self.futures - if f.invoked and not _is_started(f) - } - for call in to_process: - f = pending.get(call[0]) - if f is None: - continue - call_status = { - 'type': '__init__', - 'activation_id': call[1], - 'worker_start_tstamp': current_time, - } - f._set_running(call_status) - - self.callids_running_processed_timeout.update(to_process) - self._future_timeout_checker(self.futures) - - def _tag_future_as_ready(self, callids_done): - """ - Mark which futures has a call_status ready to be downloaded - """ - not_ready_futures = [ - f for f in self.futures if not _is_finished(f) - ] - to_process = callids_done - self.callids_done_processed_status - fs_to_query = [] - - ten_percent = int(len(self.futures) * (10 / 100)) - if len(self.futures) - len(callids_done) <= max(10, ten_percent): - fs_to_query = not_ready_futures - else: - for f in not_ready_futures: - if _future_id(f) in to_process: - fs_to_query.append(f) - - if not fs_to_query: - return - - def get_status(f): - cs = self.internal_storage.get_call_status( - f.executor_id, f.job_id, f.call_id - ) - f._status_query_count += 1 - if cs: - if not self._check_new_futures(cs, f): - f._set_ready(cs) - return _future_id(f) - return None - - try: - call_ids_processed = set( - self._get_ready_pool().map(get_status, fs_to_query) - ) - except Exception: - return - finally: - # The final sweep of run() happens after the thread is done, so - # the pool it lazily recreated has to be dropped again - if not self.is_alive(): - self._shutdown_ready_pool() - - call_ids_processed.discard(None) - self.callids_done_processed_status.update(call_ids_processed) - - 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: - return - - running_new = ( - callids_running - self.callids_running_processed - ) - done_new = callids_done - self.callids_done_processed - - for call_id, worker_id in running_new: - self.workers.setdefault(worker_id, set()).add(call_id) - self.callids_running_worker[call_id] = worker_id - - for callid_done in done_new: - if callid_done in self.callids_running_worker: - worker_id = self.callids_running_worker[callid_done] - self.callids_done_worker.setdefault(worker_id, []).append( - callid_done - ) - - for worker_id in self.callids_done_worker: - job_id = self.callids_done_worker[worker_id][0][1] - if job_id not in self.present_jobs: - continue - chunksize = self.job_chunksize[job_id] - done_count = len(self.callids_done_worker[worker_id]) - if worker_id not in self.workers_done and done_count == chunksize: - self.workers_done.append(worker_id) - if self.should_run: - self.token_bucket_q.put('#') - else: - break - - self.callids_running_processed.update(running_new) - self.callids_done_processed.update(done_new) - - def _poll_and_process_job_status(self, previous_log, log_time): - """ - Reads the job status from storage and applies it to the futures. - Returns the call ids that are newly done, along with the updated - log state its caller has to pass back on the next round - """ - status = self.internal_storage.get_job_status( - self.executor_id, job_ids=self.present_jobs - ) - callids_running, callids_done = status - new_callids_done = ( - callids_done - self.callids_done_processed_status - ) - - self._generate_tokens(callids_running, callids_done) - self._tag_future_as_running(callids_running) - self._tag_future_as_ready(callids_done) - - previous_log, log_time = self._print_status_log(previous_log, log_time) - - return new_callids_done, previous_log, log_time - - def run(self): - """ - Polls the storage backend until the monitor is stopped, backing off - to the configured interval whenever a round brings nothing new - """ - logger.debug( - f'{log_prefix(self.executor_id)} - Starting Storage job monitor' - ) - - wait_dur_sec = self.monitoring_interval - previous_log = None - log_time = 0 - - while self.should_run: - try: - new_callids_done, previous_log, log_time = ( - self._poll_and_process_job_status( - previous_log, log_time - ) - ) - if new_callids_done: - wait_dur_sec = self.monitoring_interval / 5 - else: - wait_dur_sec = self.monitoring_interval - except Exception as e: - logger.error( - f'{log_prefix(self.executor_id)} - Error during ' - f'monitor: {e}', - exc_info=True, - ) - if not self.should_run: - break - time.sleep(wait_dur_sec) - log_time += wait_dur_sec - - # One last sweep, so that statuses written between the final poll - # and the stop are not lost. The storage may already be gone - try: - self._poll_and_process_job_status(previous_log, log_time) - except Exception: - pass - - self._shutdown_ready_pool() - logger.debug( - f'{log_prefix(self.executor_id)} - Storage job monitor finished' - ) - - -class JobMonitor: - """ - Owns the monitor thread of one executor, and picks the implementation - that matches the configured monitoring backend - """ - - def __init__(self, executor_id, internal_storage, config=None): - self.executor_id = executor_id - self.internal_storage = internal_storage - self.storage_config = internal_storage.get_storage_config() - self.storage_backend = internal_storage.backend - self.config = config - self.type = ( - config['lithops']['monitoring'].lower() if config else 'storage' - ) - - self.token_bucket_q = queue.Queue() - self.monitor = None - self.job_chunksize = {} - - self.MonitorClass = getattr( - lithops.monitor, - f'{self.type.capitalize()}Monitor' - ) - - def start(self, fs, job_id=None, chunksize=None, generate_tokens=False): - """ - Tracks a new set of futures, spawning the monitor thread unless a - live one can take them over - """ - if self.type == 'storage': - interval = self.storage_config['monitoring_interval'] - monitor_config = {'monitoring_interval': interval} - else: - monitor_config = self.config.get(self.type) - - if job_id: - self.job_chunksize[job_id] = chunksize - - if not self.monitor or not self.monitor.is_alive(): - self.monitor = self.MonitorClass( - executor_id=self.executor_id, - internal_storage=self.internal_storage, - token_bucket_q=self.token_bucket_q, - job_chunksize=self.job_chunksize, - generate_tokens=generate_tokens, - config=monitor_config - ) - - self.monitor.add_futures(fs) - - if not self.monitor.is_alive(): - self.monitor.start() - - def is_alive(self): - """ - Tells whether the monitor thread is still running. False when none - was ever started, which is what an executor asked to wait on futures - it did not invoke itself has - """ - return self.monitor is not None and self.monitor.is_alive() - - def remove(self, fs): - """ - Stops tracking a set of futures - """ - if self.monitor and self.monitor.is_alive(): - self.monitor.remove_futures(fs) - - def stop(self): - """ - Stops the monitor thread and waits for it to wind down - """ - if self.monitor and self.monitor.is_alive(): - self.monitor.stop() - self.monitor.join(timeout=5) diff --git a/lithops/monitoring/__init__.py b/lithops/monitoring/__init__.py new file mode 100644 index 000000000..cd204086f --- /dev/null +++ b/lithops/monitoring/__init__.py @@ -0,0 +1,49 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +""" +Client-side job monitoring and worker-side status reporting. + +Backends live under :mod:`lithops.monitoring.backends` and are imported +on demand, so that only the SDK of the configured one is ever loaded. +""" + +from lithops.monitoring.backends import DEFAULT_BACKEND, resolve_backend +from lithops.monitoring.monitor import ( + LOG_INTERVAL, + MessageMonitor, + Monitor, + PollingMessageMonitor, +) +from lithops.monitoring.job_monitor import JobMonitor +from lithops.monitoring.status import ( + CallStatus, + MessageCallStatus, + StorageCallStatus, + create_call_status, +) + +__all__ = [ + 'DEFAULT_BACKEND', + 'LOG_INTERVAL', + 'CallStatus', + 'JobMonitor', + 'MessageCallStatus', + 'MessageMonitor', + 'Monitor', + 'PollingMessageMonitor', + 'StorageCallStatus', + 'create_call_status', + 'resolve_backend', +] diff --git a/lithops/monitoring/backends/__init__.py b/lithops/monitoring/backends/__init__.py new file mode 100644 index 000000000..a04352ef3 --- /dev/null +++ b/lithops/monitoring/backends/__init__.py @@ -0,0 +1,122 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +""" +Monitoring backends. + +Each backend is a package named after the service (``storage``, +``rabbitmq``, ``redis``, ``aws_sqs``, ``gcp_pubsub``, +``azure_queue``, ...). It must export: + +* ``MonitoringBackend`` — a :class:`~lithops.monitoring.monitor.Monitor` + (or :class:`~lithops.monitoring.monitor.MessageMonitor`) subclass the + client runs as a thread. +* ``CallStatus`` — a :class:`~lithops.monitoring.status.CallStatus` + subclass workers use to report progress. + +and carry a ``config.py`` with a ``load_config(config_data)`` function. + +Adding a backend is adding a package. :class:`~lithops.monitoring.JobMonitor` +and :func:`~lithops.monitoring.create_call_status` load it with:: + + lithops.monitoring.backends. + +The name of the package is also the name of the config section the backend +reads and the value ``monitoring:`` selects it by; ``Monitor`` checks that +its ``backend_name`` agrees with the package it is defined in. +""" + +import importlib +from typing import Any, Dict, Optional + +#: Backend used when the configuration does not name one. Every storage +#: backend can act as a monitoring channel, so this always works +DEFAULT_BACKEND = 'storage' + +#: Attribute name each backend package exports, and the base class it has +#: to be a subclass of. Loaded lazily so that importing this module does +#: not pull the whole monitoring package in +_CONTRACT = { + 'MonitoringBackend': ('lithops.monitoring.monitor', 'Monitor'), + 'CallStatus': ('lithops.monitoring.status', 'CallStatus'), +} + + +def resolve_backend( + config: Optional[Dict[str, Any]] = None, + backend: Optional[str] = None, +) -> str: + """ + Name of the monitoring backend to use. + + ``backend`` wins over ``config['lithops']['monitoring']``, which in turn + wins over :data:`DEFAULT_BACKEND`. Resolved the same way on the client + and in the worker, so the two cannot pick different backends + """ + if backend: + return str(backend).lower() + if config: + monitoring = (config.get('lithops') or {}).get('monitoring') + if monitoring: + return str(monitoring).lower() + return DEFAULT_BACKEND + + +def import_backend_module(backend: str, submodule: Optional[str] = None): + """ + Imports ``lithops.monitoring.backends.`` or one of its + submodules. + + Raises ValueError only when the backend itself is not there. A + backend whose SDK is missing keeps its own ImportError, which names + the package to install instead of claiming the backend is unknown. + """ + module_name = f'lithops.monitoring.backends.{backend}' + if submodule: + module_name = f'{module_name}.{submodule}' + try: + return importlib.import_module(module_name) + except ModuleNotFoundError as exc: + if exc.name and not module_name.startswith(exc.name): + raise + raise ValueError(f'Unknown monitoring backend: {backend}') from exc + + +def load_backend_attr(backend: str, attr: str): + """ + Returns ``attr`` of ``lithops.monitoring.backends.``, checked + against the backend contract so that a package that exports the wrong + thing fails here rather than halfway through a job + """ + module = import_backend_module(backend) + + try: + value = getattr(module, attr) + except AttributeError as exc: + raise ValueError( + f"Monitoring backend '{backend}' exports no {attr}" + ) from exc + + expected = _CONTRACT.get(attr) + if expected is None: + return value + + base_module, base_name = expected + base = getattr(importlib.import_module(base_module), base_name) + if not (isinstance(value, type) and issubclass(value, base)): + raise ValueError( + f"Monitoring backend '{backend}' exports {attr}=" + f"{value!r}, which is not a {base_name} subclass" + ) + return value diff --git a/lithops/monitoring/backends/aws_sqs/__init__.py b/lithops/monitoring/backends/aws_sqs/__init__.py new file mode 100644 index 000000000..62f29cfef --- /dev/null +++ b/lithops/monitoring/backends/aws_sqs/__init__.py @@ -0,0 +1,6 @@ +from .aws_sqs import SqsMonitor +from .aws_sqs import SqsMonitor as MonitoringBackend +from .status import SqsCallStatus as CallStatus +from .status import SqsCallStatus + +__all__ = ['MonitoringBackend', 'CallStatus', 'SqsMonitor', 'SqsCallStatus'] diff --git a/lithops/monitoring/backends/aws_sqs/aws_sqs.py b/lithops/monitoring/backends/aws_sqs/aws_sqs.py new file mode 100644 index 000000000..6c3aee534 --- /dev/null +++ b/lithops/monitoring/backends/aws_sqs/aws_sqs.py @@ -0,0 +1,115 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import logging + +from lithops.monitoring.monitor import PollingMessageMonitor +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +def sqs_client(config): + """Builds an SQS client from a lithops ``aws_sqs`` section""" + import boto3 + return boto3.client( + 'sqs', + region_name=config.get('region'), + aws_access_key_id=config.get('access_key_id'), + aws_secret_access_key=config.get('secret_access_key'), + aws_session_token=config.get('session_token'), + ) + + +class SqsMonitor(PollingMessageMonitor): + """ + Job monitor that learns the status of every call from messages the + workers send to an SQS queue. + + The queue is created with the executor and deleted in cleanup() + (executor exit / lithops clean on exit). stop() keeps it: SQS + refuses to recreate a queue of the same name for 60 seconds, and a + later map() on the same executor would fail. + """ + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + self.queue = self.monitoring_queue_name() + self.client = sqs_client(config) + self.queue_url = None + self._create_resources() + + def _create_resources(self): + logger.debug( + f'{log_prefix(self.executor_id)} - Creating SQS queue {self.queue}' + ) + response = self.client.create_queue(QueueName=self.queue) + self.queue_url = response['QueueUrl'] + + def _delete_resources(self): + if not self.queue_url: + return + try: + self.client.delete_queue(QueueUrl=self.queue_url) + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted SQS queue {self.queue}' + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete SQS ' + f'queue {self.queue}', + exc_info=True, + ) + self.queue_url = None + + def _receive_messages(self, timeout): + if not self.queue_url: + return + response = self.client.receive_message( + QueueUrl=self.queue_url, + MaxNumberOfMessages=10, + WaitTimeSeconds=min(20, max(1, int(timeout))), + VisibilityTimeout=30, + ) + # Deleted only once the status has been applied: an exception on the + # way leaves the message on the queue, and SQS hands it over again + # when the visibility timeout is up + for message in response.get('Messages', []): + yield message['Body'] + try: + self.client.delete_message( + QueueUrl=self.queue_url, + ReceiptHandle=message['ReceiptHandle'], + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete ' + 'an SQS message after applying it', + exc_info=True, + ) diff --git a/lithops/monitoring/backends/aws_sqs/config.py b/lithops/monitoring/backends/aws_sqs/config.py new file mode 100644 index 000000000..3a97d2bc8 --- /dev/null +++ b/lithops/monitoring/backends/aws_sqs/config.py @@ -0,0 +1,35 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import copy + + +def load_config(config_data): + overrides = copy.deepcopy(config_data.get('aws_sqs') or {}) + merged = {} + if config_data.get('aws'): + merged.update(config_data['aws']) + merged.update(overrides) + config_data['aws_sqs'] = merged + + if 'region_name' in config_data['aws_sqs']: + config_data['aws_sqs']['region'] = config_data['aws_sqs'].pop( + 'region_name' + ) + + if 'region' not in config_data['aws_sqs']: + raise Exception( + "'region' is mandatory under 'aws_sqs' or 'aws' section " + "of the configuration" + ) diff --git a/lithops/monitoring/backends/aws_sqs/status.py b/lithops/monitoring/backends/aws_sqs/status.py new file mode 100644 index 000000000..4adfe845a --- /dev/null +++ b/lithops/monitoring/backends/aws_sqs/status.py @@ -0,0 +1,83 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# 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): + """ + Reports the status of a call by sending it to SQS, which reaches the + client faster, and falls back to Object Storage at the end + """ + + service_name = 'SQS' + + def __init__(self, job, internal_storage): + super().__init__(job, internal_storage) + self._urls = {} + + @cached_property + def client(self): + """ + Built on the first status rather than in __init__, and then kept for + the whole worker process: a call that never reports opens nothing, + and the calls that follow publish through the same client. See + MessageCallStatus.obtain_client() + """ + return self.obtain_client( + 'client', + lambda: sqs_backend.sqs_client(self.config.get('aws_sqs') or {}), + ) + + 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 + """ + 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'] + self._urls[name] = url + return url + + 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, + ) diff --git a/lithops/monitoring/backends/azure_queue/__init__.py b/lithops/monitoring/backends/azure_queue/__init__.py new file mode 100644 index 000000000..71070561c --- /dev/null +++ b/lithops/monitoring/backends/azure_queue/__init__.py @@ -0,0 +1,11 @@ +from .azure_queue import AzureQueueMonitor +from .azure_queue import AzureQueueMonitor as MonitoringBackend +from .status import AzureQueueCallStatus as CallStatus +from .status import AzureQueueCallStatus + +__all__ = [ + 'MonitoringBackend', + 'CallStatus', + 'AzureQueueMonitor', + 'AzureQueueCallStatus', +] diff --git a/lithops/monitoring/backends/azure_queue/azure_queue.py b/lithops/monitoring/backends/azure_queue/azure_queue.py new file mode 100644 index 000000000..a61ee34ed --- /dev/null +++ b/lithops/monitoring/backends/azure_queue/azure_queue.py @@ -0,0 +1,148 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import hashlib +import logging +import re + +from lithops.monitoring.monitor import ( + PollingMessageMonitor, + is_named_error, +) +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +#: Azure Storage queue names: 3 to 63 lowercase letters, digits and single +#: hyphens, starting and ending with a letter or a digit +_INVALID_QUEUE_CHARS = re.compile(r'[^a-z0-9-]+') +QUEUE_NAME_MAX_LEN = 63 + + +def azure_queue_name(name): + """ + Turns a lithops queue name into one Azure Queue Storage accepts. + + Names are lowercase, 3 to 63 letters, digits and single hyphens, and + start and end with a letter or a digit. A name that goes past that is + kept unique by ending it with a digest of the original + """ + cleaned = _INVALID_QUEUE_CHARS.sub('-', name.lower()) + cleaned = re.sub(r'-{2,}', '-', cleaned).strip('-') + + if len(cleaned) > QUEUE_NAME_MAX_LEN: + digest = hashlib.sha1(name.encode('utf-8')).hexdigest()[:8] + keep = QUEUE_NAME_MAX_LEN - len(digest) - 1 + cleaned = f'{cleaned[:keep].rstrip("-")}-{digest}' + + if len(cleaned) < 3: + cleaned = f'{cleaned}-queue'.lstrip('-') + + return cleaned + + +def queue_service(config): + """Builds a QueueServiceClient from a lithops ``azure_queue`` section""" + from azure.storage.queue import QueueServiceClient + account = config['storage_account_name'] + return QueueServiceClient( + account_url=f'https://{account}.queue.core.windows.net', + credential=config['storage_account_key'], + ) + + +class AzureQueueMonitor(PollingMessageMonitor): + """ + Job monitor that learns the status of every call from messages the + workers send to an Azure Storage queue. + + The queue is created with the executor and deleted in cleanup(). + stop() keeps it so a later map() on the same executor can reuse it. + """ + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + self.queue = azure_queue_name(self.monitoring_queue_name()) + self.service = queue_service(config) + self.queue_client = None + self._create_resources() + + def _create_resources(self): + logger.debug( + f'{log_prefix(self.executor_id)} - Creating Azure queue ' + f'{self.queue}' + ) + try: + self.queue_client = self.service.create_queue(self.queue) + except Exception as exc: + if not is_named_error(exc, 'ResourceExistsError'): + raise + self.queue_client = self.service.get_queue_client(self.queue) + if self.queue_client is None: + self.queue_client = self.service.get_queue_client(self.queue) + + def _delete_resources(self): + try: + self.service.delete_queue(self.queue) + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted Azure queue ' + f'{self.queue}' + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete Azure ' + f'queue {self.queue}', + exc_info=True, + ) + self.queue_client = None + + def _receive_messages(self, timeout): + if not self.queue_client: + return + # Deleted only once the status has been applied: an exception on the + # way leaves the message on the queue, and Azure hands it over again + # when the visibility timeout is up + messages = self.queue_client.receive_messages( + messages_per_page=16, + visibility_timeout=30, + ) + for message in messages: + content = message.content + if isinstance(content, bytes): + content = content.decode('utf-8') + yield content + try: + self.queue_client.delete_message(message) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete ' + 'an Azure queue message after applying it', + exc_info=True, + ) diff --git a/lithops/monitoring/backends/azure_queue/config.py b/lithops/monitoring/backends/azure_queue/config.py new file mode 100644 index 000000000..5aec358cb --- /dev/null +++ b/lithops/monitoring/backends/azure_queue/config.py @@ -0,0 +1,36 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import copy + + +REQ_PARAMS = ('storage_account_name', 'storage_account_key') + + +def load_config(config_data): + overrides = copy.deepcopy(config_data.get('azure_queue') or {}) + merged = {} + if config_data.get('azure'): + merged.update(config_data['azure']) + if config_data.get('azure_storage'): + merged.update(config_data['azure_storage']) + merged.update(overrides) + config_data['azure_queue'] = merged + + for param in REQ_PARAMS: + if param not in config_data['azure_queue']: + raise Exception( + f"'{param}' is mandatory under 'azure_queue' or " + "'azure_storage' section of the configuration" + ) diff --git a/lithops/monitoring/backends/azure_queue/status.py b/lithops/monitoring/backends/azure_queue/status.py new file mode 100644 index 000000000..84c3b482d --- /dev/null +++ b/lithops/monitoring/backends/azure_queue/status.py @@ -0,0 +1,76 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +from functools import cached_property + +from lithops.monitoring.backends.azure_queue import azure_queue as azure_backend +from lithops.monitoring.backends.azure_queue.azure_queue import azure_queue_name +from lithops.monitoring.status import MessageCallStatus + + +class AzureQueueCallStatus(MessageCallStatus): + """ + Reports the status of a call by sending it to Azure Queue Storage, + which reaches the client faster, and falls back to Object Storage + at the end + """ + + service_name = 'Azure Queue' + + def __init__(self, job, internal_storage): + super().__init__(job, internal_storage) + self._queues = {} + + @cached_property + def service(self): + """ + Built on the first status rather than in __init__, and then kept for + the whole worker process: a call that never reports opens nothing, + and the calls that follow publish through the same client. See + MessageCallStatus.obtain_client() + """ + return self.obtain_client( + 'service', + lambda: azure_backend.queue_service( + self.config.get('azure_queue') or {} + ), + ) + + 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) + if client: + return client + client = self.service.get_queue_client(name) + self._queues[name] = client + return client + + def close(self) -> None: + # The per-queue clients hang off the service client, and are rebuilt + # from it in a couple of microseconds; the service itself is what is + # expensive to open, and it is kept for the process + for client in self._queues.values(): + try: + client.close() + except Exception: + pass + self._queues.clear() + super().close() + + def _publish(self, payload: str) -> None: + for name in self._targets(): + self._queue(name).send_message(payload) diff --git a/lithops/monitoring/backends/gcp_pubsub/__init__.py b/lithops/monitoring/backends/gcp_pubsub/__init__.py new file mode 100644 index 000000000..cf6f2b852 --- /dev/null +++ b/lithops/monitoring/backends/gcp_pubsub/__init__.py @@ -0,0 +1,11 @@ +from .gcp_pubsub import GcpPubsubMonitor +from .gcp_pubsub import GcpPubsubMonitor as MonitoringBackend +from .status import GcpPubsubCallStatus as CallStatus +from .status import GcpPubsubCallStatus + +__all__ = [ + 'MonitoringBackend', + 'CallStatus', + 'GcpPubsubMonitor', + 'GcpPubsubCallStatus', +] diff --git a/lithops/monitoring/backends/gcp_pubsub/config.py b/lithops/monitoring/backends/gcp_pubsub/config.py new file mode 100644 index 000000000..8c0190c23 --- /dev/null +++ b/lithops/monitoring/backends/gcp_pubsub/config.py @@ -0,0 +1,52 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import copy +import json +import os + + +def load_config(config_data): + overrides = copy.deepcopy(config_data.get('gcp_pubsub') or {}) + merged = {} + if config_data.get('gcp'): + merged.update(config_data['gcp']) + merged.update(overrides) + config_data['gcp_pubsub'] = merged + + section = config_data['gcp_pubsub'] + if 'credentials_path' not in section: + if 'GOOGLE_APPLICATION_CREDENTIALS' in os.environ: + section['credentials_path'] = os.environ.get( + 'GOOGLE_APPLICATION_CREDENTIALS' + ) + + if 'credentials_path' in section: + section['credentials_path'] = os.path.expanduser( + section['credentials_path'] + ) + if 'project_name' not in section: + try: + with open(section['credentials_path']) as creds: + project = json.load(creds).get('project_id') + if project: + section['project_name'] = project + except Exception: + pass + + if 'project_name' not in section: + raise Exception( + "'project_name' is mandatory under 'gcp_pubsub' or 'gcp' section " + "of the configuration" + ) diff --git a/lithops/monitoring/backends/gcp_pubsub/gcp_pubsub.py b/lithops/monitoring/backends/gcp_pubsub/gcp_pubsub.py new file mode 100644 index 000000000..6a48adc2d --- /dev/null +++ b/lithops/monitoring/backends/gcp_pubsub/gcp_pubsub.py @@ -0,0 +1,179 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import logging + +from lithops.monitoring.monitor import ( + PollingMessageMonitor, + is_named_error, +) +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +def _topic_path(project, name): + return f'projects/{project}/topics/{name}' + + +def _subscription_path(project, name): + return f'projects/{project}/subscriptions/{name}' + + +def pubsub_clients(config): + """Builds the Pub/Sub publisher and subscriber clients""" + from google.cloud import pubsub_v1 + + kwargs = {} + path = config.get('credentials_path') + if path: + from google.oauth2 import service_account + kwargs['credentials'] = ( + service_account.Credentials.from_service_account_file(path) + ) + return ( + pubsub_v1.PublisherClient(**kwargs), + pubsub_v1.SubscriberClient(**kwargs), + ) + + +class GcpPubsubMonitor(PollingMessageMonitor): + """ + Job monitor that learns the status of every call from messages the + workers publish to a Pub/Sub topic. + + The topic and its pull subscription are created with the executor + and deleted in cleanup(). stop() keeps them so a later map() on the + same executor can reuse them. + """ + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + self.queue = self.monitoring_queue_name() + self.project = config.get('project_name') + self.publisher, self.subscriber = pubsub_clients(config) + self.topic_path = _topic_path(self.project, self.queue) + self.subscription_path = _subscription_path(self.project, self.queue) + self._create_resources() + + def _create_resources(self): + logger.debug( + f'{log_prefix(self.executor_id)} - Creating Pub/Sub topic ' + f'{self.queue}' + ) + try: + self.publisher.create_topic(name=self.topic_path) + except Exception as exc: + if not is_named_error(exc, 'AlreadyExists'): + raise + try: + self.subscriber.create_subscription( + name=self.subscription_path, + topic=self.topic_path, + ack_deadline_seconds=30, + ) + except Exception as exc: + if not is_named_error(exc, 'AlreadyExists'): + raise + + def _delete_resources(self): + if self.subscription_path: + try: + self.subscriber.delete_subscription( + subscription=self.subscription_path + ) + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted Pub/Sub ' + f'subscription {self.queue}' + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete ' + f'Pub/Sub subscription {self.queue}', + exc_info=True, + ) + self.subscription_path = None + if self.topic_path: + try: + self.publisher.delete_topic(topic=self.topic_path) + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted Pub/Sub ' + f'topic {self.queue}' + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete ' + f'Pub/Sub topic {self.queue}', + exc_info=True, + ) + self.topic_path = None + + def _receive_messages(self, timeout): + if not self.subscription_path: + return + try: + response = self.subscriber.pull( + subscription=self.subscription_path, + max_messages=10, + timeout=max(1.0, float(timeout)), + retry=None, + ) + except Exception as exc: + if is_named_error(exc, 'DeadlineExceeded', 'RetryError'): + return + if self.should_run: + logger.warning( + f'{log_prefix(self.executor_id)} - Pub/Sub pull failed', + exc_info=True, + ) + return + + # Acknowledged only once every status of the batch has been + # applied: an exception on the way leaves them unacknowledged, and + # Pub/Sub hands them over again when the ack deadline is up + received = getattr(response, 'received_messages', None) or [] + ack_ids = [] + for item in received: + data = item.message.data + if isinstance(data, bytes): + data = data.decode('utf-8') + yield data + ack_ids.append(item.ack_id) + if ack_ids: + try: + self.subscriber.acknowledge( + subscription=self.subscription_path, + ack_ids=ack_ids, + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not ack ' + 'Pub/Sub messages after applying them', + exc_info=True, + ) diff --git a/lithops/monitoring/backends/gcp_pubsub/status.py b/lithops/monitoring/backends/gcp_pubsub/status.py new file mode 100644 index 000000000..8baa153ce --- /dev/null +++ b/lithops/monitoring/backends/gcp_pubsub/status.py @@ -0,0 +1,91 @@ +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# 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): + """ + Reports the status of a call by publishing it to Pub/Sub, which + reaches the client faster, and falls back to Object Storage at the end + """ + + service_name = 'Pub/Sub' + + 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): + """ + Built on the first status rather than in __init__, and then kept for + the whole worker process: a call that never reports opens nothing, + and the calls that follow publish through the same publisher. See + MessageCallStatus.obtain_client() + """ + def build(): + publisher, _subscriber = pubsub_backend.pubsub_clients( + self.config.get('gcp_pubsub') or {} + ) + return publisher + + 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) diff --git a/lithops/monitoring/backends/rabbitmq/__init__.py b/lithops/monitoring/backends/rabbitmq/__init__.py new file mode 100644 index 000000000..ae2c7f21d --- /dev/null +++ b/lithops/monitoring/backends/rabbitmq/__init__.py @@ -0,0 +1,5 @@ +from .rabbitmq import RabbitmqMonitor +from .rabbitmq import RabbitmqMonitor as MonitoringBackend +from .status import RabbitmqCallStatus as CallStatus + +__all__ = ['MonitoringBackend', 'CallStatus', 'RabbitmqMonitor'] diff --git a/lithops/monitoring/backends/rabbitmq/config.py b/lithops/monitoring/backends/rabbitmq/config.py new file mode 100644 index 000000000..5dbd9fd8c --- /dev/null +++ b/lithops/monitoring/backends/rabbitmq/config.py @@ -0,0 +1,32 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + + +REQ_PARAMS = ('amqp_url',) + + +def load_config(config_data): + if 'rabbitmq' not in config_data or not config_data['rabbitmq']: + raise Exception( + "'rabbitmq' section is mandatory in the configuration" + ) + + for param in REQ_PARAMS: + if param not in config_data['rabbitmq']: + raise Exception( + f"'{param}' is mandatory under 'rabbitmq' section " + "of the configuration" + ) diff --git a/lithops/monitoring/backends/rabbitmq/rabbitmq.py b/lithops/monitoring/backends/rabbitmq/rabbitmq.py new file mode 100644 index 000000000..3f73c0c8c --- /dev/null +++ b/lithops/monitoring/backends/rabbitmq/rabbitmq.py @@ -0,0 +1,188 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import logging + +import pika + +from lithops.monitoring.monitor import PollingMessageMonitor +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +class RabbitmqMonitor(PollingMessageMonitor): + """ + Job monitor that learns the status of every call from the messages the + workers publish to a RabbitMQ queue. + + Messages are consumed through ``BlockingChannel.consume()``, a + generator over a real AMQP consumer: the broker pushes messages with + prefetch, and the generator hands back control when nothing has + arrived for a while, which is what lets the shared polling loop expire + futures and notice stop(). Reading with ``basic_get`` instead would + cost a round trip per message. + """ + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + + self.rabbit_amqp_url = config.get('amqp_url') + self.pikaparams = pika.URLParameters(self.rabbit_amqp_url) + # The connection is opened here, on the thread that builds the + # monitor, and used by the monitor thread from then on. Only one of + # the two ever touches it, which is what a pika BlockingConnection + # needs; stop() is the exception, and hands its close over with + # add_callback_threadsafe() + self.queue = self.monitoring_queue_name() + self.connection = None + self.channel = None + self.consumer = None + self._create_resources() + + def _create_resources(self): + """ + Opens the connection and declares the queue the workers publish to + """ + 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.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 + """ + if self.consumer is None: + if self.connection is None or self.connection.is_closed: + self._create_resources() + self.channel = self.connection.channel() + self.consumer = self.channel.consume( + self.queue, auto_ack=True, inactivity_timeout=timeout + ) + return self.consumer + + def _discard_consumer(self): + """ + Forgets the consumer and its connection without touching the + broker, for when they are already broken + """ + self.consumer = None + self.channel = None + connection, self.connection = self.connection, None + if connection is None: + return + try: + # stop() may already have closed it to unblock the consumer, + # and pika logs an error of its own for a second close + if connection.is_open: + connection.close() + except Exception: + pass + + def stop(self): + """ + Asks the loop to exit and unblocks the consumer, which is otherwise + waiting for the broker to push until the inactivity timeout. The + connection belongs to the monitor thread, so the close is handed to + it instead of being done here + """ + self.should_run = False + connection = self.connection + if connection is None: + return + try: + connection.add_callback_threadsafe(connection.close) + except Exception: + # The connection is already gone, or its loop is not running, + # and the inactivity timeout ends the wait either way + pass + + def _receive_messages(self, timeout): + """ + Yields whatever the broker has pushed so far, and returns once it + goes quiet for ``timeout`` seconds + """ + try: + for method, _properties, body in self._consume(timeout): + if method is None: + # Nothing arrived within the inactivity timeout + return + yield body.decode('utf-8') + except Exception: + # The channel or the connection is gone. Drop them so the next + # round opens a new consumer, and let the loop report it + self._discard_consumer() + raise + + def _close_receiver(self): + """ + Cancels the consumer and closes its connection. Runs on the monitor + thread, the only one allowed to touch a pika BlockingConnection + """ + connection = self.connection + if self.channel is not None and connection is not None \ + and connection.is_open: + try: + self.channel.cancel() + except Exception: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not cancel the ' + 'RabbitMQ consumer', + exc_info=True, + ) + self._discard_consumer() + + def _delete_resources(self): + """ + Deletes the queue of this executor. + + Called from the thread that shuts the executor down, so it uses a + connection of its own rather than the one the monitor thread was + consuming with + """ + connection = pika.BlockingConnection(self.pikaparams) + try: + channel = connection.channel() + channel.queue_delete(queue=self.queue) + channel.close() + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted RabbitMQ queue ' + f'{self.queue}' + ) + finally: + connection.close() diff --git a/lithops/monitoring/backends/rabbitmq/status.py b/lithops/monitoring/backends/rabbitmq/status.py new file mode 100644 index 000000000..3913e0882 --- /dev/null +++ b/lithops/monitoring/backends/rabbitmq/status.py @@ -0,0 +1,111 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +from types import SimpleNamespace +from typing import Any + +import pika + +from lithops.monitoring.status import MessageCallStatus + + +class RabbitmqCallStatus(MessageCallStatus): + """ + Reports the status of a call by publishing it to RabbitMQ, which reaches + the client faster, and falls back to the Object Storage at the end + """ + + service_name = 'RabbitMQ' + + def __init__(self, job: SimpleNamespace, internal_storage): + super().__init__(job, internal_storage) + self._amqp = None + + @property + def pikaparams(self): + """ + Connection parameters, read from the config the first time they + are needed. Nothing is opened here + """ + amqp_url = (self.config.get('rabbitmq') or {}).get('amqp_url') + return pika.URLParameters(amqp_url) + + def _connect(self): + connection = pika.BlockingConnection(self.pikaparams) + return connection, connection.channel() + + def _channel(self) -> Any: + """ + The channel to publish through. + + Opened once and kept for the whole worker process, since opening one + costs some 150 times what publishing through it does, and a worker + runs the calls of its chunk one after another. The broker drops a + connection that has been idle past the heartbeat, and a long + function is exactly that, so one that is no longer open is replaced + rather than reused + """ + if self._amqp is None: + self._amqp = self.obtain_client('_amqp', self._connect) + + connection, channel = self._amqp + if connection.is_open and channel.is_open: + return channel + + self._drop_channel() + self._amqp = self.obtain_client('_amqp', self._connect) + return self._amqp[1] + + def _drop_channel(self) -> None: + """ + Forgets the connection, here and in the process cache, and closes + it: one that just failed must not be handed to the next call + """ + amqp, self._amqp = self._amqp, None + self.discard_client('_amqp') + if amqp is None: + return + for closeable in reversed(amqp): + try: + if closeable.is_open: + closeable.close() + except Exception: + pass + + def close(self) -> None: + """ + Leaves a shared connection open for the next call of the chunk, and + closes one this call built for itself + """ + if '_amqp' in self._own_clients: + self._drop_channel() + self._amqp = None + + def _publish(self, payload: str) -> None: + try: + channel = self._channel() + for queue in self._targets(): + channel.basic_publish( + exchange='', + routing_key=queue, + 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, + # do not publish into it again + self._drop_channel() + raise diff --git a/lithops/monitoring/backends/redis/__init__.py b/lithops/monitoring/backends/redis/__init__.py new file mode 100644 index 000000000..12c8c32ce --- /dev/null +++ b/lithops/monitoring/backends/redis/__init__.py @@ -0,0 +1,5 @@ +from .redis import RedisMonitor +from .redis import RedisMonitor as MonitoringBackend +from .status import RedisCallStatus as CallStatus + +__all__ = ['MonitoringBackend', 'CallStatus', 'RedisMonitor'] diff --git a/lithops/monitoring/backends/redis/config.py b/lithops/monitoring/backends/redis/config.py new file mode 100644 index 000000000..278f47f8c --- /dev/null +++ b/lithops/monitoring/backends/redis/config.py @@ -0,0 +1,30 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + + +REQ_PARAMS = ('host',) + + +def load_config(config_data): + if 'redis' not in config_data or not config_data['redis']: + raise Exception("'redis' section is mandatory in the configuration") + + for param in REQ_PARAMS: + if param not in config_data['redis']: + raise Exception( + f"'{param}' is mandatory under 'redis' section " + "of the configuration" + ) diff --git a/lithops/monitoring/backends/redis/redis.py b/lithops/monitoring/backends/redis/redis.py new file mode 100644 index 000000000..619f3d036 --- /dev/null +++ b/lithops/monitoring/backends/redis/redis.py @@ -0,0 +1,226 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import inspect +import logging +from functools import lru_cache + +from lithops.monitoring.monitor import PollingMessageMonitor +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +@lru_cache(maxsize=1) +def _accepted_params(): + """ + The keyword arguments ``redis.Redis()`` takes. Read off the signature + once: a worker builds a client per call, and every executor builds one + for its monitor + """ + import redis + + accepted = set(inspect.signature(redis.Redis.__init__).parameters) + accepted.discard('self') + return frozenset(accepted) + + +def _redis_params(config): + """ + Keeps of a lithops ``redis`` section only what ``redis.Redis()`` takes. + + An allow list rather than a deny list: the section is shared with the + storage, multiprocessing and joblib backends, which put keys of their + own in it, and ``redis.Redis()`` raises TypeError on any it does not + know + """ + accepted = _accepted_params() + return { + key: value for key, value in config.items() if key in accepted + } + + +def redis_client(config): + """ + Builds a Redis client from a lithops ``redis`` section. + + Every caller gets a client, and so a connection pool, of its own: the + monitor closes its client when it stops, and it must not take the + connections of the storage or multiprocessing backends down with it + """ + import redis + + return redis.Redis(**_redis_params(config)) + + +def _decode(payload): + if isinstance(payload, bytes): + return payload.decode('utf-8') + return payload + + +class RedisMonitor(PollingMessageMonitor): + """ + Job monitor that learns the status of every call from messages the + workers push onto a Redis list. + + The list is deleted in cleanup(), not in stop(), so a later map() + on the same executor can reuse it. + """ + + #: How many statuses one read takes off the list. BLPOP hands over one + #: at a time, so the rest of the batch comes off in a single LPOP: it is + #: what keeps a map of n calls from costing n round trips, which over a + #: network is the whole cost of monitoring it + BATCH_SIZE = 1000 + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + self.queue = self.monitoring_queue_name() + self.client = redis_client(config) + # LPOP takes a count from Redis 6.2 on. An older server answers with + # an error, and the fallback is one LPOP per status, pipelined + self._lpop_count = True + self._can_batch = True + self._create_resources() + + def _create_resources(self): + logger.debug( + f'{log_prefix(self.executor_id)} - Using Redis list {self.queue}' + ) + try: + self.client.ping() + except Exception: + logger.error( + f'{log_prefix(self.executor_id)} - Could not reach Redis', + exc_info=True, + ) + raise + + def _delete_resources(self): + try: + self.client.delete(self.queue) + logger.debug( + f'{log_prefix(self.executor_id)} - Deleted Redis list {self.queue}' + ) + except Exception: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not delete Redis ' + f'list {self.queue}', + exc_info=True, + ) + + def stop(self): + """ + Asks the loop to exit and drops the connections under the BLPOP that + is waiting on the broker, which ends it at once. + + Waiting for the poll timeout instead costs a second or two on every + stop, and stop() runs after every wait() that finds its futures + done, not only at shutdown. The pool being torn down is this + monitor's own: redis_client() builds a client per caller, so the + storage, multiprocessing and joblib backends keep theirs + """ + self.should_run = False + try: + self.client.connection_pool.disconnect() + except Exception: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not drop the Redis ' + 'connections when stopping', + exc_info=True, + ) + + def _drain(self, limit): + """ + Takes up to ``limit`` further statuses off the list in one round + trip, without blocking. + + ``LPOP key `` returns only what is there, so it costs the + same whether the list holds one status or a thousand. Servers older + than Redis 6.2 do not take the count, and clients that cannot do + either fall back to one status per read + """ + if limit <= 0: + return [] + + if self._lpop_count: + try: + return self.client.lpop(self.queue, limit) or [] + except Exception as e: + self._lpop_count = False + logger.debug( + f'{log_prefix(self.executor_id)} - This Redis does not ' + f'take a count on LPOP ({e}); falling back to a pipeline' + ) + + if not self._can_batch: + return [] + try: + pipe = self.client.pipeline() + for _ in range(min(limit, 64)): + pipe.lpop(self.queue) + return [item for item in pipe.execute() if item is not None] + except Exception as e: + self._can_batch = False + logger.debug( + f'{log_prefix(self.executor_id)} - This Redis client cannot ' + f'pipeline ({e}); reading one status per round trip' + ) + return [] + + def _receive_messages(self, timeout): + """ + Blocks until a status shows up, then takes whatever else is already + on the list along with it + """ + item = self.client.blpop(self.queue, timeout=max(1, int(timeout))) + if not item: + return + _key, payload = item + yield _decode(payload) + for payload in self._drain(self.BATCH_SIZE - 1): + yield _decode(payload) + + def _close_receiver(self): + """ + Releases the client of this monitor once its loop is done. The list + is deleted through cleanup() afterwards, on a connection redis-py + opens again by itself + """ + try: + self.client.close() + except Exception: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not close the Redis ' + 'client', + exc_info=True, + ) diff --git a/lithops/monitoring/backends/redis/status.py b/lithops/monitoring/backends/redis/status.py new file mode 100644 index 000000000..02c5dd1b9 --- /dev/null +++ b/lithops/monitoring/backends/redis/status.py @@ -0,0 +1,46 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +from functools import cached_property + +from lithops.monitoring.backends.redis import redis as redis_backend +from lithops.monitoring.status import MessageCallStatus + + +class RedisCallStatus(MessageCallStatus): + """ + Reports the status of a call by pushing it onto a Redis list, which + reaches the client faster, and falls back to Object Storage at the end + """ + + service_name = 'Redis' + + @cached_property + def client(self): + """ + Built on the first status rather than in __init__, and then kept for + the whole worker process: a call that never reports opens nothing, + and the calls that follow publish through the same connection. See + MessageCallStatus.obtain_client() + """ + return self.obtain_client( + 'client', + 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) diff --git a/lithops/monitoring/backends/storage/__init__.py b/lithops/monitoring/backends/storage/__init__.py new file mode 100644 index 000000000..ebdfc45a8 --- /dev/null +++ b/lithops/monitoring/backends/storage/__init__.py @@ -0,0 +1,5 @@ +from lithops.monitoring.status import StorageCallStatus as CallStatus +from .storage import StorageMonitor +from .storage import StorageMonitor as MonitoringBackend + +__all__ = ['MonitoringBackend', 'CallStatus', 'StorageMonitor'] diff --git a/lithops/monitoring/backends/storage/config.py b/lithops/monitoring/backends/storage/config.py new file mode 100644 index 000000000..c83f3414f --- /dev/null +++ b/lithops/monitoring/backends/storage/config.py @@ -0,0 +1,23 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + + +def load_config(config_data): + """ + Storage monitoring has no section of its own: it polls the storage + backend already selected with ``lithops.storage``, using + ``lithops.monitoring_interval``. + """ diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py new file mode 100644 index 000000000..735955afe --- /dev/null +++ b/lithops/monitoring/backends/storage/storage.py @@ -0,0 +1,313 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import logging +import time +import concurrent.futures as cf + +from lithops.monitoring.monitor import ( + Monitor, + _future_id, + _is_finished, + _is_started, +) +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +class StorageMonitor(Monitor): + """ + Job monitor that learns the status of every call by polling the storage + backend, where the workers leave their status objects. + + This is a monitoring *channel*, not a storage *provider*. The objects + it reads live in whichever storage backend the executor already uses + (S3, IBM COS, localhost, ...). + """ + + THREADPOOL_SIZE = 64 + + #: How often the calls that the listing does not report as done are + #: queried anyway, near the end of a job. The listing is what says which + #: statuses are there; this is only a safety net for one that is behind, + #: so it runs on a clock rather than on every poll + BLIND_SWEEP_INTERVAL = 30 + + def __init__( + self, + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ): + super().__init__( + executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config + ) + + self.monitoring_interval = config['monitoring_interval'] + + # vars for _generate_tokens + self.callids_running_worker = {} + self.callids_running_processed = set() + self.callids_done_processed = set() + self.worker_job = {} + + # vars for _mark_status_as_running + self.callids_running_processed_timeout = set() + + # vars for _mark_status_as_ready + self.callids_done_processed_status = set() + self._ready_pool = None + self._last_blind_sweep = time.time() + + @classmethod + def prepare_config(cls, config, internal_storage): + interval = internal_storage.get_storage_config()['monitoring_interval'] + return {'monitoring_interval': interval} + + def join(self, timeout=None): + """ + Waits for the monitor thread, and drops the pool it downloads the + statuses with, which outlives the thread on a join that timed out + """ + super().join(timeout) + self._shutdown_ready_pool() + + def _get_ready_pool(self): + if self._ready_pool is None: + self._ready_pool = cf.ThreadPoolExecutor( + max_workers=self.THREADPOOL_SIZE + ) + return self._ready_pool + + def _shutdown_ready_pool(self): + pool = self._ready_pool + if pool is None: + return + self._ready_pool = None + pool.shutdown(wait=False) + + def _tag_future_as_running(self, callids_running): + """ + Mark which futures are in running status based on callids_running + """ + current_time = time.time() + to_process = ( + callids_running - self.callids_running_processed_timeout + ) + for call in to_process: + f = self.future_by_id(call[0]) + if f is None or not f.invoked or _is_started(f): + continue + call_status = { + 'type': '__init__', + 'activation_id': call[1], + 'worker_start_tstamp': current_time, + } + f._set_running(call_status) + + self.callids_running_processed_timeout.update(to_process) + self._future_timeout_checker() + + def _tag_future_as_ready(self, callids_done): + """ + Mark which futures has a call_status ready to be downloaded + """ + futures = self.tracked_futures() + not_ready_futures = [f for f in futures if not _is_finished(f)] + to_process = callids_done - self.callids_done_processed_status + + # The calls the listing reports as done and whose status has not + # been read yet. This is the whole job in the normal case + fs_to_query = [ + f for f in not_ready_futures if _future_id(f) in to_process + ] + + # Near the end, the calls the listing does NOT report as done are + # queried as well, in case it is behind. Rate limited: a job with a + # long tail spends most of its life in this branch, and querying + # every straggler on every poll turned one GET per call into + # dozens, all of them for objects the listing had already said + # were not there + ten_percent = int(len(futures) * (10 / 100)) + near_the_end = ( + len(futures) - len(callids_done) <= max(10, ten_percent) + ) + now = time.time() + if near_the_end and now - self._last_blind_sweep >= \ + self.BLIND_SWEEP_INTERVAL: + self._last_blind_sweep = now + queried = set(fs_to_query) + fs_to_query.extend( + f for f in not_ready_futures if f not in queried + ) + + if not fs_to_query: + return + + def get_status(f): + cs = self.internal_storage.get_call_status( + f.executor_id, f.job_id, f.call_id + ) + f._status_query_count += 1 + if cs: + if not self._check_new_futures(cs, f): + f._set_ready(cs) + return _future_id(f) + return None + + try: + call_ids_processed = set( + self._get_ready_pool().map(get_status, fs_to_query) + ) + except Exception as e: + # One unreadable status object must not take the monitor down, + # but it is not something to keep quiet about either: the next + # round queries the same futures again + if self.should_run: + logger.warning( + f'{log_prefix(self.executor_id)} - Could not read the ' + f'status of {len(fs_to_query)} call(s): {e}', + exc_info=True, + ) + return + finally: + # The final sweep of run() happens after the thread is done, so + # the pool it lazily recreated has to be dropped again + if not self.is_alive(): + self._shutdown_ready_pool() + + call_ids_processed.discard(None) + self.callids_done_processed_status.update(call_ids_processed) + + 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: + return + + running_new = ( + callids_running - self.callids_running_processed + ) + done_new = callids_done - self.callids_done_processed + + for call_id, worker_id in running_new: + self.callids_running_worker[call_id] = worker_id + + for callid_done in done_new: + worker_id = self.callids_running_worker.get(callid_done) + if worker_id is None: + continue + self.callids_done_worker.setdefault(worker_id, set()).add( + callid_done + ) + # The job the worker belongs to, kept aside so that the chunksize + # can be looked up without picking a call id back out of the set + self.worker_job.setdefault(worker_id, callid_done[1]) + + present_jobs = self.present_jobs + for worker_id, done_calls in self.callids_done_worker.items(): + 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: + continue + chunksize = self.job_chunksize.get(job_id) + if chunksize is None or len(done_calls) < chunksize: + continue + self.workers_done.add(worker_id) + if not self.should_run: + break + self.token_bucket_q.put('#') + + self.callids_running_processed.update(running_new) + self.callids_done_processed.update(done_new) + + 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 + """ + status = self.internal_storage.get_job_status( + self.executor_id, job_ids=self.job_ids() + ) + callids_running, callids_done = status + new_callids_done = ( + callids_done - self.callids_done_processed_status + ) + + self._generate_tokens(callids_running, callids_done) + self._tag_future_as_running(callids_running) + self._tag_future_as_ready(callids_done) + + self._print_status_log() + + return new_callids_done + + def run(self): + """ + Polls the storage backend until the monitor is stopped, backing off + to the configured interval whenever a round brings nothing new + """ + logger.debug( + f'{log_prefix(self.executor_id)} - Starting Storage job monitor' + ) + + wait_dur_sec = self.monitoring_interval + + while self.should_run: + try: + new_callids_done = self._poll_and_process_job_status() + if new_callids_done: + wait_dur_sec = self.monitoring_interval / 5 + else: + wait_dur_sec = self.monitoring_interval + except Exception as e: + logger.error( + f'{log_prefix(self.executor_id)} - Error during ' + f'monitor: {e}', + exc_info=True, + ) + # Short-circuited, so that a monitor already stopped does not + # even ask to wait before the final sweep + if not self.should_run or not self.sleep(wait_dur_sec): + break + + # One last sweep, so that statuses written between the final poll + # and the stop are not lost. The storage may already be gone + try: + self._poll_and_process_job_status() + except Exception as e: + logger.debug( + f'{log_prefix(self.executor_id)} - The final status sweep ' + f'did not go through: {e}' + ) + + self._print_status_log(force=True) + self._shutdown_ready_pool() + logger.debug( + f'{log_prefix(self.executor_id)} - Storage job monitor finished' + ) diff --git a/lithops/monitoring/job_monitor.py b/lithops/monitoring/job_monitor.py new file mode 100644 index 000000000..088b2f13e --- /dev/null +++ b/lithops/monitoring/job_monitor.py @@ -0,0 +1,195 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import logging +import queue + +from lithops.monitoring.backends import load_backend_attr, resolve_backend +from lithops.utils import log_prefix + +logger = logging.getLogger(__name__) + + +class JobMonitor: + """ + Owns the monitor thread of one executor, and picks the implementation + that matches the configured monitoring backend. + + ``config`` is the full Lithops config. The selected backend extracts + the section it needs through :meth:`Monitor.prepare_config`. + ``backend`` overrides ``config['lithops']['monitoring']`` when set, and + ``queue_name`` the queue the monitor reads from, which the remote + invoker needs so as not to consume what the client is waiting for. + """ + + #: How long stop() waits for the monitor thread to wind down. A poll + #: blocks for PollingMessageMonitor.POLL_TIMEOUT at most, so a healthy + #: monitor is gone well inside this; the rest is slack for a consumer + #: that has to unwind a connection, and the cap on how long a wedged + #: one may hold up the exit of the executor + STOP_TIMEOUT = 10 + + def __init__( + self, + executor_id, + internal_storage, + config=None, + backend=None, + queue_name=None, + ): + self.executor_id = executor_id + self.internal_storage = internal_storage + self.storage_config = internal_storage.get_storage_config() + self.storage_backend = internal_storage.backend + self.config = config + self.queue_name = queue_name + self.type = resolve_backend(config, backend) + + self.token_bucket_q = queue.Queue() + self.monitor = None + self.job_chunksize = {} + + self.MonitorClass = load_backend_attr( + self.type, 'MonitoringBackend' + ) + + def start(self, fs, job_id=None, chunksize=None, generate_tokens=False): + """ + Tracks a new set of futures, spawning the monitor thread unless a + live one can take them over + """ + if job_id: + self.job_chunksize[job_id] = chunksize + + if not self.monitor or self._thread_finished(): + self._spawn_monitor(generate_tokens) + elif generate_tokens: + self.monitor.generate_tokens = True + + self.monitor.add_futures(fs) + + if not self.monitor.is_alive(): + self.monitor.start() + + def prepare(self): + """ + Creates backend resources (queues, keys) before workers are + invoked, so the first status is not published into nowhere. + """ + if self.monitor is None: + self._spawn_monitor(generate_tokens=False) + + def _spawn_monitor(self, generate_tokens): + # A monitor that was stopped is replaced, never revived, and the old + # 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 + self._join_monitor() + monitor_config = self.MonitorClass.prepare_config( + self.config, self.internal_storage + ) + if self.queue_name: + # Copied rather than mutated: prepare_config() may well have + # handed back the caller's own config section + monitor_config = dict(monitor_config) + monitor_config['queue_name'] = self.queue_name + self.monitor = self.MonitorClass( + executor_id=self.executor_id, + internal_storage=self.internal_storage, + token_bucket_q=self.token_bucket_q, + job_chunksize=self.job_chunksize, + generate_tokens=generate_tokens, + config=monitor_config + ) + + def _thread_finished(self): + """ + Whether the current monitor is spent: it ran and exited, or it was + asked to stop. A stopped one is not reused, since its loop would + return on the next round without picking the new futures up + """ + if self.monitor is None: + return False + if not self.monitor.should_run: + return True + return ( + self.monitor.ident is not None + and not self.monitor.is_alive() + ) + + def _join_monitor(self): + """ + Waits for the monitor thread to wind down, and says whether it did. + + Only the paths that replace the monitor or delete what it consumes + from have to wait; a plain stop() leaves the thread to exit on its + own, so that a wait() whose futures are all done returns at once + """ + if self.monitor is None or not self.monitor.is_alive(): + return True + self.monitor.join(timeout=self.STOP_TIMEOUT) + if self.monitor.is_alive(): + logger.warning( + f'{log_prefix(self.executor_id)} - The {self.type} job ' + f'monitor did not stop within {self.STOP_TIMEOUT} seconds' + ) + return False + return True + + def is_alive(self): + """ + Tells whether the monitor thread is still running. False when none + was ever started, which is what an executor asked to wait on futures + it did not invoke itself has + """ + return self.monitor is not None and self.monitor.is_alive() + + def remove(self, fs): + """ + Stops tracking a set of futures + """ + if self.monitor and self.monitor.is_alive(): + self.monitor.remove_futures(fs) + + def stop(self): + """ + Asks the monitor thread to exit, without waiting for it. + + This runs after every wait() whose futures are all done, not only at + shutdown, and a backend whose read blocks for a poll interval would + hold the caller up every single time. The thread is a daemon and + winds down on its own; cleanup() and the next start() are the two + that wait for it, because they replace it or delete what it reads + from. Queues stay until cleanup(). + """ + if self.monitor is None: + return + self.monitor.stop() + + def cleanup(self): + """ + Deletes queues, keys or other backend resources of this executor, + once the thread that consumes from them has wound down + """ + if self.monitor is None: + return + self.monitor.stop() + if not self._join_monitor(): + logger.warning( + f'{log_prefix(self.executor_id)} - Deleting the {self.type} ' + 'monitoring resources while it is still reading from them' + ) + self.monitor.cleanup() diff --git a/lithops/monitoring/monitor.py b/lithops/monitoring/monitor.py new file mode 100644 index 000000000..6db77ad1f --- /dev/null +++ b/lithops/monitoring/monitor.py @@ -0,0 +1,790 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import json +import logging +import pickle +import sys +import threading +import time +from typing import Any, Dict, Optional + +from tblib import pickling_support + +from lithops.utils import _future_id, log_prefix, monitoring_queue_name + +# _future_timeout_checker() pickles sys.exc_info() so that the client can +# re-raise a real traceback for a worker that never reported back +pickling_support.install() + +logger = logging.getLogger(__name__) + +LOG_INTERVAL = 30 # Print monitor debug every LOG_INTERVAL seconds + +# Package every monitoring backend lives under. A Monitor subclass defined +# there is a backend, and the contract is checked against it +BACKENDS_PACKAGE = 'lithops.monitoring.backends' + + +def _status_id(call_status): + return ( + call_status['executor_id'], + call_status['job_id'], + call_status['call_id'], + ) + + +def _is_finished(fut): + return fut.ready or fut.success or fut.done + + +def _is_started(fut): + return fut.running or _is_finished(fut) + + +def is_named_error(exc, *names): + """ + Tells whether an exception is one of the named cloud SDK errors, without + importing the SDK that defines them. The whole inheritance chain is + checked, so a subclass of the named error matches too + """ + return any( + klass.__name__ in names for klass in type(exc).__mro__ + ) + + +def _backend_package_of(cls) -> Optional[str]: + """ + Name of the backend package a class is defined in, or None when it does + not live under :data:`BACKENDS_PACKAGE` + """ + prefix = f'{BACKENDS_PACKAGE}.' + module = cls.__module__ or '' + if not module.startswith(prefix): + return None + return module[len(prefix):].split('.')[0] + + +class Monitor(threading.Thread): + """ + Base class of the background threads that follow the futures of an + executor and move them along their states as their status arrives. + + A monitoring backend is a subclass of this class (or of + :class:`MessageMonitor` / :class:`PollingMessageMonitor`). It must + implement ``run()`` — or ``_receive_messages()`` when it subclasses + :class:`PollingMessageMonitor` — and may override ``stop()`` and + ``prepare_config()``. The class is loaded from + ``lithops.monitoring.backends.`` as ``MonitoringBackend``. + + ``backend_name`` names the configuration section the backend reads, and + is derived from the package the class lives in so that the two cannot + drift apart. + """ + + #: Config section this backend reads, and the name ``monitoring:`` + #: selects it by. Filled in from the package name for backends + backend_name = None + + #: How many statuses that arrived before their future may be held + MAX_HELD_STATUS = 100_000 + + def __init_subclass__(cls, abstract: bool = False, **kwargs): + """ + Checks the backend contract as soon as the class is defined, so that + a backend that does not hold up its end fails at import rather than + halfway through a job. + + ``abstract=True`` opts a helper class out of the check + """ + super().__init_subclass__(**kwargs) + + package = _backend_package_of(cls) + if abstract or package is None: + return + + if cls.backend_name is None: + cls.backend_name = package + elif cls.backend_name != package: + raise TypeError( + f"{cls.__name__}.backend_name is '{cls.backend_name}' but the " + f"backend package is '{package}'. The two name the same " + f"thing: the config section, and the value of 'monitoring:'" + ) + + polling = globals().get('PollingMessageMonitor') + implements_run = cls.run is not threading.Thread.run + implements_receive = polling is not None and issubclass( + cls, polling + ) and cls._receive_messages is not polling._receive_messages + if not implements_run and not implements_receive: + raise TypeError( + f'{cls.__name__} implements neither run() nor ' + f'_receive_messages(). A monitoring backend has to consume ' + f'statuses one way or the other' + ) + + def __init__(self, executor_id, + internal_storage, + token_bucket_q, + job_chunksize, + generate_tokens, + config): + + super().__init__() + self.executor_id = executor_id + self.internal_storage = internal_storage + # Every idle wait of the loop goes through this event rather than + # time.sleep(), so that stop() ends it at once instead of leaving + # the caller to wait out a poll interval. stop() is called after + # every wait() whose futures are all done, not only at shutdown + self._stopped = threading.Event() + self.token_bucket_q = token_bucket_q + self.job_chunksize = job_chunksize + self.generate_tokens = generate_tokens + self.config = config + self.daemon = True + self._cleaned = False + + # Futures are tracked from the client threads that submit jobs and + # 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() + self.futures = set() + self._futures_by_id = {} + self.present_jobs = set() + + # vars for _generate_tokens + self.workers_done = set() + self.callids_done_worker = {} + # vars for MessageMonitor._hold_status + self._held_status = {} + self._held_lock = threading.Lock() + self._held_overflow_logged = False + self._held_may_match = False + # When a status last arrived. A channel that is delivering has + # nothing for the storage sweep to recover + self._last_message_tstamp = time.time() + # Re-entrancy guard of _apply_held_status(), per thread: the monitor + # thread and the threads that submit jobs both get there + self._applying_held = threading.local() + # vars for _print_status_log + self._last_status_counts = None + self._last_status_log_time = 0.0 + + @property + def should_run(self): + """Whether the loop should keep going. False once stop() was called""" + return not self._stopped.is_set() + + @should_run.setter + def should_run(self, value): + if value: + self._stopped.clear() + else: + self._stopped.set() + + def sleep(self, seconds): + """ + Waits, unless the monitor is stopped first. Returns False when the + wait was cut short by stop() + """ + if seconds <= 0: + return self.should_run + return not self._stopped.wait(seconds) + + @classmethod + def prepare_config( + cls, + config: Optional[Dict[str, Any]], + internal_storage, + ) -> Dict[str, Any]: + """ + Returns the dict this backend's ``__init__`` expects, extracted from + the full Lithops config. + + Backends whose settings live in the config section named after them + (``rabbitmq``, ``aws_sqs``, ...) can keep this default. + """ + if not config: + return {} + return config.get(cls.backend_name) or {} + + def monitoring_queue_name(self): + """ + Name of the queue, topic or key this monitor reads from. + + Derived from the executor id, unless the config names one: a + monitor that follows the calls of an executor it does not own, as + the remote invoker does, needs its own queue so that it does not + take the messages the owner is waiting for + """ + named = (self.config or {}).get('queue_name') + return named or monitoring_queue_name(self.executor_id) + + def add_futures(self, fs): + """ + Extends the current thread list of futures to track + """ + with self._futures_lock: + self.futures.update(fs) + for future in fs: + self._futures_by_id[_future_id(future)] = future + # Nothing held can start matching unless futures were added, so + # this is what keeps _take_held_status() from walking the held + # set once per message while a nested job piles statuses up + self._held_may_match = True + # Rebound rather than mutated, so that a reader that got hold of + # the set before this call keeps iterating a set of its own + self.present_jobs = self.present_jobs | { + future.job_id for future in fs + } + + def remove_futures(self, fs): + """ + Remove from the current thread a list of futures + """ + self._print_status_log() + with self._futures_lock: + self.futures.difference_update(fs) + for future in 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} + + def tracked_futures(self): + """ + A snapshot of the futures being tracked, safe to iterate while other + threads add or remove some + """ + with self._futures_lock: + return tuple(self.futures) + + def job_ids(self): + """ + A snapshot of the ids of the jobs that still have futures to track + """ + with self._futures_lock: + return set(self.present_jobs) + + def future_by_id(self, future_id): + """ + The tracked future a call status belongs to, or None when it is not + tracked (yet) + """ + with self._futures_lock: + return self._futures_by_id.get(future_id) + + def stop(self): + """ + Asks the monitor thread to exit. Does not delete queues or keys: + the executor may still map() again. + + Returns as soon as the thread has been asked; JobMonitor.cleanup() + is what waits for it, right before the resources it consumes from + are deleted. Override to cut short a blocking read that this alone + cannot reach (close a connection, cancel a consumer). + """ + self.should_run = False + + def _create_resources(self): + """ + Creates the queues, topics or keys this monitor consumes from. + Called by the backend once its client is built. + """ + + def _delete_resources(self): + """ + Deletes what :meth:`_create_resources` created. Called once, + through cleanup(). + """ + + def cleanup(self): + """ + Deletes queues, keys or other backend resources that must not + outlive the executor. Called from clean() and executor shutdown. + Idempotent: a second call is a no-op. + """ + if self._cleaned: + return + self._cleaned = True + self._delete_resources() + + def _all_ready(self): + """ + Checks if all futures are ready, success or done + """ + return all(_is_finished(f) for f in self.tracked_futures()) + + def _check_new_futures(self, call_status, f): + """ + Checks if a function returned new futures to track + """ + if 'new_futures' not in call_status: + return False + + f._set_futures(call_status) + self.add_futures(f._new_futures) + logger.debug( + f'{log_prefix(self.executor_id)} - Received {len(f._new_futures)} ' + 'new function Futures to track' + ) + + return True + + def _future_timeout_checker(self, futures=None): + """ + Checks if running futures exceeded the timeout + """ + current_time = time.time() + if futures is None: + futures = self.tracked_futures() + futures_running = [f for f in futures if f.running and f._call_status] + for fut in futures_running: + try: + start_tstamp = fut._call_status['worker_start_tstamp'] + fut_timeout = start_tstamp + fut.execution_timeout + 5 + if current_time > fut_timeout: + msg = ( + 'The function exceeded the execution timeout ' + f'of {fut.execution_timeout} seconds.' + ) + raise TimeoutError('HANDLER', msg) + except TimeoutError: + # Raising and catching the error right away is what fills + # sys.exc_info(), so that the client re-raises a real + # traceback for a worker that never reported back + pickled_exception = str(pickle.dumps(sys.exc_info())) + call_status = { + 'type': '__end__', + 'exception': True, + 'exc_info': pickled_exception, + 'executor_id': fut.executor_id, + 'job_id': fut.job_id, + 'call_id': fut.call_id, + 'activation_id': fut.activation_id, + 'worker_start_tstamp': start_tstamp, + 'worker_end_tstamp': time.time(), + } + fut._set_ready(call_status) + + def _print_status_log(self, force=False): + """ + Logs pending/running/done counts. + + Redis and RabbitMQ see a change on every message, so this is + throttled: the first snapshot, then one every LOG_INTERVAL seconds + while the job is running, and one more when it finishes or when + ``force`` is set on shutdown. + """ + futures = self.tracked_futures() + if not futures: + return + + callids_pending = callids_running = callids_done = 0 + for fut in futures: + if fut.invoked: + callids_pending += 1 + if fut.running: + callids_running += 1 + if _is_finished(fut): + callids_done += 1 + counts = (callids_pending, callids_running, callids_done) + + now = time.time() + changed = counts != self._last_status_counts + still_working = callids_done < len(futures) + elapsed = now - self._last_status_log_time > LOG_INTERVAL + should_log = ( + self._last_status_counts is None + or (changed and (not still_working or force)) + or (still_working and elapsed) + ) + + self._last_status_counts = counts + if not should_log: + return + + self._last_status_log_time = now + logger.debug( + f'{log_prefix(self.executor_id)} - Pending: ' + f'{callids_pending} - Running: {callids_running} - ' + f'Done: {callids_done}' + ) + + +class MessageMonitor(Monitor, abstract=True): + """ + Monitor for backends that receive one call-status message at a time + (RabbitMQ, SQS, Pub/Sub, ...). + + The backend only has to deliver each JSON status payload to + :meth:`_apply_status_message`; tagging futures and handing tokens + back to the invoker live here. + """ + + def _hold_status(self, call_status): + """ + Keeps a status whose future is not tracked yet. + + A nested executor publishes the statuses of its own calls to the + queue of every executor up the chain, and those can arrive before + 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 + """ + with self._held_lock: + self._held_status[_status_id(call_status)] = call_status + self._held_may_match = True + 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 + while len(self._held_status) > self.MAX_HELD_STATUS: + del self._held_status[next(iter(self._held_status))] + if not self._held_overflow_logged: + self._held_overflow_logged = True + logger.warning( + f'{log_prefix(self.executor_id)} - More than ' + f'{self.MAX_HELD_STATUS} call statuses arrived for ' + 'futures that are not tracked; dropping the oldest' + ) + + def _take_held_status(self): + """ + Removes and returns the held statuses whose future is now tracked. + + Also forgets the ones whose future finished some other way, such + as an expired execution timeout, so they are not held for ever + """ + with self._held_lock: + if not self._held_status or not self._held_may_match: + return () + self._held_may_match = False + ready = [] + for future_id in list(self._held_status): + future = self.future_by_id(future_id) + if future is None: + continue + call_status = self._held_status.pop(future_id) + if not _is_finished(future): + ready.append(call_status) + return tuple(ready) + + def _apply_held_status(self): + """ + Applies the statuses that arrived before their future did. + + The statuses leave the held set before any of them is applied, and + the lock is not held while applying. Applying one can reveal further + futures, whose own held statuses this then picks up, so the work is + drained in a loop rather than by calling back into here: a chain of + nested jobs would otherwise recurse once per held status + """ + local = self._applying_held + if getattr(local, 'busy', False): + return + local.busy = True + try: + while True: + batch = self._take_held_status() + if not batch: + return + for call_status in batch: + self._apply_status_message(call_status) + finally: + local.busy = False + + def add_futures(self, fs): + """ + Tracks new futures, applying any status that beat them here + """ + super().add_futures(fs) + self._apply_held_status() + + def _tag_future_as_running(self, call_status): + """ + Assigns a call_status to its future. Returns whether the future is + tracked, which is what tells the caller the status can be dropped + """ + future = self.future_by_id(_status_id(call_status)) + if future is None: + return False + if not _is_started(future): + future._set_running(call_status) + return True + + def _tag_future_as_ready(self, call_status): + """ + Tags a future as ready based on call_status. Returns whether the + future is tracked + """ + future = self.future_by_id(_status_id(call_status)) + if future is None: + return False + if not _is_finished(future): + if not self._check_new_futures(call_status, future): + future._set_ready(call_status) + return True + + def _generate_tokens(self, call_status): + """ + Hands a token back to the invoker once a whole worker is free. + + The call ids of a worker are kept in a set: a message service that + redelivers can hand the same __end__ over twice, and counting it + twice would either release a token early or push the count past the + chunksize and never release one at all + """ + 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: + return + + 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('#') + + def _apply_status_message(self, call_status): + """ + Applies one worker status payload to its future, holding it back + when the future it belongs to is not tracked yet + """ + # A status arriving is the proof the channel works, which is what + # tells the storage sweep it has nothing to look for + self._last_message_tstamp = time.time() + if call_status['type'] == '__init__': + if not self._tag_future_as_running(call_status): + self._hold_status(call_status) + elif call_status['type'] == '__end__': + if self._tag_future_as_ready(call_status): + self._generate_tokens(call_status) + else: + self._hold_status(call_status) + + def _storage_sweep(self): + """ + Picks up from the Object Storage the statuses whose message never + arrived. + + A message service delivers a status at most once (RabbitMQ acks on + delivery, a Redis BLPOP removes it), so a status can be lost. The + worker also writes every __end__ to the storage, and this is what + reads it back: without it a lost __end__ turns into a bogus + execution timeout, and losing both statuses of a call hangs wait() + for ever, since the timeout checker only looks at running futures + """ + if self.internal_storage is None: + return 0 + + pending = [f for f in self.tracked_futures() if not _is_finished(f)] + if not pending: + return 0 + + _running, callids_done = self.internal_storage.get_job_status( + self.executor_id, job_ids=self.job_ids() + ) + if not callids_done: + return 0 + + recovered = 0 + for future in pending: + future_id = _future_id(future) + if future_id not in callids_done or _is_finished(future): + continue + call_status = self.internal_storage.get_call_status(*future_id) + future._status_query_count += 1 + if not call_status: + continue + if not self._check_new_futures(call_status, future): + future._set_ready(call_status) + recovered += 1 + if self.generate_tokens and 'activation_id' in call_status: + self._generate_tokens(call_status) + + if recovered: + logger.debug( + f'{log_prefix(self.executor_id)} - Recovered {recovered} ' + f'call status(es) from the storage, whose {self.backend_name} ' + 'message never arrived' + ) + return recovered + + +class PollingMessageMonitor(MessageMonitor, abstract=True): + """ + Pulls status messages with a timeout so the same loop can expire + futures and notice stop(). Redis, SQS, Pub/Sub and Azure Queue use + this; RabbitMQ keeps its own blocking AMQP consumer. + """ + + POLL_TIMEOUT = 2 + + #: How long the channel has to have been quiet before the statuses the + #: workers left in the storage are read back for the futures whose + #: message never arrived. Zero disables it + STORAGE_SWEEP_INTERVAL = 60 + + #: The sweep backs off to this while it keeps finding nothing + MAX_SWEEP_INTERVAL = 600 + + def __init__(self, *args, **kwargs): + super().__init__(*args, **kwargs) + # How long the channel has to be quiet before the next sweep. Grows + # while the sweeps keep finding nothing + self._sweep_interval = self.STORAGE_SWEEP_INTERVAL + + def _receive_messages(self, timeout): + """Yields JSON strings. Empty if nothing arrived.""" + raise NotImplementedError + + def _close_receiver(self): + """ + Releases whatever _receive_messages() opened. Called on the monitor + thread once its loop is done, so a backend whose client must be used + from a single thread can close it from the thread that used it + """ + + def _poll_once(self): + """ + Receives and applies one batch of status messages, then sleeps off + whatever is left of the poll budget when nothing arrived. + + The wait belongs here rather than in _receive_messages(): a + backend without server-side long polling (Azure Queue) returns + right away on an empty queue, and so does one that keeps failing + (unreachable service, wrong credentials), either of which would + otherwise turn this loop into a spin. + """ + poll_t = time.time() + received = False + try: + for payload in self._receive_messages(self.POLL_TIMEOUT): + self._apply_status_message(json.loads(payload)) + # A status can name new futures whose own statuses were + # read earlier and held back. Applied per message rather + # than per batch, because a backend that only returns once + # the queue has gone quiet would otherwise sit on them + self._apply_held_status() + received = True + except Exception as e: + # A failed poll must not take the monitor down with it: nothing + # else moves the futures along, so wait() would block for ever. + # The storage sweep is what recovers whatever was lost with it + if self.should_run: + logger.error( + f'{log_prefix(self.executor_id)} - Error during ' + f'monitor: {e}', + exc_info=True, + ) + if received: + return + remaining = self.POLL_TIMEOUT - (time.time() - poll_t) + self.sleep(remaining) + + def _sweep_storage(self, last_sweep): + """ + Reads the call statuses back from the storage when the channel has + gone quiet, and returns when that last happened. + + Two things keep this off the critical path of a healthy job. It only + looks while no status has arrived for a whole interval, since a + channel that is delivering has nothing to recover; and every sweep + that finds nothing doubles the wait before the next one, up to + MAX_SWEEP_INTERVAL, since a long-running job is quiet by nature. A + sweep lists every status key of every live job, which on a large map + is a page of listing per thousand calls + """ + if not self.STORAGE_SWEEP_INTERVAL: + return last_sweep + + now = time.time() + if now - self._last_message_tstamp < self._sweep_interval: + return last_sweep + if now - last_sweep < self._sweep_interval: + return last_sweep + + try: + recovered = self._storage_sweep() + except Exception as e: + if self.should_run: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not read the ' + f'call statuses back from the storage: {e}' + ) + recovered = 0 + + if recovered: + self._sweep_interval = self.STORAGE_SWEEP_INTERVAL + else: + self._sweep_interval = min( + self._sweep_interval * 2, self.MAX_SWEEP_INTERVAL + ) + return now + + def run(self): + logger.debug( + f'{log_prefix(self.executor_id)} - Starting ' + f'{self.backend_name} job monitor' + ) + # Both sweeps walk every tracked future, so they run on a clock + # rather than once per loop: a backend that hands over one message + # at a time would otherwise turn a map of n calls into n*n work + last_sweep = time.time() + self._sweep_interval = self.STORAGE_SWEEP_INTERVAL + last_check = 0.0 + try: + # Stay up until stop(), like StorageMonitor, so wait() does not + # spawn a second thread (and a second cleanup) once every future + # is ready. New futures of a later map() are added to this one. + while self.should_run: + now = time.time() + if now - last_check >= self.POLL_TIMEOUT: + last_check = now + self._print_status_log() + self._future_timeout_checker() + last_sweep = self._sweep_storage(last_sweep) + self._poll_once() + finally: + self._print_status_log(force=True) + try: + self._close_receiver() + except Exception: + logger.debug( + f'{log_prefix(self.executor_id)} - Could not close the ' + f'{self.backend_name} receiver', + exc_info=True, + ) + logger.debug( + f'{log_prefix(self.executor_id)} - ' + f'{self.backend_name} job monitor finished' + ) diff --git a/lithops/monitoring/status.py b/lithops/monitoring/status.py new file mode 100644 index 000000000..ab83ac070 --- /dev/null +++ b/lithops/monitoring/status.py @@ -0,0 +1,349 @@ +# +# Copyright Cloudlab URV 2021 +# +# Licensed under the Apache License, Version 2.0 (the "License"); +# you may not use this file except in compliance with the License. +# You may obtain a copy of the License at +# +# http://www.apache.org/licenses/LICENSE-2.0 +# +# Unless required by applicable law or agreed to in writing, software +# distributed under the License is distributed on an "AS IS" BASIS, +# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. +# See the License for the specific language governing permissions and +# limitations under the License. +# + +import atexit +import json +import logging +import os +import threading +import time +from types import SimpleNamespace +from typing import Any, Callable, Hashable + +from lithops.monitoring.backends import resolve_backend +from lithops.storage.utils import create_init_key, create_status_key +from lithops.utils import monitoring_queue_name, sizeof_fmt + +logger = logging.getLogger(__name__) + +#: 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 +REUSE_CLIENTS_ENV = 'LITHOPS_REUSE_MONITORING_CLIENTS' + +_SHARED_CLIENTS = {} +_SHARED_LOCK = threading.RLock() +_ATEXIT_REGISTERED = False + + +def reuse_clients() -> bool: + """ + Whether one client serves every call of this process. + + A worker runs the calls of its chunk one after another, and building a + client per call costs far more than publishing the status does: opening + an AMQP connection is some 150 times the cost of the publish it carries + """ + return os.environ.get(REUSE_CLIENTS_ENV, '1').strip().lower() not in { + '0', 'false', 'no' + } + + +def _release_client(client: Any, service: str = 'monitoring') -> None: + """Closes a client with whichever of close() and stop() its SDK offers""" + if client is None: + return + for method in ('close', 'stop'): + release = getattr(client, method, None) + if release is None: + continue + try: + release() + except Exception as e: + logger.debug(f'Could not {method}() the {service} client: {e}') + return + + +def shared_client(key: Hashable, factory: Callable[[], Any]) -> Any: + """ + The client kept for this process under ``key``, built on first use + """ + global _ATEXIT_REGISTERED + with _SHARED_LOCK: + client = _SHARED_CLIENTS.get(key) + if client is None: + client = _SHARED_CLIENTS[key] = factory() + if not _ATEXIT_REGISTERED: + _ATEXIT_REGISTERED = True + atexit.register(close_shared_clients) + return client + + +def drop_shared_client(key: Hashable) -> Any: + """Forgets the client under ``key``, and returns it so it can be closed""" + with _SHARED_LOCK: + return _SHARED_CLIENTS.pop(key, None) + + +def close_shared_clients() -> None: + """Releases every client this process kept. Runs at interpreter exit""" + with _SHARED_LOCK: + clients = list(_SHARED_CLIENTS.items()) + _SHARED_CLIENTS.clear() + for key, client in clients: + _release_client(client, str(key)) + + +def create_call_status(job: SimpleNamespace, internal_storage) -> 'CallStatus': + """ + Creates the call status class of the configured monitoring backend. + + The backend is resolved exactly as the client resolves it, so a config + that does not name one reports through the same default the client + listens on + """ + from lithops.monitoring.backends import load_backend_attr, resolve_backend + + backend = resolve_backend(job.config) + status_cls = load_backend_attr(backend, 'CallStatus') + return status_cls(job, internal_storage) + + +class CallStatus: + """ + Status of a single call, reported to the client both when the task starts + and when it finishes. + + A monitoring backend exports a subclass of this class as ``CallStatus``. + Workers only call :meth:`send_init_event` and :meth:`send_finish_event`; + the subclass implements :meth:`_send`. + """ + + def __init__(self, job: SimpleNamespace, internal_storage): + self.job = job + self.config = job.config + self.internal_storage = internal_storage + + self.status = { + 'exception': False, + 'activation_id': os.environ.get('__LITHOPS_ACTIVATION_ID'), + 'python_version': os.environ.get("PYTHON_VERSION"), + 'worker_start_tstamp': job.start_tstamp, + 'host_submit_tstamp': job.host_submit_tstamp, + 'call_id': job.call_id, + 'job_id': job.job_id, + 'executor_id': job.executor_id, + 'chunksize': job.chunksize + } + + is_warm = os.environ.get('WARM_CONTAINER', '').lower() in { + '1', 'true', 'yes' + } + self.status['worker_cold_start'] = not is_warm + if not is_warm: + os.environ['WARM_CONTAINER'] = 'True' + + def add(self, key: str, value: Any) -> None: + """ Adds data to the call status""" + self.status[key] = value + + def send_init_event(self) -> None: + """ Sends the init event""" + self.status['type'] = '__init__' + self._send() + + def send_finish_event(self) -> None: + """ Sends the finish event""" + self.status['type'] = '__end__' + self._send() + + def _send(self) -> None: + raise NotImplementedError + + +class StorageCallStatus(CallStatus): + """Reports the status of a call by writing it to the Object Storage""" + + def _send(self) -> None: + """ + Sends the status event to the Object Storage + """ + executor_id = self.status['executor_id'] + job_id = self.status['job_id'] + call_id = self.status['call_id'] + act_id = self.status['activation_id'] + + if self.status['type'] == '__init__': + init_key = create_init_key(executor_id, job_id, call_id, act_id) + self.internal_storage.put_data(init_key, '') + + elif self.status['type'] == '__end__': + status_key = create_status_key(executor_id, job_id, call_id) + dmpd_response_status = json.dumps(self.status) + logger.info( + f"Storing execution stats - " + f"Size: {sizeof_fmt(len(dmpd_response_status))}" + ) + self.internal_storage.put_data(status_key, dmpd_response_status) + + +class MessageCallStatus(StorageCallStatus): + """ + Reports the status of a call by publishing it to a message service, + which reaches the client faster, and falls back to Object Storage + at the end. + + Subclasses implement :meth:`_publish`. + """ + + MAX_ATTEMPTS = 5 + RETRY_SLEEP = 0.2 + MAX_RETRY_SLEEP = 5 + service_name = 'message service' + + def __init__(self, job: SimpleNamespace, internal_storage): + super().__init__(job, internal_storage) + # Clients this object built for itself, which nothing else uses and + # close() therefore has to release. A shared one outlives the call + self._own_clients = set() + + def _client_key(self, name: str) -> Hashable: + """ + What makes a shared client shareable: the class, the name of the + client, and the settings it was built from. A process that reports + to two brokers must not publish to one of them through the other's + connection + """ + backend = resolve_backend(self.config) + section = (self.config or {}).get(backend) or {} + settings = tuple(sorted( + (str(key), repr(value)) for key, value in section.items() + )) + return (type(self).__name__, name, settings) + + def obtain_client(self, name: str, factory: Callable[[], Any]) -> Any: + """ + The client to publish through, built on first use. + + Kept for the whole process unless reuse is turned off, in which case + each call builds and releases its own. Subclasses reach this through + a cached_property, so the client is looked up once per call + """ + if reuse_clients(): + return shared_client(self._client_key(name), factory) + client = factory() + self._own_clients.add(name) + return client + + def discard_client(self, name: str) -> None: + """ + Drops the client under ``name`` and closes it. + + A shared one is dropped from the process cache as well: a connection + that just failed must not be handed to the next call + """ + self.__dict__.pop(name, None) + if name in self._own_clients: + self._own_clients.discard(name) + return + _release_client( + drop_shared_client(self._client_key(name)), self.service_name + ) + + def _send(self) -> None: + """ + Publishes the status, and writes an __end__ to the Object Storage as + well. + + 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() + """ + dmpd_response_status = json.dumps(self.status) + 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 + 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: + logger.error( + f"Could not send the execution status to {self.service_name} " + f"after {self.MAX_ATTEMPTS} attempts: {exc}" + ) + + if self.status['type'] == '__end__': + super()._send() + + def _targets(self) -> list: + """ + Names this status has to be published to: every executor up the + chain, ending with this one. The client sends the list with the + job; without it only this executor can be reached. + """ + queues = getattr(self.job, 'monitoring_queues', None) + if queues: + return list(queues) + + logger.warning( + 'The job carries no monitoring queues, reporting only to the ' + f'queue of {self.job.executor_id}' + ) + return [monitoring_queue_name(self.job.executor_id)] + + def send_finish_event(self) -> None: + """ + Sends the last status of the call and releases the client with it: + the object is not used again, and a worker that keeps warm would + otherwise leave one connection per call behind + """ + try: + super().send_finish_event() + finally: + try: + self.close() + except Exception as e: + logger.debug( + f'Could not close the {self.service_name} client: {e}' + ) + + def close(self) -> None: + """ + Releases the clients this call owns, after its last status. + + A client kept for the process is left alone: the next call of the + chunk publishes through it, which is the point of keeping it + """ + self._release_cached(*sorted(self._own_clients)) + + def _release_cached(self, *names: str) -> None: + """ + Releases the clients a subclass built with ``cached_property``, + taken out of the instance dict rather than through the attribute so + that closing one that was never needed does not build it + """ + for name in names: + client = self.__dict__.pop(name, None) + self._own_clients.discard(name) + _release_client(client, self.service_name) + + def _publish(self, payload: str) -> None: + raise NotImplementedError diff --git a/lithops/scripts/cli.py b/lithops/scripts/cli.py index f329c4987..7c501ec1c 100644 --- a/lithops/scripts/cli.py +++ b/lithops/scripts/cli.py @@ -492,28 +492,31 @@ def hello(config, backend, storage, debug, region, map_count): def hello_fn(name): return f'Hello {name}!' - fexec = lithops.FunctionExecutor( - config=config_data, backend=backend, storage=storage, region=region - ) expected = f'Hello {username}!' - - if map_count: - fexec.map(hello_fn, [username] * map_count) - results = fexec.get_result() - print() - if all(result == expected for result in results): - print(f'All {map_count} map activations returned: {expected}') - print('Lithops is working as expected :)') - else: - print(results, 'Something went wrong :(') - else: - fexec.call_async(hello_fn, username) - result = fexec.get_result() - print() - if result == expected: - print(result, 'Lithops is working as expected :)') + with lithops.FunctionExecutor( + config=config_data, backend=backend, storage=storage, region=region + ) as fexec: + if map_count: + fexec.map(hello_fn, [username] * map_count) + results = fexec.get_result() + succeeded = all(result == expected for result in results) + message = ( + f'All {map_count} map activations returned: {expected}\n' + 'Lithops is working as expected :)' + if succeeded else + f'{results} Something went wrong :(' + ) else: - print(result, 'Something went wrong :(') + fexec.call_async(hello_fn, username) + result = fexec.get_result() + message = ( + f'{result} Lithops is working as expected :)' + if result == expected else + f'{result} Something went wrong :(' + ) + + print() + print(message) print() diff --git a/lithops/storage/storage.py b/lithops/storage/storage.py index c654d23e8..50f568cf5 100644 --- a/lithops/storage/storage.py +++ b/lithops/storage/storage.py @@ -379,7 +379,9 @@ def get_job_status(self, executor_id, job_ids: Optional[Iterable[str]] = None): """ if job_ids: keys = [] - for job_id in job_ids: + # Copied first: a caller may pass a set that its own threads + # keep adding jobs to while this listing runs + for job_id in tuple(job_ids): prefix = '/'.join([ JOBS_PREFIX, utils.create_job_key(executor_id, job_id) ]) diff --git a/lithops/tests/conftest.py b/lithops/tests/conftest.py index 76d27f14a..f7c670655 100644 --- a/lithops/tests/conftest.py +++ b/lithops/tests/conftest.py @@ -3,8 +3,10 @@ import logging from lithops.config import ( default_config, + extract_storage_config, load_yaml_config ) +from lithops.storage import Storage logger = logging.getLogger(__name__) @@ -62,3 +64,33 @@ def setup_global(request): lithops_config = default_config(config_data=config_data, config_overwrite=config_ow) pytest.lithops_config = lithops_config + _clear_tests_prefix(lithops_config) + + +def _clear_tests_prefix(config): + """ + Deletes whatever an earlier session left under the tests prefix. + + Every test class removes its own objects on teardown, but a session + that was interrupted never gets there, and what it left behind then + turns up in the listings of the next one, which counts words and + objects and gets a number nobody can explain + """ + try: + storage = Storage(storage_config=extract_storage_config(config)) + keys = storage.list_keys(bucket=storage.bucket, prefix=TESTS_PREFIX) + for key in keys: + storage.delete_object(bucket=storage.bucket, key=key) + except Exception: + # Never fail the session over this: the tests that care clean up + # after themselves, and this only spares them a dirty start + logger.warning( + f'Could not clear the {TESTS_PREFIX} prefix left by an earlier ' + 'test session', exc_info=True + ) + return + if keys: + logger.info( + f'Removed {len(keys)} object(s) left under {TESTS_PREFIX} by an ' + 'earlier test session' + ) diff --git a/lithops/tests/functions.py b/lithops/tests/functions.py index 12e4021e3..fa789ec8f 100644 --- a/lithops/tests/functions.py +++ b/lithops/tests/functions.py @@ -25,6 +25,32 @@ def _func(x): return fexec.get_result() +def _started(fut): + """ + Tells whether a future has at least started, the way the job monitor + does. The states are mutually exclusive, so a future that already ran + past Ready into Success or Done is no longer `ready`: testing only + `running or ready` misses it and loops for ever + """ + return fut.running or fut.ready or fut.success or fut.done + + +def _wait_until_started(futures, timeout=60): + """ + Waits for every future to have started, so that the parent executor + can pick them up once this one returns them. Required for the + localhost tests to pass on Windows + """ + deadline = time.time() + timeout + while not all(_started(f) for f in futures): + if time.time() > deadline: + raise TimeoutError( + 'Nested futures did not start within ' + f'{timeout}s: {[f._state for f in futures]}' + ) + time.sleep(0.1) + + def lithops_return_futures_map(x): def _func(x): return x + 1 @@ -32,9 +58,7 @@ def _func(x): fexec = lithops.FunctionExecutor() futures = fexec.map(_func, range(x)) - # this while loop is required to pass localhost tests on Windows - while not all(f.running or f.ready for f in futures): - time.sleep(0.1) + _wait_until_started(futures) return futures @@ -48,9 +72,7 @@ def _func(x, y): fexec = lithops.FunctionExecutor() futures = fexec.map(partial(_func, 2), range(x)) - # this while loop is required to pass localhost tests on Windows - while not all(f.running or f.ready for f in futures): - time.sleep(0.1) + _wait_until_started(futures) return futures @@ -62,9 +84,7 @@ def _func(x): fexec = lithops.FunctionExecutor() fut = fexec.call_async(_func, x + 5) - # this while loop is required to pass localhost tests on Windows - while not (fut.running or fut.ready): - time.sleep(0.1) + _wait_until_started([fut]) return fut @@ -77,9 +97,7 @@ def _func(x): fut1 = fexec.map(_func, range(x)) fut2 = fexec.map(_func, range(x)) - # this while loop is required to pass localhost tests on Windows - while not all(f.running or f.ready for f in fut1 + fut2): - time.sleep(0.1) + _wait_until_started(fut1 + fut2) return fut1 + fut2 diff --git a/lithops/tests/test_concurrent_futures.py b/lithops/tests/test_concurrent_futures.py index 8554987a1..c1e3ca531 100644 --- a/lithops/tests/test_concurrent_futures.py +++ b/lithops/tests/test_concurrent_futures.py @@ -145,7 +145,7 @@ def is_alive(self): class FakeJobMonitor: """ - Stand-in for lithops.monitor.JobMonitor. Records the futures it was + Stand-in for lithops.monitoring.JobMonitor. Records the futures it was asked to track so a test can tell whether the adapter restarted it """ @@ -169,6 +169,14 @@ def stop(self): if self.monitor is not None: self.monitor.alive = False + def cleanup(self): + pass + + def prepare(self): + if self.monitor is None: + self.monitor = FakeMonitor() + self.monitor.alive = False + class FakeInnerExecutor: """ diff --git a/lithops/tests/test_config.py b/lithops/tests/test_config.py index 5d3a71252..3f6390ea1 100644 --- a/lithops/tests/test_config.py +++ b/lithops/tests/test_config.py @@ -465,6 +465,92 @@ def test_unknown_mode_raises(self): 'lithops': {'mode': 'spaceship', 'storage': c.LOCALHOST} }) + def test_unknown_monitoring_backend_raises(self): + with pytest.raises(Exception, match='Unknown monitoring backend'): + default_config(config_data=_localhost_input(monitoring='nope')) + + def test_a_null_monitoring_key_falls_back_to_storage(self): + """ + An explicit null used to reach .lower() and raise AttributeError + rather than falling back the way a missing key does + """ + config_data = _localhost_input() + config_data['lithops']['monitoring'] = None + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'storage' + + def test_the_monitoring_backend_name_is_normalised(self): + config_data = _localhost_input(monitoring='RabbitMQ') + config_data['rabbitmq'] = {'amqp_url': 'amqp://guest@localhost'} + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'rabbitmq' + + def test_rabbitmq_monitoring_requires_amqp_url(self): + with pytest.raises(Exception, match='rabbitmq'): + default_config(config_data=_localhost_input(monitoring='rabbitmq')) + + def test_rabbitmq_monitoring_loads_with_amqp_url(self): + config_data = _localhost_input(monitoring='rabbitmq') + config_data['rabbitmq'] = {'amqp_url': 'amqp://guest@localhost'} + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'rabbitmq' + assert cfg['rabbitmq']['amqp_url'] == 'amqp://guest@localhost' + + def test_redis_monitoring_requires_host(self): + with pytest.raises(Exception, match='redis'): + default_config(config_data=_localhost_input(monitoring='redis')) + + def test_redis_monitoring_loads_with_host(self): + config_data = _localhost_input(monitoring='redis') + config_data['redis'] = {'host': 'localhost'} + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'redis' + assert cfg['redis']['host'] == 'localhost' + + def test_aws_sqs_monitoring_merges_aws_section(self): + config_data = _localhost_input(monitoring='aws_sqs') + config_data['aws'] = {'region': 'eu-west-1', 'access_key_id': 'AK'} + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'aws_sqs' + assert cfg['aws_sqs']['region'] == 'eu-west-1' + assert cfg['aws_sqs']['access_key_id'] == 'AK' + + def test_aws_sqs_monitoring_requires_region(self): + with pytest.raises(Exception, match='region'): + default_config(config_data=_localhost_input(monitoring='aws_sqs')) + + def test_gcp_pubsub_monitoring_merges_gcp_section(self, monkeypatch): + monkeypatch.delenv('GOOGLE_APPLICATION_CREDENTIALS', raising=False) + config_data = _localhost_input(monitoring='gcp_pubsub') + config_data['gcp'] = { + 'project_name': 'my-proj', + 'credentials_path': '/tmp/creds.json', + } + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'gcp_pubsub' + assert cfg['gcp_pubsub']['project_name'] == 'my-proj' + assert cfg['gcp_pubsub']['credentials_path'] == '/tmp/creds.json' + + def test_gcp_pubsub_monitoring_requires_project_name(self, monkeypatch): + monkeypatch.delenv('GOOGLE_APPLICATION_CREDENTIALS', raising=False) + with pytest.raises(Exception, match='project_name'): + default_config(config_data=_localhost_input(monitoring='gcp_pubsub')) + + def test_azure_queue_monitoring_merges_azure_storage(self): + config_data = _localhost_input(monitoring='azure_queue') + config_data['azure_storage'] = { + 'storage_account_name': 'acct', + 'storage_account_key': 'key', + } + cfg = default_config(config_data=config_data) + assert cfg['lithops']['monitoring'] == 'azure_queue' + assert cfg['azure_queue']['storage_account_name'] == 'acct' + assert cfg['azure_queue']['storage_account_key'] == 'key' + + def test_azure_queue_monitoring_requires_account(self): + with pytest.raises(Exception, match='storage_account_name'): + default_config(config_data=_localhost_input(monitoring='azure_queue')) + class TestStorageAndExtract: diff --git a/lithops/tests/test_executors.py b/lithops/tests/test_executors.py index 1c5a12d7d..b540529e5 100644 --- a/lithops/tests/test_executors.py +++ b/lithops/tests/test_executors.py @@ -345,6 +345,16 @@ def test_wait_stops_monitor_when_all_tracked_futures_are_done(self, mock_wait): executor.wait([future], return_when=ALL_COMPLETED, show_progressbar=False) executor.job_monitor.stop.assert_called_once() + @patch('lithops.executors.wait') + def test_wait_stops_monitor_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._cleanup_jobs = lambda *a, **k: order.append('clean') + executor.wait([future], return_when=ALL_COMPLETED, show_progressbar=False) + assert order == ['stop', 'clean'] + @patch('lithops.executors.wait') def test_wait_keeps_monitor_when_other_futures_are_pending(self, mock_wait): done = FakeFuture(done=True, success=True) @@ -353,6 +363,59 @@ def test_wait_keeps_monitor_when_other_futures_are_pending(self, mock_wait): executor.wait([done], return_when=ALL_COMPLETED, show_progressbar=False) executor.job_monitor.stop.assert_not_called() + def test_exit_waits_for_the_invoker_threads(self): + """ + The invoker loops drain the invocations already in flight only as + they exit, so leaving the block has to give them the chance rather + than returning while they are still dispatching + """ + executor = _bare_executor() + executor.__exit__(None, None, None) + executor.invoker.stop.assert_called_once_with(wait=True) + executor.job_monitor.stop.assert_called_once() + executor.job_monitor.cleanup.assert_called_once() + executor.compute_handler.clear.assert_called_once() + + def test_invoking_a_job_creates_the_monitor_resources_first(self): + """ + The queue, topic or key the workers report to has to exist before + the first of them is invoked, or the first status is published into + nowhere. Doing it in __init__ instead meant that merely building an + executor created a queue in the cloud, and failed on a broker that + was not reachable + """ + calls = [] + executor = _bare_executor() + executor.job_monitor.prepare.side_effect = lambda: calls.append( + 'prepare' + ) + executor.invoker.run_job.side_effect = lambda job: ( + calls.append('run_job') or [] + ) + executor._invoke(MagicMock()) + assert calls == ['prepare', 'run_job'] + + def test_the_monitor_resources_are_released_at_exit_either_way(self): + """ + data_cleaner decides whether the temporary job data is deleted, not + whether a queue this executor created outlives it: nothing else + comes back to delete that one + """ + for data_cleaner in (True, False): + executor = _bare_executor(data_cleaner=data_cleaner) + with patch.object(executor, 'clean') as clean: + executor._clean_at_exit() + executor.job_monitor.stop.assert_called_once() + executor.job_monitor.cleanup.assert_called_once() + assert clean.called is data_cleaner + + def test_a_failure_at_exit_does_not_stop_the_remaining_hooks(self): + executor = _bare_executor(data_cleaner=True) + executor.job_monitor.stop.side_effect = RuntimeError('broker gone') + with patch.object(executor, 'clean') as clean: + executor._clean_at_exit() + clean.assert_called_once() + @patch('lithops.executors.wait', side_effect=RuntimeError('boom')) def test_wait_exception_stops_invoker_and_reraises(self, mock_wait): future = FakeFuture() @@ -376,6 +439,17 @@ def test_get_result_unwraps_single_non_map_result(self): assert executor.get_result() == 42 assert future._read is True + def test_get_result_cleans_after_collecting_results(self): + future = FakeFuture(_result=42) + executor = _bare_executor( + data_cleaner=True, last_call='call_async', futures=[future] + ) + with patch.object(executor, 'wait', return_value=([future], [])) as waited: + with patch.object(executor, '_cleanup_jobs') as cleanup: + assert executor.get_result() == 42 + assert waited.call_args.kwargs['clean_jobs'] is False + cleanup.assert_called_once() + def test_get_result_keeps_list_for_map(self): future = FakeFuture(_result=42) executor = _bare_executor(last_call='map', futures=[future]) diff --git a/lithops/tests/test_localhost.py b/lithops/tests/test_localhost.py index 14378757e..aba7f9495 100644 --- a/lithops/tests/test_localhost.py +++ b/lithops/tests/test_localhost.py @@ -13,6 +13,7 @@ import signal import subprocess as sp import sys +import time from pathlib import Path from unittest.mock import MagicMock, patch @@ -185,6 +186,12 @@ def test_start_manager_is_noop_when_already_running(self): handler.env.start.assert_not_called() def test_clear_drains_queue_and_unlocks_jobs(self): + """ + clear() without a job named is the executor going away, so the + running tasks are stopped: nothing is waiting on their output, + and waiting for one would hold up the shutdown for as long as + it runs + """ handler = LocalhostHandlerV2(_config()) handler.env = MagicMock() handler.env.work_queue = queue.Queue() @@ -195,8 +202,30 @@ def test_clear_drains_queue_and_unlocks_jobs(self): handler.clear() handler.env.drop_pending_tasks.assert_called_once_with(None) handler.env.stop.assert_called_once_with(None) + handler.env.finish.assert_not_called() assert latch.done is True + def test_clear_of_a_named_job_lets_its_tasks_finish(self): + """ + A named job that ended cleanly keeps its runner log, so its + tasks are left to exit on their own + """ + handler = LocalhostHandlerV2(_config()) + handler.env = MagicMock() + handler.env.jobs = {} + handler.clear({'sess-0-M000'}) + handler.env.finish.assert_called_once_with({'sess-0-M000'}) + handler.env.stop.assert_not_called() + + def test_clear_kills_running_tasks_on_exception(self): + handler = LocalhostHandlerV2(_config()) + handler.env = MagicMock() + handler.env.jobs = {} + error = RuntimeError('boom') + handler.clear(exception=error) + handler.env.stop.assert_called_once_with(None) + handler.env.finish.assert_not_called() + def test_clear_leaves_the_latches_of_other_jobs_alone(self): handler = LocalhostHandlerV2(_config()) handler.env = MagicMock() @@ -236,11 +265,30 @@ def test_invoke_queues_prepared_job_file(self): assert handler.invocation_in_progress is False def test_clear_drains_queue_and_sends_sentinel(self): + """ + clear() without a job named is the executor going away, so the + running job is stopped rather than waited for + """ handler = LocalhostHandlerV1(_config()) handler.env = MagicMock() handler.job_manager = object() handler.job_queue.put(('job', 'file')) handler.clear() + handler.env.stop.assert_called_once_with(None) + assert handler.job_queue.get_nowait() == (None, None) + + def test_clear_of_a_named_job_lets_it_finish(self): + handler = LocalhostHandlerV1(_config()) + handler.env = MagicMock() + handler.job_manager = object() + handler.clear({'sess-0-M000'}) + handler.env.stop.assert_not_called() + + def test_clear_kills_running_jobs_on_exception(self): + handler = LocalhostHandlerV1(_config()) + handler.env = MagicMock() + handler.job_manager = object() + handler.clear(exception=RuntimeError('boom')) handler.env.stop.assert_called_once() assert handler.job_queue.get_nowait() == (None, None) @@ -345,6 +393,17 @@ def test_default_run_task_invokes_runner_and_drops_process(self): log_fail.assert_called_once() assert log_fail.call_args.kwargs['stderr'] == b'Traceback: boom\n' + def test_default_run_task_does_not_dump_logs_when_signalled(self): + env = v2.DefaultEnvironment(_config()) + proc = MagicMock() + proc.returncode = -9 + proc.communicate.return_value = (b'', b'') + with patch('lithops.localhost.v2.localhost.sp.Popen', return_value=proc), \ + patch('lithops.localhost.v2.localhost.log_process_failure') as log_fail: + env.run_task('sess-0-M000', '00000') + log_fail.assert_not_called() + assert 'sess-0-M000-00000' not in env.task_processes + def test_default_stop_kills_matching_process_group(self): env = v2.DefaultEnvironment(_config(worker_processes=1)) proc = MagicMock() @@ -390,6 +449,31 @@ def test_stop_keeps_consumers_while_another_job_runs(self): env.stop(['sess-0-M001']) assert env.consumer_threads == [] + def test_finish_keeps_consumers_while_another_job_runs(self): + env = v2.DefaultEnvironment(_config(worker_processes=1)) + env.jobs = { + 'sess-0-M000': CountDownLatch(0), + 'sess-0-M001': CountDownLatch(1), + } + threads = [MagicMock()] + env.consumer_threads = list(threads) + env.finish(['sess-0-M000']) + assert env.consumer_threads == threads + threads[0].join.assert_not_called() + + def test_finish_tears_down_without_killing(self): + env = v2.DefaultEnvironment(_config(worker_processes=1)) + proc = MagicMock() + proc.poll.return_value = None + env.task_processes['sess-0-M000-00000'] = proc + env.jobs = {'sess-0-M000': CountDownLatch(0)} + env.consumer_threads = [MagicMock()] + with patch('lithops.localhost.utils.os.killpg') as killpg: + env.finish(['sess-0-M000']) + killpg.assert_not_called() + assert 'sess-0-M000-00000' in env.task_processes + assert env.consumer_threads == [] + def test_drop_pending_tasks_keeps_the_other_jobs_tasks(self): env = v2.DefaultEnvironment(_config(worker_processes=1)) mine = json.dumps({'job_key': 'sess-0-M000'}) @@ -450,7 +534,10 @@ def test_container_metadata_command_uses_runner_and_user(self): assert '--user' in cmd assert '1000:1000' in joined assert 'get_metadata' in joined - assert f'/tmp/{USER_TEMP_DIR}/localhost-runner.py' in joined + # Taken from the constant, not spelled out: the runner name + # carries the localhost version, and v1 and v2 must differ + assert v2.DOCKER_RUNNER_FILE in joined + assert f'/tmp/{USER_TEMP_DIR}/' in v2.DOCKER_RUNNER_FILE def test_container_run_task_uses_docker_exec(self): with patch.object(v2, 'get_docker_path', return_value='docker'), \ @@ -689,6 +776,97 @@ def test_copy_lithops_package_skips_pycache(self, tmp_path): assert not (copied / '__pycache__').exists() assert (dest_root / 'runner.py').read_text() == '# runner\n' + def test_copy_lithops_package_always_installs_the_given_runner( + self, tmp_path + ): + """ + The v1 and v2 backends copy a different runner to the same + destination, so switching between them in one process has to + replace it. The package tree itself is only copied once + """ + from lithops.localhost import utils as localhost_utils + + src = tmp_path / 'src' / 'lithops' + src.mkdir(parents=True) + (src / 'mod.py').write_text('x = 1\n') + runner_a = tmp_path / 'a.py' + runner_a.write_text('# runner A\n') + runner_b = tmp_path / 'b.py' + runner_b.write_text('# runner B\n') + dest_root = tmp_path / 'dest' + installed = dest_root / 'runner.py' + + copies = [] + real_copytree = localhost_utils.shutil.copytree + + def counting(*args, **kwargs): + copies.append(1) + return real_copytree(*args, **kwargs) + + with patch.object(localhost_utils.shutil, 'copytree', counting): + for runner in (runner_a, runner_b, runner_a): + copy_lithops_package( + str(src), str(runner), str(installed), str(dest_root) + ) + assert installed.read_text() == runner.read_text() + + assert len(copies) == 1, 'the package tree was copied more than once' + assert (dest_root / 'lithops' / 'mod.py').is_file() + + def test_copy_lithops_package_recopies_a_changed_source(self, tmp_path): + """ + A development install changes under a running process, and a cache + keyed on the path alone would keep serving the tree as it was when + the first executor of the session started + """ + from lithops.localhost import utils as localhost_utils + + src = tmp_path / 'src' / 'lithops' + src.mkdir(parents=True) + (src / 'mod.py').write_text('x = 1\n') + runner_src = tmp_path / 'runner.py' + runner_src.write_text('# runner\n') + dest_root = tmp_path / 'dest' + args = ( + str(src), str(runner_src), + str(dest_root / 'runner.py'), str(dest_root), + ) + + copies = [] + real_copytree = localhost_utils.shutil.copytree + + def counting(*a, **kw): + copies.append(1) + return real_copytree(*a, **kw) + + with patch.object(localhost_utils.shutil, 'copytree', counting): + copy_lithops_package(*args) + copy_lithops_package(*args) + assert len(copies) == 1 + + (src / 'mod.py').write_text('x = 2\n') + os.utime(src / 'mod.py', (time.time() + 10, time.time() + 10)) + copy_lithops_package(*args) + assert len(copies) == 2 + + assert (dest_root / 'lithops' / 'mod.py').read_text() == 'x = 2\n' + + def test_copy_lithops_package_recopies_a_missing_tree(self, tmp_path): + src = tmp_path / 'src' / 'lithops' + src.mkdir(parents=True) + (src / 'mod.py').write_text('x = 1\n') + runner_src = tmp_path / 'runner.py' + runner_src.write_text('# runner\n') + dest_root = tmp_path / 'dest' + args = ( + str(src), str(runner_src), + str(dest_root / 'runner.py'), str(dest_root), + ) + copy_lithops_package(*args) + shutil.rmtree(dest_root / 'lithops') + copy_lithops_package(*args) + assert (dest_root / 'lithops' / 'mod.py').is_file() + class TestLocalhostRunners: @@ -989,6 +1167,7 @@ def test_map_in_python_container(self): cfg['lithops']['backend'] = 'localhost' cfg['lithops']['mode'] = 'localhost' cfg['lithops']['storage'] = 'localhost' + cfg['lithops']['monitoring'] = 'storage' cfg.setdefault('localhost', {}) cfg['localhost']['runtime'] = image cfg['localhost']['pull_runtime'] = False diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index 2e1dfd6a0..94fd2e573 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -17,24 +17,34 @@ import queue import threading import time +from types import SimpleNamespace +from contextlib import contextmanager from unittest.mock import MagicMock, patch +import pytest -from lithops.monitor import ( +from lithops.monitoring import JobMonitor +from lithops.monitoring.backends.rabbitmq import RabbitmqMonitor +from lithops.monitoring.backends.storage import StorageMonitor +from lithops.monitoring.backends import resolve_backend +from lithops.monitoring.monitor import ( LOG_INTERVAL, - JobMonitor, Monitor, - RabbitmqMonitor, - StorageMonitor, + PollingMessageMonitor, _is_finished, _is_started, _status_id, ) -from lithops import monitor as rabbit_monitor_module +from lithops.monitoring.backends.rabbitmq import rabbitmq as rabbitmq_backend +from lithops.monitoring.backends.redis import redis as redis_backend +from lithops.monitoring.backends.aws_sqs import aws_sqs as sqs_backend +from lithops.monitoring.backends.azure_queue import azure_queue as azure_backend +from lithops.monitoring.backends.gcp_pubsub import gcp_pubsub as pubsub_backend from lithops.utils import ( _future_id, monitoring_queue_name, monitoring_queues, + remote_invoker_queue_name, ) @@ -73,6 +83,20 @@ def _set_futures(self, call_status): self._new_futures = ['nested'] +@contextmanager +def _client(module, factory, value): + """ + Points a backend's client factory at a fake. + + The clients are built by a module-level factory rather than taken out of + the config: a test seam that lives in the user's configuration is one + more key every backend has to remember to filter out before handing the + section to its SDK + """ + with patch.object(module, factory, return_value=value): + yield + + def _monitor(): return Monitor( executor_id='sess-0', @@ -97,6 +121,73 @@ def test_add_futures_tracks_jobs(self): assert monitor.futures == {first, second, third} assert monitor.present_jobs == {'M000', 'M001'} + def test_add_futures_leaves_an_earlier_snapshot_alone(self): + """ + The monitor thread lists the storage prefix of every job in + present_jobs; growing that very set from another thread is what + used to raise "Set changed size during iteration" + """ + monitor = _monitor() + monitor.add_futures([FakeFuture('M000')]) + snapshot = monitor.present_jobs + monitor.add_futures([FakeFuture('M001')]) + assert snapshot == {'M000'} + assert monitor.present_jobs == {'M000', 'M001'} + + def test_present_jobs_can_be_iterated_while_futures_are_added(self): + monitor = _monitor() + monitor.add_futures([FakeFuture(f'M{i:03d}') for i in range(50)]) + errors = [] + stop = threading.Event() + + def reader(): + while not stop.is_set(): + try: + for _job_id in monitor.present_jobs: + pass + except RuntimeError as exc: + errors.append(exc) + return + + thread = threading.Thread(target=reader) + thread.start() + try: + for i in range(50, 1500): + monitor.add_futures([FakeFuture(f'M{i:04d}')]) + finally: + stop.set() + thread.join(timeout=5) + assert not errors + + def test_concurrent_adds_do_not_lose_a_job(self): + """ + Guards the invariant, not the race: replacing present_jobs is a + read-modify-write, so the rebind is locked to stop two submitting + threads from reading the same set and dropping each other's job. + A job missing from it is never listed and its futures never get a + status. The interleaving is too narrow to provoke here, so this + only pins the result down + """ + monitor = _monitor() + expected = {f'M{i:03d}' for i in range(200)} + barrier = threading.Barrier(4) + + def adder(job_ids): + barrier.wait() + for job_id in job_ids: + monitor.add_futures([FakeFuture(job_id)]) + + jobs = sorted(expected) + threads = [ + threading.Thread(target=adder, args=(jobs[i::4],)) + for i in range(4) + ] + for thread in threads: + thread.start() + for thread in threads: + thread.join(timeout=10) + assert monitor.present_jobs == expected + def test_remove_futures_drops_job_ids_from_removed_set(self): monitor = _monitor() keep = FakeFuture('M000', done=True) @@ -147,15 +238,36 @@ def test_all_ready_false_when_any_pending(self): ]) assert monitor._all_ready() is False - def test_all_ready_swallows_unexpected_errors(self): - class Broken: - @property - def ready(self): - raise RuntimeError('boom') - + def test_all_ready_iterates_a_snapshot(self): + """ + The futures set is read from the monitor thread and written from the + threads that submit jobs. Every reader takes a snapshot under the + lock, so a concurrent add can no longer raise "Set changed size + during iteration" in the middle of a check + """ monitor = _monitor() - monitor.futures.add(Broken()) - assert monitor._all_ready() is False + monitor.add_futures([FakeFuture('M000', call_id=f'{i:05d}') + for i in range(200)]) + errors = [] + stop = threading.Event() + + def reader(): + while not stop.is_set(): + try: + monitor._all_ready() + except RuntimeError as exc: + errors.append(exc) + return + + thread = threading.Thread(target=reader) + thread.start() + try: + for i in range(200, 2000): + monitor.add_futures([FakeFuture('M001', call_id=f'{i:05d}')]) + finally: + stop.set() + thread.join(timeout=5) + assert not errors class TestJobMonitor: @@ -167,6 +279,9 @@ def test_defaults_to_storage_monitor_without_config(self): job_monitor = JobMonitor('sess-0', storage) assert job_monitor.type == 'storage' assert job_monitor.storage_backend == 'localhost' + assert StorageMonitor.prepare_config(None, storage) == { + 'monitoring_interval': 2 + } def test_start_creates_monitor_and_records_chunksize(self): storage = MagicMock() @@ -177,6 +292,9 @@ def test_start_creates_monitor_and_records_chunksize(self): instance = MagicMock() instance.is_alive.return_value = False job_monitor.MonitorClass = MagicMock(return_value=instance) + job_monitor.MonitorClass.prepare_config.return_value = { + 'monitoring_interval': 2 + } futures = [FakeFuture('M000')] job_monitor.start(futures, job_id='M000', chunksize=4, generate_tokens=True) @@ -218,10 +336,16 @@ def test_rabbitmq_type_uses_backend_section_as_monitor_config(self): job_monitor = JobMonitor('sess-0', storage, config=config) assert job_monitor.type == 'rabbitmq' assert job_monitor.MonitorClass is RabbitmqMonitor + assert RabbitmqMonitor.prepare_config(config, storage) == { + 'amqp_url': 'amqp://guest@localhost' + } instance = MagicMock() instance.is_alive.return_value = False job_monitor.MonitorClass = MagicMock(return_value=instance) + job_monitor.MonitorClass.prepare_config.return_value = { + 'amqp_url': 'amqp://guest@localhost' + } job_monitor.start([FakeFuture('M000')]) assert job_monitor.MonitorClass.call_args.kwargs['config'] == { 'amqp_url': 'amqp://guest@localhost' @@ -235,7 +359,13 @@ def test_remove_and_stop_are_noops_without_a_live_monitor(self): job_monitor.remove([FakeFuture('M000')]) job_monitor.stop() - def test_stop_joins_a_live_monitor(self): + def test_stop_does_not_wait_for_a_live_monitor(self): + """ + stop() runs after every wait() whose futures are all done, not only + at shutdown. Joining there made the caller wait out a poll interval + of the backend every time; the thread is a daemon and winds down on + its own + """ storage = MagicMock() storage.get_storage_config.return_value = {'monitoring_interval': 2} storage.backend = 'localhost' @@ -245,7 +375,76 @@ def test_stop_joins_a_live_monitor(self): job_monitor.monitor = live job_monitor.stop() live.stop.assert_called_once() - live.join.assert_called_once_with(timeout=5) + live.join.assert_not_called() + + def test_cleanup_waits_for_the_monitor_before_deleting(self): + """ + The queue, topic or key is deleted under the thread that reads from + it otherwise + """ + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + job_monitor = JobMonitor('sess-0', storage) + live = MagicMock() + live.is_alive.side_effect = [True, False] + job_monitor.monitor = live + job_monitor.cleanup() + live.stop.assert_called_once() + live.join.assert_called_once_with(timeout=JobMonitor.STOP_TIMEOUT) + assert live.method_calls.index(('cleanup', (), {})) > \ + live.method_calls.index(('join', (), {'timeout': JobMonitor.STOP_TIMEOUT})) + + def test_a_stopped_monitor_is_replaced_not_revived(self): + """ + Its loop would return on the next round without ever picking the new + futures up. The old thread is waited for first: two threads reading + the same queue split the statuses between them, and the one on its + way out takes what it reads to the grave + """ + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + job_monitor = JobMonitor('sess-0', storage) + + stopped = MagicMock() + stopped.should_run = False + stopped.is_alive.side_effect = [True, False, False] + job_monitor.monitor = stopped + + fresh = MagicMock() + fresh.is_alive.return_value = False + job_monitor.MonitorClass = MagicMock(return_value=fresh) + job_monitor.MonitorClass.prepare_config.return_value = {} + + job_monitor.start([FakeFuture('M001')]) + + stopped.join.assert_called_once_with(timeout=JobMonitor.STOP_TIMEOUT) + assert job_monitor.monitor is fresh + fresh.start.assert_called_once() + + def test_stop_releases_resources_of_a_finished_monitor(self): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + job_monitor = JobMonitor('sess-0', storage) + finished = MagicMock() + finished.is_alive.return_value = False + job_monitor.monitor = finished + job_monitor.stop() + finished.stop.assert_called_once() + finished.join.assert_not_called() + + def test_cleanup_delegates_to_the_backend(self): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + job_monitor = JobMonitor('sess-0', storage) + job_monitor.cleanup() + backend = MagicMock() + job_monitor.monitor = backend + job_monitor.cleanup() + backend.cleanup.assert_called_once() def test_is_alive_without_a_started_monitor(self): """ @@ -259,6 +458,95 @@ def test_is_alive_without_a_started_monitor(self): assert job_monitor.monitor is None assert job_monitor.is_alive() is False + def test_unknown_backend_raises(self): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + with pytest.raises(ValueError, match='Unknown monitoring backend'): + JobMonitor( + 'sess-0', storage, + config={'lithops': {'monitoring': 'nope'}}, + ) + + def test_backend_kwarg_overrides_config(self): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + storage.backend = 'localhost' + job_monitor = JobMonitor( + 'sess-0', storage, + backend='storage', + config={'lithops': {'monitoring': 'rabbitmq'}}, + ) + assert job_monitor.type == 'storage' + assert job_monitor.MonitorClass is StorageMonitor + + +class TestMonitoringQueueName: + """ + The remote invoker follows the calls of the client's executor from + inside a worker. A message taken off a queue is gone, so the two of + them reading the same one would split the statuses between them and + leave the client waiting on calls it never hears about again + """ + + def test_the_invoker_queue_is_not_the_executor_queue(self): + assert ( + remote_invoker_queue_name('sess-0') + != monitoring_queue_name('sess-0') + ) + + def test_a_monitor_reads_its_executor_queue_by_default(self): + monitor = _monitor() + assert monitor.monitoring_queue_name() == monitoring_queue_name('sess-0') + + def test_the_config_can_name_the_queue_instead(self): + monitor = Monitor( + 'sess-0', None, queue.Queue(), {}, False, + {'queue_name': remote_invoker_queue_name('sess-0')}, + ) + assert monitor.monitoring_queue_name() == 'lithops-sess-0-invoker' + + def test_every_message_backend_honours_the_name(self): + from lithops.tests.mp_fakeredis import FakeRedis + from lithops.monitoring.backends.redis import RedisMonitor + from lithops.monitoring.backends.aws_sqs import SqsMonitor + + named = remote_invoker_queue_name('sess-0') + sqs = MagicMock() + sqs.create_queue.return_value = {'QueueUrl': 'url'} + built = [] + with _client(redis_backend, 'redis_client', FakeRedis()): + built.append(RedisMonitor( + 'sess-0', None, queue.Queue(), {}, False, + {'queue_name': named}, + )) + with _client(sqs_backend, 'sqs_client', sqs): + built.append(SqsMonitor( + 'sess-0', None, queue.Queue(), {}, False, + {'queue_name': named}, + )) + for monitor in built: + assert monitor.queue == named, type(monitor).__name__ + + def test_job_monitor_passes_the_name_without_touching_the_config(self): + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + config = {'lithops': {'monitoring': 'redis'}, 'redis': {}} + named = remote_invoker_queue_name('sess-0') + + with _client(redis_backend, 'redis_client', MagicMock()): + job_monitor = JobMonitor( + 'sess-0', storage, config=config, queue_name=named + ) + job_monitor.prepare() + assert job_monitor.monitor.queue == named + # prepare_config() hands back the caller's own section + assert 'queue_name' not in config['redis'] + + default = JobMonitor('sess-0', storage, config=config) + default.prepare() + assert default.monitor.queue == monitoring_queue_name('sess-0') + class TestMonitorHelpers: @@ -284,6 +572,22 @@ def test_is_finished_and_is_started(self): class TestTimeoutAndStatusLog: + @pytest.fixture(autouse=True) + def _propagate_monitor_logs(self): + """ + Lets caplog see the monitor debug log. Other tests in the suite + run setup_lithops_logger(), which stops the 'lithops' logger + from propagating to the root handler caplog installs, so without + this the assertions below either fail or pass vacuously + """ + lithops_logger = logging.getLogger('lithops') + propagate = lithops_logger.propagate + lithops_logger.propagate = True + try: + yield + finally: + lithops_logger.propagate = propagate + def test_timeout_checker_marks_expired_running_future_ready(self): monitor = _monitor() future = FakeFuture('M000', running=True, execution_timeout=1, activation_id='act-1') @@ -299,49 +603,105 @@ def test_timeout_checker_ignores_futures_without_call_status(self): monitor._future_timeout_checker([future]) assert future.ready is False - def test_print_status_log_returns_previous_when_empty(self): + def test_print_status_log_is_silent_without_futures(self, caplog): monitor = _monitor() - assert monitor._print_status_log('prev', 3) == ('prev', 3) + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert caplog.records == [] - def test_print_status_log_none_log_time_is_short_circuited(self): + def test_print_status_log_emits_the_first_snapshot(self, caplog): monitor = _monitor() monitor.add_futures([FakeFuture('M000', invoked=True)]) - # Historical: `log_time > LOG_INTERVAL` is not evaluated when counts change. - counts, log_time = monitor._print_status_log(previous_log=None, log_time=None) - assert counts == (1, 0, 0) - assert log_time == 0 + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert 'Pending: 1' in caplog.text + assert monitor._last_status_counts == (1, 0, 0) - def test_print_status_log_repeats_after_interval(self): + def test_print_status_log_repeats_after_the_interval(self, caplog): monitor = _monitor() monitor.add_futures([FakeFuture('M000', invoked=True)]) - first, _ = monitor._print_status_log(previous_log=None, log_time=0) - same, log_time = monitor._print_status_log(previous_log=first, log_time=0) - assert log_time == 0 - _, log_time = monitor._print_status_log( - previous_log=first, log_time=LOG_INTERVAL + 1 - ) - assert log_time == 0 + monitor._print_status_log() + caplog.clear() + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert caplog.records == [] + + monitor._last_status_log_time -= LOG_INTERVAL + 1 + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert 'Pending: 1' in caplog.text - def test_print_status_log_does_not_repeat_when_all_finished(self, caplog): + def test_print_status_log_throttles_count_changes_until_the_interval( + self, caplog + ): + monitor = _monitor() + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + monitor._print_status_log() + future.invoked = False + future.running = True + caplog.clear() + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert caplog.records == [] + assert monitor._last_status_counts == (0, 1, 0) + + def test_print_status_log_emits_when_the_job_completes(self, caplog): + monitor = _monitor() + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + monitor._print_status_log() + future.invoked = False + future.ready = True + caplog.clear() + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log() + assert 'Done: 1' in caplog.text + + def test_print_status_log_force_emits_a_changed_snapshot(self, caplog): + monitor = _monitor() + future = FakeFuture('M000', invoked=True) + monitor.add_futures([future]) + monitor._print_status_log() + future.invoked = False + future.running = True + caplog.clear() + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log(force=True) + assert 'Running: 1' in caplog.text + + def test_print_status_log_force_keeps_quiet_when_nothing_moved(self, caplog): monitor = _monitor() monitor.add_futures([FakeFuture('M000', invoked=True, ready=True)]) - first, _ = monitor._print_status_log(previous_log=None, log_time=0) + monitor._print_status_log() caplog.clear() - with caplog.at_level(logging.DEBUG, logger='lithops.monitor'): - counts, log_time = monitor._print_status_log( - previous_log=first, log_time=LOG_INTERVAL + 1 - ) - assert counts == first - assert log_time == LOG_INTERVAL + 1 + with caplog.at_level(logging.DEBUG, logger='lithops.monitoring.monitor'): + monitor._print_status_log(force=True) assert caplog.records == [] - def test_check_new_futures_updates_tracking_set(self): + def test_check_new_futures_tracks_and_indexes_the_nested_ones(self): + """ + The nested futures go through add_futures(), so their job id reaches + present_jobs and their call ids reach the index. Adding them straight + to the set left the storage monitor never listing their prefix, and + the message monitors with no way to match their statuses + """ + nested = FakeFuture('A000', call_id='00042', executor_id='sess-0-1') + + class Outer(FakeFuture): + def _set_futures(self, call_status): + self._call_status = call_status + self.ready = True + self._new_futures = [nested] + monitor = _monitor() - future = FakeFuture('M000') + future = Outer('M000') monitor.add_futures([future]) assert monitor._check_new_futures({'type': '__end__'}, future) is False assert monitor._check_new_futures({'new_futures': 'x'}, future) is True - assert 'nested' in monitor.futures + assert nested in monitor.futures + assert 'A000' in monitor.present_jobs + assert monitor.future_by_id(_future_id(nested)) is nested class TestStorageMonitorTokensAndTags: @@ -464,11 +824,11 @@ def test_poll_and_process_returns_new_done_ids_and_tags(self): monitor._generate_tokens = MagicMock() monitor._tag_future_as_running = MagicMock() monitor._tag_future_as_ready = MagicMock() - monitor._print_status_log = MagicMock(return_value=('log', 1)) + monitor._print_status_log = MagicMock() running = {(('sess-0', 'M000', '00000'), 'w1')} done = {('sess-0', 'M000', '00000')} monitor.internal_storage.get_job_status.return_value = (running, done) - new, prev, log_time = monitor._poll_and_process_job_status(None, 0) + 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() @@ -476,8 +836,7 @@ def test_poll_and_process_returns_new_done_ids_and_tags(self): 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) - assert prev == 'log' - assert log_time == 1 + monitor._print_status_log.assert_called_once_with() def test_poll_and_process_emits_token_when_chunk_completes(self): monitor = self._storage() @@ -494,8 +853,8 @@ def test_poll_and_process_emits_token_when_chunk_completes(self): 'type': '__end__', 'activation_id': 'w1', } - monitor._print_status_log = MagicMock(return_value=('log', 1)) - monitor._poll_and_process_job_status(None, 0) + monitor._print_status_log = MagicMock() + monitor._poll_and_process_job_status() assert monitor.token_bucket_q.get_nowait() == '#' assert future0.ready is True assert future1.ready is True @@ -504,23 +863,22 @@ def test_run_sleeps_shorter_when_new_done_then_polls_after_loop(self): monitor = self._storage() polls = [] - def poll(previous_log, log_time): + def poll(): polls.append(1) if len(polls) == 1: - return {('sess-0', 'M000', '00000')}, previous_log, log_time + return {('sess-0', 'M000', '00000')} monitor.should_run = False - return set(), previous_log, log_time + return set() monitor._poll_and_process_job_status = poll sleeps = [] - test_thread = threading.current_thread() def sleep(seconds): - if threading.current_thread() is test_thread: - sleeps.append(seconds) + sleeps.append(seconds) + return monitor.should_run - with patch('lithops.monitor.time.sleep', side_effect=sleep): - monitor.run() + monitor.sleep = sleep + monitor.run() assert sleeps == [0.2] assert len(polls) == 3 @@ -528,23 +886,22 @@ def test_run_skips_sleep_and_swallows_final_poll_errors_after_stop(self): monitor = self._storage() polls = [] - def poll(previous_log, log_time): + def poll(): polls.append(1) monitor.should_run = False if len(polls) > 1: raise RuntimeError('storage gone') - return set(), previous_log, log_time + return set() monitor._poll_and_process_job_status = poll sleeps = [] - test_thread = threading.current_thread() def sleep(seconds): - if threading.current_thread() is test_thread: - sleeps.append(seconds) + sleeps.append(seconds) + return monitor.should_run - with patch('lithops.monitor.time.sleep', side_effect=sleep): - monitor.run() + monitor.sleep = sleep + monitor.run() assert sleeps == [] assert len(polls) == 2 @@ -552,17 +909,23 @@ def sleep(seconds): class TestRabbitmqMonitorTags: def _rabbit(self): - monitor = RabbitmqMonitor.__new__(RabbitmqMonitor) - Monitor.__init__( - monitor, 'sess-0', None, queue.Queue(), {'M000': 1}, True, {} - ) - return monitor + """ + A monitor built through its own __init__, with pika mocked out, so + it has the attributes the class actually relies on + """ + pika = rabbitmq_backend.pika + with patch.object(pika, 'URLParameters'), \ + patch.object(pika, 'BlockingConnection'): + return RabbitmqMonitor( + 'sess-0', None, queue.Queue(), {'M000': 1}, True, + {'amqp_url': 'amqp://guest:guest@localhost:5672'}, + ) def test_the_declared_queue_is_the_one_the_workers_publish_to(self): # The monitor declares and consumes one queue; the workers derive the # names they publish to from the same helper. If these two ever drift # apart, every rabbitmq job hangs without a word - pika = rabbit_monitor_module.pika + pika = rabbitmq_backend.pika with patch.object(pika, 'URLParameters'), \ patch.object(pika, 'BlockingConnection') as connection: monitor = RabbitmqMonitor( @@ -626,40 +989,1560 @@ def test_generate_tokens_waits_for_chunksize_completions(self): monitor._generate_tokens(second) assert monitor.token_bucket_q.get_nowait() == '#' - def test_run_processes_init_and_end_until_all_ready(self): + def _consuming(self, monitor, *payloads): + """ + Points the monitor at a channel whose consume() generator yields + these payloads and then reports the inactivity timeout + """ + channel = MagicMock() + messages = [(MagicMock(), None, p.encode()) for p in payloads] + messages.append((None, None, None)) + channel.consume.return_value = iter(messages) + connection = MagicMock() + connection.is_closed = False + connection.channel.return_value = channel + monitor.connection = connection + monitor.POLL_TIMEOUT = 0.01 + return channel + + def test_a_poll_applies_every_consumed_status(self): monitor = self._rabbit() future = FakeFuture('M000', invoked=True, call_id='00000') monitor.add_futures([future]) - monitor.queue = 'lithops-sess-0' - monitor.should_run = True - monitor._print_status_log = MagicMock(return_value=(None, 0)) + _init, init_raw = _status(kind='__init__') + _end, end_raw = _status(kind='__end__') + channel = self._consuming(monitor, init_raw, end_raw) - channel = MagicMock() - monitor.connection = MagicMock() - monitor.connection.channel.return_value = channel - - def consume(): - callback = channel.basic_consume.call_args[0][1] - init = json.dumps({ - 'type': '__init__', - 'executor_id': 'sess-0', - 'job_id': 'M000', - 'call_id': '00000', - 'activation_id': 'act-1', - }).encode() - end = json.dumps({ - 'type': '__end__', - 'executor_id': 'sess-0', - 'job_id': 'M000', - 'call_id': '00000', - 'activation_id': 'act-1', - 'chunksize': 1, - }).encode() - callback(channel, None, None, init) - callback(channel, None, None, end) - - channel.start_consuming.side_effect = consume - with patch('lithops.monitor.threading.Thread'): - monitor.run() + monitor._poll_once() + + assert future.ready is True + assert channel.consume.call_args.kwargs['inactivity_timeout'] == 0.01 + assert channel.consume.call_args.kwargs['auto_ack'] is True + + def test_a_nested_status_read_early_is_applied_in_the_same_batch(self): + """ + The consumer only returns once the queue has gone quiet, so a held + status has to be applied as each message is handled rather than + after the batch, or it waits a whole inactivity timeout + """ + monitor = self._rabbit() + nested_id = 'sess-0-A000-00000-1' + nested = FakeFuture('M000', running=True, executor_id=nested_id) + + class Outer(FakeFuture): + def _set_futures(self, call_status): + self._call_status = call_status + self.ready = True + self._new_futures = [nested] + + monitor.add_futures([Outer('A000', invoked=True, call_id='00000')]) + + nested_end, _raw = _status(kind='__end__') + nested_end['executor_id'] = nested_id + outer_end, _raw = _status(call_id='00000', kind='__end__') + outer_end['job_id'] = 'A000' + outer_end['new_futures'] = True + + # The nested __end__ is read first, before its future is known + self._consuming( + monitor, json.dumps(nested_end), json.dumps(outer_end) + ) + monitor._poll_once() + + assert nested.ready is True + + def test_stop_closes_the_connection_from_the_monitor_thread(self): + """ + pika's BlockingConnection belongs to one thread, so the close that + unblocks the consumer is handed to it instead of being called here + """ + monitor = self._rabbit() + connection = MagicMock() + monitor.connection = connection + monitor.stop() + assert monitor.should_run is False + connection.add_callback_threadsafe.assert_called_once_with( + connection.close + ) + connection.close.assert_not_called() + + +def _status(call_id='00000', kind='__init__', chunksize=1): + payload = { + 'type': kind, + 'executor_id': 'sess-0', + 'job_id': 'M000', + 'call_id': call_id, + 'activation_id': 'act-1', + 'chunksize': chunksize, + 'worker_start_tstamp': time.time(), + } + return payload, json.dumps(payload) + + +def _run_polling_until_idle(monitor, payloads): + """ + Feeds a polling monitor the given payloads then stops it, so run() + returns without waiting for an external stop() + """ + pending = list(payloads) + + def receive(timeout): + if pending: + yield pending.pop(0) + else: + monitor.should_run = False + + monitor._receive_messages = receive + monitor.run() + + +class TestPollingMessageMonitor: + + def test_run_keeps_going_after_all_ready_until_stop(self): + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + POLL_TIMEOUT = 0.01 + + def _receive_messages(self, timeout): + time.sleep(timeout) + return [] + + monitor = FakePoll( + 'sess-0', None, queue.Queue(), {}, False, {} + ) + future = FakeFuture('M000', invoked=True, ready=True) + monitor.add_futures([future]) + thread = threading.Thread(target=monitor.run) + thread.start() + thread.join(timeout=0.05) + assert thread.is_alive() + monitor.stop() + thread.join(timeout=2) + assert not thread.is_alive() + + def test_stop_does_not_wait_for_a_blocking_read(self): + """ + SQS, Pub/Sub and Azure Queue block in their own read, which nothing + outside the thread can cut short. stop() runs after every wait() + whose futures are all done, so waiting for one there cost a poll + interval per map. cleanup() is what waits, once per executor + """ + class Blocking(PollingMessageMonitor): + backend_name = 'blocking' + POLL_TIMEOUT = 1 + + def _receive_messages(self, timeout): + time.sleep(self.POLL_TIMEOUT) + return [] + + storage = MagicMock() + storage.get_storage_config.return_value = {'monitoring_interval': 2} + job_monitor = JobMonitor('sess-0', storage) + job_monitor.MonitorClass = Blocking + with patch.object(Blocking, 'prepare_config', return_value={}): + job_monitor.prepare() + monitor = job_monitor.monitor + monitor.start() + try: + time.sleep(0.2) + started = time.time() + job_monitor.stop() + assert time.time() - started < 0.5 + assert monitor.should_run is False + finally: + job_monitor.cleanup() + assert not monitor.is_alive() + + def test_an_idle_wait_ends_as_soon_as_the_monitor_is_stopped(self): + """ + Azure Queue does not long poll at all: the loop does the waiting. + Sleeping through it meant the thread outlived stop() by a whole + poll interval, which cleanup() then had to sit through + """ + class NoLongPoll(PollingMessageMonitor): + backend_name = 'no-long-poll' + POLL_TIMEOUT = 30 + + def _receive_messages(self, timeout): + return [] + + monitor = NoLongPoll('sess-0', None, queue.Queue(), {}, False, {}) + thread = threading.Thread(target=monitor.run) + thread.start() + time.sleep(0.2) + started = time.time() + monitor.stop() + thread.join(timeout=5) + assert not thread.is_alive() + assert time.time() - started < 1 + + def test_a_status_arriving_before_its_future_is_not_lost(self): + """ + A nested executor publishes its call statuses to the queue of every + executor up the chain, so they can arrive before the __end__ of the + outer call that tells this monitor those futures exist. A queue read + is destructive, so a status dropped here would hang wait() for ever + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + POLL_TIMEOUT = 0.01 + + def _receive_messages(self, timeout): + return [] + + monitor = FakePoll('sess-0', None, queue.Queue(), {}, False, {}) + nested = FakeFuture( + 'M000', running=True, executor_id='sess-0-A000-00000-1' + ) + # The nested __end__ lands while only the outer future is tracked + payload, _raw = _status(kind='__end__') + payload['executor_id'] = 'sess-0-A000-00000-1' + monitor._apply_status_message(payload) + assert nested.ready is False + + # ...and is applied as soon as the future shows up + monitor.add_futures([nested]) + assert nested.ready is True + + def test_a_held_status_frees_a_worker_token_only_once(self): + """ + A status held back and applied later must be counted for the token + bucket exactly once: counting it on arrival as well would free the + worker before its whole chunk is really done + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + + def _receive_messages(self, timeout): + return [] + + tokens = queue.Queue() + monitor = FakePoll( + 'sess-0', None, tokens, {'M000': 2}, True, {} + ) + payload, _raw = _status(kind='__end__', chunksize=2) + + # Arrives before its future is tracked: held, and no token yet + monitor._apply_status_message(payload) + assert tokens.qsize() == 0 + + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + assert future.ready is True + # One call of a two-call chunk is done, so still no token + assert tokens.qsize() == 0 + + # The second call completes the chunk, and frees exactly one token + second, _raw = _status(call_id='00001', kind='__end__', chunksize=2) + monitor.add_futures([ + FakeFuture('M000', invoked=True, call_id='00001') + ]) + monitor._apply_status_message(second) + assert tokens.qsize() == 1 + + def test_stop_does_not_delete_cleanup_does_once(self): + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + deletes = 0 + + def _receive_messages(self, timeout): + return [] + + def _delete_resources(self): + type(self).deletes += 1 + + monitor = FakePoll( + 'sess-0', None, queue.Queue(), {}, False, {} + ) + monitor.stop() + assert FakePoll.deletes == 0 + monitor.cleanup() + monitor.cleanup() + assert FakePoll.deletes == 1 + + def test_run_paces_a_backend_that_does_not_long_poll(self): + """ + Azure Queue Storage returns right away on an empty queue, so the + loop has to do the waiting itself instead of spinning on it + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + POLL_TIMEOUT = 0.2 + polls = 0 + + def _receive_messages(self, timeout): + type(self).polls += 1 + return [] + + monitor = FakePoll('sess-0', None, queue.Queue(), {}, False, {}) + thread = threading.Thread(target=monitor.run) + thread.start() + time.sleep(0.5) + monitor.stop() + thread.join(timeout=2) + assert not thread.is_alive() + assert FakePoll.polls <= 4 + + def test_run_survives_a_failing_poll(self): + """ + A poll that raises must not take the thread down: nothing else + moves the futures along, so wait() would block for ever + """ + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + POLL_TIMEOUT = 0.01 + polls = 0 + + def _receive_messages(self, timeout): + type(self).polls += 1 + if type(self).polls == 1: + raise ConnectionError('transient') + _payload, raw = _status(kind='__end__') + yield raw + + monitor = FakePoll('sess-0', None, queue.Queue(), {}, False, {}) + future = FakeFuture('M000', invoked=True, running=True) + monitor.add_futures([future]) + thread = threading.Thread(target=monitor.run) + thread.start() + for _ in range(200): + if future.ready: + break + time.sleep(0.01) + assert thread.is_alive() + assert future.ready is True + monitor.stop() + thread.join(timeout=2) + + +class TestMessageLossAndRecovery: + """ + RabbitMQ acknowledges on delivery and a Redis BLPOP removes the entry, + so those two deliver a status at most once. Anything that drops a + message between the read and the future is a call that never finishes + """ + + class FakePoll(PollingMessageMonitor): + backend_name = 'fake' + POLL_TIMEOUT = 0.01 + STORAGE_SWEEP_INTERVAL = 0 + + def _receive_messages(self, timeout): + return [] + + def _monitor(self, storage=None, tokens=None, chunksize=None): + return self.FakePoll( + 'sess-0', storage, tokens or queue.Queue(), + chunksize or {}, chunksize is not None, {}, + ) + + def test_applying_a_status_does_not_iterate_the_futures_set(self): + """ + Guards the cause, which a race is too narrow to provoke on demand. + + Tagging used to scan the futures set, and the threads that submit + jobs grow that very set. "Set changed size during iteration" + surfaced in the poll loop as a logged error, and the message it was + carrying was already off the queue: the call then stayed running + until its execution timeout, or for ever. Tagging is a lookup in an + index kept beside the set now, so there is no iteration left to + interrupt + """ + class NeverIterated(set): + def __iter__(self): + raise AssertionError('the futures set was iterated') + + monitor = self._monitor() + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + with monitor._futures_lock: + monitor.futures = NeverIterated(set(monitor.futures)) + + init, _raw = _status(kind='__init__') + monitor._apply_status_message(init) + assert future.running is True + end, _raw = _status(kind='__end__') + monitor._apply_status_message(end) assert future.ready is True - channel.stop_consuming.assert_called() + + def test_applying_statuses_while_futures_are_added_loses_nothing(self): + """ + Pins the result the invariant above buys: every status finds its + future, and none is left held, while another thread keeps adding + """ + monitor = self._monitor() + tracked = [ + FakeFuture('M000', invoked=True, call_id=f'{i:05d}') + for i in range(300) + ] + monitor.add_futures(tracked) + + errors = [] + applied = threading.Event() + + def apply_statuses(): + try: + for future in tracked: + payload, _raw = _status( + call_id=future.call_id, kind='__end__' + ) + monitor._apply_status_message(payload) + except Exception as exc: # noqa: BLE001 - recorded, not handled + errors.append(exc) + finally: + applied.set() + + thread = threading.Thread(target=apply_statuses) + thread.start() + for i in range(300, 2000): + monitor.add_futures([FakeFuture('M001', call_id=f'{i:05d}')]) + applied.wait(timeout=10) + thread.join(timeout=5) + + assert not errors + assert all(f.ready for f in tracked) + assert not monitor._held_status + + def test_a_redelivered_end_frees_one_token_not_two(self): + """ + SQS, Pub/Sub and Azure Queue redeliver a message whose status was + applied but whose delete or ack did not go through. Counting the + same call twice would free the worker before its chunk is done + """ + 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'), + ]) + + first, _raw = _status(call_id='00000', kind='__end__', chunksize=2) + monitor._apply_status_message(first) + monitor._apply_status_message(dict(first)) + assert tokens.qsize() == 0 + + second, _raw = _status(call_id='00001', kind='__end__', chunksize=2) + monitor._apply_status_message(second) + assert tokens.qsize() == 1 + monitor._apply_status_message(dict(second)) + assert tokens.qsize() == 1 + + 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 + back, because tagging reported "no match" for a future it had in + fact found. Held statuses of futures that never come back are a leak + """ + monitor = self._monitor() + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + payload, _raw = _status(kind='__init__') + monitor._apply_status_message(payload) + monitor._apply_status_message(dict(payload)) + assert future.running is True + assert monitor._held_status == {} + + def test_held_statuses_do_not_grow_without_bound(self): + monitor = self._monitor() + monitor.MAX_HELD_STATUS = 10 + for i in range(50): + payload, _raw = _status(call_id=f'{i:05d}', kind='__end__') + monitor._apply_status_message(payload) + assert len(monitor._held_status) == 10 + # The newest are the ones kept + assert ('sess-0', 'M000', '00049') in monitor._held_status + + def test_the_storage_sweep_recovers_a_lost_end(self): + """ + The worker writes every __end__ to the storage as well. Without + reading it back, a lost message shows up as an execution timeout for + a call that in fact succeeded + """ + storage = MagicMock() + monitor = self._monitor(storage=storage) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + + done = {('sess-0', 'M000', '00000')} + storage.get_job_status.return_value = (set(), done) + storage.get_call_status.return_value = { + 'type': '__end__', 'activation_id': 'act-1', 'chunksize': 1, + } + + monitor._storage_sweep() + + assert future.ready is True + storage.get_job_status.assert_called_once_with( + 'sess-0', job_ids={'M000'} + ) + storage.get_call_status.assert_called_once_with( + 'sess-0', 'M000', '00000' + ) + + def test_the_storage_sweep_leaves_a_call_that_is_still_running(self): + storage = MagicMock() + monitor = self._monitor(storage=storage) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + storage.get_job_status.return_value = (set(), set()) + + monitor._storage_sweep() + + assert future.ready is False + storage.get_call_status.assert_not_called() + + def test_the_storage_sweep_recovers_a_call_that_never_reported_running(self): + """ + Losing both statuses of a call is what hangs wait() for ever: the + timeout checker only looks at futures it saw start + """ + storage = MagicMock() + monitor = self._monitor(storage=storage) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + monitor._future_timeout_checker() + assert future.ready is False + + storage.get_job_status.return_value = ( + set(), {('sess-0', 'M000', '00000')} + ) + storage.get_call_status.return_value = {'type': '__end__'} + monitor._storage_sweep() + assert future.ready is True + + def test_the_sweep_only_looks_once_the_channel_has_gone_quiet(self): + """ + A channel that is delivering has nothing for the sweep to recover, + and a sweep lists every status key of every live job: on a large map + that is a page of listing per thousand calls, every interval + """ + storage = MagicMock() + storage.get_job_status.return_value = (set(), set()) + monitor = self._monitor(storage=storage) + monitor.STORAGE_SWEEP_INTERVAL = 30 + monitor._sweep_interval = 30 + monitor.add_futures([FakeFuture('M000', invoked=True)]) + + # A status just arrived, so there is nothing to look for + monitor._last_message_tstamp = time.time() + monitor._sweep_storage(time.time() - 3600) + storage.get_job_status.assert_not_called() + + # ...and the channel then goes quiet + monitor._last_message_tstamp = time.time() - 31 + monitor._sweep_storage(time.time() - 3600) + storage.get_job_status.assert_called_once() + + def test_applying_a_status_counts_as_the_channel_being_alive(self): + monitor = self._monitor() + monitor._last_message_tstamp = 0 + monitor.add_futures([ + FakeFuture('M000', invoked=True, call_id='00000') + ]) + payload, _raw = _status(kind='__init__') + monitor._apply_status_message(payload) + assert monitor._last_message_tstamp > 0 + + def test_a_sweep_that_finds_nothing_backs_off(self): + """ + A long-running job is quiet by nature, and sweeping it every minute + costs a full listing each time for nothing + """ + storage = MagicMock() + storage.get_job_status.return_value = (set(), set()) + monitor = self._monitor(storage=storage) + monitor.STORAGE_SWEEP_INTERVAL = 10 + monitor.MAX_SWEEP_INTERVAL = 40 + monitor._sweep_interval = 10 + monitor.add_futures([FakeFuture('M000', invoked=True)]) + + intervals = [] + for _ in range(5): + monitor._last_message_tstamp = 0 + monitor._sweep_storage(0) + intervals.append(monitor._sweep_interval) + assert intervals == [20, 40, 40, 40, 40] + + def test_a_sweep_that_recovers_something_goes_back_to_the_base_interval(self): + storage = MagicMock() + monitor = self._monitor(storage=storage) + monitor.STORAGE_SWEEP_INTERVAL = 10 + monitor._sweep_interval = 80 + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + storage.get_job_status.return_value = ( + set(), {('sess-0', 'M000', '00000')} + ) + storage.get_call_status.return_value = {'type': '__end__'} + + monitor._last_message_tstamp = 0 + monitor._sweep_storage(0) + + assert future.ready is True + assert monitor._sweep_interval == 10 + + def test_a_failing_sweep_does_not_take_the_monitor_down(self): + storage = MagicMock() + storage.get_job_status.side_effect = RuntimeError('storage gone') + monitor = self._monitor(storage=storage) + monitor.STORAGE_SWEEP_INTERVAL = 1 + monitor.add_futures([FakeFuture('M000', invoked=True)]) + assert monitor._sweep_storage(0) > 0 + + +class TestBackendContract: + """ + "Adding a backend is adding a package" only holds if a package that + does not hold up its end says so, instead of quietly monitoring nothing + """ + + def _in_backends(self, name='fake'): + return {'__module__': f'lithops.monitoring.backends.{name}.{name}'} + + def test_backend_name_comes_from_the_package(self): + cls = type('Good', (PollingMessageMonitor,), dict( + self._in_backends(), + _receive_messages=lambda self, timeout: iter(()), + )) + assert cls.backend_name == 'fake' + + def test_a_backend_name_that_disagrees_is_rejected(self): + with pytest.raises(TypeError, match='backend package'): + type('Drifted', (Monitor,), dict( + self._in_backends(), + backend_name='something-else', + run=lambda self: None, + )) + + def test_a_backend_that_consumes_nothing_is_rejected(self): + with pytest.raises(TypeError, match='neither run'): + type('Empty', (Monitor,), dict(self._in_backends())) + + def test_a_helper_class_can_opt_out(self): + cls = type('Helper', (Monitor,), dict(self._in_backends()), + abstract=True) + assert cls.backend_name is None + + def test_classes_outside_the_backends_package_are_left_alone(self): + cls = type('Local', (Monitor,), {'__module__': 'somewhere.else'}) + assert cls.backend_name is None + + def test_exports_are_checked_against_the_base_classes(self): + from lithops.monitoring.backends import load_backend_attr + module = MagicMock() + module.MonitoringBackend = 'not a class' + with patch( + 'lithops.monitoring.backends.importlib.import_module', + return_value=module, + ): + with pytest.raises(ValueError, match='not a Monitor subclass'): + load_backend_attr('fake', 'MonitoringBackend') + + def test_a_missing_export_is_reported(self): + from lithops.monitoring.backends import load_backend_attr + module = SimpleNamespace() + with patch( + 'lithops.monitoring.backends.importlib.import_module', + return_value=module, + ): + with pytest.raises(ValueError, match='exports no CallStatus'): + load_backend_attr('fake', 'CallStatus') + + def test_every_built_in_backend_holds_up_its_end(self): + from lithops.monitoring.backends import load_backend_attr + from lithops.monitoring.status import CallStatus + for name in ( + 'storage', 'rabbitmq', 'redis', + 'aws_sqs', 'gcp_pubsub', 'azure_queue', + ): + backend = load_backend_attr(name, 'MonitoringBackend') + status = load_backend_attr(name, 'CallStatus') + assert backend.backend_name == name + assert issubclass(backend, Monitor) + assert issubclass(status, CallStatus) + + def test_the_client_and_the_worker_resolve_the_same_backend(self): + """ + create_call_status() used to read the key straight out of the config + while the client fell back to storage, so a config with no + 'monitoring' key had the worker raise instead of reporting + """ + for config in ( + None, {}, {'lithops': {}}, {'lithops': {'monitoring': None}}, + ): + assert resolve_backend(config) == 'storage' + assert resolve_backend({'lithops': {'monitoring': 'RabbitMQ'}}) \ + == 'rabbitmq' + assert resolve_backend({'lithops': {'monitoring': 'redis'}}, 'STORAGE') \ + == 'storage' + + +class TestCallStatusPublishing: + + @pytest.fixture(autouse=True) + def _no_clients_left_over(self): + """ + The clients are kept for the process, so one test would otherwise + hand its client to the next + """ + from lithops.monitoring.status import close_shared_clients + close_shared_clients() + yield + close_shared_clients() + + def _job(self, backend='redis'): + return SimpleNamespace( + config={'lithops': {'monitoring': backend}, backend: {}}, + start_tstamp=0, + host_submit_tstamp=0, + call_id='00000', + job_id='M000', + executor_id='sess-0', + chunksize=1, + monitoring_queues=['lithops-sess-0'], + ) + + def _status_cls(self, publish): + from lithops.monitoring.status import MessageCallStatus + + class Fake(MessageCallStatus): + service_name = 'fake' + RETRY_SLEEP = 0 + closed = 0 + + def _publish(self, payload): + publish(payload) + + def close(self): + type(self).closed += 1 + + return Fake + + def _plain_status_cls(self, publish=lambda payload: None): + """The same, but keeping the real close() so it can be exercised""" + from lithops.monitoring.status import MessageCallStatus + + class Plain(MessageCallStatus): + service_name = 'plain' + RETRY_SLEEP = 0 + + def _publish(self, payload): + publish(payload) + + return Plain + + def test_a_publish_that_keeps_failing_still_writes_to_the_storage(self): + cls = self._status_cls( + lambda payload: (_ for _ in ()).throw(ConnectionError('down')) + ) + storage = MagicMock() + status = cls(self._job(), storage) + status.send_finish_event() + # The client reads this back through MessageMonitor._storage_sweep() + assert storage.put_data.call_count == 1 + + def test_the_attempts_are_backed_off(self): + attempts = [] + cls = self._status_cls( + lambda payload: (_ for _ in ()).throw(ConnectionError('down')) + ) + cls.RETRY_SLEEP = 0.2 + cls.MAX_RETRY_SLEEP = 1 + status = cls(self._job(), MagicMock()) + with patch( + 'lithops.monitoring.status.time.sleep', side_effect=attempts.append + ): + status.send_init_event() + assert attempts == [0.2, 0.4, 0.8, 1] + + def test_the_client_is_released_after_the_last_status(self): + cls = self._status_cls(lambda payload: None) + status = cls(self._job(), MagicMock()) + status.send_init_event() + assert cls.closed == 0 + status.send_finish_event() + assert cls.closed == 1 + + def test_the_client_is_released_even_when_the_last_status_fails(self): + cls = self._status_cls( + lambda payload: (_ for _ in ()).throw(ConnectionError('down')) + ) + cls.RETRY_SLEEP = 0 + storage = MagicMock() + storage.put_data.side_effect = RuntimeError('storage gone') + status = cls(self._job(), storage) + with pytest.raises(RuntimeError): + status.send_finish_event() + assert cls.closed == 1 + + def test_every_backend_keeps_one_client_for_the_process(self): + """ + A warm container runs one call after another, each building its own + call status. Opening a connection per call costs far more than the + publish it carries, so the client is kept and released at exit + """ + from lithops.monitoring.status import ( + _SHARED_CLIENTS, close_shared_clients, + ) + from lithops.monitoring.backends.redis.status import RedisCallStatus + from lithops.monitoring.backends.aws_sqs.status import SqsCallStatus + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + from lithops.monitoring.backends.gcp_pubsub.status import ( + GcpPubsubCallStatus, + ) + + cases = [ + (RedisCallStatus, 'redis', redis_backend, 'redis_client', + 'client'), + (SqsCallStatus, 'aws_sqs', sqs_backend, 'sqs_client', 'client'), + (AzureQueueCallStatus, 'azure_queue', azure_backend, + 'queue_service', 'service'), + (GcpPubsubCallStatus, 'gcp_pubsub', pubsub_backend, + 'pubsub_clients', 'publisher'), + ] + for cls, name, module, factory, attr in cases: + close_shared_clients() + built = MagicMock() + value = (built, MagicMock()) if factory == 'pubsub_clients' \ + else built + with patch.object(module, factory, return_value=value) as build: + for _ in range(3): + status = cls(self._job(name), MagicMock()) + getattr(status, attr) + status.send_finish_event() + assert build.call_count == 1, name + assert built.close.called is False, name + assert _SHARED_CLIENTS, name + close_shared_clients() + assert built.close.called or built.stop.called, name + + def test_reuse_can_be_turned_off(self): + """ + The escape hatch for a runtime where a client that outlives the call + does not survive the fork of the next one + """ + from lithops.monitoring.status import ( + REUSE_CLIENTS_ENV, _SHARED_CLIENTS, + ) + + cls = self._plain_status_cls() + clients = [] + with patch.dict('os.environ', {REUSE_CLIENTS_ENV: '0'}): + for _ in range(3): + status = cls(self._job(), MagicMock()) + client = MagicMock() + clients.append(client) + status.__dict__['client'] = status.obtain_client( + 'client', lambda c=client: c + ) + status.send_finish_event() + + assert len(clients) == 3 + assert not _SHARED_CLIENTS + for client in clients: + client.close.assert_called_once() + + def test_one_client_serves_every_call_of_the_process(self): + """ + A worker runs the calls of its chunk one after another + """ + cls = self._plain_status_cls() + built = [] + for _ in range(5): + status = cls(self._job(), MagicMock()) + status.obtain_client('client', lambda: built.append(1) or 'c') + status.send_finish_event() + assert len(built) == 1 + + def test_a_shared_client_is_not_closed_with_the_call(self): + from lithops.monitoring.status import close_shared_clients + + client = MagicMock() + cls = self._plain_status_cls() + status = cls(self._job(), MagicMock()) + status.__dict__['client'] = status.obtain_client( + 'client', lambda: client + ) + status.send_finish_event() + client.close.assert_not_called() + close_shared_clients() + client.close.assert_called_once() + + def test_two_brokers_do_not_share_a_client(self): + """ + The settings are part of what makes a client shareable: a process + reporting to two brokers must not publish to one through the other + """ + cls = self._plain_status_cls() + first = cls(self._job(), MagicMock()) + first.config['redis'] = {'host': 'one'} + second = cls(self._job(), MagicMock()) + second.config['redis'] = {'host': 'two'} + a = first.obtain_client('client', MagicMock) + b = second.obtain_client('client', MagicMock) + assert a is not b + + def test_a_client_that_failed_is_not_handed_to_the_next_call(self): + cls = self._plain_status_cls() + status = cls(self._job(), MagicMock()) + first = status.obtain_client('client', MagicMock) + status.discard_client('client') + second = cls(self._job(), MagicMock()).obtain_client( + 'client', MagicMock + ) + assert second is not first + + def test_rabbitmq_replaces_a_connection_that_died(self): + """ + The broker drops a connection idle past the heartbeat, and a long + function is exactly that. A shared one must be replaced, not reused + """ + from lithops.monitoring.backends.rabbitmq.status import ( + RabbitmqCallStatus, + ) + + job = self._job('rabbitmq') + job.config['rabbitmq'] = {'amqp_url': 'amqp://guest@localhost'} + dead_conn, dead_ch = MagicMock(), MagicMock() + dead_conn.is_open = False + live_conn, live_ch = MagicMock(), MagicMock() + live_conn.is_open = live_ch.is_open = True + + status = RabbitmqCallStatus(job, MagicMock()) + status.obtain_client('_amqp', lambda: (dead_conn, dead_ch)) + with patch.object( + status, '_connect', return_value=(live_conn, live_ch) + ): + assert status._channel() is live_ch + + # ...and the replacement is what the next call gets + nxt = RabbitmqCallStatus(job, MagicMock()) + assert nxt.obtain_client('_amqp', MagicMock) == (live_conn, live_ch) + + def test_releasing_a_client_that_was_never_built_builds_nothing(self): + from lithops.monitoring.backends.redis.status import RedisCallStatus + + with patch.object(redis_backend, 'redis_client') as build: + status = RedisCallStatus(self._job(), MagicMock()) + status.close() + build.assert_not_called() + + def test_no_client_is_built_before_the_first_status(self): + """ + The worker builds the call status and then forks the JobRunner off. + A network client that already exists at that point is what the + fork() safety check of the Apple frameworks aborts the child over + """ + from lithops.monitoring.backends.redis.status import RedisCallStatus + from lithops.monitoring.backends.aws_sqs.status import SqsCallStatus + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + from lithops.monitoring.backends.gcp_pubsub.status import ( + GcpPubsubCallStatus, + ) + + cases = [ + (RedisCallStatus, 'redis', redis_backend, 'redis_client'), + (SqsCallStatus, 'aws_sqs', sqs_backend, 'sqs_client'), + (AzureQueueCallStatus, 'azure_queue', azure_backend, + 'queue_service'), + (GcpPubsubCallStatus, 'gcp_pubsub', pubsub_backend, + 'pubsub_clients'), + ] + for cls, name, module, factory in cases: + with patch.object(module, factory) as build: + cls(self._job(name), MagicMock()) + assert build.call_count == 0, name + + +class TestRedisMonitor: + + def _redis(self, client): + from lithops.monitoring.backends.redis import RedisMonitor + with _client(redis_backend, 'redis_client', client): + return RedisMonitor( + 'sess-0', None, queue.Queue(), {'M000': 1}, True, {}, + ) + + def test_the_list_is_the_one_the_workers_publish_to(self): + from lithops.tests.mp_fakeredis import FakeRedis + monitor = self._redis(FakeRedis()) + assert monitor.queue == monitoring_queue_name('sess-0') + assert monitoring_queues('sess-0') == [monitor.queue] + + def test_run_processes_init_and_end(self): + from lithops.tests.mp_fakeredis import FakeRedis + client = FakeRedis() + monitor = self._redis(client) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + _, init_body = _status(kind='__init__') + _, end_body = _status(kind='__end__') + _run_polling_until_idle(monitor, [init_body, end_body]) + assert future.ready is True + + def test_stop_keeps_the_list_cleanup_deletes_it(self): + from lithops.tests.mp_fakeredis import FakeRedis + client = FakeRedis() + monitor = self._redis(client) + client.rpush(monitor.queue, b'leftover') + monitor.stop() + assert client.llen(monitor.queue) == 1 + monitor.cleanup() + assert client.llen(monitor.queue) == 0 + monitor.cleanup() + assert client.llen(monitor.queue) == 0 + + def test_call_status_publishes_to_every_queue_in_the_chain(self): + from lithops.monitoring.backends.redis.status import RedisCallStatus + from lithops.tests.mp_fakeredis import FakeRedis + client = FakeRedis() + job = SimpleNamespace( + config={'lithops': {'monitoring': 'redis'}, 'redis': {}}, + start_tstamp=0, + host_submit_tstamp=0, + call_id='00000', + job_id='M000', + executor_id='sess-0', + chunksize=1, + monitoring_queues=['lithops-parent', 'lithops-sess-0'], + ) + with _client(redis_backend, 'redis_client', client): + status = RedisCallStatus(job, MagicMock()) + status.status['type'] = '__init__' + status._publish('{"type": "__init__"}') + assert client.llen('lithops-parent') == 1 + assert client.llen('lithops-sess-0') == 1 + + def test_only_the_keys_redis_accepts_reach_the_client(self): + """ + The 'redis' section is shared with the storage, multiprocessing and + joblib backends, which put keys of their own in it. redis.Redis() + raises TypeError on any it does not know, so the section is filtered + by what the constructor takes rather than by a list of exclusions + """ + from lithops.monitoring.backends.redis.redis import _redis_params + params = _redis_params({ + 'host': 'localhost', + 'port': 6379, + 'password': 'secret', + 'storage_bucket': 'storage', + 'user_agent': 'lithops', + 'some_backend_key': 'value', + }) + assert params == { + 'host': 'localhost', 'port': 6379, 'password': 'secret' + } + + def test_a_blocking_read_takes_the_rest_of_the_batch_with_it(self): + """ + BLPOP hands over one status at a time. Draining what is already on + the list in the same round trip is what keeps a map of n calls from + costing n round trips, and n sweeps of the futures, to monitor + """ + from lithops.tests.mp_fakeredis import FakeRedis + client = FakeRedis() + monitor = self._redis(client) + for i in range(5): + _payload, raw = _status(call_id=f'{i:05d}', kind='__end__') + client.rpush(monitor.queue, raw.encode()) + + received = list(monitor._receive_messages(1)) + + assert len(received) == 5 + assert client.llen(monitor.queue) == 0 + + def test_the_batch_comes_off_the_list_in_one_lpop(self): + """ + LPOP takes a count from Redis 6.2 on, and returns only what is + there, so a thousand statuses cost the same round trip as one. Over + a network the round trips are the whole cost of monitoring a map + """ + client = MagicMock() + _payload, raw = _status(kind='__end__') + client.blpop.return_value = (b'q', raw.encode()) + client.lpop.return_value = [raw.encode()] * 4 + monitor = self._redis(client) + + received = list(monitor._receive_messages(1)) + + assert len(received) == 5 + client.lpop.assert_called_once_with( + monitor.queue, monitor.BATCH_SIZE - 1 + ) + client.pipeline.assert_not_called() + + def test_a_redis_older_than_6_2_falls_back_to_a_pipeline(self): + client = MagicMock() + _payload, raw = _status(kind='__end__') + client.blpop.return_value = (b'q', raw.encode()) + client.lpop.side_effect = TypeError('lpop() takes 2 arguments') + pipe = client.pipeline.return_value + pipe.execute.return_value = [raw.encode(), None] + monitor = self._redis(client) + + received = list(monitor._receive_messages(1)) + + assert len(received) == 2 + assert monitor._lpop_count is False + client.pipeline.assert_called_once() + + def test_a_client_that_cannot_pipeline_falls_back_to_one_at_a_time(self): + from lithops.tests.mp_fakeredis import FakeRedis + client = FakeRedis() + monitor = self._redis(client) + _payload, raw = _status(kind='__end__') + client.rpush(monitor.queue, raw.encode()) + with patch.object( + monitor.client, 'pipeline', side_effect=AttributeError('no') + ): + received = list(monitor._receive_messages(1)) + assert received == [raw] + assert monitor._can_batch is False + + def test_stop_drops_the_connections_under_the_blocking_read(self): + """ + stop() runs after every wait() that finds its futures done, not only + at shutdown. Leaving the BLPOP to reach its own timeout costs a + second or two every time, which is most of a test run + """ + client = MagicMock() + monitor = self._redis(client) + monitor.stop() + assert monitor.should_run is False + client.connection_pool.disconnect.assert_called_once() + monitor._close_receiver() + client.close.assert_called_once() + + def test_the_monitor_does_not_share_its_client(self): + """ + stop() tears the pool down, so the client has to be this monitor's + own: the redis section is shared with the storage, multiprocessing + and joblib backends, and taking their connections with it would + break them + """ + import redis as redis_sdk + from lithops.monitoring.backends.redis.redis import redis_client + first = redis_client({'host': 'localhost'}) + second = redis_client({'host': 'localhost'}) + assert isinstance(first, redis_sdk.Redis) + assert first is not second + assert first.connection_pool is not second.connection_pool + + def test_a_stopped_monitor_still_deletes_its_list(self): + """ + cleanup() runs after stop(), so it talks to a pool that was just + disconnected. redis-py opens a connection again by itself + """ + client = MagicMock() + monitor = self._redis(client) + monitor.stop() + monitor.cleanup() + client.delete.assert_called_once_with(monitor.queue) + + +class TestSqsMonitor: + + def _sqs(self, client): + from lithops.monitoring.backends.aws_sqs import SqsMonitor + client.create_queue.return_value = {'QueueUrl': 'https://sqs/lithops-sess-0'} + with _client(sqs_backend, 'sqs_client', client): + return SqsMonitor( + 'sess-0', None, queue.Queue(), {'M000': 1}, True, + {'region': 'us-east-1'}, + ) + + def test_the_created_queue_is_the_one_the_workers_publish_to(self): + client = MagicMock() + monitor = self._sqs(client) + assert monitor.queue == monitoring_queue_name('sess-0') + client.create_queue.assert_called_once_with(QueueName='lithops-sess-0') + assert monitor.queue_url == 'https://sqs/lithops-sess-0' + + def test_run_processes_init_and_end_and_deletes_messages(self): + client = MagicMock() + monitor = self._sqs(client) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + _, init_body = _status(kind='__init__') + _, end_body = _status(kind='__end__') + client.receive_message.side_effect = [ + {'Messages': [ + {'Body': init_body, 'ReceiptHandle': 'h1'}, + {'Body': end_body, 'ReceiptHandle': 'h2'}, + ]}, + {'Messages': []}, + ] + orig = monitor._receive_messages + + def receive(timeout): + items = list(orig(timeout)) + for item in items: + yield item + if not items: + monitor.should_run = False + + monitor._receive_messages = receive + monitor.run() + assert future.ready is True + deleted = [c.kwargs['ReceiptHandle'] for c in client.delete_message.call_args_list] + assert deleted == ['h1', 'h2'] + + def test_stop_keeps_the_queue_cleanup_deletes_it(self): + client = MagicMock() + monitor = self._sqs(client) + monitor.stop() + client.delete_queue.assert_not_called() + assert monitor.queue_url == 'https://sqs/lithops-sess-0' + monitor.cleanup() + client.delete_queue.assert_called_once_with( + QueueUrl='https://sqs/lithops-sess-0' + ) + assert monitor.queue_url is None + + def test_call_status_sends_to_every_queue_in_the_chain(self): + from lithops.monitoring.backends.aws_sqs.status import SqsCallStatus + client = MagicMock() + client.get_queue_url.side_effect = [ + {'QueueUrl': 'https://sqs/parent'}, + {'QueueUrl': 'https://sqs/own'}, + ] + job = SimpleNamespace( + config={'lithops': {'monitoring': 'aws_sqs'}, 'aws_sqs': {}}, + start_tstamp=0, + host_submit_tstamp=0, + call_id='00000', + job_id='M000', + executor_id='sess-0', + chunksize=1, + monitoring_queues=['lithops-parent', 'lithops-sess-0'], + ) + with _client(sqs_backend, 'sqs_client', client): + status = SqsCallStatus(job, MagicMock()) + status._publish('{"type": "__init__"}') + urls = [c.kwargs['QueueUrl'] for c in client.send_message.call_args_list] + assert urls == ['https://sqs/parent', 'https://sqs/own'] + + +class TestGcpPubsubMonitor: + + def _monitor(self, publisher, subscriber): + from lithops.monitoring.backends.gcp_pubsub import GcpPubsubMonitor + with patch.object( + pubsub_backend, 'pubsub_clients', + return_value=(publisher, subscriber), + ): + return GcpPubsubMonitor( + 'sess-0', None, queue.Queue(), {'M000': 1}, True, + {'project_name': 'proj'}, + ) + + def test_the_created_topic_is_the_one_the_workers_publish_to(self): + publisher = MagicMock() + subscriber = MagicMock() + monitor = self._monitor(publisher, subscriber) + assert monitor.queue == monitoring_queue_name('sess-0') + publisher.create_topic.assert_called_once_with( + name='projects/proj/topics/lithops-sess-0' + ) + subscriber.create_subscription.assert_called_once_with( + name='projects/proj/subscriptions/lithops-sess-0', + topic='projects/proj/topics/lithops-sess-0', + ack_deadline_seconds=30, + ) + + def test_run_processes_init_and_end_and_acks_messages(self): + publisher = MagicMock() + subscriber = MagicMock() + monitor = self._monitor(publisher, subscriber) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + _, init_body = _status(kind='__init__') + _, end_body = _status(kind='__end__') + + def _msg(body, ack_id): + item = MagicMock() + item.ack_id = ack_id + item.message.data = body.encode('utf-8') + return item + + first = MagicMock() + first.received_messages = [_msg(init_body, 'a1'), _msg(end_body, 'a2')] + empty = MagicMock() + empty.received_messages = [] + subscriber.pull.side_effect = [first, empty] + orig = monitor._receive_messages + + def receive(timeout): + items = list(orig(timeout)) + for item in items: + yield item + if not items: + monitor.should_run = False + + monitor._receive_messages = receive + monitor.run() + assert future.ready is True + subscriber.acknowledge.assert_called_once_with( + subscription='projects/proj/subscriptions/lithops-sess-0', + ack_ids=['a1', 'a2'], + ) + + def test_stop_keeps_the_topic_cleanup_deletes_it(self): + publisher = MagicMock() + subscriber = MagicMock() + monitor = self._monitor(publisher, subscriber) + monitor.stop() + publisher.delete_topic.assert_not_called() + subscriber.delete_subscription.assert_not_called() + monitor.cleanup() + subscriber.delete_subscription.assert_called_once_with( + subscription='projects/proj/subscriptions/lithops-sess-0' + ) + publisher.delete_topic.assert_called_once_with( + topic='projects/proj/topics/lithops-sess-0' + ) + assert monitor.topic_path is None + assert monitor.subscription_path is None + + def test_call_status_publishes_to_every_topic_in_the_chain(self): + from lithops.monitoring.backends.gcp_pubsub.status import GcpPubsubCallStatus + publisher = MagicMock() + job = SimpleNamespace( + config={ + 'lithops': {'monitoring': 'gcp_pubsub'}, + 'gcp_pubsub': {'project_name': 'proj'}, + }, + start_tstamp=0, + host_submit_tstamp=0, + call_id='00000', + job_id='M000', + executor_id='sess-0', + chunksize=1, + monitoring_queues=['lithops-parent', 'lithops-sess-0'], + ) + with patch.object( + pubsub_backend, 'pubsub_clients', + return_value=(publisher, MagicMock()), + ): + status = GcpPubsubCallStatus(job, MagicMock()) + status._publish('{"type": "__init__"}') + 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__"}' + + +class TestAzureQueueMonitor: + + def _monitor(self, service): + from lithops.monitoring.backends.azure_queue import AzureQueueMonitor + queue_client = MagicMock() + service.create_queue.return_value = queue_client + with _client(azure_backend, 'queue_service', service): + monitor = AzureQueueMonitor( + 'sess-0', None, queue.Queue(), {'M000': 1}, True, {}, + ) + return monitor, queue_client + + def test_the_created_queue_is_the_one_the_workers_publish_to(self): + service = MagicMock() + monitor, _queue_client = self._monitor(service) + assert monitor.queue == monitoring_queue_name('sess-0') + service.create_queue.assert_called_once_with('lithops-sess-0') + + def test_run_processes_init_and_end_and_deletes_messages(self): + service = MagicMock() + monitor, queue_client = self._monitor(service) + future = FakeFuture('M000', invoked=True, call_id='00000') + monitor.add_futures([future]) + _, init_body = _status(kind='__init__') + _, end_body = _status(kind='__end__') + + def _msg(body): + item = MagicMock() + item.content = body + return item + + queue_client.receive_messages.side_effect = [ + [_msg(init_body), _msg(end_body)], + [], + ] + orig = monitor._receive_messages + + def receive(timeout): + items = list(orig(timeout)) + for item in items: + yield item + if not items: + monitor.should_run = False + + monitor._receive_messages = receive + monitor.run() + assert future.ready is True + assert queue_client.delete_message.call_count == 2 + + def test_stop_keeps_the_queue_cleanup_deletes_it(self): + service = MagicMock() + monitor, _queue_client = self._monitor(service) + monitor.stop() + service.delete_queue.assert_not_called() + monitor.cleanup() + service.delete_queue.assert_called_once_with('lithops-sess-0') + assert monitor.queue_client is None + + def test_call_status_sends_to_every_queue_in_the_chain(self): + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + parent = MagicMock() + own = MagicMock() + service = MagicMock() + service.get_queue_client.side_effect = lambda name: { + 'lithops-parent': parent, + 'lithops-sess-0': own, + }[name] + job = SimpleNamespace( + config={'lithops': {'monitoring': 'azure_queue'}, 'azure_queue': {}}, + start_tstamp=0, + host_submit_tstamp=0, + call_id='00000', + job_id='M000', + executor_id='sess-0', + chunksize=1, + monitoring_queues=['lithops-parent', 'lithops-sess-0'], + ) + 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__"}') + + +class TestAzureQueueNames: + """ + Azure Queue Storage takes 3 to 63 lowercase letters, digits and single + hyphens. A name that does not fit is rejected by the service, and the + executor that built it fails at construction + """ + + def test_a_plain_name_only_loses_its_case(self): + from lithops.monitoring.backends.azure_queue.azure_queue import ( + azure_queue_name, + ) + assert azure_queue_name('lithops-ABC123-0') == 'lithops-abc123-0' + + def test_characters_azure_rejects_are_replaced(self): + from lithops.monitoring.backends.azure_queue.azure_queue import ( + azure_queue_name, + ) + assert azure_queue_name('lithops-a_b/c-0') == 'lithops-a-b-c-0' + + def test_a_long_name_is_cut_and_kept_unique(self): + from lithops.monitoring.backends.azure_queue.azure_queue import ( + azure_queue_name, QUEUE_NAME_MAX_LEN, + ) + first = azure_queue_name('lithops-' + 'a' * 90) + second = azure_queue_name('lithops-' + 'a' * 91) + assert len(first) == QUEUE_NAME_MAX_LEN + assert first != second + + def test_a_short_name_is_padded_to_the_minimum(self): + from lithops.monitoring.backends.azure_queue.azure_queue import ( + azure_queue_name, + ) + assert len(azure_queue_name('AB')) >= 3 + + def test_the_monitor_and_the_workers_agree_on_the_name(self): + from lithops.monitoring.backends.azure_queue.azure_queue import ( + azure_queue_name, + ) + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + service = MagicMock() + with _client(azure_backend, 'queue_service', service): + from lithops.monitoring.backends.azure_queue import ( + AzureQueueMonitor, + ) + monitor = AzureQueueMonitor( + 'SESS-0', None, queue.Queue(), {}, False, {}, + ) + job = SimpleNamespace( + config={'lithops': {'monitoring': 'azure_queue'}, 'azure_queue': {}}, + start_tstamp=0, host_submit_tstamp=0, call_id='00000', + job_id='M000', executor_id='SESS-0', chunksize=1, + monitoring_queues=[monitoring_queue_name('SESS-0')], + ) + with _client(azure_backend, 'queue_service', service): + status = AzureQueueCallStatus(job, MagicMock()) + assert status._targets() == [monitor.queue] + assert monitor.queue == azure_queue_name( + monitoring_queue_name('SESS-0') + ) + + +def _localhost_redis(): + try: + import redis + client = redis.Redis( + host='localhost', port=6379, + socket_connect_timeout=0.5, socket_timeout=1, + ) + client.ping() + return client + except Exception: + return None + + +@pytest.mark.skipif(_localhost_redis() is None, reason='Redis is not running on localhost') +class TestRedisAgainstAServer: + + def test_publish_consume_and_delete_the_list(self): + from lithops.monitoring.backends.redis import RedisMonitor + from lithops.monitoring.backends.redis.status import RedisCallStatus + + client = _localhost_redis() + list_name = monitoring_queue_name('sess-live') + client.delete(list_name) + try: + monitor = RedisMonitor( + 'sess-live', None, queue.Queue(), {'M000': 1}, False, + {'host': 'localhost'}, + ) + future = FakeFuture( + 'M000', invoked=True, call_id='00000', executor_id='sess-live' + ) + monitor.add_futures([future]) + job = SimpleNamespace( + config={'lithops': {'monitoring': 'redis'}, 'redis': {'host': 'localhost'}}, + start_tstamp=time.time(), + host_submit_tstamp=time.time(), + call_id='00000', + job_id='M000', + executor_id='sess-live', + chunksize=1, + monitoring_queues=[list_name], + ) + status = RedisCallStatus(job, MagicMock()) + status.send_init_event() + status.send_finish_event() + thread = threading.Thread(target=monitor.run) + thread.start() + deadline = time.time() + 5 + while not future.ready and time.time() < deadline: + time.sleep(0.05) + assert future.ready is True + monitor.stop() + thread.join(timeout=5) + monitor.cleanup() + assert client.llen(list_name) == 0 + finally: + client.delete(list_name) diff --git a/lithops/tests/test_scripts.py b/lithops/tests/test_scripts.py index 0128e5bd2..7ca0c5816 100644 --- a/lithops/tests/test_scripts.py +++ b/lithops/tests/test_scripts.py @@ -218,6 +218,7 @@ class TestHelloAndClean: def test_hello_call_async(self): fexec = MagicMock() + fexec.__enter__.return_value = fexec fexec.get_result.return_value = 'Hello tester!' with patch('getpass.getuser', return_value='tester'): with patch( @@ -228,7 +229,11 @@ def test_hello_call_async(self): result = _cli('hello') assert result.exit_code == 0 fexec.call_async.assert_called_once() + fexec.__exit__.assert_called_once() assert 'Lithops is working as expected' in result.output + assert result.output.strip().endswith( + 'Hello tester! Lithops is working as expected :)' + ) def test_clean_localhost(self): cfg = { diff --git a/lithops/tests/test_wait.py b/lithops/tests/test_wait.py index 2de70d8ec..73ba84e4a 100644 --- a/lithops/tests/test_wait.py +++ b/lithops/tests/test_wait.py @@ -197,6 +197,64 @@ def test_ready_futures_download_includes_success_until_done(self): exec_data = SimpleNamespace(futures=[success, done]) assert _ready_futures(exec_data, download_results=True) == [success] + def test_ready_futures_over_every_state_combination(self): + """ + This used to intersect a set of the futures whose status had arrived + with a set of the ones not fetched yet, walking the list four times + and building a call id per future on each. It is one filter now, and + this pins the two down as the same answer for every state a future + can be in + """ + import itertools + + combos = list(itertools.product([False, True], repeat=3)) + futures = [ + FakeFuture(ready=r, success=s, done=d, call_id=f'{i:05d}') + for i, (r, s, d) in enumerate(combos) + ] + exec_data = SimpleNamespace(futures=futures) + + assert _ready_futures(exec_data, download_results=False) == [ + f for f in futures if f.ready and not (f.success or f.done) + ] + assert _ready_futures(exec_data, download_results=True) == [ + f for f in futures if (f.ready or f.success) and not f.done + ] + + def test_ready_futures_does_not_look_at_call_ids(self): + """ + Two futures of the same job never share a call id, so matching them + up by id was only ever asking two things of the same future — at the + cost of a tuple per future, four times per poll, ten polls a second + """ + ready = FakeFuture(ready=True, call_id='00000') + other = FakeFuture(ready=True, call_id='00000') + exec_data = SimpleNamespace(futures=[ready, other]) + assert _ready_futures(exec_data, download_results=False) == [ + ready, other + ] + + def test_check_done_any_completed_stops_at_the_first(self): + """ + Counting every future to compare the total against one is a full + pass per poll, on the caller's thread + """ + seen = [] + + class Counted(FakeFuture): + @property + def success(self): + seen.append(self.call_id) + return True + + @success.setter + def success(self, value): + pass + + fs = [Counted(call_id=f'{i:05d}') for i in range(100)] + assert _check_done(fs, ANY_COMPLETED, False) is True + assert len(seen) == 1 + def test_get_executor_data_fetches_status_and_extends_new_futures(self): parent = FakeFuture(ready=True, call_id='00000') child = FakeFuture(call_id='00001') diff --git a/lithops/tests/test_worker.py b/lithops/tests/test_worker.py index 4912c4749..584731812 100644 --- a/lithops/tests/test_worker.py +++ b/lithops/tests/test_worker.py @@ -13,6 +13,7 @@ # import io +import json import os import pickle import sys @@ -21,6 +22,9 @@ from types import SimpleNamespace from unittest.mock import MagicMock, mock_open, patch +import ast +import signal + import pytest import lithops.worker.handler as handler_module @@ -37,12 +41,12 @@ run_task, ) from lithops.worker.jobrunner import JobRunner, JobStats, _prepare_args -from lithops.worker.status import ( +from lithops.monitoring import ( CallStatus, - RabbitmqCallStatus, StorageCallStatus, create_call_status, ) +from lithops.monitoring.backends.rabbitmq.status import RabbitmqCallStatus from lithops.worker.utils import ( LogStream, SystemMonitor, @@ -400,6 +404,9 @@ def test_keeps_existing_activation_id(self, tmp_path, monkeypatch): assert os.environ['__LITHOPS_ACTIVATION_ID'] == 'alreadythere1' +_MISSING_EXITCODE = object() + + class TestRunTask: def _patch_run(self, task, jrp, handler_conn, stats_text=None): @@ -475,18 +482,62 @@ def test_timeout_raises_handler_timeout_error(self, tmp_path): assert added['exception'] is True assert 'exc_info' in added - def test_no_completion_message_is_memory_error(self, tmp_path): - task = _task() - task.log_stream = MagicMock() - task.log_file = str(tmp_path / 'execution.log') - task.stats_file = str(tmp_path / 'missing.txt') + def _run_without_completion(self, task, exitcode): + """ + Drives run_task() down the path where the JobRunner reported + nothing, with the given exit code, and returns the recorded status + """ jrp = MagicMock() jrp.is_alive.return_value = False + if exitcode is _MISSING_EXITCODE: + del jrp.exitcode + else: + jrp.exitcode = exitcode conn = MagicMock() conn.poll.return_value = False - status = self._patch_run(task, jrp, conn) + return self._patch_run(task, jrp, conn) + + def _exc_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] + + def test_a_sigkilled_jobrunner_is_reported_as_memory(self, tmp_path): + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'missing.txt') + status = self._run_without_completion(task, -signal.SIGKILL) added = {c.args[0]: c.args[1] for c in status.add.call_args_list} assert added['exception'] is True + assert self._exc_of(status) is MemoryError + + def test_another_signal_is_not_reported_as_memory(self, tmp_path): + """ + Guessing at an out-of-memory kill for every silent JobRunner is + what sent us looking in the wrong place for a fork() abort + """ + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'missing.txt') + status = self._run_without_completion(task, -signal.SIGABRT) + assert self._exc_of(status) is RuntimeError + + def test_a_jobrunner_without_an_exitcode_does_not_crash(self, tmp_path): + """ + Where there is no fork the JobRunner is a Thread, which has no + exitcode at all + """ + task = _task() + task.log_stream = MagicMock() + task.log_file = str(tmp_path / 'execution.log') + task.stats_file = str(tmp_path / 'missing.txt') + status = self._run_without_completion(task, _MISSING_EXITCODE) + added = {c.args[0]: c.args[1] for c in status.add.call_args_list} + assert added['exception'] is True + assert self._exc_of(status) is RuntimeError def test_keyboard_interrupt_skips_finish_event(self, tmp_path): task = _task() @@ -495,6 +546,14 @@ def test_keyboard_interrupt_skips_finish_event(self, tmp_path): task.stats_file = str(tmp_path / 'missing.txt') status = MagicMock() status.send_init_event.side_effect = KeyboardInterrupt() + # The init event is sent after the JobRunner has been started, so + # the context is mocked out like the other tests here do: without + # it this unit test forks a real process to interrupt + jrp = MagicMock() + jrp.is_alive.return_value = False + ctx = MagicMock() + ctx.Pipe.return_value = (MagicMock(), MagicMock()) + ctx.Process.return_value = jrp with patch('lithops.worker.handler.setup_lithops_logger'): with patch( 'lithops.worker.handler.extract_storage_config', return_value={} @@ -504,7 +563,10 @@ def test_keyboard_interrupt_skips_finish_event(self, tmp_path): 'lithops.worker.handler.create_call_status', return_value=status, ): - run_task(task) + with patch('lithops.worker.handler._MP_CTX', ctx): + with patch('lithops.worker.handler.JobRunner'): + run_task(task) + status.send_init_event.assert_called_once() status.send_finish_event.assert_not_called() def test_runtime_memory_log_branch(self, tmp_path): @@ -534,6 +596,89 @@ def test_does_not_mutate_extra_env_with_session_id(self, tmp_path): assert 'LITHOPS_CONFIG' not in extra +class TestJobRunnerDeathReason: + """ + The JobRunner leaving without a result used to be reported as an + out-of-memory kill whatever the cause, which sends anyone reading the + error looking in the wrong place + """ + + def test_sigkill_reads_as_memory(self): + from lithops.worker.handler import _jobrunner_death_reason + reason = _jobrunner_death_reason(-signal.SIGKILL) + assert 'SIGKILL' in reason + assert 'memory' in reason + + def test_a_plain_exit_code_is_reported_as_such(self): + from lithops.worker.handler import _jobrunner_death_reason + reason = _jobrunner_death_reason(3) + assert 'exited with code 3' in reason + assert 'memory' not in reason + + def test_still_running_is_not_called_a_kill(self): + from lithops.worker.handler import _jobrunner_death_reason + assert 'no\n exit code' not in _jobrunner_death_reason(None) + assert 'exit code' in _jobrunner_death_reason(None) + + def test_sigabrt_on_macos_points_at_the_fork_check(self): + from lithops.worker.handler import _jobrunner_death_reason + with patch('lithops.worker.handler.sys.platform', 'darwin'): + reason = _jobrunner_death_reason(-signal.SIGABRT) + assert 'fork()' in reason + assert 'OBJC_DISABLE_INITIALIZE_FORK_SAFETY' in reason + + def test_macos_is_told_to_allow_a_fork_with_a_client_open(self, monkeypatch): + """ + A worker keeps its client for the whole process, so from the second + call on there is one alive when the next JobRunner is forked. This + is the workaround Apple documents for the fork() safety check its + frameworks apply, and the one this very module points at when a + JobRunner dies of SIGABRT + """ + import lithops.worker.handler as handler + + monkeypatch.setattr(handler.sys, 'platform', 'darwin') + monkeypatch.delenv(handler.FORK_SAFETY_ENV, raising=False) + handler._allow_fork_after_a_client_exists() + assert os.environ[handler.FORK_SAFETY_ENV] == 'YES' + + def test_a_value_the_user_chose_is_left_alone(self, monkeypatch): + import lithops.worker.handler as handler + + monkeypatch.setattr(handler.sys, 'platform', 'darwin') + monkeypatch.setenv(handler.FORK_SAFETY_ENV, 'NO') + handler._allow_fork_after_a_client_exists() + assert os.environ[handler.FORK_SAFETY_ENV] == 'NO' + + def test_other_platforms_are_left_alone(self, monkeypatch): + import lithops.worker.handler as handler + + monkeypatch.setattr(handler.sys, 'platform', 'linux') + monkeypatch.delenv(handler.FORK_SAFETY_ENV, raising=False) + handler._allow_fork_after_a_client_exists() + assert handler.FORK_SAFETY_ENV not in os.environ + + def test_a_platform_without_sigkill_is_not_an_attribute_error(self): + """ + Windows has no signal.SIGKILL, and a Thread stands in for the + Process there, so it has no exit code either. Reaching for SIGKILL + by name on that path turned a silent death into an AttributeError + """ + import lithops.worker.handler as handler + with patch.object(handler, '_SIGKILL', None): + assert 'exit code' in handler._jobrunner_death_reason(None) + assert 'code 1' in handler._jobrunner_death_reason(1) + # A negative code cannot happen there, but must not raise here + assert handler._jobrunner_death_reason(-9) + + def test_sigabrt_elsewhere_stays_generic(self): + from lithops.worker.handler import _jobrunner_death_reason + with patch('lithops.worker.handler.sys.platform', 'linux'): + reason = _jobrunner_death_reason(-signal.SIGABRT) + assert 'SIGABRT' in reason + assert 'OBJC_DISABLE' not in reason + + class TestGetFunctionAndModules: def test_loads_from_storage_without_modules(self): @@ -757,6 +902,14 @@ def test_memory_monitor_breaks_when_usage_is_none(self): class TestCallStatus: + @pytest.fixture(autouse=True) + def _no_clients_left_over(self): + """The clients are kept for the process, so tests must not share one""" + from lithops.monitoring.status import close_shared_clients + close_shared_clients() + yield + close_shared_clients() + def test_create_call_status_storage_and_rabbitmq(self): job = _task() st = create_call_status(job, MagicMock()) @@ -765,6 +918,83 @@ def test_create_call_status_storage_and_rabbitmq(self): rb = create_call_status(job, MagicMock()) assert isinstance(rb, RabbitmqCallStatus) + def test_create_call_status_redis_and_sqs(self): + from lithops.monitoring.backends.redis.status import RedisCallStatus + from lithops.monitoring.backends.aws_sqs.status import SqsCallStatus + + job = _task() + job.config['lithops']['monitoring'] = 'redis' + job.config['redis'] = {'host': 'localhost'} + assert isinstance(create_call_status(job, MagicMock()), RedisCallStatus) + + job.config['lithops']['monitoring'] = 'aws_sqs' + job.config['aws_sqs'] = {'region': 'us-east-1'} + assert isinstance(create_call_status(job, MagicMock()), SqsCallStatus) + + def test_create_call_status_gcp_pubsub_and_azure_queue(self): + from lithops.monitoring.backends.gcp_pubsub.status import ( + GcpPubsubCallStatus, + ) + from lithops.monitoring.backends.azure_queue.status import ( + AzureQueueCallStatus, + ) + + job = _task() + job.config['lithops']['monitoring'] = 'gcp_pubsub' + job.config['gcp_pubsub'] = {'project_name': 'proj'} + assert isinstance( + create_call_status(job, MagicMock()), GcpPubsubCallStatus + ) + + job.config['lithops']['monitoring'] = 'azure_queue' + job.config['azure_queue'] = { + 'storage_account_name': 'acct', 'storage_account_key': 'key', + } + assert isinstance( + create_call_status(job, MagicMock()), AzureQueueCallStatus + ) + + def test_create_call_status_falls_back_to_storage(self): + """ + The client falls back to the storage monitor when nothing names a + backend, so the worker has to report through the same one. Reading + the key straight out of the config raised here instead + """ + job = _task() + job.config['lithops'].pop('monitoring', None) + assert isinstance( + create_call_status(job, MagicMock()), StorageCallStatus + ) + + def test_create_call_status_unknown_backend(self): + job = _task() + job.config['lithops']['monitoring'] = 'nope' + with pytest.raises(ValueError, match='Unknown monitoring backend'): + create_call_status(job, MagicMock()) + + def test_no_backend_client_is_built_before_the_first_status(self): + """ + run_task() builds the call status and then forks the JobRunner off. + A client that already exists at that point is what the fork() safety + check of the Apple frameworks aborts the child over, so every + backend builds its own only when the first status is published + """ + from lithops.monitoring.backends.redis import redis as redis_backend + from lithops.monitoring.backends.aws_sqs import aws_sqs as sqs_backend + + job = _task() + job.config['lithops']['monitoring'] = 'redis' + job.config['redis'] = {'host': 'localhost'} + with patch.object(redis_backend, 'redis_client') as build: + create_call_status(job, MagicMock()) + build.assert_not_called() + + job.config['lithops']['monitoring'] = 'aws_sqs' + job.config['aws_sqs'] = {'region': 'us-east-1'} + with patch.object(sqs_backend, 'sqs_client') as build: + create_call_status(job, MagicMock()) + build.assert_not_called() + def test_warm_container_flag(self, monkeypatch): monkeypatch.delenv('WARM_CONTAINER', raising=False) job = _task() @@ -807,7 +1037,8 @@ def test_rabbitmq_end_also_writes_storage(self): status.status['type'] = '__end__' status.status['activation_id'] = 'act' with patch( - 'lithops.worker.status.pika.BlockingConnection', return_value=conn + 'lithops.monitoring.backends.rabbitmq.status.pika.BlockingConnection', + return_value=conn ): status._send() assert channel.basic_publish.call_count == 2 @@ -821,7 +1052,7 @@ def test_rabbitmq_publishes_to_the_queues_it_was_given(self): ] job.config = _job_config(monitoring='rabbitmq') status = RabbitmqCallStatus(job, MagicMock()) - assert status._queue_names() == job.monitoring_queues + assert status._targets() == job.monitoring_queues def test_rabbitmq_falls_back_to_its_own_queue(self): # A payload with no chain can only reach this executor's own queue @@ -829,7 +1060,7 @@ def test_rabbitmq_falls_back_to_its_own_queue(self): job.executor_id = 'sess-0-M000-00000-0' job.config = _job_config(monitoring='rabbitmq') status = RabbitmqCallStatus(job, MagicMock()) - assert status._queue_names() == ['lithops-sess-0-M000-00000-0'] + assert status._targets() == ['lithops-sess-0-M000-00000-0'] def test_rabbitmq_gives_up_after_five_failures(self): job = _task() @@ -839,7 +1070,7 @@ def test_rabbitmq_gives_up_after_five_failures(self): status = RabbitmqCallStatus(job, storage) status.status['type'] = '__init__' with patch( - 'lithops.worker.status.pika.BlockingConnection', + 'lithops.monitoring.backends.rabbitmq.status.pika.BlockingConnection', side_effect=Exception('down'), ): test_thread = threading.current_thread() @@ -849,9 +1080,12 @@ def sleep(_seconds): if threading.current_thread() is test_thread: sleeps.append(_seconds) - with patch('lithops.worker.status.time.sleep', side_effect=sleep): + with patch('lithops.monitoring.status.time.sleep', side_effect=sleep): status._send() - assert len(sleeps) == 5 + # Five attempts have four gaps between them: there is nothing left + # to wait for after the last one. Backed off, so that they span a + # broker hiccup instead of being spent within the same second + assert sleeps == [0.2, 0.4, 0.8, 1.6] storage.put_data.assert_not_called() @@ -1144,6 +1378,78 @@ def test_function_invoker_wires_handlers(self, monkeypatch): assert os.environ['LITHOPS_WORKER'] == 'True' assert payload['config']['aws_lambda']['invoke_pool_threads'] == 128 + def test_the_remote_invoker_takes_a_queue_of_its_own(self, monkeypatch): + """ + It watches the client's executor from a worker, so it must not read + the client's queue: the statuses it took would never reach the + client. It reads its own, and the calls report to both + """ + from lithops.utils import ( + MONITORING_QUEUES_ENV, + monitoring_queue_name, + monitoring_queues, + remote_invoker_queue_name, + ) + + monkeypatch.delenv('LITHOPS_WORKER', raising=False) + monkeypatch.delenv(MONITORING_QUEUES_ENV, raising=False) + payload = { + 'config': _job_config( + monitoring='redis', backend='aws_lambda' + ), + 'job': { + 'job_key': 'jk', + 'executor_id': 'ex', + 'job_id': 'j0', + 'chunksize': 1, + }, + } + payload['config']['aws_lambda'] = {} + job_monitor = MagicMock() + with patch( + 'lithops.worker.invoker.extract_storage_config', return_value={} + ): + with patch('lithops.worker.invoker.InternalStorage'): + with patch( + 'lithops.worker.invoker.extract_serverless_config', + return_value={}, + ): + with patch('lithops.worker.invoker.ServerlessHandler'): + with patch( + 'lithops.worker.invoker.JobMonitor', + return_value=job_monitor, + ) as monitor_cls: + with patch( + 'lithops.worker.invoker.FaaSRemoteInvoker' + ): + function_invoker(payload) + + client_queue = monitoring_queue_name('ex') + invoker_queue = remote_invoker_queue_name('ex') + assert monitor_cls.call_args.kwargs['queue_name'] == invoker_queue + assert invoker_queue != client_queue + + # the calls this invoker spawns report to both queues + assert json.loads(os.environ[MONITORING_QUEUES_ENV]) == [ + client_queue, invoker_queue + ] + assert monitoring_queues('ex') == [client_queue, invoker_queue] + + def test_the_remote_invoker_deletes_its_own_queue(self): + """ + Nothing else knows about that queue, so if this worker leaves it + behind it stays on the broker for good + """ + from lithops.worker.invoker import FaaSRemoteInvoker + inv = FaaSRemoteInvoker.__new__(FaaSRemoteInvoker) + inv.job_monitor = MagicMock() + inv.pending_calls_q = MagicMock() + inv.pending_calls_q.qsize.return_value = 0 + inv.stop = MagicMock() + inv._run_job = MagicMock(return_value=['f']) + inv.run_job(SimpleNamespace(job_id='j0', chunksize=1)) + inv.job_monitor.cleanup.assert_called_once() + def test_remote_invoker_run_job_drains_then_stops_waiting(self): from lithops.worker.invoker import FaaSRemoteInvoker inv = FaaSRemoteInvoker.__new__(FaaSRemoteInvoker) diff --git a/lithops/utils.py b/lithops/utils.py index e3e8138e1..77221de4b 100644 --- a/lithops/utils.py +++ b/lithops/utils.py @@ -109,6 +109,17 @@ def monitoring_queue_name(executor_id: str) -> str: return f'lithops-{executor_id}' +def remote_invoker_queue_name(executor_id: str) -> str: + """ + Returns the name of the queue the remote invoker is monitored through. + + It follows the calls of an executor it does not own, so it cannot read + the queue of that executor: a message taken from a queue is gone, and + the client waiting on the other end would never see it + """ + return f'{monitoring_queue_name(executor_id)}-invoker' + + def monitoring_queues(executor_id: str) -> List[str]: """ Returns every queue a call status of this executor has to be published to: diff --git a/lithops/wait.py b/lithops/wait.py index c58f31949..c62712600 100644 --- a/lithops/wait.py +++ b/lithops/wait.py @@ -31,12 +31,11 @@ is_lithops_worker, FuturesList, _as_future_list, - _future_id, log_prefix, ) from lithops.storage import InternalStorage from lithops.future import ResponseFuture -from lithops.monitor import JobMonitor +from lithops.monitoring import JobMonitor ALWAYS = 0 @@ -377,13 +376,15 @@ def _check_done(fs, return_when, download_results): """ Checks if return_when% of futures are ready or done """ + if return_when == ANY_COMPLETED: + # Stops at the first one, rather than counting every future on + # every poll to compare the total against one + return any(_future_is_complete(f, download_results) for f in fs) + total_done = sum( 1 for f in fs if _future_is_complete(f, download_results) ) - if return_when == ANY_COMPLETED: - return total_done >= 1 - done_percentage = int(total_done * 100 / len(fs)) return done_percentage >= return_when @@ -391,19 +392,23 @@ def _check_done(fs, return_when, download_results): def _ready_futures(exec_data, download_results): """ Returns the futures of one executor that have data waiting on the other - side: their status has arrived, but the caller has not fetched it yet + side: their status has arrived, but the caller has not fetched it yet. + + One pass, no call ids: this used to intersect a set of the futures that + had arrived with a set of the ones not fetched yet, which walked the + list four times and built a tuple per future on each. The futures of an + executor are distinct objects, so the intersection was only ever asking + both things of the same future """ if download_results: - done_ids = { - _future_id(f) for f in exec_data.futures if f.ready or f.success - } - pending = (f for f in exec_data.futures if not f.done) - else: - done_ids = {_future_id(f) for f in exec_data.futures if f.ready} - pending = (f for f in exec_data.futures if not (f.success or f.done)) - - ready_ids = {_future_id(f) for f in pending} & done_ids - return [f for f in exec_data.futures if _future_id(f) in ready_ids] + return [ + f for f in exec_data.futures + if (f.ready or f.success) and not f.done + ] + return [ + f for f in exec_data.futures + if f.ready and not (f.success or f.done) + ] def _get_executor_data( diff --git a/lithops/worker/handler.py b/lithops/worker/handler.py index 39f11aa4f..2020f6a6a 100644 --- a/lithops/worker/handler.py +++ b/lithops/worker/handler.py @@ -26,6 +26,7 @@ import pickle import struct import logging +import signal import traceback import multiprocessing as mp from queue import Queue, Empty @@ -48,7 +49,7 @@ setup_lithops_logger, is_unix_system, ) -from lithops.worker.status import create_call_status +from lithops.monitoring import create_call_status pickling_support.install() @@ -317,6 +318,71 @@ def prepare_and_run_task(task: SimpleNamespace) -> None: os.environ.pop(key, None) +# Windows has no SIGKILL, and no process there is reported as killed by one +_SIGKILL = getattr(signal, 'SIGKILL', None) + +#: Apple's own opt-out of the fork() safety check of its frameworks, which +#: aborts a child forked from a process where one of them was being set up +FORK_SAFETY_ENV = 'OBJC_DISABLE_INITIALIZE_FORK_SAFETY' + + +def _allow_fork_after_a_client_exists() -> None: + """ + Lets the worker fork the JobRunner off while a monitoring client is open. + + A worker keeps its client for the whole process, so from the second call + on there is one alive when the next JobRunner is forked. On macOS that is + what the fork() safety check of the Apple frameworks can abort the child + over, and this is the workaround Apple documents for it — the same one + the error message of a dead JobRunner points at. Set before the first + fork, and never over a value the user chose + """ + if sys.platform != 'darwin' or FORK_SAFETY_ENV in os.environ: + return + os.environ[FORK_SAFETY_ENV] = 'YES' + + +def _jobrunner_death_reason(exitcode: Optional[int]) -> str: + """ + Explains why the JobRunner left without reporting its result. A + negative exit code is the number of the signal that killed it + """ + if exitcode is None: + return ( + 'The function ended without reporting its result, and left no ' + 'exit code to say why: either it ran in a thread, which has ' + 'none, or the process is somehow still running' + ) + if exitcode >= 0: + return ( + f'The function process exited with code {exitcode} before ' + 'reporting its result' + ) + + killed_by = -exitcode + try: + name = signal.Signals(killed_by).name + except ValueError: + name = f'signal {killed_by}' + + if killed_by == _SIGKILL: + return ( + 'The function process was killed with SIGKILL, which is what ' + 'the out-of-memory killer does: the function most likely ' + 'exceeded the memory available to it' + ) + if killed_by == signal.SIGABRT and sys.platform == 'darwin': + return ( + 'The function process was aborted with SIGABRT. On macOS this ' + 'is usually the fork() safety check of the Apple frameworks: ' + 'something the parent process had already used, such as a ' + 'network client, cannot be used again in a forked child. ' + 'Setting OBJC_DISABLE_INITIALIZE_FORK_SAFETY=YES in the ' + 'environment works around it' + ) + return f'The function process was killed with {name}' + + def _add_resource_usage(call_status, sys_monitor: SystemMonitor) -> None: """ Reports the CPU, network and memory that the task consumed @@ -404,6 +470,7 @@ def run_task(task: SimpleNamespace) -> None: } os.environ.update(task.extra_env) os.environ.update(injected_env) + _allow_fork_after_a_client_exists() storage_config = extract_storage_config(task.config) internal_storage = InternalStorage(storage_config) @@ -423,8 +490,6 @@ def run_task(task: SimpleNamespace) -> None: job_interrupted = False try: - call_status.send_init_event() - handler_conn, jobrunner_conn = _MP_CTX.Pipe() jobrunner = JobRunner(task, jobrunner_conn, internal_storage) logger.debug('Starting JobRunner process') @@ -441,6 +506,14 @@ def run_task(task: SimpleNamespace) -> None: sys_monitor.start() jrp.start() + + # Reported once the process is running, which is also when the call + # has really started. Sending it here rather than before the fork + # 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() jrp.join(task.execution_timeout) sys_monitor.stop() @@ -461,15 +534,21 @@ def run_task(task: SimpleNamespace) -> None: ) if not handler_conn.poll(): - # The JobRunner sends exactly one message when it finishes, so no - # message means it was killed. That is an OOM 99% of the times + # The JobRunner sends exactly one message when it finishes, so + # no message means it died before getting there. Its exit code + # says why, and guessing at an out-of-memory kill regardless + # sends whoever reads the error looking in the wrong place + # A Thread stands in for the Process where there is no fork, + # and it has no exit code to report + exitcode = getattr(jrp, 'exitcode', None) + reason = _jobrunner_death_reason(exitcode) logger.error( - 'No completion message received from JobRunner process' - ) - logger.debug('Assuming memory overflow...') - raise MemoryError( - 'Function exceeded maximum memory and was killed' + 'No completion message received from the JobRunner ' + f'process, which exited with code {exitcode}: {reason}' ) + if _SIGKILL is not None and exitcode == -_SIGKILL: + raise MemoryError(reason) + raise RuntimeError(reason) _add_task_stats(call_status, task.stats_file) diff --git a/lithops/worker/invoker.py b/lithops/worker/invoker.py index d4e7813c9..b9e4f401b 100644 --- a/lithops/worker/invoker.py +++ b/lithops/worker/invoker.py @@ -21,11 +21,15 @@ from typing import Any, Dict from lithops.serverless import ServerlessHandler -from lithops.monitor import JobMonitor +from lithops.monitoring import JobMonitor from lithops.storage import InternalStorage from lithops.config import extract_serverless_config, extract_storage_config from lithops.invokers import FaaSInvoker -from lithops.utils import MONITORING_QUEUES_ENV, monitoring_queues +from lithops.utils import ( + MONITORING_QUEUES_ENV, + monitoring_queues, + remote_invoker_queue_name, +) logger = logging.getLogger(__name__) @@ -39,14 +43,21 @@ def function_invoker(job_payload: Dict[str, Any]) -> None: config = job_payload['config'] job = SimpleNamespace(**job_payload['job']) + # This invoker watches the calls of the client's executor, but it cannot + # read the client's queue: a message taken from a queue is gone, and the + # two would end up splitting the statuses between them. It takes a queue + # of its own, and the calls report to both + invoker_queue = remote_invoker_queue_name(job.executor_id) + os.environ.update({ 'LITHOPS_WORKER': 'True', 'PYTHONUNBUFFERED': 'True', '__LITHOPS_SESSION_ID': job.job_key, - # The job this invoker spawns reports to the queues of the client, and - # an executor created here extends that chain rather than replacing it + # The job this invoker spawns reports to the queues of the client and + # to this invoker's own, and an executor created here extends that + # chain rather than replacing it MONITORING_QUEUES_ENV: json.dumps( - monitoring_queues(job.executor_id) + monitoring_queues(job.executor_id) + [invoker_queue] ), }) @@ -59,13 +70,13 @@ def function_invoker(job_payload: Dict[str, Any]) -> None: serverless_config = extract_serverless_config(config) compute_handler = ServerlessHandler(serverless_config, storage_config) - monitoring_backend = config['lithops']['monitoring'].lower() job_monitor = JobMonitor( executor_id=job.executor_id, internal_storage=internal_storage, - backend=monitoring_backend, - config=config.get(monitoring_backend) + config=config, + queue_name=invoker_queue, ) + job_monitor.prepare() invoker = FaaSRemoteInvoker( config, @@ -104,5 +115,8 @@ def run_job(self, job: SimpleNamespace) -> None: # Waits for the invocations still in flight, which this worker must not # be frozen in the middle of self.stop(wait=True) + # The queue belongs to this invoker, and nothing else will come back + # to delete it once the worker is gone + self.job_monitor.cleanup() logger.info('Remote Invoker Finished') diff --git a/lithops/worker/status.py b/lithops/worker/status.py deleted file mode 100644 index 7d7a2de27..000000000 --- a/lithops/worker/status.py +++ /dev/null @@ -1,200 +0,0 @@ -# -# Licensed under the Apache License, Version 2.0 (the "License"); -# you may not use this file except in compliance with the License. -# You may obtain a copy of the License at -# -# http://www.apache.org/licenses/LICENSE-2.0 -# -# Unless required by applicable law or agreed to in writing, software -# distributed under the License is distributed on an "AS IS" BASIS, -# WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. -# See the License for the specific language governing permissions and -# limitations under the License. -# - -import os -import pika -import json -import time -import logging -from tblib import pickling_support -from contextlib import contextmanager -from types import SimpleNamespace -from typing import Any, Iterator - -from lithops.utils import monitoring_queue_name, sizeof_fmt -from lithops.storage.utils import create_status_key, create_init_key - - -pickling_support.install() - -logger = logging.getLogger(__name__) - - -def create_call_status(job: SimpleNamespace, internal_storage) -> 'CallStatus': - """Creates a call status class based on the monitoring backend""" - monitoring_backend = job.config['lithops']['monitoring'].lower() - try: - status_cls = _STATUS_CLASSES[monitoring_backend] - except KeyError as exc: - raise ValueError( - f'Unknown monitoring backend: {monitoring_backend}' - ) from exc - return status_cls(job, internal_storage) - - -class CallStatus: - """ - Status of a single call, reported to the client both when the task starts - and when it finishes - """ - - def __init__(self, job: SimpleNamespace, internal_storage): - self.job = job - self.config = job.config - self.internal_storage = internal_storage - - self.status = { - 'exception': False, - 'activation_id': os.environ.get('__LITHOPS_ACTIVATION_ID'), - 'python_version': os.environ.get("PYTHON_VERSION"), - 'worker_start_tstamp': job.start_tstamp, - 'host_submit_tstamp': job.host_submit_tstamp, - 'call_id': job.call_id, - 'job_id': job.job_id, - 'executor_id': job.executor_id, - 'chunksize': job.chunksize - } - - is_warm = os.environ.get('WARM_CONTAINER', '').lower() in { - '1', 'true', 'yes' - } - self.status['worker_cold_start'] = not is_warm - if not is_warm: - os.environ['WARM_CONTAINER'] = 'True' - - def add(self, key: str, value: Any) -> None: - """ Adds data to the call status""" - self.status[key] = value - - def send_init_event(self) -> None: - """ Sends the init event""" - self.status['type'] = '__init__' - self._send() - - def send_finish_event(self) -> None: - """ Sends the finish event""" - self.status['type'] = '__end__' - self._send() - - -class StorageCallStatus(CallStatus): - """Reports the status of a call by writing it to the Object Storage""" - - def _send(self) -> None: - """ - Sends the status event to the Object Storage - """ - executor_id = self.status['executor_id'] - job_id = self.status['job_id'] - call_id = self.status['call_id'] - act_id = self.status['activation_id'] - - if self.status['type'] == '__init__': - init_key = create_init_key(executor_id, job_id, call_id, act_id) - self.internal_storage.put_data(init_key, '') - - elif self.status['type'] == '__end__': - status_key = create_status_key(executor_id, job_id, call_id) - dmpd_response_status = json.dumps(self.status) - logger.info( - f"Storing execution stats - " - f"Size: {sizeof_fmt(len(dmpd_response_status))}" - ) - self.internal_storage.put_data(status_key, dmpd_response_status) - - -class RabbitmqCallStatus(StorageCallStatus): - """ - Reports the status of a call by publishing it to RabbitMQ, which reaches - the client faster, and falls back to the Object Storage at the end - """ - MAX_ATTEMPTS = 5 - - def __init__(self, job: SimpleNamespace, internal_storage): - super().__init__(job, internal_storage) - - rabbit_amqp_url = self.config['rabbitmq'].get('amqp_url') - self.pikaparams = pika.URLParameters(rabbit_amqp_url) - - @contextmanager - def _create_channel(self) -> Iterator[Any]: - """ - Creates a rabbitmq channel, closed along with its connection - """ - connection = pika.BlockingConnection(self.pikaparams) - channel = connection.channel() - try: - yield channel - finally: - channel.close() - connection.close() - - def _queue_names(self): - """ - Returns the name of every queue this status has to be published to, - which the client worked out and sent along with the job. - - The fallback only reaches the queue of this very executor: a payload - without the chain cannot say which executors are waiting further up, - so a nested job would go unnoticed by its ancestors - """ - queues = getattr(self.job, 'monitoring_queues', None) - if queues: - return list(queues) - - logger.warning( - 'The job carries no monitoring queues, reporting only to the ' - f'queue of {self.job.executor_id}' - ) - return [monitoring_queue_name(self.job.executor_id)] - - def _send(self) -> None: - """ - Sends the status event to RabbitMQ - """ - dmpd_response_status = json.dumps(self.status) - queues = self._queue_names() - exc = None - - for _ in range(self.MAX_ATTEMPTS): - try: - with self._create_channel() as channel: - for queue in queues: - channel.basic_publish( - exchange='', - routing_key=queue, - body=dmpd_response_status - ) - logger.info( - f"Execution status sent to RabbitMQ - " - f"Size: {sizeof_fmt(len(dmpd_response_status))}" - ) - break - except Exception as e: - exc = e - time.sleep(0.2) - else: - logger.error( - f"Could not send the execution status to RabbitMQ after " - f"{self.MAX_ATTEMPTS} attempts: {exc}" - ) - - if self.status['type'] == '__end__': - super()._send() - - -_STATUS_CLASSES = { - 'storage': StorageCallStatus, - 'rabbitmq': RabbitmqCallStatus, -}