Integrate Tracing (derived from OpenTelemetry) #15

CMCDragonkai · 2022-07-19T16:01:07Z

Specification

OpenTelemetry is an overly complicated beast. It's far too complex to adopt into a logging system. However the basic principles of tracing makes sense. Here I'm showing how you can set one up for comparison testing, for us to derive a tracing schema and later visualise it ourselves or by passing it into an OTLP compatible visualiser.

docker run -d --name jaeger \
  -e COLLECTOR_ZIPKIN_HOST_PORT=:9411 \
  -e COLLECTOR_OTLP_ENABLED=true \
  -p 6831:6831/udp \
  -p 6832:6832/udp \
  -p 5778:5778 \
  -p 16686:16686 \
  -p 4317:4317 \
  -p 4318:4318 \
  -p 14250:14250 \
  -p 14268:14268 \
  -p 14269:14269 \
  -p 9411:9411 \
  jaegertracing/all-in-one:1.36

The above command runs jaeger. Take note of 4318 port which is the OTLP protocol over HTTP.

Visit localhost:16686 to be able to view the jaeger system.

Then any example code, like for example https://github.com/open-telemetry/opentelemetry-js/blob/main/examples/basic-tracer-node/index.js can run and push traces directly to the docker container.

What is frustrating is:

OpenTelemetry code only exports to stderr as an afterthought, it's not considered first class usage
The stderr exporters output via console.log and produce pretty printed results that are not actual JSON. Thus you cannot just pipe it to a relevant location.
The schema of the span data isn't clear, it seems different parts of the documentation still have old data, or maybe the JS implementation itself is hasn't been updated to the new schema.

The plan:

Create your own "span" derived from opentelemetry and output as just regular structured JSON
Massage it to be compatible to open telemetry viewers like jaeger
Use jaeger's 4318 to stream the JSON and view data in the interim
Find an easier way to visualise traces, maybe something that can be used CLI or in the GUI
For production usage, feed to any structured log capturer, and then feed into a viewer that understands trace information

Additional context

Tasks

...
...
...

The text was updated successfully, but these errors were encountered:

CMCDragonkai · 2022-07-19T16:05:56Z

It seems alot of the complexity is due to the vendors fragmentation and they are trying to make everything compatible.

CMCDragonkai · 2022-07-19T17:04:36Z

Most tracing tools like https://nodejs.org/api/tracing.html and chrome:://tracing expect a finite dataset, that is expected that a trace has a beginning and end. That's why it's always been "request" driven. Open telemetry is just deriving stuff that came before like in https://github.com/gaogaotiantian/viztracer https://github.com/janestreet/magic-trace https://github.com/kunalb/panopticon and more.

I'm interested in more than just request-driven tracing but live infinite traces (call it continuous tracing that shows finished and live spans at the same time), and correlates them too. I'm guessing we need zoomable levels of detail the ability to filter out irrelevant information dynamically.

Open telemetry in particular does not appear to emit a span until it is done. I'd imagine knowing when a span started even if it did not end yet would be useful for live continuous tracing.

Abby010 · 2025-03-03T10:42:58Z

Status Update

Current Progress:

We now have a working visualization (Attaching terminal recordings for reference at the end).
The core library has been implemented, and we are now focusing on improving visualization.

Research Done:

✔ Analyzed git log --graph & tree command for box-drawing character alignment.
✔ Explored UTF-8 box characters (│ ├ └ ─) for structured branching.
✔ Reviewed time-based vs. logical event-based sampling logic for implementing switching.
✔ Studied grid-based painting algorithms to properly align and render spans in a structured format.

Next Steps:

Implement box-drawing characters for structured TUI visualization (inspired by git log --graph).
Add --sample logical vs. --sample 1s switching for time-based vs. logical event ordering.
Test and refine span rendering for readability, hierarchy correctness, and terminal compatibility.

Timeline:

🎯 Targeting completion by the next sprint meeting - 10th March, 2025

Terminal 1: React-Ink Visualization

