diff --git a/src/main/kotlin/com/dprint/formatter/DprintFormattingTask.kt b/src/main/kotlin/com/dprint/formatter/DprintFormattingTask.kt index 861e254..45b8db4 100644 --- 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,6 +38,7 @@ class DprintFormattingTask( ) { private var formattingIds = mutableListOf() 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. @@ -35,65 +46,135 @@ class DprintFormattingTask( private val allFormatFutures = mutableListOf>() 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? { 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() + 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() - 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 { diff --git a/src/main/kotlin/com/dprint/otel/AttributeKeys.kt b/src/main/kotlin/com/dprint/otel/AttributeKeys.kt new file mode 100644 index 0000000..4640965 --- /dev/null +++ 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 new file mode 100644 index 0000000..a2eee8e --- /dev/null +++ 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 index 246487e..24ddc66 100644 --- a/src/main/kotlin/com/dprint/services/editorservice/EditorServiceManager.kt +++ b/src/main/kotlin/com/dprint/services/editorservice/EditorServiceManager.kt @@ -3,6 +3,8 @@ package com.dprint.services.editorservice import com.dprint.config.ProjectConfiguration import com.dprint.i18n.DprintBundle import com.dprint.messages.DprintMessage +import com.dprint.otel.AttributeKeys +import com.dprint.otel.DprintScope import com.dprint.services.editorservice.v4.EditorServiceV4 import com.dprint.services.editorservice.v5.EditorServiceV5 import com.dprint.utils.errorLogWithConsole @@ -21,6 +23,14 @@ import com.intellij.openapi.diagnostic.logger import com.intellij.openapi.fileEditor.FileEditorManager import com.intellij.openapi.project.Project import com.intellij.openapi.vfs.VirtualFile +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.SpanKind +import io.opentelemetry.api.trace.StatusCode +import io.opentelemetry.api.trace.Tracer +import io.opentelemetry.context.Context import kotlinx.serialization.json.Json import kotlinx.serialization.json.int import kotlinx.serialization.json.jsonObject @@ -38,61 +48,129 @@ class EditorServiceManager(private val project: Project) { private var configPath: String? = null private val editorServiceTaskQueue = EditorServiceTaskQueue(project) private var canFormatCache = LRUMap() + private val tracer: Tracer = TelemetryManager.getInstance().getTracer(DprintScope.EditorServiceScope) private var hasAttemptedInitialisation = false private fun getSchemaVersion(configPath: String?): Int? { - val executablePath = getValidExecutablePath(project) - val timeout = project.service().state.initialisationTimeout - - val commandLine = - GeneralCommandLine( - executablePath, - "editor-info", + val span = + tracer.spanBuilder("dprint.get_schema_version") + .setSpanKind(SpanKind.CLIENT) + .setAttribute(AttributeKeys.CONFIG_PATH, configPath ?: "null") + .startSpan() + + return span.use { scope -> + val executablePath = getValidExecutablePath(project) + val timeout = project.service().state.initialisationTimeout + + span.setAttribute(AttributeKeys.TIMEOUT_MS, timeout) + + val commandLine = + GeneralCommandLine( + executablePath, + "editor-info", + ) + configPath?.let { + val workingDir = File(it).parent + span.setAttribute("working_dir", workingDir) + commandLine.withWorkDirectory(workingDir) + } + + span.addEvent( + "executing_command", + Attributes.of( + AttributeKey.stringKey("command"), + commandLine.commandLineString, + ), ) - configPath?.let { - val workingDir = File(it).parent - commandLine.withWorkDirectory(workingDir) - } - val result = ExecUtil.execAndGetOutput(commandLine, timeout.toInt()) + val cmdSpan = + tracer.spanBuilder("dprint.exec_editor_info") + .setParent(Context.current().with(span)) + .setSpanKind(SpanKind.CLIENT) + .startSpan() + + val result = + try { + val res = ExecUtil.execAndGetOutput(commandLine, timeout.toInt()) + cmdSpan.setAttribute("exit_code", res.exitCode.toLong()) + cmdSpan.setAttribute("stdout_length", res.stdout.length.toLong()) + cmdSpan.setAttribute("stderr_length", res.stderr.length.toLong()) + res + } catch (e: Exception) { + cmdSpan.recordException(e) + cmdSpan.setStatus(StatusCode.ERROR, "Command execution failed: ${e.message}") + throw e + } finally { + cmdSpan.end() + } - return try { val jsonText = result.stdout infoLogWithConsole(DprintBundle.message("config.dprint.editor.info", jsonText), project, LOGGER) - Json.parseToJsonElement(jsonText).jsonObject["schemaVersion"]?.jsonPrimitive?.int - } catch (e: RuntimeException) { - val stdout = result.stdout.trim() - val stderr = result.stderr.trim() - val message = - when { - stdout.isEmpty() && stderr.isNotEmpty() -> - DprintBundle.message( - "error.failed.to.parse.json.schema.error", - result.stderr.trim(), - ) - - stdout.isNotEmpty() && stderr.isEmpty() -> - DprintBundle.message( - "error.failed.to.parse.json.schema.received", - result.stdout.trim(), - ) - - stdout.isNotEmpty() && stderr.isNotEmpty() -> - DprintBundle.message( - "error.failed.to.parse.json.schema.received.error", - result.stdout.trim(), - result.stderr.trim(), - ) - - else -> DprintBundle.message("error.failed.to.parse.json.schema") - } - errorLogWithConsole( - message, - project, - LOGGER, - ) - throw e + try { + val parseSpan = + tracer.spanBuilder("dprint.parse_schema_json") + .setParent(Context.current().with(span)) + .startSpan() + + val schemaVersion = + try { + val version = + Json.parseToJsonElement( + jsonText, + ).jsonObject["schemaVersion"]?.jsonPrimitive?.int + parseSpan.setAttribute(AttributeKeys.SCHEMA_VERSION, version?.toLong() ?: -1) + version + } catch (e: Exception) { + parseSpan.recordException(e) + parseSpan.setStatus(StatusCode.ERROR, "JSON parsing failed: ${e.message}") + throw e + } finally { + parseSpan.end() + } + + span.setAttribute(AttributeKeys.SCHEMA_VERSION, schemaVersion?.toLong() ?: -1) + span.setStatus(StatusCode.OK) + schemaVersion + } catch (e: RuntimeException) { + val stdout = result.stdout.trim() + val stderr = result.stderr.trim() + val message = + when { + stdout.isEmpty() && stderr.isNotEmpty() -> + DprintBundle.message( + "error.failed.to.parse.json.schema.error", + result.stderr.trim(), + ) + + stdout.isNotEmpty() && stderr.isEmpty() -> + DprintBundle.message( + "error.failed.to.parse.json.schema.received", + result.stdout.trim(), + ) + + stdout.isNotEmpty() && stderr.isNotEmpty() -> + DprintBundle.message( + "error.failed.to.parse.json.schema.received.error", + result.stdout.trim(), + result.stderr.trim(), + ) + + else -> DprintBundle.message("error.failed.to.parse.json.schema") + } + + span.recordException(e) + span.setAttribute("stdout", stdout) + span.setAttribute("stderr", stderr) + span.setStatus(StatusCode.ERROR, message) + + errorLogWithConsole( + message, + project, + LOGGER, + ) + throw e + } } } @@ -119,34 +197,90 @@ class EditorServiceManager(private val project: Project) { * Primes the canFormat result cache for the passed in virtual file. */ fun primeCanFormatCacheForFile(virtualFile: VirtualFile) { - // Mainly used for project startup. The file opened listener runs before the ProjectStartUp listener - if (!hasAttemptedInitialisation) { - return + val span = + tracer.spanBuilder("dprint.prime_can_format_file") + .setAttribute(AttributeKeys.FILE_PATH, virtualFile.path) + .setAttribute("file_name", virtualFile.name) + .startSpan() + + try { + // Mainly used for project startup. The file opened listener runs before the ProjectStartUp listener + if (!hasAttemptedInitialisation) { + span.setAttribute("initialisation_attempted", false) + span.addEvent("skipping_not_initialized") + return + } + + span.setAttribute("initialisation_attempted", true) + primeCanFormatCache(virtualFile.path) + } finally { + span.end() } - primeCanFormatCache(virtualFile.path) } private fun primeCanFormatCache(path: String) { - val timeout = project.service().state.commandTimeout - editorServiceTaskQueue.createTaskWithTimeout( - TaskInfo(TaskType.PrimeCanFormat, path, null), - DprintBundle.message("editor.service.manager.priming.can.format.cache", path), - { - if (editorService == null) { - warnLogWithConsole(DprintBundle.message("editor.service.manager.not.initialised"), project, LOGGER) - } + val span = + tracer.spanBuilder("dprint.prime_can_format_cache") + .setAttribute(AttributeKeys.FILE_PATH, path) + .startSpan() + + try { + val timeout = project.service().state.commandTimeout + span.setAttribute(AttributeKeys.TIMEOUT_MS, timeout) + + editorServiceTaskQueue.createTaskWithTimeout( + TaskInfo(TaskType.PrimeCanFormat, path, null), + DprintBundle.message("editor.service.manager.priming.can.format.cache", path), + { + val taskSpan = + tracer.spanBuilder("dprint.execute_can_format") + .setParent(Context.current().with(span)) + .setSpanKind(SpanKind.CLIENT) + .setAttribute(AttributeKeys.FILE_PATH, path) + .startSpan() + + try { + if (editorService == null) { + taskSpan.setAttribute("editor_service_available", false) + taskSpan.addEvent("editor_service_not_initialized") + warnLogWithConsole( + DprintBundle.message("editor.service.manager.not.initialised"), + project, + LOGGER, + ) + } else { + taskSpan.setAttribute("editor_service_available", true) + } - editorService?.canFormat(path) { canFormat -> - if (canFormat == null) { - infoLogWithConsole("Unable to determine if $path can be formatted.", project, LOGGER) - } else { - canFormatCache[path] = canFormat - infoLogWithConsole("$path ${if (canFormat) "can" else "cannot"} be formatted", project, LOGGER) + editorService?.canFormat(path) { canFormat -> + if (canFormat == null) { + taskSpan.setAttribute("result_available", false) + taskSpan.addEvent("cannot_determine_format_capability") + infoLogWithConsole("Unable to determine if $path can be formatted.", project, LOGGER) + } else { + taskSpan.setAttribute("result_available", true) + taskSpan.setAttribute("can_format", canFormat) + canFormatCache[path] = canFormat + infoLogWithConsole( + "$path ${if (canFormat) "can" else "cannot"} be formatted", + project, + LOGGER, + ) + } + taskSpan.end() + } + } catch (e: Exception) { + taskSpan.recordException(e) + taskSpan.setStatus(StatusCode.ERROR, "Can format check failed: ${e.message}") + taskSpan.end() + throw e } - } - }, - timeout, - ) + }, + timeout, + ) + } finally { + span.end() + } } /** @@ -158,7 +292,51 @@ class EditorServiceManager(private val project: Project) { content: String, onFinished: (FormatResult) -> Unit, ) { - format(editorService?.maybeGetFormatId(), path, content, null, null, onFinished) + val span = + tracer.spanBuilder("dprint.format_file") + .setAttribute(AttributeKeys.FILE_PATH, path) + .setAttribute(AttributeKeys.CONTENT_LENGTH, content.length.toLong()) + .startSpan() + + try { + val formatId = editorService?.maybeGetFormatId() + span.setAttribute(AttributeKeys.FORMATTING_ID, formatId?.toLong() ?: -1) + span.setAttribute("full_file_format", true) + + // Create a wrapped callback that will record the result + val wrappedCallback: (FormatResult) -> Unit = { result -> + val resultSpan = + tracer.spanBuilder("dprint.format_callback") + .setParent(Context.current().with(span)) + .setAttribute(AttributeKeys.FILE_PATH, path) + .startSpan() + + try { + if (result.error != null) { + resultSpan.setAttribute("has_error", true) + resultSpan.setStatus(StatusCode.ERROR, result.error) + } else { + resultSpan.setAttribute("has_error", false) + resultSpan.setAttribute("content_changed", result.formattedContent != content) + if (result.formattedContent != null) { + resultSpan.setAttribute("result_length", result.formattedContent.length.toLong()) + } + } + + onFinished(result) + } catch (e: Exception) { + resultSpan.recordException(e) + resultSpan.setStatus(StatusCode.ERROR, "Callback execution failed: ${e.message}") + throw e + } finally { + resultSpan.end() + } + } + + format(formatId, path, content, null, null, wrappedCallback) + } finally { + span.end() + } } /** @@ -173,91 +351,294 @@ class EditorServiceManager(private val project: Project) { endIndex: Int?, onFinished: (FormatResult) -> Unit, ) { - val timeout = project.service().state.commandTimeout - editorServiceTaskQueue.createTaskWithTimeout( - TaskInfo(TaskType.Format, path, formatId), - DprintBundle.message("editor.service.manager.creating.formatting.task", path), - { - if (editorService == null) { - warnLogWithConsole(DprintBundle.message("editor.service.manager.not.initialised"), project, LOGGER) + val span = + tracer.spanBuilder("dprint.editor_service.format_range") + .setAttribute(AttributeKeys.FILE_PATH, path) + .setAttribute(AttributeKeys.CONTENT_LENGTH, content.length.toLong()) + .setAttribute(AttributeKeys.FORMATTING_ID, formatId?.toLong() ?: -1) + .startSpan() + + if (startIndex != null) { + span.setAttribute(AttributeKeys.RANGE_START, startIndex.toLong()) + } + + if (endIndex != null) { + span.setAttribute(AttributeKeys.RANGE_END, endIndex.toLong()) + } + + span.setAttribute("is_range_format", startIndex != null && endIndex != null) + + try { + val timeout = project.service().state.commandTimeout + span.setAttribute(AttributeKeys.TIMEOUT_MS, timeout) + + // Create a wrapped callback that will record the result + val wrappedCallback: (FormatResult) -> Unit = { result -> + val resultSpan = + tracer.spanBuilder("dprint.format_range_callback") + .setParent(Context.current().with(span)) + .setAttribute(AttributeKeys.FILE_PATH, path) + .startSpan() + + try { + if (result.error != null) { + resultSpan.setAttribute("has_error", true) + resultSpan.setStatus(StatusCode.ERROR, result.error) + } else { + resultSpan.setAttribute("has_error", false) + resultSpan.setAttribute("content_changed", result.formattedContent != content) + if (result.formattedContent != null) { + resultSpan.setAttribute("result_length", result.formattedContent.length.toLong()) + } + } + + onFinished(result) + } catch (e: Exception) { + resultSpan.recordException(e) + resultSpan.setStatus(StatusCode.ERROR, "Callback execution failed: ${e.message}") + throw e + } finally { + resultSpan.end() } - editorService?.fmt(formatId, path, content, startIndex, endIndex, onFinished) - }, - timeout, - { - onFinished(FormatResult()) - }, - ) + } + + editorServiceTaskQueue.createTaskWithTimeout( + TaskInfo(TaskType.Format, path, formatId), + DprintBundle.message("editor.service.manager.creating.formatting.task", path), + { + val taskSpan = + tracer.spanBuilder("dprint.execute_format") + .setParent(Context.current().with(span)) + .setSpanKind(SpanKind.CLIENT) + .setAttribute(AttributeKeys.FILE_PATH, path) + .startSpan() + + try { + if (editorService == null) { + taskSpan.setAttribute("editor_service_available", false) + taskSpan.addEvent("editor_service_not_initialized") + warnLogWithConsole( + DprintBundle.message("editor.service.manager.not.initialised"), + project, + LOGGER, + ) + taskSpan.end() + } else { + taskSpan.setAttribute("editor_service_available", true) + editorService?.fmt(formatId, path, content, startIndex, endIndex) { result -> + try { + if (result.error != null) { + taskSpan.setAttribute("has_error", true) + taskSpan.setStatus(StatusCode.ERROR, result.error) + } else { + taskSpan.setAttribute("has_error", false) + if (result.formattedContent != null) { + taskSpan.setAttribute( + "result_length", + result.formattedContent.length.toLong(), + ) + } + } + } finally { + taskSpan.end() + } + wrappedCallback(result) + } + } + } catch (e: Exception) { + taskSpan.recordException(e) + taskSpan.setStatus(StatusCode.ERROR, "Format execution failed: ${e.message}") + taskSpan.end() + throw e + } + }, + timeout, + { + wrappedCallback(FormatResult()) + }, + ) + } finally { + span.end() + } } private fun initialiseFreshEditorService(): Boolean { - hasAttemptedInitialisation = true - configPath = getValidConfigPath(project) - val schemaVersion = getSchemaVersion(configPath) - infoLogWithConsole( - DprintBundle.message( - "editor.service.manager.received.schema.version", - schemaVersion ?: "none", - ), - project, - LOGGER, - ) - when { - schemaVersion == null -> - project.messageBus.syncPublisher(DprintMessage.DPRINT_MESSAGE_TOPIC).info( - DprintBundle.message("config.dprint.schemaVersion.not.found"), - ) + val span = + tracer.spanBuilder("dprint.initialise_editor_service") + .setSpanKind(SpanKind.INTERNAL) + .startSpan() - schemaVersion < SCHEMA_V4 -> - project.messageBus.syncPublisher(DprintMessage.DPRINT_MESSAGE_TOPIC) - .info( - DprintBundle.message("config.dprint.schemaVersion.older"), - ) + try { + span.makeCurrent().use { scope -> + hasAttemptedInitialisation = true + span.setAttribute("has_attempted_initialisation", true) + + configPath = getValidConfigPath(project) + span.setAttribute(AttributeKeys.CONFIG_PATH, configPath ?: "null") + + val schemaVersion = getSchemaVersion(configPath) - schemaVersion == SCHEMA_V4 -> editorService = project.service() - schemaVersion == SCHEMA_V5 -> editorService = project.service() - schemaVersion > SCHEMA_V5 -> infoLogWithConsole( - DprintBundle.message("config.dprint.schemaVersion.newer"), + DprintBundle.message( + "editor.service.manager.received.schema.version", + schemaVersion ?: "none", + ), project, LOGGER, ) - } - if (editorService == null) { - return false - } + val createServiceSpan = + tracer.spanBuilder("dprint.create_editor_service") + .setAttribute("schema_version", schemaVersion?.toLong() ?: -1) + .startSpan() + + createServiceSpan.use { + when { + schemaVersion == null -> { + createServiceSpan.addEvent("schema_version_not_found") + project.messageBus.syncPublisher(DprintMessage.DPRINT_MESSAGE_TOPIC).info( + DprintBundle.message("config.dprint.schemaVersion.not.found"), + ) + } - editorService?.initialiseEditorService() - return true - } + schemaVersion < SCHEMA_V4 -> { + createServiceSpan.setAttribute("schema_version_supported", false) + createServiceSpan.addEvent("schema_version_too_old") + project.messageBus.syncPublisher(DprintMessage.DPRINT_MESSAGE_TOPIC) + .info( + DprintBundle.message("config.dprint.schemaVersion.older"), + ) + } - fun restartEditorService() { - if (!project.service().state.enabled) { - return - } + schemaVersion == SCHEMA_V4 -> { + createServiceSpan.setAttribute("schema_version_supported", true) + createServiceSpan.setAttribute("service_type", "v4") + editorService = project.service() + } - // Slightly larger incase the json schema step times out - val timeout = project.service().state.initialisationTimeout - editorServiceTaskQueue.createTaskWithTimeout( - TaskInfo(TaskType.Initialisation, null, null), - DprintBundle.message("editor.service.manager.initialising.editor.service"), - { - clearCanFormatCache() - val initialised = initialiseFreshEditorService() - if (initialised) { - for (virtualFile in FileEditorManager.getInstance(project).openFiles) { - if (isFormattableFile(project, virtualFile)) { - primeCanFormatCacheForFile(virtualFile) + schemaVersion == SCHEMA_V5 -> { + createServiceSpan.setAttribute("schema_version_supported", true) + createServiceSpan.setAttribute("service_type", "v5") + editorService = project.service() + } + + schemaVersion > SCHEMA_V5 -> { + createServiceSpan.setAttribute("schema_version_supported", false) + createServiceSpan.addEvent("schema_version_too_new") + infoLogWithConsole( + DprintBundle.message("config.dprint.schemaVersion.newer"), + project, + LOGGER, + ) } } + + createServiceSpan.setAttribute("editor_service_created", editorService != null) + } + + if (editorService == null) { + span.setAttribute("initialisation_success", false) + span.addEvent("editor_service_not_created") + return false } - }, - timeout, - { - this.notifyFailedToStart() - }, - ) + + val initSpan = + tracer.spanBuilder("dprint.initialise_service_instance") + .setSpanKind(SpanKind.CLIENT) + .startSpan() + + try { + editorService?.initialiseEditorService() + initSpan.setStatus(StatusCode.OK) + } catch (e: Exception) { + initSpan.recordException(e) + initSpan.setStatus(StatusCode.ERROR, "Service initialization failed: ${e.message}") + throw e + } finally { + initSpan.end() + } + + span.setAttribute("initialisation_success", true) + return true + } + } catch (e: Exception) { + span.recordException(e) + span.setStatus(StatusCode.ERROR) + throw e + } finally { + span.end() + } + } + + fun restartEditorService() { + val span = + tracer.spanBuilder("dprint.restart_editor_service") + .startSpan() + + try { + if (!project.service().state.enabled) { + span.setAttribute("plugin_enabled", false) + span.addEvent("skipping_restart_disabled_plugin") + return + } + + span.setAttribute("plugin_enabled", true) + + // Slightly larger incase the json schema step times out + val timeout = project.service().state.initialisationTimeout + span.setAttribute(AttributeKeys.TIMEOUT_MS, timeout) + + editorServiceTaskQueue.createTaskWithTimeout( + TaskInfo(TaskType.Initialisation, null, null), + DprintBundle.message("editor.service.manager.initialising.editor.service"), + { + val taskSpan = + tracer.spanBuilder("dprint.execute_restart") + .setParent(Context.current().with(span)) + .startSpan() + + taskSpan.use { + clearCanFormatCache() + val initialised = initialiseFreshEditorService() + taskSpan.setAttribute("initialisation_success", initialised) + + if (initialised) { + val primeSpan = + tracer.spanBuilder("dprint.prime_cache_for_open_files") + .startSpan() + + primeSpan.use { + val openFiles = FileEditorManager.getInstance(project).openFiles + primeSpan.setAttribute("open_files_count", openFiles.size.toLong()) + + var formattableFilesCount = 0 + for (virtualFile in openFiles) { + if (isFormattableFile(project, virtualFile)) { + formattableFilesCount++ + primeCanFormatCacheForFile(virtualFile) + } + } + primeSpan.setAttribute("formattable_files_count", formattableFilesCount.toLong()) + } + } + + taskSpan.setStatus(StatusCode.OK) + } + }, + timeout, + { + this.notifyFailedToStart() + }, + ) + + span.setStatus(StatusCode.OK) + } catch (e: Exception) { + span.recordException(e) + span.setStatus(StatusCode.ERROR) + throw e + } finally { + span.end() + } } private fun notifyFailedToStart() { @@ -277,7 +658,26 @@ class EditorServiceManager(private val project: Project) { } fun destroyEditorService() { - editorService?.destroyEditorService() + val span = + tracer.spanBuilder("dprint.destroy_editor_service") + .startSpan() + + try { + span.setAttribute("editor_service_available", editorService != null) + + if (editorService != null) { + span.addEvent("destroying_editor_service") + editorService?.destroyEditorService() + } else { + span.addEvent("no_editor_service_to_destroy") + } + } catch (e: Exception) { + span.recordException(e) + span.setStatus(StatusCode.ERROR, "Failed to destroy editor service: ${e.message}") + throw e + } finally { + span.end() + } } fun getConfigPath(): String? { @@ -289,17 +689,57 @@ class EditorServiceManager(private val project: Project) { } fun maybeGetFormatId(): Int? { - return editorService?.maybeGetFormatId() + val span = + tracer.spanBuilder("dprint.get_format_id") + .setSpanKind(SpanKind.CLIENT) + .startSpan() + + span.use { + val formatId = editorService?.maybeGetFormatId() + span.setAttribute("editor_service_available", editorService != null) + if (formatId != null) { + span.setAttribute(AttributeKeys.FORMATTING_ID, formatId.toLong()) + } + return formatId + } } fun cancelFormat(formatId: Int) { - val timeout = project.service().state.commandTimeout - editorServiceTaskQueue.createTaskWithTimeout( - TaskInfo(TaskType.Cancel, null, formatId), - "Cancelling format $formatId", - { editorService?.cancelFormat(formatId) }, - timeout, - ) + val span = + tracer.spanBuilder("dprint.editor_service.cancel_format") + .setAttribute(AttributeKeys.FORMATTING_ID, formatId.toLong()) + .startSpan() + + span.use { + val timeout = project.service().state.commandTimeout + span.setAttribute(AttributeKeys.TIMEOUT_MS, timeout) + + editorServiceTaskQueue.createTaskWithTimeout( + TaskInfo(TaskType.Cancel, null, formatId), + "Cancelling format $formatId", + { + val taskSpan = + tracer.spanBuilder("dprint.execute_cancel_format") + .setParent(Context.current().with(span)) + .setSpanKind(SpanKind.CLIENT) + .setAttribute(AttributeKeys.FORMATTING_ID, formatId.toLong()) + .startSpan() + + try { + taskSpan.setAttribute("editor_service_available", editorService != null) + editorService?.cancelFormat(formatId) + taskSpan.setStatus(StatusCode.OK) + } catch (e: Exception) { + taskSpan.recordException(e) + taskSpan.setStatus(StatusCode.ERROR, "Cancel format failed: ${e.message}") + throw e + } finally { + taskSpan.end() + } + }, + timeout, + ) + } } fun canCancelFormat(): Boolean {