DEV Community: Paolo

The Row Says 'system': Spring Data JPA Auditing Outside the HTTP Request

Paolo — Wed, 23 Sep 2026 18:49:03 +0000

Every table in our platform has the same four columns at the end: created_by, created_at, updated_by, updated_at. Spring Data JPA fills them in for you with four annotations and one @EnableJpaAuditing. That part takes five minutes.

Then you look at the data a month later and find rows that say system, and you cannot tell which ones deserved it. Some of them really were written by a scheduled job. Some were written by a queue consumer on behalf of a real person whose identity got lost on the way. A few were written by a user whose session had not been set up yet. All three look identical in the audit trail, which makes the audit trail useless for exactly the question it exists to answer.

What follows is what happens after those first five minutes: where the auditor's identity comes from, what to return when there is no logged-in user, what to actually put in that column, and how to package all of it in a library that a dozen services can share without any of them breaking at startup. The setup is deliberately not Spring Security. Our services keep the logged-in user in a session-scoped bean of their own, and the auditor reads from there. If you use SecurityContextHolder, the interesting parts still apply, because the problem is not where the identity is stored. The problem is that on a scheduler thread there is no identity to read.

Everything is in a companion repository: auditor-aware-demo. It is a single Spring Boot module on an in-memory H2 database, with two test classes that cover the two situations described below, so mvn test is all you need.

Versions used: Spring Boot 3.5.16, Spring Data JPA 3.5.13, Hibernate 6.6.53.Final, H2 2.3.232, Java 21. Boot 3.5.x is out of OSS support since July 2026; everything here runs unchanged on 4.x.

The problem

Here is the shape of the system: several Spring Boot services, each with its own database, all of them persisting through JPA. A user logs in once, and from then on every row that user writes should carry their id.

Some rows, though, are not written by a user at all:

a nightly job that archives stale records;
a consumer that picks a command off a queue and executes it;
an @Async method that was started inside a request and finishes after the request is gone.

Spring Data has one hook for all of this, AuditorAware<T>, and it has one method: Optional<T> getCurrentAuditor(). Most of this article is about what that method should return, and what it should never do.

The basic setup

The entity side first, because it does not change.

@MappedSuperclass
@EntityListeners(AuditingEntityListener.class)
public abstract class AuditableEntity {

    @CreatedBy
    @Column(name = "created_by", updatable = false)
    private String createdBy;

    @CreatedDate
    @Column(name = "created_at", updatable = false)
    private Instant createdAt;

    @LastModifiedBy
    @Column(name = "updated_by")
    private String updatedBy;

    @LastModifiedDate
    @Column(name = "updated_at")
    private Instant updatedAt;

    // getters only
}

Three things about this class are deliberate choices rather than the defaults you would end up with by accident.

No setters. These fields are written by AuditingEntityListener and by nobody else. If application code can call setCreatedBy, sooner or later it will, usually in a "migration" or an "import" that somebody wrote in a hurry. The updatable = false on the two created_* columns is the same idea one layer down: even if an entity is loaded, modified and merged back, those two columns are not part of the UPDATE.

No equals/hashCode. Do not generate them over these fields. All four change the moment the entity is persisted, so an entity in a HashSet before save() is a different object after it. With Lombok that means @Getter on this class, not @Data.

Instant, not LocalDateTime. The audit trail is going to be read across services that may not share a timezone. Instant is unambiguous, and Spring Data converts it without configuration.

Every entity in every service extends this:

@Entity
@Table(name = "note")
public class Note extends AuditableEntity {
    @Id @GeneratedValue(strategy = GenerationType.IDENTITY)
    private Long id;
    private String text;
    private boolean archived;
    // ...
}

Then turn auditing on:

@Configuration
@EnableJpaAuditing
public class JpaAuditingConfig {
}

That is the entire configuration; the auditor is a @Component implementing AuditorAware<String>, shown in the next section. Many examples add auditorAwareRef = "auditorAware" and an explicit @Bean. The attribute is optional: without it, Spring Data autowires the AuditingHandler by type, and one AuditorAware bean in the context is enough. Why it has to be exactly one comes up when the configuration moves into a library.

