Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Observability using OpenTelemetry #478

Open
spuliaiev-sfdc opened this issue Jul 17, 2024 · 20 comments
Open

Observability using OpenTelemetry #478

spuliaiev-sfdc opened this issue Jul 17, 2024 · 20 comments

Comments

@spuliaiev-sfdc
Copy link

Our objective is to enhance the visibility of the command execution process for DEVCONTAINER-CLI. To achieve this, we plan to integrate tracing support. Our chosen method for this integration is the OPENTELEMETRY library, owing to its robust capabilities. The initial focus will be on instrumenting the 'UP' command, which will serve as our first milestone in this endeavor. This enhancement will significantly improve our understanding and control of the process.

@samruddhikhandale
Copy link
Member

// cc @chrmarti Wondering if you have any thoughts here!

@chrmarti
Copy link
Contributor

@spuliaiev-sfdc Could you explain a bit more what the goal is here? You mentioned on the other issue that you need this ASAP, what is driving this?

@spuliaiev-sfdc
Copy link
Author

spuliaiev-sfdc commented Jul 18, 2024

Right now the start of the container and installing all the features + postCreate scripts takes the most of the time for our initialization of VM with containers. And we have no observability on where the time is spent, and which operations fail.

Therefore we want to report the spans for the operations, their attributes and status so we can analyze the flow, detect abnormalities and create Alerting and Reporting for customer VM+Containers startup process.
Out main focus right now is UP operation, so we want to created traces for Feature install, postCreateCommand and anything else happening during the UP operation.

For Example - using HoneyComb (screenshots from google)
image

image

@chrmarti
Copy link
Contributor

Are you using the Dev Containers CLI directly? There is a JSON log format that includes some start and stop events, would that contain enough information? E.g.:

❯ devcontainer up --workspace-folder . --log-format json                                                                            
{"type":"text","level":3,"timestamp":1721747265575,"text":"@devcontainers/cli 0.66.0. Node.js v20.13.1. darwin 23.5.0 arm64."}
{"type":"start","level":2,"timestamp":1721747265575,"text":"Run: docker buildx version"}
{"type":"stop","level":2,"timestamp":1721747265701,"text":"Run: docker buildx version","startTimestamp":1721747265575}
{"type":"text","level":2,"timestamp":1721747265701,"text":"github.com/docker/buildx v0.15.1-desktop.1 5a84cb97872a2e717a86a0dec58b20fd3f0bea46\r\n"}
{"type":"text","level":2,"timestamp":1721747265701,"text":"\u001b[1m\u001b[31m\u001b[39m\u001b[22m\r\n"}
{"type":"start","level":2,"timestamp":1721747265701,"text":"Run: docker -v"}
{"type":"stop","level":2,"timestamp":1721747265714,"text":"Run: docker -v","startTimestamp":1721747265701}
{"type":"start","level":2,"timestamp":1721747265714,"text":"Resolving Remote"}
{"type":"start","level":2,"timestamp":1721747265716,"text":"Run: git rev-parse --show-cdup"}
{"type":"stop","level":2,"timestamp":1721747265730,"text":"Run: git rev-parse --show-cdup","startTimestamp":1721747265716}
{"type":"start","level":2,"timestamp":1721747265731,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json"}
{"type":"stop","level":2,"timestamp":1721747265755,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json","startTimestamp":1721747265731}
{"type":"start","level":2,"timestamp":1721747265755,"text":"Run: docker inspect --type container b03b56935cc8"}
{"type":"stop","level":2,"timestamp":1721747265777,"text":"Run: docker inspect --type container b03b56935cc8","startTimestamp":1721747265755}
{"type":"start","level":2,"timestamp":1721747266675,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json"}
{"type":"stop","level":2,"timestamp":1721747266707,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json","startTimestamp":1721747266675}
{"type":"start","level":2,"timestamp":1721747266707,"text":"Run: docker inspect --type container b03b56935cc8"}
{"type":"stop","level":2,"timestamp":1721747266741,"text":"Run: docker inspect --type container b03b56935cc8","startTimestamp":1721747266707}
{"type":"start","level":2,"timestamp":1721747266742,"text":"Starting container"}
{"type":"start","level":3,"timestamp":1721747266742,"text":"Run: docker start b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c"}
{"type":"text","level":3,"timestamp":1721747266882,"text":"b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c\n"}
{"type":"stop","level":3,"timestamp":1721747266884,"text":"Run: docker start b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c","startTimestamp":1721747266742}
{"type":"stop","level":2,"timestamp":1721747266885,"text":"Starting container","startTimestamp":1721747266742}
{"type":"start","level":2,"timestamp":1721747266885,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json"}
{"type":"stop","level":2,"timestamp":1721747266903,"text":"Run: docker ps -q -a --filter label=devcontainer.local_folder=/Users/chrmarti/Development/repos/smktst --filter label=devcontainer.config_file=/Users/chrmarti/Development/repos/smktst/.devcontainer/devcontainer.json","startTimestamp":1721747266885}
{"type":"start","level":2,"timestamp":1721747266903,"text":"Run: docker inspect --type container b03b56935cc8"}
{"type":"stop","level":2,"timestamp":1721747266923,"text":"Run: docker inspect --type container b03b56935cc8","startTimestamp":1721747266903}
{"type":"start","level":2,"timestamp":1721747266924,"text":"Inspecting container"}
{"type":"start","level":2,"timestamp":1721747266924,"text":"Run: docker inspect --type container b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c"}
{"type":"stop","level":2,"timestamp":1721747266943,"text":"Run: docker inspect --type container b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c","startTimestamp":1721747266924}
{"type":"stop","level":2,"timestamp":1721747266943,"text":"Inspecting container","startTimestamp":1721747266924}
{"type":"start","level":2,"timestamp":1721747266944,"text":"Run in container: /bin/sh"}
{"type":"start","level":2,"timestamp":1721747266946,"text":"Run in container: uname -m"}
{"type":"text","level":2,"timestamp":1721747266985,"text":"aarch64\n"}
{"type":"text","level":2,"timestamp":1721747266985,"text":""}
{"type":"stop","level":2,"timestamp":1721747266985,"text":"Run in container: uname -m","startTimestamp":1721747266946}
{"type":"start","level":2,"timestamp":1721747266985,"text":"Run in container: (cat /etc/os-release || cat /usr/lib/os-release) 2>/dev/null"}
{"type":"text","level":2,"timestamp":1721747266986,"text":"PRETTY_NAME=\"Debian GNU/Linux 12 (bookworm)\"\nNAME=\"Debian GNU/Linux\"\nVERSION_ID=\"12\"\nVERSION=\"12 (bookworm)\"\nVERSION_CODENAME=bookworm\nID=debian\nHOME_URL=\"https://www.debian.org/\"\nSUPPORT_URL=\"https://www.debian.org/support\"\nBUG_REPORT_URL=\"https://bugs.debian.org/\"\n"}
{"type":"text","level":2,"timestamp":1721747266986,"text":""}
{"type":"stop","level":2,"timestamp":1721747266986,"text":"Run in container: (cat /etc/os-release || cat /usr/lib/os-release) 2>/dev/null","startTimestamp":1721747266985}
{"type":"start","level":2,"timestamp":1721747266986,"text":"Run in container:  (command -v getent >/dev/null 2>&1 && getent passwd 'node' || grep -E '^node|^[^:]*:[^:]*:node:' /etc/passwd || true)"}
{"type":"stop","level":2,"timestamp":1721747266987,"text":"Run in container:  (command -v getent >/dev/null 2>&1 && getent passwd 'node' || grep -E '^node|^[^:]*:[^:]*:node:' /etc/passwd || true)","startTimestamp":1721747266986}
{"type":"start","level":2,"timestamp":1721747266988,"text":"Run in container: test -f '/var/devcontainer/.patchEtcEnvironmentMarker'"}
{"type":"text","level":2,"timestamp":1721747266988,"text":""}
{"type":"text","level":2,"timestamp":1721747266988,"text":""}
{"type":"stop","level":2,"timestamp":1721747266988,"text":"Run in container: test -f '/var/devcontainer/.patchEtcEnvironmentMarker'","startTimestamp":1721747266988}
{"type":"start","level":2,"timestamp":1721747266989,"text":"Run in container: test -f '/var/devcontainer/.patchEtcProfileMarker'"}
{"type":"text","level":2,"timestamp":1721747266989,"text":""}
{"type":"text","level":2,"timestamp":1721747266989,"text":""}
{"type":"stop","level":2,"timestamp":1721747266989,"text":"Run in container: test -f '/var/devcontainer/.patchEtcProfileMarker'","startTimestamp":1721747266989}
{"type":"text","level":2,"timestamp":1721747266989,"text":"userEnvProbe: loginInteractiveShell (default)"}
{"type":"text","level":1,"timestamp":1721747266989,"text":"LifecycleCommandExecutionMap: {\n    \"onCreateCommand\": [],\n    \"updateContentCommand\": [],\n    \"postCreateCommand\": [],\n    \"postStartCommand\": [],\n    \"postAttachCommand\": [],\n    \"initializeCommand\": []\n}"}
{"type":"text","level":2,"timestamp":1721747266989,"text":"userEnvProbe: not found in cache"}
{"type":"text","level":2,"timestamp":1721747266990,"text":"userEnvProbe shell: /bin/bash"}
{"type":"start","level":2,"timestamp":1721747266990,"text":"Run in container: /bin/bash -lic echo -n 570a15bf-dce2-4168-b675-8918fa8550b0; cat /proc/self/environ; echo -n 570a15bf-dce2-4168-b675-8918fa8550b0"}
{"type":"start","level":2,"timestamp":1721747266990,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.onCreateCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.onCreateCommandMarker'"}
{"type":"text","level":2,"timestamp":1721747266992,"text":""}
{"type":"text","level":2,"timestamp":1721747266992,"text":""}
{"type":"stop","level":2,"timestamp":1721747266992,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.onCreateCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.onCreateCommandMarker'","startTimestamp":1721747266990}
{"type":"start","level":2,"timestamp":1721747266992,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.updateContentCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.updateContentCommandMarker'"}
{"type":"text","level":2,"timestamp":1721747266994,"text":""}
{"type":"text","level":2,"timestamp":1721747266994,"text":""}
{"type":"stop","level":2,"timestamp":1721747266994,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.updateContentCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.updateContentCommandMarker'","startTimestamp":1721747266992}
{"type":"start","level":2,"timestamp":1721747266994,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.postCreateCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.postCreateCommandMarker'"}
{"type":"text","level":2,"timestamp":1721747266995,"text":""}
{"type":"text","level":2,"timestamp":1721747266995,"text":""}
{"type":"stop","level":2,"timestamp":1721747266995,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.postCreateCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T13:31:05.568135053Z}\" != '2024-07-23T13:31:05.568135053Z' ] && echo '2024-07-23T13:31:05.568135053Z' > '/home/node/.devcontainer/.postCreateCommandMarker'","startTimestamp":1721747266994}
{"type":"start","level":2,"timestamp":1721747266995,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.postStartCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T15:07:46.791617347Z}\" != '2024-07-23T15:07:46.791617347Z' ] && echo '2024-07-23T15:07:46.791617347Z' > '/home/node/.devcontainer/.postStartCommandMarker'"}
{"type":"text","level":2,"timestamp":1721747266997,"text":""}
{"type":"text","level":2,"timestamp":1721747266997,"text":""}
{"type":"stop","level":2,"timestamp":1721747266997,"text":"Run in container: mkdir -p '/home/node/.devcontainer' && CONTENT=\"$(cat '/home/node/.devcontainer/.postStartCommandMarker' 2>/dev/null || echo ENOENT)\" && [ \"${CONTENT:-2024-07-23T15:07:46.791617347Z}\" != '2024-07-23T15:07:46.791617347Z' ] && echo '2024-07-23T15:07:46.791617347Z' > '/home/node/.devcontainer/.postStartCommandMarker'","startTimestamp":1721747266995}
{"type":"stop","level":2,"timestamp":1721747266997,"text":"Resolving Remote","startTimestamp":1721747265714}
{"outcome":"success","containerId":"b03b56935cc842d1be63e58a75dadf18991fcacc46b8afe485eb961cc3deaa2c","remoteUser":"node","remoteWorkspaceFolder":"/workspaces/smktst"}

@spuliaiev-sfdc
Copy link
Author

We are using HoneyComb to fetch the runtime status of the initialization process.
Sometimes it takes a lot of time and it would be useful to get the complete steps in HC on time.
It would be good to understand it post execution using logs, but to get it in the runtime - it would be hard to pull the logs periodically using some service and post it using OTEL. Also removing already posted events...
It's way too complex.

@spuliaiev-sfdc
Copy link
Author

It would be great to add the OTEL logger which will report this data to the telemetry service, along with logging these events.

@alexanderilyin
Copy link

alexanderilyin commented Aug 14, 2024

On related note I was thinking about creating some kind of distributed cache for UP. If one uses devcontainer.json to describe env, then in cluster like environment each server will have to build image at least once, and each server also could build same image more than once. Idea here is to use remote locks to build image once on-demand and then pull it from the cache which will be just a regular registry.

P. S. features seems to be really convenient way to add project specific dependencies, but using this at scale currently leads to drawbacks.

P. P. S. Still thinking on implementation, and it feels that one of the solutions could be relying on remote bazel builds to produce distroless like images. I'm new to TypeScript and Bazel but I'm thinking about implementing this feature as my pet project to learn TS and Bazel.

P. P. P. S. My bad, this is spec repo and not cli tool... on 2nd thought maybe JSON should define something related to centralized building... Actually one can create a microservice to pass devcontainer.json and then build image locally and then return tag which should be pulled. Anyway sorry for off-topic.

@abl
Copy link

abl commented Aug 15, 2024

(Hi! I work with @spuliaiev-sfdc; I happen to be based in the greater Redmond area and would be happy to chat about what we're doing if it's of interest. We're big fans of devcontainers and o11y.)

Yes, we're using the reference CLI.

The goals we have with distributed tracing are a bit more complex than we can do with logs alone; for example, the logs don't expose parent-child relationships and children can't expose structured metadata, just text on stdout, so a lot of nuance gets lost and a lot of regexes get written and I'm honestly not entirely sure what to do with {"type":"text","level":2,"timestamp":1721747265701,"text":"\u001b[1m\u001b[31m\u001b[39m\u001b[22m\r\n"}.

Thanks for the json log-format pointer; I'm probably going to draft and publish a collector that aggregates those log entries and emits ~equivalent otel spans to get us moving. Our immediate needs are figuring out the components of devcontainer up waiting time so we know where to invest improvement efforts - is it our container registry, is it users writing dotfiles that take 20 minutes to execute, is it a feature that's trying to download assets from someone's desktop, etc.

(@alexanderilyin you'd probably have more fun with nix flakes and devenv.sh if you're looking for things that can be composed and cached, and I know this because we've been going down a similar path :)

@alexanderilyin
Copy link

alexanderilyin commented Aug 22, 2024

On related note... I'm playing with "Dev Container Features" and have to rebuild often and now it seems I'm throttled by GH:

(*) Installing buildx 0.16.2...
--2024-08-22 04:39:07-- https://github.com/docker/buildx/releases/download/v0.16.2/buildx-v0.16.2.linux-amd64
Resolving github.com (github.com)...140.82.116.4
Connecting to github.com (github.com)|140.82.116.4|:443...connected.
HTTP request sent, awaiting response...302 Found
Location: https://objects.githubusercontent.com/github-production-release-asset-2e65be/177210627/0b54c2a0-9b0a-4b29-a225-398f5dc8211f?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240822%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240822T043756Z&X-Amz-Expires=300&X-Amz-Signature=ae54928636f9115754f881ac2ba483151cf0fd644701f396d4c1de430ca139eb&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=177210627&response-content-disposition=attachment%3B%20filename%3Dbuildx-v0.16.2.linux-amd64&response-content-type=application%2Foctet-stream [following]
--2024-08-22 04:39:07-- https://objects.githubusercontent.com/github-production-release-asset-2e65be/177210627/0b54c2a0-9b0a-4b29-a225-398f5dc8211f?X-Amz-Algorithm=AWS4-HMAC-SHA256&X-Amz-Credential=releaseassetproduction%2F20240822%2Fus-east-1%2Fs3%2Faws4_request&X-Amz-Date=20240822T043756Z&X-Amz-Expires=300&X-Amz-Signature=ae54928636f9115754f881ac2ba483151cf0fd644701f396d4c1de430ca139eb&X-Amz-SignedHeaders=host&actor_id=0&key_id=0&repo_id=177210627&response-content-disposition=attachment%3B%20filename%3Dbuildx-v0.16.2.linux-amd64&response-content-type=application%2Foctet-stream
Resolving objects.githubusercontent.com (objects.githubusercontent.com)...185.199.111.133, 185.199.109.133, 185.199.108.133, ...
Connecting to objects.githubusercontent.com (objects.githubusercontent.com)|185.199.111.133|:443...connected.
HTTP request sent, awaiting response...200 OK
Length: 57041048 (54M) [application/octet-stream]
Saving to: 'buildx-v0.16.2.linux-amd64'
0K .......... ........................................ 0%162K 5m44s
...
1900K .......... .......... .......... .......... .......... 3% 5.19K 41m37s
...
18550K .......... .......... .......... .......... .......... 33% 24.0K 27m47s

At the same time my connection seem pretty fast:

image

Point is it's nice to be able to drill down to "RUN ..." instruction for the related docker build which would require adding support to Docker itself (attaching related outputs) and then passing Trace/Span ID into it and probably Docker can't do it just yet.

P. S. Turns out Docker already provides traces (at least Docker for Desktop on Windows)

jaeger

@abl
Copy link

abl commented Aug 22, 2024

@alexanderilyin ensuring you pass a personal access token with your requests used to help, possibly still does, not entirely sure in this case tho

@chrmarti in your example, some of your start events, such as {"type":"start","level":2,"timestamp":1721747266944,"text":"Run in container: /bin/sh"} have no matching stop event. Not sure how to interpret that.

@chrmarti
Copy link
Contributor

@chrmarti in your example, some of your start events, such as {"type":"start","level":2,"timestamp":1721747266944,"text":"Run in container: /bin/sh"} have no matching stop event. Not sure how to interpret that.

This is a long-running shell that we reuse to execute commands. The stop message is probably lost or skipped during process shutdown.

@austinlparker
Copy link

Hi, I'm from the OpenTelemetry project! We'd love to see OpenTelemetry support added to DevContainers. Would be happy to answer any questions -- if you're looking for examples of how you might integrate tracing into the code, might be interesting to see how Moby does it: https://github.com/search?q=repo:moby/moby%20opentelemetry&type=code. They trace various requests around launching containers.

@Kcc940930
Copy link

Hi, I'm from the OpenTelemetry project! We'd love to see OpenTelemetry support added to DevContainers. Would be happy to answer any questions -- if you're looking for examples of how you might integrate tracing into the code, might be interesting to see how Moby does it: https://github.com/search?q=repo:moby/moby%20opentelemetry&type=code. They trace various requests around launching containers.

``

@12Kirk2v121BTMST
Copy link

800080

@12Kirk2v121BTMST
Copy link

[]([modern-work-plan-comparison---enterprise-2-2024-08-01.pdf](https://github.com/user-attachments/files/16986780/modern-work-plan-comparison---enterprise-2-2024-08-01.pdf))

@spuliaiev-sfdc
Copy link
Author

spuliaiev-sfdc commented Sep 13, 2024

@chrmarti

There is a JSON log format that includes some start and stop events, would that contain enough information?

Is there a documentation on the format of this log?
I am reviewing what I get from our execution and quite confused by these lines.
For example:

  • There are text and raw types. Not really understand the difference. Looks like raw can have \n and \r
  • There different level specified for lines. Is it logging level (like info/debug/trace) or command execution hierarchy level? Default level is info - so I did not expect to see debug and info there...
  • I see that some text and raw entries have channel attribute. What it means?
  • There is progress type of entry. Not sure where it supposed to be applied. Looks like to channel, but who creates these channels, and when they close? With next stop ? BTW some progress do not have channel attribute.

Kind of a lot of questions...

@spuliaiev-sfdc
Copy link
Author

spuliaiev-sfdc commented Sep 13, 2024

One more thing... If I understand correctly from your example, the text entries in line 3 and 4 are output of the command started at the line 1 and stopped at the line 2?

{"type":"start","level":2,"timestamp":1721747265575,"text":"Run: docker buildx version"}
{"type":"stop","level":2,"timestamp":1721747265701,"text":"Run: docker buildx version","startTimestamp":1721747265575}
{"type":"text","level":2,"timestamp":1721747265701,"text":"github.com/docker/buildx v0.15.1-desktop.1 5a84cb97872a2e717a86a0dec58b20fd3f0bea46\r\n"}
{"type":"text","level":2,"timestamp":1721747265701,"text":"\u001b[1m\u001b[31m\u001b[39m\u001b[22m\r\n"}

And unfortunately we cannot even use timestamp to link them together, because in our execution I see that text entries have a different timestamps:

{"type":"start","level":2,"timestamp":1726254415859,"text":"Run: docker buildx version"}
{"type":"stop","level":2,"timestamp":1726254418844,"text":"Run: docker buildx version","startTimestamp":1726254415859}
{"type":"text","level":2,"timestamp":1726254418845,"text":"github.com/docker/buildx v0.12.1 30feaa1\r\n"}
{"type":"text","level":2,"timestamp":1726254418845,"text":"\u001b[1m\u001b[31m\u001b[39m\u001b[22m\r\n"}

@austinlparker
Copy link

In general, supporting OpenTelemetry tracing would require a tracing context to be passed around so that all actions/RPCs that were associated with each other could be linked. In languages like Go, this is typically performed through the Context library. Other languages (such as JS/TS) use different mechanisms.

In the example logs in this thread, timestamps alone would be insufficient as context identifiers.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

10 participants