Preview (https://asciinema.org/a/W1yuT5ZngCE8AFkG1VG9yXfVX) - start from the 10th Second
Runs cli.tsx, which uses React-Ink to display spans in a tree-like, real-time interface.
Shows each span (e.g., User Request, Order Processing, etc.) as a vertical hierarchy, updating every second with any new or completed spans.

Terminal 2: Simple Tail-Style Output

Preview (https://asciinema.org/a/dqgzPEHVjRvERp44RnA3F00kp) - start from the 20th second
Runs simple-cli.tsx, which prints raw JSON logs of the spans, similar to tail -f on a log file.
Displays span data in an array (one array entry per span) and updates every second to reflect newly created or completed spans.

Terminal 3: Test Script (`asciinemaTest.ts`)

Preview (https://asciinema.org/a/g6um0fQMdHV3co6ThtviRh6oN)
Generates spans by calling logger.info(), which under the hood calls openSpan and closeSpan.
Simulates real operations like "User Request", "Order Processing", and "Payment Processing", each with delayed completions.
Provides the tracing data that Terminals 1 and 2 observe in real-time.

CMCDragonkai · 2025-03-04T08:38:29Z

@abhishek.mehta you should start to write out the tasks in this issue. Plus your progress should be in the associated feature-branch PR.

CMCDragonkai · 2025-03-04T08:40:11Z

BTW your viz shows using ts-node, we already moved away from that, we use tsx. Actually have a look at ESM migrated repos and start writing your scripts following how we write ESM like code and scripts/executables. See benches as an example.

CMCDragonkai · 2025-03-04T08:42:11Z

Any forking should have a \ to fork out if you're using pure ASCII.

tegefaulkes · 2025-03-12T05:45:22Z

@Abby010 where is your code? I don't see an associated branch or PR for this. Are you working purely locally?

Please make a branch and PR.

CMCDragonkai · 2025-03-30T23:20:52Z

@aryanjassal check this out for integration and plan with @Abby010 in order to debug PK-CLI and seed nodes. Dump data into JSON first, since the terminal react-ink is only for prototyping.

CMCDragonkai · 2025-04-14T00:30:03Z

@aryanjassal your priority right now is to help @Abby010 to prototype the integration (via monkeypatching) to get that visibility in PK. Then display it here.

CMCDragonkai · 2025-04-14T00:45:12Z

~/Projects/Polykey/node_modules/@matrixai/async-init/dist

aryanjassal · 2025-04-17T06:28:17Z

This issue is currently being treated like an epic, where multiple PRs will address this issue. The first PR was just the first iteration of the tracer code.

aryanjassal · 2025-04-29T08:22:35Z

A quick monkey patch to add tracing to the start-stop event gave me this.

{"type":"start","span":{"spanId":"span-1745914565530-f7d","name":"span-startstop-Status","startTime":1745914565530,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566553-jri","name":"span-startstop-ClientService","startTime":1745914566553,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566553-r5d","name":"span-startstop-RPCServer","startTime":1745914566553,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566554-pwr","name":"span-startstop-WebSocketServer","startTime":1745914566554,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566595-sqr","name":"span-startstop-NodeConnectionManager","startTime":1745914566595,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566595-n27","name":"span-startstop-RPCServer","startTime":1745914566595,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566595-p64","name":"span-startstop-QUICSocket","startTime":1745914566595,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566596-9h3","name":"span-startstop-QUICServer","startTime":1745914566596,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566597-0xe","name":"span-startstop-NodeManager","startTime":1745914566597,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914566979-cic","name":"span-startstop-MDNS","startTime":1745914566979,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567144-fwz","name":"span-startstop-QUICConnection","startTime":1745914567144,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567146-w67","name":"span-startstop-QUICConnection","startTime":1745914567146,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567152-kp9","name":"span-startstop-QUICConnection","startTime":1745914567152,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567153-9ir","name":"span-startstop-QUICConnection","startTime":1745914567153,"isCompleted":false,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567146-w67","name":"span-startstop-QUICConnection","startTime":1745914567146,"endTime":1745914567209,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567153-9ir","name":"span-startstop-QUICConnection","startTime":1745914567153,"endTime":1745914567599,"isCompleted":true,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567636-l91","name":"span-startstop-QUICConnection","startTime":1745914567636,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567637-1m7","name":"span-startstop-QUICConnection","startTime":1745914567637,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567637-2ww","name":"span-startstop-QUICConnection","startTime":1745914567637,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567637-9s4","name":"span-startstop-QUICConnection","startTime":1745914567637,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567638-vc6","name":"span-startstop-QUICConnection","startTime":1745914567638,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567638-l7z","name":"span-startstop-QUICConnection","startTime":1745914567638,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914567638-ypa","name":"span-startstop-QUICConnection","startTime":1745914567638,"isCompleted":false,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567636-l91","name":"span-startstop-QUICConnection","startTime":1745914567636,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567637-1m7","name":"span-startstop-QUICConnection","startTime":1745914567637,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567637-2ww","name":"span-startstop-QUICConnection","startTime":1745914567637,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567637-9s4","name":"span-startstop-QUICConnection","startTime":1745914567637,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567638-vc6","name":"span-startstop-QUICConnection","startTime":1745914567638,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567638-l7z","name":"span-startstop-QUICConnection","startTime":1745914567638,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567638-ypa","name":"span-startstop-QUICConnection","startTime":1745914567638,"endTime":1745914569912,"isCompleted":true,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569921-j3f","name":"span-startstop-QUICConnection","startTime":1745914569921,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569924-27k","name":"span-startstop-QUICConnection","startTime":1745914569924,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569924-xsw","name":"span-startstop-QUICConnection","startTime":1745914569924,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569925-gvd","name":"span-startstop-QUICConnection","startTime":1745914569925,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569925-n0w","name":"span-startstop-QUICConnection","startTime":1745914569925,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569925-5ey","name":"span-startstop-QUICConnection","startTime":1745914569925,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569925-216","name":"span-startstop-QUICConnection","startTime":1745914569925,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569930-nnc","name":"span-startstop-QUICConnection","startTime":1745914569930,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569930-kwq","name":"span-startstop-QUICConnection","startTime":1745914569930,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-gv8","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-f1o","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-bjh","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-dor","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-yrj","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-p28","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-l8a","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-c72","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-8k4","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569933-9hb","name":"span-startstop-QUICConnection","startTime":1745914569933,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569936-hiu","name":"span-startstop-QUICConnection","startTime":1745914569936,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569937-0gf","name":"span-startstop-QUICConnection","startTime":1745914569937,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569937-tnx","name":"span-startstop-QUICConnection","startTime":1745914569937,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569937-2y7","name":"span-startstop-QUICConnection","startTime":1745914569937,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569940-rru","name":"span-startstop-QUICConnection","startTime":1745914569940,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569941-nk6","name":"span-startstop-QUICConnection","startTime":1745914569941,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569941-7l4","name":"span-startstop-QUICConnection","startTime":1745914569941,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569942-d0a","name":"span-startstop-QUICConnection","startTime":1745914569942,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569944-ef9","name":"span-startstop-QUICConnection","startTime":1745914569944,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569944-d2w","name":"span-startstop-QUICConnection","startTime":1745914569944,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569944-4zn","name":"span-startstop-QUICConnection","startTime":1745914569944,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569946-xg9","name":"span-startstop-QUICConnection","startTime":1745914569946,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569946-y56","name":"span-startstop-QUICConnection","startTime":1745914569946,"isCompleted":false,"children":[]}}
{"type":"start","span":{"spanId":"span-1745914569946-9ln","name":"span-startstop-QUICConnection","startTime":1745914569946,"isCompleted":false,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567144-fwz","name":"span-startstop-QUICConnection","startTime":1745914567144,"endTime":1745914571452,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567144-fwz","name":"span-startstop-QUICConnection","startTime":1745914567144,"endTime":1745914571452,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567144-fwz","name":"span-startstop-QUICConnection","startTime":1745914567144,"endTime":1745914571453,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567152-kp9","name":"span-startstop-QUICConnection","startTime":1745914567152,"endTime":1745914572595,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567152-kp9","name":"span-startstop-QUICConnection","startTime":1745914567152,"endTime":1745914572596,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914567152-kp9","name":"span-startstop-QUICConnection","startTime":1745914567152,"endTime":1745914572597,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566596-9h3","name":"span-startstop-QUICServer","startTime":1745914566596,"endTime":1745914572599,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566595-p64","name":"span-startstop-QUICSocket","startTime":1745914566595,"endTime":1745914572601,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566595-p64","name":"span-startstop-QUICSocket","startTime":1745914566595,"endTime":1745914572601,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566595-n27","name":"span-startstop-RPCServer","startTime":1745914566595,"endTime":1745914572602,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566595-sqr","name":"span-startstop-NodeConnectionManager","startTime":1745914566595,"endTime":1745914572602,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566979-cic","name":"span-startstop-MDNS","startTime":1745914566979,"endTime":1745914572610,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566597-0xe","name":"span-startstop-NodeManager","startTime":1745914566597,"endTime":1745914572918,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566554-pwr","name":"span-startstop-WebSocketServer","startTime":1745914566554,"endTime":1745914572919,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566554-pwr","name":"span-startstop-WebSocketServer","startTime":1745914566554,"endTime":1745914572919,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566553-r5d","name":"span-startstop-RPCServer","startTime":1745914566553,"endTime":1745914572919,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914566553-jri","name":"span-startstop-ClientService","startTime":1745914566553,"endTime":1745914572919,"isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745914565530-f7d","name":"span-startstop-Status","startTime":1745914565530,"endTime":1745914572944,"isCompleted":true,"children":[]}}

Interestingly, some spans seem to stop multiple times. This could be an issue with how I monkey-patch stuff, or could be intentional. Currently, closeSpan isn't idempotent - I will make that change. But, this is the first artifact of the tracing. Progress!

CMCDragonkai · 2025-04-29T08:42:37Z

No children?

aryanjassal · 2025-04-30T00:46:34Z

Yesterday I was only tracking the lifecycle of a single start/stop based class individually. Now that I am using the async store, I was able to get parent-children relationships showing up!

...
{"type":"stop","span":{"spanId":"span-1745973870668-5jm","name":"span-startstop-RPCServer","startTime":1745973870668,"endTime":1745973873902,"parentSpanId":"span-1745973870668-l53","isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745973870668-l53","name":"span-startstop-NodeConnectionManager","startTime":1745973870668,"endTime":1745973873902,"isCompleted":true,"children":[{"spanId":"span-1745973870668-5jm","name":"span-startstop-RPCServer","startTime":1745973870668,"endTime":1745973873902,"parentSpanId":"span-1745973870668-l53","isCompleted":true,"children":[]},{"spanId":"span-1745973870668-d88","name":"span-startstop-QUICSocket","startTime":1745973870668,"endTime":1745973873901,"parentSpanId":"span-1745973870668-l53","isCompleted":true,"children":[]},{"spanId":"span-1745973870669-lg8","name":"span-startstop-QUICServer","startTime":1745973870669,"endTime":1745973873898,"parentSpanId":"span-1745973870668-l53","isCompleted":true,"children":[]}]}}
{"type":"stop","span":{"spanId":"span-1745973871055-q1f","name":"span-startstop-MDNS","startTime":1745973871055,"endTime":1745973873910,"parentSpanId":"span-1745973870670-cum","isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745973870670-cum","name":"span-startstop-NodeManager","startTime":1745973870670,"endTime":1745973874231,"isCompleted":true,"children":[{"spanId":"span-1745973871055-q1f","name":"span-startstop-MDNS","startTime":1745973871055,"endTime":1745973873910,"parentSpanId":"span-1745973870670-cum","isCompleted":true,"children":[]}]}}
{"type":"stop","span":{"spanId":"span-1745973870626-tt5","name":"span-startstop-WebSocketServer","startTime":1745973870626,"endTime":1745973874232,"parentSpanId":"span-1745973870625-eqx","isCompleted":true,"children":[]}}
{"type":"stop","span":{"spanId":"span-1745973870626-tt5","name":"span-startstop-WebSocketServer","startTime":1745973870626,"endTime":1745973874232,"parentSpanId":"span-1745973870625-eqx","isCompleted":true,"children":[]}}
...

The NodeConnectionManager shows that It has the RPCServer, QUICSocket, and QUICServer as its children.

aryanjassal · 2025-04-30T02:31:42Z

Brian recommended some format improvements for the spans. Before I implement them, this is the output when all the async-init methods (CreateDestroy, StartStop, StartStopCreateDestroy) get the tracer integration.

This artifact was generated by me starting my agent and immediately exiting it once I could see the status text like 'pid, nodeId, etc.'

span.jsonl

aryanjassal · 2025-04-30T07:34:23Z

{"type":"start","id":"mBoEdF0AkcAG6TxlnEgZGfA","spanId":"mBoEdF0AkcACAsjQ5L9usMw","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdF0AocAGCemUGi1oYIA","spanId":"mBoEdF0AocACPJWiBZ0y45Q","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0AocAK1D8cyebY0oA","spanId":"mBoEdF0AgcACM2ZTkFTCQkg","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdF0AtcAGoBzdDplPLsA","spanId":"mBoEdF0AtcACSPe7l2/sjMQ","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0AxcAC3uoIDD7mMvQ","spanId":"mBoEdF0AkcACAsjQ5L9usMw","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0AxcAGPezS8bvIrnA","spanId":"mBoEdF0AocACPJWiBZ0y45Q","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdF0AxcAOFGMHhBwytew","spanId":"mBoEdF0AxcAK0oNx9QtADrQ","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0A1cACyBQGbOD0rXw","spanId":"mBoEdF0AtcACSPe7l2/sjMQ","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdF0A1cAKmZ5ipxlaD7g","spanId":"mBoEdF0A1cAGBMMDLEFKUfw","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0A5cACmgFZMUyb7MQ","spanId":"mBoEdF0AxcAK0oNx9QtADrQ","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdF0A9cAGnK+IICKp8Qg","spanId":"mBoEdF0A9cACmhfldXHTayg","name":"cd-DBTransaction"}
{"type":"end","id":"mBoEdF0A9cAKYig3DiYE6BQ","spanId":"mBoEdF0A1cAGBMMDLEFKUfw","name":"cd-DBTransaction"}

This is a snippet of the new format of the span events. Note that the IdSortable has been converted to base64 so it can be easily serialised. The relationships, instead of being hardcoded in the children field, is now implicit via the parentSpanId field.

{"type":"start","id":"mBoEdFqK8cAC5iwXvImVV3Q","spanId":"mBoEdFqK4cACwDdlonLHnyA","name":"ss-Status"}
{"type":"start","id":"mBoEdFqLAcAGbiECqRUUtoQ","spanId":"mBoEdFqLAcACpsF3797KRxg","name":"cdss-cd-Schema"}
{"type":"start","id":"mBoEdFqLEcAGJ2FrcwERKyQ","spanId":"mBoEdFqLEcACJgOalOQklkQ","name":"cdss-ss-Schema"}
{"type":"start","id":"mBoEdFqLIcAGLThMCWrGBQA","spanId":"mBoEdFqLIcACym3g51WOwXg","name":"cdss-cd-KeyRing"}
{"type":"start","id":"mBoEdFqLMcACpqQxOo4fIGw","spanId":"mBoEdFqLIcAKlANZxIG6CcQ","name":"cdss-ss-KeyRing"}
{"type":"start","id":"mBoEdFq14cAGEMJ5HAtIRtw","spanId":"mBoEdFq14cACP+KGLgLEkvw","name":"cdss-cd-DB"}
{"type":"start","id":"mBoEdFq18cAGkrbXWMVhgKQ","spanId":"mBoEdFq18cACg0QgDxbyVzw","name":"cdss-ss-DB"}
{"type":"start","id":"mBoEdFq5qcAG1RS0sBJj52A","spanId":"mBoEdFq5qcACSqn9hO1WslQ","name":"cdss-cd-TaskManager"}
{"type":"start","id":"mBoEdFq5qcAObvRgiMmGLig","spanId":"mBoEdFq5qcAKWistW+/+dEw","name":"cdss-ss-TaskManager"}
...
{"type":"start","id":"mBoEdFq/GcAGJgYOGo97QpQ","spanId":"mBoEdFq/GcACiPlX9p/KFiQ","name":"cdss-cd-VaultManager"}
{"type":"start","id":"mBoEdFq/GcAO0p6TRX4mrkw","spanId":"mBoEdFq/GcAKUjD2xYUtgGQ","name":"cdss-ss-VaultManager"}
{"type":"start","id":"mBoEdFq/KcACU5r/B9QcoMQ","spanId":"mBoEdFq/GcASO5U2jQoqRng","name":"cd-DBTransaction"}
{"type":"start","id":"mBoEdFq/OcAGmoEODkEPGjQ","spanId":"mBoEdFq/OcACHCHhNJjv+Qg","parentSpanId":"mBoEdFq/GcAKUjD2xYUtgGQ","name":"cdss-ss-DB"}
{"type":"start","id":"mBoEdFrB+cAGv49+QhawOZg","spanId":"mBoEdFrB+cACw+GyKKhaJag","parentSpanId":"mBoEdFq/GcAKUjD2xYUtgGQ","name":"cdss-cd-INodeManager"}
{"type":"start","id":"mBoEdFrCDcAGh/JM4ik764g","spanId":"mBoEdFrCDcACqIx6lJQnFZA","parentSpanId":"mBoEdFq/GcAKUjD2xYUtgGQ","name":"cdss-ss-INodeManager"}

For reference, cd is short for CreateDestroy spans, ss for StartStop, and cdss for CreateDestroyStartStop. As a different span is used to track the start/stop and the create/destroy, they have been labelled as cdss-cd for the create/destroy spans and cdss-ss for the start/stop spans.

spans.jsonl

CMCDragonkai · 2025-04-30T08:56:46Z

You should be using multibase with hex16, use the same encoding we use for node IDs. You can preserve the binary order that way too if it matters. Useful for later ordered indexing.

CMCDragonkai · 2025-05-04T23:21:45Z

If #47 was merged, this issue should be fixed. However new issues can be created to address new features or bugs regarding tracing. @aryanjassal @Abby010

CMCDragonkai · 2025-05-04T23:46:58Z

Let's change to Start/Stop to match terminology of async contexts
Each span event can have its own IdSortable in order to be able to see the exact time it occurred - IdSortable is monotonic with respect to the nodeId - this has some interesting interaction with multiple nodes
The parentId may or may not exist for both start and stop, and that means there's a possibility of a spans in one location and then fading out and then fading into another location
@faithveloro09 review in relation to the PKE audit log

type SpanId = IdSortableEncoded;

type SpanStart = {
  type: 'Start';
  id: SpanId;
  parentId?: SpanId;
}

type SpanStop = {
  type = 'Stop';
  id: SpanId;
  startId: SpanId;
  parentId?: SpanId;
}

CMCDragonkai · 2025-05-04T23:56:29Z

@shafiqihtsham - review the above concept in relation to the audit log with @faithveloro09

aryanjassal · 2025-05-05T04:50:18Z

Let's change to Start/Stop to match terminology of async contexts

Each span event can have its own IdSortable in order to be able to see the exact time it occurred - IdSortable is monotonic with respect to the nodeId - this has some interesting interaction with multiple nodes

The parentId may or may not exist for both start and stop, and that means there's a possibility of a spans in one location and then fading out and then fading into another location

@faithveloro09 review in relation to the PKE audit log
type SpanId = IdSortableEncoded;

type SpanStart = {
  type: 'Start';
  id: SpanId;
  parentId?: SpanId;
}

type SpanStop = {
  type = 'Stop';
  id: SpanId;
  startId: SpanId;
  parentId?: SpanId;
}

#60

aryanjassal · 2025-05-05T04:52:46Z

I have made a new issue with all the improvements we discussed about the format. This issue can now be closed as the initial version of the tracing has been merged.

I need to synthesise the information from this issue into the tracing project on linear as this contains a lot of relevant information, especially regarding the project requirements, specs, and what we have explored and their results.

CMCDragonkai added the development Standard development label Jul 19, 2022

CMCDragonkai mentioned this issue Jul 19, 2022

Structured JSON Logging #14

Merged

15 tasks

This was referenced Mar 17, 2025

Tracing Visualization #46

Closed

Implement OpenTracing-like tracer #47

Merged

aryanjassal closed this as completed in #47 Apr 17, 2025

aryanjassal reopened this Apr 17, 2025

aryanjassal mentioned this issue Apr 21, 2025

Integrate high-level observability using Tracer MatrixAI/Polykey-CLI#392

Open

aryanjassal mentioned this issue Apr 28, 2025

Visualise event-based spans for tracing #52

Closed

aryanjassal mentioned this issue May 5, 2025

Clean up Span format #60

Closed

aryanjassal closed this as completed May 5, 2025

aryanjassal mentioned this issue May 7, 2025

Reduce redundancy in the span format #61

Merged

9 tasks

Integrate Tracing (derived from OpenTelemetry) #15

Integrate Tracing (derived from OpenTelemetry) #15

Comments

CMCDragonkai commented Jul 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Specification

Additional context

Tasks

CMCDragonkai commented Jul 19, 2022

Uh oh!

CMCDragonkai commented Jul 19, 2022 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Abby010 commented Mar 3, 2025

Status Update

Current Progress:

Research Done:

Next Steps:

Timeline:

Terminal 1: React-Ink Visualization

Terminal 2: Simple Tail-Style Output

Terminal 3: Test Script (asciinemaTest.ts)

Uh oh!

CMCDragonkai commented Mar 4, 2025

Uh oh!

CMCDragonkai commented Mar 4, 2025

Uh oh!

CMCDragonkai commented Mar 4, 2025

Uh oh!

tegefaulkes commented Mar 12, 2025

Uh oh!

CMCDragonkai commented Mar 30, 2025

Uh oh!

CMCDragonkai commented Apr 14, 2025

Uh oh!

CMCDragonkai commented Apr 14, 2025

Uh oh!

aryanjassal commented Apr 17, 2025

Uh oh!

aryanjassal commented Apr 29, 2025

Uh oh!

CMCDragonkai commented Apr 29, 2025

Uh oh!

aryanjassal commented Apr 30, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

aryanjassal commented Apr 30, 2025

Uh oh!

aryanjassal commented Apr 30, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

CMCDragonkai commented Apr 30, 2025

Uh oh!

CMCDragonkai commented May 4, 2025

Uh oh!

CMCDragonkai commented May 4, 2025 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

CMCDragonkai commented May 4, 2025

Uh oh!

aryanjassal commented May 5, 2025

Uh oh!

aryanjassal commented May 5, 2025

Uh oh!

CMCDragonkai commented Jul 19, 2022 •

edited

Loading

CMCDragonkai commented Jul 19, 2022 •

edited

Loading

Terminal 3: Test Script (`asciinemaTest.ts`)

aryanjassal commented Apr 30, 2025 •

edited

Loading

aryanjassal commented Apr 30, 2025 •

edited

Loading

CMCDragonkai commented May 4, 2025 •

edited

Loading