One behaviour to know before the first test: on insert, Spring Data fills in all four columns, not just the created_* pair. @LastModifiedBy and @LastModifiedDate are set on creation too, so a freshly inserted row has updated_by == created_by and updated_at == created_at. If your reporting logic treats a null updated_at as "never modified", it is wrong for every row you insert, not just the ones that were later modified. @EnableJpaAuditing(modifyOnCreate = false) turns this off.

Where the identity comes from

Our services keep the logged-in user in a session-scoped bean:

@Component
@SessionScope
public class CurrentUser implements Serializable {
    private String userId;
    // getter, setter
}

One instance per HTTP session, populated at login. How that bean gets populated, and why it is session-scoped at all, is a topic for another article. What matters here is one property of it: the auditor is a singleton, and what it receives is a proxy. Every call on that proxy is routed to the session of the current request thread. On a thread that is not serving a request, there is no session to route to, and the call throws:

org.springframework.beans.factory.support.ScopeNotActiveException:
  Error creating bean with name 'scopedTarget.currentUser':
  Scope 'session' is not active for the current thread; ...
Caused by: java.lang.IllegalStateException: No thread-bound request found:
  Are you referring to request attributes outside of an actual web request,
  or processing a request outside of the originally receiving thread? ...

So the auditor has to know, before touching the session, whether there is a request at all. RequestContextHolder answers that question:

@Component
public class CurrentUserAuditorAware implements AuditorAware<String> {

    public static final String ANONYMOUS = "anonymous";
    public static final String USER_PREFIX = "user:";

    private final CurrentUser currentUser;

    public CurrentUserAuditorAware(CurrentUser currentUser) {
        this.currentUser = currentUser;
    }

    @Override
    public Optional<String> getCurrentAuditor() {
        Optional<String> explicit = AuditorContext.current();
        if (explicit.isPresent()) {
            return explicit;
        }

        // No request bound to this thread: a scheduled job, a queue consumer, a test.
        // Touching the session-scoped bean here would throw, so we do not.
        if (RequestContextHolder.getRequestAttributes() == null) {
            return Optional.of(Auditors.SYSTEM); // "system", a constant of the shared library
        }

        return Optional.of(Optional.ofNullable(currentUser.getUserId())
                .map(id -> USER_PREFIX + id)
                .orElse(ANONYMOUS));
    }
}

The last statement is the happy path: a request, a session, a user in it. The values are namespaced (user:42, not 42) so that a user, a job and a consumer can never be mistaken for one another; the full argument is in What goes in the column.

The RequestContextHolder guard is what prevents the exception above. There is a version of this class that checks currentUser == null instead; it shows up in a lot of codebases and it is dead code. The proxy is injected at startup and is never null; what can be missing on a given thread is the request that the proxy needs in order to reach a session.

The distinction between anonymous and system is deliberate. A request with nobody logged in and no request at all are different situations, and when you are staring at a row three months later, knowing which one produced it is worth a lot more than the two extra constants cost.

The first three lines, the explicit auditor, are the subject of the next section.

When there is no user

system is a correct answer to "who wrote this row" when a job did it. It is a poor answer when the row was written by a consumer executing a command that a specific person put on a queue thirty seconds earlier. And it is a wrong answer when an @Async method, started inside a request by a logged-in user, finishes its work on a pool thread where RequestContextHolder is empty. All three cases hit the same return Optional.of(Auditors.SYSTEM), and the audit trail cannot tell them apart.

The fix is to stop treating the auditor as something that has to be discovered from ambient state, and let the code that actually knows who is acting say so:

public final class AuditorContext {

    private static final ThreadLocal<String> CURRENT = new ThreadLocal<>();

    public static void runAs(String auditor, Runnable action) {
        callAs(auditor, () -> { action.run(); return null; });
    }

    public static <T> T callAs(String auditor, Supplier<T> action) {
        String previous = CURRENT.get();
        CURRENT.set(auditor);
        try {
            return action.get();
        } finally {
            if (previous == null) CURRENT.remove(); else CURRENT.set(previous);
        }
    }

    public static Optional<String> current() {
        return Optional.ofNullable(CURRENT.get());
    }
}

A thread-local with a try/finally around it, nothing more. The previous bookkeeping makes it safe to nest, which matters the first time a job calls a service method that has its own runAs. On Java 25 you would reach for ScopedValue instead; the shape of the API is the same.

The auditor checks this first, before looking at any request. An explicit statement of who is acting beats an inference from ambient state.

