Expection on child workflow execution

Puneet_Chaturvedi · March 18, 2024, 5:25pm

Using a ParentWorkflow → Child Workflow → SubchildWorkflow structure to process multiple list of records ~50K (list of UUIDs) concurrently, Child workflow are being submitted using async function. For batch of ids getting below exception from Child workflow, using java-sdk version 1.23.0

{
[info]   "time" : "2024-03-18T13:11:19.610-04:00",
[info]   "thread_name" : "Workflow Executor taskQueue=\"default\", namespace=\"default\": 112",
[info]   "level" : "INFO",
[info]   "ServiceName" : "Amos",
[info]   "TaskQueue" : "default",
[info]   "Namespace" : "default",
[info]   "stackTrace" : "i.g.StatusRuntimeException: INVALID_ARGUMENT: UnhandledCommand
[info]          at i.g.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:271)
[info]          at i.g.stub.ClientCalls.getUnchecked(ClientCalls.java:252)
[info]          at i.g.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:165)
[info]          at i.t.a.w.v.WorkflowServiceGrpc$WorkflowServiceBlockingStub.respondWorkflowTaskCompleted(WorkflowServiceGrpc.java:3924)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.lambda$sendTaskCompleted$0(WorkflowWorker.java:468)
[info]          at i.t.i.r.GrpcSyncRetryer.retry(GrpcSyncRetryer.java:69)
[info]          at i.t.i.r.GrpcRetryer.retryWithResult(GrpcRetryer.java:60)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.sendTaskCompleted(WorkflowWorker.java:463)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:335)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:263)
[info]          at i.t.i.w.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:105)
[info]          ... 3 common frames omitted
[info] Wrapped by: j.l.RuntimeException: Failure processing workflow task. WorkflowId=34400051119699900893-1, RunId=accbcee6-7415-46fc-865e-a33c3ec99ead, Attempt=1
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.wrapFailure(WorkflowWorker.java:422)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.wrapFailure(WorkflowWorker.java:263)
[info]          at i.t.i.w.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:110)
[info]          at j.u.c.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[info]          at j.u.c.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[info]          at java.lang.Thread.run(Thread.java:748)
[info] "
[info] }
[info] Error during child workflow execution: workflowId='FCE14543-8017-497E-9BBA-606547919EE1-123', runId='', workflowType='MigrateBlobSubChildWorkflow', initiatedEventId=11, startedEventId=0, namespace='default', retryState=RETRY_STATE_NON_RETRYABLE_FAILURE
[info] {
[info]   "time" : "2024-03-18T13:11:20.218-04:00",
[info]   "thread_name" : "Workflow Executor taskQueue=\"default\", namespace=\"default\": 2",
[info]   "level" : "WARN",
[info]   "ServiceName" : "Amos",
[info]   "WorkflowType" : "MigrationBlobChildWorkflow",
[info]   "TaskQueue" : "default",
[info]   "WorkflowId" : "25800051119699900893-1",
[info]   "RunId" : "f689dfd1-229e-4b53-9cef-c8e7352adba1",
[info]   "Namespace" : "default",
[info]   "stackTrace" : "i.g.StatusRuntimeException: INVALID_ARGUMENT: UnhandledCommand
[info]          at i.g.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:271)
[info]          at i.g.stub.ClientCalls.getUnchecked(ClientCalls.java:252)
[info]          at i.g.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:165)
[info]          at i.t.a.w.v.WorkflowServiceGrpc$WorkflowServiceBlockingStub.respondWorkflowTaskCompleted(WorkflowServiceGrpc.java:3924)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.lambda$sendTaskCompleted$0(WorkflowWorker.java:468)
[info]          at i.t.i.r.GrpcSyncRetryer.retry(GrpcSyncRetryer.java:69)
[info]          at i.t.i.r.GrpcRetryer.retryWithResult(GrpcRetryer.java:60)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.sendTaskCompleted(WorkflowWorker.java:463)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:335)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:263)
[info]          at i.t.i.w.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:105)
[info]          at j.u.c.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[info]          at j.u.c.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[info]          at java.lang.Thread.run(Thread.java:748)
[info] "
[info] }
[info] {
[info]   "time" : "2024-03-18T13:11:20.230-04:00",
[info]   "thread_name" : "Workflow Executor taskQueue=\"default\", namespace=\"default\": 2",
[info]   "level" : "INFO",
[info]   "TaskQueue" : "default",
[info]   "Namespace" : "default",
[info]   "stackTrace" : "i.g.StatusRuntimeException: INVALID_ARGUMENT: UnhandledCommand
[info]          at i.g.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:271)
[info]          at i.g.stub.ClientCalls.getUnchecked(ClientCalls.java:252)
[info]          at i.g.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:165)
[info]          at i.t.a.w.v.WorkflowServiceGrpc$WorkflowServiceBlockingStub.respondWorkflowTaskCompleted(WorkflowServiceGrpc.java:3924)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.lambda$sendTaskCompleted$0(WorkflowWorker.java:468)
[info]          at i.t.i.r.GrpcSyncRetryer.retry(GrpcSyncRetryer.java:69)
[info]          at i.t.i.r.GrpcRetryer.retryWithResult(GrpcRetryer.java:60)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.sendTaskCompleted(WorkflowWorker.java:463)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:335)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:263)
[info]          at i.t.i.w.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:105)
[info]          ... 3 common frames omitted
[info] Wrapped by: j.l.RuntimeException: Failure processing workflow task. WorkflowId=25800051119699900893-1, RunId=f689dfd1-229e-4b53-9cef-c8e7352adba1, Attempt=1
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.wrapFailure(WorkflowWorker.java:422)
[info]          at i.t.i.w.WorkflowWorker$TaskHandlerImpl.wrapFailure(WorkflowWorker.java:263)
[info]          at i.t.i.w.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:110)
[info]          at j.u.c.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1149)
[info]          at j.u.c.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:624)
[info]          at java.lang.Thread.run(Thread.java:748)
[info] "

antonio.perez · March 20, 2024, 11:07am

Hi @Puneet_Chaturvedi

UnhandledCommand is benign most or the time, depending on the rate you see it.

In your current scenario, this can be caused by a child’s workflow completing at the same time the parent tries to close the workflow execution. Completing the child workflow will add an event to the parent workflow history, the server will reject closing the parent while there are buffered events.

Let me know if it helps,
Antonio

Puneet_Chaturvedi · April 4, 2024, 7:43pm

Thanks @antonio.perez this helps to understand whats going on here, what should be best way to avoid this issue and prevent from closing so that all child finishes first.

Topic		Replies	Views
Event corruption with child workflows? (Java SDK) Community Support java-sdk	30	1121	October 18, 2021
Query Workflow Methods & Invalid ArgumentException for Timeout Workflow? Community Support java-sdk	3	707	November 13, 2021
Childflows replay due the mainflow replay Community Support child-workflow	1	516	July 17, 2021
Workflow ID Collision Errors Community Support go-sdk , general-impl	5	497	January 13, 2023
How to identify what was failing when "Failure processing workflow task" happens Community Support	8	2305	March 29, 2021

Expection on child workflow execution

Related Topics