Support for OpenTelemetry tracing instrumentation - #14231
sureshanaparti wants to merge 4 commits into
Conversation
…y span trace id and span id
…t managed opentelemetry-api version; fix removeContextParameters CME
|
@blueorangutan package |
Codecov Report❌ Patch coverage is Additional details and impacted files@@ Coverage Diff @@
## 4.22 #14231 +/- ##
============================================
+ Coverage 17.98% 17.99% +0.01%
- Complexity 16195 16215 +20
============================================
Files 5930 5939 +9
Lines 535649 535978 +329
Branches 65590 65626 +36
============================================
+ Hits 96343 96460 +117
- Misses 428330 428527 +197
- Partials 10976 10991 +15
Flags with carried forward coverage won't be shown. Click here to find out more. ☔ View full report in Codecov by Harness. 🚀 New features to boost your workflow:
|
- Add support to API layer - All API requests get a traceId in LogContext (via ApiTraceFilter) - Read the trace and span threadcontext key names from the environment - Instrument cloudstack Agents and VM operations
54fd54d to
90b0202
Compare
|
@blueorangutan package |
|
@blueorangutan package |
|
Packaging result [SF]: ✔️ el8 ✔️ el9 ✔️ el10 ✔️ debian ✔️ suse15. SL-JID 19316 |
|
@blueorangutan test |
There was a problem hiding this comment.
with otelagent
docker run -d --name jaeger \
-e COLLECTOR_OTLP_ENABLED=true \
-p 16686:16686 -p 4317:4317 -p 4318:4318 \
jaegertracing/all-in-one:1.60
[root@ref-trl-12381-k-Mol8-kiran-chavala-mgmt1 management]# ss -lntp | grep -E "4317|16686"
LISTEN 0 4096 0.0.0.0:4317 0.0.0.0:* users:(("docker-proxy",pid=87583,fd=4))
LISTEN 0 4096 0.0.0.0:16686 0.0.0.0:* users:(("docker-proxy",pid=87543,fd=4))
LISTEN 0 4096 [::]:4317 [::]:* users:(("docker-proxy",pid=87589,fd=4))
LISTEN 0 4096 [::]:16686 [::]:* users:(("docker-proxy",pid=87549,fd=4))
Grab the agent and wire it into the management server (/etc/default/cloudstack-management)
curl -Lo /usr/share/cloudstack-management/lib/opentelemetry-javaagent.jar \
https://github.com/open-telemetry/opentelemetry-java-iownload/v2.27.0/opentelemetry-javaagent.jar
[root@ref-trl-12381-k-Mol8-kiran-chavala-mgmt1 lib]# chmod 644 /usr/share/cloudstack-management/lib/opentelemetry-javaagent.jar
[root@ref-trl-12381-k-Mol8-kiran-chavala-mgmt1 lib]# chown cloud:cloud /usr/share/cloudstack-management/lib/opentelemetry-javaagent.jar
[root@ref-trl-12381-k-Mol8-kiran-chavala-mgmt1 lib]# sudo -u cloud test -r /usr/share/cloudstack-management/lib/opentelemetry-javaagent.jar && echo "readable by cloud"
readable by cloud
make sure thge javagent is present in /etc/default/cloudstack-management
JAVA_OPTS="-Djava.security.properties=/etc/cloudstack/management/java.security.ciphers -Djava.awt.headless=true -Xmx2G -XX:+UseParallelGC -XX:MaxGCPauseMillis=500 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/log/cloudstack/management/ -XX:ErrorFile=/var/log/cloudstack/management/cloudstack-management.err -XX:-OmitStackTraceInFastThrow -javaagent:/usr/share/cloudstack-management/lib/opentelemetry-javaagent.jar"
[root@ref-trl-12381-k-Mol8-kiran-chavala-mgmt1 lib]# cat >> /etc/default/cloudstack-management <<'EOF'
OTEL_SERVICE_NAME=cloudstack-management
OTEL_TRACES_EXPORTER=otlp
OTEL_METRICS_EXPORTER=none
OTEL_LOGS_EXPORTER=none
OTEL_EXPORTER_OTLP_PROTOCOL=grpc
OTEL_EXPORTER_OTLP_ENDPOINT=http://localhost:4317
OTEL_TRACES_SAMPLER=always_on
OTEL_JAVA_EXPERIMENTAL_SPAN_ATTRIBUTES_COPY_FROM_BAGGAGE_INCLUDE=cloudstack.phase,cloudstack.vm.op,cloudstack.vm.id,cloudstack.traffic
EOF
- Add the keys to the log pattern. The management server's log4j-cloud.xml has monitorInterval="60", so the change is picked up within 60 seconds without a restart.
cp /etc/cloudstack/management/log4j-cloud.xml /root/log4j-cloud.xml.bak
Add the PR's keys (otel_*) and the agent's own keys (trace_id) to every pattern
sed -i 's|(logid:%X{logcontextid})|(logid:%X{logcontextid}) (otel:%X{otel_trace_id}/%X{otel_span_id}) (agent:%X{trace_id}/%X{span_id})|' \
/etc/cloudstack/management/log4j-cloud.xml
grep -c "otel_trace_id" /etc/cloudstack/management/log4j-cloud.xml # should be >0
sleep 70
- Make some traced calls:
cmk list zones
cmk deploy virtualmachine zoneid=$ZONE serviceofferingid=$SO templateid=$TMPL networkids=$NET name=otel-b6
- Check the log lines:
LOG=/var/log/cloudstack/management/management-server.log
grep "listZones" $LOG | grep -o "(otel:[^)]*) (agent:[^)]*)" | tail -3
grep -E "VmWorkStart|StartCommand" $LOG | grep -o "(otel:[^)]*)" | sort -u | tail -5
┌─────────────────────────────────────────────────────────────────────┬─────────────────────────────────────────────────────────────────────────────────────────────────┐
│ Expected │ If not, it means │
├─────────────────────────────────────────────────────────────────────┼─────────────────────────────────────────────────────────────────────────────────────────────────┤
│ otel:<32 hex>/<16 hex> on API and job lines │ Empty otel:/ while agent: is filled means the wrapper isn't working under the agent (a finding) │
├─────────────────────────────────────────────────────────────────────┼─────────────────────────────────────────────────────────────────────────────────────────────────┤
│ The otel: trace ID equals the agent: trace ID on the same line │ They should never differ │
├─────────────────────────────────────────────────────────────────────┼─────────────────────────────────────────────────────────────────────────────────────────────────┤
│ Background threads (pings, scanners, not inside a span) show otel:/ │ IDs on unrelated threads mean an ID leaked on a pooled thread │
└─────────────────────────────────────────────────────────────────────┴─────────────────────────────────────────────────────────────────────────────────────────────────┘
|
@blueorangutan package |
|
Packaging result [SF]: ✔️ el8 ✔️ el9 ✔️ el10 ✔️ debian ✔️ suse15. SL-JID 19320 |
There was a problem hiding this comment.
LGTM , Tested manually
MS=http://<mgmt-ip>:8080/client/api
JAEGER=http://<jaeger-ip>:16686
LOG=/var/log/cloudstack/management/management-server.log
DBPW='<mysql-root-password>'
ZONE=<zone-id>; SO=<service-offering-id>; TMPL=<template-id>; NET=<network-id>
docker run -d --name jaeger -e COLLECTOR_OTLP_ENABLED=true -p 16686:16686 -p 4317:4317 -p 4318:4318 jaegertracing/all-in-one:1.60
q() { mysql -u root -p"$DBPW" cloud -e "$1"; }
login() { curl -s -c cj -d "command=login&username=admin&password=password&response=json" $MS > login.json
SK=$(jq -r .loginresponse.sessionkey login.json); echo "SK=$SK"; }
# api <traceid-or-empty> "<query string>"
api() { local h=(); [ -n "$1" ] && h=(-H "traceid: $1"); curl -s -b cj "${h[@]}" "$MS?$2&response=json&sessionkey=$SK"; }
login
Run login again whenever the session expires.
Test A Without the OTel agent (regression)
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# q "select version from version order by id desc limit 1; show columns from async_job like 'context';"
mysql: [Warning] Using a password on the command line interface can be insecure.
+----------+
| version |
+----------+
| 4.22.2.0 |
+----------+
+---------+------+------+-----+---------+-------+
| Field | Type | Null | Key | Default | Extra |
+---------+------+------+-----+---------+-------+
| context | text | YES | | NULL | |
+---------+------+------+-----+---------+-------+
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "(traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id})" /etc/cloudstack/management/log4j-cloud.xml
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id}) %m%ex{filters(${filters})}%n"/>
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id}) %m%ex{filters(${filters})}%n"/>
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id}) %m%ex{filters(${filters})}%n"/>
<PatternLayout pattern="%d{DEFAULT} %-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id}) %m%ex{filters(${filters})}%n"/>
<PatternLayout pattern="%-5p [%c{1.}] (%t:%x) (logid:%X{logcontextid}) (traceid:%X{traceid}) (trace_id:%X{trace_id} span_id:%X{span_id}) %m%ex{filters(${filters})}%n"/>
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep -E "Done Starting CloudStack Components|bean \[.*\] started in" $LOG | tail -3
2026-09-25 10:42:38,029 INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:[ctx-be3a01e1]) (logid:) (traceid:) (trace_id: span_id:) Done Starting CloudStack Components
2026-09-25 10:42:38,029 INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:[ctx-be3a01e1]) (logid:) (traceid:) (trace_id: span_id:) bean [REDFISH] started in 0 ms
2026-09-25 10:42:38,029 INFO [o.a.c.s.l.CloudStackExtendedLifeCycle] (main:[ctx-be3a01e1]) (logid:) (traceid:) (trace_id: span_id:) Done Starting CloudStack Components
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# api kiran-a2-001 "command=listZones" >/dev/null # >0: your header is used
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "traceid:kiran-a2-001" $LOG
2026-09-25 12:12:02,129 DEBUG [c.c.a.ApiServlet] (qtp698741991-22:[ctx-f817e867]) (logid:5a3b5983) (traceid:kiran-a2-001) (trace_id: span_id:) ===START=== 10.0.32.222 -- GET command=listZones&response=json&sessionkey=
2026-09-25 12:12:02,129 DEBUG [c.c.a.ApiServer] (qtp698741991-22:[ctx-f817e867, ctx-93c25d0e]) (logid:5a3b5983) (traceid:kiran-a2-001) (trace_id: span_id:) Expired session, missing signature, or missing apiKey -- ignoring request. Signature: null, apiKey: null
2026-09-25 12:12:02,131 DEBUG [c.c.a.ApiServlet] (qtp698741991-22:[ctx-f817e867, ctx-93c25d0e]) (logid:5a3b5983) (traceid:kiran-a2-001) (trace_id: span_id:) ===END=== 10.0.32.222 -- GET command=listZones&response=json&sessionkey=
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# api "" "command=listZones" >/dev/null # a generated UUID
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "command=listZones" $LOG | tail -1 | grep -o "traceid:[^)]*"
traceid:0ccc18a1-552d-4c54-bf01-66dcab4f6335
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]#api "$(printf 'a%.0s' {1..200})" "command=listZones" >/dev/null
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]#grep -c "traceid:aaaaaaaaaa" $LOG # 0: over 128 chars is rejected
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]#curl -s -b cj -H $'traceid: abc\tdef' "$MS?command=listZones&response=json&sessionkey=$SK" >/dev/null
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]#grep -c "traceid:abc" $LOG # 0: control characters are rejected
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# api kiran-a3-001 "command=deployVirtualMachine&zoneid=$ZONE&serviceofferingid=$SO&templateid=$TMPL&networkids=$NET&name=a3-vm" | jq .
{
"deployvirtualmachineresponse": {
"id": "970c80fc-b4e4-4d45-804e-81bc67519ca2",
"jobid": "107a662c-5c46-4484-8615-f06b16ddeb39"
}
}
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# q "select id, related, job_cmd, job_dispatcher, context from async_job order by id desc limit 3\G" | grep -E "id:|related|job_cmd:|dispatcher|context"
mysql: [Warning] Using a password on the command line interface can be insecure.
id: 41
related:
job_cmd:
job_dispatcher: VmWorkJobPlaceHolder
context: NULL
id: 40
related: 39
job_cmd: com.cloud.vm.VmWorkStart
job_dispatcher: VmWorkJobDispatcher
context: NULL
id: 39
related:
job_cmd: org.apache.cloudstack.api.command.admin.vm.DeployVMCmdByAdmin
job_dispatcher: ApiAsyncJobDispatcher
context: {"traceid":"kiran-a3-001"}
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "kiran-a3-001" $LOG | grep -oE "\((API|Work)-Job-Executor-[0-9]+" | sort | uniq -c
97 (API-Job-Executor-31
Also check that a second async job without a header doesn't reuse kiran-a3-001:
api "" "command=stopVirtualMachine&id=<a3-vm-id>" >/dev/null; sleep 30
grep "kiran-a3-001" $LOG | tail -3 # nothing newer than the a3-vm deploy
External-DHCP startup scan.
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "External-DHCP VM-IP map seeded" $LOG | tail -1
2026-09-25 10:42:36,849 INFO [c.c.v.UserVmManagerImpl] (main:[]) (logid:) (traceid:) (trace_id: span_id:) External-DHCP VM-IP map seeded: 0 shared-without-service networks, 0 nics added, took 16 ms
Test B. With the OTel agent (the feature)
1. Create the directory
mkdir -p /opt/otel
2. Download the agent (2.16.0 matches the annotations version the PR uses)
curl -fL -o /opt/otel/opentelemetry-javaagent.jar \
https://github.com/open-telemetry/opentelemetry-java-instrumentation/releases/download/v2.16.0/opentelemetry-javaagent.jar
3. Owner cloud; the jar is read-only, the directory is readable and searchable
chown -R cloud:cloud /opt/otel
chmod 755 /opt/otel
chmod 644 /opt/otel/opentelemetry-javaagent.jar
4. Check it
ls -l /opt/otel/
unzip -p /opt/otel/opentelemetry-javaagent.jar META-INF/MANIFEST.MF | grep -i "Implementation-Version" # 2.16.0
sudo -u cloud test -r /opt/otel/opentelemetry-javaagent.jar && echo "cloud can read it"
ls /opt/otel/opentelemetry-javaagent.jar # must NOT be under /usr/share/cloudstack-management/lib
Add these to the end of JAVA_OPTS in /etc/default/cloudstack-management:
-javaagent:/opt/otel/opentelemetry-javaagent.jar -Dotel.service.name=cloudstack-management -Dotel.exporter.otlp.endpoint=http://<jaeger-ip>:4318 -Dotel.metrics.exporter=none -Dotel.logs.exporter=none
systemctl restart cloudstack-management
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# ps -ef | grep "[o]pentelemetry-javaagent"
cloud 32411 1 99 12:33 ? 00:01:54 /usr/bin/java -Djava.security.properties=/etc/cloudstack/management/java.security.ciphers -Djava.awt.headless=true -Xmx2G -XX:+UseParallelGC -XX:MaxGCPauseMillis=500 -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=/var/log/cloudstack/management/ -XX:ErrorFile=/var/log/cloudstack/management/cloudstack-management.err --add-opens=java.base/java.lang=ALL-UNNAMED --add-exports=java.base/sun.security.x509=ALL-UNNAMED -Djava.io.tmpdir=/var/tmp -javaagent:/opt/otel/opentelemetry-javaagent.jar -Dotel.service.name=cloudstack-management -Dotel.exporter.otlp.endpoint=http://localhost:4318 -Dotel.metrics.exporter=none -Dotel.logs.exporter=none -cp /usr/share/cloudstack-management/lib/*:/etc/cloudstack/management:/usr/share/cloudstack-common:/usr/share/cloudstack-management/setup:/usr/share/cloudstack-management:/usr/share/cloudstack-mysql-ha/lib/* org.apache.cloudstack.ServerDaemon
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/traces?service=cloudstack-management&operation=startup.modules.load&limit=1" | jq '.data[0].spans | length'
127
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/traces?service=cloudstack-management&operation=startup.beans.start&limit=1" \
> | jq -r '.data[0].spans[] | .operationName + " " + ([.tags[]|select(.key=="bean.name")|.value]|join(""))' | head
startup.bean.start REDFISH
startup.beans.start
API spans
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# cmk list zones; cmk list virtualmachines
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/traces?service=cloudstack-management&tags=%7B%22api.command%22%3A%22listZones%22%7D&limit=1" \
> | jq -r '.data[0].spans[].operationName' | sort | uniq -c
1 ApiServer.handleRequest listZones
47 Execute prepared statement
2 Ping
1 POST /client/api/*
47 Prepare statement
7 Rollback
2 SELECT cloud
12 SELECT cloud.account
1 SELECT cloud.account_details
1 SELECT cloud.annotations
1 SELECT cloud.as_number_range
1 SELECT cloud.cluster
14 SELECT cloud.configuration
1 SELECT cloud.data_center
5 SELECT cloud.data_center_details
2 SELECT cloud.data_center_view
2 SELECT cloud.domain_details
1 SELECT cloud.netris_providers
1 SELECT cloud.nsx_providers
1 SELECT cloud.resource_tag_view
1 SELECT cloud.roles
1 SELECT cloud.user
14 Set variable 'autocommit'
VM lifecycle spans
cmk deploy virtualmachine zoneid=$ZONE serviceofferingid=$SO templateid=$TMPL networkids=$NET name=b3-vm
cmk stop virtualmachine id=<b3-vm-id>; cmk start virtualmachine id=<b3-vm-id>
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# for op in VmWorkStart VmWorkStop ; do
> echo "== $op"
> curl -s "$JAEGER/api/traces?service=cloudstack-management&operation=$op&limit=1" \
> | jq -r '.data[0].spans[] | select(.operationName|test("^VmWork|^agent\\.")) | "\(.operationName) \([.tags[]|select(.key|startswith("cloudstack."))|"\(.key)=\(.value)"]|join(" "))"'
> done
== VmWorkStart
agent.out.DhcpEntryCommand cloudstack.traffic=hypervisor cloudstack.host.id=2 cloudstack.agent.call=true cloudstack.agent.command=DhcpEntryCommand
agent.out.SavePasswordCommand cloudstack.traffic=hypervisor cloudstack.host.id=2 cloudstack.agent.call=true cloudstack.agent.command=SavePasswordCommand
agent.out.StartCommand cloudstack.traffic=hypervisor cloudstack.host.id=1 cloudstack.agent.call=true cloudstack.agent.command=StartCommand
VmWorkStart cloudstack.traffic=hypervisor cloudstack.vm.id=5 cloudstack.op.root=true cloudstack.job.result=SUCCEEDED cloudstack.vm.op=VmWorkStart
== VmWorkStop
agent.out.GetVmDiskStatsCommand cloudstack.traffic=hypervisor cloudstack.host.id=1 cloudstack.agent.call=true cloudstack.agent.command=GetVmDiskStatsCommand
agent.out.GetVmNetworkStatsCommand cloudstack.traffic=hypervisor cloudstack.host.id=1 cloudstack.agent.call=true cloudstack.agent.command=GetVmNetworkStatsCommand
agent.out.StopCommand cloudstack.traffic=hypervisor cloudstack.host.id=1 cloudstack.agent.call=true cloudstack.agent.command=StopCommand
VmWorkStop cloudstack.traffic=hypervisor cloudstack.vm.id=5 cloudstack.op.root=true cloudstack.job.result=SUCCEEDED cloudstack.vm.op=VmWorkStop
Failed job
cmk create serviceoffering name=huge displaytext=huge cpunumber=128 cpuspeed=1000 memory=1048576
cmk deploy virtualmachine zoneid=$ZONE serviceofferingid=<huge-id> templateid=$TMPL networkids=$NET name=b4-vm # should fail
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/traces?service=cloudstack-management&operation=VmWorkStart&limit=1" \
> | jq -r '.data[0].spans[] | select(.operationName=="VmWorkStart") | .tags[] | select(.key=="cloudstack.job.result") | .value'
SUCCEEDED
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep -iE "span|opentelemetry" $LOG | grep -iE "exception" | tail -3
2026-09-25 12:34:51,690 DEBUG [c.c.c.ClusterManagerImpl] (main:[]) (logid:) (traceid:) (trace_id: span_id:) Unable to ping management server at 10.0.32.222:9090 due to ConnectException java.net.ConnectException: Connection refused
2026-09-25 12:52:02,417 DEBUG [o.a.c.a.c.a.v.DeployVMCmdByAdmin] (API-Job-Executor-6:[ctx-21af445e, job-56, ctx-db15efaf]) (logid:8052006a) (traceid:646022cb-5ec8-4603-ae6d-de4f6a6a8792) (trace_id:b0368dbd291579fdb2ac742aecf6f222 span_id:4818991c8e4b51d0) No destination found for a deployment for VM instance {"id":6,"instanceName":"i-2-6-VM","state":"Stopped","type":"User","uuid":"847b8b73-2b8a-41f1-adf7-92abef32afb1"} com.cloud.exception.InsufficientServerCapacityException: No destination found for a deployment for VM instance {"id":6,"instanceName":"i-2-6-VM","state":"Stopped","type":"User","uuid":"847b8b73-2b8a-41f1-adf7-92abef32afb1"}Scope=interface com.cloud.dc.DataCenter; id=1
2026-09-25 12:52:02,418 DEBUG [o.a.c.f.j.i.AsyncJobManagerImpl] (API-Job-Executor-6:[ctx-21af445e, job-56]) (logid:8052006a) (traceid:646022cb-5ec8-4603-ae6d-de4f6a6a8792) (trace_id:b0368dbd291579fdb2ac742aecf6f222 span_id:4818991c8e4b51d0) Complete async job-56, jobStatus: FAILED, resultCode: 533, result: org.apache.cloudstack.api.response.ExceptionResponse/null/{"uuidList":[],"errorcode":"533","errortext":"No destination found for a deployment for VM instance {"id":6,"instanceName":"i-2-6-VM","state":"Stopped","type":"User","uuid":"847b8b73-2b8a-41f1-adf7-92abef32afb1"}"}
Outbound agent spans
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/services/cloudstack-management/operations" | jq -r '.data[]' | grep "^agent\.out\."
agent.out.NetworkUsageCommand
agent.out.GetVmDiskStatsCommand
agent.out.StopCommand
agent.out.GetStorageStatsCommand
agent.out.CheckNetworkCommand
agent.out.ReadyCommand
agent.out.StartCommand
agent.out.GetVmNetworkStatsCommand
agent.out.ModifyStoragePoolCommand
agent.out.DhcpEntryCommand
agent.out.GetVolumeStatsCommand
agent.out.GetVmStatsCommand
agent.out.GetHostStatsCommand
agent.out.SavePasswordCommand
Inbound agent spans
systemctl restart cloudstack-agent
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# curl -s "$JAEGER/api/services/cloudstack-management/operations" | jq -r '.data[]' | grep "^agent\.in\."
agent.in.StartupRoutingCommand
Trace and span IDs in log lines
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep "command=listZones" $LOG | tail -2 | grep -o "(traceid:[^)]*) (trace_id:[^)]*)"
(traceid:497ffacb-409c-40be-9dbf-7ad905630889) (trace_id:4bef5c02e920cbe588984176048fd0cc span_id:16b792ab24ea39db)
(traceid:497ffacb-409c-40be-9dbf-7ad905630889) (trace_id:4bef5c02e920cbe588984176048fd0cc span_id:16b792ab24ea39db)
[root@ref-trl-12432-k-Mol8-kiran-chavala-mgmt1 ~]# grep -E "VmWorkStart|StartCommand" $LOG | tail -5 | grep -o "(traceid:[^)]*) (trace_id:[^)]*)"
(traceid:) (trace_id:bb2125afd8d0751748a6d54533fde8a1 span_id:79fb8ea250845e33)
(traceid:) (trace_id:bb2125afd8d0751748a6d54533fde8a1 span_id:c6bce3df66887293)
(traceid:) (trace_id:bb2125afd8d0751748a6d54533fde8a1 span_id:79fb8ea250845e33)
(traceid:) (trace_id: span_id:)
(traceid:) (trace_id: span_id:)
Screenshots
Description
This PR adds support for OpenTelemetry distributed tracing instrumentation, has the following changes
Adds support to API layer
All API requests get a traceId in LogContext (via ApiTraceFilter), captures traceID from API. Async jobs store that context JSON in DB, restored before execution. All logs show traceId automatically via %X{traceId}
the ApiTraceFilter that records a per request trace id on the log context when a request runs inside an active OpenTelemetry span, it also records the span trace id and span id on the log context, so log lines can be joined to the distributed trace. The existing header or UUID traceid behaviour is unchanged.
No id is invented: when there is no valid span the keys are left unset and render empty, and all keys are removed in the finally block. The filter lives in the api module. LogContext gains the key constants and ThreadContext write/remove support.
When the OTel Java agent is attached (via
-javaagent), every API request is traced with:listVirtualMachines,deployVirtualMachine) viaSpan.current().updateName()and a filterableapi.commandattribute, making it possible to analyze latency per API command.All changes are no-ops without the OTel agent deployed. The
@WithSpanannotation is ignored,Span.current()returns a no-op, and theopentelemetry-apicalls return immediately with zero overhead. The two added dependencies (opentelemetry-instrumentation-annotationsandopentelemetry-api) are lightweight JARs (~50KB + ~200KB) with no transitive dependencies.Changes:
server/pom.xml: Addopentelemetry-instrumentation-annotations(2.16.0) andopentelemetry-api(1.51.0) dependenciesapi/pom.xml: Addopentelemetry-instrumentation-annotations(2.16.0) dependencyApiServer.java: Add@WithSpanonhandleRequest()with dynamic span naming using the API command parameter andapi.commandspan attributesupervisord.conf: Addredirect_stderr=trueto cloudstack process so OTel agent startup logs are visible in container logsInstrument cloudstack Agents and VM operations
Changes:
AgentAttache.send) are now wrapped in aCLIENTspan namedagent.out.<CommandName>, tagged with the traffic type, command name, host id, and an agent-call marker.AgentManagerImpl.processRequest) are now wrapped in aSERVERspan namedagent.in.<CommandName>, tagged with the same set of attributes so the incoming side of a command can be correlated with the outgoing side.VirtualMachineManagerImpl.handleVmWorkJob) are now wrapped in a span named after the work operation (e.g.VmWorkStart), tagged with the operation, VM id, an op-root marker, and the resulting job status. The VM operation, VM id, and traffic type are also propagated as OpenTelemetry baggage for the duration of the job so downstream spans inherit that context.TracingLabelsutility class centralizes the span attribute / baggage keys (and shared values like thehypervisortraffic type) so instrumentation stays consistent across handlers.opentelemetry-apiandopentelemetry-instrumentation-annotationsdependencies toengine/orchestration.This is purely additive instrumentation. When no OpenTelemetry agent/SDK is attached, the API is a no-op and behavior is unchanged.
handleVmWorkJobguards against a null result before recording the job-status attribute.Read the trace and span threadcontext key names from the environment
The ThreadContext key names used for the OpenTelemetry trace and span ids were hardcoded in LogContext. This reads them from the environment instead, so the key names are deployment specific rather than baked into core:
CLOUDSTACK_TRACE_ID_MDC_KEY, defaultotel_trace_idCLOUDSTACK_SPAN_ID_MDC_KEY, defaultotel_span_idThe default applies whenever the property is absent or blank, so a deployment that configures nothing still gets working, self describing key names. A deployment that needs a particular field name in its log pipeline sets the properties, and nothing in core has to know about it.
Changes:
Four files: the constants and property lookup in LogContext, the two usages plus a javadoc line in TraceContextMdcWrapper, the assertions in TraceContextMdcWrapperTest, and one comment in ServerDaemon. No behaviour changes beyond where the key names come from.
Types of changes
Feature/Enhancement Scale or Bug Severity
Feature/Enhancement Scale
Bug Severity
Screenshots (if appropriate):
How Has This Been Tested?
How did you try to break this feature and the system with this change?