Add OpenTelemetry tracing to EditorServiceManager and formatter

davo-canva · davo-canva · commit 0d223cf3f1d9 · 2025-05-01T11:54:06.000+10:00
Extended EditorServiceManager and related classes with OpenTelemetry spans to track performance and debug issues effectively. Applied spans to key methods, such as service initialization, formatting, and cache priming, to capture execution details and errors comprehensively.
diff --git a/src/main/kotlin/com/dprint/formatter/DprintFormattingTask.kt b/src/main/kotlin/com/dprint/formatter/DprintFormattingTask.kt
@@ -1,6 +1,8 @@
 package com.dprint.formatter
 
 import com.dprint.i18n.DprintBundle
+import com.dprint.otel.AttributeKeys
+import com.dprint.otel.DprintScope
 import com.dprint.services.editorservice.EditorServiceManager
 import com.dprint.services.editorservice.FormatResult
 import com.dprint.services.editorservice.exceptions.ProcessUnavailableException
@@ -11,6 +13,14 @@ import com.intellij.formatting.service.AsyncFormattingRequest
 import com.intellij.openapi.diagnostic.logger
 import com.intellij.openapi.project.Project
 import com.intellij.openapi.util.TextRange
+import com.intellij.platform.diagnostic.telemetry.TelemetryManager
+import com.intellij.platform.diagnostic.telemetry.helpers.use
+import io.opentelemetry.api.common.AttributeKey
+import io.opentelemetry.api.common.Attributes
+import io.opentelemetry.api.trace.Span
+import io.opentelemetry.api.trace.StatusCode
+import io.opentelemetry.api.trace.Tracer
+import io.opentelemetry.context.Context
 import java.util.concurrent.CancellationException
 import java.util.concurrent.CompletableFuture
 import java.util.concurrent.ExecutionException