Now the three cases become three different rows.

The scheduled job names itself:

@Component
public class NightlyArchiveJob {

    public static final String AUDITOR = "job:nightly-archive";
    private static final Duration RETENTION = Duration.ofDays(30);

    private final NoteService noteService;

    public NightlyArchiveJob(NoteService noteService) {
        this.noteService = noteService;
    }

    @Scheduled(cron = "0 0 3 * * *", zone = "UTC")
    public void run() {
        archiveCreatedBefore(Instant.now().minus(RETENTION));
    }

    public int archiveCreatedBefore(Instant cutoff) {
        return AuditorContext.callAs(AUDITOR, () -> noteService.archiveEachCreatedBefore(cutoff));
    }
}

archiveEachCreatedBefore does what the name says: it loads the stale notes and flips them one at a time, so each row goes through the auditing listener and gets updated_by = job:nightly-archive. That is a row you can act on directly, whereas a row that says system sends you to the logs to find out which process wrote it.

A side note on the zone attribute, since it is the kind of thing that only bites in production: a cron expression runs in the JVM's default time zone unless you say otherwise. In a container that is usually UTC; on the laptop where you tested it, it is not. Spelling it out costs nothing and removes a whole category of "why did the job run at 4" questions. The cutoff itself is an Instant, so the comparison has no time zone to get wrong.

The queue consumer carries the originating user through. The producer knew who asked for this; it is a header on the message, or a field in the payload. The consumer's only job is not to lose it:

@Component
public class NoteCommandConsumer {

    public static final String AUDITOR = "consumer:note-commands";

    // requestedBy is already namespaced upstream (e.g. "user:42")
    public record NoteCommand(String text, String requestedBy) {
    }

    private final NoteService noteService;

    public NoteCommandConsumer(NoteService noteService) {
        this.noteService = noteService;
    }

    public Note onMessage(NoteCommand command) {
        String auditor = command.requestedBy() != null ? command.requestedBy() : AUDITOR;
        return AuditorContext.callAs(auditor, () -> noteService.create(command.text()));
    }
}

When the message has no origin, the consumer falls back to its own name (consumer:note-commands) rather than to system, so the row still says something specific about where it came from.

One caveat that has to be stated: requestedBy is a value the producer controls. This only works if the producer is trusted, which in practice means the queue is internal and the message was authenticated on the way in. An auditor taken from an unauthenticated payload is a spoofable audit trail.

The value also arrives already namespaced, because normalising an identity into user:42 belongs at the boundary where it enters the system, not in every consumer that happens to handle it.

The @Async method is the same problem in a different costume. Thread-locals do not cross thread boundaries, and that applies equally to RequestContextHolder, to SecurityContextHolder and to our own AuditorContext. Capture the auditor before the hop and re-establish it on the other side, either by hand (String who = ...; executor.submit(() -> AuditorContext.runAs(who, ...))) or with a TaskDecorator on the executor that does it for every task. We will not go further into that here. The point is that once the auditor is a value you can hold in a variable, propagating it becomes a solved problem, which it never was while the identity stayed buried in a session proxy.

The test that lied to us

The two test classes in the repo are split on purpose: one goes through MockMvc with a real session, the other has no request at all. The second one is where the system branch gets exercised.

Our first version of it was a plain @SpringBootTest calling the service directly. The row came back anonymous.

Not system. anonymous. Which means the auditor found a request bound to the test thread, found no user on it, and gave the right answer for what it saw. Where did the request come from?

From Spring itself. When a test's context is a WebApplicationContext (the default for @SpringBootTest in a web project), ServletTestExecutionListener binds a MockHttpServletRequest to the test thread before every test method. The intent is that code depending on RequestContextHolder works in tests without MockMvc. The side effect is that a test meant to simulate "no request" is not simulating it at all, and the branch you wrote the test for never runs.

The fix is one attribute:

@SpringBootTest(webEnvironment = SpringBootTest.WebEnvironment.NONE)
class AuditingOutsideRequestTest { ... }

With no web layer in the context, the listener does not run and nothing gets bound to the thread. That is also what a batch worker's context looks like, and it is the situation this test is meant to cover.

What goes in the column

The values so far have been strings like user:42 and job:nightly-archive. That is a decision, and one that is hard to undo once a few million rows carry it.

