Skip to content

Commit a1393b2

Browse files
authored
Merge pull request #57 from runcycles/claude/optimize-cycle-performance-hwNX9
Claude/optimize cycle performance hw nx9
2 parents 67d3a9c + ebf284a commit a1393b2

13 files changed

Lines changed: 375 additions & 58 deletions

File tree

AUDIT.md

Lines changed: 67 additions & 12 deletions
Original file line numberDiff line numberDiff line change
@@ -27,8 +27,9 @@
2727
| Test Coverage || 0 |
2828
| Tenant Default Config || 0 |
2929
| Performance Optimizations | 7/7 | 0 |
30+
| Production Hardening | 3/3 | 0 |
3031

31-
**All previously identified issues have been fixed. No remaining spec violations found. Performance optimized and benchmarked.**
32+
**All previously identified issues have been fixed. No remaining spec violations found. Performance optimized, hardened, and benchmarked.**
3233

3334
---
3435

@@ -213,22 +214,76 @@ Seven optimizations applied to the reserve/commit/release hot path, preserving a
213214

214215
End-to-end HTTP latency measured with `CyclesProtocolBenchmarkTest` (Spring Boot + Jedis + Redis 7 via Testcontainers). 200 measured iterations after 50 warmup iterations per operation.
215216

216-
| Operation | p50 | p95 | p99 | min | max | mean |
217-
|-------------------|--------|--------|--------|--------|--------|--------|
218-
| Reserve | 5.2ms | 6.0ms | 6.4ms | 4.0ms | 6.8ms | 5.2ms |
219-
| Commit | 4.1ms | 4.7ms | 5.2ms | 2.6ms | 5.3ms | 4.1ms |
220-
| Release | 4.4ms | 5.6ms | 6.6ms | 3.5ms | 14.0ms | 4.5ms |
221-
| Extend | 8.5ms | 10.7ms | 11.4ms | 7.0ms | 21.4ms | 8.7ms |
222-
| Decide | 5.8ms | 6.6ms | 7.6ms | 4.5ms | 15.4ms | 5.8ms |
223-
| Event | 5.2ms | 6.1ms | 10.0ms | 3.9ms | 20.7ms | 5.4ms |
224-
| Reserve + Commit | 12.2ms | 14.1ms | 16.7ms | 10.6ms | 21.5ms | 12.5ms |
225-
| Reserve + Release | 10.3ms | 12.7ms | 14.0ms | 8.4ms | 20.6ms | 10.6ms |
217+
#### Single-Threaded Latency
218+
219+
| Operation | p50 | p95 | p99 | min | max | mean |
220+
|---------------------|--------|--------|--------|--------|--------|--------|
221+
| Reserve | 6.1ms | 7.9ms | 8.5ms | 4.8ms | 13.7ms | 6.3ms |
222+
| Commit | 5.0ms | 6.7ms | 7.1ms | 3.4ms | 7.2ms | 5.2ms |
223+
| Release | 5.2ms | 6.0ms | 6.5ms | 3.9ms | 6.7ms | 5.2ms |
224+
| Extend | 7.6ms | 9.7ms | 12.0ms | 5.8ms | 17.2ms | 7.8ms |
225+
| Decide | 6.9ms | 8.1ms | 10.4ms | 5.5ms | 16.0ms | 7.0ms |
226+
| Event | 5.1ms | 6.7ms | 7.2ms | 3.6ms | 8.8ms | 5.2ms |
227+
| Reserve + Commit | 14.7ms | 17.8ms | 19.9ms | 11.2ms | 20.4ms | 14.9ms |
228+
| Reserve + Release | 11.7ms | 14.4ms | 17.4ms | 9.6ms | 20.2ms | 11.9ms |
229+
230+
#### Concurrent Throughput (Reserve→Commit lifecycle)
231+
232+
| Threads | Total Ops | Ops/sec | p50 | p95 | p99 | min | max | Errors |
233+
|---------|-----------|----------|---------|---------|---------|--------|---------|--------|
234+
| 8 | 4,023 | 804.6 | 9.7ms | 11.8ms | 17.9ms | 7.1ms | 33.7ms | 0 |
235+
| 16 | 5,506 | 1,101.2 | 14.2ms | 19.8ms | 23.9ms | 6.8ms | 28.8ms | 0 |
236+
| 32 | 12,416 | 2,483.2 | 11.6ms | 21.4ms | 35.2ms | 6.9ms | 65.8ms | 0 |
237+
238+
#### Analysis
239+
240+
**Phase 2 optimization impact (Extend & Event Lua balance snapshots):**
241+
242+
| Operation | Before (p50) | After (p50) | Before (p99) | After (p99) | Change |
243+
|-----------|-------------|-------------|-------------|-------------|--------|
244+
| Extend | 8.5ms | 7.6ms | 11.4ms | 12.0ms | p50 -11%, tail similar |
245+
| Event | 5.2ms | 5.1ms | 10.0ms | 7.2ms | p50 flat, **p99 -28%** |
246+
247+
- **Extend** p50 improved from 8.5ms to 7.6ms by eliminating the pre-Lua HMGET prefetch round-trip. The improvement is smaller than predicted (~5ms) because the Lua-side balance snapshot collection adds overhead that partially offsets the saved Java round-trip. Extend remains the slowest single operation because it still does more Redis commands inside Lua (read reservation fields + read all scope budgets + write TTL updates) than other operations.
248+
- **Event** p99 improved significantly from 10.0ms to 7.2ms (28% reduction). The variable-cost Java-side `fetchBalancesForScopes()` pipeline was the main tail latency driver — moving it into Lua eliminated the per-scope RTT variability. p50 was unchanged since simple single-scope events were already fast.
249+
250+
**Concurrent scaling observations:**
251+
- Near-linear throughput scaling from 8→32 threads (805 → 2,483 ops/s, 3.1x at 4x threads)
252+
- Zero errors at all concurrency levels — Redis connection pool (max 50) is not a bottleneck
253+
- p50 latency at 32 threads (11.6ms) is lower than at 16 threads (14.2ms), suggesting connection pool warm-up effects
254+
- p99 tail grows with concurrency (17.9ms → 35.2ms) due to Redis Lua script serialization and connection pool contention
255+
- Max latency at 32 threads (65.8ms) indicates occasional GC pauses or connection pool waits
226256

