Query Workflow Methods & Invalid ArgumentException for Timeout Workflow?

Hi,

I’m trying to understand what this exception really means and where the INVALID_ARGUMENT comes from. Based on the stack trace it looks like the exception is thrown when the worker gets a request to query a workflow that timed-out. getCoolWorkflowStatus. Can you not query workflows that have timed out?

io.grpc.StatusRuntimeException: INVALID_ARGUMENT: io.temporal.internal.replay.InternalWorkflowTaskException: Failure handling event 10 of 'EVENT_TYPE_WORKFLOW_EXECUTION_TIMED_OUT' type. IsReplaying=false, PreviousStartedEventId=8, workflowTaskStartedEventId=0, Currently Processing StartedEventId=8
	at io.temporal.internal.statemachines.WorkflowStateMachines.handleEvent(WorkflowStateMachines.java:193)
	at io.temporal.internal.replay.ReplayWorkflowRunTaskHandler.handleEvent(ReplayWorkflowRunTaskHandler.java:140)
	at io.temporal.internal.replay.ReplayWorkflowRunTaskHandler.handleWorkflowTaskImpl(ReplayWorkflowRunTaskHandler.java:180)
	at io.temporal.internal.replay.ReplayWorkflowRunTaskHandler.handleQueryWorkflowTask(ReplayWorkflowRunTaskHandler.java:254)
	at io.temporal.internal.replay.ReplayWorkflowTaskHandler.handleQueryOnlyWorkflowTask(ReplayWorkflowTaskHandler.java:257)
	at io.temporal.internal.replay.ReplayWorkflowTaskHandler.handleWorkflowTask(ReplayWorkflowTaskHandler.java:112)
	at io.temporal.internal.worker.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:319)
	at io.temporal.internal.worker.WorkflowWorker$TaskHandlerImpl.handle(WorkflowWorker.java:279)
	at io.temporal.internal.worker.PollTaskExecutor.lambda$process$0(PollTaskExecutor.java:73)
	at java.base/java.util.concurrent.ThreadPoolExecutor.runWorker(ThreadPoolExecutor.java:1128)
	at java.base/java.util.concurrent.ThreadPoolExecutor$Worker.run(ThreadPoolExecutor.java:628)
	at java.base/java.lang.Thread.run(Thread.java:829)
Caused by: java.lang.IllegalArgumentException: Unexpected event:event_id: 10
event_time {
  seconds: 1636780456
  nanos: 460371739
}
event_type: EVENT_TYPE_WORKFLOW_EXECUTION_TIMED_OUT
task_id: 82676480
workflow_execution_timed_out_event_attributes {
  retry_state: RETRY_STATE_TIMEOUT
}

	at io.temporal.internal.statemachines.WorkflowStateMachines.handleNonStatefulEvent(WorkflowStateMachines.java:418)
	at io.temporal.internal.statemachines.WorkflowStateMachines.handleEventImpl(WorkflowStateMachines.java:215)
	at io.temporal.internal.statemachines.WorkflowStateMachines.handleEvent(WorkflowStateMachines.java:178)
	... 11 more

	at io.grpc.stub.ClientCalls.toStatusRuntimeException(ClientCalls.java:262)
	at io.grpc.stub.ClientCalls.getUnchecked(ClientCalls.java:243)
	at io.grpc.stub.ClientCalls.blockingUnaryCall(ClientCalls.java:156)
	at io.temporal.api.workflowservice.v1.WorkflowServiceGrpc$WorkflowServiceBlockingStub.queryWorkflow(WorkflowServiceGrpc.java:2970)
	at io.temporal.internal.external.GenericWorkflowClientExternalImpl.lambda$query$5(GenericWorkflowClientExternalImpl.java:216)
	at io.temporal.internal.common.GrpcRetryer.retryWithResult(GrpcRetryer.java:97)
	at io.temporal.internal.external.GenericWorkflowClientExternalImpl.query(GenericWorkflowClientExternalImpl.java:209)
	at io.temporal.internal.sync.WorkflowStubImpl.query(WorkflowStubImpl.java:470)
	... 83 common frames omitted