The temptation is to store the user's primary key. It is what you have at hand and what the rest of the schema uses, and AuditorAware<Long> makes it look like the intended choice. Then the first scheduled job runs and you need a value for it. If the column is a BIGINT, you invent one: 0, -1, a "system user" row. If the column is a VARCHAR that happens to always contain digits, you write system into it, and somewhere downstream a frontend or a report does Long.parseLong(createdBy) and falls over, though not immediately: it happens weeks later, on the one screen that happens to list rows a job touched.

The rule we landed on is boring: one column, one kind of value, and never mix kinds. Two ways to honour it.

Everything is a user. The column is a foreign key to the users table, and every non-human actor is a real row in it: a technical user for each job, and likewise for each consumer and each integration that writes rows. job:nightly-archive becomes user 10001, with a display name, and the frontend resolves it like any other user without special cases. This is the cleanest option if you already have a users table in every service and you can afford to seed it with the technical accounts. It is also the one where AuditorAware<Long> is the accurate type.

Everything is a string, and the string says what it is. The column is text, the values are user:42, job:nightly-archive, consumer:note-commands, system, anonymous, and no code anywhere is allowed to parse a number out of it. The namespace is the guard: nobody looks at user:42 and thinks it is an integer. This is what the demo does, because it needs no users table and it works across services that do not share one.

What you should not do is the thing that happens by default: a string column that contains a number for people and a word for everyone else. That is a Long with a lie in it, and every consumer of the column has to know about the lie.

Whichever you pick, store a stable identifier rather than a display name, because names change over time, they get corrected, and sometimes they get anonymised, and none of that should propagate into an audit trail.

Sharing it across microservices

Everything above lives in one service. We have a dozen, and they all need the same four columns and the same AuditableEntity, governed by the same rules. The natural move is a shared library, and the natural mistake is to put AuditableEntity in the library and leave each service to write its own configuration.

What the library should own:

AuditableEntity
Auditors, the values the library itself knows about (system)
AuditorContext
the @EnableJpaAuditing itself
a default AuditorAware for services that have no notion of a user

What each service should own: its AuditorAware, if it has something better than the default to say. That is the whole contract.

In Spring Boot terms, the library ships an auto-configuration:

@AutoConfiguration
@EnableJpaAuditing
public class AuditingAutoConfiguration {

    @Bean
    @ConditionalOnMissingBean(AuditorAware.class)
    public AuditorAware<String> systemAuditorAware() {
        return () -> Optional.of(AuditorContext.current().orElse(Auditors.SYSTEM));
    }
}

registered in META-INF/spring/org.springframework.boot.autoconfigure.AutoConfiguration.imports:

com.example.auditdemo.audit.AuditingAutoConfiguration

A web-facing service keeps its CurrentUserAuditorAware as a @Component and deletes its JpaAuditingConfig; the @EnableJpaAuditing now lives in the library. Auto-configurations are evaluated after the service's own beans, so @ConditionalOnMissingBean sees the service's bean and the default steps aside. A batch worker with no session does not need to declare anything: it gets the default, and its rows say whatever AuditorContext was told, or system when it was told nothing. No service ever writes @EnableJpaAuditing.

That last sentence is a rule, and Spring enforces it at startup. @EnableJpaAuditing registers its infrastructure beans by fixed name, and Boot has refused to silently override bean definitions since 2.1. A service that keeps its old configuration alongside the library's auto-configuration does not start:

BeanDefinitionOverrideException: Invalid bean definition with name 'jpaAuditingHandler'
  defined in null: Cannot register bean definition [...] for bean 'jpaAuditingHandler'
  since there is already [...] bound.

defined in null is the tell, because it means the bean was registered by an annotation's registrar rather than by a class you can open in the IDE. When you see this one, the search term is @EnableJpaAuditing, and the answer is that it is declared twice.

The same exception shows up in a second disguise. If an AuditorAware implementation is annotated @Component("auditorAware") and a configuration class has a @Bean method called auditorAware returning it (a common combination, because the @Bean version gets added when someone reads about auditorAwareRef and nobody removes the @Component), the two definitions collide on the name, and one of them has to go; the @Component on its own is enough.

The demo repository is a single module, but the audit package in it is wired exactly this way, imports file included, so you can see the mechanism working without a second pom.xml.

Pitfalls

The null column

getCurrentAuditor() returns an Optional for a reason: Optional.empty() means "unknown", and Spring Data leaves the column untouched. On insert, that means NULL.

Whether that is acceptable is a schema question. With created_by NOT NULL, an empty auditor turns into a constraint violation at flush time, several stack frames away from the auditor and with a message about the table rather than about the cause. We went with a sentinel (system) instead of empty() for that reason, and because a NULL in an audit column is one more thing that "cannot happen" that will happen.

Two related traps. Returning null instead of an Optional fails immediately with Auditor must not be null, which is at least loud. And a user object that exists but has a null id (a half-initialised session) will produce the string "null" if you build the value with String.valueOf. Check that the id is present as well as the object before building the value.

Bulk queries

This one is not a bug so much as a property of how JPA works, and it seems to catch everyone once. The nightly job above archives one entity at a time. Here is the same operation written as a bulk update instead:

@Modifying
@Query("update Note n set n.archived = true where n.archived = false and n.createdAt < :before")
int bulkArchiveCreatedBefore(@Param("before") Instant before);

A JPQL or native UPDATE goes straight to the database. No entity is loaded, no @PreUpdate fires, and the audit columns keep whatever they had. Run the job this way and it produces rows that say nothing about it: the test in the repo shows the archived flag flipping while updated_by and updated_at do not move. deleteAllInBatch and every native query are the same story.

Your options, in the order we usually pick them: load the entities and modify them one by one, as the job does (correct, slow past a few thousand rows); set the audit columns explicitly in the query (set n.archived = true, n.updatedBy = :who, n.updatedAt = :now), which works but duplicates the auditor logic in every bulk query; or accept that bulk operations are unaudited at the row level and log them as one event at the job level. The wrong option is not deciding, which is what happens by default.

Listeners that do nothing

@EntityListeners(AuditingEntityListener.class) on AuditableEntity is what makes any of this happen, and it is inherited by every subclass, so you write it once. But the listener is only a hook. It delegates to an AuditingHandler that @EnableJpaAuditing creates and injects, which works because Boot hands Hibernate a Spring-aware bean container, so the listener Hibernate instantiates is actually a Spring bean.

Take @EnableJpaAuditing away and nothing fails. The listener still runs, but it finds no handler and simply returns, so every audit column on every row is NULL and there is not a single log line to say why. We reproduced it in the demo by excluding the auto-configuration: createdBy=null createdAt=null, test green.

This is the failure mode to expect in a new service that pulled in the library but is missing something. The checklist, in order: is the listener on the entity or its superclass? Is @EnableJpaAuditing present, exactly once? Is there exactly one AuditorAware bean? The first two fail silently; the third fails at startup, which is a mercy.

What this does not cover

Row-level audit columns tell you who last touched a row. They do not tell you what it looked like before, and they cannot be trusted to record every touch, as the bulk-query section shows. A real audit log is a separate concern: Hibernate Envers, a history table maintained by triggers, or change data capture off the transaction log. The four columns are the cheap first layer, and they are worth having precisely because they are cheap.

What they are not worth having is half-configured. An auditor that returns system from every path it does not understand will pass every test you write on a request thread, and then spend a year writing system into rows that a specific person, or a specific job, was responsible for. The fix is not more fallback logic. It is making the code that knows who is acting say so, and making the fallback the exception it was supposed to be.

Where OpenTelemetry Stops: the missing 44ms in a Spring Boot trace

Paolo — Fri, 31 Jul 2026 12:19:47 +0000

A POST /orders in this demo takes 178 milliseconds. The OpenTelemetry Java agent, attached with a single JVM flag and no code changes, will tell you that 127 of those went to a downstream service and 6 to the database. It will not tell you anything about the remaining 44.

That gap is where auto-instrumentation ends and your own code begins. This article locates that boundary precisely, then crosses it: with distributed tracing across two Spring Boot services with zero code changes, then with the minimum instrumentation needed to make the missing 44 milliseconds visible.

Everything is in a companion repository: spring-boot-otel-demo. If you have Docker installed you can clone it and have a live trace in front of you in about two minutes.

Versions used: OpenTelemetry Java agent 2.30.0, opentelemetry-instrumentation-annotations 2.30.0, Spring Boot 3.5.16, Java 21, otel/opentelemetry-collector-contrib:0.157.0, jaegertracing/all-in-one:1.76.0, postgres:18-alpine. This ecosystem moves fast. Check the current OpenTelemetry Java documentation before copying any version number.

