From eaf66756489a0df4b1c7f5cb886a70570b22b14f Mon Sep 17 00:00:00 2001 From: Arata Nakafushiki <274594+raydive@users.noreply.github.com> Date: Tue, 20 Oct 2026 16:48:36 +0900 Subject: [PATCH] fix: start post_processor span before the factory call Work done inside PostProcessorFactory.apply(...) (e.g. building matching patterns from external data) was attributed only to the enclosing markdown.parse.post_process span. Start the markdown.parse.post_processor span before the factory call and set markdown.post_processor.class once the instance exists, so the per-processor breakdown is complete. Add opentelemetry-sdk-testing (test scope) and a test asserting that the factory is applied inside its span. Co-Authored-By: Claude Fable 5.1 --- flexmark-core-test/pom.xml | 5 + .../parser/PostProcessorManagerSpanTest.java | 118 ++++++++++++++++++ .../parser/internal/PostProcessorManager.java | 45 ++++--- pom.xml | 7 ++ 4 files changed, 156 insertions(+), 19 deletions(-) create mode 100644 flexmark-core-test/src/test/java/com/vladsch/flexmark/core/test/util/parser/PostProcessorManagerSpanTest.java diff --git a/flexmark-core-test/pom.xml b/flexmark-core-test/pom.xml index e609e1ab12..fff34091f0 100644 --- a/flexmark-core-test/pom.xml +++ b/flexmark-core-test/pom.xml @@ -38,5 +38,10 @@ jmh-generator-annprocess test + + io.opentelemetry + opentelemetry-sdk-testing + test + diff --git a/flexmark-core-test/src/test/java/com/vladsch/flexmark/core/test/util/parser/PostProcessorManagerSpanTest.java b/flexmark-core-test/src/test/java/com/vladsch/flexmark/core/test/util/parser/PostProcessorManagerSpanTest.java new file mode 100644 index 0000000000..96f05212a0 --- /dev/null +++ b/flexmark-core-test/src/test/java/com/vladsch/flexmark/core/test/util/parser/PostProcessorManagerSpanTest.java @@ -0,0 +1,118 @@ +package com.vladsch.flexmark.core.test.util.parser; + +import com.vladsch.flexmark.ast.Text; +import com.vladsch.flexmark.parser.Parser; +import com.vladsch.flexmark.parser.block.DocumentPostProcessor; +import com.vladsch.flexmark.parser.block.DocumentPostProcessorFactory; +import com.vladsch.flexmark.parser.block.NodePostProcessor; +import com.vladsch.flexmark.parser.block.NodePostProcessorFactory; +import com.vladsch.flexmark.util.ast.Document; +import com.vladsch.flexmark.util.ast.Node; +import com.vladsch.flexmark.util.ast.NodeTracker; +import io.opentelemetry.api.GlobalOpenTelemetry; +import io.opentelemetry.api.common.AttributeKey; +import io.opentelemetry.api.trace.Span; +import io.opentelemetry.sdk.testing.junit4.OpenTelemetryRule; +import io.opentelemetry.sdk.trace.data.SpanData; +import org.jetbrains.annotations.NotNull; +import org.junit.After; +import org.junit.Before; +import org.junit.Rule; +import org.junit.Test; + +import java.util.List; + +import static org.junit.Assert.assertEquals; +import static org.junit.Assert.assertNotNull; +import static org.junit.Assert.assertTrue; + +/** + * Verifies that the per-processor span wraps {@code PostProcessorFactory.apply(...)}, so time spent + * constructing a post processor is attributed to that processor's span. + */ +final public class PostProcessorManagerSpanTest { + private static final AttributeKey CLASS_ATTRIBUTE = AttributeKey.stringKey("markdown.post_processor.class"); + + @Rule + public final OpenTelemetryRule openTelemetry = OpenTelemetryRule.create(); + + @Before + public void installAsGlobal() { + // PostProcessorManager obtains its tracer from GlobalOpenTelemetry, which the rule does not register. + GlobalOpenTelemetry.resetForTest(); + GlobalOpenTelemetry.set(openTelemetry.getOpenTelemetry()); + } + + @After + public void resetGlobal() { + GlobalOpenTelemetry.resetForTest(); + } + + @Test + public void nodePostProcessorFactoryIsAppliedInsideItsSpan() { + RecordingNodePostProcessorFactory factory = new RecordingNodePostProcessorFactory(); + Parser.builder().postProcessorFactory(factory).build().parse("some text"); + + assertFactoryAppliedInsideSpan(factory.spanCurrentDuringApply, RecordingNodePostProcessor.class); + } + + @Test + public void documentPostProcessorFactoryIsAppliedInsideItsSpan() { + RecordingDocumentPostProcessorFactory factory = new RecordingDocumentPostProcessorFactory(); + Parser.builder().postProcessorFactory(factory).build().parse("some text"); + + assertFactoryAppliedInsideSpan(factory.spanCurrentDuringApply, RecordingDocumentPostProcessor.class); + } + + private void assertFactoryAppliedInsideSpan(Span spanCurrentDuringApply, Class expectedProcessorClass) { + assertNotNull("factory was not applied", spanCurrentDuringApply); + List spans = openTelemetry.getSpans(); + assertEquals(1, spans.size()); + SpanData span = spans.get(0); + assertEquals("markdown.parse.post_processor", span.getName()); + assertEquals("factory was applied outside the post_processor span", span.getSpanId(), spanCurrentDuringApply.getSpanContext().getSpanId()); + assertEquals(expectedProcessorClass.getName(), span.getAttributes().get(CLASS_ATTRIBUTE)); + assertTrue(span.hasEnded()); + } + + static class RecordingNodePostProcessorFactory extends NodePostProcessorFactory { + Span spanCurrentDuringApply; + + RecordingNodePostProcessorFactory() { + super(false); + addNodes(Text.class); + } + + @NotNull + @Override + public NodePostProcessor apply(@NotNull Document document) { + spanCurrentDuringApply = Span.current(); + return new RecordingNodePostProcessor(); + } + } + + static class RecordingNodePostProcessor extends NodePostProcessor { + @Override + public void process(@NotNull NodeTracker state, @NotNull Node node) { + } + } + + static class RecordingDocumentPostProcessorFactory extends DocumentPostProcessorFactory { + Span spanCurrentDuringApply; + + @NotNull + @Override + public DocumentPostProcessor apply(@NotNull Document document) { + spanCurrentDuringApply = Span.current(); + return new RecordingDocumentPostProcessor(); + } + } + + static class RecordingDocumentPostProcessor extends DocumentPostProcessor { + @NotNull + @Override + public Document processDocument(@NotNull Document document) { + return document; + } + } +} diff --git a/flexmark/src/main/java/com/vladsch/flexmark/parser/internal/PostProcessorManager.java b/flexmark/src/main/java/com/vladsch/flexmark/parser/internal/PostProcessorManager.java index 765fe3fdd8..2d1f36e3db 100644 --- a/flexmark/src/main/java/com/vladsch/flexmark/parser/internal/PostProcessorManager.java +++ b/flexmark/src/main/java/com/vladsch/flexmark/parser/internal/PostProcessorManager.java @@ -76,9 +76,10 @@ public Document postProcess(Document document) { boolean hadGlobal = false; for (PostProcessorFactory dependent : stage.dependents) { if (dependent.affectsGlobalScope()) { - PostProcessor postProcessor = dependent.apply(document); - Span span = startPostProcessorSpan(postProcessor); + Span span = startPostProcessorSpan(); try (Scope ignored = span.makeCurrent()) { + PostProcessor postProcessor = dependent.apply(document); + span.setAttribute(POST_PROCESSOR_CLASS_ATTRIBUTE, postProcessor.getClass().getName()); document = postProcessor.processDocument(document); } catch (Throwable t) { span.setStatus(StatusCode.ERROR, t.getClass().getSimpleName() + ": " + t.getMessage()); @@ -98,17 +99,18 @@ public Document postProcess(Document document) { } Map, Set>> dependentNodeTypes = dependent.getNodeTypes(); - PostProcessor postProcessor = dependent.apply(document); - BitSet exclusionSet = new BitSet(); - if (dependentNodeTypes != null) { - for (Set> excluded : dependentNodeTypes.values()) { - BitSet mapped = classifyingNodeTracker.getExclusionSet().indexBitSet(excluded); - exclusionSet.or(mapped); - } + Span span = startPostProcessorSpan(); + try (Scope ignored = span.makeCurrent()) { + PostProcessor postProcessor = dependent.apply(document); + span.setAttribute(POST_PROCESSOR_CLASS_ATTRIBUTE, postProcessor.getClass().getName()); + BitSet exclusionSet = new BitSet(); + if (dependentNodeTypes != null) { + for (Set> excluded : dependentNodeTypes.values()) { + BitSet mapped = classifyingNodeTracker.getExclusionSet().indexBitSet(excluded); + exclusionSet.or(mapped); + } - ReversibleIterable nodes = classifyingNodeTracker.getCategoryItems(Node.class, dependentNodeTypes.keySet()); - Span span = startPostProcessorSpan(postProcessor); - try (Scope ignored = span.makeCurrent()) { + ReversibleIterable nodes = classifyingNodeTracker.getCategoryItems(Node.class, dependentNodeTypes.keySet()); for (Node node : nodes) { if (node.getParent() == null) continue; // was already removed // now we need to get the bitset for the excluded ancestors of the node, then intersect it with the actual ancestors of this factory @@ -132,12 +134,12 @@ public Document postProcess(Document document) { } postProcessor.process(classifyingNodeTracker, node); } - } catch (Throwable t) { - span.setStatus(StatusCode.ERROR, t.getClass().getSimpleName() + ": " + t.getMessage()); - throw t; - } finally { - span.end(); } + } catch (Throwable t) { + span.setStatus(StatusCode.ERROR, t.getClass().getSimpleName() + ": " + t.getMessage()); + throw t; + } finally { + span.end(); } } } @@ -146,11 +148,16 @@ public Document postProcess(Document document) { return document; } - private static Span startPostProcessorSpan(PostProcessor postProcessor) { + private static final String POST_PROCESSOR_CLASS_ATTRIBUTE = "markdown.post_processor.class"; + + // Started before PostProcessorFactory.apply(...) so that work done while constructing the processor + // (which may be expensive, e.g. loading data to build matching patterns) is attributed to this span + // instead of showing up only as unexplained time in the enclosing post_process span. The processor + // class is therefore added as an attribute by the caller once the instance exists. + private static Span startPostProcessorSpan() { // no-op span unless a Java agent (or the application) has wired GlobalOpenTelemetry return GlobalOpenTelemetry.getTracer("com.vladsch.flexmark") .spanBuilder("markdown.parse.post_processor") - .setAttribute("markdown.post_processor.class", postProcessor.getClass().getName()) .startSpan(); } diff --git a/pom.xml b/pom.xml index 85c61f39a6..c4d318fd01 100644 --- a/pom.xml +++ b/pom.xml @@ -546,6 +546,13 @@ opentelemetry-instrumentation-annotations 2.16.0 + + + io.opentelemetry + opentelemetry-sdk-testing + 1.50.0 +