Wrapped by: io.temporal.client.WorkflowQueryException: workflowId='0becbce5-0053-45a2-bbb3-4771f0b883e9', runId='', workflowType='CoolWorkflow'}
	at io.temporal.internal.sync.WorkflowStubImpl.query(WorkflowStubImpl.java:475)
	at io.temporal.internal.sync.WorkflowInvocationHandler$SyncWorkflowInvocationHandler.queryWorkflow(WorkflowInvocationHandler.java:312)
	at io.temporal.internal.sync.WorkflowInvocationHandler$SyncWorkflowInvocationHandler.invoke(WorkflowInvocationHandler.java:275)
	at io.temporal.internal.sync.WorkflowInvocationHandler.invoke(WorkflowInvocationHandler.java:181)
	at com.sun.proxy.$Proxy105.getCoolStatusDetails(Unknown Source)
	at com.snapchat.ci_cd_orchestrator.workflow.cool.CoolWorkflowManager.getCoolWorkflowStatus(CoolWorkflowManager.java:116)
	at com.snapchat.ci_cd_orchestrator.resources.CoolWorkflowResource.getCoolWorkflowStatus(CoolWorkflowResource.java:65)
	at jdk.internal.reflect.GeneratedMethodAccessor395.invoke(Unknown Source)
	at java.base/jdk.internal.reflect.DelegatingMethodAccessorImpl.invoke(DelegatingMethodAccessorImpl.java:43)
	at java.base/java.lang.reflect.Method.invoke(Method.java:566)
	at org.glassfish.jersey.server.model.internal.ResourceMethodInvocationHandlerFactory.lambda$static$0(ResourceMethodInvocationHandlerFactory.java:52)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher$1.run(AbstractJavaResourceMethodDispatcher.java:124)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.invoke(AbstractJavaResourceMethodDispatcher.java:167)
	at org.glassfish.jersey.server.model.internal.JavaResourceMethodDispatcherProvider$ResponseOutInvoker.doDispatch(JavaResourceMethodDispatcherProvider.java:176)
	at org.glassfish.jersey.server.model.internal.AbstractJavaResourceMethodDispatcher.dispatch(AbstractJavaResourceMethodDispatcher.java:79)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.invoke(ResourceMethodInvoker.java:469)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:391)
	at org.glassfish.jersey.server.model.ResourceMethodInvoker.apply(ResourceMethodInvoker.java:80)
	at org.glassfish.jersey.server.ServerRuntime$1.run(ServerRuntime.java:255)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:248)
	at org.glassfish.jersey.internal.Errors$1.call(Errors.java:244)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:292)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:274)
	at org.glassfish.jersey.internal.Errors.process(Errors.java:244)
	at org.glassfish.jersey.process.internal.RequestScope.runInScope(RequestScope.java:265)
	at org.glassfish.jersey.server.ServerRuntime.process(ServerRuntime.java:234)
	at org.glassfish.jersey.server.ApplicationHandler.handle(ApplicationHandler.java:680)
	at org.glassfish.jersey.servlet.WebComponent.serviceImpl(WebComponent.java:394)
	at org.glassfish.jersey.servlet.WebComponent.service(WebComponent.java:346)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:366)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:319)
	at org.glassfish.jersey.servlet.ServletContainer.service(ServletContainer.java:205)
	at org.eclipse.jetty.servlet.ServletHolder.handle(ServletHolder.java:791)
	at org.eclipse.jetty.servlet.ServletHandler$ChainEnd.doFilter(ServletHandler.java:1626)
	at io.dropwizard.servlets.ThreadNameFilter.doFilter(ThreadNameFilter.java:35)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at io.dropwizard.jersey.filter.AllowedMethodsFilter.handle(AllowedMethodsFilter.java:47)
	at io.dropwizard.jersey.filter.AllowedMethodsFilter.doFilter(AllowedMethodsFilter.java:41)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at snapchat.analysis.v2.filters.MetricsFilter.filterWithProcessed(MetricsFilter.java:92)
	at snapchat.analysis.v2.filters.MetricsFilter.doFilter(MetricsFilter.java:66)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at com.snapchat.ci_cd_orchestrator.filter.TraceLogFilter.doFilter(TraceLogFilter.java:81)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at com.google.inject.servlet.FilterChainInvocation.doFilter(FilterChainInvocation.java:89)
	at com.google.inject.servlet.ManagedFilterPipeline.dispatch(ManagedFilterPipeline.java:121)
	at com.google.inject.servlet.GuiceFilter.doFilter(GuiceFilter.java:133)
	at org.eclipse.jetty.servlet.FilterHolder.doFilter(FilterHolder.java:193)
	at org.eclipse.jetty.servlet.ServletHandler$Chain.doFilter(ServletHandler.java:1601)
	at org.eclipse.jetty.servlet.ServletHandler.doHandle(ServletHandler.java:548)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextHandle(ScopedHandler.java:233)
	at org.eclipse.jetty.server.handler.ContextHandler.doHandle(ContextHandler.java:1435)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:188)
	at org.eclipse.jetty.servlet.ServletHandler.doScope(ServletHandler.java:501)
	at org.eclipse.jetty.server.handler.ScopedHandler.nextScope(ScopedHandler.java:186)
	at org.eclipse.jetty.server.handler.ContextHandler.doScope(ContextHandler.java:1350)
	at org.eclipse.jetty.server.handler.ScopedHandler.handle(ScopedHandler.java:141)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at com.codahale.metrics.jetty9.InstrumentedHandler.handle(InstrumentedHandler.java:313)
	at io.dropwizard.jetty.RoutingHandler.handle(RoutingHandler.java:52)
	at org.eclipse.jetty.server.handler.gzip.GzipHandler.handle(GzipHandler.java:766)
	at org.eclipse.jetty.server.handler.RequestLogHandler.handle(RequestLogHandler.java:54)
	at org.eclipse.jetty.server.handler.StatisticsHandler.handle(StatisticsHandler.java:179)
	at org.eclipse.jetty.server.handler.HandlerWrapper.handle(HandlerWrapper.java:127)
	at org.eclipse.jetty.server.Server.handle(Server.java:516)
	at org.eclipse.jetty.server.HttpChannel.lambda$handle$1(HttpChannel.java:388)
	at org.eclipse.jetty.server.HttpChannel.dispatch(HttpChannel.java:633)
	at org.eclipse.jetty.server.HttpChannel.handle(HttpChannel.java:380)
	at org.eclipse.jetty.server.HttpConnection.onFillable(HttpConnection.java:273)
	at org.eclipse.jetty.io.AbstractConnection$ReadCallback.succeeded(AbstractConnection.java:311)
	at org.eclipse.jetty.io.FillInterest.fillable(FillInterest.java:105)
	at org.eclipse.jetty.io.ChannelEndPoint$1.run(ChannelEndPoint.java:104)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.runTask(EatWhatYouKill.java:336)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.doProduce(EatWhatYouKill.java:313)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.tryProduce(EatWhatYouKill.java:171)
	at org.eclipse.jetty.util.thread.strategy.EatWhatYouKill.run(EatWhatYouKill.java:129)
	at org.eclipse.jetty.util.thread.ReservedThreadExecutor$ReservedThread.run(ReservedThreadExecutor.java:375)
	at org.eclipse.jetty.util.thread.QueuedThreadPool.runJob(QueuedThreadPool.java:773)
	at org.eclipse.jetty.util.thread.QueuedThreadPool$Runner.run(QueuedThreadPool.java:905)
	at java.base/java.lang.Thread.run(Thread.java:829)