The repository has two branches on purpose. master is the agent-only state described in Step 1: no OpenTelemetry dependency in either service. manual-spans is the annotated version from Step 2. Clone, run master first, then switch branches to see the difference.

The problem

Here is a request that touches two services and a database.

POST /orders arrives at order-service. The service validates the request, calculates pricing, calls inventory-service over HTTP to check stock, persists the order to PostgreSQL, and returns a response.

It takes around 180 milliseconds. Sometimes it takes 900. Where does the time go?

The usual answer is to open the logs of both services, filter by timestamp, and reconstruct the sequence by hand. That works with two services. It does not work with eight, and it does not work at all when two requests overlap in the same window.

Traces, spans, and the one header that matters

A trace is one request through your whole system. A span is one unit of work inside it: an HTTP handler, a database query, a method call. Spans nest: each has a parent, and the trace is a tree.

Every span in a trace carries the same trace id. That is what lets a UI stitch together work that happened in different processes, on different machines.

The mechanism for carrying that id across a service boundary is a single HTTP header, traceparent, defined by the W3C Trace Context specification. order-service sends it, inventory-service reads it, and the second service knows it belongs to a trace that started somewhere else.

Here is the setup we are building:

Note the shape. The two services never talk to Jaeger. They talk to an OpenTelemetry Collector, and the Collector decides where the data goes. We will come back to why that matters.

Step 1: tracing with zero code changes

The OpenTelemetry Java agent attaches to the JVM and rewrites bytecode at class-loading time. It recognises Spring MVC, JDBC, Hibernate and HTTP clients, and creates spans for them without the application knowing.

Download the agent jar in your Dockerfile, then start the service with:

ENTRYPOINT ["java", "-javaagent:/app/opentelemetry-javaagent.jar", "-jar", "/app/app.jar"]

Configure it with environment variables in docker-compose.yml:

environment:
  OTEL_SERVICE_NAME: order-service
  OTEL_EXPORTER_OTLP_ENDPOINT: http://otel-collector:4317
  OTEL_EXPORTER_OTLP_PROTOCOL: grpc
  OTEL_TRACES_EXPORTER: otlp

The protocol line is load-bearing, not decoration. Port 4317 is the gRPC port and the Collector in this repo opens a gRPC receiver only. Defaults for this variable have varied across SDKs and versions, so set it explicitly: if the agent picks http/protobuf and sends it to 4317, every export fails and no traces reach Jaeger.

The failure is at least loud. The agent logs it to the service's own stdout on every export cycle, naming both the exporter and the endpoint:

[otel.javaagent] ... ERROR io.opentelemetry.exporter.otlp.internal.HttpExporter
- Failed to export spans. The request could not be executed.
java.net.SocketException: Connection reset

If Jaeger is empty, docker compose logs order-service is the first place to look. The word HttpExporter against a port you configured for gRPC is the whole diagnosis.

That is the entire integration. No dependency in pom.xml, no configuration class, no SDK.

Bring the stack up and send a request:

curl -X POST http://localhost:8080/orders \
  -H "Content-Type: application/json" \
  -d '{"customerId":"CUST-001","sku":"SKU-1000","quantity":5}'

Then open Jaeger at http://localhost:16686, select order-service, and click Find Traces:

One thing before you read anything into the numbers: let the JVM warm up. The first request through a fresh service can be three times slower than the steady state, and the shape of that first trace is misleading. Send the request ten times and look at the last one.

What you got for free

Read that waterfall carefully, because there is more in it than it first appears.

The trace crosses the service boundary. inventory-service GET /inventory/{sku} is nested inside the client span of order-service. Two JVMs, two containers, one trace. Nobody wrote code to make that happen. The agent injected traceparent on the way out and read it on the way in.

The persistence layer is broken down for you. OrderRepository.save at 5.93ms contains Session.persist at 1.36ms, the actual INSERT at 496µs, and Transaction.commit at 3.37ms.

That last pair is worth sitting with. The INSERT is under half a millisecond. The commit costs nearly seven times as much. Most of the time spent persisting this order is not the query. It is everything around it. You would never learn that from a log line, and it is the kind of detail that changes how you think about transaction boundaries under load.

