Add OpenTelemetry tracing to EditorServiceManager and formatting

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)
-
-        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 initialResult = FormatResult(formattedContent = content)
+                val baseFormatFuture = CompletableFuture.completedFuture(initialResult)
+                allFormatFutures.add(baseFormatFuture)
+
+                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,45 +232,89 @@ class DprintFormattingTask(
             return null
         }
 
-        // Need to update the formatting id so the correct job would be cancelled
-        val formattingId = editorServiceManager.maybeGetFormatId()
-        formattingId?.let {
-            formattingIds.add(it)
-        }
+        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()
+
+        // This span is ended in the callback, don't end it early.
+        return span.makeCurrent().use { scope ->
+            // 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()
 
-        val nextFuture = CompletableFuture<FormatResult>()
-        allFormatFutures.add(nextFuture)
-        val nextHandler: (FormatResult) -> Unit = { nextResult ->
-            nextFuture.complete(nextResult)
+                nextFuture.complete(nextResult)
+            }
+            editorServiceManager.format(
+                formattingId,
+                path,
+                contentToFormat,
+                startIndex,
+                endIndex,
+                nextHandler,
+            )
+
+            nextFuture
         }
-        editorServiceManager.format(
-            formattingId,
-            path,
-            contentToFormat,
-            startIndex,
-            endIndex,
-            nextHandler,
-        )
-
-        return nextFuture
     }
 
     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 {

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")
+}

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")
+}