where event 10 is

 {
    "eventTime": "2021-11-13T05:14:16.000Z",
    "eventType": "WorkflowExecutionTimedOut",
    "eventId": "10",
    "details": {
      "retryState": "Timeout",
      "eventId": "10",
      "eventType": "WorkflowExecutionTimedOut",
      "kvps": [
        {
          "key": "eventTime",
          "value": "Nov 12th 9:14:16 pm"
        },
        {
          "key": "eventId",
          "value": "10"
        },
        {
          "key": "retryState",
          "value": "Timeout"
        }
      ],
      "eventTime": "Nov 12th 9:14:16 pm"
    },
    "eventTimeDisplay": "Nov 12th 9:14:16 pm",
    "timeElapsedDisplay": "1h 20m (+1h 20m)",
    "eventSummary": {
      "retryState": "Timeout",
      "eventId": "10",
      "eventType": "WorkflowExecutionTimedOut",
      "kvps": [
        {
          "key": "retryState",
          "value": "Timeout"
        }
      ]
    },
    "eventFullDetails": {
      "retryState": "Timeout",
      "eventId": "10",
      "eventType": "WorkflowExecutionTimedOut",
      "kvps": [
        {
          "key": "retryState",
          "value": "Timeout"
        }
      ]
    }
  }

Looks like this could be tie to this bug Flaky testShouldReturnQueryResultAfterWorkflowTimeout · Issue #630 · temporalio/sdk-java · GitHub?

You should be able to query timed out workflow execution.

#630 is related to an edge case when there is not a single successful workflow task in the workflow history and an exception there is a bit different. In the future when this bug is addressed a query to a workflow that doesn’t have a single successful workflow task will most likely still end up with an exception, it will likely be a more clear one though.

This exception looks like a state machines exception. Would be great to get a full history to investigate.
Can you post a full workflow history?

Confirmed with @darewreck that it’s fixed in the last releases of JavaSDK.