ActivityTaskStarted is not reported timely

Community Support
1

Recently we meet a problem that some of our workflows are stuck at ActivityTaskScheduled, as the problems discussed at Activity is scheduled but does not start and Activity scheduled but not started (need help).

At the beginning, I also think there’s something wrong with the schedule and queuing mechanism, because the worker works fine and is not busy, but the activity is stuck at the ActivityTaskScheduled for hours. I tried to set a shorter ScheduleToStart timeout(10 miniutes), but that did not help.

Screen Shot 2022-11-15 at 10.08.32 AM
Screen Shot 2022-11-15 at 10.08.32 AM2184×582 100 KB

Screen Shot 2022-11-15 at 10.14.25 AM
Screen Shot 2022-11-15 at 10.14.25 AM2600×358 39.8 KB

Screen Shot 2022-11-15 at 10.03.05 AM
Screen Shot 2022-11-15 at 10.03.05 AM1280×556 64.6 KB

But when I test with a normal workflow, I find that it is also stuck at ActivityTaskScheduled for a long time, even when the activity actually has started.
So I think the problem should be ActivityTaskStarted is not reported timely. In this case, if error happens in the the activity execution, we would observe that the workflow stuck at ActivityTaskScheduled, instead of ActivityTaskStarted. As to the abnormal workflow I posted, I check our implementation and find that no heartbeat is used, and this should be the stuck cause. But the ActivityTaskScheduled state gives a misleading.
Can anyone help to confirm the behavior of ActivityTaskStarted state reporting?

2

So I think the problem should be ActivityTaskStarted is not reported timely.

ActivityTaskStarted event is not reported in history until activity completes / fails / times out, after all retries are exhausted.

Could you share the full json history for this execution please? Either from web ui or tctl
tctl wf show -w -r --of myhistory.json

3

@tihomir Here is the full json:

