|
| 1 | +# OpenTelemetry example |
| 2 | + |
| 3 | +An example HTTP server that uses a Valkey client, both of which emit Distributed Tracing spans |
| 4 | +via [Swift OTel](https://github.com/swift-otel/swift-otel). |
| 5 | + |
| 6 | +## Overview |
| 7 | + |
| 8 | +This example bootstraps Swift OTel to export Distributed Tracing spans to Jaeger. |
| 9 | + |
| 10 | +It then starts a Hummingbird HTTP server along with its associated middleware for instrumentation. |
| 11 | + |
| 12 | +Finally, the server uses a Valkey client in its request handler to demonstrate the spans |
| 13 | +created by executing various Valkey commands. |
| 14 | + |
| 15 | +## Testing |
| 16 | + |
| 17 | +The example uses [Docker Compose](https://docs.docker.com/compose) to run a Valkey server alongside Jaeger to collect |
| 18 | +and visualize the spans from the HTTP server and Valkey client, which is running on your local machine. |
| 19 | + |
| 20 | +### Running Valkey and Jaeger |
| 21 | + |
| 22 | +In one terminal window, run the following command: |
| 23 | + |
| 24 | +```console |
| 25 | +% docker compose up |
| 26 | +[+] Running 4/4 |
| 27 | + ✔ Network open-telemetry_default Created 0.0s |
| 28 | + ✔ Volume "open-telemetry_valkey_data" Created 0.0s |
| 29 | + ✔ Container open-telemetry-jaeger-1 Created 0.0s |
| 30 | + ✔ Container open-telemetry-valkey-1 Created 0.0s |
| 31 | +... |
| 32 | +``` |
| 33 | + |
| 34 | +### Running the server |
| 35 | + |
| 36 | +Now, in another terminal, run the server locally using the following command: |
| 37 | + |
| 38 | +```console |
| 39 | +% swift run |
| 40 | +``` |
| 41 | + |
| 42 | +### Making some requests |
| 43 | + |
| 44 | +Finally, in a third terminal, make a request to the server: |
| 45 | + |
| 46 | +```console |
| 47 | +% curl http://localhost:8080/compute/42 |
| 48 | +``` |
| 49 | + |
| 50 | +The example server fakes an expensive algorithm which is hard-coded to take a couple of seconds to complete. |
| 51 | +That's why the first request will take a decent amount of time. |
| 52 | + |
| 53 | +Now, make the same request again: |
| 54 | + |
| 55 | +```console |
| 56 | +% curl http://localhost:8080/compute/42 |
| 57 | +``` |
| 58 | + |
| 59 | +You should see that it returns instantaniously. We successfully cached the previously computed value in Valkey |
| 60 | +and can now read it from the cache instead of re-computing it each time. |
| 61 | + |
| 62 | +### Visualizing the traces using Jaeger UI |
| 63 | + |
| 64 | +Visit Jaeger UI in your browser at [localhost:16686](http://localhost:16686). |
| 65 | + |
| 66 | +Select `example` from the dropdown and click `Find Traces`. |
| 67 | + |
| 68 | +You should see a handful of traces, including: |
| 69 | + |
| 70 | +#### `/compute/{x}` with an execution time of ~ 3.2 seconds |
| 71 | + |
| 72 | +This corresponds to the first request to `/42` where we had to compute the value. Click on this trace to reveal |
| 73 | +its spans. The root span represents our entire Hummingbird request handling. Nested inside are three child spans: |
| 74 | + |
| 75 | +1. `HGET`: Shows the `HGET` Valkey command used to look up the cached value for `42`. |
| 76 | +2. `compute`: Represents our expensive algorithm. We can see that this takes up the majority of the entire trace. |
| 77 | +3. `HSET`: Shows the `HSET` Valkey command sent to store the computed value for future retrieval. |
| 78 | + |
| 79 | +#### `/compute/{x}` with an execution time of a few milliseconds |
| 80 | + |
| 81 | +This span corresponds to a subsequent request to `/42` where we could utelize our cache to avoid the |
| 82 | +expensive computation. Click on this trace to reveal its spans. Like before, the root span represents |
| 83 | +the Hummingbird request handling. We can also see a single child span: |
| 84 | + |
| 85 | +1. `HGET`: Shows the `HGET` Valkey command used to look up the cached value for `42`. |
| 86 | + |
| 87 | +### Making some more requests |
| 88 | + |
| 89 | +The example also comes with a few more API endpoints to demonstrate other Valkey commands: |
| 90 | + |
| 91 | +#### Pipelined commands |
| 92 | + |
| 93 | +Send the following request to kick off multiple pipelined commands: |
| 94 | + |
| 95 | +```console |
| 96 | +% curl http://localhost:8080/multi |
| 97 | +``` |
| 98 | + |
| 99 | +This will run three pipelined `EVAL` commands and produces a trace made up of the following spans: |
| 100 | + |
| 101 | +1. `/multi`: The Hummingbird request handling. |
| 102 | +2. `MULTI`: The Valkey client span representing the execution of the pipelined commands. |
| 103 | + |
| 104 | +Click on the `MULTI` span to reveal its attributes. New here are the following two attributes: |
| 105 | + |
| 106 | +- `db.operation.batch.size`: This is set to `3` and represents the number of pipelined commands. |
| 107 | +- `db.operation.name`: This is set to `MULTI EVAL`, showing that the pipeline consists only of `EVAL` commands. |
| 108 | + |
| 109 | +#### Failing commands |
| 110 | + |
| 111 | +Send the following request to send some gibberish to Valkey resulting in an error: |
| 112 | + |
| 113 | +```console |
| 114 | +% curl http://localhost:8080/error |
| 115 | +``` |
| 116 | + |
| 117 | +This will send an `EVAL` command with invalid script contents (`EVAL not a script`) resulting in a trace |
| 118 | +made up of the following spans: |
| 119 | + |
| 120 | +1. `/error`: The Hummingbird request handling. |
| 121 | +2. `EVAL`: The Valkey client span representing the failed `EVAL` command. |
| 122 | + |
| 123 | +Click on the `EVAL` span to reveal its attributes. New here are the following two attributes: |
| 124 | + |
| 125 | +- `db.response.status_code`: This is set to `ERR` and represents the prefix of the simple error returned |
| 126 | +by Valkey. |
| 127 | +- `error`: This is set to `true` indicating that the operation failed. In Jaeger, this is additionally displayed |
| 128 | +via a red exclamation mark next to the span name. |
0 commit comments