Issue Details
The Subscriber keepalive pings the server every 30s, but the monitor that watches
for the answer times out after 15s. The two values can't work together, and the
stream gets torn down on every ping the server doesn't answer.
This is a follow-up to googleapis/java-pubsub#2651,
which I can't comment on since that repo is archived. That issue was closed by
googleapis/java-pubsub#2652, which disabled the keepalive and lowered the log to
INFO. googleapis/java-pubsub#2672 re-enabled the keepalive. The log level stayed
at INFO, but the timing was never looked at, and I think that's the real problem.
In StreamingSubscriberConnection:
private static final Duration CLIENT_PING_INTERVAL = Duration.ofSeconds(30);
private static final Duration SERVER_MONITOR_INTERVAL = Duration.ofSeconds(10);
private static final Duration SERVER_PING_TIMEOUT_DURATION = Duration.ofSeconds(15);
The monitor measures the time since the last ping, and every ping resets that
clock:
Duration elapsedSincePing = Duration.ofNanos(now - lastPing);
if (elapsedSincePing.compareTo(SERVER_PING_TIMEOUT_DURATION) < 0) {
return;
}
So with a ping every 30s and a 15s tolerance, a ping the server doesn't answer
tears the stream down ~20s later, before the next ping ever happens. Lowering
CLIENT_PING_INTERVAL below 15s doesn't fix it either, it just makes the check
unreachable. Either way the two constants don't line up.
Two ways to fix it as far as I can see:
- make
SERVER_PING_TIMEOUT_DURATION larger than CLIENT_PING_INTERVAL
- or track the oldest unanswered ping instead of the last one, so a new ping
doesn't reset the timeout
Happy to send a PR, just let me know which one you'd prefer.
Environment
Required: Provide details about your environment. If relevant, please also provide details about your GCP environment. The environment details MUST be filled out.
Provide the relevant details about your environment:
- OS Type and Version: Ubuntu 24.04.5 LTS (kernel 6.8.0-139), and Docker
eclipse-temurin:21-jre for the deployed services
- Java Version and JDK Vendor: 21.0.5, Temurin 21.0.5+11 LTS
- (If using GraalVM) GraalVM Version: not used
Dependencies
Relevant part of mvn dependency:tree:
com.google.cloud:spring-cloud-gcp-starter-pubsub:jar:7.4.10:compile
+- com.google.cloud:spring-cloud-gcp-starter:jar:7.4.10:compile
| +- com.google.cloud:spring-cloud-gcp-core:jar:7.4.10:compile
| | \- com.google.cloud:google-cloud-core:jar:2.72.0:compile
| \- com.google.cloud:spring-cloud-gcp-autoconfigure:jar:7.4.10:compile
\- com.google.cloud:spring-cloud-gcp-pubsub:jar:7.4.10:compile
\- com.google.cloud:google-cloud-pubsub:jar:1.152.0:compile
+- com.google.auth:google-auth-library-oauth2-http:jar:1.49.0:compile
+- com.google.auth:google-auth-library-credentials:jar:1.49.0:compile
+- com.google.http-client:google-http-client-gson:jar:2.1.1:compile
+- com.google.api:gax:jar:2.82.0:compile
+- com.google.api:gax-grpc:jar:2.82.0:compile
+- io.grpc:grpc-core:jar:1.81.0:compile
+- com.google.api:gax-httpjson:jar:2.82.0:compile
\- com.google.http-client:google-http-client:jar:2.1.1:compile
Versions:
- Libraries-Bom: 26.85.0, pulled in by spring-cloud-gcp-dependencies 7.4.10
- google-cloud-pubsub: 1.152.0
- Gax: gax 2.82.0 / gax-grpc 2.82.0 / gax-httpjson 2.82.0
- Auth: google-auth-library-oauth2-http 1.49.0 / google-auth-library-credentials 1.49.0
- Google-Http-Java-Client: 2.1.1
- grpc-core: 1.81.0
Reproducer
I don't have a standalone reproducer to attach. The steps below are what I get
from reading the code, and they match what another user described on
googleapis/java-pubsub#2651 after the keepalive was re-enabled.
Steps to reproduce:
- Start the Pub/Sub emulator, which doesn't answer the keepalive ping
- Create a topic and a subscription
- Start a
Subscriber on that subscription and leave it idle
- Watch the logs from
com.google.cloud.pubsub.v1.StreamingSubscriberConnection
The log shows up every ~30s per subscriber thread, and the stream is closed with
Status.UNAVAILABLE / "Keepalive timeout with server" each time.
The same happens against real Pub/Sub, but only when a ping goes unanswered, so
it's occasional rather than constant.
Logs and Stack Trace
The line is logged by com.google.cloud.pubsub.v1.StreamingSubscriberConnection
at INFO and looks like this:
INFO: No response from server for 15 seconds since last ping. Closing stream.
There is no stack trace: the stream is closed on purpose by the monitor, with
clientStream.closeSendWithError(
Status.UNAVAILABLE.withDescription("Keepalive timeout with server").asException());
Behavior
Optional: Any additional information about the behavior of the error is helpful to debug.
Behavioral Questions:
Issue Details
The Subscriber keepalive pings the server every 30s, but the monitor that watches
for the answer times out after 15s. The two values can't work together, and the
stream gets torn down on every ping the server doesn't answer.
This is a follow-up to googleapis/java-pubsub#2651,
which I can't comment on since that repo is archived. That issue was closed by
googleapis/java-pubsub#2652, which disabled the keepalive and lowered the log to
INFO. googleapis/java-pubsub#2672 re-enabled the keepalive. The log level stayed
at INFO, but the timing was never looked at, and I think that's the real problem.
In
StreamingSubscriberConnection:The monitor measures the time since the last ping, and every ping resets that
clock:
So with a ping every 30s and a 15s tolerance, a ping the server doesn't answer
tears the stream down ~20s later, before the next ping ever happens. Lowering
CLIENT_PING_INTERVALbelow 15s doesn't fix it either, it just makes the checkunreachable. Either way the two constants don't line up.
Two ways to fix it as far as I can see:
SERVER_PING_TIMEOUT_DURATIONlarger thanCLIENT_PING_INTERVALdoesn't reset the timeout
Happy to send a PR, just let me know which one you'd prefer.
Environment
Required: Provide details about your environment. If relevant, please also provide details about your GCP environment. The environment details MUST be filled out.
Provide the relevant details about your environment:
eclipse-temurin:21-jrefor the deployed servicesDependencies
Relevant part of
mvn dependency:tree:Versions:
Reproducer
I don't have a standalone reproducer to attach. The steps below are what I get
from reading the code, and they match what another user described on
googleapis/java-pubsub#2651 after the keepalive was re-enabled.
Steps to reproduce:
Subscriberon that subscription and leave it idlecom.google.cloud.pubsub.v1.StreamingSubscriberConnectionThe log shows up every ~30s per subscriber thread, and the stream is closed with
Status.UNAVAILABLE/ "Keepalive timeout with server" each time.The same happens against real Pub/Sub, but only when a ping goes unanswered, so
it's occasional rather than constant.
Logs and Stack Trace
The line is logged by
com.google.cloud.pubsub.v1.StreamingSubscriberConnectionat INFO and looks like this:
There is no stack trace: the stream is closed on purpose by the monitor, with
Behavior
Optional: Any additional information about the behavior of the error is helpful to debug.
Behavioral Questions:
the keepalive (feat: Enable Subscriber StreamingPull keepalives by increasing the StreamingPull protocol version java-pubsub#2672). It was quiet between 1.144.1 and
1.146.x because the keepalive was disabled there.
production.
subscriptions.