227257
**Notes:**
228258
- Results are from a containerized CI environment (Testcontainers Redis 7-Alpine, localhost networking). Production with dedicated Redis will be faster.
229259
- Latencies include full HTTP round-trip: Spring Boot request handling, auth filter, JSON serialization, Redis EVALSHA, Lua execution, response building.
230260
- The BCrypt cache eliminates ~100ms+ from all operations after the first request per API key (60s cache window).
231-
- Run benchmarks: `mvn test -Dgroups=benchmark` (requires Docker)
261+
- Run benchmarks: `mvn test -Pbenchmark` (requires Docker)
262+
- Benchmarks are excluded from default `mvn verify` builds via `<excludedGroups>benchmark</excludedGroups>` in surefire config
263+
264+
### Production Hardening (Phase 2 audit)
265+
266+
Code review of all changes identified and fixed four defensive issues:
267+
268+
1. **All Lua scripts: `cjson.decode` crash on corrupted Redis data** — If `affected_scopes` or `budgeted_scopes` stored in a reservation hash contains malformed JSON, `cjson.decode` would crash the Lua script with an unhandled error. Fixed with `pcall(cjson.decode, ...)` wrappers in all five mutation scripts:
269+
- `extend.lua`: returns empty balances on decode failure
270+
- `commit.lua`: returns `INTERNAL_ERROR` on decode failure
271+
- `release.lua`: returns `INTERNAL_ERROR` on decode failure
272+
- `expire.lua`: silently skips budget adjustment (background sweep must not get stuck on corrupted data; reservation still expires)
273+
274+
2. **Java `valueOf` crash on invalid `estimate_unit`**`Enums.UnitEnum.valueOf(estimateUnitStr)` in `extendReservation()` would throw `IllegalArgumentException` if Redis contained a corrupted unit string. Fixed with try-catch fallback to `USD_MICROCENTS`.
275+
276+
3. **Concurrent benchmark thread leak and CI flakiness**`ExecutorService` wasn't cleaned up on timeout (thread leak risk in CI). Hard `errors == 0` assertion would fail on transient CI issues. Fixed with try/finally + `shutdownNow()`, and replaced zero-error assertion with <1% error rate threshold.
277+
278+
**Items reviewed and confirmed correct (no fix needed):**
279+
- `luaScripts.eval()` return value — Lua scripts always return via `cjson.encode()`, never nil
280+
- Event idempotency replay returns empty balances — consistent with commit/release pattern; `parseLuaBalances()` handles gracefully
281+
- `fetchBalancesForScopes()` still used in reserve idempotency-hit fallback path — not dead code
282+
- Thread safety: all caches use `ConcurrentHashMap`, `ThreadLocal<MessageDigest>` for digests, Jedis connections scoped to try-with-resources
283+
- Balance snapshot ordering: collected after mutations in all Lua scripts
284+
- Percentile calculations: mathematically correct with bounds checking
285+
- Redis pool size (50) / timeout (2s) — deployment tuning, configurable via RedisConfig
286+
- Cache race conditions in `ApiKeyRepository` and `LuaScriptRegistry``ConcurrentHashMap` ops are atomic; duplicate work is harmless
232287

233288
---
234289

cycles-protocol-service/cycles-protocol-service-api/pom.xml

Lines changed: 17 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -74,6 +74,7 @@
7474
<excludes>
7575
<exclude>**/*IntegrationTest.java</exclude>
7676
</excludes>
77+
<excludedGroups>benchmark</excludedGroups>
7778
</configuration>
7879
</plugin>
7980
</plugins>
@@ -93,5 +94,21 @@
9394
</plugins>
9495
</build>
9596
</profile>
97+
<profile>
98+
<id>benchmark</id>
99+
<build>
100+
<plugins>
101+
<plugin>
102+
<groupId>org.apache.maven.plugins</groupId>
103+
<artifactId>maven-surefire-plugin</artifactId>
104+
<configuration>
105+
<excludes combine.self="override" />
106+
<excludedGroups combine.self="override" />
107+
<groups>benchmark</groups>
108+
</configuration>
109+
</plugin>
110+
</plugins>
111+
</build>
112+
</profile>
96113
</profiles>
97114
</project>

cycles-protocol-service/cycles-protocol-service-api/src/test/java/io/runcycles/protocol/api/CyclesProtocolBenchmarkTest.java

Lines changed: 3 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -2,6 +2,7 @@
22

33
import org.junit.jupiter.api.*;
44
import org.springframework.http.ResponseEntity;
5+
import org.springframework.test.context.ActiveProfiles;
56

67
import java.util.*;
78
import java.util.stream.LongStream;
@@ -17,10 +18,11 @@
1718
* Results are environment-dependent (CI vs local, container overhead, etc.).
1819
* Use these numbers as relative guidance, not absolute SLA targets.
1920
*
20-
* Run separately: mvn test -Dgroups=benchmark
21+
* Run separately: mvn test -Pbenchmark
2122
*/
2223
@DisplayName("Performance Benchmarks")
2324
@Tag("benchmark")
25+
@ActiveProfiles({"test", "benchmark"})
2426
class CyclesProtocolBenchmarkTest extends BaseIntegrationTest {
2527

2628
private static final int WARMUP_ITERATIONS = 50;
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,197 @@
1+
package io.runcycles.protocol.api;
2+
3+
import org.junit.jupiter.api.*;
4+
import org.springframework.http.ResponseEntity;
5+
import org.springframework.test.context.ActiveProfiles;
6+
7+
import java.util.*;
8+
import java.util.concurrent.*;
9+
import java.util.concurrent.atomic.AtomicBoolean;
10+
import java.util.concurrent.atomic.AtomicInteger;
11+
12+
import static org.assertj.core.api.Assertions.assertThat;
13+
14+
/**
15+
* Concurrent load benchmarks for Cycles Protocol operations.
16+
*
17+
* Measures throughput (ops/sec) and latency under concurrent load by running
18+
* multiple threads executing Reserve→Commit lifecycles simultaneously.
19+
*
20+
* Tests ramp from 8 → 16 → 32 concurrent threads to reveal contention
21+
* at the Redis connection pool (max 50), Lua script execution, and
22+
* Spring Boot request processing layers.
23+
*
24+
* Results are CI-environment sensitive — latency and throughput depend on
25+
* container resources, Redis container networking, and JVM warm-up.
26+
*
27+
* Run separately: mvn test -Pbenchmark
28+
*/
29+
@DisplayName("Concurrent Load Benchmarks")
30+
@Tag("benchmark")
31+
@TestMethodOrder(MethodOrderer.OrderAnnotation.class)
32+
@ActiveProfiles({"test", "benchmark"})
33+
class CyclesProtocolConcurrentBenchmarkTest extends BaseIntegrationTest {
34+
35+
private static final int WARMUP_OPS = 50;
36+
private static final long MEASURE_DURATION_MS = 5_000;
37+
/** Max acceptable error rate (%) before failing the test */
38+
private static final double MAX_ERROR_RATE_PERCENT = 1.0;
39+
40+
private static final List<ConcurrencyResult> ALL_RESULTS = new ArrayList<>();
41+
42+
record ConcurrencyResult(int threads, long totalOps, double opsPerSec,
43+
long p50, long p95, long p99, long min, long max, int errors) {}
44+
45+
@AfterAll
46+
static void printSummary() {
47+
if (ALL_RESULTS.isEmpty()) return;
48+
49+
System.out.println();
50+
System.out.println("+----------+----------+-----------+--------+--------+--------+--------+--------+--------+");
51+
System.out.println("| Threads | Total Ops| Ops/sec | p50 | p95 | p99 | min | max | Errors |");
52+
System.out.println("+----------+----------+-----------+--------+--------+--------+--------+--------+--------+");
53+
for (ConcurrencyResult r : ALL_RESULTS) {
54+
System.out.printf("| %8d | %8d | %9.1f | %5.1fms| %5.1fms| %5.1fms| %5.1fms| %5.1fms| %6d |%n",
55+
r.threads, r.totalOps, r.opsPerSec,
56+
r.p50 / 1_000_000.0, r.p95 / 1_000_000.0, r.p99 / 1_000_000.0,
57+
r.min / 1_000_000.0, r.max / 1_000_000.0, r.errors);
58+
}
59+
System.out.println("+----------+----------+-----------+--------+--------+--------+--------+--------+--------+");
60+
System.out.printf(" Duration per level: %ds (after %d warmup ops)%n",
61+
MEASURE_DURATION_MS / 1000, WARMUP_OPS);
62+
System.out.println();
63+
}
64+
65+
@Test
66+
@Order(1)
67+
@DisplayName("Reserve→Commit lifecycle at 8 threads")
68+
void concurrentLifecycle_8threads() throws Exception {
69+
runConcurrentLifecycle(8);
70+
}
71+
72+
@Test
73+
@Order(2)
74+
@DisplayName("Reserve→Commit lifecycle at 16 threads")
75+
void concurrentLifecycle_16threads() throws Exception {
76+
runConcurrentLifecycle(16);
77+
}
78+
79+
@Test
80+
@Order(3)
81+
@DisplayName("Reserve→Commit lifecycle at 32 threads")
82+
void concurrentLifecycle_32threads() throws Exception {
83+
runConcurrentLifecycle(32);
84+
}
85+
86+
private void runConcurrentLifecycle(int threadCount) throws Exception {
87+
// Re-seed budget with enough headroom for sustained concurrent load
88+
try (var jedis = jedisPool.getResource()) {
89+
seedBudget(jedis, TENANT_A, "TOKENS", 1_000_000_000L);
90+
}
91+
92+
// Warm up: sequential operations to prime JIT, connection pool, EVALSHA cache
93+
for (int i = 0; i < WARMUP_OPS; i++) {
94+
String resId = createReservationAndGetId(TENANT_A, API_KEY_SECRET_A, 100);
95+
post("/v1/reservations/" + resId + "/commit", API_KEY_SECRET_A, commitBody(80));
96+
}
97+
98+
ExecutorService executor = Executors.newFixedThreadPool(threadCount);
99+
try {
100+
ConcurrentLinkedQueue<Long> timings = new ConcurrentLinkedQueue<>();
101+
AtomicInteger errorCount = new AtomicInteger(0);
102+
CountDownLatch startLatch = new CountDownLatch(1);
103+
AtomicBoolean running = new AtomicBoolean(true);
104+
105+
// Submit worker tasks
106+
for (int t = 0; t < threadCount; t++) {
107+
executor.submit(() -> {
108+
try {
109+
startLatch.await();
110+
} catch (InterruptedException e) {
111+
Thread.currentThread().interrupt();
112+
return;
113+
}
114+
115+
while (running.get()) {
116+
long start = System.nanoTime();
117+
try {
118+
Map<String, Object> reserveBody = reservationBody(TENANT_A, 100);
119+
ResponseEntity<Map> reserveResp = post("/v1/reservations", API_KEY_SECRET_A, reserveBody);
120+
if (!reserveResp.getStatusCode().is2xxSuccessful()) {
121+
errorCount.incrementAndGet();
122+
continue;
123+
}
124+
String resId = (String) reserveResp.getBody().get("reservation_id");
125+
126+
ResponseEntity<Map> commitResp = post("/v1/reservations/" + resId + "/commit",
127+
API_KEY_SECRET_A, commitBody(80));
128+
if (!commitResp.getStatusCode().is2xxSuccessful()) {
129+
errorCount.incrementAndGet();
130+
continue;
131+
}
132+
133+
timings.add(System.nanoTime() - start);
134+
} catch (Exception e) {
135+
errorCount.incrementAndGet();
136+
}
137+
}
138+
});
139+
}
140+
141+
// Release all threads and measure for MEASURE_DURATION_MS
142+
startLatch.countDown();
143+
Thread.sleep(MEASURE_DURATION_MS);
144+
running.set(false);
145+
146+
// Wait for in-flight operations to complete
147+
executor.shutdown();
148+
if (!executor.awaitTermination(30, TimeUnit.SECONDS)) {
149+
executor.shutdownNow();
150+
}
151+
152+
// Collect and analyze results
153+
long[] sorted = timings.stream().mapToLong(Long::longValue).sorted().toArray();
154+
int totalOps = sorted.length;
155+
int errors = errorCount.get();
156+
double opsPerSec = totalOps / (MEASURE_DURATION_MS / 1000.0);
157+
158+
ConcurrencyResult result;
159+
if (totalOps > 0) {
160+
result = new ConcurrencyResult(threadCount, totalOps, opsPerSec,
161+
p(sorted, 50), p(sorted, 95), p(sorted, 99),
162+
sorted[0], sorted[sorted.length - 1], errors);
163+
} else {
164+
result = new ConcurrencyResult(threadCount, 0, 0, 0, 0, 0, 0, 0, errors);
165+
}
166+
167+
synchronized (ALL_RESULTS) {
168+
ALL_RESULTS.add(result);
169+
}
170+
171+
System.out.printf("[Concurrent] %2d threads: %d ops in %ds = %.1f ops/s p50=%.1fms p95=%.1fms p99=%.1fms errors=%d%n",
172+
threadCount, totalOps, MEASURE_DURATION_MS / 1000, opsPerSec,
173+
totalOps > 0 ? sorted[percentileIndex(sorted.length, 50)] / 1_000_000.0 : 0,
174+
totalOps > 0 ? sorted[percentileIndex(sorted.length, 95)] / 1_000_000.0 : 0,
175+
totalOps > 0 ? sorted[percentileIndex(sorted.length, 99)] / 1_000_000.0 : 0,
176+
errors);
177+
178+
// Allow small error rate for CI environment transient failures
179+
int totalAttempts = totalOps + errors;
180+
double errorRate = totalAttempts > 0 ? (errors * 100.0 / totalAttempts) : 0;
181+
assertThat(errorRate)
182+
.as("Error rate at %d threads (errors=%d, total=%d)", threadCount, errors, totalAttempts)
183+
.isLessThan(MAX_ERROR_RATE_PERCENT);
184+
assertThat(totalOps).as("Total ops at %d threads", threadCount).isGreaterThan(0);
185+
} finally {
186+
executor.shutdownNow();
187+
}
188+
}
189+
190+
private static long p(long[] sorted, int percentile) {
191+
return sorted[percentileIndex(sorted.length, percentile)];
192+
}
193+
194+
private static int percentileIndex(int length, int percentile) {
195+
return Math.min((int) Math.ceil(percentile / 100.0 * length) - 1, length - 1);
196+
}
197+
}
Lines changed: 6 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,6 @@
1+
# Benchmark profile — suppress all logging so only benchmark result tables are visible
2+
logging.level.root=WARN
3+
logging.level.io.runcycles.protocol=WARN
4+
logging.level.org.springframework=WARN
5+
logging.level.org.testcontainers=WARN
6+
logging.level.com.github.dockerjava=WARN

0 commit comments

Comments
 (0)