getResult(timeout) busy-loops GetWorkflowExecutionHistory in the last second before the timeout (server 1.29+)
Maintainer thường phản hồi trong vòng 1 ngày
Chưa có ai nhận issue này.
Đánh giá
- Độ khó
- 4/5
- Thời gian dự kiến
- 3-5 ngày
- Mức phù hợp với người mới
- 55/100
- Loại issue
- Lỗi
- Độ rõ ràng
- Đặc tả rõ ràng
- Mức độ hoạt động
- Sôi nổi
- Công nghệ
- java
- Lĩnh vực
- backend-api-design
Hướng nghiên cứu
Start with WorkflowClientLongPollHelper.getInstanceCloseEvent and WorkflowClientLongPollAsyncHelper.getInstanceCloseEventAsync, identified in the issue, and trace how empty poll responses are retried against the shared deadline. The issue proposes a minimum interval between empty polls for both paths and a fake-client unit test that mimics the server soft timeout. Done means the test passes, requests are paced without exceeding the deadline, and the sync and async paths are covered.
Do mô hình lập chỉ mục viết ra từ nội dung của issue.
Mô tả
When WorkflowStub.getResult(timeout, unit, ...) (or getResultAsync) waits on a workflow that doesn't complete within the timeout, the SDK re-sends GetWorkflowExecutionHistory back to back, with no delay, for the last second before the deadline. Against a local dev server, a single 2s wait that times out sends roughly 3,000-4,000 history requests. The same code sends 1 request against server 1.28.0, so this looks like a regression that started with server 1.29.0.
With several callers waiting at the same time, the burst also hits the namespace rate limit. getResult then fails with RESOURCE_EXHAUSTED instead of throwing TimeoutException, and it returns later than the requested timeout.
Expected Behavior
getResult(2, TimeUnit.SECONDS, ...) on a workflow that is still running should wait with one or two history long polls and throw TimeoutException after 2 seconds. This is what happens against server 1.28.0 (1 request).
Actual Behavior
GetWorkflowExecutionHistory calls for a single getResult(2s) that times out on a running workflow:
| Server | SDK | GetWorkflowExecutionHistory calls |
|---|---|---|
| 1.28.0 | 1.40.0 | 1 |
| 1.30.1 | 1.38.0 | ~3,800-4,300 |
| 1.32.0 | 1.40.0 | ~2,900-4,000 |
- The calls are packed into the last second before the deadline, so the timeout value barely changes the count. 1s, 5s and 25s waits produced about 2,500-4,600 calls each.
getResultAsyncbehaves the same way (~3,800-4,000 calls).
With concurrent waiters (server 1.32.0, N threads each calling getResult(2s) twice on the same running workflow):
| Concurrent callers | Threw TimeoutException |
Failed with RESOURCE_EXHAUSTED |
|---|---|---|
| 3 | 0 of 6 | 6 of 6 |
| 10 | 1 of 20 | 19 of 20 |
| 20 | 4 of 40 | 36 of 40 |
The failed calls got a WorkflowServiceException caused by StatusRuntimeException: RESOURCE_EXHAUSTED: namespace rate limit exceeded after 2.0-2.9 seconds. In one run, a call failed with service rate limit exceeded instead. Other calls in the same namespace (DescribeWorkflowExecution and a non-waiting GetWorkflowExecutionHistory) were not throttled in these runs.
We also saw this in production on a self-hosted cluster: every short getResult wait that timed out produced a few hundred history requests. It went away after we replaced getResult with describe() and a retry from the client.
Steps to Reproduce the Problem
- Start a dev server with Temporal CLI 1.9.1 (server 1.32.0):
temporal server start-dev - Run the program below with Java SDK 1.40.0.
- It prints something like
getResult(2s) timed out after 2004 ms, GetWorkflowExecutionHistory calls: 2981. - Against a dev server from Temporal CLI 1.4.1 (server 1.28.0), the same program prints
calls: 1.
Repro (single file, public APIs only)
import io.grpc.CallOptions;
import io.grpc.Channel;
import io.grpc.ClientCall;
import io.grpc.ClientInterceptor;
import io.grpc.MethodDescriptor;
import io.temporal.client.WorkflowClient;
import io.temporal.client.WorkflowOptions;
import io.temporal.client.WorkflowStub;
import io.temporal.serviceclient.WorkflowServiceStubs;
import io.temporal.serviceclient.WorkflowServiceStubsOptions;
import io.temporal.worker.WorkerFactory;
import io.temporal.workflow.Workflow;
import io.temporal.workflow.WorkflowInterface;
import io.temporal.workflow.WorkflowMethod;
import java.time.Duration;
import java.util.Collections;
import java.util.concurrent.TimeUnit;
import java.util.concurrent.TimeoutException;
import java.util.concurrent.atomic.AtomicInteger;
public class GetResultHistoryFloodRepro {
@WorkflowInterface
public interface SleepWorkflow {
@WorkflowMethod
void run();
}
public static class SleepWorkflowImpl implements SleepWorkflow {
@Override
public void run() {
Workflow.sleep(Duration.ofMinutes(5));
}
}
public static void main(String[] args) throws Exception {
AtomicInteger historyCalls = new AtomicInteger();
ClientInterceptor countHistoryCalls =
new ClientInterceptor() {
@Override
public <ReqT, RespT> ClientCall<ReqT, RespT> interceptCall(
MethodDescriptor<ReqT, RespT> method, CallOptions callOptions, Channel next) {
if ("GetWorkflowExecutionHistory".equals(method.getBareMethodName())) {
historyCalls.incrementAndGet();
}
return next.newCall(method, callOptions);
}
};
WorkflowServiceStubs service =
WorkflowServiceStubs.newServiceStubs(
WorkflowServiceStubsOptions.newBuilder()
.setTarget("127.0.0.1:7233")
.setGrpcClientInterceptors(Collections.singletonList(countHistoryCalls))
.build());
WorkflowClient client = WorkflowClient.newInstance(service);
WorkerFactory factory = WorkerFactory.newInstance(client);
factory.newWorker("repro").registerWorkflowImplementationTypes(SleepWorkflowImpl.class);
factory.start();
SleepWorkflow workflow =
client.newWorkflowStub(
SleepWorkflow.class,
WorkflowOptions.newBuilder()
.setTaskQueue("repro")
.setWorkflowId("repro-" + System.currentTimeMillis())
.build());
WorkflowClient.start(workflow::run);
WorkflowStub stub = WorkflowStub.fromTyped(workflow);
Thread.sleep(1000);
historyCalls.set(0);
long startedAt = System.nanoTime();
try {
stub.getResult(2, TimeUnit.SECONDS, Void.class);
} catch (TimeoutException expected) {
// The workflow sleeps for 5 minutes, so the wait times out.
}
System.out.printf(
"getResult(2s) timed out after %d ms, GetWorkflowExecutionHistory calls: %d%n",
(System.nanoTime() - startedAt) / 1_000_000, historyCalls.get());
stub.terminate("repro done");
factory.shutdownNow();
service.shutdownNow();
System.exit(0);
}
}
Specifications
- Version: Java SDK 1.40.0 (also reproduced with 1.38.0)
- Platform: macOS (Darwin 25.4.0, arm64), OpenJDK 25.0.2
- Server: Temporal CLI dev server 1.4.1 (server 1.28.0, not affected), 1.6.1 (server 1.30.1) and 1.9.1 (server 1.32.0)
- Regression: works as expected up to server 1.28.0. Starts with 1.29.0, which includes temporalio/temporal#8238.
Root cause
Since server 1.29.0, a GetWorkflowExecutionHistory long poll only waits until one second before the caller's deadline and then returns an empty response (temporalio/temporal#8238, "GetWorkflowExecutionHistory long poll soft timeout"). Once less than one second is left, the computed wait is zero and the server returns an empty response right away:
- https://github.com/temporalio/temporal/blob/e161e3bc28d4e86ce76ae5f83d12c2443e76cb8d/service/history/api/get_workflow_util.go#L190-L191
- https://github.com/temporalio/temporal/blob/e161e3bc28d4e86ce76ae5f83d12c2443e76cb8d/common/contextutil/deadline.go#L34-L36
- https://github.com/temporalio/temporal/blob/e161e3bc28d4e86ce76ae5f83d12c2443e76cb8d/common/constants.go#L36-L39
On the SDK side, WorkflowClientLongPollHelper.getInstanceCloseEvent uses the same overall deadline for every poll and sends the next request immediately after an empty response. getInstanceCloseEventAsync does the same:
- https://github.com/temporalio/sdk-java/blob/705c3bbe6685eb05c2d60294c8d9c05578e23dbe/temporal-sdk/src/main/java/io/temporal/internal/client/WorkflowClientLongPollHelper.java#L70-L113
- https://github.com/temporalio/sdk-java/blob/705c3bbe6685eb05c2d60294c8d9c05578e23dbe/temporal-sdk/src/main/java/io/temporal/internal/client/WorkflowClientLongPollAsyncHelper.java#L91-L101
Together, these turn the last second into a loop of "empty response, retry right away" until the deadline. The server change was meant to reduce connection churn, but when the remaining deadline is short it multiplies the number of requests instead.
Possible fix
In the SDK, keep a minimum interval (e.g. 100ms) between polls when the previous poll came back empty, without going past the deadline. Normal long polls, which return after several seconds, are not affected.
Results from a local test with this change applied to the sync path only:
| Case | Before | After |
|---|---|---|
getResult(2s) times out, server 1.32.0 |
~4,000 calls | 12 calls |
| Same, server 1.28.0 | 1 call | 1 call |
| 20 concurrent callers | 36 of 40 failed with RESOURCE_EXHAUSTED |
40 of 40 threw TimeoutException at 2s |
| Workflow completes during the last second | returned right away | returned up to 100ms later (15-51ms in our runs) |
The async path needs the same rule. Since the SDK still targets Java 8, I'd like to know the preferred way to schedule the delay there (for example, reusing an existing scheduler).
Another option is to change the server so that it doesn't answer immediately when the remaining time is below the buffer. That would cover every SDK, but it's a server change.
Workaround
Don't rely on getResult(timeout) timing out while handling a request. Check the status with describe() first and call getResult only for completed executions, or let the client retry. This is what we ended up doing.
If this direction sounds reasonable, I'm happy to open a PR with the sync and async changes and a unit test. The test uses a fake client that mimics the server's soft timeout; it fails on the current code and passes with the change.
- Ngôn ngữ chính
- Java
- Star
- 433
- Fork
- 257
- Merge trung bình
- 2 ngày 18 giờ
- Pull request đã merge (30 ngày)
- 24
Chuẩn bị môi trường
- Không có Dockerfile hay tệp Docker Compose
- Không có mẫu pull request
- Đọc hướng dẫn đóng góp
Bắt đầu từ đâu
- Đọc hết issue, rồi đọc hướng dẫn đóng góp của dự án.
- Bình luận trên issue rằng bạn sẽ nhận — tránh hai người làm cùng một việc.
- Fork repository và làm thay đổi trên một nhánh.
- Mở pull request có tham chiếu số hiệu của issue.
Issue khác của temporalio/sdk-java
-
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 78/100
temporalio/sdk-java#3134 ·
Maintainer thường phản hồi trong vòng 1 ngày
-
enhancement
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 65/100
temporalio/sdk-java#1825 ·
Maintainer thường phản hồi trong vòng 1 ngày
-
enhancement
Độ khó 4/5 3-5 ngày Mức phù hợp với người mới 54/100
temporalio/sdk-java#3125 · 2 bình luận ·
Maintainer thường phản hồi trong vòng 1 ngày
-
enhancement
Độ khó 3/5 1-2 ngày Mức phù hợp với người mới 55/100
temporalio/sdk-java#3124 ·
Maintainer thường phản hồi trong vòng 1 ngày
-
enhancement
Độ khó 5/5 Hơn một tuần Mức phù hợp với người mới 35/100
temporalio/sdk-java#3122 ·
Maintainer thường phản hồi trong vòng 1 ngày
Tất cả issue của temporalio/sdk-java
Issue tương tự
-
waiting-for-triage
Độ khó 1/5 Dưới một giờ Mức phù hợp với người mới 72/100
spring-cloud/spring-cloud-openfeign#1443 ·
Maintainer thường phản hồi trong vòng 1 ngày
-
Độ khó 1/5 1-3 giờ Mức phù hợp với người mới 84/100
ADORSYS-GIS/keycloak-oid4vp-plugin#221 ·
Maintainer thường phản hồi trong vòng 2 ngày
-
Upgrade to Spring Pulsar 2.0.8Đang mởstatus: team-only type: dependency-upgrade
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 65/100
spring-projects/spring-boot#52099 ·
Maintainer thường phản hồi trong vòng 1 ngày
-
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 67/100
tchiotludo/akhq#3307 · 1 reaction ·
Maintainer thường phản hồi trong vòng 1 ngày
-
Độ khó 2/5 1-3 giờ Mức phù hợp với người mới 75/100
objectionary/jeo-maven-plugin#1885 ·
Maintainer thường phản hồi trong vòng 4 ngày