{"record":{"id":"3594af197e524436","repo":"pinpoint-apm/pinpoint","slug":"starttime-not-recorded","errorCode":null,"errorMessage":"startTime not recorded","messagePattern":"startTime not recorded","errorType":"exception","errorClass":"IllegalStateException","httpStatus":null,"severity":"error","filePath":"agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/context/SpanEvent.java","lineNumber":110,"sourceCode":"\n    public long getStartTime() {\n        return startTime;\n    }\n\n    public void markAfterTime() {\n        checkStartTime();\n        setAfterTime(System.currentTimeMillis());\n    }\n\n\n    public void setAfterTime(long afterTime) {\n        checkStartTime();\n        this.elapsedTime = (int) (afterTime - startTime);\n    }\n\n    private void checkStartTime() {\n        if (startTime == 0) {\n            throw new IllegalStateException(\"startTime not recorded\");\n        }\n    }\n\n    public long getAfterTime() {\n        return startTime + elapsedTime;\n    }\n\n    public int getStackId() {\n        return stackId;\n    }\n\n    public void setStackId(int stackId) {\n        this.stackId = stackId;\n    }\n\n    public boolean isTimeRecording() {\n        return timeRecording;\n    }","sourceCodeStart":92,"sourceCodeEnd":128,"githubUrl":"https://github.com/pinpoint-apm/pinpoint/blob/744c3d3075e595656abb1ae331ad2c0e4c9eb996/agent-module/profiler/src/main/java/com/navercorp/pinpoint/profiler/context/SpanEvent.java#L92-L128","documentation":"SpanEvent tracks its own lifecycle with startTime and afterTime; elapsedTime is computed as afterTime - startTime when the event completes. checkStartTime() enforces the invariant that markAfterTime/setAfterTime can only run after markStartTime recorded a non-zero startTime. If the event ended without ever being started, the state machine is broken, so an IllegalStateException is thrown rather than recording a bogus elapsed time.","triggerScenarios":"Calling spanEvent.markAfterTime() or setAfterTime(...) on a SpanEvent whose markStartTime() was never invoked (or whose startTime was lost, e.g. the event was constructed but begin() flow was skipped) — typically when an interceptor's after() runs without its matching before() storing the start time.","commonSituations":"Custom plugins/interceptors that only implement the 'after' side of instrumentation or short-circuit before(); recursive/reentrant calls where a nested event overwrote state; exceptions in before() leaving the event half-initialized; SpanEvents serialized across async boundaries without copying startTime.","solutions":["Ensure the interceptor/async flow always calls markStartTime() (or the before-phase) before markAfterTime()/setAfterTime().","Guard the after-phase: only call markAfterTime if the event is still in the expected state (check currentSpanEvent/depth consistency).","Check plugin interceptor logic for early returns or exceptions in before() that skip start-time recording.","If timing is genuinely unknown, avoid setAfterTime and construct the event via APIs that record both endpoints.","Reproduce with a minimal interceptor and log trace.getTraceId() + spanEvent depth to find which call path skips markStartTime."],"exampleFix":"// before\nspanEvent.markAfterTime(); // throws if never started\n// after\nif (spanEvent.getStartTime() != 0) {\n    spanEvent.markAfterTime();\n}","handlingStrategy":"try-catch","validationCode":"if (spanEvent.getStartTime() != 0) {\n    spanEvent.markAfterTime();\n} else {\n    // start time missing; skip or log the lifecycle bug\n}","typeGuard":"boolean isSpanEventStarted(SpanEvent e) {\n    return e != null && e.getStartTime() != 0;\n}","tryCatchPattern":"try {\n    spanEvent.markAfterTime();\n} catch (IllegalStateException e) {\n    logger.warn(\"SpanEvent ended without startTime; interceptor before-phase likely skipped\", e);\n}","preventionTips":["Pair every interceptor before() with a guaranteed after() (use try/finally)","Never early-return from before() without recording start time","Test plugins with exceptions thrown in the before phase","Verify depth/currentSpanEvent consistency in nested/async flows","Log span event lifecycle in staging to catch missing start calls early"],"tags":["java","pinpoint","tracing","illegal-state","lifecycle"],"backgroundTag":"invalid-state-transition","analyzedSha":"744c3d3075e595656abb1ae331ad2c0e4c9eb996","analyzedAt":"2026-09-07T18:48:45.289Z","contentChangedAt":"2026-09-07T18:48:45.289Z","schemaVersion":2},"datasetVersion":"2026-09-14T05:17:10.506Z"}