diff --git a/docs/.vitepress/config.mts b/docs/.vitepress/config.mts index d06107619..1c33c25b2 100644 --- a/docs/.vitepress/config.mts +++ b/docs/.vitepress/config.mts @@ -99,6 +99,7 @@ export default defineConfig({ { text: "Windows Sandbox", link: "/guides/windows-sandbox" }, { text: "Client Pool", link: "/guides/client-pool" }, { text: "SDK Telemetry", link: "/guides/sdk-telemetry" }, + { text: "SDK Tracing (Pool Warmup)", link: "/guides/sdk-tracing" }, ], }, ], diff --git a/docs/guides/client-pool.md b/docs/guides/client-pool.md index f9b36a431..7fa6f32ce 100644 --- a/docs/guides/client-pool.md +++ b/docs/guides/client-pool.md @@ -296,6 +296,15 @@ validate a positive concurrency value and wait for every drained ID to receive a best-effort kill attempt. The Go method is intentionally outside the `SandboxPool` interface to preserve compatibility with third-party implementors. +### Tracing warmups (Kotlin) + +The Kotlin SDK can emit an OpenTelemetry trace per warmup task (`pool.warmup` +root span plus `create` / `prepare` / `renew` / `commit` phases) when +`ConnectionConfig.enableTracing(true)` is set and an OpenTelemetry SDK + +exporter is on the classpath. `trace_id` / `span_id` are published to the +SLF4J MDC, so search your logs for a `sandbox_id` to find the warmup trace and +drill into phase durations. See [SDK Tracing (Pool Warmup)](/guides/sdk-tracing). + ### Retiring an old pool namespace The retirement procedure differs across SDKs because Go does not currently ship a diff --git a/docs/guides/sdk-tracing.md b/docs/guides/sdk-tracing.md new file mode 100644 index 000000000..5df7d9201 --- /dev/null +++ b/docs/guides/sdk-tracing.md @@ -0,0 +1,182 @@ +--- +title: SDK Tracing (Pool Warmup) +description: How to enable OpenTelemetry tracing for the Kotlin SDK pool warmup path, what spans are produced, and how to query and drill down into warmup traces. +--- + +# SDK Tracing (Pool Warmup) + +The Kotlin/Java SDK (`com.alibaba.opensandbox:sandbox`) can emit +[OpenTelemetry](https://opentelemetry.io/) traces for the client-side +`SandboxPool` warmup path. Each warmup task becomes one trace that covers the +full lifecycle — from the moment the reconcile loop submits the task until the +warmed sandbox is committed to the idle buffer — with per-phase spans so you +can find the actual warmup bottleneck. + +Tracing is **opt-in** (`enableTracing(true)`) and **best-effort**: without an +OpenTelemetry SDK + exporter on the application classpath, all span calls are +no-ops and nothing is exported. Tracing never throws and never affects pool +behavior. + +## Requirements + +| Component | Minimum version | +|-----------|-----------------| +| Kotlin / Java SDK (`com.alibaba.opensandbox:sandbox`) | `1.0.19` | + +Only the Kotlin SDK emits these traces today; the other language SDKs do not +yet support `enableTracing`. + +## Enabling tracing + +### 1. Add an OpenTelemetry SDK + exporter to your application + +The SDK depends only on `opentelemetry-api` (no-op by default). To actually +export traces you bring your own SDK and exporter, for example OTLP over HTTP: + +```kotlin +dependencies { + implementation("io.opentelemetry:opentelemetry-api:1.51.0") + implementation("io.opentelemetry:opentelemetry-sdk:1.51.0") + implementation("io.opentelemetry:opentelemetry-exporter-otlp:1.51.0") +} +``` + +### 2. Configure a global `OpenTelemetry` instance + +Warmup spans use the global instance (`GlobalOpenTelemetry`). Configure it at +application startup, e.g. with `OpenTelemetrySdk`: + +```java +import io.opentelemetry.sdk.OpenTelemetrySdk; +import io.opentelemetry.sdk.trace.SdkTracerProvider; +import io.opentelemetry.sdk.trace.export.BatchSpanProcessor; +import io.opentelemetry.exporter.otlp.trace.OtlpGrpcSpanExporter; + +SdkTracerProvider tracerProvider = SdkTracerProvider.builder() + .addSpanProcessor(BatchSpanProcessor.create( + OtlpGrpcSpanExporter.builder() + .setEndpoint("http://otel-collector:4317") + .build())) + .build(); + +OpenTelemetrySdk sdk = OpenTelemetrySdk.builder() + .setTracerProvider(tracerProvider) + .build(); + +GlobalOpenTelemetry.set(sdk); +``` + +::: tip Propagators +`OpenTelemetrySdk.builder()` defaults to **noop propagators**. If you want the +SDK to inject the W3C `traceparent` header into lifecycle requests (so the +lifecycle server can join the same trace once it supports tracing), configure +W3C propagation explicitly: + +```java +.setPropagators(ContextPropagators.create(W3CTraceContextPropagator.getInstance())) +``` +::: + +::: tip Sampling +To keep trace volume bounded, use a sampling strategy such as +`parentbased_traceidratio(0.1)` on the `SdkTracerProvider`. Trace-id-ratio +sampling keeps client and server spans consistent for the same warmup. +::: + +### 3. Turn tracing on for the pool + +```java +ConnectionConfig config = ConnectionConfig.builder() + .enableTracing(true) + .build(); + +SandboxPool pool = SandboxPool.builder() + .poolName("demo-pool") + .maxIdle(3) + .stateStore(new InMemoryPoolStateStore()) + .connectionConfig(config) + .creationSpec(PoolCreationSpec.builder().image("ubuntu:22.04").build()) + .build(); +``` + +That is all. No environment variables are involved; `enableTracing` defaults +to `false`. + +## What is traced + +Each warmup task produces **one trace** with a root span and four sequential +phase spans (siblings under the root, so each phase duration stands alone for +comparison): + +| Span name | Covers | +|-----------|--------| +| `pool.warmup` (root) | Task submission → sandbox committed to idle. Backdated to submission time, so the queue wait before the first phase is visible as the gap before the first child span | +| `pool.warmup.create` | Sandbox create API call, endpoint resolution, and readiness wait | +| `pool.warmup.prepare` | The configured `warmupSandboxPreparer` (user init script / setup work) | +| `pool.warmup.renew` | TTL renewal right before committing the sandbox | +| `pool.warmup.commit` | Primary-lock renewal + `putIdle` against the state store (runs on the pool scheduler thread) | + +Root span attributes (these are your drill-down dimensions): + +| Attribute | Value | +|-----------|-------| +| `pool.name` | Pool name | +| `pool.owner` | Pool owner id | +| `pool.run.generation` | Pool run generation | +| `sandbox.id` | Sandbox id (success only) | +| `sandbox.image` | Creation image (success only) | +| `result` | `success` or `failure` | + +Failures are recorded with `recordException` on the root span plus +`result=failure`; the `pool.warmup.commit` span is not emitted for failed +warmups. + +## Correlating logs to traces + +While a warmup trace is in progress, the pool publishes the trace ids to the +SLF4J [MDC](https://www.slf4j.org/api/org/slf4j/MDC.html): + +| MDC key | Value | +|---------|-------| +| `trace_id` | Current trace id | +| `span_id` | Current span id | + +MDC requires a real SLF4J provider (logback, log4j2, ...). Add the keys to +your log pattern once, and every pool log line carries the trace context: + +```xml +%d %-5level [%thread] %logger{36} trace_id=%X{trace_id} span_id=%X{span_id} - %msg%n +``` + +## Querying traces + +The trace id is random, so a warmup trace cannot be looked up "by pool name" +directly. The reliable paths are: + +1. **Log correlation (recommended).** The pool already logs `pool_name` and + `sandbox_id` on its warmup lines (e.g. `Pool warmup sandbox entered idle`). + Search your logs for a `sandbox_id` — the matching log lines carry + `trace_id`, which you can open directly in your trace backend. +2. **Attribute query in the trace backend.** Filter spans by time window and + attribute, e.g. TraceQL `{ span.pool.name = "demo-pool" }` (Grafana Tempo), + or Jaeger tag search on `pool.name=...`. Backends that derive metrics from + spans (Tempo metrics, Datadog span analytics) let you look at + `pool.warmup` duration percentiles per `pool.name` first, then drill into + slow traces. +3. **Trace-id-ratio sampling.** With sampled traces, `trace_id` in logs and + the backend are consistent for the same warmup. + +### Bottleneck drill-down + +``` +pool.warmup root duration (p50/p95/p99) per pool.name + └─ phase spans: pool.warmup.create / prepare / renew / commit + └─ single trace: root start gap = queue wait, then each phase duration +``` + +| Symptom | Likely cause | +|---------|--------------| +| Long gap before the first child span | Warmup tasks queued — `warmupConcurrency` too low, or the executor is busy with cleanup kills | +| `pool.warmup.create` slow | Lifecycle server slow (image pull / execd startup) or readiness polling takes long | +| `pool.warmup.prepare` slow | Your `warmupSandboxPreparer` work is the bottleneck | +| `pool.warmup.renew` / `pool.warmup.commit` slow | State store (e.g. Redis) round-trips | diff --git a/docs/sdks/kotlin.md b/docs/sdks/kotlin.md index 91e5203a1..23834ea3d 100644 --- a/docs/sdks/kotlin.md +++ b/docs/sdks/kotlin.md @@ -301,6 +301,14 @@ poolManager.destroy( - Use `warmupSandboxPreparer(...)` if you need to prepare a sandbox after warmup readiness succeeds and before it is put into the idle pool. ::: +::: tip Observing warmup performance +To trace the warmup path, enable `ConnectionConfig.builder().enableTracing(true)` and add an +OpenTelemetry SDK + exporter to your application. Each warmup becomes one trace +(`pool.warmup` root span plus `create` / `prepare` / `renew` / `commit` phases) with +`trace_id` / `span_id` published to the SLF4J MDC, so you can look up a sandbox's +warmup by searching logs for its `sandbox_id`. See [SDK Tracing (Pool Warmup)](/guides/sdk-tracing). +::: + ::: tip Distributed Deployment For distributed deployment, use the optional `com.alibaba.opensandbox:sandbox-pool-redis` module or provide a custom `PoolStateStore` implementation. The Redis module accepts a caller-managed Jedis client, so your application keeps ownership of Redis connection configuration and lifecycle. Nodes sharing the same pool namespace must use the same sandbox creation and warmup definition; use a new `poolName` or namespace when changing that definition. Configure `primaryLockTtl` greater than `warmupReadyTimeout` plus expected warmup preparer time and buffer, otherwise leadership may expire while a node is creating idle sandboxes. @@ -329,6 +337,7 @@ The `ConnectionConfig` class manages API server connection settings. | `retryPolicy` | Automatic retry policy for non-streaming requests (see [Automatic retries](#_2-automatic-retries)) | Enabled (`RetryPolicy()`) | - | | `useServerProxy` | Use sandbox server as proxy for execd/endpoint requests (e.g. when client cannot reach the sandbox directly) | `false` | - | | `disableMetrics` | Disable SDK create-latency telemetry (see [SDK Telemetry](/guides/sdk-telemetry)) | `false` | `OPENSANDBOX_DISABLE_METRICS` | +| `enableTracing` | Enable OpenTelemetry tracing for pool warmup (see [SDK Tracing](/guides/sdk-tracing)) | `false` | - | ```java // 1. Basic configuration diff --git a/sdks/sandbox/kotlin/gradle/libs.versions.toml b/sdks/sandbox/kotlin/gradle/libs.versions.toml index 6998d867e..d363627c8 100644 --- a/sdks/sandbox/kotlin/gradle/libs.versions.toml +++ b/sdks/sandbox/kotlin/gradle/libs.versions.toml @@ -17,6 +17,7 @@ kotlin = "2.2.21" kotlinx-serialization = "1.9.0" okhttp = "4.12.0" slf4j = "2.0.9" +opentelemetry = "1.51.0" jedis = "5.2.0" junit = "5.10.1" mockk = "1.13.8" @@ -43,6 +44,11 @@ kotlinx-serialization-json = { module = "org.jetbrains.kotlinx:kotlinx-serializa # Logging slf4j-api = { module = "org.slf4j:slf4j-api", version.ref = "slf4j" } +logback-classic = { module = "ch.qos.logback:logback-classic", version = "1.5.18" } + +# Tracing (API only; no-op when no OpenTelemetry SDK is on the classpath) +opentelemetry-api = { module = "io.opentelemetry:opentelemetry-api", version.ref = "opentelemetry" } +opentelemetry-sdk-testing = { module = "io.opentelemetry:opentelemetry-sdk-testing", version.ref = "opentelemetry" } # Redis jedis = { module = "redis.clients:jedis", version.ref = "jedis" } diff --git a/sdks/sandbox/kotlin/sandbox-bom/build.gradle.kts b/sdks/sandbox/kotlin/sandbox-bom/build.gradle.kts index d00f1c41b..a8a4a8d26 100644 --- a/sdks/sandbox/kotlin/sandbox-bom/build.gradle.kts +++ b/sdks/sandbox/kotlin/sandbox-bom/build.gradle.kts @@ -29,5 +29,6 @@ dependencies { api(libs.okhttp) api(libs.okhttp.logging) api(libs.slf4j.api) + api(libs.opentelemetry.api) } } diff --git a/sdks/sandbox/kotlin/sandbox/build.gradle.kts b/sdks/sandbox/kotlin/sandbox/build.gradle.kts index 51b1c9241..1d32b6b76 100644 --- a/sdks/sandbox/kotlin/sandbox/build.gradle.kts +++ b/sdks/sandbox/kotlin/sandbox/build.gradle.kts @@ -21,10 +21,13 @@ dependencies { implementation(libs.okhttp) implementation(libs.okhttp.logging) + implementation(libs.opentelemetry.api) compileOnly(libs.bundles.serialization) testImplementation(libs.bundles.testing) testImplementation(libs.bundles.serialization) + testImplementation(libs.opentelemetry.sdk.testing) + testRuntimeOnly(libs.logback.classic) testRuntimeOnly(libs.junit.platform.launcher) } diff --git a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/HttpClientProvider.kt b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/HttpClientProvider.kt index 8abbbbf3f..92e58bba2 100644 --- a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/HttpClientProvider.kt +++ b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/HttpClientProvider.kt @@ -19,7 +19,12 @@ package com.alibaba.opensandbox.sandbox import com.alibaba.opensandbox.sandbox.config.ConnectionConfig import com.alibaba.opensandbox.sandbox.domain.models.execd.SECURE_ACCESS_HEADER import com.alibaba.opensandbox.sandbox.transport.RetryInterceptor +import io.opentelemetry.api.GlobalOpenTelemetry +import io.opentelemetry.context.Context +import io.opentelemetry.context.propagation.TextMapPropagator +import io.opentelemetry.context.propagation.TextMapSetter import okhttp3.ConnectionPool +import okhttp3.Headers import okhttp3.Interceptor import okhttp3.OkHttpClient import okhttp3.Response @@ -44,12 +49,21 @@ class HttpClientProvider( private val connectionPoolOwnedBySdk: Boolean = config.connectionPool == null private val baseBuilder: OkHttpClient.Builder - get() = - OkHttpClient.Builder() - .connectionPool(connectionPool) - .addInterceptor(UserAgentInterceptor(config.userAgent)) - .addInterceptor(ExtraHeadersInterceptor(config.headers)) - .addInterceptor(ClientIpInterceptor { ClientIpDetector.clientIp() }) + get() { + val builder = + OkHttpClient.Builder() + .connectionPool(connectionPool) + .addInterceptor(UserAgentInterceptor(config.userAgent)) + .addInterceptor(ExtraHeadersInterceptor(config.headers)) + .addInterceptor(ClientIpInterceptor { ClientIpDetector.clientIp() }) + if (config.enableTracing) { + // Propagate the active trace context (W3C traceparent) so the + // lifecycle server can join the same trace. No-op when there + // is no active span in the current context. + builder.addInterceptor(TraceContextInterceptor(GlobalOpenTelemetry.getPropagators().textMapPropagator)) + } + return builder + } // 1. Explicit lazy definition to allow checking initialization status private val httpClientLazy = @@ -202,6 +216,27 @@ class HttpClientProvider( } } + /** + * Injects the W3C `traceparent` / `tracestate` headers of the current + * OpenTelemetry context into every request. When no span is active the + * propagator injects nothing and the request passes through unchanged. + */ + private class TraceContextInterceptor( + private val propagators: TextMapPropagator, + ) : Interceptor { + private val setter = + TextMapSetter { carrier: Headers.Builder?, key, value -> + carrier?.set(key, value) + } + + override fun intercept(chain: Interceptor.Chain): Response { + val request = chain.request() + val headers = request.headers.newBuilder() + propagators.inject(Context.current(), headers, setter) + return chain.proceed(request.newBuilder().headers(headers.build()).build()) + } + } + // --- Cleanup --- /** diff --git a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/config/ConnectionConfig.kt b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/config/ConnectionConfig.kt index c58533cee..e0beb4c48 100644 --- a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/config/ConnectionConfig.kt +++ b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/config/ConnectionConfig.kt @@ -59,6 +59,17 @@ class ConnectionConfig private constructor( * Also honored via the `OPENSANDBOX_DISABLE_METRICS=1` environment variable. */ val disableMetrics: Boolean = false, + /** + * Enable OpenTelemetry tracing for the client-side sandbox pool warmup path. + * + * Off by default. When enabled, each pool warmup creates an OpenTelemetry + * trace (`pool.warmup` root span plus per-phase spans) and the active + * trace context is propagated to lifecycle requests via the W3C + * `traceparent` header. Tracing is best-effort: without an + * OpenTelemetry SDK + exporter on the classpath, all span calls are + * no-ops and nothing is exported. + */ + val enableTracing: Boolean = false, /** * Retry policy applied to non-streaming requests. Enabled by default; pass * [RetryPolicy.disabled] to disable SDK-policy retries and fall back to @@ -88,6 +99,7 @@ class ConnectionConfig private constructor( endpointCacheSize = this.endpointCacheSize, endpointCacheDisabled = this.endpointCacheDisabled, disableMetrics = this.disableMetrics, + enableTracing = this.enableTracing, retryPolicy = this.retryPolicy, ) @@ -188,6 +200,7 @@ class ConnectionConfig private constructor( private var endpointCacheSize: Int = 1024 private var endpointCacheDisabled: Boolean = false private var disableMetrics: Boolean = false + private var enableTracing: Boolean = false private var retryPolicy: RetryPolicy = RetryPolicy() /** @@ -228,6 +241,17 @@ class ConnectionConfig private constructor( return this } + /** + * Enable OpenTelemetry tracing for the client-side sandbox pool warmup path. + * + * Off by default; pass `true` to opt in. Tracing is best-effort and no-ops + * unless an OpenTelemetry SDK + exporter is on the classpath. + */ + fun enableTracing(enable: Boolean = true): Builder { + this.enableTracing = enable + return this + } + /** * Set the API key used for authentication. * @@ -383,6 +407,7 @@ class ConnectionConfig private constructor( endpointCacheSize = endpointCacheSize, endpointCacheDisabled = endpointCacheDisabled, disableMetrics = disableMetrics, + enableTracing = enableTracing, retryPolicy = retryPolicy, ) } diff --git a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/internal/PoolTracer.kt b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/internal/PoolTracer.kt new file mode 100644 index 000000000..23d66f05a --- /dev/null +++ b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/internal/PoolTracer.kt @@ -0,0 +1,236 @@ +/* + * Copyright 2026 Alibaba Group Holding Ltd. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.alibaba.opensandbox.sandbox.internal + +import com.alibaba.opensandbox.sandbox.config.ConnectionConfig +import io.opentelemetry.api.GlobalOpenTelemetry +import io.opentelemetry.api.trace.Span +import io.opentelemetry.api.trace.Tracer +import org.slf4j.MDC +import java.util.concurrent.TimeUnit + +/** + * Best-effort OpenTelemetry tracing for the client-side pool warmup path. + * + * Tracing is opt-in via [ConnectionConfig.enableTracing]. When enabled, each + * warmup task produces one trace rooted at a [WARMUP_ROOT_SPAN] span with + * per-phase child spans (create / prepare / renew / commit). The root span + * starts at task submission time so queue-waiting time is visible as the gap + * before the first child span. + * + * While a warmup trace is current, `trace_id` and `span_id` are published to + * the SLF4J [MDC] so application logs emitted by the pool (which already + * carry `pool_name` / `sandbox_id`) can be correlated back to a trace — + * search logs by sandbox_id to obtain the trace_id, then open it in the + * trace backend. + * + * All span/MDC calls are best-effort and MUST NOT surface any exception to + * the caller: without an OpenTelemetry SDK on the classpath every call is a + * no-op, and MDC access can fail under unusual logging setups. + */ +internal class PoolTracer private constructor( + private val tracer: Tracer?, +) { + val enabled: Boolean + get() = tracer != null + + /** + * Starts the root span of one warmup trace, backdated to + * [submittedEpochNanos] (epoch wall-clock, see + * [WarmupTrace.endSuccess]) so the queue-wait time is part of the trace. + * Returns null when tracing is disabled; the caller then runs without + * spans. + */ + fun startWarmupRoot( + poolName: String, + ownerId: String, + runGeneration: Long, + submittedEpochNanos: Long, + ): WarmupTrace? { + val t = tracer ?: return null + val root = + t.spanBuilder(WARMUP_ROOT_SPAN) + .setAttribute(ATTR_POOL_NAME, poolName) + .setAttribute(ATTR_POOL_OWNER, ownerId) + .setAttribute(ATTR_POOL_RUN_GENERATION, runGeneration) + .setStartTimestamp(submittedEpochNanos, TimeUnit.NANOSECONDS) + .startSpan() + return WarmupTrace(root) + } + + /** + * Runs [block] under a child span of the currently-current span (the + * warmup root). No-op span when tracing is disabled. + */ + internal inline fun withPhaseSpan( + spanName: String, + crossinline block: () -> T, + ): T { + val t = tracer ?: return block() + val span = t.spanBuilder(spanName).startSpan() + val scope = span.makeCurrent() + return try { + block() + } finally { + safeClose(scope) + span.end() + } + } + + companion object { + const val WARMUP_ROOT_SPAN = "pool.warmup" + const val WARMUP_CREATE_SPAN = "pool.warmup.create" + const val WARMUP_PREPARE_SPAN = "pool.warmup.prepare" + const val WARMUP_RENEW_SPAN = "pool.warmup.renew" + const val WARMUP_COMMIT_SPAN = "pool.warmup.commit" + + const val MDC_TRACE_ID = "trace_id" + const val MDC_SPAN_ID = "span_id" + + const val ATTR_POOL_NAME = "pool.name" + const val ATTR_POOL_OWNER = "pool.owner" + const val ATTR_POOL_RUN_GENERATION = "pool.run.generation" + const val ATTR_SANDBOX_ID = "sandbox.id" + const val ATTR_SANDBOX_IMAGE = "sandbox.image" + const val ATTR_RESULT = "result" + const val ATTR_DROP_REASON = "drop.reason" + + private const val INSTRUMENTATION_NAME = "com.alibaba.opensandbox.sandbox" + + fun from(connectionConfig: ConnectionConfig): PoolTracer { + if (!connectionConfig.enableTracing) return PoolTracer(null) + return PoolTracer( + GlobalOpenTelemetry.get().tracerBuilder(INSTRUMENTATION_NAME).build(), + ) + } + } +} + +/** + * One in-flight warmup trace: the root [Span] plus the ability to run work in + * its context (with `trace_id` / `span_id` published to MDC) and to end the + * trace with outcome attributes. + */ +internal class WarmupTrace internal constructor( + private val root: Span, +) { + val traceId: String + get() = root.spanContext.traceId + + val spanId: String + get() = root.spanContext.spanId + + /** + * Runs [block] with this trace's root span current (child spans + * auto-parent to it) and `trace_id`/`span_id` in the SLF4J MDC for the + * duration of [block]. The previous thread-local MDC values are restored + * afterwards. Never throws. + */ + fun withCurrent(block: () -> T): T { + val prevTrace = safeMdcGet(PoolTracer.MDC_TRACE_ID) + val prevSpan = safeMdcGet(PoolTracer.MDC_SPAN_ID) + safeMdcPut(PoolTracer.MDC_TRACE_ID, traceId) + safeMdcPut(PoolTracer.MDC_SPAN_ID, spanId) + val scope = root.makeCurrent() + return try { + block() + } finally { + safeClose(scope) + safeMdcRestore(PoolTracer.MDC_TRACE_ID, prevTrace) + safeMdcRestore(PoolTracer.MDC_SPAN_ID, prevSpan) + } + } + + /** Ends the trace as successful, recording sandbox identity for drill-down. */ + fun endSuccess( + sandboxId: String, + image: String?, + ) { + root.setAttribute(PoolTracer.ATTR_SANDBOX_ID, sandboxId) + if (!image.isNullOrBlank()) { + root.setAttribute(PoolTracer.ATTR_SANDBOX_IMAGE, image) + } + root.setAttribute(PoolTracer.ATTR_RESULT, RESULT_SUCCESS) + root.end() + } + + /** Ends the trace as failed, recording the failure. */ + fun endFailure(error: Throwable) { + root.recordException(error) + root.setAttribute(PoolTracer.ATTR_RESULT, RESULT_FAILURE) + root.end() + } + + /** + * Ends the trace as failed because the warmup outcome could not be + * committed (stale run, primary lock lost, or putIdle failure) — the + * sandbox never entered the idle pool and is scheduled for cleanup. + * [source] matches the pool's cleanup-source values, e.g. + * `warmup-lock-lost`. + */ + fun endDropped(source: String) { + root.setAttribute(PoolTracer.ATTR_RESULT, RESULT_FAILURE) + root.setAttribute(PoolTracer.ATTR_DROP_REASON, source) + root.end() + } + + private companion object { + const val RESULT_SUCCESS = "success" + const val RESULT_FAILURE = "failure" + } +} + +private fun safeMdcGet(key: String): String? = + try { + MDC.get(key) + } catch (_: Throwable) { + null + } + +private fun safeMdcPut( + key: String, + value: String, +) { + try { + MDC.put(key, value) + } catch (_: Throwable) { + // best-effort + } +} + +private fun safeMdcRestore( + key: String, + previous: String?, +) { + try { + if (previous == null) { + MDC.remove(key) + } else { + MDC.put(key, previous) + } + } catch (_: Throwable) { + // best-effort + } +} + +private fun safeClose(scope: io.opentelemetry.context.Scope) { + try { + scope.close() + } catch (_: Throwable) { + // best-effort + } +} diff --git a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/pool/SandboxPool.kt b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/pool/SandboxPool.kt index dcbd7a38c..565dc45e8 100644 --- a/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/pool/SandboxPool.kt +++ b/sdks/sandbox/kotlin/sandbox/src/main/kotlin/com/alibaba/opensandbox/sandbox/pool/SandboxPool.kt @@ -38,6 +38,8 @@ import com.alibaba.opensandbox.sandbox.domain.pool.PooledSandboxCreator import com.alibaba.opensandbox.sandbox.domain.pool.SandboxPreparer import com.alibaba.opensandbox.sandbox.infrastructure.pool.PoolReconciler import com.alibaba.opensandbox.sandbox.infrastructure.pool.ReconcileState +import com.alibaba.opensandbox.sandbox.internal.PoolTracer +import com.alibaba.opensandbox.sandbox.internal.WarmupTrace import com.alibaba.opensandbox.sandbox.internal.isCausedByInterruption import org.slf4j.LoggerFactory import java.time.Duration @@ -113,6 +115,7 @@ class SandboxPool internal constructor( private val creationSpec: PoolCreationSpec = config.creationSpec private val sandboxCreator: PooledSandboxCreator? = config.sandboxCreator private val reconcileState = ReconcileState(config.degradedThreshold) + private val poolTracer = PoolTracer.from(config.connectionConfig) @Volatile private var currentMaxIdle: Int = config.maxIdle @@ -1006,7 +1009,7 @@ class SandboxPool internal constructor( ) { return } - val task = TrackedWarmupTask(run) + val task = TrackedWarmupTask(run, submittedEpochNanos()) try { run.warmupExecutor.execute(task) } catch (e: Exception) { @@ -1021,8 +1024,16 @@ class SandboxPool internal constructor( } } + /** + * Epoch-based submission timestamp (OpenTelemetry start timestamps are + * wall-clock, not monotonic). Used to backdate the warmup root span so the + * queue-wait window is part of the trace. + */ + private fun submittedEpochNanos(): Long = System.currentTimeMillis() * 1_000_000L + private inner class TrackedWarmupTask( private val run: RunContext, + private val submittedEpochNanos: Long, ) : Runnable { private val completed = AtomicBoolean(false) @@ -1032,21 +1043,45 @@ class SandboxPool internal constructor( } override fun run() { - val outcome = - try { - WarmupOutcome.Success(createOneSandbox()) - } catch (failure: Throwable) { - WarmupOutcome.Failure(failure) + // Backdate the root span to task submission so queue-wait time + // (submit -> run) is visible inside the trace. + val trace = + poolTracer.startWarmupRoot( + poolName = config.poolName, + ownerId = config.ownerId, + runGeneration = run.generation, + submittedEpochNanos = submittedEpochNanos, + ) + val outcome: WarmupOutcome + if (trace == null) { + outcome = captureOutcome() + } else { + outcome = trace.withCurrent { captureOutcome() } + if (outcome is WarmupOutcome.Failure) { + trace.endFailure(outcome.error) } - dispatchCompletion(outcome) + } + // Keep the trace open on success: the commit phase (scheduler + // thread) ends it after the sandbox is put idle. + dispatchCompletion(outcome, if (outcome is WarmupOutcome.Success) trace else null) } + private fun captureOutcome(): WarmupOutcome = + try { + WarmupOutcome.Success(createOneSandbox()) + } catch (failure: Throwable) { + WarmupOutcome.Failure(failure) + } + fun completeIfDropped() { - complete(WarmupOutcome.Cancelled) + complete(WarmupOutcome.Cancelled, null) } - private fun dispatchCompletion(outcome: WarmupOutcome) { - val completion = TrackedWarmupCompletionTask(run, this, outcome) + private fun dispatchCompletion( + outcome: WarmupOutcome, + trace: WarmupTrace?, + ) { + val completion = TrackedWarmupCompletionTask(run, this, outcome, trace) run.pendingWarmupCompletions.add(completion) try { run.scheduler.execute(completion) @@ -1060,10 +1095,13 @@ class SandboxPool internal constructor( } } - fun complete(outcome: WarmupOutcome) { + fun complete( + outcome: WarmupOutcome, + trace: WarmupTrace?, + ) { if (!completed.compareAndSet(false, true)) return try { - handleWarmupOutcome(run, outcome) + handleWarmupOutcome(run, outcome, trace) } finally { run.warmingCount.decrementAndGet() endOperation(run) @@ -1091,10 +1129,11 @@ class SandboxPool internal constructor( private val run: RunContext, private val warmupTask: TrackedWarmupTask, private val outcome: WarmupOutcome, + private val trace: WarmupTrace?, ) : Runnable { override fun run() { try { - warmupTask.complete(outcome) + warmupTask.complete(outcome, trace) } finally { run.pendingWarmupCompletions.remove(this) } @@ -1124,9 +1163,10 @@ class SandboxPool internal constructor( private fun handleWarmupOutcome( run: RunContext, outcome: WarmupOutcome, + trace: WarmupTrace?, ) { when (outcome) { - is WarmupOutcome.Success -> commitWarmupSandbox(run, outcome.sandboxId) + is WarmupOutcome.Success -> commitWarmupSandbox(run, outcome.sandboxId, trace) is WarmupOutcome.Failure -> { if (isCurrentRun(run) && lifecycleState.get() == LifecycleState.RUNNING) { reconcileState.recordAsyncFailure(outcome.error.message) @@ -1139,57 +1179,77 @@ class SandboxPool internal constructor( private fun commitWarmupSandbox( run: RunContext, sandboxId: String, + trace: WarmupTrace?, ) { var cleanupSource: String? = null - run.commitLock.lock() - try { - val state = lifecycleState.get() - if (!isCurrentRun(run) || (state != LifecycleState.RUNNING && state != LifecycleState.DRAINING)) { - cleanupSource = "warmup-stale-run" - } else { - try { - ensurePoolNamespaceActive() - if (!stateStore.renewPrimaryLock(config.poolName, config.ownerId, config.primaryLockTtl)) { - run.primaryOwned.set(false) + val commit: () -> Unit = { + run.commitLock.lock() + try { + val state = lifecycleState.get() + if (!isCurrentRun(run) || (state != LifecycleState.RUNNING && state != LifecycleState.DRAINING)) { + cleanupSource = "warmup-stale-run" + } else { + try { + ensurePoolNamespaceActive() + if (!stateStore.renewPrimaryLock(config.poolName, config.ownerId, config.primaryLockTtl)) { + run.primaryOwned.set(false) + logger.warn( + "Pool lost primary lock before putIdle; dropping warmup sandbox: " + + "pool_name={} sandbox_id={} run={}", + config.poolName, + sandboxId, + run.generation, + ) + cleanupSource = "warmup-lock-lost" + } else { + stateStore.putIdle(config.poolName, sandboxId) + reconcileState.recordSuccess() + logger.debug( + "Pool warmup sandbox entered idle: pool_name={} sandbox_id={} run={}", + config.poolName, + sandboxId, + run.generation, + ) + } + } catch (e: Exception) { + if (isCurrentRun(run) && lifecycleState.get() == LifecycleState.RUNNING) { + reconcileState.recordAsyncFailure(e.message) + } + try { + stateStore.removeIdle(config.poolName, sandboxId) + } catch (_: Exception) { + // best-effort remove before remote cleanup + } + cleanupSource = "warmup-commit-failed" logger.warn( - "Pool lost primary lock before putIdle; dropping warmup sandbox: " + - "pool_name={} sandbox_id={} run={}", - config.poolName, - sandboxId, - run.generation, - ) - cleanupSource = "warmup-lock-lost" - } else { - stateStore.putIdle(config.poolName, sandboxId) - reconcileState.recordSuccess() - logger.debug( - "Pool warmup sandbox entered idle: pool_name={} sandbox_id={} run={}", + "Pool warmup commit failed; dropped sandbox: pool_name={} sandbox_id={} run={} error={}", config.poolName, sandboxId, run.generation, + e.message, ) } - } catch (e: Exception) { - if (isCurrentRun(run) && lifecycleState.get() == LifecycleState.RUNNING) { - reconcileState.recordAsyncFailure(e.message) - } - try { - stateStore.removeIdle(config.poolName, sandboxId) - } catch (_: Exception) { - // best-effort remove before remote cleanup - } - cleanupSource = "warmup-commit-failed" - logger.warn( - "Pool warmup commit failed; dropped sandbox: pool_name={} sandbox_id={} run={} error={}", - config.poolName, - sandboxId, - run.generation, - e.message, - ) } + } finally { + run.commitLock.unlock() + } + } + if (trace == null) { + commit() + } else { + // Runs on the scheduler thread; re-attach the warmup trace's + // context (and MDC trace_id/span_id) so the commit span and its + // log lines belong to the same trace as the create phases. + trace.withCurrent { + poolTracer.withPhaseSpan(PoolTracer.WARMUP_COMMIT_SPAN) { commit() } + } + if (cleanupSource != null) { + // The sandbox never entered the idle pool (stale run, lock + // lost, or commit failure); do not report a success. + trace.endDropped(cleanupSource) + } else { + trace.endSuccess(sandboxId, creationSpec.imageSpec.image) } - } finally { - run.commitLock.unlock() } cleanupSource?.let { source -> scheduleKillDiscardedAlive( @@ -1209,17 +1269,23 @@ class SandboxPool internal constructor( */ private fun createOneSandbox(): String { return try { - val sandbox = buildWarmupSandbox() + // Phase spans auto-parent to the warmup root via the trace context + // made current by the warmup task; they no-op when tracing is off. + val sandbox = poolTracer.withPhaseSpan(PoolTracer.WARMUP_CREATE_SPAN) { buildWarmupSandbox() } var failure: Throwable? = null try { - config.warmupSandboxPreparer?.prepare(sandbox) + poolTracer.withPhaseSpan(PoolTracer.WARMUP_PREPARE_SPAN) { + config.warmupSandboxPreparer?.prepare(sandbox) + } // The server-side TTL has been ticking since sandbox creation; readiness // wait and `warmupSandboxPreparer` can both consume meaningful time (think // initialization scripts). Renew right before handing the id back to the // reconciler so the store's stamped expiry (now + idleTimeout) actually matches // what the server will honor — otherwise `acquireMinRemainingTtl` overestimates // remaining TTL by the warmup duration. - sandbox.renew(config.idleTimeout) + poolTracer.withPhaseSpan(PoolTracer.WARMUP_RENEW_SPAN) { + sandbox.renew(config.idleTimeout) + } sandbox.id } catch (t: Throwable) { failure = t diff --git a/sdks/sandbox/kotlin/sandbox/src/test/kotlin/com/alibaba/opensandbox/sandbox/pool/PoolWarmupTracingTest.kt b/sdks/sandbox/kotlin/sandbox/src/test/kotlin/com/alibaba/opensandbox/sandbox/pool/PoolWarmupTracingTest.kt new file mode 100644 index 000000000..a239486bd --- /dev/null +++ b/sdks/sandbox/kotlin/sandbox/src/test/kotlin/com/alibaba/opensandbox/sandbox/pool/PoolWarmupTracingTest.kt @@ -0,0 +1,385 @@ +/* + * Copyright 2026 Alibaba Group Holding Ltd. + * + * Licensed under the Apache License, Version 2.0 (the "License"); + * you may not use this file except in compliance with the License. + * You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * Unless required by applicable law or agreed to in writing, software + * distributed under the License is distributed on an "AS IS" BASIS, + * WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + * See the License for the specific language governing permissions and + * limitations under the License. + */ + +package com.alibaba.opensandbox.sandbox.pool + +import com.alibaba.opensandbox.sandbox.HttpClientProvider +import com.alibaba.opensandbox.sandbox.Sandbox +import com.alibaba.opensandbox.sandbox.config.ConnectionConfig +import com.alibaba.opensandbox.sandbox.domain.pool.PoolCreationSpec +import com.alibaba.opensandbox.sandbox.domain.pool.PooledSandboxCreator +import com.alibaba.opensandbox.sandbox.domain.pool.SandboxPreparer +import com.alibaba.opensandbox.sandbox.infrastructure.pool.InMemoryPoolStateStore +import com.alibaba.opensandbox.sandbox.internal.PoolTracer +import io.mockk.every +import io.mockk.mockk +import io.opentelemetry.api.GlobalOpenTelemetry +import io.opentelemetry.api.common.AttributeKey +import io.opentelemetry.api.trace.propagation.W3CTraceContextPropagator +import io.opentelemetry.context.propagation.ContextPropagators +import io.opentelemetry.sdk.OpenTelemetrySdk +import io.opentelemetry.sdk.testing.exporter.InMemorySpanExporter +import io.opentelemetry.sdk.trace.SdkTracerProvider +import io.opentelemetry.sdk.trace.export.SimpleSpanProcessor +import okhttp3.Request +import okhttp3.mockwebserver.MockResponse +import okhttp3.mockwebserver.MockWebServer +import org.junit.jupiter.api.AfterEach +import org.junit.jupiter.api.Assertions.assertEquals +import org.junit.jupiter.api.Assertions.assertNotNull +import org.junit.jupiter.api.Assertions.assertNull +import org.junit.jupiter.api.Assertions.assertTrue +import org.junit.jupiter.api.Test +import org.slf4j.MDC +import java.time.Duration +import java.util.concurrent.TimeUnit +import java.util.concurrent.atomic.AtomicReference + +class PoolWarmupTracingTest { + private var exporter: InMemorySpanExporter? = null + private var openTelemetry: OpenTelemetrySdk? = null + + @AfterEach + fun tearDown() { + openTelemetry?.close() + openTelemetry = null + exporter = null + GlobalOpenTelemetry.resetForTest() + } + + private fun installSdkTracerProvider(): InMemorySpanExporter { + val spanExporter = InMemorySpanExporter.create() + val sdkTracerProvider = + SdkTracerProvider.builder() + .addSpanProcessor(SimpleSpanProcessor.create(spanExporter)) + .build() + val otel = + OpenTelemetrySdk.builder() + .setTracerProvider(sdkTracerProvider) + // Default propagators are noop; set W3C so traceparent injection + // (HttpClientProvider) can be asserted. + .setPropagators(ContextPropagators.create(W3CTraceContextPropagator.getInstance())) + .build() + GlobalOpenTelemetry.set(otel) + exporter = spanExporter + openTelemetry = otel + return spanExporter + } + + @Test + fun `warmup emits a full span tree with drill-down attributes when tracing enabled`() { + val spanExporter = installSdkTracerProvider() + val capturedTraceId = AtomicReference() + val capturedSpanId = AtomicReference() + + val store = InMemoryPoolStateStore() + val pool = + SandboxPool.builder() + .poolName("trace-pool") + .ownerId("trace-owner") + .maxIdle(1) + .warmupConcurrency(1) + .stateStore(store) + .connectionConfig(ConnectionConfig.builder().enableTracing().build()) + .creationSpec(PoolCreationSpec.builder().image("ubuntu:22.04").build()) + .sandboxCreator( + PooledSandboxCreator { + mockk(relaxed = true).also { sandbox -> + every { sandbox.id } returns "warmup-trace-1" + } + }, + ).warmupSkipHealthCheck() + .warmupSandboxPreparer( + SandboxPreparer { + capturedTraceId.set(MDC.get(PoolTracer.MDC_TRACE_ID)) + capturedSpanId.set(MDC.get(PoolTracer.MDC_SPAN_ID)) + }, + ).reconcileInterval(Duration.ofSeconds(30)) + .drainTimeout(Duration.ofSeconds(2)) + .build() + + pool.start() + try { + awaitCondition { store.snapshotCounters("trace-pool").idleCount == 1 } + val spans = spanExporter.finishedSpanItems + val root = spans.single { it.name == PoolTracer.WARMUP_ROOT_SPAN } + assertEquals("trace-pool", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_POOL_NAME)]) + assertEquals("trace-owner", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_POOL_OWNER)]) + assertEquals(1L, root.attributes[AttributeKey.longKey(PoolTracer.ATTR_POOL_RUN_GENERATION)]) + assertEquals("warmup-trace-1", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_SANDBOX_ID)]) + assertEquals("ubuntu:22.04", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_SANDBOX_IMAGE)]) + assertEquals("success", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_RESULT)]) + + // MDC must expose the same trace while warmup code runs. + assertEquals(root.traceId, capturedTraceId.get()) + assertEquals(root.spanId, capturedSpanId.get()) + + val names = spans.map { it.name }.toSet() + assertTrue(names.contains(PoolTracer.WARMUP_CREATE_SPAN)) + assertTrue(names.contains(PoolTracer.WARMUP_PREPARE_SPAN)) + assertTrue(names.contains(PoolTracer.WARMUP_RENEW_SPAN)) + assertTrue(names.contains(PoolTracer.WARMUP_COMMIT_SPAN)) + + // All spans share one trace; phase spans are sequential siblings + // under the root (each phase duration stands alone for drill-down), + // and commit re-attaches to the root on the scheduler thread. + spans.forEach { span -> + assertEquals(root.traceId, span.traceId, "all spans must share the warmup trace id") + } + val create = spans.single { it.name == PoolTracer.WARMUP_CREATE_SPAN } + val prepare = spans.single { it.name == PoolTracer.WARMUP_PREPARE_SPAN } + val renew = spans.single { it.name == PoolTracer.WARMUP_RENEW_SPAN } + val commit = spans.single { it.name == PoolTracer.WARMUP_COMMIT_SPAN } + assertEquals(root.spanId, create.parentSpanId) + assertEquals(root.spanId, prepare.parentSpanId) + assertEquals(root.spanId, renew.parentSpanId) + assertEquals(root.spanId, commit.parentSpanId) + + // Root span is backdated to submission, so the trace covers the + // queue wait before the create phase. + assertTrue(root.startEpochNanos <= create.startEpochNanos) + // Root start must be epoch wall-clock (not monotonic nanoTime): + // within a minute of test start, and not some arbitrary boot-relative value. + val testStartEpochNanos = System.currentTimeMillis() * 1_000_000L + assertTrue( + root.startEpochNanos <= testStartEpochNanos, + "root start must be in the past relative to test start", + ) + assertTrue( + root.startEpochNanos >= testStartEpochNanos - Duration.ofMinutes(1).toNanos(), + "root start must be epoch wall-clock near test start", + ) + } finally { + pool.shutdown(graceful = false) + } + } + + @Test + fun `failed warmup emits a failure root span without a commit span`() { + val spanExporter = installSdkTracerProvider() + val store = InMemoryPoolStateStore() + val pool = + SandboxPool.builder() + .poolName("trace-fail-pool") + .ownerId("trace-fail-owner") + .maxIdle(1) + .warmupConcurrency(1) + .stateStore(store) + .connectionConfig(ConnectionConfig.builder().enableTracing().build()) + .creationSpec(PoolCreationSpec.builder().image("ubuntu:22.04").build()) + .sandboxCreator( + PooledSandboxCreator { + throw RuntimeException("create boom") + }, + ).warmupSkipHealthCheck() + .reconcileInterval(Duration.ofSeconds(30)) + .drainTimeout(Duration.ofMillis(200)) + .build() + + pool.start() + try { + awaitCondition { pool.snapshot().failureCount >= 1 } + val spans = spanExporter.finishedSpanItems + val root = spans.single { it.name == PoolTracer.WARMUP_ROOT_SPAN } + assertEquals("failure", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_RESULT)]) + assertEquals( + 1, + root.events.count { it.name == "exception" }, + "failure must be recorded on the root span", + ) + assertTrue(spans.none { it.name == PoolTracer.WARMUP_COMMIT_SPAN }) + } finally { + pool.shutdown(graceful = false) + } + } + + @Test + fun `dropped warmup commit is traced as a failure`() { + val spanExporter = installSdkTracerProvider() + val store = LockLossOnCommitPoolStateStore() + val pool = + SandboxPool.builder() + .poolName("trace-drop-pool") + .ownerId("trace-drop-owner") + .maxIdle(1) + .warmupConcurrency(1) + .stateStore(store) + .connectionConfig(ConnectionConfig.builder().enableTracing().build()) + .creationSpec(PoolCreationSpec.builder().image("ubuntu:22.04").build()) + .sandboxCreator( + PooledSandboxCreator { + mockk(relaxed = true).also { sandbox -> + every { sandbox.id } returns "warmup-dropped-1" + } + }, + ).warmupSkipHealthCheck() + .warmupSandboxPreparer( + SandboxPreparer { + store.failRenewPrimaryLock = true + }, + ).reconcileInterval(Duration.ofSeconds(30)) + .drainTimeout(Duration.ofSeconds(2)) + .build() + + pool.start() + try { + awaitCondition { spanExporter.finishedSpanItems.any { it.name == PoolTracer.WARMUP_ROOT_SPAN } } + val spans = spanExporter.finishedSpanItems + val root = spans.single { it.name == PoolTracer.WARMUP_ROOT_SPAN } + assertEquals("failure", root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_RESULT)]) + assertEquals( + "warmup-lock-lost", + root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_DROP_REASON)], + ) + assertNull(root.attributes[AttributeKey.stringKey(PoolTracer.ATTR_SANDBOX_ID)]) + assertTrue( + spans.any { it.name == PoolTracer.WARMUP_COMMIT_SPAN }, + "commit phase must still be traced", + ) + } finally { + pool.shutdown(graceful = false) + } + } + + @Test + fun `warmup emits no spans when tracing is disabled`() { + val spanExporter = installSdkTracerProvider() + val store = InMemoryPoolStateStore() + val pool = + SandboxPool.builder() + .poolName("no-trace-pool") + .ownerId("no-trace-owner") + .maxIdle(1) + .warmupConcurrency(1) + .stateStore(store) + .connectionConfig(ConnectionConfig.builder().build()) + .creationSpec(PoolCreationSpec.builder().image("ubuntu:22.04").build()) + .sandboxCreator( + PooledSandboxCreator { + mockk(relaxed = true).also { sandbox -> + every { sandbox.id } returns "no-trace-1" + } + }, + ).warmupSkipHealthCheck() + .reconcileInterval(Duration.ofSeconds(30)) + .drainTimeout(Duration.ofSeconds(2)) + .build() + + pool.start() + try { + awaitCondition { store.snapshotCounters("no-trace-pool").idleCount == 1 } + assertTrue( + spanExporter.finishedSpanItems.isEmpty(), + "no spans may be emitted when enableTracing is false", + ) + } finally { + pool.shutdown(graceful = false) + } + } + + @Test + fun `requests inject traceparent only when tracing is enabled and a span is current`() { + val spanExporter = installSdkTracerProvider() + val server = MockWebServer() + try { + server.enqueue(MockResponse().setResponseCode(204)) + server.enqueue(MockResponse().setResponseCode(204)) + server.enqueue(MockResponse().setResponseCode(204)) + val tracer = GlobalOpenTelemetry.get().tracerBuilder("test").build() + val span = tracer.spanBuilder("test-span").startSpan() + span.makeCurrent().use { + HttpClientProvider( + ConnectionConfig.builder() + .domain(server.url("/").toString().removeSuffix("/")) + .enableTracing() + .build(), + ).use { provider -> + provider.httpClient.newCall(Request.Builder().url(server.url("/tracing")).build()).execute() + .use { } + val recorded = server.takeRequest(1, TimeUnit.SECONDS)!! + val traceparent = recorded.getHeader("traceparent") + assertNotNull(traceparent, "traceparent must be injected for an active span") + assertTrue(traceparent!!.startsWith("00-"), "traceparent must be W3C v00 format") + assertTrue(traceparent.contains(span.spanContext.traceId), "traceparent must carry the trace id") + } + } + span.end() + + // No active span -> no injection, even with tracing enabled. + HttpClientProvider( + ConnectionConfig.builder() + .domain(server.url("/").toString().removeSuffix("/")) + .enableTracing() + .build(), + ).use { provider -> + provider.httpClient.newCall(Request.Builder().url(server.url("/no-span")).build()).execute().use { } + val recorded = server.takeRequest(1, TimeUnit.SECONDS)!! + assertNull(recorded.getHeader("traceparent")) + } + + // Tracing disabled -> no injection even with an active span. + val disabledSpan = tracer.spanBuilder("disabled-span").startSpan() + disabledSpan.makeCurrent().use { + HttpClientProvider( + ConnectionConfig.builder() + .domain(server.url("/").toString().removeSuffix("/")) + .build(), + ).use { provider -> + provider.httpClient.newCall(Request.Builder().url(server.url("/disabled")).build()).execute() + .use { } + val recorded = server.takeRequest(1, TimeUnit.SECONDS)!! + assertNull(recorded.getHeader("traceparent")) + } + } + disabledSpan.end() + assertTrue(spanExporter.finishedSpanItems.isNotEmpty()) + } finally { + server.shutdown() + } + } + + private fun awaitCondition( + timeout: Duration = Duration.ofSeconds(5), + condition: () -> Boolean, + ) { + val deadline = System.nanoTime() + timeout.toNanos() + while (System.nanoTime() < deadline) { + if (condition()) return + Thread.sleep(20) + } + throw AssertionError("condition not met within $timeout") + } + + /** + * In-memory store whose primary-lock renewal starts failing once a warmup + * preparer sets [failRenewPrimaryLock], so the commit path drops the + * warmed sandbox with `warmup-lock-lost`. + */ + private class LockLossOnCommitPoolStateStore( + private val delegate: InMemoryPoolStateStore = InMemoryPoolStateStore(), + ) : com.alibaba.opensandbox.sandbox.domain.pool.PoolStateStore by delegate { + @Volatile + var failRenewPrimaryLock: Boolean = false + + override fun renewPrimaryLock( + poolName: String, + ownerId: String, + ttl: Duration, + ): Boolean { + if (failRenewPrimaryLock) return false + return delegate.renewPrimaryLock(poolName, ownerId, ttl) + } + } +}