@@ -28,72 +38,143 @@ class DprintFormattingTask(
 ) {
     private var formattingIds = mutableListOf<Int>()
     private var isCancelled = false
+    private val tracer: Tracer = TelemetryManager.getInstance().getTracer(DprintScope.FormatterScope)
 
     /**
      * Used when we want to cancel a format, so that we can cancel every future in the chain.
      */
     private val allFormatFutures = mutableListOf<CompletableFuture<FormatResult>>()
 
     fun run() {
-        val content = formattingRequest.documentText
-        val ranges =
-            if (editorServiceManager.canRangeFormat()) {
-                formattingRequest.formattingRanges
-            } else {
-                mutableListOf(
-                    TextRange(0, content.length),
+        val rootSpan =
+            tracer.spanBuilder("dprint.format")
+                .setAttribute(AttributeKeys.FILE_PATH, path)
+                .startSpan()
+
+        try {
+            rootSpan.makeCurrent().use { scope ->
+                val content = formattingRequest.documentText
+
+                rootSpan.setAttribute(AttributeKeys.CONTENT_LENGTH, content.length.toLong())
+
+                val ranges =
+                    tracer.spanBuilder("dprint.determine_ranges")
+                        .startSpan().use { rangesSpan ->
+                            if (editorServiceManager.canRangeFormat()) {
+                                rangesSpan.setAttribute("range_format_supported", true)
+                                rangesSpan.setAttribute(
+                                    "ranges_count",
+                                    formattingRequest.formattingRanges.size.toLong(),
+                                )
+                                formattingRequest.formattingRanges
+                            } else {
+                                rangesSpan.setAttribute("range_format_supported", false)
+                                rangesSpan.setAttribute("ranges_count", 1L)
+                                mutableListOf(
+                                    TextRange(0, content.length),
+                                )
+                            }
+                        }
+
+                infoLogWithConsole(
+                    DprintBundle.message("external.formatter.running.task", path),
+                    project,
+                    LOGGER,
                 )
-            }
 
-        infoLogWithConsole(
-            DprintBundle.message("external.formatter.running.task", path),
-            project,
-            LOGGER,
-        )
+                val initialResult = FormatResult(formattedContent = content)
+                val baseFormatFuture = CompletableFuture.completedFuture(initialResult)
+                allFormatFutures.add(baseFormatFuture)
 
-        val initialResult = FormatResult(formattedContent = content)
-        val baseFormatFuture = CompletableFuture.completedFuture(initialResult)
-        allFormatFutures.add(baseFormatFuture)
-
-        var nextFuture = baseFormatFuture
-        for (range in ranges.subList(0, ranges.size)) {
-            nextFuture.thenCompose { formatResult ->
-                nextFuture =
-                    if (isCancelled) {
-                        // Revert to the initial contents
-                        CompletableFuture.completedFuture(initialResult)
-                    } else {
-                        applyNextRangeFormat(
-                            path,
-                            formatResult,
-                            getStartOfRange(formatResult.formattedContent, content, range),
-                            getEndOfRange(formatResult.formattedContent, content, range),
-                        )
+                val formatRangesSpan =
+                    tracer.spanBuilder("dprint.format_ranges")
+                        .setAttribute("ranges_count", ranges.size.toLong())
+                        .startSpan()
+
+                var nextFuture = baseFormatFuture
+                for (range in ranges.subList(0, ranges.size)) {
+                    formatRangesSpan.addEvent(
+                        "processing_range",
+                        Attributes.of(
+                            AttributeKeys.RANGE_START,
+                            range.startOffset.toLong(),
+                            AttributeKeys.RANGE_END,
+                            range.endOffset.toLong(),
+                        ),
+                    )
+
+                    nextFuture.thenCompose { formatResult ->
+                        nextFuture =
+                            if (isCancelled) {
+                                formatRangesSpan.addEvent(
+                                    "format_cancelled",
+                                    Attributes.of(
+                                        AttributeKeys.RANGE_START,
+                                        range.startOffset.toLong(),
+                                        AttributeKeys.RANGE_END,
+                                        range.endOffset.toLong(),
+                                    ),
+                                )
+                                // Revert to the initial contents
+                                CompletableFuture.completedFuture(initialResult)
+                            } else {
+                                applyNextRangeFormat(
+                                    path,
+                                    formatResult,
+                                    getStartOfRange(formatResult.formattedContent, content, range),
+                                    getEndOfRange(formatResult.formattedContent, content, range),
+                                    formatRangesSpan,
+                                )
+                            }
+                        nextFuture
                     }
-                nextFuture
-            }
-        }
+                }
 
-        // Timeouts are handled at the EditorServiceManager level and an empty result will be
-        // returned if something goes wrong
-        val result = getFuture(nextFuture)
+                // Timeouts are handled at the EditorServiceManager level and an empty result will be
+                // returned if something goes wrong
+                val result = getFuture(nextFuture)
+                formatRangesSpan.end()
 
-        // If cancelled there is no need to utilise the formattingRequest finalising methods
-        if (isCancelled) return
+                // If cancelled there is no need to utilise the formattingRequest finalising methods
+                if (isCancelled) {
+                    rootSpan.addEvent("formatting_cancelled")
+                    return
+                }
 
-        // If the result is null we don't want to change the document text, so we just set it to be the original.
-        // This should only happen if getting the future throws.
-        if (result == null) {
-            formattingRequest.onTextReady(content)
-            return
-        }
+                val resultSpan =
+                    tracer.spanBuilder("dprint.process_result")
+                        .startSpan()
+
+                resultSpan.use {
+                    // If the result is null we don't want to change the document text, so we just set it to be the original.
+                    // This should only happen if getting the future throws.
+                    if (result == null) {
+                        resultSpan.setAttribute("result", "null")
+                        formattingRequest.onTextReady(content)
+                        return
+                    }
+
+                    val error = result.error
+                    if (error != null) {
+                        resultSpan.setStatus(StatusCode.ERROR, error)
+                        formattingRequest.onError(DprintBundle.message("formatting.error"), error)
+                    } else {
+                        // Record if there was any content change
+                        resultSpan.setAttribute("content_changed", (result.formattedContent != content))
 
-        val error = result.error
-        if (error != null) {
-            formattingRequest.onError(DprintBundle.message("formatting.error"), error)
-        } else {
-            // If the result is a no op it will be null, in which case we pass the original content back in
-            formattingRequest.onTextReady(result.formattedContent ?: content)
+                        // If the result is a no op it will be null, in which case we pass the original content back in
+                        val finalContent = result.formattedContent ?: content
+                        resultSpan.setAttribute("final_content_length", finalContent.length.toLong())
+                        formattingRequest.onTextReady(finalContent)
+                    }
+                }
+            }
+        } catch (e: Exception) {
+            rootSpan.recordException(e)
+            rootSpan.setStatus(StatusCode.ERROR)
+            throw e
+        } finally {
+            rootSpan.end()
         }
     }
 
@@ -134,6 +215,7 @@ class DprintFormattingTask(
         previousFormatResult: FormatResult,
         startIndex: Int?,
         endIndex: Int?,
+        parentSpan: Span,
     ): CompletableFuture<FormatResult>? {
         val contentToFormat = previousFormatResult.formattedContent
         if (contentToFormat == null || startIndex == null || endIndex == null) {
@@ -150,15 +232,37 @@ class DprintFormattingTask(
             return null
         }
 
+        val span =
+            tracer.spanBuilder("dprint.formatter.apply_range_format")
+                .setParent(Context.current().with(parentSpan))
+                .setAttribute(AttributeKeys.FILE_PATH, path)
+                .setAttribute(AttributeKeys.RANGE_START, startIndex.toLong())
+                .setAttribute(AttributeKeys.RANGE_END, endIndex.toLong())
+                .setAttribute(AttributeKeys.CONTENT_LENGTH, contentToFormat.length.toLong())
+                .startSpan()
+
         // Need to update the formatting id so the correct job would be cancelled
         val formattingId = editorServiceManager.maybeGetFormatId()
         formattingId?.let {
             formattingIds.add(it)
+            span.setAttribute(AttributeKeys.FORMATTING_ID, it.toLong())
         }
 
         val nextFuture = CompletableFuture<FormatResult>()
         allFormatFutures.add(nextFuture)
         val nextHandler: (FormatResult) -> Unit = { nextResult ->
+            // Add result information to the span
+            if (nextResult.error != null) {
+                span.setStatus(StatusCode.ERROR, nextResult.error)
+            } else {
+                span.setStatus(StatusCode.OK)
+                if (nextResult.formattedContent != null) {
+                    val contentLengthDiff = nextResult.formattedContent.length - contentToFormat.length
+                    span.setAttribute("content_length_diff", contentLengthDiff.toLong())
+                }
+            }
+            span.end()
+
             nextFuture.complete(nextResult)
         }
         editorServiceManager.format(
@@ -174,21 +278,40 @@ class DprintFormattingTask(
     }
 
     fun cancel(): Boolean {
-        if (!editorServiceManager.canCancelFormat()) return false
+        val span =
+            tracer.spanBuilder("dprint.formatter.cancel_format")
+                .setAttribute(AttributeKeys.FILE_PATH, path)
+                .startSpan()
 
-        isCancelled = true
-        for (id in formattingIds) {
-            infoLogWithConsole(
-                DprintBundle.message("external.formatter.cancelling.task", id),
-                project,
-                LOGGER,
+        span.use { scope ->
+            if (!editorServiceManager.canCancelFormat()) {
+                span.setAttribute("can_cancel", false)
+                span.addEvent("cancel_not_supported")
+                return false
+            }
+
+            span.setAttribute("can_cancel", true)
+            span.setAttribute("formatting_ids_count", formattingIds.size.toLong())
+
+            isCancelled = true
+            for (id in formattingIds) {
+                span.addEvent("cancelling_task", Attributes.of(AttributeKeys.FORMATTING_ID, id.toLong()))
+                infoLogWithConsole(
+                    DprintBundle.message("external.formatter.cancelling.task", id),
+                    project,
+                    LOGGER,
+                )
+                editorServiceManager.cancelFormat(id)
+            }
+
+            // Clean up state so process can complete
+            span.addEvent(
+                "cancelling_futures",
+                Attributes.of(AttributeKey.longKey("futures_count"), allFormatFutures.size.toLong()),
             )
-            editorServiceManager.cancelFormat(id)
+            allFormatFutures.stream().forEach { f -> f.cancel(true) }
+            return true
         }
-
-        // Clean up state so process can complete
-        allFormatFutures.stream().forEach { f -> f.cancel(true) }
-        return true
     }
 
     fun isRunUnderProgress(): Boolean {
diff --git a/src/main/kotlin/com/dprint/otel/AttributeKeys.kt b/src/main/kotlin/com/dprint/otel/AttributeKeys.kt
@@ -0,0 +1,15 @@
+package com.dprint.otel
+
+import io.opentelemetry.api.common.AttributeKey
+
+/** OpenTelemetry attribute keys */
+object AttributeKeys {
+    val FILE_PATH = AttributeKey.stringKey("file.path")
+    val CONFIG_PATH = AttributeKey.stringKey("config.path")
+    val SCHEMA_VERSION = AttributeKey.longKey("schema.version")
+    val TIMEOUT_MS = AttributeKey.longKey("timeout.ms")
+    val RANGE_START = AttributeKey.longKey("range.start")
+    val RANGE_END = AttributeKey.longKey("range.end")
+    val FORMATTING_ID = AttributeKey.longKey("formatting.id")
+    val CONTENT_LENGTH = AttributeKey.longKey("content.length")
+}
diff --git a/src/main/kotlin/com/dprint/otel/DprintScope.kt b/src/main/kotlin/com/dprint/otel/DprintScope.kt
@@ -0,0 +1,8 @@
+package com.dprint.otel
+
+import com.intellij.platform.diagnostic.telemetry.Scope
+
+object DprintScope {
+    val FormatterScope = Scope("com.dprint.formatter")
+    val EditorServiceScope = Scope("com.dprint.editorservice")
+}
diff --git a/src/main/kotlin/com/dprint/services/editorservice/EditorServiceManager.kt b/src/main/kotlin/com/dprint/services/editorservice/EditorServiceManager.kt
