diff --git a/CHANGELOG.md b/CHANGELOG.md index a0934763b..9e02b0772 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -6,12 +6,12 @@ - [API] Added `lithops.concurrent.futures`, a `concurrent.futures`-compatible executor interface backed by Lithops. - [Monitoring] Added Redis, AWS SQS, GCP Pub/Sub and Azure Queue Storage monitoring backends. -- [Monitoring] Added the `aws_sqs`, `gcp_pubsub` and `azure_queue` config sections, which fall back to the `aws`, `gcp` and `azure_storage` credentials. - [Core] Added a cache of serialized functions to avoid re-uploading the same function. - [Core] Added `clean_jobs` to `wait()`, to keep the temporary data until the results are read. - [AWS Batch] Added the `instance_types` config option for EC2/SPOT compute environments. - [Multiprocessing] Added `timeout` to `acquire()`, and `_getvalue()`, `_callmethod()` and `copy_proxy()` to the manager proxies. - [Multiprocessing] Added `ThreadPool`, `Manager`, the standard error classes and the module-level helpers (`freeze_support()`, `get_logger()`, `log_to_stderr()`). +- [Telemetry] Added `lithops.telemetry`, which turns the call statuses the monitor reads into 29 Prometheus or OpenTelemetry metrics. - [Tests] Added a unit test suite for all non-backend modules. ### Changed diff --git a/config/config_template.yaml b/config/config_template.yaml index baf3d59f8..3b8abf2b9 100644 --- a/config/config_template.yaml +++ b/config/config_template.yaml @@ -34,7 +34,8 @@ #log_format: "%(asctime)s [%(levelname)s] %(name)s -- %(message)s" #log_stream: ext://sys.stderr #log_filename: - #telemetry: False # Enable Prometheus push-gateway metrics + #telemetry: False # Client-side metrics. One of: False, prometheus, otlp + #telemetry_interval: 10 # Seconds between metric pushes. Default: 10 # ============================================================================= @@ -584,7 +585,24 @@ # ============================================================================= -# Prometheus – pushed metrics when `lithops.telemetry=True` +# Prometheus – metrics pushed when `lithops.telemetry=prometheus` # ============================================================================= #prometheus: - #apigateway: # Prometheus Pushgateway base URL + #gateway: http://localhost:9091 # Pushgateway base URL. Default: http://localhost:9091 + #job: lithops # Pushgateway job label. Default: lithops + #instance: # Pushgateway instance label. Default: the hostname + #username: # Basic auth user, when the gateway needs one + #password: # Basic auth password, when the gateway needs one + #timeout: 10 # Push timeout in seconds. Default: 10 + + +# ============================================================================= +# OpenTelemetry – metrics exported when `lithops.telemetry=otlp` +# ============================================================================= +#otlp: + #endpoint: http://localhost:4318 # Collector endpoint. Default: http://localhost:4318 + #protocol: http/protobuf # One of: http/protobuf, grpc. Default: http/protobuf + #service_name: lithops # OTel service.name. Default: lithops + #instance: # OTel host.name. Default: the hostname + #headers: {} # Extra headers, e.g. authentication + #timeout: 10 # Export timeout in seconds. Default: 10 diff --git a/docs/index.rst b/docs/index.rst index 024cfd947..7344c9c3e 100644 --- a/docs/index.rst +++ b/docs/index.rst @@ -276,6 +276,7 @@ Lithops is an open-source project, actively maintained and supported by a commun :caption: Advanced Features source/monitoring.rst + source/metrics.rst Custom Runtimes @@ -284,7 +285,6 @@ Lithops is an open-source project, actively maintained and supported by a commun :maxdepth: 0 :caption: Experimental Features - source/metrics.rst source/dso.rst diff --git a/docs/source/design.rst b/docs/source/design.rst index f72241177..a469c4f3e 100644 --- a/docs/source/design.rst +++ b/docs/source/design.rst @@ -75,6 +75,10 @@ directly to a module or class in the ``lithops`` package: - ``lithops/monitoring/`` - Tracks completion through either ``StorageMonitor`` (polling) or ``RabbitmqMonitor`` (push notifications). + * - Telemetry + - ``lithops/telemetry/`` + - Turns the call statuses the monitor reads into metrics, and pushes them + to Prometheus or to an OpenTelemetry collector. Off by default. * - ``InternalStorage`` - ``lithops/storage/storage.py`` - Uniform storage client used by both the client and the workers, backed by diff --git a/docs/source/grafana/lithops-dashboard.json b/docs/source/grafana/lithops-dashboard.json new file mode 100644 index 000000000..b3e0065cd --- /dev/null +++ b/docs/source/grafana/lithops-dashboard.json @@ -0,0 +1,1517 @@ +{ + "title": "Lithops", + "uid": "lithops-overview", + "description": "Serverless jobs run through Lithops: throughput, where the time goes, what the workers cost, and what the client spends getting a job out of the door. Requires lithops.telemetry to be enabled. A Lithops client is a script rather than a service, so its counters live for the life of the process and start again from zero in the next run: the panels read the counters as they stand rather than as a rate.", + "tags": [ + "lithops", + "serverless" + ], + "timezone": "browser", + "editable": true, + "graphTooltip": 1, + "schemaVersion": 39, + "version": 1, + "refresh": "10s", + "time": { + "from": "now-1h", + "to": "now" + }, + "templating": { + "list": [ + { + "name": "datasource", + "label": "Data source", + "type": "datasource", + "query": "prometheus", + "refresh": 1, + "current": {}, + "hide": 0 + }, + { + "name": "backend", + "label": "Compute backend", + "type": "query", + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "query": { + "query": "label_values(lithops_calls_completed_total, backend)", + "refId": "var-backend" + }, + "definition": "label_values(lithops_calls_completed_total, backend)", + "refresh": 2, + "includeAll": true, + "allValue": ".*", + "multi": true, + "sort": 1, + "current": {}, + "options": [], + "hide": 0 + }, + { + "name": "runtime", + "label": "Runtime", + "type": "query", + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "query": { + "query": "label_values(lithops_calls_completed_total{backend=~\"$backend\"}, runtime_name)", + "refId": "var-runtime" + }, + "definition": "label_values(lithops_calls_completed_total{backend=~\"$backend\"}, runtime_name)", + "refresh": 2, + "includeAll": true, + "allValue": ".*", + "multi": true, + "sort": 1, + "current": {}, + "options": [], + "hide": 0 + }, + { + "name": "function", + "label": "Function", + "type": "query", + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "query": { + "query": "label_values(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\"}, function_name)", + "refId": "var-function" + }, + "definition": "label_values(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\"}, function_name)", + "refresh": 2, + "includeAll": true, + "allValue": ".*", + "multi": true, + "sort": 1, + "current": {}, + "options": [], + "hide": 0 + } + ] + }, + "panels": [ + { + "type": "row", + "title": "Overview", + "id": 1, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 0 + }, + "panels": [] + }, + { + "type": "stat", + "title": "Calls in flight", + "id": 2, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Invoked but not yet finished.", + "gridPos": { + "h": 4, + "w": 6, + "x": 0, + "y": 1 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "clamp_min(sum(lithops_calls_invoked_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) - sum(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 0)", + "legendFormat": "", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "justifyMode": "auto", + "textMode": "auto" + }, + "fieldConfig": { + "defaults": { + "unit": "short", + "decimals": null, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "stat", + "title": "Calls completed", + "id": 3, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Since the exporting process started.", + "gridPos": { + "h": 4, + "w": 6, + "x": 6, + "y": 1 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"})", + "legendFormat": "", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "justifyMode": "auto", + "textMode": "auto" + }, + "fieldConfig": { + "defaults": { + "unit": "short", + "decimals": null, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "stat", + "title": "Failure rate", + "id": 4, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Calls finishing as failure, timeout or chained.", + "gridPos": { + "h": 4, + "w": 6, + "x": 12, + "y": 1 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\", outcome!=\"success\"}) / clamp_min(sum(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "justifyMode": "auto", + "textMode": "auto" + }, + "fieldConfig": { + "defaults": { + "unit": "percentunit", + "decimals": 2, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "green", + "value": null + }, + { + "color": "orange", + "value": 0.01 + }, + { + "color": "red", + "value": 0.1 + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "stat", + "title": "Cold start rate", + "id": 5, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Calls that ran in a cold worker.", + "gridPos": { + "h": 4, + "w": 6, + "x": 18, + "y": 1 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum(lithops_cold_starts_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum(lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "reduceOptions": { + "calcs": [ + "lastNotNull" + ], + "fields": "", + "values": false + }, + "colorMode": "value", + "graphMode": "area", + "justifyMode": "auto", + "textMode": "auto" + }, + "fieldConfig": { + "defaults": { + "unit": "percentunit", + "decimals": 2, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Throughput and latency", + "id": 6, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 5 + }, + "panels": [] + }, + { + "type": "timeseries", + "title": "Calls completed, by outcome", + "id": 7, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Cumulative for as long as the client process lives. It steps up as a job finishes and starts again from zero with the next run.", + "gridPos": { + "h": 8, + "w": 12, + "x": 0, + "y": 6 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum by (outcome) (lithops_calls_completed_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"})", + "legendFormat": "{{outcome}}", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "short", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 25, + "showPoints": "never", + "stacking": { + "mode": "normal", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "Function execution time", + "id": 8, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Wall clock time inside the user function.", + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 6 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.5, sum by (le) (lithops_call_duration_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p50", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le) (lithops_call_duration_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p95", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.99, sum by (le) (lithops_call_duration_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p99", + "range": true, + "instant": false, + "refId": "C" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "s", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Where the time goes", + "id": 9, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 14 + }, + "panels": [] + }, + { + "type": "timeseries", + "title": "Mean time per call, by phase", + "id": 10, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Every second of a call, from submission to the result in hand. The phases add up to the end-to-end time on the right.", + "gridPos": { + "h": 8, + "w": 12, + "x": 0, + "y": 15 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_queue_delay_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_queue_delay_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "queue", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_worker_setup_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_worker_setup_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "worker setup", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_duration_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_duration_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "function", + "range": true, + "instant": false, + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_worker_teardown_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_worker_teardown_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "worker teardown", + "range": true, + "instant": false, + "refId": "D" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_status_latency_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_status_latency_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "status latency", + "range": true, + "instant": false, + "refId": "E" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_result_download_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_result_download_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "result download", + "range": true, + "instant": false, + "refId": "F" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "s", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 40, + "showPoints": "never", + "stacking": { + "mode": "normal", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "End-to-end latency", + "id": 11, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Submission to the result in hand: what the caller actually waits.", + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 15 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.5, sum by (le) (lithops_call_end_to_end_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p50", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le) (lithops_call_end_to_end_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p95", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.99, sum by (le) (lithops_call_end_to_end_seconds_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p99", + "range": true, + "instant": false, + "refId": "C" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "s", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Memory", + "id": 12, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 23 + }, + "panels": [] + }, + { + "type": "timeseries", + "title": "Memory utilisation of the runtime", + "id": 13, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Peak memory over the memory the runtime is configured with. Well under 1 at p95 means the runtime is over-provisioned; near 1 means calls are close to being killed.", + "gridPos": { + "h": 8, + "w": 12, + "x": 0, + "y": 24 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.5, sum by (le) (lithops_worker_memory_utilization_ratio_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\", kind=\"peak\"}))", + "legendFormat": "p50", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le) (lithops_worker_memory_utilization_ratio_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\", kind=\"peak\"}))", + "legendFormat": "p95", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.99, sum by (le) (lithops_worker_memory_utilization_ratio_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\", kind=\"peak\"}))", + "legendFormat": "p99", + "range": true, + "instant": false, + "refId": "C" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "percentunit", + "decimals": 2, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "Memory per call, by kind", + "id": 14, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "peak is the high water mark of the task; baseline is that mark before the function started, so the difference is what the function itself cost.", + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 24 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum by (kind) (lithops_worker_memory_bytes_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum by (kind) (lithops_worker_memory_bytes_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "{{kind}}", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "bytes", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Data and storage", + "id": 15, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 32 + }, + "panels": [] + }, + { + "type": "timeseries", + "title": "Result size", + "id": 16, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "", + "gridPos": { + "h": 8, + "w": 8, + "x": 0, + "y": 33 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.5, sum by (le) (lithops_call_result_size_bytes_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p50", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.95, sum by (le) (lithops_call_result_size_bytes_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p95", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "histogram_quantile(0.99, sum by (le) (lithops_call_result_size_bytes_bucket{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}))", + "legendFormat": "p99", + "range": true, + "instant": false, + "refId": "C" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "bytes", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "Storage requests per call", + "id": 17, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "What the monitoring channel and the result reads cost against the storage backend. Zero status requests means a push channel.", + "gridPos": { + "h": 8, + "w": 8, + "x": 8, + "y": 33 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_status_queries_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_status_queries_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "status", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_call_result_queries_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_call_result_queries_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "result", + "range": true, + "instant": false, + "refId": "B" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "short", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "Worker network traffic", + "id": 18, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Cumulative for the life of the client process.", + "gridPos": { + "h": 8, + "w": 8, + "x": 16, + "y": 33 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum by (direction) (lithops_worker_network_bytes_total{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"})", + "legendFormat": "{{direction}}", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "bytes", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Client-side job preparation", + "id": 19, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 41 + }, + "panels": [] + }, + { + "type": "timeseries", + "title": "Time to prepare a job", + "id": 20, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "Everything the client does before the first worker exists.", + "gridPos": { + "h": 8, + "w": 12, + "x": 0, + "y": 42 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_job_partition_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_job_partition_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "partition", + "range": true, + "instant": false, + "refId": "A" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_job_serialize_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_job_serialize_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "serialize", + "range": true, + "instant": false, + "refId": "B" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum (lithops_job_create_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum (lithops_job_create_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "create (total)", + "range": true, + "instant": false, + "refId": "C" + }, + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum by (part) (lithops_job_upload_seconds_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum by (part) (lithops_job_upload_seconds_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "upload {{part}}", + "range": true, + "instant": false, + "refId": "D" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "s", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "timeseries", + "title": "Bytes uploaded per job, by part", + "id": 21, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "", + "gridPos": { + "h": 8, + "w": 12, + "x": 12, + "y": 42 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "sum by (part) (lithops_job_payload_bytes_sum{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}) / clamp_min(sum by (part) (lithops_job_payload_bytes_count{backend=~\"$backend\", runtime_name=~\"$runtime\", function_name=~\"$function\"}), 1)", + "legendFormat": "{{part}}", + "range": true, + "instant": false, + "refId": "A" + } + ], + "options": { + "legend": { + "displayMode": "table", + "placement": "bottom", + "showLegend": true, + "calcs": [ + "mean", + "max" + ] + }, + "tooltip": { + "mode": "multi", + "sort": "desc" + } + }, + "fieldConfig": { + "defaults": { + "unit": "bytes", + "decimals": null, + "custom": { + "drawStyle": "line", + "lineWidth": 2, + "fillOpacity": 0, + "showPoints": "never", + "stacking": { + "mode": "none", + "group": "A" + }, + "axisSoftMin": 0 + }, + "mappings": [], + "thresholds": { + "mode": "absolute", + "steps": [ + { + "color": "text", + "value": null + } + ] + } + }, + "overrides": [] + } + }, + { + "type": "row", + "title": "Execution environment", + "id": 22, + "collapsed": false, + "gridPos": { + "h": 1, + "w": 24, + "x": 0, + "y": 50 + }, + "panels": [] + }, + { + "type": "table", + "title": "Runtimes in use", + "id": 23, + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "description": "One row per execution environment Lithops has run in.", + "gridPos": { + "h": 8, + "w": 24, + "x": 0, + "y": 51 + }, + "targets": [ + { + "datasource": { + "type": "prometheus", + "uid": "${datasource}" + }, + "editorMode": "code", + "expr": "lithops_worker_info{backend=~\"$backend\", runtime_name=~\"$runtime\"}", + "legendFormat": "", + "range": false, + "instant": true, + "refId": "A" + } + ], + "transformations": [ + { + "id": "organize", + "options": { + "excludeByName": { + "Time": true, + "Value": true, + "__name__": true, + "job": true, + "service_name": true, + "service_namespace": true, + "service_version": true, + "host_name": true, + "telemetry_sdk_language": true, + "telemetry_sdk_name": true, + "telemetry_sdk_version": true + }, + "renameByName": { + "backend": "Compute backend", + "runtime_name": "Runtime", + "runtime_memory": "Runtime memory (MB)", + "python_version": "Python", + "lithops_version": "Lithops", + "instance": "Client", + "service_instance_id": "Client" + } + } + } + ], + "options": { + "showHeader": true, + "cellHeight": "sm" + }, + "fieldConfig": { + "defaults": { + "custom": { + "align": "auto" + } + }, + "overrides": [] + } + } + ] +} diff --git a/docs/source/lithops_config_keys.csv b/docs/source/lithops_config_keys.csv index 484c23da8..e7f4cfd0b 100644 --- a/docs/source/lithops_config_keys.csv +++ b/docs/source/lithops_config_keys.csv @@ -4,6 +4,8 @@ lithops;storage;`aws_s3`;no;Storage backend implementation. Default is AWS S3. 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_interval;`2`;no;Interval in seconds for monitoring checks (used if monitoring is set to **storage**). +lithops;telemetry;`False`;no;Client-side metrics exporter. Options: **False**, **prometheus** or **otlp**. See the Metrics and Telemetry section. +lithops;telemetry_interval;`10`;no;Interval in seconds between metric pushes (used if telemetry is enabled). 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 for functions in seconds. Functions exceeding this time are killed. Can also be set per call using the `timeout` parameter. lithops;include_modules;`[]`;no;List of dependencies to explicitly include for pickling. If empty, all required dependencies are included. If set to None, no dependencies are included. diff --git a/docs/source/metrics.rst b/docs/source/metrics.rst index 570d6e0b6..c84c8e2c5 100644 --- a/docs/source/metrics.rst +++ b/docs/source/metrics.rst @@ -1,57 +1,669 @@ -Prometheus Monitoring +Metrics and Telemetry ===================== -.. warning:: This feature is experimental and as such is unstable. Using it in production is discouraged. Expect errors and API/functionality changes in future releases. +Lithops already measures a great deal about every call it runs: how long the +function took, how long it waited to be scheduled, how much memory and CPU the +worker used, how much data it moved, whether the worker was cold, and how big +the result was. All of it comes back with the call status, and until the job +ends it lives only in the client process. -Lithops can send execution metrics to Prometheus for real-time monitoring purposes. -Currently, this feature works by using a Prometheus push gateway. +Telemetry turns those numbers into metrics, so a job can be watched while it +runs and compared against every job that ran before it. -Installation +.. code:: yaml + + lithops: + telemetry: prometheus + + +How it works ------------ -For testing purposes, the easiest way to get everything up is to use an Ubuntu VM and install the pre-compiled packages from the *apt* repository. +Metrics are produced entirely on the **client**. The worker writes its status +exactly as it always did; the monitor thread that reads the status feeds the +numbers into the exporter on its way past, and a background thread pushes what +has been aggregated every ``telemetry_interval`` seconds. -1. Install the Prometheus server: +Nothing is added to the critical path of a function, no worker needs a route to +the metrics system, and every monitoring backend — ``storage``, ``rabbitmq``, +``redis``, ``aws_sqs``, ``gcp_pubsub``, ``azure_queue`` — is instrumented by the +same code. -.. code:: +Two backends ship with Lithops: + +.. list-table:: + :header-rows: 1 + :widths: 15 85 + + * - Backend + - Use it when + * - ``prometheus`` + - There is a Prometheus Pushgateway, or you would rather not add the + OpenTelemetry SDK to the client. Lithops pushes to the gateway, which + Prometheus then scrapes. One small pure-Python dependency. + * - ``otlp`` + - Everything else, including Prometheus. Lithops exports over OTLP, which + Prometheus can receive directly, an OpenTelemetry collector can forward + to Prometheus over remote write, and a hosted service can take as it + is. No Pushgateway, and none of the caveats that come with one. - apt-get update - apt-get install prometheus -y +Both backends export the same metric names, so a dashboard written against one +works against the other, and switching is a one-line configuration change. -2. Install Prometheus Pushgateway module: +Install the dependencies with: .. code:: - apt-get install prometheus-pushgateway -y + pip install lithops[telemetry] + + +Enabling it +----------- + +``telemetry`` names the backend. ``true`` is accepted and selects +``prometheus``; the default is ``false``, and while telemetry is off the client +library of a backend is never even imported. + +.. list-table:: + :header-rows: 1 + :widths: 15 20 15 50 + + * - Group + - Key + - Default + - Additional info + * - lithops + - telemetry + - ``False`` + - Telemetry backend. One of ``False``, ``prometheus``, ``otlp``. + * - lithops + - telemetry_interval + - ``10`` + - Seconds between pushes. Metrics are also pushed once when the executor + is cleaned up and once when the process exits. + + +Prometheus +---------- + +Lithops is a client, not a server: it runs for as long as the job does, so +there is nothing for Prometheus to scrape. The Pushgateway exists for exactly +that. Lithops keeps a registry of cumulative metrics and replaces its +Pushgateway group with it on every push. + +Installing Prometheus and the Pushgateway +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +The quickest way to get all three services up, including Grafana: + +.. code:: yaml + + # docker-compose.yml + services: + pushgateway: + image: prom/pushgateway + ports: ["9091:9091"] + prometheus: + image: prom/prometheus + ports: ["9090:9090"] + volumes: ["./prometheus.yml:/etc/prometheus/prometheus.yml"] + grafana: + image: grafana/grafana + ports: ["3000:3000"] + +.. code:: yaml + + # prometheus.yml + global: + scrape_interval: 15s + scrape_configs: + - job_name: pushgateway + honor_labels: true # keep the job/instance labels Lithops pushes + static_configs: + - targets: ["pushgateway:9091"] + +``honor_labels: true`` matters: without it Prometheus overwrites the ``job`` +and ``instance`` labels of everything the gateway serves with the identity of +the gateway itself. Configuration +~~~~~~~~~~~~~ + +.. code:: yaml + + lithops: + telemetry: prometheus + + prometheus: + gateway: http://localhost:9091 + +.. list-table:: + :header-rows: 1 + :widths: 15 20 20 45 + + * - Group + - Key + - Default + - Additional info + * - prometheus + - gateway + - ``http://localhost:9091`` + - Pushgateway base URL, with the scheme and the port. + * - prometheus + - job + - ``lithops`` + - The ``job`` label of the pushed group. + * - prometheus + - instance + - the hostname + - The ``instance`` label of the pushed group. See the note below before + changing it. + * - prometheus + - username + - - + - Basic auth user, when the gateway is behind one. + * - prometheus + - password + - - + - Basic auth password, when the gateway is behind one. + * - prometheus + - timeout + - ``10`` + - Push timeout, in seconds. + +.. note:: + + A Pushgateway group never expires: it is served to Prometheus until + something deletes it. ``instance`` therefore defaults to the hostname + rather than to anything derived from the execution, so that a machine + reuses one group for every job it ever runs instead of leaving one behind + on every run. Set it explicitly only to something equally stable, and give + two Lithops clients running concurrently on the same host two different + values, or they will overwrite each other's group. + + +OpenTelemetry ------------- -Edit your config and enable the monitoring system by including the *telemetry* key in the lithops section: +.. code:: yaml + + lithops: + telemetry: otlp + + otlp: + endpoint: http://localhost:4318 + +Straight into Prometheus, without a collector +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ + +Prometheus can receive OTLP itself, which means the ``otlp`` backend reaches it +with no collector and no Pushgateway in between. Start Prometheus with +``--web.enable-otlp-receiver`` and point Lithops at its OTLP path: .. code:: yaml lithops: - telemetry: true + telemetry: otlp + + otlp: + endpoint: http://localhost:9090/api/v1/otlp + +This is the option to prefer for a new deployment. A Pushgateway group never +expires and has to be reasoned about; a push straight into Prometheus is +written to the TSDB and that is the end of it. The metric names Lithops +exports are already in Prometheus form, so they arrive unchanged. + +Trying it end to end, locally +~~~~~~~~~~~~~~~~~~~~~~~~~~~~~ -Add in your config a new section called *prometheus* with the following keys: +Grafana publishes a single container that is an entire OpenTelemetry backend — +collector, Prometheus, Loki, Tempo and Grafana — meant for exactly this. It is +a development image, not a production one. .. code:: yaml - prometheus: - apigateway: + # docker-compose.yml + services: + lgtm: + image: grafana/otel-lgtm + ports: + - "4318:4318" # OTLP/HTTP, where Lithops pushes + - "3000:3000" # Grafana + +.. code:: + + pip install lithops[telemetry] + docker compose up -d + +Point a localhost executor at it, so that nothing leaves the machine: + +.. code:: yaml + + lithops: + backend: localhost + storage: localhost + telemetry: otlp + telemetry_interval: 5 + + otlp: + endpoint: http://localhost:4318 + +.. code:: python + + import lithops + + def double(x): + return x * 2 + + with lithops.FunctionExecutor() as fexec: + fexec.map(double, range(20)) + print(fexec.get_result()) +Open Grafana on http://localhost:3000, pick the Prometheus datasource, and the +metrics are there within a ``telemetry_interval``. ``lithops_calls_completed_total`` +is the one to check first; ``lithops_worker_info`` shows the runtime the calls +ran in. + +Prometheus on its own +~~~~~~~~~~~~~~~~~~~~~ + +Leaner, if the dashboards are not the point yet: + +.. code:: yaml + + # docker-compose.yml + services: + prometheus: + image: prom/prometheus + command: + - --config.file=/etc/prometheus/prometheus.yml + - --web.enable-otlp-receiver + ports: ["9090:9090"] + volumes: ["./prometheus.yml:/etc/prometheus/prometheus.yml"] + +.. code:: yaml + + # prometheus.yml + storage: + tsdb: + # Pushed metrics do not arrive in the order Prometheus scrapes in + out_of_order_time_window: 30m + otlp: + promote_resource_attributes: + - service.instance.id + - service.name + +.. code:: yaml + + lithops: + telemetry: otlp + otlp: + endpoint: http://localhost:9090/api/v1/otlp + +Lithops sets ``service.name`` and ``service.instance.id``, which Prometheus +turns into the ``job`` and ``instance`` labels — the same identity the metrics +would have had through the Pushgateway. + +Through a collector +~~~~~~~~~~~~~~~~~~~ + +The collector is worth the extra hop when Lithops is one workload among many, +or when the same metrics have to reach more than one destination: + +.. code:: yaml + + # otel-collector-config.yaml + receivers: + otlp: + protocols: + http: + endpoint: 0.0.0.0:4318 + exporters: + prometheusremotewrite: + endpoint: http://prometheus:9090/api/v1/write + service: + pipelines: + metrics: + receivers: [otlp] + exporters: [prometheusremotewrite] + +Prometheus needs ``--web.enable-remote-write-receiver`` for that endpoint. .. list-table:: :header-rows: 1 + :widths: 15 20 20 45 * - Group - Key - Default - - Optional - - Additional Info - * - prometheus - - apigateway - - ``None`` - - No - - Prometheus apigateway endpoint. Make sure to use the ``http://`` prefix and the corresponding port. For example: ``http://localhost:9091`` + - Additional info + * - otlp + - endpoint + - ``http://localhost:4318`` + - Collector endpoint. For ``http/protobuf`` the ``/v1/metrics`` path is + appended if it is not already there. + * - otlp + - protocol + - ``http/protobuf`` + - One of ``http/protobuf``, ``grpc``. ``grpc`` additionally needs the + ``opentelemetry-exporter-otlp-proto-grpc`` package. + * - otlp + - service_name + - ``lithops`` + - The ``service.name`` resource attribute. + * - otlp + - instance + - the hostname + - The ``host.name`` resource attribute. + * - otlp + - headers + - ``{}`` + - Extra headers, which is where the authentication of a hosted collector + goes. + * - otlp + - timeout + - ``10`` + - Export timeout, in seconds. + + +What is exported +---------------- + +Counters are exported without the ``_total`` suffix; Prometheus and +OpenTelemetry both add it themselves. + +.. list-table:: + :header-rows: 1 + :widths: 42 12 46 + + * - Metric + - Type + - What it measures + * - ``lithops_jobs_submitted_total`` + - counter + - Jobs handed to the compute backend. + * - ``lithops_calls_invoked_total`` + - counter + - Function calls handed to the compute backend. + * - ``lithops_calls_started_total`` + - counter + - Calls the client has seen start running. + * - ``lithops_calls_completed_total`` + - counter + - Calls that reached a final state, by ``outcome``: ``success``, + ``failure``, ``timeout`` or ``chained``. + * - ``lithops_cold_starts_total`` + - counter + - Calls that ran in a cold worker. + * - ``lithops_worker_cpu_seconds_total`` + - counter + - CPU time consumed by the function, by ``mode``: ``user`` or ``system``. + * - ``lithops_worker_network_bytes_total`` + - counter + - Network traffic of the function, by ``direction``: ``sent`` or ``recv``. + * - ``lithops_call_duration_seconds`` + - histogram + - Wall clock time spent inside the user function. + * - ``lithops_call_total_duration_seconds`` + - histogram + - Wall clock time the worker spent on the call, Lithops overhead included. + * - ``lithops_call_queue_delay_seconds`` + - histogram + - Submission to worker start. The scheduling latency of the backend. + * - ``lithops_call_worker_setup_seconds`` + - histogram + - Worker start to the user function starting: unpacking the job, + importing the modules, fetching the data. + * - ``lithops_call_worker_teardown_seconds`` + - histogram + - User function returning to the worker finishing: writing the result and + reporting the status. + * - ``lithops_call_status_latency_seconds`` + - histogram + - Worker finish to client notice. The latency of the monitoring channel. + * - ``lithops_call_result_download_seconds`` + - histogram + - Client notice to the client holding the result, by ``source``: + ``inline`` (the result travelled in the call status, no request needed) + or ``storage`` (it had to be fetched). + * - ``lithops_call_result_queries`` + - histogram + - Storage requests the client made to get one result. Zero for an inline + result. + * - ``lithops_call_end_to_end_seconds`` + - histogram + - Submission to the result in hand. The number the user actually feels — + every other timing above is a slice of this one. + * - ``lithops_call_result_size_bytes`` + - histogram + - Size of the value the function returned. + * - ``lithops_call_result_upload_seconds`` + - histogram + - Time the worker spent writing the result to storage. Zero for a result + small enough to travel in the call status. + * - ``lithops_call_status_queries`` + - histogram + - Storage requests the client made to learn the status of one call — what + the monitoring channel costs against storage. Zero for the channels + that push. + * - ``lithops_worker_memory_bytes`` + - histogram + - Memory of the worker, by ``kind``: ``peak``, ``baseline``, ``rss``, + ``vms``, ``uss``. See the note below. + * - ``lithops_worker_memory_utilization_ratio`` + - histogram + - Memory over the memory the runtime was configured with, by ``kind``: + ``peak`` or ``rss``. + * - ``lithops_worker_cpu_utilization_percent`` + - histogram + - CPU utilisation of the worker while the function ran. + * - ``lithops_worker_info`` + - gauge + - Always 1. Carries ``python_version`` and ``lithops_version`` as labels, + alongside ``backend``, ``runtime_name`` and ``runtime_memory``. + * - ``lithops_job_calls`` + - histogram + - How many calls a job is made of. + * - ``lithops_job_create_seconds`` + - histogram + - Everything the client did before the first worker was invoked. + * - ``lithops_job_serialize_seconds`` + - histogram + - Of that, the time spent serialising the function and its data. + * - ``lithops_job_partition_seconds`` + - histogram + - Of that, the time spent partitioning the input, for a job that + processes objects. + * - ``lithops_job_upload_seconds`` + - histogram + - Of that, the time spent uploading, by ``part``: ``function`` or + ``data``. Zero for a function already in the cache. + * - ``lithops_job_payload_bytes`` + - histogram + - Size of what the client uploaded, by ``part``: ``function`` or ``data``. + +.. note:: + + The five kinds of ``lithops_worker_memory_bytes`` answer different + questions, and it is worth knowing which one to look at. + + ``peak`` is the high water mark of the whole task, taken from + ``getrusage``, and it is the number an out-of-memory kill is measured + against — this is the one to size a runtime by. ``baseline`` is that same + mark taken before the function started, so it is what the runtime itself + costs before any user code runs, and ``peak - baseline`` is what the + function added. ``rss``, ``vms`` and ``uss`` are single samples taken as + the function returns, useful for the shape of the memory but not for the + ceiling. ``peak`` and ``baseline`` are absent on workers that are not Unix. + +.. note:: + + The timing metrics decompose one call end to end, so a stacked graph of + them accounts for every second of ``lithops_call_end_to_end_seconds``:: + + host_submit ──┬── queue_delay ──── the backend scheduling the call + │ + worker_start ─┼── worker_setup ─── unpack, import, fetch data + │ + func_start ───┼── duration ─────── the user function + │ + func_end ─────┼── worker_teardown ─ write the result, report + │ + worker_end ───┼── status_latency ── the monitoring channel + │ + status_done ──┼── result_download ─ fetching what it returned + │ + result_done ──┘ + + ``lithops_call_total_duration_seconds`` is the worker's share of that + (setup + duration + teardown), which is the part a FaaS backend bills for. + ``result_download`` is only recorded for the calls whose result is actually + read: a job whose results are never fetched has none. + +Every metric carries the same four labels, plus the one its own dimension adds. +``lithops_worker_info`` is the exception: it deliberately leaves out +``function_name``, because it describes what a runtime *is* rather than what +ran on it. + + + +.. list-table:: + :header-rows: 1 + :widths: 22 78 + + * - Label + - Value + * - ``backend`` + - The compute backend the job ran on, e.g. ``aws_lambda``. + * - ``runtime_name`` + - The runtime the job ran in. + * - ``runtime_memory`` + - The memory the runtime was configured with, in MB. + * - ``function_name`` + - The name of the function that was mapped. + +.. note:: + + There is deliberately no ``job_id``, ``call_id`` or ``activation_id`` + label. Every distinct combination of label values is a separate time + series, and Lithops runs jobs of tens of thousands of calls: a per-call + label would mean a series per call, kept for ever. The label set is + therefore bounded by how many distinct functions and runtimes are executed, + not by how much work is done — which is what lets a 100,000 call job be + summarised by ``histogram_quantile`` in a single query. + + Per-call detail is not lost. It is in the call status, which the client + keeps, and which ``fexec.plot()`` and ``fexec.job_summary()`` render. + + +Querying it +----------- + +.. note:: + + A Lithops client is a script, not a service. Its counters live for as + long as the process does and start again from zero in the next run, so + ``rate()`` over a five minute window is zero for most of the window and + meaningless for the rest. Read the counters as they stand instead — + ``sum(x)`` for a total, ``sum(x_sum) / sum(x_count)`` for a mean, + ``histogram_quantile(q, sum by (le) (x_bucket))`` for a percentile. + ``rate()`` comes into its own only for a long-lived client. + +.. code:: + + # Calls completed, by outcome + sum by (outcome) (lithops_calls_completed_total) + + # Calls still in flight + sum(lithops_calls_invoked_total) - sum(lithops_calls_completed_total) + + # Failure rate + sum(lithops_calls_completed_total{outcome!="success"}) + / sum(lithops_calls_completed_total) + + # Cold start rate + sum(lithops_cold_starts_total) / sum(lithops_calls_completed_total) + + # p95 execution time + histogram_quantile(0.95, + sum by (le, function_name) (lithops_call_duration_seconds_bucket)) + + # End-to-end latency as the caller feels it, p95 + histogram_quantile(0.95, + sum by (le, function_name) (lithops_call_end_to_end_seconds_bucket)) + + # Scheduling latency of the backend, p95 + histogram_quantile(0.95, + sum by (le, backend) (lithops_call_queue_delay_seconds_bucket)) + + # Runtimes that are over-provisioned: p95 peak memory well under 1. + # Use kind="peak" — summing across the kinds mixes two distributions + histogram_quantile(0.95, + sum by (le, runtime_name, runtime_memory) + (lithops_worker_memory_utilization_ratio_bucket{kind="peak"})) + + # What the runtime costs before any user code runs + sum by (runtime_name) (lithops_worker_memory_bytes_sum{kind="baseline"}) + / sum by (runtime_name) (lithops_worker_memory_bytes_count{kind="baseline"}) + + # Mean time per call in one phase, e.g. what the client spent preparing + sum(lithops_job_create_seconds_sum) / sum(lithops_job_create_seconds_count) + + # What the monitoring channel costs against the storage backend, + # in requests per call. Zero means a channel that pushes + sum(lithops_call_status_queries_sum) / sum(lithops_call_status_queries_count) + + # How often a result was small enough to skip storage entirely + sum(lithops_call_result_download_seconds_count{source="inline"}) + / sum(lithops_call_result_download_seconds_count) + + # Worker seconds, the billed part of a call, split by the memory the + # runtime was given. PromQL cannot turn the runtime_memory label into + # a number, so multiply the two columns in Grafana for GB-seconds + sum by (function_name, runtime_memory) ( + lithops_call_total_duration_seconds_sum) + + # The execution environments in use, for an "environment" panel + count by (backend, runtime_name, runtime_memory, python_version, + lithops_version) (lithops_worker_info) + + +A ready-made Grafana dashboard +------------------------------ + +``docs/source/grafana/lithops-dashboard.json`` is the dashboard these +queries add up to: an overview row, throughput and latency, the phase +decomposition of a call, memory, storage, client-side job preparation, and +a table of the execution environments. It has ``backend``, ``runtime`` and +``function`` template variables, and asks for the Prometheus datasource on +import. + +In Grafana: **Dashboards → New → Import → Upload JSON file**, then pick the +Prometheus datasource. Or over the API: + +.. code:: + + curl -u admin:admin -H 'Content-Type: application/json' \ + -X POST http://localhost:3000/api/dashboards/db \ + -d "{\"dashboard\": $(cat docs/source/grafana/lithops-dashboard.json), \ + \"overwrite\": true}" + +Two panels stay empty on the localhost backend, and correctly so: memory +utilisation needs a ``runtime_memory`` to divide by, and the partitioning +time only exists for a job that processes objects. + + +Troubleshooting +--------------- + +**Nothing arrives.** Metrics are pushed every ``telemetry_interval`` seconds, +so a job that finishes in less than that is only visible after the push that +the executor makes on cleanup. Raise the log level to ``DEBUG``: the exporter +logs the backend it started with and every push it could not make. + +**Metrics arrive but Prometheus shows the gateway's own labels.** Set +``honor_labels: true`` on the scrape config. + +**Telemetry never breaks a job.** A metrics system that is misconfigured or +unreachable is logged and switched off, not raised. If telemetry seems to be +doing nothing at all, ``DEBUG`` will say why. diff --git a/docs/source/monitoring.rst b/docs/source/monitoring.rst index 98eea8c31..9425d58b9 100644 --- a/docs/source/monitoring.rst +++ b/docs/source/monitoring.rst @@ -215,3 +215,11 @@ Azure Queue Storage 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. + + +Metrics +------- + +The statuses the monitor reads carry everything the worker measured about a call. Whichever backend delivers them, +those numbers can be exported to Prometheus or to an OpenTelemetry collector as they arrive, so that jobs can be +watched while they run and compared over time. See :doc:`metrics`. diff --git a/lithops/config.py b/lithops/config.py index f25a2844c..9168ac407 100644 --- a/lithops/config.py +++ b/lithops/config.py @@ -262,6 +262,7 @@ def default_config( config_data['lithops'].setdefault(key, value) _load_monitoring_backend_config(config_data) + _load_telemetry_backend_config(config_data) return config_data @@ -286,6 +287,24 @@ def _load_monitoring_backend_config(config_data): module.load_config(config_data) +def _load_telemetry_backend_config(config_data): + """ + Lets the config module of the telemetry backend fill in its own + defaults. A no-op when telemetry is off, which is the default: the + client library of a backend nobody asked for is never imported + """ + from lithops.telemetry import load_backend_config, resolve_backend + + telemetry = resolve_backend(config_data) + config_data['lithops']['telemetry'] = telemetry or False + if telemetry is None: + return + try: + load_backend_config(config_data) + except ValueError as exc: + raise Exception(str(exc)) from exc + + 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/constants.py b/lithops/constants.py index 02356113d..9062a6046 100644 --- a/lithops/constants.py +++ b/lithops/constants.py @@ -93,6 +93,8 @@ def _in_temp(*parts): LITHOPS_DEFAULT_CONFIG_KEYS = { 'monitoring': 'storage', 'monitoring_interval': 2, + 'telemetry': False, + 'telemetry_interval': 10, 'execution_timeout': 1800 } diff --git a/lithops/future.py b/lithops/future.py index 0e6a740f1..4cd6261a6 100644 --- a/lithops/future.py +++ b/lithops/future.py @@ -33,6 +33,7 @@ create_job_key ) from lithops.constants import FN_LOG_FILE, LOGS_DIR +from lithops.telemetry.metrics import SOURCE_INLINE, SOURCE_STORAGE from lithops.utils import log_prefix logger = logging.getLogger(__name__) @@ -85,6 +86,7 @@ def __init__(self, call_id, job, job_metadata, storage_config): self.execution_timeout = job.execution_timeout self.runtime_name = job.runtime_name self.runtime_memory = job.runtime_memory + self.backend = getattr(job, 'backend', None) self.activation_id = None self.stats = {} self.logs = None @@ -348,6 +350,23 @@ def _resolve_new_futures(self) -> None: else: self._new_futures = new_futures + def _record_result_stats(self, source: str, query_count: int) -> None: + """ + Records the arrival of the result. + + The monitor measures everything up to the call being done; this is + the only part of it that happens afterwards, so it is the only + part the monitor cannot report. The telemetry of the process is + looked up rather than held, so that a future stays as picklable as + it was: a worker pickles one whenever a function returns futures + """ + self.stats['host_result_done_tstamp'] = time.time() + self.stats['host_result_query_count'] = query_count + + from lithops.telemetry import current_telemetry + + current_telemetry(self.backend).on_result_read(self, source) + def _read_inline_result(self) -> None: """ Takes the result the worker embedded in the status, which saves the @@ -356,8 +375,7 @@ def _read_inline_result(self) -> None: self._call_output = _pickle_from_encoded( self._call_status['result'] ) - self.stats['host_result_done_tstamp'] = time.time() - self.stats['host_result_query_count'] = 0 + self._record_result_stats(SOURCE_INLINE, 0) logger.debug( f'{self._id_prefix()} - Got output from call ' f'{self.call_id} - Activation ID: {self.activation_id}' @@ -523,8 +541,9 @@ def result( return None self._call_output = pickle.loads(call_output) - self.stats['host_result_done_tstamp'] = time.time() - self.stats['host_result_query_count'] = self._output_query_count + self._record_result_stats( + SOURCE_STORAGE, self._output_query_count + ) logger.debug( f'{self._id_prefix()} - Got output from call ' f'{self.call_id} - Activation ID: {self.activation_id}' diff --git a/lithops/invokers.py b/lithops/invokers.py index 78fefdc00..c7ef97d1c 100644 --- a/lithops/invokers.py +++ b/lithops/invokers.py @@ -44,7 +44,7 @@ SA_INSTALL_DIR, STANDALONE_BACKENDS ) -from lithops.util.metrics import PrometheusExporter +from lithops.telemetry import get_telemetry logger = logging.getLogger(__name__) @@ -147,12 +147,9 @@ def __init__( self.is_lithops_worker = is_lithops_worker() self.job_monitor = job_monitor - prom_enabled = self.config['lithops'].get('telemetry', False) - prom_config = self.config.get('prometheus', {}) - self.prometheus = PrometheusExporter(prom_enabled, prom_config) - self.mode = self.config['lithops']['mode'] self.backend = self.config['lithops']['backend'] + self.telemetry = get_telemetry(self.config, self.backend) self.include_function = self.config[self.backend].get( 'runtime_include_function', False ) @@ -247,27 +244,6 @@ def _create_payload(self, job): 'worker_processes': job.worker_processes } - def _send_job_metrics(self, job): - """ - Reports the size of the job to Prometheus, if telemetry is enabled - """ - labels = ( - ('job_id', job.job_key), - ('function_name', job.function_name), - ) - self.prometheus.send_metric( - name='job_total_calls', - value=job.total_calls, - type='counter', - labels=labels, - ) - self.prometheus.send_metric( - name='job_runtime_memory', - value=job.runtime_memory or 0, - type='counter', - labels=labels, - ) - def _build_futures(self, job): """ Creates one future per call of the job, already marked as invoked @@ -306,7 +282,10 @@ def _run_job(self, job): f'{job.total_calls} activations' ) - self._send_job_metrics(job) + # After the runtime is settled, so that the job is measured under + # the runtime it actually runs on + job.runtime_name = self.runtime_name + self.telemetry.on_job_submitted(job) if self.backend not in STANDALONE_BACKENDS: logger.debug( @@ -315,7 +294,6 @@ def _run_job(self, job): ) try: - job.runtime_name = self.runtime_name self._invoke_job(job) except (KeyboardInterrupt, Exception): self.stop() diff --git a/lithops/job/job.py b/lithops/job/job.py index da2702161..7684e9772 100644 --- a/lithops/job/job.py +++ b/lithops/job/job.py @@ -509,6 +509,7 @@ def _create_job( if execution_timeout is None else execution_timeout ) + job.backend = backend job.executor_id = executor_id job.job_id = job_id job.job_key = create_job_key(job.executor_id, job.job_id) diff --git a/lithops/monitoring/backends/storage/storage.py b/lithops/monitoring/backends/storage/storage.py index 735955afe..e3fb7f8a7 100644 --- a/lithops/monitoring/backends/storage/storage.py +++ b/lithops/monitoring/backends/storage/storage.py @@ -125,7 +125,7 @@ def _tag_future_as_running(self, callids_running): 'activation_id': call[1], 'worker_start_tstamp': current_time, } - f._set_running(call_status) + self._mark_running(f, call_status) self.callids_running_processed_timeout.update(to_process) self._future_timeout_checker() @@ -173,7 +173,7 @@ def get_status(f): f._status_query_count += 1 if cs: if not self._check_new_futures(cs, f): - f._set_ready(cs) + self._mark_ready(f, cs) return _future_id(f) return None diff --git a/lithops/monitoring/job_monitor.py b/lithops/monitoring/job_monitor.py index 088b2f13e..0fdf6d719 100644 --- a/lithops/monitoring/job_monitor.py +++ b/lithops/monitoring/job_monitor.py @@ -18,6 +18,7 @@ import queue from lithops.monitoring.backends import load_backend_attr, resolve_backend +from lithops.telemetry import get_telemetry from lithops.utils import log_prefix logger = logging.getLogger(__name__) @@ -62,6 +63,11 @@ def __init__( self.monitor = None self.job_chunksize = {} + # Metrics are produced from the statuses the monitor reads, so the + # telemetry of the executor is resolved here and handed to every + # monitor thread this object spawns. NOOP when telemetry is off + self.telemetry = get_telemetry(config) + self.MonitorClass = load_backend_attr( self.type, 'MonitoringBackend' ) @@ -114,6 +120,9 @@ def _spawn_monitor(self, generate_tokens): generate_tokens=generate_tokens, config=monitor_config ) + # Attached before the caller adds any future, so that no status + # can reach the monitor while it is still pointing at the no-op + self.monitor.attach_telemetry(self.telemetry) def _thread_finished(self): """ @@ -184,6 +193,12 @@ def cleanup(self): Deletes queues, keys or other backend resources of this executor, once the thread that consumes from them has wound down """ + # The executor is done with, so what has been measured is pushed + # now rather than on the next tick of the flush timer. The + # exporter itself outlives the executor: it belongs to the + # process, and another executor may still be running + self.telemetry.flush() + if self.monitor is None: return self.monitor.stop() diff --git a/lithops/monitoring/monitor.py b/lithops/monitoring/monitor.py index 6db77ad1f..c7b319897 100644 --- a/lithops/monitoring/monitor.py +++ b/lithops/monitoring/monitor.py @@ -24,6 +24,8 @@ from tblib import pickling_support +from lithops.telemetry import NOOP as NOOP_TELEMETRY +from lithops.telemetry.metrics import OUTCOME_CHAINED, OUTCOME_TIMEOUT from lithops.utils import _future_id, log_prefix, monitoring_queue_name # _future_timeout_checker() pickles sys.exc_info() so that the client can @@ -102,6 +104,12 @@ class Monitor(threading.Thread): #: How many statuses that arrived before their future may be held MAX_HELD_STATUS = 100_000 + #: Where the metrics of every call go. A class attribute, so that a + #: monitor nobody attached telemetry to is safe rather than broken, + #: and so that a backend that forgets to call super().__init__() does + #: not turn into an AttributeError on the first status + telemetry = NOOP_TELEMETRY + def __init_subclass__(cls, abstract: bool = False, **kwargs): """ Checks the backend contract as soon as the class is defined, so that @@ -324,6 +332,38 @@ def cleanup(self): self._cleaned = True self._delete_resources() + def attach_telemetry(self, telemetry): + """ + Points the monitor at the telemetry of its executor. Called by + :class:`~lithops.monitoring.JobMonitor` right after the monitor is + built, before any future is added to it + """ + self.telemetry = telemetry + + def _mark_running(self, future, call_status): + """ + Moves a future to running and measures it. + + Every state change of a future goes through this method or + through :meth:`_mark_ready`, and both are called from behind the + guard that makes the transition happen at most once. A message + service that redelivers a status, or a storage sweep that reads + one the channel already delivered, therefore counts once + """ + future._set_running(call_status) + self.telemetry.on_call_started(future, call_status) + + def _mark_ready(self, future, call_status, outcome=None): + """ + Moves a future to ready and measures it. ``outcome`` is derived + from the status when the caller does not know better + + Measured after the transition, so that the timestamp the future + records for the arrival of the status is part of what is measured + """ + future._set_ready(call_status) + self.telemetry.on_call_finished(future, call_status, outcome) + def _all_ready(self): """ Checks if all futures are ready, success or done @@ -338,6 +378,11 @@ def _check_new_futures(self, call_status, f): return False f._set_futures(call_status) + # A call that returned futures produced no result of its own. It + # is counted here, once, under its own outcome, so that it is + # neither missing from the totals nor mixed in with the calls + # that did return something + self.telemetry.on_call_finished(f, call_status, OUTCOME_CHAINED) self.add_futures(f._new_futures) logger.debug( f'{log_prefix(self.executor_id)} - Received {len(f._new_futures)} ' @@ -380,7 +425,7 @@ def _future_timeout_checker(self, futures=None): 'worker_start_tstamp': start_tstamp, 'worker_end_tstamp': time.time(), } - fut._set_ready(call_status) + self._mark_ready(fut, call_status, OUTCOME_TIMEOUT) def _print_status_log(self, force=False): """ @@ -527,7 +572,7 @@ def _tag_future_as_running(self, call_status): if future is None: return False if not _is_started(future): - future._set_running(call_status) + self._mark_running(future, call_status) return True def _tag_future_as_ready(self, call_status): @@ -540,7 +585,7 @@ def _tag_future_as_ready(self, call_status): return False if not _is_finished(future): if not self._check_new_futures(call_status, future): - future._set_ready(call_status) + self._mark_ready(future, call_status) return True def _generate_tokens(self, call_status): @@ -626,7 +671,7 @@ def _storage_sweep(self): if not call_status: continue if not self._check_new_futures(call_status, future): - future._set_ready(call_status) + self._mark_ready(future, call_status) recovered += 1 if self.generate_tokens and 'activation_id' in call_status: self._generate_tokens(call_status) diff --git a/lithops/monitoring/status.py b/lithops/monitoring/status.py index ab83ac070..1e62d6f94 100644 --- a/lithops/monitoring/status.py +++ b/lithops/monitoring/status.py @@ -25,7 +25,11 @@ 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 +from lithops.utils import ( + CURRENT_PY_VERSION, + monitoring_queue_name, + sizeof_fmt, +) logger = logging.getLogger(__name__) @@ -130,7 +134,8 @@ def __init__(self, job: SimpleNamespace, internal_storage): self.status = { 'exception': False, 'activation_id': os.environ.get('__LITHOPS_ACTIVATION_ID'), - 'python_version': os.environ.get("PYTHON_VERSION"), + 'python_version': os.environ.get('PYTHON_VERSION') + or CURRENT_PY_VERSION, 'worker_start_tstamp': job.start_tstamp, 'host_submit_tstamp': job.host_submit_tstamp, 'call_id': job.call_id, diff --git a/lithops/telemetry/__init__.py b/lithops/telemetry/__init__.py new file mode 100644 index 000000000..3b7e4d72b --- /dev/null +++ b/lithops/telemetry/__init__.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. +# + +""" +Client-side telemetry. + +Lithops already measures a great deal about every call and reports it in +the call status. This package aggregates those numbers as they arrive and +ships them to a metrics system, so that a job can be watched and compared +over time instead of only summarised once it ends. + +Backends live under :mod:`lithops.telemetry.backends` and are imported on +demand, so only the client library of the configured one is ever loaded. +""" + +from lithops.telemetry.backend import MetricsBackend +from lithops.telemetry.backends import DEFAULT_BACKEND, resolve_backend +from lithops.telemetry.exporter import ( + NOOP, + BoundTelemetry, + TelemetryExporter, + current_telemetry, + default_instance_id, + get_telemetry, + load_backend_config, + shutdown_telemetry, +) + +__all__ = [ + 'DEFAULT_BACKEND', + 'NOOP', + 'BoundTelemetry', + 'MetricsBackend', + 'TelemetryExporter', + 'current_telemetry', + 'default_instance_id', + 'get_telemetry', + 'load_backend_config', + 'resolve_backend', + 'shutdown_telemetry', +] diff --git a/lithops/telemetry/backend.py b/lithops/telemetry/backend.py new file mode 100644 index 000000000..d496b9677 --- /dev/null +++ b/lithops/telemetry/backend.py @@ -0,0 +1,110 @@ +# +# 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. +# + +""" +The contract a telemetry backend implements. + +A backend owns an aggregator (a Prometheus registry, an OpenTelemetry +meter provider) and knows how to get what it has aggregated out of the +process. It never decides *what* is measured: that is +:mod:`lithops.telemetry.metrics`. +""" + +import logging +import threading +from abc import ABC, abstractmethod +from typing import Any, Dict, Optional + +from lithops.telemetry.metrics import MetricSpec + +logger = logging.getLogger(__name__) + + +class MetricsBackend(ABC): + """ + Aggregates observations and ships them somewhere. + + Backends are instantiated with the section of the Lithops + configuration named after them, already filled in with the defaults + their ``config.py`` declares. + + Implementations only have to build their instruments and push. The + exporter above them takes care of never calling into a backend with + labels the spec does not declare, and of swallowing whatever a + backend raises: telemetry never breaks a job. + """ + + #: Config section this backend reads, and the value ``telemetry:`` + #: selects it by. Derived from the package name in + #: :mod:`lithops.telemetry.backends` + backend_name: Optional[str] = None + + def __init__(self, config: Dict[str, Any]): + self.config = config + # Instruments are built on first use from the monitor thread and + # from the threads that submit jobs, so the cache is locked. The + # underlying client libraries are themselves thread safe once the + # instrument exists; this only guards the creation + self._instruments: Dict[str, Any] = {} + self._instruments_lock = threading.Lock() + + def _instrument(self, spec: MetricSpec) -> Any: + """ + The instrument of ``spec``, built once and cached + """ + instrument = self._instruments.get(spec.name) + if instrument is not None: + return instrument + with self._instruments_lock: + # Checked again: two threads can get past the fast path + if spec.name not in self._instruments: + self._instruments[spec.name] = self._create_instrument(spec) + return self._instruments[spec.name] + + @abstractmethod + def _create_instrument(self, spec: MetricSpec) -> Any: + """ + Builds the backend instrument that records ``spec`` + """ + + @abstractmethod + def observe( + self, + spec: MetricSpec, + value: float, + labels: Dict[str, str], + ) -> None: + """ + Records one observation. ``labels`` holds exactly the keys of + ``spec.labelnames`` + """ + + def flush(self) -> None: + """ + Gets what has been aggregated so far out of the process. Called on + a timer by the exporter, and once more on shutdown + """ + + def shutdown(self) -> None: + """ + Gets the last of what has been aggregated out of the process and + releases whatever the backend holds. Called once. + + The default is a plain flush, which is all a backend that holds + nothing has to do. One that does override it, and are then + responsible for the final flush themselves: exporting twice on the + way out is how a client library ends up logging about a batch it + can no longer send + """ + self.flush() diff --git a/lithops/telemetry/backends/__init__.py b/lithops/telemetry/backends/__init__.py new file mode 100644 index 000000000..3f2ab76dd --- /dev/null +++ b/lithops/telemetry/backends/__init__.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. +# + +""" +Telemetry backends. + +Each backend is a package named after the system it ships metrics to +(``prometheus``, ``otlp``). It must export ``MetricsBackend`` -- a +:class:`~lithops.telemetry.backend.MetricsBackend` subclass -- and carry +a ``config.py`` with a ``load_config(config_data)`` function that fills +in the defaults of its own configuration section. + +The name of the package is the name of that section and the value +``lithops.telemetry`` selects it by. +""" + +import importlib +from typing import Any, Dict, Optional + +#: Backend used when telemetry is switched on without naming one +DEFAULT_BACKEND = 'prometheus' + +#: Values of ``lithops.telemetry`` that mean "off". Written out because a +#: config file that says ``telemetry: false`` parses to the bool, one that +#: says ``telemetry: "false"`` to the string, and both mean the same thing +_DISABLED = frozenset({'', 'false', 'no', 'none', 'off', '0'}) + +#: Values that mean "on, backend unspecified" +_ENABLED = frozenset({'true', 'yes', 'on', '1'}) + + +def resolve_backend( + config: Optional[Dict[str, Any]] = None, + backend: Optional[str] = None, +) -> Optional[str]: + """ + Name of the telemetry backend to use, or None when telemetry is off. + + ``backend`` wins over ``config['lithops']['telemetry']``. A truthy + value that does not name a backend selects :data:`DEFAULT_BACKEND`, + so that ``telemetry: true`` keeps working as the switch it reads like + """ + value = backend + if value is None and config: + value = (config.get('lithops') or {}).get('telemetry') + + if value is None or value is False: + return None + if value is True: + return DEFAULT_BACKEND + + value = str(value).strip().lower() + if value in _DISABLED: + return None + if value in _ENABLED: + return DEFAULT_BACKEND + return value + + +def import_backend_module(backend: str, submodule: Optional[str] = None): + """ + Imports ``lithops.telemetry.backends.`` or one of its + submodules. + + Raises ValueError only when the backend itself is not there. A + backend whose client library is missing keeps its own ImportError, + which names the package to install instead of claiming the backend is + unknown. + """ + module_name = f'lithops.telemetry.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 telemetry backend: {backend}') from exc + + +def load_backend_class(backend: str): + """ + Returns the ``MetricsBackend`` class of ``backend``, checked against + the contract so that a package that exports the wrong thing fails + here rather than halfway through a job + """ + from lithops.telemetry.backend import MetricsBackend + + module = import_backend_module(backend) + try: + cls = module.MetricsBackend + except AttributeError as exc: + raise ValueError( + f"Telemetry backend '{backend}' exports no MetricsBackend" + ) from exc + + if not (isinstance(cls, type) and issubclass(cls, MetricsBackend)): + raise ValueError( + f"Telemetry backend '{backend}' exports MetricsBackend={cls!r}, " + f"which is not a MetricsBackend subclass" + ) + if cls.backend_name is None: + cls.backend_name = backend + return cls diff --git a/lithops/telemetry/backends/otlp/__init__.py b/lithops/telemetry/backends/otlp/__init__.py new file mode 100644 index 000000000..3c2bf6cf6 --- /dev/null +++ b/lithops/telemetry/backends/otlp/__init__.py @@ -0,0 +1,3 @@ +from lithops.telemetry.backends.otlp.otlp import MetricsBackend + +__all__ = ['MetricsBackend'] diff --git a/lithops/telemetry/backends/otlp/config.py b/lithops/telemetry/backends/otlp/config.py new file mode 100644 index 000000000..ce3775765 --- /dev/null +++ b/lithops/telemetry/backends/otlp/config.py @@ -0,0 +1,38 @@ +# +# 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 lithops.telemetry.exporter import default_instance_id + +DEFAULT_CONFIG_KEYS = { + 'endpoint': 'http://localhost:4318', + 'protocol': 'http/protobuf', + 'service_name': 'lithops', + 'timeout': 10, + # The exporter drives the export itself, on lithops.telemetry_interval. + # This is only the backstop of the OpenTelemetry SDK, in seconds + 'export_interval': 3600, +} + + +def load_config(config_data): + """ + Fills in the defaults of the ``otlp`` section + """ + section = config_data.get('otlp') or {} + config_data['otlp'] = section + + for key, value in DEFAULT_CONFIG_KEYS.items(): + section.setdefault(key, value) + section.setdefault('instance', default_instance_id()) + section.setdefault('headers', {}) diff --git a/lithops/telemetry/backends/otlp/otlp.py b/lithops/telemetry/backends/otlp/otlp.py new file mode 100644 index 000000000..fec650bdb --- /dev/null +++ b/lithops/telemetry/backends/otlp/otlp.py @@ -0,0 +1,250 @@ +# +# 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. +# + +""" +OpenTelemetry telemetry backend. + +Where the Prometheus backend talks to one specific system, this one talks +to an OpenTelemetry collector, which is then free to forward the same +metrics to Prometheus over remote write, to a hosted service, or to +several at once. It is the option to reach for when Lithops is one +workload among many rather than the thing being watched. + +Metric names are the ones :mod:`lithops.telemetry.metrics` declares, so a +dashboard written against the Prometheus backend keeps working when the +metrics arrive through a collector instead. +""" + +import logging +from typing import Any, Dict + +from lithops.telemetry.backend import MetricsBackend as BaseMetricsBackend +from lithops.telemetry.metrics import ( + ALL_METRICS, + COUNTER, + GAUGE, + HISTOGRAM, + UPDOWN, + MetricSpec, +) +from lithops.version import __version__ + +logger = logging.getLogger(__name__) + +_METRICS_PATH = '/v1/metrics' + + +def _metrics_endpoint(endpoint: str) -> str: + """ + The OTLP/HTTP metrics endpoint. Both the collector root and the full + signal URL are accepted, because both are what people have written + down + """ + endpoint = endpoint.rstrip('/') + if endpoint.endswith(_METRICS_PATH): + return endpoint + return endpoint + _METRICS_PATH + + +class MetricsBackend(BaseMetricsBackend): + """ + Aggregates through an OpenTelemetry meter and exports over OTLP + """ + + backend_name = 'otlp' + + def __init__(self, config: Dict[str, Any]): + super().__init__(config) + + try: + from opentelemetry.sdk.metrics import MeterProvider + from opentelemetry.sdk.resources import Resource + except ImportError as exc: + raise ImportError( + 'The OTLP telemetry backend needs the opentelemetry-sdk ' + 'package. Install it with ' + '"pip install lithops[telemetry]"' + ) from exc + + # service.name and service.instance.id are what a collector, and + # Prometheus' own OTLP receiver, turn into the job and instance + # labels. Setting both is what makes the metrics land under the + # same identity they would have had through the Pushgateway + resource = Resource.create({ + 'service.name': config['service_name'], + 'service.namespace': 'lithops', + 'service.instance.id': config['instance'], + 'service.version': __version__, + 'host.name': config['instance'], + }) + # The exporter above owns the shutdown, and it flushes before it + # shuts the provider down. Left to itself the SDK registers an + # atexit hook of its own, which runs after that one and tries to + # export through a reader that is already closed + self._provider = MeterProvider( + resource=resource, + metric_readers=[self._create_reader(config)], + views=self._create_views(), + shutdown_on_exit=False, + ) + self._meter = self._provider.get_meter('lithops', __version__) + + logger.debug( + f"OTLP telemetry: exporting to {config['endpoint']} over " + f"{config['protocol']} as {config['service_name']}" + ) + + @staticmethod + def _cumulative_temporality(): + """ + Every instrument exported as a cumulative total rather than as a + delta since the last export. + + Pinned rather than left to the SDK. Cumulative is what Prometheus + accepts, whether the metrics reach it through its own OTLP + receiver or through a collector, and the SDK default is + overridden by an OTEL_EXPORTER_OTLP_METRICS_TEMPORALITY_PREFERENCE + that may well be in the environment for something else + """ + from opentelemetry.sdk.metrics import ( + Counter, + Histogram, + ObservableCounter, + ObservableGauge, + ObservableUpDownCounter, + UpDownCounter, + ) + from opentelemetry.sdk.metrics.export import AggregationTemporality + + return { + instrument: AggregationTemporality.CUMULATIVE + for instrument in ( + Counter, + UpDownCounter, + Histogram, + ObservableCounter, + ObservableUpDownCounter, + ObservableGauge, + ) + } + + @classmethod + def _create_reader(cls, config: Dict[str, Any]): + """ + The periodic reader and the OTLP exporter behind it. + + Split out so that a test, or a backend that wants a different + transport, can put its own reader in without reimplementing the + instrument and view handling + """ + from opentelemetry.sdk.metrics.export import ( + PeriodicExportingMetricReader, + ) + + temporality = cls._cumulative_temporality() + protocol = str(config['protocol']).lower() + if protocol in ('grpc', 'grpc/protobuf'): + from opentelemetry.exporter.otlp.proto.grpc.metric_exporter import ( + OTLPMetricExporter, + ) + exporter = OTLPMetricExporter( + endpoint=config['endpoint'], + headers=config['headers'] or None, + timeout=config['timeout'], + preferred_temporality=temporality, + ) + elif protocol in ('http', 'http/protobuf'): + from opentelemetry.exporter.otlp.proto.http.metric_exporter import ( + OTLPMetricExporter, + ) + exporter = OTLPMetricExporter( + endpoint=_metrics_endpoint(config['endpoint']), + headers=config['headers'] or None, + timeout=config['timeout'], + preferred_temporality=temporality, + ) + else: + raise ValueError( + f"Unknown OTLP protocol '{config['protocol']}'. Use " + f"'http/protobuf' or 'grpc'" + ) + + return PeriodicExportingMetricReader( + exporter, + export_interval_millis=float(config['export_interval']) * 1000, + ) + + @staticmethod + def _create_views(): + """ + Pins the bucket boundaries of every histogram. + + Views have to exist before the meter provider does, which is why + this walks the whole inventory rather than being done lazily with + the instruments + """ + from opentelemetry.sdk.metrics.view import ( + ExplicitBucketHistogramAggregation, + View, + ) + + return [ + View( + instrument_name=spec.name, + aggregation=ExplicitBucketHistogramAggregation( + boundaries=spec.buckets + ), + ) + for spec in ALL_METRICS + if spec.kind == HISTOGRAM + ] + + def _create_instrument(self, spec: MetricSpec): + # The unit is deliberately not declared: it is already part of + # every metric name, and a collector translating to Prometheus + # appends the unit to the name it is given + if spec.kind == COUNTER: + return self._meter.create_counter( + spec.name, description=spec.documentation + ) + if spec.kind == HISTOGRAM: + return self._meter.create_histogram( + spec.name, description=spec.documentation + ) + if spec.kind == UPDOWN: + return self._meter.create_up_down_counter( + spec.name, description=spec.documentation + ) + if spec.kind == GAUGE: + return self._meter.create_gauge( + spec.name, description=spec.documentation + ) + raise ValueError(f'{spec.name}: unsupported kind {spec.kind}') + + def observe( + self, spec: MetricSpec, value: float, labels: Dict[str, str] + ) -> None: + instrument = self._instrument(spec) + if spec.kind == HISTOGRAM: + instrument.record(value, attributes=labels) + elif spec.kind == GAUGE: + instrument.set(value, attributes=labels) + else: + instrument.add(value, attributes=labels) + + def flush(self) -> None: + self._provider.force_flush() + + def shutdown(self) -> None: + self._provider.shutdown() diff --git a/lithops/telemetry/backends/prometheus/__init__.py b/lithops/telemetry/backends/prometheus/__init__.py new file mode 100644 index 000000000..cdffff2ed --- /dev/null +++ b/lithops/telemetry/backends/prometheus/__init__.py @@ -0,0 +1,3 @@ +from lithops.telemetry.backends.prometheus.prometheus import MetricsBackend + +__all__ = ['MetricsBackend'] diff --git a/lithops/telemetry/backends/prometheus/config.py b/lithops/telemetry/backends/prometheus/config.py new file mode 100644 index 000000000..1096afcc8 --- /dev/null +++ b/lithops/telemetry/backends/prometheus/config.py @@ -0,0 +1,39 @@ +# +# 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 lithops.telemetry.exporter import default_instance_id + +DEFAULT_CONFIG_KEYS = { + 'gateway': 'http://localhost:9091', + 'job': 'lithops', + 'timeout': 10, +} + + +def load_config(config_data): + """ + Fills in the defaults of the ``prometheus`` section. + + ``instance`` defaults to the hostname rather than to anything derived + from the execution: it is part of the Pushgateway grouping key, and a + key that changed on every run would leave a group behind on every run. + The Pushgateway has no expiry, so those groups would be served to + Prometheus for ever + """ + section = config_data.get('prometheus') or {} + config_data['prometheus'] = section + + for key, value in DEFAULT_CONFIG_KEYS.items(): + section.setdefault(key, value) + section.setdefault('instance', default_instance_id()) diff --git a/lithops/telemetry/backends/prometheus/prometheus.py b/lithops/telemetry/backends/prometheus/prometheus.py new file mode 100644 index 000000000..31ead5add --- /dev/null +++ b/lithops/telemetry/backends/prometheus/prometheus.py @@ -0,0 +1,187 @@ +# +# 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. +# + +""" +Prometheus Pushgateway telemetry backend. + +Prometheus scrapes, and a Lithops client is not there to be scraped: it +is a script that runs for as long as the job does. The Pushgateway exists +for exactly that, and this backend keeps a registry of cumulative metrics +and replaces the gateway group with it on every flush. + +Because the group is replaced rather than added to, and because the +grouping key is fixed for the lifetime of the machine, the gateway holds +one group per host no matter how many jobs are run through it. +""" + +import logging +from typing import Any, Dict + +from lithops.telemetry.backend import MetricsBackend as BaseMetricsBackend +from lithops.telemetry.metrics import ( + COUNTER, + GAUGE, + HISTOGRAM, + UPDOWN, + MetricSpec, +) + +logger = logging.getLogger(__name__) + + +class MetricsBackend(BaseMetricsBackend): + """ + Aggregates into a ``prometheus_client`` registry and pushes it to a + Pushgateway + """ + + backend_name = 'prometheus' + + def __init__(self, config: Dict[str, Any]): + super().__init__(config) + + try: + from prometheus_client import CollectorRegistry + except ImportError as exc: + raise ImportError( + 'The Prometheus telemetry backend needs the ' + 'prometheus-client package. Install it with ' + '"pip install lithops[telemetry]"' + ) from exc + + self.gateway = config['gateway'] + self.job = config['job'] + self.timeout = config['timeout'] + self.grouping_key = {'instance': config['instance']} + self.registry = CollectorRegistry() + self._handler = self._build_handler(config) + + logger.debug( + f'Prometheus telemetry: pushing to {self.gateway} as ' + f'job={self.job} instance={self.grouping_key["instance"]}' + ) + + @staticmethod + def _build_handler(config: Dict[str, Any]): + """ + The push handler, which is where authentication goes when the + gateway is behind one + """ + username = config.get('username') + password = config.get('password') + if not (username and password): + return None + + from prometheus_client.exposition import basic_auth_handler + + def handler(url, method, timeout, headers, data): + return basic_auth_handler( + url, method, timeout, headers, data, username, password + ) + + return handler + + def _create_instrument(self, spec: MetricSpec): + from prometheus_client import Counter, Gauge, Histogram + + kwargs = { + 'name': spec.name, + 'documentation': spec.documentation, + 'labelnames': spec.labelnames, + 'registry': self.registry, + } + if spec.kind == COUNTER: + # The _total suffix is the client's to add, and the unit is + # already part of the name, so neither is passed here + return Counter(**kwargs) + if spec.kind == HISTOGRAM: + return Histogram(buckets=spec.buckets, **kwargs) + if spec.kind in (UPDOWN, GAUGE): + return Gauge(**kwargs) + raise ValueError(f'{spec.name}: unsupported kind {spec.kind}') + + def observe( + self, spec: MetricSpec, value: float, labels: Dict[str, str] + ) -> None: + instrument = self._instrument(spec).labels(**labels) + if spec.kind == HISTOGRAM: + instrument.observe(value) + elif spec.kind == GAUGE: + instrument.set(value) + else: + instrument.inc(value) + + def flush(self) -> None: + """ + Replaces the gateway group with the current state of the registry. + + A PUT rather than a POST: the registry holds every metric this + process has recorded since it started, so replacing the group is + both correct and self healing after a push that did not land + """ + from prometheus_client import push_to_gateway + + push_to_gateway( + self.gateway, + job=self.job, + registry=_WithoutCreatedSeries(self.registry), + grouping_key=self.grouping_key, + timeout=self.timeout, + handler=self._handler or _default_handler, + ) + + +class _WithoutCreatedSeries: + """ + A registry with the ``_created`` series left out. + + ``prometheus_client`` exposes a ``_created`` gauge next to every + counter, holding the time the counter was first observed. It is of no + use here and it doubles the number of series a counter costs, which + is the one thing the metric inventory is shaped to keep down. There is + no per instrument switch for it, only a process wide one, so it is + filtered on the way out instead. + + Duck typed rather than a real registry: an object with ``collect()`` + is all the exposition format needs + """ + + __slots__ = ('_registry',) + + def __init__(self, registry): + self._registry = registry + + def collect(self): + from prometheus_client.metrics_core import Metric + + for family in self._registry.collect(): + kept = [ + sample for sample in family.samples + if not sample.name.endswith('_created') + ] + if not kept: + continue + # A copy, so that filtering the push never touches what the + # registry itself holds + filtered = Metric( + family.name, family.documentation, family.type, family.unit + ) + filtered.samples = kept + yield filtered + + +def _default_handler(url, method, timeout, headers, data): + from prometheus_client.exposition import default_handler + + return default_handler(url, method, timeout, headers, data) diff --git a/lithops/telemetry/exporter.py b/lithops/telemetry/exporter.py new file mode 100644 index 000000000..45e32351b --- /dev/null +++ b/lithops/telemetry/exporter.py @@ -0,0 +1,645 @@ +# +# 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. +# + +""" +Turns the call statuses Lithops already collects into metrics. + +Everything is measured on the client. The worker writes its status once, +as it always did, and the monitor thread that reads it feeds the numbers +in here on its way past. Nothing is added to the critical path of a +function, no worker needs a route to the metrics system, and every +monitoring backend is instrumented by the same code. + +The exporter is a process-wide singleton. Counters are cumulative for the +lifetime of the process, which is what a time series database expects, +and one process pushes under one identity however many executors it +creates. +""" + +import atexit +import logging +import os +import socket +import threading +from typing import Any, Dict, Optional + +from lithops.telemetry import metrics as M +from lithops.version import __version__ +from lithops.telemetry.backends import ( + import_backend_module, + load_backend_class, + resolve_backend, +) + +logger = logging.getLogger(__name__) + +#: How often the aggregated metrics leave the process, in seconds +DEFAULT_FLUSH_INTERVAL = 10 + +_UNKNOWN = 'unknown' + + +def _number(status: Dict[str, Any], key: str) -> Optional[float]: + """ + A numeric field of a call status, or None when it is absent or not a + number. + + Not every status carries every field: a call that timed out never + reported resource usage, and one whose worker was killed reported + nothing at all. A missing measurement is skipped, never recorded as a + zero, because a zero is a real value that drags a histogram quantile + down with it + """ + value = status.get(key) + if value is None or isinstance(value, bool): + return None + try: + return float(value) + except (TypeError, ValueError): + return None + + +def _mean(value: Any) -> Optional[float]: + """ + A measurement that may come back as one number or as one number per + core, averaged into the single figure the metric holds. The CPU usage + of a worker is the second kind + """ + if isinstance(value, (list, tuple)): + numbers = [ + float(item) for item in value + if isinstance(item, (int, float)) and not isinstance(item, bool) + ] + return sum(numbers) / len(numbers) if numbers else None + if value is None or isinstance(value, bool): + return None + try: + return float(value) + except (TypeError, ValueError): + return None + + +def _delta( + status: Dict[str, Any], end_key: str, start_key: str +) -> Optional[float]: + """ + The time between two timestamps of a call status, when both are there + and the result makes sense. Clocks of a client and a worker are not + the same clock, so a small negative delta is not an error, it is skew + """ + end = _number(status, end_key) + start = _number(status, start_key) + if end is None or start is None: + return None + delta = end - start + return delta if delta >= 0 else 0.0 + + +class BoundTelemetry: + """ + The exporter as one compute backend sees it. + + A :class:`TelemetryExporter` is process-wide, but ``backend`` is a + label of every metric and belongs to the executor. Binding pins it + once instead of threading it through every call site. + """ + + __slots__ = ('_exporter', '_backend') + + def __init__(self, exporter: 'TelemetryExporter', backend: str): + self._exporter = exporter + self._backend = backend or _UNKNOWN + + @property + def enabled(self) -> bool: + return True + + def _labels(self, source: Any, **extra: str) -> Dict[str, str]: + """ + The label set of a job or a future. Both carry the same four + attributes, which is why one function covers them + """ + labels = { + 'backend': self._backend, + 'runtime_name': getattr(source, 'runtime_name', None) or _UNKNOWN, + 'runtime_memory': str(getattr(source, 'runtime_memory', None) or 0), + 'function_name': ( + getattr(source, 'function_name', None) or _UNKNOWN + ), + } + labels.update(extra) + return labels + + def on_job_submitted(self, job: Any) -> None: + """ + Records a job on its way to the compute backend, and what the + client spent getting it there. + + This is the only thing measured before a worker has run; + everything else comes back with a call status + """ + try: + self._record_submitted(job) + except Exception as exc: + logger.debug(f'Telemetry: could not record the job: {exc}') + + def _record_submitted(self, job: Any) -> None: + labels = self._labels(job) + observe = self._exporter.observe + + observe(M.JOBS_SUBMITTED, 1, labels) + observe(M.CALLS_INVOKED, job.total_calls, labels) + observe(M.JOB_CALLS, job.total_calls, labels) + + # What the client spent partitioning, serialising and uploading. + # Invisible until now: it happens before the first worker exists, + # so no call status has ever carried it + metadata = getattr(job, 'metadata', None) or {} + for spec, key in ( + (M.JOB_CREATE_DURATION, 'host_job_created_time'), + (M.JOB_SERIALIZE_DURATION, 'host_job_serialize_time'), + (M.JOB_PARTITION_DURATION, 'host_job_create_partitions_time'), + ): + value = _number(metadata, key) + if value is not None: + observe(spec, value, labels) + + for part, duration_key, size_key in ( + ('function', 'host_func_upload_time', 'func_module_size_bytes'), + ('data', 'host_data_upload_time', 'func_data_size_bytes'), + ): + duration = _number(metadata, duration_key) + if duration is not None: + observe( + M.JOB_UPLOAD_DURATION, duration, dict(labels, part=part) + ) + size = _number(metadata, size_key) + if size is not None: + observe( + M.JOB_PAYLOAD_SIZE, size, dict(labels, part=part) + ) + + def on_call_started(self, future: Any, call_status: Dict[str, Any]) -> None: + """ + Records a call the client has seen start. + + Not every call is seen starting: the storage sweep that recovers a + lost status jumps straight to finished. Started and completed are + therefore counted separately and never assumed to match + """ + try: + self._exporter.observe(M.CALLS_STARTED, 1, self._labels(future)) + except Exception as exc: + logger.debug(f'Telemetry: could not record the call start: {exc}') + + def on_call_finished( + self, + future: Any, + call_status: Dict[str, Any], + outcome: Optional[str] = None, + ) -> None: + """ + Records a call that reached a final state, and everything the + worker measured while it ran + """ + try: + self._record_finished(future, call_status or {}, outcome) + except Exception as exc: + # The caller is the monitor thread. Letting anything out of + # here would take the thread down and hang every wait() of + # the executor, so a metric that cannot be recorded is a + # metric that is not recorded + logger.debug(f'Telemetry: could not record the call: {exc}') + + def _record_finished( + self, + future: Any, + status: Dict[str, Any], + outcome: Optional[str], + ) -> None: + if outcome is None: + outcome = ( + M.OUTCOME_FAILURE if status.get('exception') + else M.OUTCOME_SUCCESS + ) + + labels = self._labels(future) + observe = self._exporter.observe + observe(M.CALLS_COMPLETED, 1, dict(labels, outcome=outcome)) + + # Counted here rather than when the call started: the status that + # says a call is running is synthesised by the storage backend from + # a listing, and carries nothing the worker measured. The status + # that says it finished always comes from the worker itself + if status.get('worker_cold_start'): + observe(M.COLD_STARTS, 1, labels) + + observations = ( + (M.CALL_DURATION, _delta( + status, 'worker_func_end_tstamp', 'worker_func_start_tstamp' + )), + (M.CALL_TOTAL_DURATION, _delta( + status, 'worker_end_tstamp', 'worker_start_tstamp' + )), + (M.CALL_QUEUE_DELAY, _delta( + status, 'worker_start_tstamp', 'host_submit_tstamp' + )), + (M.CALL_WORKER_SETUP, _delta( + status, 'worker_func_start_tstamp', 'worker_start_tstamp' + )), + (M.CALL_WORKER_TEARDOWN, _delta( + status, 'worker_end_tstamp', 'worker_func_end_tstamp' + )), + (M.CALL_RESULT_SIZE, _number(status, 'func_result_size')), + (M.CALL_RESULT_UPLOAD, _number(status, 'worker_result_upload_time')), + (M.WORKER_CPU_UTILIZATION, _mean(status.get('worker_func_cpu_usage'))), + # Kept by the client, not by the worker: how many times it had + # to ask the storage backend before this call reported in + (M.CALL_STATUS_QUERIES, getattr(future, '_status_query_count', None)), + ) + for spec, value in observations: + if value is not None: + observe(spec, value, labels) + + # The monitoring channel is measured against the client clock, so + # only the part of it the client timed is used + status_done = getattr(future, '_host_status_done_tstamp', None) + worker_end = _number(status, 'worker_end_tstamp') + if status_done and worker_end: + observe( + M.CALL_STATUS_LATENCY, max(0.0, status_done - worker_end), + labels + ) + + # Five readings of the same thing, and they answer different + # questions. "peak" is the high water mark of the whole task, which + # is what an out-of-memory kill is measured against; "baseline" is + # that same mark before the function started, so the difference is + # what the function itself cost on top of the runtime + runtime_bytes = ( + float(getattr(future, 'runtime_memory', None) or 0) * 1024 * 1024 + ) + for kind, key in ( + ('rss', 'worker_func_rss'), + ('vms', 'worker_func_vms'), + ('uss', 'worker_func_uss'), + ('peak', 'worker_peak_memory_end'), + ('baseline', 'worker_peak_memory_start'), + ): + value = _number(status, key) + if value is None: + continue + observe(M.WORKER_MEMORY, value, dict(labels, kind=kind)) + # Only the two that mean "how close was this to the limit" + if runtime_bytes and kind in ('rss', 'peak'): + observe( + M.WORKER_MEMORY_RATIO, value / runtime_bytes, + dict(labels, kind=kind), + ) + + for mode, key in ( + ('user', 'worker_func_cpu_user_time'), + ('system', 'worker_func_cpu_system_time'), + ): + value = _number(status, key) + if value is not None: + observe( + M.WORKER_CPU_SECONDS, value, dict(labels, mode=mode) + ) + + for direction, key in ( + ('sent', 'worker_func_sent_net_io'), + ('recv', 'worker_func_recv_net_io'), + ): + value = _number(status, key) + if value is not None: + observe( + M.WORKER_NETWORK_BYTES, value, + dict(labels, direction=direction), + ) + + # What the runtime is, rather than what it did. Carried by its own + # metric so that none of the above has to grow a label for it + observe(M.WORKER_INFO, 1, { + 'backend': self._backend, + 'runtime_name': getattr(future, 'runtime_name', None) or _UNKNOWN, + 'runtime_memory': str( + getattr(future, 'runtime_memory', None) or 0 + ), + 'python_version': status.get('python_version') or _UNKNOWN, + 'lithops_version': __version__, + }) + + def on_result_read(self, future: Any, source: str) -> None: + """ + Records the client getting hold of the result of a call. + + This is the one part of a call the monitor never sees: it happens + in ``get_result()``, on whichever thread the user is on, long + after the future went ready + """ + try: + self._record_result_read(future, source) + except Exception as exc: + logger.debug(f'Telemetry: could not record the result: {exc}') + + def _record_result_read(self, future: Any, source: str) -> None: + stats = getattr(future, 'stats', None) or {} + labels = self._labels(future) + observe = self._exporter.observe + + done = _number(stats, 'host_result_done_tstamp') + + # From knowing the call was done to holding what it returned + download = _delta( + stats, 'host_result_done_tstamp', 'host_status_done_tstamp' + ) + if download is not None: + observe( + M.CALL_RESULT_DOWNLOAD, download, dict(labels, source=source) + ) + + queries = _number(stats, 'host_result_query_count') + if queries is not None: + observe(M.CALL_RESULT_QUERIES, queries, labels) + + # The number the user actually feels: submit to result in hand + submitted = _number(stats, 'host_submit_tstamp') + if done is not None and submitted is not None: + observe(M.CALL_END_TO_END, max(0.0, done - submitted), labels) + + def flush(self) -> None: + """Pushes what has been recorded so far, out of band of the timer""" + self._exporter.flush() + + +class NoopTelemetry(BoundTelemetry): + """ + What every call site holds when telemetry is off: the same shape, and + nothing behind it. Instrumenting a code path therefore costs an + attribute lookup and a call that returns, with no ``if enabled`` + scattered around the monitor + """ + + __slots__ = () + + def __init__(self): # noqa: D107 - deliberately takes no exporter + pass + + @property + def enabled(self) -> bool: + return False + + def on_job_submitted(self, job): + pass + + def on_call_started(self, future, call_status): + pass + + def on_call_finished(self, future, call_status, outcome=None): + pass + + def on_result_read(self, future, source): + pass + + def flush(self): + pass + + +#: Shared instance. Immutable and stateless, so one is enough +NOOP = NoopTelemetry() + + +class TelemetryExporter: + """ + Owns the metrics backend and the thread that flushes it. + + Built through :func:`get_exporter`, which keeps one per process. + """ + + def __init__(self, backend, flush_interval: float): + self.backend = backend + self.flush_interval = flush_interval + self._stopped = threading.Event() + self._shutdown_done = False + self._shutdown_lock = threading.Lock() + self._flusher = threading.Thread( + target=self._flush_loop, + name='lithops-telemetry-flush', + daemon=True, + ) + self._flusher.start() + # A script that never closes its executor is the common case, and + # the metrics of its last seconds are the ones worth having + atexit.register(self.shutdown) + + def observe( + self, spec: M.MetricSpec, value: float, labels: Dict[str, str] + ) -> None: + """ + Records one observation, after checking that the labels are the + ones the spec declares. + + The check is what keeps the cardinality rules of + :mod:`lithops.telemetry.metrics` true at runtime rather than only + at import: a call site that invents a label is dropped and logged, + not written to the backend + """ + if set(labels) != set(spec.labelnames): + logger.error( + f'Telemetry: {spec.name} takes labels ' + f'{sorted(spec.labelnames)}, got {sorted(labels)}. ' + f'The observation was dropped' + ) + return + try: + self.backend.observe(spec, value, labels) + except Exception as exc: + logger.debug(f'Telemetry: {spec.name} was not recorded: {exc}') + + def bind(self, compute_backend: str) -> BoundTelemetry: + """The exporter as an executor on ``compute_backend`` sees it""" + return BoundTelemetry(self, compute_backend) + + def flush(self) -> None: + """ + Pushes what has been recorded so far. + + A no-op once the exporter has been shut down. The executor + flushes from its own atexit hook, which can run after the one + that shut the exporter down, and a client library asked to send a + batch through something it has already closed is entitled to + complain about it + """ + if self._shutdown_done: + return + try: + self.backend.flush() + except Exception as exc: + logger.warning(f'Telemetry: could not flush the metrics: {exc}') + + def _flush_loop(self) -> None: + while not self._stopped.wait(self.flush_interval): + self.flush() + + def shutdown(self) -> None: + """ + Shuts the backend down, which is what flushes it one last time. + Idempotent, and best effort: it runs from atexit, where the + interpreter may already be tearing the modules the HTTP client + needs down + """ + with self._shutdown_lock: + if self._shutdown_done: + return + self._shutdown_done = True + + self._stopped.set() + try: + self.backend.shutdown() + except Exception as exc: + logger.debug(f'Telemetry: shutdown was incomplete: {exc}') + + +# --------------------------------------------------------------------------- +# The process-wide instance +# --------------------------------------------------------------------------- + +_exporter: Optional[TelemetryExporter] = None +_exporter_backend: Optional[str] = None +_exporter_lock = threading.Lock() + + +def default_instance_id() -> str: + """ + Identity a backend labels this process with when the configuration + does not name one. + + The hostname, deliberately: it is stable across runs, which keeps the + number of series a backend holds bounded by the number of machines + running Lithops rather than growing with every execution + """ + return os.environ.get('LITHOPS_TELEMETRY_INSTANCE') or socket.gethostname() + + +def get_telemetry( + config: Optional[Dict[str, Any]], + compute_backend: Optional[str] = None, +) -> BoundTelemetry: + """ + The telemetry handle for an executor, or :data:`NOOP` when telemetry + is off or its backend cannot be loaded. + + Never raises. A metrics system that is misconfigured or unreachable + is a metrics system that is not used, not a job that does not run. + """ + backend_name = resolve_backend(config) + if backend_name is None: + return NOOP + + if 'LITHOPS_WORKER' in os.environ: + # Metrics are a client concern, and a worker gets the client's + # whole config. Without this, every worker would try to reach a + # metrics system it most likely has no route to. The remote + # invoker sets the same variable before it builds its JobMonitor, + # so it is covered too + return NOOP + + try: + exporter = _get_exporter(config, backend_name) + except Exception as exc: + logger.error( + f"Telemetry is disabled: the '{backend_name}' backend could " + f"not be initialised: {exc}" + ) + return NOOP + + return exporter.bind( + compute_backend or (config.get('lithops') or {}).get('backend') + ) + + +def _get_exporter( + config: Dict[str, Any], backend_name: str +) -> TelemetryExporter: + global _exporter, _exporter_backend + + with _exporter_lock: + if _exporter is not None: + if _exporter_backend != backend_name: + logger.warning( + f"Telemetry was already started with the " + f"'{_exporter_backend}' backend; '{backend_name}' is " + f"ignored. One process exports through one backend" + ) + return _exporter + + backend_cls = load_backend_class(backend_name) + section = config.get(backend_name) or {} + interval = float( + (config.get('lithops') or {}).get( + 'telemetry_interval', DEFAULT_FLUSH_INTERVAL + ) + ) + _exporter = TelemetryExporter(backend_cls(section), interval) + _exporter_backend = backend_name + logger.debug( + f'Telemetry enabled: {backend_name} backend, flushing every ' + f'{interval}s' + ) + return _exporter + + +def current_telemetry(compute_backend: Optional[str] = None) -> BoundTelemetry: + """ + The telemetry of this process, for a caller that has no configuration + to hand -- a :class:`~lithops.future.ResponseFuture` reading its + result, which knows which backend it ran on and nothing else. + + Returns :data:`NOOP` unless :func:`get_telemetry` has already started + an exporter, so this never switches telemetry on by itself and never + reads the configuration a second time. + """ + exporter = _exporter + if exporter is None: + return NOOP + return exporter.bind(compute_backend) + + +def shutdown_telemetry() -> None: + """ + Stops the exporter of this process, if there is one. Only the tests + and a process that wants a deterministic final push need this; + everything else is covered by the atexit hook + """ + global _exporter, _exporter_backend + + with _exporter_lock: + exporter, _exporter, _exporter_backend = _exporter, None, None + + if exporter is not None: + exporter.shutdown() + + +def load_backend_config(config_data: Dict[str, Any]) -> None: + """ + Lets the configured telemetry backend fill in its own defaults, the + way the monitoring backends do. A no-op when telemetry is off + """ + backend_name = resolve_backend(config_data) + if backend_name is None: + return + logger.debug(f'Loading Telemetry backend module: {backend_name}') + module = import_backend_module(backend_name, 'config') + module.load_config(config_data) diff --git a/lithops/telemetry/metrics.py b/lithops/telemetry/metrics.py new file mode 100644 index 000000000..18328df0e --- /dev/null +++ b/lithops/telemetry/metrics.py @@ -0,0 +1,514 @@ +# +# 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. +# + +""" +The metrics Lithops exports, declared once and materialised by whichever +telemetry backend is configured. + +A metric is a :class:`MetricSpec`: a name, a kind, the labels it carries +and, for histograms, its bucket boundaries. Backends turn a spec into +their own instrument the first time they see it, so adding a metric is +adding a spec here and nothing else. + +Cardinality is the reason this file exists. Every distinct combination of +label values is a separate time series, and Lithops runs jobs of tens of +thousands of calls: a ``call_id`` label would mean a series per call, for +ever. The label set of every metric is therefore bounded by properties of +the *job* -- never of the call -- and :data:`FORBIDDEN_LABELS` makes a +spec that breaks the rule fail at import rather than in production. + +Per-call detail is not lost, it is simply not a metric: it lives in the +call status, which the client already keeps. +""" + +from dataclasses import dataclass, field +from typing import Optional, Tuple + +#: Kinds of instrument a backend has to support +COUNTER = 'counter' +HISTOGRAM = 'histogram' +UPDOWN = 'updown' +GAUGE = 'gauge' + +_KINDS = (COUNTER, HISTOGRAM, UPDOWN, GAUGE) + +#: Labels every metric carries. All of them are properties of the job, so +#: the number of series a backend holds is bounded by how many distinct +#: functions and runtimes are executed, not by how many calls are made +BASE_LABELS: Tuple[str, ...] = ( + 'backend', + 'runtime_name', + 'runtime_memory', + 'function_name', +) + +#: The labels an info metric carries. It says what a runtime *is*, so +#: the function that happened to run on it is not part of its identity, +#: and leaving it out keeps one series per runtime rather than one per +#: (runtime, function) pair +RUNTIME_LABELS: Tuple[str, ...] = ( + 'backend', + 'runtime_name', + 'runtime_memory', +) + +#: Labels that identify a single call or a single job. Attaching one of +#: these to a metric turns a bounded series into an unbounded one, which +#: is the failure mode this whole module is shaped to prevent +FORBIDDEN_LABELS = frozenset({ + 'call_id', + 'job_id', + 'job_key', + 'executor_id', + 'activation_id', + 'worker_id', + 'instance_id', +}) + + +@dataclass(frozen=True) +class MetricSpec: + """ + One exported metric. + + ``name`` is used verbatim by every backend, so that a dashboard + written against one keeps working against another. Counters are named + without the ``_total`` suffix: both Prometheus and OpenTelemetry add + it themselves when they render the metric. + """ + + name: str + kind: str + documentation: str + unit: str = '' + base_labels: Tuple[str, ...] = BASE_LABELS + extra_labels: Tuple[str, ...] = () + buckets: Optional[Tuple[float, ...]] = None + labelnames: Tuple[str, ...] = field(init=False) + + def __post_init__(self): + if self.kind not in _KINDS: + raise ValueError( + f"{self.name}: unknown metric kind '{self.kind}'" + ) + if self.kind == HISTOGRAM and not self.buckets: + raise ValueError(f'{self.name}: a histogram needs buckets') + if self.kind != HISTOGRAM and self.buckets: + raise ValueError(f'{self.name}: only a histogram takes buckets') + + labelnames = tuple(self.base_labels) + tuple(self.extra_labels) + forbidden = FORBIDDEN_LABELS.intersection(labelnames) + if forbidden: + raise ValueError( + f"{self.name}: {', '.join(sorted(forbidden))} identifies a " + f"single call or job. A label like that gives the metric one " + f"time series per call, which no time series database " + f"survives. Per-call detail belongs in the call status" + ) + # frozen=True, so the derived field is set the long way round + object.__setattr__(self, 'labelnames', labelnames) + + +# --------------------------------------------------------------------------- +# Bucket boundaries +# +# Chosen so that the interesting part of each distribution falls in the +# middle of the range: a serverless call is a few hundred milliseconds to a +# few minutes, a cold start a few seconds, a result a few kilobytes +# --------------------------------------------------------------------------- + +DURATION_BUCKETS = ( + 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60, 120, 300, 600, 1800 +) + +DELAY_BUCKETS = ( + 0.01, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60, 120, 300 +) + +SIZE_BUCKETS = ( + 1024, 8192, 65536, 524288, 1048576, 8388608, 67108864, 536870912 +) + +MEMORY_BUCKETS = ( + 16777216, 67108864, 134217728, 268435456, 536870912, + 1073741824, 2147483648, 4294967296, 8589934592 +) + +#: A ratio over 1 means the function used more than the memory the runtime +#: was configured with, which is worth seeing rather than clamping away +RATIO_BUCKETS = (0.1, 0.25, 0.5, 0.6, 0.7, 0.8, 0.9, 0.95, 1.0, 1.25) + +PERCENT_BUCKETS = (1, 5, 10, 25, 50, 75, 90, 95, 99, 100) + +#: For the client side of a job: serialising, uploading, and the storage +#: round trips the monitor makes. All of it is fractions of a second to a +#: few seconds when it is healthy +OVERHEAD_BUCKETS = ( + 0.001, 0.005, 0.01, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10, 30, 60 +) + +#: Counts of storage requests per call. A well behaved monitoring channel +#: needs one or two; the long tail is what a rate limited poll looks like +COUNT_BUCKETS = (1, 2, 3, 5, 8, 13, 21, 34, 55, 89) + +#: Sizes of a job rather than of a result: the serialised function is +#: kilobytes, the data can be anything +JOB_SIZE_BUCKETS = ( + 1024, 16384, 131072, 1048576, 8388608, 67108864, 536870912, 4294967296 +) + +#: How many calls a job is made of +JOB_CALLS_BUCKETS = (1, 5, 10, 50, 100, 500, 1000, 5000, 10000, 50000) + + +# --------------------------------------------------------------------------- +# The inventory +# --------------------------------------------------------------------------- + +JOBS_SUBMITTED = MetricSpec( + name='lithops_jobs_submitted', + kind=COUNTER, + documentation='Jobs submitted for execution', +) + +CALLS_INVOKED = MetricSpec( + name='lithops_calls_invoked', + kind=COUNTER, + documentation='Function calls handed to the compute backend', +) + +CALLS_STARTED = MetricSpec( + name='lithops_calls_started', + kind=COUNTER, + documentation='Function calls the client has seen start running', +) + +CALLS_COMPLETED = MetricSpec( + name='lithops_calls_completed', + kind=COUNTER, + documentation=( + 'Function calls that reached a final state. The outcome label is ' + 'one of success, failure, timeout or chained' + ), + extra_labels=('outcome',), +) + +COLD_STARTS = MetricSpec( + name='lithops_cold_starts', + kind=COUNTER, + documentation='Function calls that ran in a cold worker', +) + +WORKER_CPU_SECONDS = MetricSpec( + name='lithops_worker_cpu_seconds', + kind=COUNTER, + documentation='CPU time consumed by the function, by mode (user, system)', + unit='seconds', + extra_labels=('mode',), +) + +WORKER_NETWORK_BYTES = MetricSpec( + name='lithops_worker_network_bytes', + kind=COUNTER, + documentation='Network traffic of the function, by direction (sent, recv)', + unit='bytes', + extra_labels=('direction',), +) + +CALL_DURATION = MetricSpec( + name='lithops_call_duration_seconds', + kind=HISTOGRAM, + documentation='Wall clock time spent inside the user function', + unit='seconds', + buckets=DURATION_BUCKETS, +) + +CALL_TOTAL_DURATION = MetricSpec( + name='lithops_call_total_duration_seconds', + kind=HISTOGRAM, + documentation=( + 'Wall clock time the worker spent on the call, including the ' + 'Lithops overhead around the user function' + ), + unit='seconds', + buckets=DURATION_BUCKETS, +) + +CALL_QUEUE_DELAY = MetricSpec( + name='lithops_call_queue_delay_seconds', + kind=HISTOGRAM, + documentation=( + 'Time between the client submitting the call and the worker ' + 'starting it. This is the scheduling latency of the backend' + ), + unit='seconds', + buckets=DELAY_BUCKETS, +) + +CALL_STATUS_LATENCY = MetricSpec( + name='lithops_call_status_latency_seconds', + kind=HISTOGRAM, + documentation=( + 'Time between the worker finishing the call and the client ' + 'learning about it. This is the latency of the monitoring channel' + ), + unit='seconds', + buckets=DELAY_BUCKETS, +) + +CALL_RESULT_SIZE = MetricSpec( + name='lithops_call_result_size_bytes', + kind=HISTOGRAM, + documentation='Size of the value the function returned', + unit='bytes', + buckets=SIZE_BUCKETS, +) + +WORKER_MEMORY = MetricSpec( + name='lithops_worker_memory_bytes', + kind=HISTOGRAM, + documentation=( + 'Memory of the worker, by kind. "peak" is the high water mark of ' + 'the whole task and is what an out-of-memory kill is measured ' + 'against; "baseline" is the same reading taken before the function ' + 'started, which is what the runtime itself costs. "rss", "vms" and ' + '"uss" are sampled once, as the function returns' + ), + unit='bytes', + extra_labels=('kind',), + buckets=MEMORY_BUCKETS, +) + +WORKER_MEMORY_RATIO = MetricSpec( + name='lithops_worker_memory_utilization_ratio', + kind=HISTOGRAM, + documentation=( + 'Memory of the worker over the memory the runtime was configured ' + 'with, by kind. Values close to 1 are calls about to be killed; ' + 'values close to 0 are memory paid for and not used. The "peak" ' + 'kind is the one to size a runtime by' + ), + extra_labels=('kind',), + buckets=RATIO_BUCKETS, +) + +CALL_RESULT_UPLOAD = MetricSpec( + name='lithops_call_result_upload_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the worker spent writing the result to the storage backend. ' + 'Zero for a result small enough to travel in the call status' + ), + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +CALL_WORKER_SETUP = MetricSpec( + name='lithops_call_worker_setup_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the worker spent between starting and entering the user ' + 'function: unpacking the job, importing the modules and fetching ' + 'the data' + ), + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +CALL_WORKER_TEARDOWN = MetricSpec( + name='lithops_call_worker_teardown_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the worker spent after the user function returned: writing ' + 'the result and reporting the status' + ), + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +CALL_RESULT_DOWNLOAD = MetricSpec( + name='lithops_call_result_download_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the client spent getting the result of a call once it knew ' + 'the call was done, by source. "inline" is a result small enough to ' + 'have travelled in the call status, so it costs no request at all; ' + '"storage" is one that had to be fetched' + ), + unit='seconds', + extra_labels=('source',), + buckets=OVERHEAD_BUCKETS, +) + +CALL_RESULT_QUERIES = MetricSpec( + name='lithops_call_result_queries', + kind=HISTOGRAM, + documentation=( + 'Storage requests the client made to get the result of one call. ' + 'Zero for a result that travelled in the call status' + ), + buckets=COUNT_BUCKETS, +) + +CALL_END_TO_END = MetricSpec( + name='lithops_call_end_to_end_seconds', + kind=HISTOGRAM, + documentation=( + 'Time from the client submitting a call to the client holding its ' + 'result. Everything else is a part of this one' + ), + unit='seconds', + buckets=DURATION_BUCKETS, +) + +CALL_STATUS_QUERIES = MetricSpec( + name='lithops_call_status_queries', + kind=HISTOGRAM, + documentation=( + 'Storage requests the client made to learn the status of one call. ' + 'This is what the monitoring channel costs against the storage ' + 'backend, and it is zero for the channels that push' + ), + buckets=COUNT_BUCKETS, +) + +WORKER_CPU_UTILIZATION = MetricSpec( + name='lithops_worker_cpu_utilization_percent', + kind=HISTOGRAM, + documentation='CPU utilisation of the worker while the function ran', + unit='percent', + buckets=PERCENT_BUCKETS, +) + +JOB_CALLS = MetricSpec( + name='lithops_job_calls', + kind=HISTOGRAM, + documentation='How many calls a job is made of', + buckets=JOB_CALLS_BUCKETS, +) + +JOB_CREATE_DURATION = MetricSpec( + name='lithops_job_create_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the client spent preparing the job before the first worker ' + 'was invoked: partitioning, serialising and uploading' + ), + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +JOB_SERIALIZE_DURATION = MetricSpec( + name='lithops_job_serialize_seconds', + kind=HISTOGRAM, + documentation='Time the client spent serialising the function and its data', + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +JOB_PARTITION_DURATION = MetricSpec( + name='lithops_job_partition_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the client spent partitioning the input data, for a job that ' + 'processes objects' + ), + unit='seconds', + buckets=OVERHEAD_BUCKETS, +) + +JOB_UPLOAD_DURATION = MetricSpec( + name='lithops_job_upload_seconds', + kind=HISTOGRAM, + documentation=( + 'Time the client spent uploading the job to the storage backend, by ' + 'part (function, data). Zero for a function already in the cache' + ), + unit='seconds', + extra_labels=('part',), + buckets=OVERHEAD_BUCKETS, +) + +JOB_PAYLOAD_SIZE = MetricSpec( + name='lithops_job_payload_bytes', + kind=HISTOGRAM, + documentation=( + 'Size of what the client uploaded for the job, by part (function, ' + 'data)' + ), + unit='bytes', + extra_labels=('part',), + buckets=JOB_SIZE_BUCKETS, +) + +WORKER_INFO = MetricSpec( + name='lithops_worker_info', + kind=GAUGE, + documentation=( + 'Always 1. Carries the properties of the execution environment as ' + 'labels, so that a dashboard can show what a runtime actually is ' + 'without any of them having to be a label of every other metric' + ), + base_labels=RUNTIME_LABELS, + extra_labels=('python_version', 'lithops_version'), +) + +#: Every spec, which is what a backend needs in order to declare its +#: instruments (OpenTelemetry views, for one, have to be registered before +#: the meter is built) +ALL_METRICS: Tuple[MetricSpec, ...] = ( + JOBS_SUBMITTED, + CALLS_INVOKED, + CALLS_STARTED, + CALLS_COMPLETED, + COLD_STARTS, + WORKER_CPU_SECONDS, + WORKER_NETWORK_BYTES, + CALL_DURATION, + CALL_TOTAL_DURATION, + CALL_QUEUE_DELAY, + CALL_STATUS_LATENCY, + CALL_WORKER_SETUP, + CALL_WORKER_TEARDOWN, + CALL_RESULT_SIZE, + CALL_RESULT_UPLOAD, + CALL_RESULT_DOWNLOAD, + CALL_RESULT_QUERIES, + CALL_END_TO_END, + CALL_STATUS_QUERIES, + WORKER_MEMORY, + WORKER_MEMORY_RATIO, + WORKER_CPU_UTILIZATION, + WORKER_INFO, + JOB_CALLS, + JOB_CREATE_DURATION, + JOB_SERIALIZE_DURATION, + JOB_PARTITION_DURATION, + JOB_UPLOAD_DURATION, + JOB_PAYLOAD_SIZE, +) + + +# --------------------------------------------------------------------------- +# Outcomes of a call, the only per-call dimension that is safe to label +# --------------------------------------------------------------------------- + +#: Where the client read the result of a call from +SOURCE_INLINE = 'inline' +SOURCE_STORAGE = 'storage' + +OUTCOME_SUCCESS = 'success' +OUTCOME_FAILURE = 'failure' +OUTCOME_TIMEOUT = 'timeout' +OUTCOME_CHAINED = 'chained' diff --git a/lithops/tests/test_constants.py b/lithops/tests/test_constants.py index 4e7e9b342..dae790c67 100644 --- a/lithops/tests/test_constants.py +++ b/lithops/tests/test_constants.py @@ -98,9 +98,12 @@ def test_storage_prefixes_are_posix(self): def test_default_config_keys(self): assert set(constants.LITHOPS_DEFAULT_CONFIG_KEYS) == { - 'monitoring', 'monitoring_interval', 'execution_timeout' + 'monitoring', 'monitoring_interval', 'telemetry', + 'telemetry_interval', 'execution_timeout' } assert constants.LITHOPS_DEFAULT_CONFIG_KEYS['monitoring_interval'] == 2 + assert constants.LITHOPS_DEFAULT_CONFIG_KEYS['telemetry'] is False + assert constants.LITHOPS_DEFAULT_CONFIG_KEYS['telemetry_interval'] == 10 def test_get_mode_and_default_backend_round_trip(self): assert get_mode(constants.LOCALHOST) == constants.LOCALHOST diff --git a/lithops/tests/test_invokers.py b/lithops/tests/test_invokers.py index 41e925d53..adb16a151 100644 --- a/lithops/tests/test_invokers.py +++ b/lithops/tests/test_invokers.py @@ -147,7 +147,7 @@ def _bare_invoker(**attrs): config={'lithops': {'mode': SERVERLESS, 'backend': 'ibm_cf'}, 'ibm_cf': {}}, backend='ibm_cf', include_function=False, - prometheus=MagicMock(), + telemetry=MagicMock(), job_monitor=MagicMock(), storage_config={'backend': 'localhost', 'localhost': {'storage_bucket': 'test-bucket'}}, max_workers=8, @@ -236,7 +236,7 @@ def test_run_job_sends_metrics_and_invokes(self, tmp_path, monkeypatch): job = _job() futures = inv._run_job(job) inv._invoke_job.assert_called_once_with(job) - inv.prometheus.send_metric.assert_called() + inv.telemetry.on_job_submitted.assert_called_once_with(job) assert len(futures) == 2 def test_run_job_include_function_extends_runtime(self, tmp_path, monkeypatch): diff --git a/lithops/tests/test_monitor.py b/lithops/tests/test_monitor.py index 94fd2e573..9309db4aa 100644 --- a/lithops/tests/test_monitor.py +++ b/lithops/tests/test_monitor.py @@ -1732,6 +1732,29 @@ def _publish(self, payload): return Plain + def test_the_python_version_falls_back_to_the_interpreter(self, monkeypatch): + """ + Only the container runtimes declare PYTHON_VERSION. Everywhere + else the interpreter running the worker is the answer, and the + field was reported as None + """ + from lithops.utils import CURRENT_PY_VERSION + + monkeypatch.delenv('PYTHON_VERSION', raising=False) + status = self._status_cls(lambda payload: None)( + self._job(), MagicMock() + ) + + assert status.status['python_version'] == CURRENT_PY_VERSION + + def test_a_declared_python_version_wins(self, monkeypatch): + monkeypatch.setenv('PYTHON_VERSION', '3.9') + status = self._status_cls(lambda payload: None)( + self._job(), MagicMock() + ) + + assert status.status['python_version'] == '3.9' + def test_a_publish_that_keeps_failing_still_writes_to_the_storage(self): cls = self._status_cls( lambda payload: (_ for _ in ()).throw(ConnectionError('down')) diff --git a/lithops/tests/test_telemetry.py b/lithops/tests/test_telemetry.py new file mode 100644 index 000000000..931c60143 --- /dev/null +++ b/lithops/tests/test_telemetry.py @@ -0,0 +1,1102 @@ +# +# 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 time +from types import SimpleNamespace +from unittest.mock import MagicMock, patch + +import pytest + +from lithops.telemetry import metrics as M +from lithops.telemetry.backend import MetricsBackend +from lithops.telemetry.backends import DEFAULT_BACKEND, resolve_backend +from lithops.telemetry.exporter import ( + NOOP, + BoundTelemetry, + TelemetryExporter, + get_telemetry, + shutdown_telemetry, +) +from lithops.monitoring.monitor import Monitor + + +class RecordingBackend(MetricsBackend): + """A backend that keeps every observation instead of shipping it""" + + backend_name = 'recording' + + def __init__(self, config=None): + super().__init__(config or {}) + self.observations = [] + self.flushes = 0 + self.shutdowns = 0 + + def _create_instrument(self, spec): + return spec.name + + def observe(self, spec, value, labels): + self.observations.append((spec.name, value, dict(labels))) + + def flush(self): + self.flushes += 1 + + def shutdown(self): + self.shutdowns += 1 + + def values(self, spec): + return [v for name, v, _ in self.observations if name == spec.name] + + def names(self): + return [name for name, _, _ in self.observations] + + +@pytest.fixture +def recorder(): + """ + A bound telemetry writing into a RecordingBackend, with the flush + thread wound all the way down before the test ends + """ + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=3600) + try: + yield exporter.bind('aws_lambda'), backend + finally: + exporter.shutdown() + + +@pytest.fixture(autouse=True) +def no_process_exporter(): + """ + The exporter is a process-wide singleton, so a test that builds one + would otherwise hand it to every test that runs afterwards + """ + shutdown_telemetry() + yield + shutdown_telemetry() + + +def _future(**attrs): + defaults = dict( + function_name='my_func', + runtime_name='python:3.11', + runtime_memory=512, + _host_status_done_tstamp=None, + _status_query_count=3, + ) + defaults.update(attrs) + return SimpleNamespace(**defaults) + + +def _call_status(**attrs): + """A call status with everything a healthy worker reports""" + status = { + 'exception': False, + 'worker_cold_start': True, + 'host_submit_tstamp': 1000.0, + 'worker_start_tstamp': 1002.0, + 'worker_func_start_tstamp': 1002.5, + 'worker_func_end_tstamp': 1007.5, + 'worker_end_tstamp': 1008.0, + 'func_result_size': 4096, + 'worker_result_upload_time': 0.12, + 'python_version': '3.11', + 'worker_func_rss': 268435456, + 'worker_func_vms': 900000000, + 'worker_func_uss': 200000000, + 'worker_peak_memory_start': 90000000, + 'worker_peak_memory_end': 402653184, + 'worker_func_cpu_usage': 42.5, + 'worker_func_cpu_user_time': 4.0, + 'worker_func_cpu_system_time': 0.5, + 'worker_func_sent_net_io': 1024, + 'worker_func_recv_net_io': 2048, + } + status.update(attrs) + return status + + +def _job(**attrs): + defaults = dict( + total_calls=120, + function_name='my_func', + runtime_name='python:3.11', + runtime_memory=512, + metadata={ + 'host_job_created_time': 1.8, + 'host_job_serialize_time': 0.4, + 'host_job_create_partitions_time': 0.05, + 'host_func_upload_time': 0.3, + 'func_module_size_bytes': 82000, + 'host_data_upload_time': 0.9, + 'func_data_size_bytes': 5500000, + }, + ) + defaults.update(attrs) + return SimpleNamespace(**defaults) + + +class TestMetricSpecs: + + def test_a_per_call_label_is_refused(self): + with pytest.raises(ValueError, match='call_id'): + M.MetricSpec( + name='lithops_bad', kind=M.COUNTER, + documentation='', extra_labels=('call_id',), + ) + + def test_a_histogram_needs_buckets(self): + with pytest.raises(ValueError, match='buckets'): + M.MetricSpec( + name='lithops_bad', kind=M.HISTOGRAM, documentation='' + ) + + def test_only_a_histogram_takes_buckets(self): + with pytest.raises(ValueError, match='histogram'): + M.MetricSpec( + name='lithops_bad', kind=M.COUNTER, + documentation='', buckets=(1, 2), + ) + + def test_no_exported_metric_is_identified_by_a_call(self): + for spec in M.ALL_METRICS: + assert not M.FORBIDDEN_LABELS.intersection(spec.labelnames) + + def test_metric_names_are_unique(self): + names = [spec.name for spec in M.ALL_METRICS] + assert len(names) == len(set(names)) + + +class TestResolveBackend: + + @pytest.mark.parametrize('value', [None, False, '', 'false', 'no', 'off']) + def test_disabled_values(self, value): + assert resolve_backend({'lithops': {'telemetry': value}}) is None + + @pytest.mark.parametrize('value', [True, 'true', 'YES', '1']) + def test_enabled_without_a_backend_picks_the_default(self, value): + config = {'lithops': {'telemetry': value}} + assert resolve_backend(config) == DEFAULT_BACKEND + + def test_a_named_backend_wins(self): + assert resolve_backend({'lithops': {'telemetry': 'OTLP'}}) == 'otlp' + + def test_the_argument_wins_over_the_config(self): + config = {'lithops': {'telemetry': 'prometheus'}} + assert resolve_backend(config, 'otlp') == 'otlp' + + def test_missing_section(self): + assert resolve_backend({}) is None + assert resolve_backend(None) is None + + +class TestRecordingACall: + + def test_a_finished_call_records_every_measurement(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + assert backend.values(M.CALL_DURATION) == [5.0] + assert backend.values(M.CALL_TOTAL_DURATION) == [6.0] + assert backend.values(M.CALL_QUEUE_DELAY) == [2.0] + assert backend.values(M.CALL_WORKER_SETUP) == [0.5] + assert backend.values(M.CALL_WORKER_TEARDOWN) == [0.5] + assert backend.values(M.CALL_RESULT_SIZE) == [4096] + assert backend.values(M.WORKER_CPU_UTILIZATION) == [42.5] + assert backend.values(M.CALL_RESULT_UPLOAD) == [0.12] + assert backend.values(M.CALL_STATUS_QUERIES) == [3] + assert sorted(backend.values(M.WORKER_CPU_SECONDS)) == [0.5, 4.0] + assert sorted(backend.values(M.WORKER_NETWORK_BYTES)) == [1024, 2048] + + def test_the_labels_are_the_job_not_the_call(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + for name, _, labels in backend.observations: + assert labels['backend'] == 'aws_lambda' + assert labels['runtime_name'] == 'python:3.11' + assert labels['runtime_memory'] == '512' + assert not M.FORBIDDEN_LABELS.intersection(labels) + if name == M.WORKER_INFO.name: + # Says what a runtime is, not what ran on it + assert 'function_name' not in labels + else: + assert labels['function_name'] == 'my_func' + + def test_cpu_and_network_carry_their_own_dimension(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + modes = { + labels['mode'] + for name, _, labels in backend.observations + if name == M.WORKER_CPU_SECONDS.name + } + directions = { + labels['direction'] + for name, _, labels in backend.observations + if name == M.WORKER_NETWORK_BYTES.name + } + assert modes == {'user', 'system'} + assert directions == {'sent', 'recv'} + + def test_a_successful_call_is_counted_as_such(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + outcomes = [ + labels['outcome'] for name, _, labels in backend.observations + if name == M.CALLS_COMPLETED.name + ] + assert outcomes == [M.OUTCOME_SUCCESS] + + def test_a_failed_call_is_counted_as_such(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status(exception=True)) + + outcomes = [ + labels['outcome'] for name, _, labels in backend.observations + if name == M.CALLS_COMPLETED.name + ] + assert outcomes == [M.OUTCOME_FAILURE] + + def test_an_explicit_outcome_wins(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished( + _future(), _call_status(exception=True), M.OUTCOME_TIMEOUT + ) + + outcomes = [ + labels['outcome'] for name, _, labels in backend.observations + if name == M.CALLS_COMPLETED.name + ] + assert outcomes == [M.OUTCOME_TIMEOUT] + + def test_the_monitoring_latency_is_measured_against_the_client_clock( + self, recorder + ): + telemetry, backend = recorder + future = _future(_host_status_done_tstamp=1008.75) + telemetry.on_call_finished(future, _call_status()) + + assert backend.values(M.CALL_STATUS_LATENCY) == [0.75] + + def test_a_started_call_is_counted_once(self, recorder): + telemetry, backend = recorder + telemetry.on_call_started(_future(), _call_status()) + + assert backend.values(M.CALLS_STARTED) == [1] + + def test_a_cold_start_is_counted_when_the_call_finishes(self, recorder): + # Not when it starts: the status that says a call is running is + # synthesised by the storage backend from a listing, and carries + # nothing the worker measured + telemetry, backend = recorder + telemetry.on_call_started(_future(), _call_status()) + + assert backend.values(M.COLD_STARTS) == [] + + telemetry.on_call_finished(_future(), _call_status()) + + assert backend.values(M.COLD_STARTS) == [1] + + def test_a_warm_call_is_not_a_cold_start(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished( + _future(), _call_status(worker_cold_start=False) + ) + + assert backend.values(M.CALLS_COMPLETED) == [1] + assert backend.values(M.COLD_STARTS) == [] + + def test_the_cpu_usage_of_every_core_is_averaged(self, recorder): + # psutil reports one figure per core, and the metric holds one + telemetry, backend = recorder + telemetry.on_call_finished( + _future(), _call_status( + worker_func_cpu_usage=[10.0, 30.0, 50.0, 10.0] + ) + ) + + assert backend.values(M.WORKER_CPU_UTILIZATION) == [25.0] + + def test_a_worker_that_reports_no_cpu_usage_is_skipped(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished( + _future(), _call_status(worker_func_cpu_usage=[]) + ) + + assert backend.values(M.WORKER_CPU_UTILIZATION) == [] + + def test_a_job_records_its_size(self, recorder): + telemetry, backend = recorder + telemetry.on_job_submitted(_job()) + + assert backend.values(M.JOBS_SUBMITTED) == [1] + assert backend.values(M.CALLS_INVOKED) == [120] + assert backend.values(M.JOB_CALLS) == [120] + + def test_a_job_records_what_the_client_spent_preparing_it(self, recorder): + telemetry, backend = recorder + telemetry.on_job_submitted(_job()) + + assert backend.values(M.JOB_CREATE_DURATION) == [1.8] + assert backend.values(M.JOB_SERIALIZE_DURATION) == [0.4] + assert backend.values(M.JOB_PARTITION_DURATION) == [0.05] + + uploads = { + labels['part']: value + for name, value, labels in backend.observations + if name == M.JOB_UPLOAD_DURATION.name + } + payloads = { + labels['part']: value + for name, value, labels in backend.observations + if name == M.JOB_PAYLOAD_SIZE.name + } + assert uploads == {'function': 0.3, 'data': 0.9} + assert payloads == {'function': 82000, 'data': 5500000} + + def test_a_job_without_metadata_still_records_its_size(self, recorder): + telemetry, backend = recorder + job = SimpleNamespace( + total_calls=7, function_name='my_func', + runtime_name='python:3.11', runtime_memory=512, + ) + telemetry.on_job_submitted(job) + + assert backend.values(M.CALLS_INVOKED) == [7] + assert backend.values(M.JOB_CREATE_DURATION) == [] + + +class TestMemoryAndEnvironment: + + def _by_kind(self, backend, spec): + return { + labels['kind']: value + for name, value, labels in backend.observations + if name == spec.name + } + + def test_every_reading_of_the_memory_is_recorded(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + assert self._by_kind(backend, M.WORKER_MEMORY) == { + 'rss': 268435456, + 'vms': 900000000, + 'uss': 200000000, + 'peak': 402653184, + 'baseline': 90000000, + } + + def test_only_the_readings_that_mean_a_limit_get_a_ratio(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + # 512MB runtime: 256MB resident, 384MB peak + assert self._by_kind(backend, M.WORKER_MEMORY_RATIO) == { + 'rss': 0.5, 'peak': 0.75 + } + + def test_a_worker_that_reports_no_peak_still_reports_the_rest( + self, recorder + ): + # peak_memory() returns None on a worker that is not Unix + telemetry, backend = recorder + status = _call_status() + del status['worker_peak_memory_start'] + del status['worker_peak_memory_end'] + telemetry.on_call_finished(_future(), status) + + kinds = self._by_kind(backend, M.WORKER_MEMORY) + assert set(kinds) == {'rss', 'vms', 'uss'} + assert set(self._by_kind(backend, M.WORKER_MEMORY_RATIO)) == {'rss'} + + def test_the_environment_is_reported_once_per_call(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(), _call_status()) + + info = [ + labels for name, _, labels in backend.observations + if name == M.WORKER_INFO.name + ] + assert len(info) == 1 + assert info[0]['python_version'] == '3.11' + assert info[0]['lithops_version'] + assert 'function_name' not in info[0] + + def test_an_unknown_python_version_is_still_reported(self, recorder): + telemetry, backend = recorder + status = _call_status() + del status['python_version'] + telemetry.on_call_finished(_future(), status) + + info = [ + labels for name, _, labels in backend.observations + if name == M.WORKER_INFO.name + ] + assert info[0]['python_version'] == 'unknown' + + +class TestIncompleteStatuses: + + def test_a_timed_out_call_records_what_little_it_has(self, recorder): + telemetry, backend = recorder + # What the timeout checker of the monitor synthesises: no resource + # usage, and no timestamps from inside the function + status = { + 'type': '__end__', 'exception': True, + 'worker_start_tstamp': 1002.0, 'worker_end_tstamp': 1032.0, + } + telemetry.on_call_finished(_future(), status, M.OUTCOME_TIMEOUT) + + assert backend.values(M.CALL_TOTAL_DURATION) == [30.0] + assert backend.values(M.CALLS_COMPLETED) == [1] + + def test_a_missing_measurement_is_skipped_not_zeroed(self, recorder): + telemetry, backend = recorder + status = _call_status() + for key in ('worker_func_rss', 'worker_func_vms', 'worker_func_uss', + 'worker_peak_memory_start', 'worker_peak_memory_end', + 'worker_func_end_tstamp'): + del status[key] + telemetry.on_call_finished(_future(), status) + + assert backend.values(M.WORKER_MEMORY) == [] + assert backend.values(M.WORKER_MEMORY_RATIO) == [] + assert backend.values(M.CALL_DURATION) == [] + # The measurements that are there are still recorded + assert backend.values(M.CALL_QUEUE_DELAY) == [2.0] + + def test_an_empty_status_records_the_outcome_and_the_environment( + self, recorder + ): + telemetry, backend = recorder + telemetry.on_call_finished( + _future(_status_query_count=None), {} + ) + + assert backend.names() == [ + M.CALLS_COMPLETED.name, M.WORKER_INFO.name + ] + + def test_a_runtime_without_a_memory_size_has_no_ratio(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished(_future(runtime_memory=None), _call_status()) + + assert backend.values(M.WORKER_MEMORY) + assert backend.values(M.WORKER_MEMORY_RATIO) == [] + + def test_clock_skew_does_not_produce_a_negative_duration(self, recorder): + telemetry, backend = recorder + # The worker clock is a fraction ahead of the client clock + telemetry.on_call_finished( + _future(), _call_status(worker_start_tstamp=999.9) + ) + + assert backend.values(M.CALL_QUEUE_DELAY) == [0.0] + + def test_a_non_numeric_measurement_is_ignored(self, recorder): + telemetry, backend = recorder + telemetry.on_call_finished( + _future(), _call_status(func_result_size='big') + ) + + assert backend.values(M.CALL_RESULT_SIZE) == [] + + +class TestReadingTheResult: + """ + The one part of a call the monitor never sees: it happens in + get_result(), long after the future went ready + """ + + # The timestamps are halves so that every delta below is exact in + # binary and can be compared with ==, as the rest of the file does + def _read(self, telemetry, *, submitted=1000.0, status_done=1008.0, + done=1008.5, queries=2, source=M.SOURCE_STORAGE): + future = _future() + future.stats = { + 'host_submit_tstamp': submitted, + 'host_status_done_tstamp': status_done, + 'host_result_done_tstamp': done, + 'host_result_query_count': queries, + } + telemetry.on_result_read(future, source) + return future + + def test_the_download_and_the_end_to_end_are_recorded(self, recorder): + telemetry, backend = recorder + self._read(telemetry) + + assert backend.values(M.CALL_RESULT_DOWNLOAD) == [0.5] + assert backend.values(M.CALL_RESULT_QUERIES) == [2] + assert backend.values(M.CALL_END_TO_END) == [8.5] + + def test_the_source_tells_a_fetch_from_an_inline_result(self, recorder): + telemetry, backend = recorder + self._read(telemetry, source=M.SOURCE_INLINE, queries=0) + self._read(telemetry, source=M.SOURCE_STORAGE) + + sources = { + labels['source'] + for name, _, labels in backend.observations + if name == M.CALL_RESULT_DOWNLOAD.name + } + assert sources == {M.SOURCE_INLINE, M.SOURCE_STORAGE} + + def test_a_result_never_read_records_nothing(self, recorder): + telemetry, backend = recorder + telemetry.on_result_read(_future(), M.SOURCE_STORAGE) + + assert backend.values(M.CALL_RESULT_DOWNLOAD) == [] + assert backend.values(M.CALL_END_TO_END) == [] + + def test_clock_skew_does_not_produce_a_negative_latency(self, recorder): + telemetry, backend = recorder + self._read(telemetry, status_done=1008.75, done=1008.25) + + assert backend.values(M.CALL_RESULT_DOWNLOAD) == [0.0] + + def test_a_broken_future_is_swallowed(self, recorder): + telemetry, _ = recorder + telemetry.on_result_read(object(), M.SOURCE_STORAGE) + + +class TestFutureRecordsItsResult: + """ + The future reaches the exporter through a module level lookup rather + than by holding it, so that it stays picklable: a worker pickles a + future whenever a function returns futures + """ + + def _future_for(self, backend='aws_lambda'): + from lithops.future import ResponseFuture + + job = SimpleNamespace( + job_id='M000', job_key='sess-M000', executor_id='sess', + function_name='my_func', execution_timeout=60, + runtime_name='python:3.11', runtime_memory=512, backend=backend, + ) + storage_config = { + 'backend': 'localhost', + 'localhost': {'storage_bucket': 'bucket'}, + } + return ResponseFuture( + '00000', job, {'host_submit_tstamp': 1000.0}, storage_config + ) + + def test_the_future_knows_which_backend_it_ran_on(self): + assert self._future_for().backend == 'aws_lambda' + + def test_a_future_stays_picklable(self): + import pickle + + future = self._future_for() + assert pickle.loads(pickle.dumps(future)).backend == 'aws_lambda' + + def test_recording_the_result_reaches_the_exporter(self): + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=3600) + future = self._future_for() + future.stats['host_status_done_tstamp'] = 1008.0 + + with patch( + 'lithops.telemetry.exporter._exporter', exporter + ): + future._record_result_stats(M.SOURCE_STORAGE, 2) + exporter.shutdown() + + assert backend.values(M.CALL_RESULT_QUERIES) == [2] + assert future.stats['host_result_query_count'] == 2 + assert future.stats['host_result_done_tstamp'] + + def test_recording_the_result_without_telemetry_is_a_no_op(self): + future = self._future_for() + + future._record_result_stats(M.SOURCE_INLINE, 0) + + assert future.stats['host_result_query_count'] == 0 + assert future.stats['host_result_done_tstamp'] + + +class TestTelemetryNeverBreaksAJob: + + def test_a_backend_that_raises_is_swallowed(self, recorder): + telemetry, backend = recorder + backend.observe = MagicMock(side_effect=RuntimeError('gateway down')) + + telemetry.on_call_finished(_future(), _call_status()) + telemetry.on_call_started(_future(), _call_status()) + telemetry.on_job_submitted( + SimpleNamespace(total_calls=1, function_name='f', + runtime_name='r', runtime_memory=1) + ) + + def test_a_future_missing_its_attributes_is_swallowed(self, recorder): + telemetry, _ = recorder + telemetry.on_call_finished(object(), _call_status()) + + def test_a_flush_that_raises_is_swallowed(self, recorder): + telemetry, backend = recorder + backend.flush = MagicMock(side_effect=OSError('unreachable')) + telemetry.flush() + + def test_an_invented_label_is_dropped_rather_than_written(self): + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=3600) + try: + exporter.observe(M.CALLS_INVOKED, 1, {'backend': 'aws_lambda'}) + finally: + exporter.shutdown() + + assert backend.observations == [] + + +class TestExporterLifecycle: + + def test_shutdown_is_idempotent(self): + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=3600) + exporter.shutdown() + exporter.shutdown() + + assert backend.shutdowns == 1 + + def test_a_flush_after_shutdown_is_ignored(self): + # The executor flushes from an atexit hook of its own, which can + # run after the hook that shut the exporter down + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=3600) + exporter.shutdown() + exporter.flush() + exporter.bind('aws_lambda').flush() + + assert backend.flushes == 0 + assert backend.shutdowns == 1 + + def test_shutting_a_backend_down_flushes_it_by_default(self): + # The last of what was recorded has to leave the process, and a + # backend that holds nothing should not have to say so + class Plain(RecordingBackend): + shutdown = MetricsBackend.shutdown + + backend = Plain() + TelemetryExporter(backend, flush_interval=3600).shutdown() + + assert backend.flushes == 1 + + def test_the_flush_thread_pushes_on_its_own(self): + backend = RecordingBackend() + exporter = TelemetryExporter(backend, flush_interval=0.01) + try: + deadline = time.time() + 2 + while backend.flushes < 2 and time.time() < deadline: + time.sleep(0.01) + assert backend.flushes >= 2 + finally: + exporter.shutdown() + + def test_telemetry_is_off_by_default(self): + assert get_telemetry({'lithops': {}}) is NOOP + assert get_telemetry(None) is NOOP + + def test_one_process_exports_through_one_exporter(self): + config = {'lithops': {'telemetry': 'recording', 'backend': 'aws_lambda'}} + with patch( + 'lithops.telemetry.exporter.load_backend_class', + return_value=RecordingBackend, + ): + first = get_telemetry(config) + second = get_telemetry(config) + + assert isinstance(first, BoundTelemetry) + assert first._exporter is second._exporter + + def test_a_worker_exports_nothing(self, monkeypatch): + # Workers get the client's whole config, and the remote invoker + # builds a JobMonitor of its own + monkeypatch.setenv('LITHOPS_WORKER', 'True') + config = {'lithops': {'telemetry': 'prometheus'}} + + assert get_telemetry(config) is NOOP + + def test_a_backend_that_cannot_be_built_disables_telemetry(self): + config = {'lithops': {'telemetry': 'nonexistent-backend'}} + assert get_telemetry(config) is NOOP + + def test_current_telemetry_never_starts_an_exporter(self): + from lithops.telemetry import current_telemetry + + assert current_telemetry('aws_lambda') is NOOP + + def test_current_telemetry_binds_the_running_exporter(self): + from lithops.telemetry import current_telemetry + + config = {'lithops': {'telemetry': 'recording'}} + with patch( + 'lithops.telemetry.exporter.load_backend_class', + return_value=RecordingBackend, + ): + bound = get_telemetry(config) + later = current_telemetry('aws_lambda') + + assert later._exporter is bound._exporter + assert later._backend == 'aws_lambda' + + def test_the_noop_records_nothing_and_raises_nothing(self): + assert NOOP.enabled is False + NOOP.on_job_submitted(None) + NOOP.on_call_started(None, None) + NOOP.on_call_finished(None, None) + NOOP.on_result_read(None, 'storage') + NOOP.flush() + + +class TestMonitorFunnel: + """ + Every state change of a future has to go past the telemetry, whatever + monitoring backend produced it + """ + + def _monitor(self, telemetry): + monitor = Monitor( + executor_id='sess-0', internal_storage=None, + token_bucket_q=None, job_chunksize={}, + generate_tokens=False, config={}, + ) + monitor.attach_telemetry(telemetry) + return monitor + + def test_an_unattached_monitor_is_safe(self): + monitor = Monitor( + executor_id='sess-0', internal_storage=None, + token_bucket_q=None, job_chunksize={}, + generate_tokens=False, config={}, + ) + assert monitor.telemetry is NOOP + + future = MagicMock() + monitor._mark_ready(future, {}) + future._set_ready.assert_called_once() + + def test_marking_a_future_running_records_it(self, recorder): + telemetry, backend = recorder + monitor = self._monitor(telemetry) + future = _future() + future._set_running = MagicMock() + + monitor._mark_running(future, _call_status()) + + future._set_running.assert_called_once() + assert backend.values(M.CALLS_STARTED) == [1] + + def test_marking_a_future_ready_records_it(self, recorder): + telemetry, backend = recorder + monitor = self._monitor(telemetry) + future = _future() + future._set_ready = MagicMock() + + monitor._mark_ready(future, _call_status()) + + future._set_ready.assert_called_once() + assert backend.values(M.CALLS_COMPLETED) == [1] + + def test_the_status_is_measured_after_the_future_records_it(self, recorder): + telemetry, backend = recorder + monitor = self._monitor(telemetry) + future = _future() + + def _set_ready(call_status): + future._host_status_done_tstamp = 1009.0 + + future._set_ready = _set_ready + monitor._mark_ready(future, _call_status()) + + assert backend.values(M.CALL_STATUS_LATENCY) == [1.0] + + def test_a_chained_call_is_counted_once_under_its_own_outcome( + self, recorder + ): + telemetry, backend = recorder + monitor = self._monitor(telemetry) + future = MagicMock() + future._new_futures = [] + monitor.add_futures = MagicMock() + + assert monitor._check_new_futures({'new_futures': 'x'}, future) is True + + outcomes = [ + labels['outcome'] for name, _, labels in backend.observations + if name == M.CALLS_COMPLETED.name + ] + assert outcomes == [M.OUTCOME_CHAINED] + + def test_a_call_that_returned_no_futures_records_nothing_here( + self, recorder + ): + telemetry, backend = recorder + monitor = self._monitor(telemetry) + + assert monitor._check_new_futures({}, MagicMock()) is False + assert backend.observations == [] + + +class TestPrometheusBackend: + + @pytest.fixture + def backend(self): + prometheus_client = pytest.importorskip('prometheus_client') + assert prometheus_client + from lithops.telemetry.backends.prometheus import MetricsBackend + from lithops.telemetry.backends.prometheus.config import load_config + + config = {'lithops': {'telemetry': 'prometheus'}} + load_config(config) + return MetricsBackend(config['prometheus']) + + def test_defaults_do_not_move_with_the_execution(self): + from lithops.telemetry.backends.prometheus.config import load_config + + first = {'lithops': {}} + second = {'lithops': {}} + load_config(first) + load_config(second) + + assert first['prometheus'] == second['prometheus'] + + def test_a_histogram_gets_the_buckets_of_its_spec(self, backend): + from prometheus_client import generate_latest + + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + } + backend.observe(M.CALL_DURATION, 1.5, labels) + exposed = generate_latest(backend.registry).decode() + + assert 'lithops_call_duration_seconds_bucket' in exposed + for bound in M.CALL_DURATION.buckets: + assert f'le="{float(bound)}"' in exposed + + def test_a_counter_accumulates(self, backend): + from prometheus_client import generate_latest + + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + 'outcome': 'success', + } + backend.observe(M.CALLS_COMPLETED, 1, labels) + backend.observe(M.CALLS_COMPLETED, 2, labels) + exposed = generate_latest(backend.registry).decode() + + assert 'lithops_calls_completed_total{' in exposed + assert '} 3.0' in exposed + + def test_the_instrument_is_built_once(self, backend): + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + } + backend.observe(M.CALLS_STARTED, 1, labels) + backend.observe(M.CALLS_STARTED, 1, labels) + + assert list(backend._instruments) == [M.CALLS_STARTED.name] + + def test_a_flush_replaces_the_group_of_this_host(self, backend): + with patch( + 'prometheus_client.push_to_gateway' + ) as push: + backend.flush() + + push.assert_called_once() + assert push.call_args.kwargs['job'] == 'lithops' + assert set(push.call_args.kwargs['grouping_key']) == {'instance'} + + def test_the_created_series_are_not_pushed(self, backend): + from prometheus_client import generate_latest + from lithops.telemetry.backends.prometheus.prometheus import ( + _WithoutCreatedSeries, + ) + + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + } + backend.observe(M.CALLS_STARTED, 1, labels) + + pushed = generate_latest( + _WithoutCreatedSeries(backend.registry) + ).decode() + assert 'lithops_calls_started_total{' in pushed + assert '_created' not in pushed + # and the registry itself is left as it was + assert '_created' in generate_latest(backend.registry).decode() + + def test_basic_auth_is_used_when_configured(self): + pytest.importorskip('prometheus_client') + from lithops.telemetry.backends.prometheus import MetricsBackend + from lithops.telemetry.backends.prometheus.config import load_config + + config = { + 'lithops': {}, + 'prometheus': {'username': 'u', 'password': 'p'}, + } + load_config(config) + backend = MetricsBackend(config['prometheus']) + + assert backend._handler is not None + + +class TestOtlpBackend: + + @pytest.fixture + def backend_and_reader(self): + pytest.importorskip('opentelemetry.sdk') + from opentelemetry.sdk.metrics.export import InMemoryMetricReader + from lithops.telemetry.backends.otlp import MetricsBackend + from lithops.telemetry.backends.otlp.config import load_config + + config = {'lithops': {'telemetry': 'otlp'}} + load_config(config) + reader = InMemoryMetricReader() + with patch.object( + MetricsBackend, '_create_reader', staticmethod(lambda cfg: reader) + ): + yield MetricsBackend(config['otlp']), reader + + @staticmethod + def _exported(reader): + exported = {} + data = reader.get_metrics_data() + for resource_metrics in data.resource_metrics: + for scope_metrics in resource_metrics.scope_metrics: + for metric in scope_metrics.metrics: + exported[metric.name] = metric + return exported + + def test_the_metric_names_match_the_prometheus_ones( + self, backend_and_reader + ): + backend, reader = backend_and_reader + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + } + backend.observe(M.CALL_DURATION, 1.5, labels) + backend.observe(M.CALLS_STARTED, 1, labels) + + exported = self._exported(reader) + assert M.CALL_DURATION.name in exported + assert M.CALLS_STARTED.name in exported + + def test_a_histogram_gets_the_buckets_of_its_spec( + self, backend_and_reader + ): + backend, reader = backend_and_reader + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + } + backend.observe(M.CALL_DURATION, 1.5, labels) + + metric = self._exported(reader)[M.CALL_DURATION.name] + point = list(metric.data.data_points)[0] + assert tuple(point.explicit_bounds) == tuple(M.CALL_DURATION.buckets) + + def test_the_labels_travel_as_attributes(self, backend_and_reader): + backend, reader = backend_and_reader + labels = { + 'backend': 'aws_lambda', 'runtime_name': 'python:3.11', + 'runtime_memory': '512', 'function_name': 'my_func', + 'outcome': 'success', + } + backend.observe(M.CALLS_COMPLETED, 1, labels) + + metric = self._exported(reader)[M.CALLS_COMPLETED.name] + point = list(metric.data.data_points)[0] + assert dict(point.attributes) == labels + + def test_the_temporality_is_pinned_to_cumulative(self): + pytest.importorskip('opentelemetry.sdk') + from opentelemetry.sdk.metrics.export import AggregationTemporality + from lithops.telemetry.backends.otlp import MetricsBackend + + temporality = MetricsBackend._cumulative_temporality() + + assert temporality + assert set(temporality.values()) == {AggregationTemporality.CUMULATIVE} + + def test_an_unknown_protocol_is_refused(self): + pytest.importorskip('opentelemetry.sdk') + from lithops.telemetry.backends.otlp import MetricsBackend + from lithops.telemetry.backends.otlp.config import load_config + + config = {'lithops': {}, 'otlp': {'protocol': 'carrier-pigeon'}} + load_config(config) + with pytest.raises(ValueError, match='carrier-pigeon'): + MetricsBackend(config['otlp']) + + @pytest.mark.parametrize('endpoint, expected', [ + ('http://collector:4318', 'http://collector:4318/v1/metrics'), + ('http://collector:4318/', 'http://collector:4318/v1/metrics'), + ('http://collector:4318/v1/metrics', 'http://collector:4318/v1/metrics'), + ]) + def test_the_signal_path_is_added_once(self, endpoint, expected): + pytest.importorskip('opentelemetry.sdk') + from lithops.telemetry.backends.otlp.otlp import _metrics_endpoint + + assert _metrics_endpoint(endpoint) == expected + + +class TestConfigIntegration: + + def test_the_telemetry_section_is_filled_in(self): + from lithops.config import _load_telemetry_backend_config + + config = {'lithops': {'telemetry': True}} + _load_telemetry_backend_config(config) + + assert config['lithops']['telemetry'] == DEFAULT_BACKEND + assert config['prometheus']['gateway'] + assert config['prometheus']['instance'] + + def test_a_disabled_telemetry_loads_no_backend(self): + from lithops.config import _load_telemetry_backend_config + + config = {'lithops': {}} + _load_telemetry_backend_config(config) + + assert config['lithops']['telemetry'] is False + assert 'prometheus' not in config + + def test_an_unknown_backend_is_reported(self): + from lithops.config import _load_telemetry_backend_config + + config = {'lithops': {'telemetry': 'graphite'}} + with pytest.raises(Exception, match='graphite'): + _load_telemetry_backend_config(config) + + def test_user_values_are_not_overwritten(self): + from lithops.config import _load_telemetry_backend_config + + config = { + 'lithops': {'telemetry': 'prometheus'}, + 'prometheus': {'gateway': 'http://gw:9091', 'instance': 'ci'}, + } + _load_telemetry_backend_config(config) + + assert config['prometheus']['gateway'] == 'http://gw:9091' + assert config['prometheus']['instance'] == 'ci' diff --git a/lithops/tests/test_util.py b/lithops/tests/test_util.py index 738613aab..e4bb992ca 100644 --- a/lithops/tests/test_util.py +++ b/lithops/tests/test_util.py @@ -20,7 +20,6 @@ import pytest -from lithops.util.metrics import PrometheusExporter from lithops.util.ssh_client import SSHClient, ssh_boot_status_message @@ -137,42 +136,6 @@ def test_upload_multiple_and_data(self): remote.write.assert_called_once_with('hello') -class TestPrometheusExporter: - - def test_missing_session_id_does_not_raise(self, monkeypatch): - monkeypatch.delenv('__LITHOPS_SESSION_ID', raising=False) - exporter = PrometheusExporter(False, None) - assert exporter.instance == 'lithops' - exporter.send_metric('n', 1, type='gauge', labels=[]) - - def test_instance_from_session_id(self, monkeypatch): - monkeypatch.setenv('__LITHOPS_SESSION_ID', 'ek-j0-00000') - exporter = PrometheusExporter(True, {'apigateway': 'http://prom'}) - assert exporter.instance == 'ek' - - def test_send_metric_posts_when_enabled(self, monkeypatch): - monkeypatch.setenv('__LITHOPS_SESSION_ID', 'sid-1') - exporter = PrometheusExporter(True, {'apigateway': 'http://prom'}) - with patch('lithops.util.metrics.requests.post') as post: - exporter.send_metric( - 'function_start', 1.5, type='gauge', - labels=[('job_id', 'j'), ('call_id', 'c')], - ) - post.assert_called_once() - url = post.call_args[0][0] - assert url.startswith('http://prom/metrics/') - assert 'job/lithops' in url - assert 'function_start' in post.call_args.kwargs['data'] - - def test_send_metric_swallows_post_errors(self, monkeypatch): - monkeypatch.setenv('__LITHOPS_SESSION_ID', 'sid-1') - exporter = PrometheusExporter(True, {'apigateway': 'http://prom'}) - with patch( - 'lithops.util.metrics.requests.post', side_effect=OSError('down') - ): - exporter.send_metric('n', 1, type='gauge', labels=[]) - - class TestIBMTokenManager: """ ibm_token_manager imports ibm_botocore, which is only present with the diff --git a/lithops/util/metrics.py b/lithops/util/metrics.py deleted file mode 100644 index d3995c259..000000000 --- a/lithops/util/metrics.py +++ /dev/null @@ -1,48 +0,0 @@ -import logging -import os -from typing import Any, Dict, Optional, Sequence, Tuple - -import requests - -logger = logging.getLogger(__name__) - -_DEFAULT_INSTANCE = 'lithops' - - -class PrometheusExporter: - """ - Pushes Lithops metrics to a Prometheus pushgateway sitting behind an API - Gateway. Does nothing unless it is enabled and a gateway is configured - """ - - def __init__(self, enabled: bool, config: Optional[Dict[str, Any]]): - self.enabled = enabled - self.apigateway = config.get('apigateway') if config else None - self.job = 'lithops' - session_id = os.environ.get('__LITHOPS_SESSION_ID', _DEFAULT_INSTANCE) - self.instance = session_id.split('-')[0] - - def send_metric( - self, - name: str, - value: Any, - type: str, - labels: Sequence[Tuple[str, Any]], - ) -> None: - """ - Sends a single metric, with the labels appended to the pushgateway - grouping key. Errors are logged and swallowed: metrics are optional - """ - if not (self.enabled and self.apigateway): - return - - dim = f'job/{self.job}/instance/{self.instance}' - for key, val in labels: - dim += f'/{key}/{val}' - url = '/'.join([self.apigateway, 'metrics', dim]) - logger.debug(f'Sending metric "{name} {value} ({type})" to {url}') - - try: - requests.post(url, data=f'# TYPE {name} {type}\n{name} {value}\n') - except Exception as exc: - logger.error(exc) diff --git a/lithops/worker/jobrunner.py b/lithops/worker/jobrunner.py index 6d893822a..5557604d7 100644 --- a/lithops/worker/jobrunner.py +++ b/lithops/worker/jobrunner.py @@ -46,7 +46,6 @@ WrappedStreamingBody, sizeof_fmt, is_object_processing_function, FuturesList, verify_args, WrappedStreamingBodyPartition ) -from lithops.util.metrics import PrometheusExporter from lithops.storage.utils import create_output_key logger = logging.getLogger(__name__) @@ -133,19 +132,6 @@ def __init__(self, job: SimpleNamespace, jobrunner_conn, internal_storage): ) self.stats = JobStats(self.job.stats_file) - prom_enabled = self.lithops_config['lithops'].get('telemetry') - prom_config = self.lithops_config.get('prometheus', {}) - self.prometheus = PrometheusExporter(prom_enabled, prom_config) - - def _prom_labels( - self, fn_name: Optional[str] - ) -> Tuple[Tuple[str, str], ...]: - return ( - ('job_id', self.job.job_key), - ('call_id', '-'.join([self.job.job_key, self.job.call_id])), - ('function_name', fn_name or 'undefined') - ) - def _create_ibm_cos_client(self): """Creates the boto3 client injected as the ibm_cos parameter""" if 'ibm_cos' not in self.lithops_config: @@ -386,13 +372,6 @@ def run(self) -> None: self._fill_optional_args(func, data) fn_name = _get_function_name(func) - self.prometheus.send_metric( - name='function_start', - value=time.time(), - type='gauge', - labels=self._prom_labels(fn_name) - ) - logger.info(f"Going to execute '{fn_name}()'") print('---------------------- FUNCTION LOG ----------------------') function_start_tstamp = time.time() @@ -412,12 +391,6 @@ def run(self) -> None: finally: self.stats.write('worker_peak_memory_end', peak_memory()) - self.prometheus.send_metric( - name='function_end', - value=time.time(), - type='gauge', - labels=self._prom_labels(fn_name) - ) if pending_output is not None: self._upload_result(pending_output) diff --git a/setup.py b/setup.py index bb1dee9fe..8af234063 100644 --- a/setup.py +++ b/setup.py @@ -99,6 +99,11 @@ 'flask', 'gevent', 'scikit-learn', + ], + 'telemetry': [ + 'prometheus-client', + 'opentelemetry-sdk', + 'opentelemetry-exporter-otlp-proto-http', ] }