Skip to content

Instantly share code, notes, and snippets.

@suejungshin

suejungshin/async_activity_issue_log Secret

Last active August 10, 2020 14:58
Show Gist options
  • Star 0 You must be signed in to star a gist
  • Fork 0 You must be signed in to fork a gist
  • Save suejungshin/e391ac0ac02d054b66b7a7a5025630f2 to your computer and use it in GitHub Desktop.
Save suejungshin/e391ac0ac02d054b66b7a7a5025630f2 to your computer and use it in GitHub Desktop.
Download ZIP
Raw
async_activity_issue_log
///////////////////////////////////////////////////
// LOGS AFTER WORKFLOW IS STARTED
//////////////////////////////////////////////////
docker run --net=host --rm temporalio/tctl:0.26.0 workflow describe -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Sun Aug 9 23:53:39 2020
{
"executionConfig": {
"taskQueue": {
"name": "system"
},
"workflowExecutionTimeoutSeconds": 315360000,
"workflowRunTimeoutSeconds": 315360000,
"workflowTaskTimeoutSeconds": 10
},
"workflowExecutionInfo": {
"execution": {
"workflowId": "91f21c11-ba10-4ffc-b58a-6e5612d4032b",
"runId": "93475d3c-c163-4433-a814-fff62b751de4"
},
"type": {
"name": "system.DeclarativeWorkflow"
},
"startTime": "2020-08-09T23:52:03Z",
"closeTime": "1970-01-01T00:00:00Z",
"status": "Running",
"historyLength": "6",
"memo": {
},
"searchAttributes": {
"indexedFields": {
"BinaryChecksums": "[37894971da460dad1dfc69a6f26af628]"
}
},
"autoResetPoints": {
"points": [
{
"binaryChecksum": "37894971da460dad1dfc69a6f26af628",
"runId": "93475d3c-c163-4433-a814-fff62b751de4",
"firstDecisionCompletedId": "4",
"createTimeNano": "1597017123169263300",
"resettable": true
}
]
}
},
"pendingActivities": [
{
"activityId": "6c9e4ff0-d9f7-4c27-b270-382ded46b00c",
"activityType": {
"name": "standard.ManualTaskActivity"
},
"state": "Started", /////// Note "Started" here vs. "Scheduled" in below, 1 hour later
"lastHeartbeatTimestamp": "2020-08-09T23:52:03Z", /////// Note timestamp here
"lastStartedTimestamp": "2020-08-09T23:52:03Z", /////// Note timestamp here
"scheduledTimestamp": "1970-01-01T00:00:00Z",
"expirationTimestamp": "1970-01-01T00:00:00Z",
"lastFailure": "nil"
}
]
}
docker run --net=host --rm temporalio/tctl:0.26.0 workflow show -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Sun Aug 9 23:53:40 2020
1 WorkflowExecutionStarted {WorkflowType:{Name:system.DeclarativeWorkflow}, ParentInitiatedEventId:0,
TaskQueue:{Name:system, Kind:Normal}, Input:{
testusecase2axonic����"
testusecase2(����:`
$35fbbc56-e53a-468a-8570-fa0a1521fdcesystem.startFlowB& $8ab538dd- c620-4aa8-8d1e-00d83836f653:�
$8ab538dd-c620-4aa8-8d1e-00d83836f653SplitSplit:2& $6c9e4ff0-d9f7-4c27-b270-382ded 46b00c2& $ ... dard
�������q detailsApproval $approveriJxDqy2eCVO1li9sPoKu4i 2activity&$018c1a89-1bd7-443c-9fc4-5bf1520ab
427"$e590db22-2153-4dc2-831c-573e77c7330d,{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic
"}}}}, WorkflowExecutionTimeoutSeconds:315360000, WorkflowRunTimeoutSeconds:315360000, WorkflowTaskTimeoutSeconds:10,
Initiator:Decider, LastCompletionResult:{}, OriginalExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4,
Identity:2910@Suejungs-MacBook-Pro-2.local@, FirstExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4, Attempt:0,
WorkflowExecutionExpirationTimestamp:0, FirstDecisionTaskBackoffSeconds:0, Header:{Fields:map{}}}
2 DecisionTaskScheduled {TaskQueue:{Name:system,
Kind:Unspecified},
StartToCloseTimeoutSeconds:10,
Attempt:0}
3 DecisionTaskStarted {ScheduledEventId:2,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
RequestId:05beddf5-8605-41f2-996d-3dadba756e67}
4 DecisionTaskCompleted {ScheduledEventId:2, StartedEventId:3,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
BinaryChecksum:37894971da460dad1dfc69a6f26af628}
5 ActivityTaskScheduled {ActivityId:6c9e4ff0-d9f7-4c27-b270-382ded46b00c, ActivityType:{Name:standard.ManualTaskActivity},
TaskQueue:{Name:standard, Kind:Unspecified}, Header:{Fields:map{}},
Input:{{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic"},"stepID":{"S":"6c9e4ff0-d9f7-4c27-b270
-382ded46b00c"}}},{"fields":{"assignee":{"S":"iJxDqy2eCVO1li9sPoKu4i"},"details":{"S":"You need to do this thing, please
do it."},"hasResolutionAttachments":{"B":true},"hasResolutionNotes":{"B":true}}}}, ScheduleToCloseTimeoutSeconds:20000000,
ScheduleToStartTimeoutSeconds:10000000, StartToCloseTimeoutSeconds:10000000, HeartbeatTimeoutSeconds:0,
DecisionTaskCompletedEventId:4}
6 ActivityTaskStarted {ScheduledEventId:5, /////// Note "ActivityTaskStarted" is listed here
Identity:52632@Suejungs-MacBook-Pro-2.local@,
RequestId:07cd0bd5-bf00-483c-870c-d43d69b1578d,
Attempt:0}
///////////////////////////////////////////////////
// LOGS AFTER 1 HOUR ELAPSES
//////////////////////////////////////////////////
docker run --net=host --rm temporalio/tctl:0.26.0 workflow describe -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Mon Aug 10 00:51:54 2020
{
"executionConfig": {
"taskQueue": {
"name": "system"
},
"workflowExecutionTimeoutSeconds": 315360000,
"workflowRunTimeoutSeconds": 315360000,
"workflowTaskTimeoutSeconds": 10
},
"workflowExecutionInfo": {
"execution": {
"workflowId": "91f21c11-ba10-4ffc-b58a-6e5612d4032b",
"runId": "93475d3c-c163-4433-a814-fff62b751de4"
},
"type": {
"name": "system.DeclarativeWorkflow"
},
"startTime": "2020-08-09T23:52:03Z",
"closeTime": "1970-01-01T00:00:00Z",
"status": "Running",
"historyLength": "6",
"memo": {
},
"searchAttributes": {
"indexedFields": {
"BinaryChecksums": "[37894971da460dad1dfc69a6f26af628]"
}
},
"autoResetPoints": {
"points": [
{
"binaryChecksum": "37894971da460dad1dfc69a6f26af628",
"runId": "93475d3c-c163-4433-a814-fff62b751de4",
"firstDecisionCompletedId": "4",
"createTimeNano": "1597017123169263300",
"resettable": true
}
]
}
},
"pendingActivities": [
{
"activityId": "6c9e4ff0-d9f7-4c27-b270-382ded46b00c",
"activityType": {
"name": "standard.ManualTaskActivity"
},
"state": "Scheduled", /////// Note "Scheduled" here vs. "Started" in above, 1 hour ago
"lastHeartbeatTimestamp": "1970-01-01T00:00:00Z",
"lastStartedTimestamp": "1970-01-01T00:00:00Z",
"scheduledTimestamp": "2020-08-09T23:52:03Z",
"expirationTimestamp": "1970-01-01T00:00:00Z",
"lastFailure": "nil"
}
]
}
docker run --net=host --rm temporalio/tctl:0.26.0 workflow show -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Mon Aug 10 00:52:37 2020
1 WorkflowExecutionStarted {WorkflowType:{Name:system.DeclarativeWorkflow}, ParentInitiatedEventId:0,
TaskQueue:{Name:system, Kind:Normal}, Input:{
testusecase2axonic����"
testusecase2(����:`
$35fbbc56-e53a-468a-8570-fa0a1521fdcesystem.startFlowB& $8ab538dd- c620-4aa8-8d1e-00d83836f653:�
$8ab538dd-c620-4aa8-8d1e-00d83836f653SplitSplit:2& $6c9e4ff0-d9f7-4c27-b270-382ded 46b00c2& $ ... dard
�������q detailsApproval $approveriJxDqy2eCVO1li9sPoKu4i 2activity&$018c1a89-1bd7-443c-9fc4-5bf1520ab
427"$e590db22-2153-4dc2-831c-573e77c7330d,{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic
"}}}}, WorkflowExecutionTimeoutSeconds:315360000, WorkflowRunTimeoutSeconds:315360000, WorkflowTaskTimeoutSeconds:10,
Initiator:Decider, LastCompletionResult:{}, OriginalExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4,
Identity:2910@Suejungs-MacBook-Pro-2.local@, FirstExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4, Attempt:0,
WorkflowExecutionExpirationTimestamp:0, FirstDecisionTaskBackoffSeconds:0, Header:{Fields:map{}}}
2 DecisionTaskScheduled {TaskQueue:{Name:system,
Kind:Unspecified},
StartToCloseTimeoutSeconds:10,
Attempt:0}
3 DecisionTaskStarted {ScheduledEventId:2,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
RequestId:05beddf5-8605-41f2-996d-3dadba756e67}
4 DecisionTaskCompleted {ScheduledEventId:2, StartedEventId:3,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
BinaryChecksum:37894971da460dad1dfc69a6f26af628}
5 ActivityTaskScheduled {ActivityId:6c9e4ff0-d9f7-4c27-b270-382ded46b00c, ActivityType:{Name:standard.ManualTaskActivity},
TaskQueue:{Name:standard, Kind:Unspecified}, Header:{Fields:map{}},
Input:{{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic"},"stepID":{"S":"6c9e4ff0-d9f7-4c27-b270
-382ded46b00c"}}},{"fields":{"assignee":{"S":"iJxDqy2eCVO1li9sPoKu4i"},"details":{"S":"You need to do this thing, please
do it."},"hasResolutionAttachments":{"B":true},"hasResolutionNotes":{"B":true}}}}, ScheduleToCloseTimeoutSeconds:20000000,
ScheduleToStartTimeoutSeconds:10000000, StartToCloseTimeoutSeconds:10000000, HeartbeatTimeoutSeconds:0,
DecisionTaskCompletedEventId:4}
6 ActivityTaskStarted {ScheduledEventId:5, /////// Note "ActivityTaskStarted" is listed here even though missing from PendingActivities above
Identity:52632@Suejungs-MacBook-Pro-2.local@,
RequestId:07cd0bd5-bf00-483c-870c-d43d69b1578d,
Attempt:0}
///////////////////////////////////////////////////
// LOGS AFTER "REFRESH TASKS" INVOKED
//////////////////////////////////////////////////
docker run --net=host --rm temporalio/tctl:0.26.0 admin workflow refresh_tasks -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b Mon Aug 10 00:54:25 2020
Refresh workflow task succeeded.
docker run --net=host --rm temporalio/tctl:0.26.0 workflow describe -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Mon Aug 10 00:54:31 2020
{
"executionConfig": {
"taskQueue": {
"name": "system"
},
"workflowExecutionTimeoutSeconds": 315360000,
"workflowRunTimeoutSeconds": 315360000,
"workflowTaskTimeoutSeconds": 10
},
"workflowExecutionInfo": {
"execution": {
"workflowId": "91f21c11-ba10-4ffc-b58a-6e5612d4032b",
"runId": "93475d3c-c163-4433-a814-fff62b751de4"
},
"type": {
"name": "system.DeclarativeWorkflow"
},
"startTime": "2020-08-09T23:52:03Z",
"closeTime": "1970-01-01T00:00:00Z",
"status": "Running",
"historyLength": "7",
"memo": {
},
"searchAttributes": {
"indexedFields": {
"BinaryChecksums": "[37894971da460dad1dfc69a6f26af628]"
}
},
"autoResetPoints": {
"points": [
{
"binaryChecksum": "37894971da460dad1dfc69a6f26af628",
"runId": "93475d3c-c163-4433-a814-fff62b751de4",
"firstDecisionCompletedId": "4",
"createTimeNano": "1597017123169263300",
"resettable": true
}
]
}
},
"pendingActivities": [
{
"activityId": "6c9e4ff0-d9f7-4c27-b270-382ded46b00c",
"activityType": {
"name": "standard.ManualTaskActivity"
},
"state": "Started",
"lastHeartbeatTimestamp": "2020-08-10T00:54:26Z",
"lastStartedTimestamp": "2020-08-10T00:54:26Z",
"scheduledTimestamp": "1970-01-01T00:00:00Z",
"expirationTimestamp": "1970-01-01T00:00:00Z",
"lastFailure": "nil"
}
]
}
docker run --net=host --rm temporalio/tctl:0.26.0 workflow show -w 91f21c11-ba10-4ffc-b58a-6e5612d4032b
Mon Aug 10 00:54:26 2020
1 WorkflowExecutionStarted {WorkflowType:{Name:system.DeclarativeWorkflow}, ParentInitiatedEventId:0,
TaskQueue:{Name:system, Kind:Normal}, Input:{
testusecase2axonic����"
testusecase2(����:`
$35fbbc56-e53a-468a-8570-fa0a1521fdcesystem.startFlowB& $8ab538dd- c620-4aa8-8d1e-00d83836f653:�
$8ab538dd-c620-4aa8-8d1e-00d83836f653SplitSplit:2& $6c9e4ff0-d9f7-4c27-b270-382ded 46b00c2& $ ... dard
�������q detailsApproval $approveriJxDqy2eCVO1li9sPoKu4i 2activity&$018c1a89-1bd7-443c-9fc4-5bf1520ab
427"$e590db22-2153-4dc2-831c-573e77c7330d,{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic
"}}}}, WorkflowExecutionTimeoutSeconds:315360000, WorkflowRunTimeoutSeconds:315360000, WorkflowTaskTimeoutSeconds:10,
Initiator:Decider, LastCompletionResult:{}, OriginalExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4,
Identity:2910@Suejungs-MacBook-Pro-2.local@, FirstExecutionRunId:93475d3c-c163-4433-a814-fff62b751de4, Attempt:0,
WorkflowExecutionExpirationTimestamp:0, FirstDecisionTaskBackoffSeconds:0, Header:{Fields:map{}}}
2 DecisionTaskScheduled {TaskQueue:{Name:system,
Kind:Unspecified},
StartToCloseTimeoutSeconds:10,
Attempt:0}
3 DecisionTaskStarted {ScheduledEventId:2,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
RequestId:05beddf5-8605-41f2-996d-3dadba756e67}
4 DecisionTaskCompleted {ScheduledEventId:2, StartedEventId:3,
Identity:13498@Suejungs-MacBook-Pro-2.local@,
BinaryChecksum:37894971da460dad1dfc69a6f26af628}
5 ActivityTaskScheduled {ActivityId:6c9e4ff0-d9f7-4c27-b270-382ded46b00c, ActivityType:{Name:standard.ManualTaskActivity},
TaskQueue:{Name:standard, Kind:Unspecified}, Header:{Fields:map{}},
Input:{{"fields":{"executionID":{"S":"n757rg4vPCp8q4RV4sQQvI"},"orgCode":{"S":"axonic"},"stepID":{"S":"6c9e4ff0-d9f7-4c27-b270
-382ded46b00c"}}},{"fields":{"assignee":{"S":"iJxDqy2eCVO1li9sPoKu4i"},"details":{"S":"You need to do this thing, please
do it."},"hasResolutionAttachments":{"B":true},"hasResolutionNotes":{"B":true}}}}, ScheduleToCloseTimeoutSeconds:20000000,
ScheduleToStartTimeoutSeconds:10000000, StartToCloseTimeoutSeconds:10000000, HeartbeatTimeoutSeconds:0,
DecisionTaskCompletedEventId:4}
6 ActivityTaskStarted {ScheduledEventId:5, ///// Note this remnant is still here
Identity:52632@Suejungs-MacBook-Pro-2.local@,
RequestId:07cd0bd5-bf00-483c-870c-d43d69b1578d,
Attempt:0}
7 ActivityTaskStarted {ScheduledEventId:5, ///// The restarted activity is here
Identity:52632@Suejungs-MacBook-Pro-2.local@,
RequestId:169e6b8b-ba51-49ca-b780-b0a753ae124c,
Attempt:0}
docker run --net=host --rm temporalio/tctl:0.26.0 taskqueue describe -tl system 490ms  Mon Aug 10 01:22:56 2020
DECISION POLLER IDENTITY | LAST ACCESS TIME
13498@Suejungs-MacBook-Pro-2.local@ | 2020-08-10T01:26:57Z
docker run --net=host --rm temporalio/tctl:0.26.0 taskqueue describe -tl standard 509ms  Mon Aug 10 01:27:09 2020
DECISION POLLER IDENTITY | LAST ACCESS TIME
52632@Suejungs-MacBook-Pro-2.local@ | 2020-08-10T01:26:46Z
docker run --net=host --rm temporalio/tctl:0.26.0 taskqueue describe -tl standard -tlt activity 405ms  Mon Aug 10 01:27:17 2020
ACTIVITY POLLER IDENTITY | LAST ACCESS TIME
52632@Suejungs-MacBook-Pro-2.local@ | 2020-08-10T01:26:57Z
@mfateev
Copy link

mfateev commented Aug 10, 2020

The history with two ActivityTaskStarted events in a row looks invalid. What database binding your service use? Can you reproduce the problem with v0.28.0 version of the service and the SDK?

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment