grpc-timeout deadline is computed incorrectly in PbjProtocolHandler.scheduleDeadline (integer overflow)
- Dominant language
- Java
- Stars
- 44
- Forks
- 15
- Avg merge
- 1d 15h
- Merged PRs (30d)
- 12
Description
## Description
`PbjProtocolHandler.scheduleDeadline(String timeout)` computes the scheduled deadline by **multiplying**
`System.nanoTime()` by the requested timeout duration, instead of using the duration alone:
```java
// pbj-core/pbj-grpc-helidon/src/main/java/com/hedera/pbj/grpc/helidon/PbjProtocolHandler.java:520-546
private ScheduledFuture scheduleDeadline(@NonNull final String timeout) {
final var matcher = GRPC_TIMEOUT_PATTERN.matcher(timeout);
if (matcher.matches()) {
final var num = Integer.parseInt(matcher.group(1));
final var unit = matcher.group(2);
final var deadline = System.nanoTime()
* TimeUnit.NANOSECONDS.convert(
num,
switch (unit) { /* H/M/S/m/u/n -> TimeUnit */ });
return deadlineDetector.scheduleDeadline(deadline, () -> {
route.deadlineExceededCounter().increment();
pipeline.onError(new GrpcException(GrpcStatus.DEADLINE_EXCEEDED));
});
}
return new NoopScheduledFuture<>();
}
```
The value passed to `deadlineDetector.scheduleDeadline(...)` is documented and implemented as a relative delay in
nanoseconds from now, not an absolute timestamp:
- `DeadlineDetector.scheduleDeadline` javadoc: *"@param deadlineNanos The deadline, in nanoseconds, from now."*
(`DeadlineDetector.java:14-25`)
- Its only implementation confirms this: `deadlineExecutorService.schedule(onDeadlineExceeded, deadline, TimeUnit.NANOSECONDS)`
(`PbjProtocolSelector.java:47-48`). `ScheduledExecutorService.schedule`'s `delay` parameter is documented as "the
time from now to delay execution", so it already expects a relative duration.
`System.nanoTime()` returns an arbitrary-origin, JVM-uptime-scale value, typically on the order of 10^17-10^18 on a
long-running JVM. Multiplying it by a nanosecond-converted duration overflows a signed 64-bit `long`, wrapping around
(two's-complement) to an essentially arbitrary value that can land on either side of zero depending on the exact
`System.nanoTime()` reading at request time. The correct computation is `TimeUnit.NANOSECONDS.convert(num, unit)`
alone.
**Impact.** Because the multiplication overflows and can wrap to a negative value, and
`ScheduledExecutorService.schedule` treats a non-positive delay as "run as soon as possible", the practical effect is
not simply "the deadline never fires"; it can be the opposite:
- **Negative overflow:** every request with a `grpc-timeout` header immediately receives `DEADLINE_EXCEEDED`,
regardless of the requested timeout or how fast the handler actually is.
- **Positive overflow:** the delay can land anywhere from near-zero to roughly 292 years, effectively never firing.
Which failure mode occurs is non-deterministic from the caller's side, since it depends on the server JVM's uptime
at the moment each request is handled, and could vary across requests, restarts, or environments. Client-side
deadline enforcement (e.g. an `io.grpc` client's own `Deadline` API) is unaffected, since that happens independently
of server behavior.
Worth checking whether any current consumer of `pbj-grpc-helidon` sets `grpc-timeout` in production. If so, this
would likely already be causing either spurious immediate `DEADLINE_EXCEEDED` errors or completely inert timeouts,
either of which seems like it should have surfaced already under another description.
## Steps to reproduce
Confirmed locally with the following JUnit test, added to
`pbj-core/pbj-grpc-helidon/src/test/java/com/hedera/pbj/grpc/helidon/PbjProtocolHandlerTest.java` (reusing that
class's existing `@BeforeEach`-populated fields: `streamWriter`, `streamId`, `flowControl`, `currentStreamState`,
`config`, `route`, `deadlineDetector`, `connectionContext`):
```
./gradlew --no-daemon :pbj-grpc-helidon:test --tests "com.hedera.pbj.grpc.helidon.PbjProtocolHandlerTest.validateDeadlineArithmetic"
```
```java
@Test
void validateDeadlineArithmetic() {
final var h = WritableHeaders.create();
h.add(HeaderNames.CONTENT_TYPE, "application/grpc");
h.add(GrpcHeaders.GRPC_TIMEOUT, "200m"); // 200 milliseconds
headers = Http2Headers.create(h);
final var capturedDeadlineNanos = new java.util.concurrent.atomic.AtomicLong(-1);
final DeadlineDetector capturingDetector = (deadlineNanos, onDeadlineExceeded) -> {
capturedDeadlineNanos.set(deadlineNanos);
return deadlineDetector.scheduleDeadline(deadlineNanos, onDeadlineExceeded);
};
final var handler = new PbjProtocolHandler(
headers, streamWriter, streamId, flowControl, currentStreamState,
config, route, capturingDetector, connectionContext);
handler.init();
final long expectedSaneNanos = java.util.concurrent.TimeUnit.MILLISECONDS.toNanos(200);
assertThat(capturedDeadlineNanos.get())
.as("deadlineNanos should be a sane relative delay (~200ms in nanos), not an astronomical number")
.isCloseTo(expectedSaneNanos, org.assertj.core.data.Offset.offset(50_000_000L));
}
```
The test wraps the real `DeadlineDetector` in a small capturing shim so the actual value
`PbjProtocolHandler.scheduleDeadline` computes can be inspected directly, with no network round trip or sleeping
needed.
**Output from a local run (`0.15.0-SNAPSHOT`, `main`):**
```
Requested grpc-timeout: 200m (200 milliseconds)
Expected sane deadlineNanos (correct impl): 200000000
Actual captured deadlineNanos (current impl): -3914286614520416768
Ratio (actual / expected): -1.9571433072602085E10
java.lang.AssertionError: [deadlineNanos should be a sane relative delay (~200ms in nanos), not an astronomical number]
Expecting actual:
-3914286614520416768L
to be close to:
200000000L
by less than 50000000L but difference was 3914286614720416768L.
```
Re-running will very likely reproduce a similarly wrong value each time. The exact number differs run-to-run since
it's derived from `System.nanoTime()`, but it will not land within a reasonable tolerance of the correct
~200,000,000ns value.
**Why the existing test suite doesn't already catch this:**
- `PbjProtocolHandlerTest.java:676-681` substitutes a `DeadlineDetectorStub` that overrides `scheduleDeadline`
entirely, so the real arithmetic in `PbjProtocolHandler.scheduleDeadline(String)` is never exercised.
- `PbjTest.java`'s `DeadlineTests.deadlineExceeded` (~line 399-426) uses an `io.grpc` client with
`Deadline.after(1, TimeUnit.NANOSECONDS)` against a handler that sleeps 1 second. That 1-nanosecond deadline is
enforced locally by the `io.grpc` client library itself, independent of server behavior, so the test passes
regardless of whether the server's own deadline math is correct. It does not exercise the server's
`DeadlineDetector` path with a realistic timeout at all.
## Additional context
Suggested fix: replace
```java
final var deadline = System.nanoTime()
* TimeUnit.NANOSECONDS.convert(num, unit);
```
with
```java
final var deadline = TimeUnit.NANOSECONDS.convert(num, unit);
```
and add a permanent regression test that exercises the real `PbjProtocolSelector`-constructed `DeadlineDetector`
(backed by an actual `ScheduledExecutorService`, not a stub) with a mid-sized timeout against a deliberately slow
handler, asserting `DEADLINE_EXCEEDED` arrives within a bounded window well short of the handler's own completion
time.
## Hedera network
N/A. This is a library-level bug in `pbj-grpc-helidon` request handling, not specific to any Hedera network
(mainnet/testnet/previewnet). It would affect any service built on this library regardless of which network it
talks to.
## Version
`0.15.0-SNAPSHOT` (current `pbj-core/version.txt` on `main`). Which released version(s) are affected hasn't been
determined; a `git blame` on `PbjProtocolHandler.java:520-546` would establish when this was introduced.
## Operating system
N/A / Any. This is pure JVM arithmetic (`System.nanoTime()`, `TimeUnit` conversion), not OS-dependent.
Contributor guide
Research direction
Start in pbj-core/pbj-grpc-helidon/src/main/java/com/hedera/pbj/grpc/helidon/PbjProtocolHandler.java at scheduleDeadline(String), then read DeadlineDetector and PbjProtocolSelector to confirm the delay contract. Run the named validateDeadlineArithmetic test in PbjProtocolHandlerTest; done means a 200m timeout produces a sane relative delay and a regression test covers the real deadline path.
Written by the indexing model from the issue text.
Assessment
- Tech stack
- grpc, java
- Domain
- api, backend, testing
- Issue type
- Bug
- Difficulty
- 2/5
- Estimated time
- 1-3 hours
- Activity status
- Active
- Clarity
- Clearly specified
- Newbie friendliness
- 88/100