Self time versus total time. The client span for the inventory call is 127.37ms, while the server span inside inventory-service is 123.69ms. The difference is real client-side and network overhead. When hunting a bottleneck, the number you want is not the widest bar, but the bar that is wide and does not have equally wide children. A service that takes two seconds is not guilty if 1.9 of them are spent waiting for someone else.

Where the agent stops

Now look at the start of the trace:

The root span starts at zero. The first child span starts around 44 milliseconds later. Nothing at all is recorded in between.

That gap is your business logic. In this service it is request validation followed by a pricing calculation: plain Java, no I/O. The DTO mapping that happens after persistence is invisible for the same reason, though at well under a millisecond it does not leave a hole you can see.

And that is exactly why the agent cannot see them. Auto-instrumentation works by recognising libraries: a servlet container, a JDBC driver, an HTTP client. It has no way to know that computePricing is a meaningful unit of work in your domain. From the agent's point of view, the time between two library calls is just time.

This is the honest limit of "zero code changes". The agent gives you the skeleton of the request for free. The flesh is your problem.

Step 2: naming your own work

Add one dependency to order-service:

<properties>
  <!-- Must match the agent version pinned in the Dockerfile -->
  <opentelemetry-instrumentation.version>2.30.0</opentelemetry-instrumentation.version>
</properties>

<dependency>
  <groupId>io.opentelemetry.instrumentation</groupId>
  <artifactId>opentelemetry-instrumentation-annotations</artifactId>
  <version>${opentelemetry-instrumentation.version}</version>
</dependency>

Keep that version aligned with the agent jar you download in the Dockerfile. A mismatch between the two is the most common reason @WithSpan spans silently fail to appear. The build succeeds, the service starts, and the spans simply are not there.

Then annotate the methods that matter. @WithSpan creates a span for the method, correctly parented to whatever span is active. @SpanAttribute attaches a method parameter to that span as a searchable field:

@WithSpan("calculate-pricing")
private PricingBreakdown computePricing(@SpanAttribute("order.sku") String sku,
                                        @SpanAttribute("order.quantity") int quantity) {
    // both helpers are plain in-memory work: a price list scan and a discount tier walk
    BigDecimal basePrice = lookupBasePrice(sku);
    BigDecimal discountRate = resolveVolumeDiscountRate(quantity);

    BigDecimal subtotalAfterDiscount = BigDecimal.ZERO;
    BigDecimal taxAmount = BigDecimal.ZERO;
    int remainingUnits = quantity;

    while (remainingUnits > 0) {
        int unitsInLine = Math.min(LINE_SIZE, remainingUnits);
        BigDecimal lineSubtotal = applyPerUnitRules(basePrice, unitsInLine);

        BigDecimal lineDiscount = lineSubtotal.multiply(discountRate).setScale(2, RoundingMode.HALF_UP);
        BigDecimal lineAfterDiscount = lineSubtotal.subtract(lineDiscount);
        BigDecimal lineTax = lineAfterDiscount.multiply(TAX_RATE).setScale(2, RoundingMode.HALF_UP);

        subtotalAfterDiscount = subtotalAfterDiscount.add(lineAfterDiscount);
        taxAmount = taxAmount.add(lineTax);
        remainingUnits -= unitsInLine;
    }

    BigDecimal totalPrice = subtotalAfterDiscount.add(taxAmount).setScale(2, RoundingMode.HALF_UP);
    return new PricingBreakdown(basePrice, discountRate, taxAmount, totalPrice);
}

No I/O, no sleeps, no database. Pure CPU work, which is exactly the point. This is the kind of method the agent cannot see.

One disclosure, since the numbers have to add up: the loop you see here is cheap at quantity = 5. The weight sits in lookupBasePrice, which builds and linearly scans a price catalog of roughly 950,000 entries, once per call rather than once per unit. That is deliberately absurd. In a real service it would be a cached lookup and the span would measure microseconds. The point of this article is the shape of the trace, not the size of the number, and a gap of forty milliseconds is easier to see in a screenshot than a gap of forty microseconds.

Two things worth knowing before scattering these around.

It works on private methods, but only because the agent is rewriting bytecode. This is not a Spring proxy, so there is no self-invocation problem to worry about. A private method called from within the same class still gets its span. If one fails to appear, check the version alignment above first, then try widening the method's visibility.

