asmhatre
c7eccd1db5
Custom OrderProcessed event, CPU/allocation/lock workloads, a diagnostic endpoint over the JVM's live FlightRecorder state, a JUnit test using the jdk.jfr.Recording API, and nine captured recordings (flagship, mid-flight snapshot, isolated vs concurrent threshold comparisons, and a real dump+stop duplication bug) with their docs/output/*.txt transcripts.
46 lines
2.0 KiB
Plaintext
46 lines
2.0 KiB
Plaintext
One GET /api/lock/contend?workers=16&holdMillis=20 call: 16 threads release
|
|
simultaneously (via a CountDownLatch) and fight over one synchronized block that
|
|
holds for 20 ms. One thread enters immediately; 15 queue up. jdk.JavaMonitorEnter
|
|
records each waiter's queueing time.
|
|
|
|
$ jfr print --events jdk.JavaMonitorEnter recordings/live-demo.jfr | head -15
|
|
jdk.JavaMonitorEnter {
|
|
startTime = 09:59:07.393 (2026-10-01)
|
|
duration = 20.4 ms
|
|
monitorClass = java.lang.Object (classLoader = bootstrap)
|
|
previousOwner = "pool-135-thread-1" (javaThreadId = 365)
|
|
address = 0x7FCAB40A4860
|
|
eventThread = "pool-135-thread-16" (javaThreadId = 380)
|
|
stackTrace = [
|
|
com.ankurm.jfr.service.WorkloadService.holdLedger(int) line: 100
|
|
com.ankurm.jfr.service.WorkloadService.lambda$contend$0(CountDownLatch, CountDownLatch, AtomicLong, int) line: 89
|
|
java.util.concurrent.Executors$RunnableAdapter.call() line: 545
|
|
java.util.concurrent.FutureTask.run() line: 328
|
|
java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor$Worker) line: 1090
|
|
]
|
|
}
|
|
|
|
$ jfr print --events jdk.JavaMonitorEnter recordings/live-demo.jfr | grep duration | sort | uniq -c
|
|
1 duration = 101 ms
|
|
1 duration = 122 ms
|
|
1 duration = 142 ms
|
|
1 duration = 162 ms
|
|
1 duration = 182 ms
|
|
1 duration = 20.4 ms
|
|
1 duration = 203 ms
|
|
1 duration = 223 ms
|
|
1 duration = 243 ms
|
|
1 duration = 263 ms
|
|
1 duration = 283 ms
|
|
1 duration = 303 ms
|
|
1 duration = 40.6 ms
|
|
1 duration = 60.9 ms
|
|
1 duration = 81.0 ms
|
|
|
|
15 events, one per waiting thread, stepping up in ~20 ms increments (20.4, 40.6,
|
|
60.9, 81.0, 101, 122, ... 303 ms) -- exactly the signature of 16 threads queueing
|
|
one at a time for a monitor held 20 ms at a time: the Nth waiter waits roughly
|
|
(N-1) x 20 ms. The total wall-clock time the HTTP endpoint reported for this call
|
|
was 326 ms, consistent with the last waiter's ~303 ms queueing time plus its own
|
|
20 ms hold.
|