Applies to VAST Cluster 5.5.
This guide shows how to see what your pipeline is doing from the command line: read and follow logs with vastde logs, find and inspect traces with vastde traces, and query built-in and custom metrics with vastde metrics. It also covers adding your own metrics in code, what to do when a function produces no logs at all, and the CLI's quirks in vastde v5.5.0-sp2.
It uses the thumbnails pipeline from the quickstart, with thumbnailer linked to indexer as in pipelines as code, and the failing errors-demo pipeline from retries and the dead-letter topic. The outputs come from a lab cluster running VAST Cluster 5.5.0-SP6 with vastde v5.5.0-sp2. Your names, IDs, GUIDs and times will differ. For where telemetry goes and how long it's kept, see logs, traces and metrics.
Logs
vastde logs get <pipeline> returns the logs of every function in a pipeline, oldest first. Each line has the time, the function deployment, the level, the scope ([user] for your code, [vast-runtime] for the runtime around it) and the message.
Filter
The filters can be combined. Only your own lines, for the last two minutes:
vastde logs get thumbnails --since 2m --scope user
2026-10-08 13:10:40.57 [indexer] [INFO] [user] indexer initialized
2026-10-08 13:11:34.30 [thumbnailer] [INFO] [user] v2: thumbnail for s3://docs-src/photos/heron.jpg -> thumbnails/heron.jpg
2026-10-08 13:11:34.71 [indexer] [INFO] [user] indexed photos/heron.jpg (thumbnail thumbnails/heron.jpg)
2026-10-08 13:11:35.54 [thumbnailer] [INFO] [user] v2: thumbnail for s3://docs-src/photos/ibis.jpg -> thumbnails/ibis.jpg
2026-10-08 13:11:35.77 [indexer] [INFO] [user] indexed photos/ibis.jpg (thumbnail thumbnails/ibis.jpg)
2026-10-08 13:11:37.03 [thumbnailer] [INFO] [user] v2: thumbnail for s3://docs-src/photos/scratch.tmp -> thumbnails/scratch.tmp
2026-10-08 13:11:37.18 [indexer] [INFO] [user] indexed photos/scratch.tmp (thumbnail thumbnails/scratch.tmp)
2026-10-08 13:11:37.18 [indexer] [WARN] [user] skipping temporary file photos/scratch.tmp
One level (--severity), here warnings:
vastde logs get thumbnails --since 2m --severity WARN
2026-10-08 13:11:37.18 [indexer] [WARN] [user] skipping temporary file photos/scratch.tmp
One function deployment (--function), with the runtime's lines around each call:
vastde logs get thumbnails --since 2m --function indexer
2026-10-08 13:10:39.24 [indexer] [INFO] [vast-runtime] Print function intercepted and redirected to 'user-print' logger
…
2026-10-08 13:10:40.57 [indexer] [INFO] [vast-runtime] Call Init Handler: init
2026-10-08 13:10:40.57 [indexer] [INFO] [user] indexer initialized
2026-10-08 13:10:40.57 [indexer] [INFO] [vast-runtime] Init Handler Completed, duration: 0:00:00.001729
2026-10-08 13:10:40.57 [indexer] [INFO] [vast-runtime] Handler is now ready to accept requests
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] START EventId: 87982405058567, TraceId: -, EventType: vastdata.com:Function, EventSource: vastdata.com:thumbnailer-nbdn4ypiyaaaa, Timestamp: 1791465094.7101285
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] Function invoked in timestamp 2026-10-08 13:11:34.710622. Event batching mode: False
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] Starting running function in timestamp 2026-10-08 13:11:34.711624
2026-10-08 13:11:34.71 [indexer] [INFO] [user] indexed photos/heron.jpg (thumbnail thumbnails/heron.jpg)
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] Function returned: None in timestamp 2026-10-08 13:11:34.712576 with duration 0.7176399230957031 milliseconds
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] No sink URL configured
2026-10-08 13:11:34.71 [indexer] [INFO] [vast-runtime] END EventId: 87982405058567, TraceId: -, Duration: 0.0032s, Response: <starlette.responses.Response object at 0x7fdafdf55520>, Timestamp: 1791465094.7132595
…
Each call is framed by a START and an END line with the event's ID, and the runtime logs what the handler returned (Function returned:). Error in handler execution: lines, at ERROR, are the runtime reporting an exception from your handler:
vastde logs get errors-demo --since 30m --severity ERROR --limit 5
2026-10-08 12:53:07.18 [faulty] [ERROR] [vast-runtime] Error in handler execution: cannot process fail/broken.txt
2026-10-08 12:53:09.19 [faulty] [ERROR] [vast-runtime] Error in handler execution: cannot process fail/broken.txt
2026-10-08 12:53:13.21 [faulty] [ERROR] [vast-runtime] Error in handler execution: cannot process fail/broken.txt
2026-10-08 12:53:21.22 [faulty] [ERROR] [vast-runtime] Error in handler execution: cannot process fail/broken.txt
2026-10-08 12:53:37.23 [faulty] [ERROR] [vast-runtime] Error in handler execution: cannot process fail/broken.txt
Get the latest lines, not the oldest
vastde logs get returns at most --limit lines, 100 unless you set it, counting from the oldest in the time window. On a busy pipeline the newest lines are the ones cut off, without a warning. Here, at 13:21, the default stops more than five minutes short:
vastde logs get ticks --since 15m | wc -l
100
vastde logs get ticks --since 15m | tail -1
2026-10-08 13:16:02.62 [ticker] [INFO] [vast-runtime] END EventId: 17914653600008216970, TraceId: 17914653-6000-0821-bd29-322d7bfe46f1, Duration: 0.0027s, Response: <starlette.responses.Response object at 0x7f1b41a8f7a0>, Timestamp: 1791465362.626268
A higher --limit gets the whole window:
vastde logs get ticks --since 15m --limit 1000 | wc -l
145
For the most recent lines, sort newest first and limit:
vastde logs get ticks --since 15m --order-by desc --limit 1
2026-10-08 13:22:02.74 [ticker] [INFO] [vast-runtime] END EventId: 17914657200014718335, TraceId: 17914657-2000-1471-bd29-322d7bfe46f1, Duration: 0.0029s, Response: <starlette.responses.Response object at 0x7f1b41a00980>, Timestamp: 1791465722.7403924
vastde logs get thumbnails --since 2m --scope user --order-by desc --limit 3
2026-10-08 13:11:37.18 [indexer] [WARN] [user] skipping temporary file photos/scratch.tmp
2026-10-08 13:11:37.18 [indexer] [INFO] [user] indexed photos/scratch.tmp (thumbnail thumbnails/scratch.tmp)
2026-10-08 13:11:37.03 [thumbnailer] [INFO] [user] v2: thumbnail for s3://docs-src/photos/scratch.tmp -> thumbnails/scratch.tmp
So in scripts, always set --since and either --limit high enough or --order-by desc.
As JSON
-o json returns each record with the function, revision and pipeline revision it came from, and its trace and span IDs:
vastde logs get thumbnails --since 2m --scope user -o json --limit 1
[
{
"guid": "193f160d-7fcd-46c3-877b-351004e4deba",
"message": "indexer initialized",
"observed_timestamp": 1791465040572674,
"resource": {
"function_deployment_name": "indexer",
"function_deployment_vrn": "vast:dataengine:function-deployments:thumbnails/indexer",
"function_host": "indexer-nbdn4ypiyaaaa-00002-deployment-84685bd9bf-lzgdh",
"function_id": "2d2524d6-525f-4e4f-bcdc-f9e2525d4136",
"function_name": "indexer",
"function_revision_id": "4ade094e-4230-458b-a6b4-cc4a10b901bf",
"function_version": "2",
"function_vrn": "vast:dataengine:functions:indexer",
"owner_vid": 4294967295,
"pipeline_id": "c7f63133-3438-4cae-af6a-91291041f1b6",
"pipeline_name": "thumbnails",
"pipeline_revision_id": "d94772b0-2eb9-41df-a4e4-ffacb8e0ee75",
"pipeline_version": "5",
"pipeline_vrn": "vast:dataengine:pipelines:thumbnails",
"runtime_version": "0.2.0",
"sdk_version": "0.2.0",
"tenant_id": "da47bae0-aefd-4e85-a5a9-2020d6a2cb91"
},
"scope": "user",
"severity": "INFO",
"span_id": "",
"timestamp": 1791465040572505,
"trace_id": ""
}
]
function_version is the function revision that wrote the line and pipeline_version the pipeline revision: useful to check that a deploy rolled out what you expected. Timestamps are microseconds since the epoch. This init line has no trace ID; lines written while handling an event have one.
Follow
vastde logs tail <pipeline> keeps printing new lines until you press Ctrl+C. Without --since, it first replays the pipeline's history:
vastde logs tail thumbnails --scope user
2026-10-08 12:25:29.84 [thumbnailer] [INFO] [user] thumbnailer initialized
2026-10-08 12:26:58.94 [thumbnailer] [INFO] [user] new object: bucket=docs-src key=photos/cat.jpg
2026-10-08 12:35:07.07 [thumbnailer] [INFO] [user] new object: bucket=docs-src key=photos/dog.jpg
…
2026-10-08 13:11:37.18 [indexer] [INFO] [user] indexed photos/scratch.tmp (thumbnail thumbnails/scratch.tmp)
2026-10-08 13:11:37.18 [indexer] [WARN] [user] skipping temporary file photos/scratch.tmp
2026-10-08 13:12:34.73 [indexer] [INFO] [user] indexed photos/kite.jpg (thumbnail thumbnails/kite.jpg)
Received interrupt signal, shutting down
The last indexed line came from an upload of photos/kite.jpg made while tail was running. thumbnailer's line for the same upload didn't appear in the tail, although that function ran (its trace is below). Use tail to watch, and logs get when you need every line.
Traces
Each event gets a trace that follows it through every function it reaches. vastde traces list <pipeline> lists them, oldest first, with their status:
vastde traces list thumbnails --since 10m
Trace ID Status Pipeline Function Start Time End Time
--------------------------------------------------------------------------------------------------------------------------------------
a51397fc5b7d2eab9eafee957b6d1e58 OK thumbnails indexer 2026-10-08 13:10:40.571 2026-10-08 13:10:40.574
0000500500000007d94772b02eb941df OK thumbnails indexer 2026-10-08 13:11:34.308 2026-10-08 13:11:34.713
0000500500000009d94772b02eb941df OK thumbnails thumbnailer 2026-10-08 13:11:35.542 2026-10-08 13:11:35.772
000050050000000bd94772b02eb941df OK thumbnails thumbnailer 2026-10-08 13:11:37.032 2026-10-08 13:11:37.181
000050150000000ed94772b02eb941df OK thumbnails thumbnailer 2026-10-08 13:12:34.293 2026-10-08 13:12:34.730
- The first trace is an instance's
init(here,indexer's new instance after a deploy). Every instance start gets one. - The other four are the four uploads. Each spans both functions, from
thumbnailer's start toindexer's end, although the Function column names only one of them.
Filter by status to find failures:
vastde traces list errors-demo --since 30m --status ERROR --limit 5
Trace ID Status Pipeline Function Start Time End Time
--------------------------------------------------------------------------------------------------------------------------------------
000050150000000a2de0c9d069d74986 ERROR errors-demo faulty 2026-10-08 12:53:07.178 2026-10-08 13:10:09.331
One event's retries stay in one trace, so this trace lasts from the first attempt to the latest.
vastde traces get <trace ID> shows a trace's event and the function instance that handled it:
vastde traces get 0000500500000007d94772b02eb941df
Trace Details (1 traces)
Trace 1: 0000500500000007d94772b02eb941df
Trace ID: 0000500500000007d94772b02eb941df
Start Time: 1791465094308895
End Time: 1791465094713183
Start Time: 2026-10-08 13:11:34.308
End Time: 2026-10-08 13:11:34.713
Duration: 404.288µs
Status: OK
Event
event_id: 87982405058567
event_type: vastdata.com:Function
event_source: vastdata.com:thumbnailer-nbdn4ypiyaaaa
event_subject: vast-broker-docs-kafka.default
Resource
Pipeline: thumbnails (id: c7f63133-3438-4cae-af6a-91291041f1b6)
Function: indexer (id: 2d2524d6-525f-4e4f-bcdc-f9e2525d4136, instance: indexer-nbdn4ypiyaaaa-00002-deployment-84685bd9bf-lzgdh)
Duration is in milliseconds, not microseconds: in vastde v5.5.0-sp2 the unit is printed wrong. The start and end times above are microseconds since the epoch, and they're 404,288 µs apart, so this trace took 404 ms.
The trace's spans, and the logs of each span, are easier to read in the VAST Web UI's trace view, which draws the tree across functions. See coming from the UI.
Metrics
Every function exports runtime metrics, and you can add your own. vastde metrics names lists what a pipeline has:
vastde metrics names -p thumbnails -o yaml
- description: Event reception latency
name: dataengine.event.reception_latency
scope: vast-runtime
type: Histogram
unit: ms
- description: Number of events processed
name: dataengine.event.total
scope: vast-runtime
type: Counter
unit: "1"
- description: Number of function invocations
name: dataengine.function.invocations
scope: vast-runtime
type: Counter
unit: "1"
- description: Function execution duration
name: dataengine.function.invoke_duration
scope: vast-runtime
type: Histogram
unit: ms
- description: Thumbnails added to the index
name: thumbnails.indexed
scope: user
type: Counter
unit: "1"
The table form (without -o yaml) cuts long names short. dataengine.function.errors appears once a function has failed:
vastde metrics names -p errors-demo
Name Scope Unit Type Description
-------------------------------------------------------------------------------------------------
dataengine.event.recep... vast-ru... ms Histogram Event reception latency
dataengine.event.total vast-ru... 1 Counter Number of events processed
dataengine.function.er... vast-ru... 1 Counter Number of function errors
dataengine.function.in... vast-ru... 1 Counter Number of function invocations
Add a custom metric
thumbnails.indexed, in the list above, is a counter that indexer creates and increments in its handler:
def init(ctx):
ctx.logger.info("indexer initialized")
def handler(ctx, event):
data = event.get_data()
# A custom counter, exported with the function's built-in metrics
ctx.counter("thumbnails.indexed", unit="1", description="Thumbnails added to the index").add(1)
ctx.logger.info("indexed %s (thumbnail %s)", data["key"], data["thumbnail_key"])
if data["key"].endswith(".tmp"):
ctx.logger.warning("skipping temporary file %s", data["key"])
ctx.counter() returns the same counter each time you call it with the same name, so it's safe in the handler. ctx.histogram(), ctx.updowncounter() and ctx.gauge() work the same way. Names start with a letter, and the dataengine. names above are reserved. See metrics in the Runtime SDK reference.
Query
vastde metrics get takes one or more metric names (-m), a pipeline (-p), an aggregation (-a, such as sum or p95), a time window (-w) and the number of points to return (-n). It prints JSON. After four uploads:
vastde metrics get -m thumbnails.indexed -p thumbnails -a sum -w 15m -n 3
{
"query": {
"aggregation": "sum",
"bucket_size_seconds": 300,
"filters": {
"pipeline": "thumbnails"
},
"metric_names": [
"thumbnails.indexed"
],
"time_range": {
"end": "2026-10-08T13:16:18.906304Z",
"start": "2026-10-08T13:01:18.906304Z"
}
},
"results": [
{
"groups": [
{
"data": [
[
"2026-10-08T13:00:00+00:00",
null,
0
],
[
"2026-10-08T13:05:00+00:00",
null,
0
],
[
"2026-10-08T13:10:00+00:00",
4,
2
],
[
"2026-10-08T13:15:00+00:00",
null,
0
]
],
"group": null,
"prop_list": [
"timestamp",
"value",
"count"
],
"statistics": {
"raw_points_count": 2,
"total_points": 1
}
}
],
"metric_description": "Thumbnails added to the index",
"metric_name": "thumbnails.indexed",
"metric_type": "Counter",
"metric_unit": "1",
"scope": "user"
}
]
}
Each data point is [bucket start, value, count] (prop_list): value is the aggregate for the bucket (4 thumbnails indexed between 13:10 and 13:15) and count the number of data points the functions exported in it. A bucket with nothing in it has null.
-g function_name splits a pipeline-wide metric by function deployment, one group each:
vastde metrics get -m dataengine.function.invocations -p thumbnails -g function_name -a sum -w 1h -n 2
{
"query": {
"aggregation": "sum",
"bucket_size_seconds": 1800,
"filters": {
"group_by": "function_name",
"pipeline": "thumbnails"
},
"metric_names": [
"dataengine.function.invocations"
],
"time_range": {
"end": "2026-10-08T13:16:21.262288Z",
"start": "2026-10-08T12:16:21.262288Z"
}
},
"results": [
{
"groups": [
{
"data": [
[
"2026-10-08T12:00:00+00:00",
null,
0
],
[
"2026-10-08T12:30:00+00:00",
1,
1
],
[
"2026-10-08T13:00:00+00:00",
4,
2
]
],
"group": "indexer",
…
"group": "thumbnailer",
…
"groups_found": [
"indexer",
"thumbnailer"
],
"metric_description": "Number of function invocations",
"metric_name": "dataengine.function.invocations",
"metric_type": "Counter",
"metric_unit": "1",
"scope": "vast-runtime"
}
]
}
For histograms such as dataengine.function.invoke_duration (in ms), use a percentile, for example -a p95. To compare failures with calls, query both counters at once:
vastde metrics get -m dataengine.function.errors,dataengine.function.invocations -p errors-demo -a sum -w 1h -n 2
{
"query": {
"aggregation": "sum",
"bucket_size_seconds": 1800,
"filters": {
"pipeline": "errors-demo"
},
"metric_names": [
"dataengine.function.errors",
"dataengine.function.invocations"
],
"time_range": {
"end": "2026-10-08T13:16:35.232887Z",
"start": "2026-10-08T12:16:35.232887Z"
}
},
"results": [
{
"groups": [
{
"data": [
[
"2026-10-08T12:00:00+00:00",
null,
0
],
[
"2026-10-08T12:30:00+00:00",
8,
4
],
[
"2026-10-08T13:00:00+00:00",
2,
2
]
],
…
"2026-10-08T13:00:00+00:00",
2,
2
]
],
"group": null,
"prop_list": [
"timestamp",
"value",
"count"
],
"statistics": {
"raw_points_count": 6,
"total_points": 2
}
}
],
"metric_description": "Number of function invocations",
"metric_name": "dataengine.function.invocations",
"metric_type": "Counter",
"metric_unit": "1",
"scope": "vast-runtime"
}
]
}
In the 13:00 bucket, errors and invocations are both 2: every call of faulty failed. The metrics in one query must all be of the same type:
vastde metrics get -m dataengine.event.reception_latency,dataengine.event.total -p thumbnails -w 1h -n 2
422 Unprocessable Entity ({"metric_type": "All metrics must have the same type. Found types: Counter, Histogram"})
When there are no logs
A function that fails while its handler file is being imported never gets as far as sending logs. Its pipeline stays InProgress, and vastde logs get has nothing:
vastde logs get errors-init --since 10m
No logs found. Try increasing the start time or changing the scope.
vastde pipelines get errors-init -o yaml
created_at: "2026-10-08T13:17:57.395Z"
guid: 6a0e2770-c755-4e3d-9bcf-13cc998a1436
id: 7.513950817699758e+18
kubernetes_cluster_vrn: vast:dataengine:kubernetes-clusters:test-cluster
last_revision_number: 1
name: errors-init
namespace: dataengine-ns-da47bae0-aefd-4e85-a5a9-2020d6a2cb91
owner:
id: "4294967295"
id_type: vid
name: root
reason: Waiting for pipeline to become ready...
status: InProgress
tenant_guid: da47bae0-aefd-4e85-a5a9-2020d6a2cb91
updated_at: "2026-10-08T13:17:57.395Z"
vrn: vast:dataengine:pipelines:errors-init
After several minutes the status changes to Error, and the reason then carries the container's output, including the traceback; write a function shows it. You don't have to wait: run the same image with vastde functions localrun and the traceback appears in seconds (catch start-up errors). Whenever a pipeline stays InProgress for more than a minute or two, check vastde pipelines get <pipeline> -o yaml and run the image locally.
A checklist for one upload
vastde traces list <pipeline> --since 5m: is there a trace, and is itOK? No trace means the trigger didn't fire (check its filters and the pipeline's status) or the event hasn't arrived yet.vastde logs get <pipeline> --since 5m --scope user --order-by desc --limit 50: what did your code log?vastde logs get <pipeline> --since 5m --severity ERROR: did a handler raise? Repeated lines for the same object are retries.vastde pipelines get <pipeline> -o yaml: is the pipelineReady, and what doesreasonsay?- After retries run out, the event is in the dead-letter topic: see read the dead-letter topic.
See also
- Architecture: logs, traces and metrics: where telemetry goes.
- Runtime SDK reference: logging, tracing and metric instruments.
- Coming from the UI: the dashboard, logs and trace views.
- KB: Viewing logs and traces, Collecting custom metrics