Extract before you annotate. A span is only useful if it wraps one coherent thing. If your pricing logic sits inline in the middle of a 200-line service method, annotating that method tells you nothing you did not already know.

Switch to the manual-spans branch, rebuild, send the same request, and the gap is gone:

validate-order-request at 32µs. calculate-pricing at 38.68ms, most of the 44ms gap from before, now with a name. check-inventory and persist-order wrap the library spans they own, and map-response closes the request at 20µs.

Note that a few milliseconds are still unaccounted for. That residue is not a failure of instrumentation: some of what sits between two spans is request deserialisation, framework dispatch and other work that is not yours to name. You are never going to close the gap completely, and chasing the last microsecond is how you end up with a trace so noisy that nobody reads it.

The totals: 178.06ms without manual spans, 184.86ms with them. Do not read that difference as the cost of instrumentation. Two annotations cannot cost seven milliseconds. The runtime overhead of a span is a context push and a timestamp, measured in fractions of a microsecond. What you are looking at is JVM noise: a minor GC, a scheduling hiccup, network jitter between two containers. Run the same request twenty times and you will see a wider spread than this with no code change at all.

There is one real cost worth naming: annotating a small private method can prevent the JIT from inlining it, so a hot, tight method may genuinely run slower once instrumented. That is an argument for instrumenting meaningful units of work rather than every method you can reach. It is not an argument against instrumenting at all. In an I/O bound service like this one, where a single HTTP call accounts for 70% of the request, it is invisible.

Attributes are where this gets useful

Click on the calculate-pricing span:

The span carries order.sku = SKU-1000 and order.quantity = 5, the actual values from the request. It also carries code.function = computePricing and code.namespace = com.example.orderservice.order.OrderService, added automatically.

This is the difference between something took 38ms and OrderService.computePricing took 38ms for SKU-1000 at quantity 5. Once those attributes are on the span you can search on them: every pricing calculation above a threshold, filtered by SKU. That is a question you cannot ask a log file without writing a parser first.

Two cautions. Whatever you put in an attribute ends up in your observability backend, so keep personal data and secrets out of them. And be careful about where that attribute travels: order.sku is harmless on a span, because traces are sampled and stored as individual records. Put the same field on a metric and you have created one time series per SKU. High-cardinality labels are the classic way to take down a Prometheus instance, and the mistake is easy to make once you start instrumenting by habit rather than by intent.

Why the Collector is in the picture

You may have noticed the agent could have pointed straight at Jaeger. In development it can. There are three reasons not to do that anywhere else.

Batching and retries belong in a separate process, not in the request path of your application. The Collector can enrich, filter and drop data centrally rather than in every service. And most importantly:

exporters:
  otlp:
    endpoint: jaeger:4317
    tls:
      insecure: true

Changing your observability backend means editing that block. It does not mean touching, rebuilding or redeploying a single service. Your applications emit OTLP, an open protocol, and where it lands is a deployment detail.

If you have ever had to argue an architecture decision on vendor lock-in grounds, this is an unusually clean example: the instrumentation is standard, the wire protocol is standard, and the vendor-specific part is one block in one file.

For completeness: OTLP travels over gRPC on port 4317 and over HTTP/protobuf on 4318. The specification says the default should be http/protobuf unless an SDK has good reason to pick gRPC (backward compatibility, typically), so what you actually get depends on your SDK and version. Pin it explicitly, as in the compose file above. gRPC is generally the right choice for agent-to-collector traffic, which is high volume and continuous. Switch to HTTP if you have proxies or load balancers in between that are unhappy with long-lived HTTP/2 connections, which is common enough in enterprise networks.

What this does not cover

Tracing every request is affordable on a laptop but not in production, so sampling strategy is the decision waiting on the other side of this setup. Traces are also only one of three signals: metrics and logs travel the same pipeline, and correlating existing Log4j2 output with trace ids is arguably the highest-value thing to do after this. Asynchronous boundaries deserve their own article: put a message on a queue and the context does not propagate on its own, so the trace breaks silently at exactly that point.

The boundary described here, though, does not move. Auto-instrumentation maps the parts of your system that are made of libraries. Everything that is genuinely yours (the logic you were actually hired to write) stays invisible until you name it.

Naming it costs one dependency and a handful of annotations.