ActivityTaskStarted is not reported timely

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.



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?

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

@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": []
      }
    }
  }
]