[
  {
    "eventId": "1",
    "eventTime": "2022-11-14T22:17:54.943729417Z",
    "eventType": "WorkflowExecutionStarted",
    "version": "0",
    "taskId": "2343567689",
    "workflowExecutionStartedEventAttributes": {
      "workflowType": {
        "name": "JdbcToAvroWorkflow"
      },
      "parentWorkflowNamespace": "",
      "parentWorkflowNamespaceId": "",
      "parentWorkflowExecution": null,
      "parentInitiatedEventId": "0",
      "taskQueue": {
        "name": "1@jdbc-worker-controller-65f59bc9f6-58pdt",
        "kind": "Normal"
      },
      "input": {
        "payloads": [
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "InRlc3RpbmctYzA4MWMyNjZmMWQ4MDRjZmFhYmYwZDcxIg=="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "ImFhMDk4ZTExLTY0NjktMTFlZC05YWI4LWQ3OTYyZWYyNzVlZCI="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Im9yYWNsZSI="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "InNlbGVjdCAqIGZyb20gKFxuU0VMRUNUIERJUkFMQy5OVU0gLCBESVJBTEMuQ0xTICwgR09PRFNILkNPREUgR0NPREUsIEdPT0RTSC5OQU1FIEdOQU1FLCBHT09EU0guQ09ERTIgLCBcbiAgICAgIFZFTkRPUi5OQU1FICwgd2FyZWhvdXNlLmNvZGUgQ0NPREUsd2FyZWhvdXNlLm5hbWUgQ05BTUUsXG4gICAgICAtMSpESVJBTENEVEwuUVRZICwgRElSQUxDRFRMLlFUWVNUUiAsIFxuICAgICAgRElSQUxDRFRMLlBSSUNFICwgLTEqRElSQUxDRFRMLlRPVEFMICwgLTEqRElSQUxDRFRMLlRBWCAsIC0xKkRJUkFMQ0RUTC5DQU1UICwgXG4gICAgICAtMSpESVJBTENEVEwuQ1RBWCAsIC0xKkRJUkFMQ0RUTC5SVE9UQUwgLCBNT0RVTEVTVEFULlNUQVROQU1FLERJUkFMQ0xPRy5USU1FLCBESVJBTENEVEwuTElORSwgVkVORE9SLkNPREUsc3RvcmUuY29kZSDlhazlj7jku6PnoIEsc3RvcmUubmFtZSDlhazlj7jlkI3np7AgLFxuXHRESVJBTENEVEwucXBjc3RyIOinhOagvCxcblx0RElSQUxDRFRMLnFwYyDku7boo4XmlbAsXG5cdERJUkFMQ0RUTC5tdW5pdCDljZXkvY0gXG4gICAgRlJPTSBESVJBTEMgRElSQUxDLCBESVJBTENMT0cgRElSQUxDTE9HLCBESVJBTENEVEwgRElSQUxDRFRMLCBHT09EU0ggR09PRFNILCBNT0RVTEVTVEFUIE1PRFVMRVNUQVQsIFZFTkRPUiBWRU5ET1Isd2FyZWhvdXNlIHdhcmVob3VzZSxzdG9yZSBzdG9yZVxuICAgICAgV0hFUkUgKChESVJBTEMuTlVNID0gRElSQUxDRFRMLk5VTSlcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0gRElSQUxDRFRMLkNMUykgICBcbiAgICAgICBhbmQgIChESVJBTEMuV3JoID0gd2FyZWhvdXNlLmdpZClcbiAgICAgICBhbmQgIChESVJBTEMuTlVNID0gRElSQUxDTE9HLk5VTSlcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0gRElSQUxDTE9HLkNMUylcbiAgICAgICBhbmQgIChESVJBTEMuU1RBVCA9IE1PRFVMRVNUQVQuTk8pXG4gICAgICAgYW5kICAoRElSQUxDRFRMLkdER0lEID0gR09PRFNILkdJRClcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0n55u06YWN5Ye66YCAJyApXG4gICAgICAgYW5kICAoRElSQUxDLkJJTExUTyA9IFZFTkRPUi5HSUQpXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlNUQVQgIElOICgnNzAwJywnNzIwJywnNzQwJywnMzIwJywnMzQwJykpXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlRJTUUgPj0gVE9fREFURSggJzIwMjItMTEtMTQnLCAnWVlZWS5NTS5ERCcgKSApXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlRJTUUgLSA2LzI0IDwgVE9fREFURSggJzIwMjItMTEtMTUnICwgJ1lZWVkuTU0uREQnICkgKVxuXHRcdFx0IGFuZCBkaXJhbGMuU0VOREVSID0gc3RvcmUuZ2lkXG4pXG4pIFwidGFibGVfcmVhbFwiIg=="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Ii9ndWFuZGF0YS1zdG9yZS9ndWFuaW5kZXhfY2FjaGVfZmlsZXMvdGVzdGluZy94ZWI1M2QwZmEwM2M3NDMxY2IzNzNjYzUveDgzMjVlM2M5YTk2YjRkYTZhMjc0M2ZiLmF2cm8i"
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Ilt7XCJuYW1lXCI6XCJOVU1cIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkNMU1wiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiR0NPREVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkdOQU1FXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCJDT0RFMlwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiTkFNRVwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiQ0NPREVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkNOQU1FXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuUVRZXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCJRVFlTVFJcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIlBSSUNFXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuVE9UQUxcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIi0xKkRJUkFMQ0RUTC5UQVhcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIi0xKkRJUkFMQ0RUTC5DQU1UXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuQ1RBWFwiLFwiZmRUeXBlXCI6XCJET1VCTEVcIn0se1wibmFtZVwiOlwiLTEqRElSQUxDRFRMLlJUT1RBTFwiLFwiZmRUeXBlXCI6XCJET1VCTEVcIn0se1wibmFtZVwiOlwiU1RBVE5BTUVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIlRJTUVcIixcImZkVHlwZVwiOlwiVElNRVNUQU1QXCJ9LHtcIm5hbWVcIjpcIkxJTkVcIixcImZkVHlwZVwiOlwiTE9OR1wifSx7XCJuYW1lXCI6XCJDT0RFXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCLlhazlj7jku6PnoIFcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIuWFrOWPuOWQjeensFwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwi6KeE5qC8XCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCLku7boo4XmlbBcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIuWNleS9jVwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn1dIg=="
          },
          {
            "metadata": {
              "encoding": "YmluYXJ5L251bGw="
            },
            "data": null
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "e30="
          }
        ]
      },
      "workflowExecutionTimeout": "0s",
      "workflowRunTimeout": "43200s",
      "workflowTaskTimeout": "10s",
      "continuedExecutionRunId": "",
      "initiator": "Unspecified",
      "continuedFailure": null,
      "lastCompletionResult": null,
      "originalExecutionRunId": "4890a934-ea80-4063-af52-49770ec9329d",
      "identity": "1@guandata-server-controller-58464f777c-kmvlg",
      "firstExecutionRunId": "4890a934-ea80-4063-af52-49770ec9329d",
      "retryPolicy": {
        "initialInterval": "2s",
        "backoffCoefficient": 2,
        "maximumInterval": "256s",
        "maximumAttempts": 1,
        "nonRetryableErrorTypes": []
      },
      "attempt": 1,
      "workflowExecutionExpirationTime": null,
      "cronSchedule": "",
      "firstWorkflowTaskBackoff": "0s",
      "memo": null,
      "searchAttributes": null,
      "prevAutoResetPoints": null,
      "header": {
        "fields": {}
      },
      "parentInitiatedEventVersion": "0"
    }
  },
  {
    "eventId": "2",
    "eventTime": "2022-11-14T22:17:54.943816618Z",
    "eventType": "WorkflowTaskScheduled",
    "version": "0",
    "taskId": "2343567690",
    "workflowTaskScheduledEventAttributes": {
      "taskQueue": {
        "name": "1@jdbc-worker-controller-65f59bc9f6-58pdt",
        "kind": "Normal"
      },
      "startToCloseTimeout": "10s",
      "attempt": 1
    }
  },
  {
    "eventId": "3",
    "eventTime": "2022-11-14T22:17:54.968677545Z",
    "eventType": "WorkflowTaskStarted",
    "version": "0",
    "taskId": "2343567696",
    "workflowTaskStartedEventAttributes": {
      "scheduledEventId": "2",
      "identity": "1@jdbc-worker-controller-65f59bc9f6-58pdt",
      "requestId": "ba1153b6-db72-455f-9053-f8f9d8188c0c",
      "suggestContinueAsNew": false,
      "historySizeBytes": "0"
    }
  },
  {
    "eventId": "4",
    "eventTime": "2022-11-14T22:17:54.987806843Z",
    "eventType": "WorkflowTaskCompleted",
    "version": "0",
    "taskId": "2343567700",
    "workflowTaskCompletedEventAttributes": {
      "scheduledEventId": "2",
      "startedEventId": "3",
      "identity": "1@jdbc-worker-controller-65f59bc9f6-58pdt",
      "binaryChecksum": ""
    }
  },
  {
    "eventId": "5",
    "eventTime": "2022-11-14T22:17:54.987862643Z",
    "eventType": "ActivityTaskScheduled",
    "version": "0",
    "taskId": "2343567701",
    "activityTaskScheduledEventAttributes": {
      "activityId": "5b00e9aa-6678-3c59-bd34-dde4e1e3d2f5",
      "activityType": {
        "name": "FetchJdbcToAvro"
      },
      "taskQueue": {
        "name": "1@jdbc-worker-controller-65f59bc9f6-58pdt",
        "kind": "Normal"
      },
      "header": {
        "fields": {}
      },
      "input": {
        "payloads": [
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "InRlc3RpbmctYzA4MWMyNjZmMWQ4MDRjZmFhYmYwZDcxIg=="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "ImFhMDk4ZTExLTY0NjktMTFlZC05YWI4LWQ3OTYyZWYyNzVlZCI="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Im9yYWNsZSI="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "InNlbGVjdCAqIGZyb20gKFxuU0VMRUNUIERJUkFMQy5OVU0gLCBESVJBTEMuQ0xTICwgR09PRFNILkNPREUgR0NPREUsIEdPT0RTSC5OQU1FIEdOQU1FLCBHT09EU0guQ09ERTIgLCBcbiAgICAgIFZFTkRPUi5OQU1FICwgd2FyZWhvdXNlLmNvZGUgQ0NPREUsd2FyZWhvdXNlLm5hbWUgQ05BTUUsXG4gICAgICAtMSpESVJBTENEVEwuUVRZICwgRElSQUxDRFRMLlFUWVNUUiAsIFxuICAgICAgRElSQUxDRFRMLlBSSUNFICwgLTEqRElSQUxDRFRMLlRPVEFMICwgLTEqRElSQUxDRFRMLlRBWCAsIC0xKkRJUkFMQ0RUTC5DQU1UICwgXG4gICAgICAtMSpESVJBTENEVEwuQ1RBWCAsIC0xKkRJUkFMQ0RUTC5SVE9UQUwgLCBNT0RVTEVTVEFULlNUQVROQU1FLERJUkFMQ0xPRy5USU1FLCBESVJBTENEVEwuTElORSwgVkVORE9SLkNPREUsc3RvcmUuY29kZSDlhazlj7jku6PnoIEsc3RvcmUubmFtZSDlhazlj7jlkI3np7AgLFxuXHRESVJBTENEVEwucXBjc3RyIOinhOagvCxcblx0RElSQUxDRFRMLnFwYyDku7boo4XmlbAsXG5cdERJUkFMQ0RUTC5tdW5pdCDljZXkvY0gXG4gICAgRlJPTSBESVJBTEMgRElSQUxDLCBESVJBTENMT0cgRElSQUxDTE9HLCBESVJBTENEVEwgRElSQUxDRFRMLCBHT09EU0ggR09PRFNILCBNT0RVTEVTVEFUIE1PRFVMRVNUQVQsIFZFTkRPUiBWRU5ET1Isd2FyZWhvdXNlIHdhcmVob3VzZSxzdG9yZSBzdG9yZVxuICAgICAgV0hFUkUgKChESVJBTEMuTlVNID0gRElSQUxDRFRMLk5VTSlcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0gRElSQUxDRFRMLkNMUykgICBcbiAgICAgICBhbmQgIChESVJBTEMuV3JoID0gd2FyZWhvdXNlLmdpZClcbiAgICAgICBhbmQgIChESVJBTEMuTlVNID0gRElSQUxDTE9HLk5VTSlcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0gRElSQUxDTE9HLkNMUylcbiAgICAgICBhbmQgIChESVJBTEMuU1RBVCA9IE1PRFVMRVNUQVQuTk8pXG4gICAgICAgYW5kICAoRElSQUxDRFRMLkdER0lEID0gR09PRFNILkdJRClcbiAgICAgICBhbmQgIChESVJBTEMuQ0xTID0n55u06YWN5Ye66YCAJyApXG4gICAgICAgYW5kICAoRElSQUxDLkJJTExUTyA9IFZFTkRPUi5HSUQpXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlNUQVQgIElOICgnNzAwJywnNzIwJywnNzQwJywnMzIwJywnMzQwJykpXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlRJTUUgPj0gVE9fREFURSggJzIwMjItMTEtMTQnLCAnWVlZWS5NTS5ERCcgKSApXG4gICAgICAgYW5kICAoRElSQUxDTE9HLlRJTUUgLSA2LzI0IDwgVE9fREFURSggJzIwMjItMTEtMTUnICwgJ1lZWVkuTU0uREQnICkgKVxuXHRcdFx0IGFuZCBkaXJhbGMuU0VOREVSID0gc3RvcmUuZ2lkXG4pXG4pIFwidGFibGVfcmVhbFwiIg=="
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Ii9ndWFuZGF0YS1zdG9yZS9ndWFuaW5kZXhfY2FjaGVfZmlsZXMvdGVzdGluZy94ZWI1M2QwZmEwM2M3NDMxY2IzNzNjYzUveDgzMjVlM2M5YTk2YjRkYTZhMjc0M2ZiLmF2cm8i"
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "Ilt7XCJuYW1lXCI6XCJOVU1cIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkNMU1wiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiR0NPREVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkdOQU1FXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCJDT0RFMlwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiTkFNRVwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwiQ0NPREVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIkNOQU1FXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuUVRZXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCJRVFlTVFJcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIlBSSUNFXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuVE9UQUxcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIi0xKkRJUkFMQ0RUTC5UQVhcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIi0xKkRJUkFMQ0RUTC5DQU1UXCIsXCJmZFR5cGVcIjpcIkRPVUJMRVwifSx7XCJuYW1lXCI6XCItMSpESVJBTENEVEwuQ1RBWFwiLFwiZmRUeXBlXCI6XCJET1VCTEVcIn0se1wibmFtZVwiOlwiLTEqRElSQUxDRFRMLlJUT1RBTFwiLFwiZmRUeXBlXCI6XCJET1VCTEVcIn0se1wibmFtZVwiOlwiU1RBVE5BTUVcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIlRJTUVcIixcImZkVHlwZVwiOlwiVElNRVNUQU1QXCJ9LHtcIm5hbWVcIjpcIkxJTkVcIixcImZkVHlwZVwiOlwiTE9OR1wifSx7XCJuYW1lXCI6XCJDT0RFXCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCLlhazlj7jku6PnoIFcIixcImZkVHlwZVwiOlwiU1RSSU5HXCJ9LHtcIm5hbWVcIjpcIuWFrOWPuOWQjeensFwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn0se1wibmFtZVwiOlwi6KeE5qC8XCIsXCJmZFR5cGVcIjpcIlNUUklOR1wifSx7XCJuYW1lXCI6XCLku7boo4XmlbBcIixcImZkVHlwZVwiOlwiRE9VQkxFXCJ9LHtcIm5hbWVcIjpcIuWNleS9jVwiLFwiZmRUeXBlXCI6XCJTVFJJTkdcIn1dIg=="
          },
          {
            "metadata": {
              "encoding": "YmluYXJ5L251bGw="
            },
            "data": null
          },
          {
            "metadata": {
              "encoding": "anNvbi9wbGFpbg=="
            },
            "data": "e30="
          }
        ]
      },
      "scheduleToCloseTimeout": "43200s",
      "scheduleToStartTimeout": "600s",
      "startToCloseTimeout": "43200s",
      "heartbeatTimeout": "0s",
      "workflowTaskCompletedEventId": "4",
      "retryPolicy": {
        "initialInterval": "1s",
        "backoffCoefficient": 2,
        "maximumInterval": "32s",
        "maximumAttempts": 1,
        "nonRetryableErrorTypes": []
      }
    }
  }
]