Errors reported on Temporal server with heavy load but workflows succeed

Community Support
1

I did a performance test on temporal server(1.17.0), and met the error below:

{"level":"error","ts":"2022-08-11T11:31:03.813Z","msg":"unavailable error","operation":"StartWorkflowExecution","wf-namespace":"default","error":"Workflow execution creation condition failed. workflow ID: testing-sc80852022539433b9b37818, current run ID: 98504757-e18e-4dac-a118-62f1c4b0f6c3, request run ID: 100e3716-33da-4468-8de6-0ba9118dab4a","logging-call-at":"telemetry.go:280","stacktrace":"go.temporal.io/server/common/log.(*zapLogger).Error\n\t/home/builder/temporal/common/log/zap_logger.go:142\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).handleError\n\t/home/builder/temporal/common/rpc/interceptor/telemetry.go:280\ngo.temporal.io/server/common/rpc/interceptor.(*TelemetryInterceptor).Intercept\n\t/home/builder/temporal/common/rpc/interceptor/telemetry.go:144\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1120\ngo.temporal.io/server/common/metrics.NewServerMetricsTrailerPropagatorInterceptor.func1\n\t/home/builder/temporal/common/metrics/grpc.go:113\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1120\ngo.temporal.io/server/common/metrics.NewServerMetricsContextInjectorInterceptor.func1\n\t/home/builder/temporal/common/metrics/grpc.go:66\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1120\ngo.temporal.io/server/common/rpc.ServiceErrorInterceptor\n\t/home/builder/temporal/common/rpc/grpc.go:132\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1.1\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1120\ngoogle.golang.org/grpc.chainUnaryInterceptors.func1\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1122\ngo.temporal.io/server/api/historyservice/v1._HistoryService_StartWorkflowExecution_Handler\n\t/home/builder/temporal/api/historyservice/v1/service.pb.go:1027\ngoogle.golang.org/grpc.(*Server).processUnaryRPC\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1283\ngoogle.golang.org/grpc.(*Server).handleStream\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:1620\ngoogle.golang.org/grpc.(*Server).serveStreams.func1.2\n\t/go/pkg/mod/google.golang.org/grpc@v1.47.0/server.go:922"}
{"level":"info","ts":"2022-08-11T11:31:03.813Z","msg":"history client encountered error","service":"frontend","error":"Workflow execution creation condition failed. workflow ID: testing-sc80852022539433b9b37818, current run ID: 98504757-e18e-4dac-a118-62f1c4b0f6c3, request run ID: 100e3716-33da-4468-8de6-0ba9118dab4a","service-error-type":"serviceerror.Unavailable","logging-call-at":"metricClient.go:683"}
{"level":"info","ts":"2022-08-11T11:31:03.916Z","msg":"Workflow task not found","service":"matching","component":"matching-engine","wf-task-queue-name":"/_sys/jdbc-query-task-q/1","wf-namespace-id":"60cc7349-1933-4558-b5cb-ca154b0beea6","wf-id":"o68a57ee097f044c0aaf7f7b","wf-run-id":"00d3c6c4-80dc-4913-a636-b667a60193d5","wf-task-queue-name":"/_sys/jdbc-query-task-q/1","queue-task-id":59600612,"queue-task-visibility-timestamp":"2022-08-11T11:31:01.959Z","wf-history-event-id":2,"error":"Workflow task not found.","logging-call-at":"matchingEngine.go:429"}

It’s thrown frequently, but the workflows all complete successfully.
What does this error mean?
And can we get rid of it? Anyway frequently thrown exceptions would affect the performance and throughput.

2

Workflow execution creation condition failed. workflow ID: testing-sc80852022539433b9b37818, current run ID: 98504757-e18e-4dac-a118-62f1c4b0f6c3, request run ID: 100e3716-33da-4468-8de6-0ba9118dab4a"

Can you see if this happens on your tests when trying to create workflow executions?
The error log is raised here
and can happen when you try to request start execution for a workflow id where there is an execution with that workflow id already running.

Temporal does not allow two running executions to have the same workflow id (in the same namespace) at the same time.

1 Like
3

@tihomir
Yes, I use multiple threads to trigger the same workflow, then there exist workflow executions with the same workflow ID.
What I am curious about is, when this error happens, how the workflow execution is processed? In my test it seems the workflow execution returns successfully, then where comes its result? from the previous running execution? If so I think that is a reasonable behavior and we need not throw the error, at least under some specific policy we can allow this behavior.

4

from the previous running execution?

Yes from the currently running execution. Which SDK are you using?
The call to start new workflow execution should fail, but with GO SDK for example, ExecuteWorkflow would attach itself to the currently running execution if there is one with the same wfid.

5

Java SDK I use, with version 1.14.0。

6

Can you share how you are starting your “exit” execution with same id?

WorkflowClient.start(myWorkflow::myWorkflowMethod, input);

should throw WorkflowExecutionAlreadyStarted exception if there is an execution running with the configured wfid.

7

@tihomir
I define a function like below to submit my workflow with fixed ID. Then In my test this function will be called in tens of threads simutaniously.

def test() = {
  val workflowId = "FixedWorkflowID" 
  val workflowTest = SimpleTestWorkflowHelper.createInstance(temporalService.client, workflowId)
  workflowTest.simpleWfCall(param)
}