Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

CronSchedule workflow stop #1829

Closed
zydovech opened this issue Aug 17, 2021 · 13 comments
Closed

CronSchedule workflow stop #1829

zydovech opened this issue Aug 17, 2021 · 13 comments
Assignees
@dnr
Labels
close-after-30-days

Comments

@zydovech
Copy link

zydovech commented Aug 17, 2021 •
edited

I run cron job ,After running for a period of time, the worker cannot get the corresponding task。

The last two tasks are：

lastRunTime_exclude               thisRunTime_include            WorkflowID                                              RunID
2021-08-18 07:58:02.448          2021-08-18 07:59:03.117         temporal_cron1_687ddd07-6e99-4c1b-96ed-f321979a0c85   8db0f3db-96e4-4908-be09-bc7a401c4315
2021-08-18 07:57:00.896          2021-08-18 07:58:02.448         temporal_cron1_687ddd07-6e99-4c1b-96ed-f321979a0c85   27a63c33-cd8b-4ec5-b32f-73563c6ceddd

the history of temporal_cron1_687ddd07-6e99-4c1b-96ed-f321979a0c85 is :

  1  WorkflowExecutionStarted  {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                ContinuedExecutionRunId:8db0f3db-96e4-4908-be09-bc7a401c4315,
                                Initiator:CronSchedule,
                                LastCompletionResult:[{"RunTime":"2021-08-18T07:59:03.117003609Z"}],
                                OriginalExecutionRunId:a6ff393b-9cfe-45aa-a37b-04d787884f0b,
                                FirstExecutionRunId:a2781a9b-b867-4099-800d-5c3f2f2bdabf,
                                Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:55s,
                                PrevAutoResetPoints:{Points:[{BinaryChecksum:bbf635f6a52ea2050d3cb1d49f888c14,
                                RunId:a2781a9b-b867-4099-800d-5c3f2f2bdabf, FirstWorkflowTaskCompletedId:4,
                                CreateTime:2021-08-18 07:46:01.656435253 +0000 UTC, ExpireTime:2021-08-21
                                07:46:03.999988743 +0000 UTC, Resettable:true}]}}
  2  WorkflowTaskScheduled     {TaskQueue:{Name:cron,
                                Kind:Normal},
                                StartToCloseTimeout:2m0s,
                                Attempt:1}

the history of runid 8db0f3db-96e4-4908-be09-bc7a401c4315 is ：

  1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:27a63c33-cd8b-4ec5-b32f-73563c6ceddd,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T07:58:02.448290516Z"}],
                                       OriginalExecutionRunId:8db0f3db-96e4-4908-be09-bc7a401c4315,
                                       FirstExecutionRunId:a2781a9b-b867-4099-800d-5c3f2f2bdabf,
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:56s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:bbf635f6a52ea2050d3cb1d49f888c14,
                                       RunId:a2781a9b-b867-4099-800d-5c3f2f2bdabf, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-18 07:46:01.656435253 +0000 UTC, ExpireTime:2021-08-21
                                       07:46:03.999988743 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:15035@xxxxxxx@,
                                       RequestId:ebe2102d-6c2b-4c3d-bb43-1aa09f908167}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:15035@xxxxxxx@,
                                       BinaryChecksum:bbf635f6a52ea2050d3cb1d49f888c14}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-18T07:58:02.448290516Z",
                                       "2021-08-18T07:59:03.117003609Z",
                                       "8db0f3db-96e4-4908-be09-bc7a401c4315"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:15035@xxxxxxx@,
                                       RequestId:ee1b2a8d-93b5-442b-a5d5-55d995441598,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:15035@xxxxxxx@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxxxx:e0290273-0ed3-4916-95ed-8e8c06ce5983,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskStarted              {ScheduledEventId:8,
                                       Identity:15035@xxxxxxx@,
                                       RequestId:53f5ec3e-0cde-4afc-921c-b388db156fba}
  10  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                       Identity:15035@xxxxxxx@,
                                       BinaryChecksum:bbf635f6a52ea2050d3cb1d49f888c14}
  11  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:a6ff393b-9cfe-45aa-a37b-04d787884f0b,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                       BackoffStartInterval:55s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T07:59:03.117003609Z"}]}

Updated relevant information

Steps to Reproduce the Problem

just run workflow with CronSchedule, in my case , I ran ten of them, and after a while, only 7 were left

Specifications

  • Version: v1.11.2
  • Platform: linux
  • Storage:mysql
@zydovech
Copy link
Author

This is another issue. It stopped running for a while in the middle.

thisRunTime_include               lastRunTime_exclude            WorkflowID                                                 RunID
2021-08-18 12:25:02.416           2021-08-18 12:14:01.416        temporal_cron1_retry_607b29b8-8327-4d33-b345-236fff95aa2a  c6035d88-68f4-4297-81c8-9a12c235cb19
2021-08-18 12:14:01.416           2021-08-18 12:13:05.127        temporal_cron1_retry_607b29b8-8327-4d33-b345-236fff95aa2a  77a21fb5-e8e7-4549-9f62-b4ddcb309aad

the history of c6035d88-68f4-4297-81c8-9a12c235cb19 :

 1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:77a21fb5-e8e7-4549-9f62-b4ddcb309aad,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T12:14:01.416853818Z"}],
                                       OriginalExecutionRunId:c6035d88-68f4-4297-81c8-9a12c235cb19,
                                       FirstExecutionRunId:79bb76f3-d36b-41b0-83d5-2290652e0846,
                                       RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                       MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:57s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                       RunId:79bb76f3-d36b-41b0-83d5-2290652e0846, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-18 09:52:03.980758417 +0000 UTC, ExpireTime:2021-08-21
                                       09:52:06.244244217 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:22987@xxxxx@,
                                       RequestId:ff67d85a-f3f0-4c3c-bd2f-498c0aee6e5b}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:22987@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-18T12:14:01.416853818Z",
                                       "2021-08-18T12:25:02.41630478Z",
                                       "c6035d88-68f4-4297-81c8-9a12c235cb19"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:22987@xxxxx@,
                                       RequestId:20802758-387f-4376-8248-e8c5fbb07869,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:22987@xxxxx@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx:a887220f-3751-4870-8b71-cbecfde4540a,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskStarted              {ScheduledEventId:8,
                                       Identity:22987@xxxxx@,
                                       RequestId:36554f69-90a7-4004-8153-c7f7eb8b8e61}
  10  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                       Identity:22987@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
  11  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:66d3879b-ba88-4211-9d48-212ffdba6d58,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                       BackoffStartInterval:56s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T12:25:02.41630478Z"}]}

the history of 77a21fb5-e8e7-4549-9f62-b4ddcb309aad is

   1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:749e2441-7bb2-41b4-9fff-e011e8107055,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T12:13:05.127929776Z"}],
                                       OriginalExecutionRunId:77a21fb5-e8e7-4549-9f62-b4ddcb309aad,
                                       FirstExecutionRunId:79bb76f3-d36b-41b0-83d5-2290652e0846,
                                       RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                       MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:53s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                       RunId:79bb76f3-d36b-41b0-83d5-2290652e0846, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-18 09:52:03.980758417 +0000 UTC, ExpireTime:2021-08-21
                                       09:52:06.244244217 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:22987@xxxxx@,
                                       RequestId:23ea0d7f-620e-4bfb-b080-391aaa65a9df}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:22987@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-18T12:13:05.127929776Z",
                                       "2021-08-18T12:14:01.416853818Z",
                                       "77a21fb5-e8e7-4549-9f62-b4ddcb309aad"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:22987@xxxxx@,
                                       RequestId:a071e3be-785d-41a6-8a0d-27ad614f70c8,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:22987@xxxxx@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx:a887220f-3751-4870-8b71-cbecfde4540a,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskTimedOut             {ScheduledEventId:8,
                                       StartedEventId:0,
                                       TimeoutType:ScheduleToStart}
  10  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
  11  WorkflowTaskStarted              {ScheduledEventId:10,
                                       Identity:22987@xxxxx@,
                                       RequestId:8401d10c-9d57-41dc-8f6b-007de9ea3efe}
  12  WorkflowTaskCompleted            {ScheduledEventId:10, StartedEventId:11,
                                       Identity:22987@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
  13  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:c6035d88-68f4-4297-81c8-9a12c235cb19,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:12,
                                       BackoffStartInterval:57s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-18T12:14:01.416853818Z"}]}

@dnr
Copy link
Member

dnr commented Aug 19, 2021

I think there's a good chance that the fixes in 1.11.4 will also fix this issue. Could you try with that and see if you can reproduce this behavior?

Unfortunately it's pretty hard to tell what's going on just from the mysql tables since there are quite a few levels of abstraction above that. It's probably more useful to examine the history events with the web ui or tctl. A cron workflow will be "started" immediately but its first task won't be scheduled until it's time to run (that's the FirstWorkflowTaskBackoff).

@zydovech
Copy link
Author

zydovech commented Aug 19, 2021 •
edited

Hi，I try again with 1.11.4 , Can reproduce。

thisRunTime_include               lastRunTime_exclude            WorkflowID                                                 RunID
2021-08-19 02:48:11.681           2021-08-19 02:47:01.355        temporal_cron1_retry_e642138e-a905-4471-aaa9-35cf428e3ae2  568a4c35-5939-4235-b26a-b9a651517835

2021-08-19 02:47:01.355           2021-08-19 02:46:02.138        temporal_cron1_retry_e642138e-a905-4471-aaa9-35cf428e3ae2  ac6f9e64-5c05-4eae-b8f8-1eb1fb9a65a8

the history info ：

  1  WorkflowExecutionStarted  {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                ContinuedExecutionRunId:568a4c35-5939-4235-b26a-b9a651517835,
                                Initiator:CronSchedule,
                                LastCompletionResult:[{"RunTime":"2021-08-19T02:48:11.681395227Z"}],
                                OriginalExecutionRunId:de9d7eb4-1749-447c-873b-6374e817844a,
                                FirstExecutionRunId:e025b65a-39dc-436e-93bc-740ae8e45a04,
                                RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:47s,
                                PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                RunId:e025b65a-39dc-436e-93bc-740ae8e45a04, FirstWorkflowTaskCompletedId:4,
                                CreateTime:2021-08-19 02:43:01.294629725 +0000 UTC, ExpireTime:2021-08-22
                                02:43:03.460015254 +0000 UTC, Resettable:true}]}}
  2  WorkflowTaskScheduled     {TaskQueue:{Name:cron,
                                Kind:Normal},
                                StartToCloseTimeout:2m0s,
                                Attempt:1}

the history info of 568a4c35-5939-4235-b26a-b9a651517835 :

 1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:ac6f9e64-5c05-4eae-b8f8-1eb1fb9a65a8,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T02:47:01.355481673Z"}],
                                       OriginalExecutionRunId:568a4c35-5939-4235-b26a-b9a651517835,
                                       FirstExecutionRunId:e025b65a-39dc-436e-93bc-740ae8e45a04,
                                       RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                       MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:57s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                       RunId:e025b65a-39dc-436e-93bc-740ae8e45a04, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-19 02:43:01.294629725 +0000 UTC, ExpireTime:2021-08-22
                                       02:43:03.460015254 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:16864@xxxxx@,
                                       RequestId:788306cf-5e48-44fc-afef-e7fbb4af6957}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:16864@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-19T02:47:01.355481673Z",
                                       "2021-08-19T02:48:11.681395227Z",
                                       "568a4c35-5939-4235-b26a-b9a651517835"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:16864@xxxxx@,
                                       RequestId:df144127-1c4c-40a0-ad76-52c199c1d860,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:16864@xxxxx@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx:7a18de50-c02a-493d-beb8-633172e9c275,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskStarted              {ScheduledEventId:8,
                                       Identity:16864@xxxxx@,
                                       RequestId:0e17840d-45d7-4eeb-ac12-6d0cf8325179}
  10  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                       Identity:16864@xxxxx@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
  11  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:de9d7eb4-1749-447c-873b-6374e817844a,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                       BackoffStartInterval:47s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T02:48:11.681395227Z"}]}

What other information needs to be provided？

@zydovech
Copy link
Author

zydovech commented Aug 19, 2021 •
edited

Did not run for a while

thisRunTime_include               lastRunTime_exclude            WorkflowID                                                 RunID
2021-08-19 03:19:04.011           2021-08-19 03:08:05.709        temporal_cron1_retry_bc38af7f-1999-4c2f-9019-b75602bb77e2  3f54a3a7-4349-4c87-a080-1ddaa4eb3d4a
2021-08-19 03:08:05.709           2021-08-19 03:07:04.335        temporal_cron1_retry_bc38af7f-1999-4c2f-9019-b75602bb77e2  7897ce00-c41d-4403-94c7-569f2320ebe2

the history of 3f54a3a7-4349-4c87-a080-1ddaa4eb3d4a


  1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:7897ce00-c41d-4403-94c7-569f2320ebe2,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T03:08:05.709589498Z"}],
                                       OriginalExecutionRunId:3f54a3a7-4349-4c87-a080-1ddaa4eb3d4a,
                                       FirstExecutionRunId:dcfa43da-7d6c-4efe-a50a-c0bb32c33209,
                                       RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                       MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:53s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                       RunId:dcfa43da-7d6c-4efe-a50a-c0bb32c33209, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-19 02:43:02.01806827 +0000 UTC, ExpireTime:2021-08-22
                                       02:43:04.503182158 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:d180cb12-a346-4d4d-9a32-bff6e220a6af}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-19T03:08:05.709589498Z",
                                       "2021-08-19T03:19:04.011877347Z",
                                       "3f54a3a7-4349-4c87-a080-1ddaa4eb3d4a"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:671b3c2e-61c3-4716-ab79-84a5d79b2aa1,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:16864@plat-sh-infra-testing-mwork002@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:plat-sh-infra-testing-mwork002:7a18de50-c02a-493d-beb8-633172e9c275,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskStarted              {ScheduledEventId:8,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:488c5066-47a6-4b8f-a393-69c4e1e6171f}
  10  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
  11  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:a9b608a6-a53a-4a5d-9153-2d19d49d8291,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                       BackoffStartInterval:54s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T03:19:04.011877347Z"}]}

the history of 7897ce00-c41d-4403-94c7-569f2320ebe2

   1  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                       WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                       ContinuedExecutionRunId:ed3fb594-9484-497b-b547-8008df60f0c0,
                                       Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T03:07:04.335371965Z"}],
                                       OriginalExecutionRunId:7897ce00-c41d-4403-94c7-569f2320ebe2,
                                       FirstExecutionRunId:dcfa43da-7d6c-4efe-a50a-c0bb32c33209,
                                       RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                       MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                       Attempt:1, CronSchedule:* * * * *, FirstWorkflowTaskBackoff:54s,
                                       PrevAutoResetPoints:{Points:[{BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c,
                                       RunId:dcfa43da-7d6c-4efe-a50a-c0bb32c33209, FirstWorkflowTaskCompletedId:4,
                                       CreateTime:2021-08-19 02:43:02.01806827 +0000 UTC, ExpireTime:2021-08-22
                                       02:43:04.503182158 +0000 UTC, Resettable:true}]}}
   2  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
   3  WorkflowTaskStarted              {ScheduledEventId:2,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:0ed4000c-a032-45ac-8f52-7d62610072f6}
   4  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
   5  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                       TaskQueue:{Name:cron, Kind:Normal},
                                       Input:["2021-08-19T03:07:04.335371965Z",
                                       "2021-08-19T03:08:05.709589498Z",
                                       "7897ce00-c41d-4403-94c7-569f2320ebe2"],
                                       ScheduleToCloseTimeout:0s,
                                       ScheduleToStartTimeout:0s,
                                       StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                       WorkflowTaskCompletedEventId:4,
                                       RetryPolicy:{InitialInterval:1s,
                                       BackoffCoefficient:2, MaximumInterval:1m40s,
                                       MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  ActivityTaskStarted              {ScheduledEventId:5,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:8b98a6e7-8b8a-47e6-8bfb-0a7928b07582,
                                       Attempt:1}
   7  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                       Identity:16864@plat-sh-infra-testing-mwork002@}
   8  WorkflowTaskScheduled            {TaskQueue:{Name:plat-sh-infra-testing-mwork002:7a18de50-c02a-493d-beb8-633172e9c275,
                                       Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  WorkflowTaskTimedOut             {ScheduledEventId:8,
                                       StartedEventId:0,
                                       TimeoutType:ScheduleToStart}
  10  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                       Kind:Normal},
                                       StartToCloseTimeout:2m0s,
                                       Attempt:1}
  11  WorkflowTaskStarted              {ScheduledEventId:10,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       RequestId:a627b7f4-27e2-4fe1-986a-08f15f5c1264}
  12  WorkflowTaskCompleted            {ScheduledEventId:10, StartedEventId:11,
                                       Identity:16864@plat-sh-infra-testing-mwork002@,
                                       BinaryChecksum:91e1b40c5f09d0596fa84bdcec5ffd6c}
  13  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:3f54a3a7-4349-4c87-a080-1ddaa4eb3d4a,
                                       WorkflowType:{Name:SampleCronWorkflow},
                                       TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                       WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:12,
                                       BackoffStartInterval:53s, Initiator:CronSchedule,
                                       LastCompletionResult:[{"RunTime":"2021-08-19T03:08:05.709589498Z"}]}

@dnr
Copy link
Member

dnr commented Aug 19, 2021

Could you include timestamps with the history (-pdt on the tctl command line)? Also, I assume you meant to say the second history is for 7897ce00-c41d-4403-94c7-569f2320ebe2?

@zydovech
Copy link
Author

zydovech commented Aug 20, 2021 •
edited

Could you include timestamps with the history (-pdt on the tctl command line)? Also, I assume you meant to say the second history is for 7897ce00-c41d-4403-94c7-569f2320ebe2?

yes, i sorry, The above content is wrong ， the second history is for 7897ce00-c41d-4403-94c7-569f2320ebe2。

the history for temporal_cron1_retry_bc38af7f-1999-4c2f-9019-b75602bb77e2 workflow was cleared by me , here is another one for you

thisRunTime_include               lastRunTime_exclude            WorkflowID                                                 RunID
2021-08-19 17:24:01.802           2021-08-19 17:12:02.645        temporal_cron2_retry_96c65e94-916d-47dd-a9da-0a46c7d95bdf  29ed2dea-95a2-4898-ad8b-ceeb80f69493
2021-08-19 17:12:02.645           2021-08-19 17:10:03.176        temporal_cron2_retry_96c65e94-916d-47dd-a9da-0a46c7d95bdf  ba6cee25-303b-4f4b-bc59-bfc40133aa95
2021-08-19 17:10:03.176           2021-08-19 17:08:04.020        temporal_cron2_retry_96c65e94-916d-47dd-a9da-0a46c7d95bdf  7921317c-f03a-490b-96f9-dd8d212a6f11

the history for 29ed2dea-95a2-4898-ad8b-ceeb80f69493 :

   1  2021-08-19T17:22:04Z  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                                             WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                                             ContinuedExecutionRunId:ba6cee25-303b-4f4b-bc59-bfc40133aa95,
                                                             Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-19T17:12:02.645156861Z"}],
                                                             OriginalExecutionRunId:29ed2dea-95a2-4898-ad8b-ceeb80f69493,
                                                             FirstExecutionRunId:c4c195d5-cfce-4fe2-ab8f-694f45ac866e,
                                                             RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                                             MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                                             Attempt:1, CronSchedule:*/2 * * * *, FirstWorkflowTaskBackoff:1m56s,
                                                             PrevAutoResetPoints:{Points:[{BinaryChecksum:92011f96509b0a809928ea71ee045142,
                                                             RunId:c4c195d5-cfce-4fe2-ab8f-694f45ac866e, FirstWorkflowTaskCompletedId:4,
                                                             CreateTime:2021-08-19 11:04:02.523195985 +0000 UTC, ExpireTime:2021-08-22
                                                             11:04:04.840936857 +0000 UTC, Resettable:true},...3 more]}}
   2  2021-08-19T17:24:00Z  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                                             Kind:Normal},
                                                             StartToCloseTimeout:2m0s,
                                                             Attempt:1}
   3  2021-08-19T17:24:01Z  WorkflowTaskStarted              {ScheduledEventId:2,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:fcf7d8df-deb0-4365-9504-0cfb0f5a4bd5}
   4  2021-08-19T17:24:01Z  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                                             Identity:17983@xxxxx@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
   5  2021-08-19T17:24:01Z  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                                             TaskQueue:{Name:cron, Kind:Normal},
                                                             Input:["2021-08-19T17:12:02.645156861Z",
                                                             "2021-08-19T17:24:01.802984416Z",
                                                             "29ed2dea-95a2-4898-ad8b-ceeb80f69493"],
                                                             ScheduleToCloseTimeout:0s,
                                                             ScheduleToStartTimeout:0s,
                                                             StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                                             WorkflowTaskCompletedEventId:4,
                                                             RetryPolicy:{InitialInterval:1s,
                                                             BackoffCoefficient:2, MaximumInterval:1m40s,
                                                             MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  2021-08-19T17:24:01Z  ActivityTaskStarted              {ScheduledEventId:5,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:2d4bdac1-bdb1-4e5d-b7d9-53f4ef600fc8,
                                                             Attempt:1}
   7  2021-08-19T17:24:03Z  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                                             Identity:17983@xxxxx@}
   8  2021-08-19T17:24:03Z  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx:9b0f9da1-675f-41ce-b3d8-16aca38b110e,
                                                             Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  2021-08-19T17:24:04Z  WorkflowTaskStarted              {ScheduledEventId:8,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:38ec78f2-b7d2-4bcc-bd7b-7462e48457b7}
  10  2021-08-19T17:24:04Z  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                                             Identity:17983@xxxxx@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
  11  2021-08-19T17:24:04Z  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:bb54c475-b96b-487e-bf76-29d35f78df18,
                                                             WorkflowType:{Name:SampleCronWorkflow},
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                                             WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                                             BackoffStartInterval:1m56s, Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-19T17:24:01.802984416Z"}]}

the history for ba6cee25-303b-4f4b-bc59-bfc40133aa95 :

   1  2021-08-19T17:10:05Z  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                                             WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                                             ContinuedExecutionRunId:7921317c-f03a-490b-96f9-dd8d212a6f11,
                                                             Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-19T17:10:03.176934144Z"}],
                                                             OriginalExecutionRunId:ba6cee25-303b-4f4b-bc59-bfc40133aa95,
                                                             FirstExecutionRunId:c4c195d5-cfce-4fe2-ab8f-694f45ac866e,
                                                             RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                                             MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                                             Attempt:1, CronSchedule:*/2 * * * *, FirstWorkflowTaskBackoff:1m55s,
                                                             PrevAutoResetPoints:{Points:[{BinaryChecksum:92011f96509b0a809928ea71ee045142,
                                                             RunId:c4c195d5-cfce-4fe2-ab8f-694f45ac866e, FirstWorkflowTaskCompletedId:4,
                                                             CreateTime:2021-08-19 11:04:02.523195985 +0000 UTC, ExpireTime:2021-08-22
                                                             11:04:04.840936857 +0000 UTC, Resettable:true},...3 more]}}
   2  2021-08-19T17:12:00Z  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                                             Kind:Normal},
                                                             StartToCloseTimeout:2m0s,
                                                             Attempt:1}
   3  2021-08-19T17:12:02Z  WorkflowTaskStarted              {ScheduledEventId:2,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:57e46f38-0b3d-45d4-a7da-35bc7e86d27d}
   4  2021-08-19T17:12:02Z  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                                             Identity:17983@xxxxx@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
   5  2021-08-19T17:12:02Z  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                                             TaskQueue:{Name:cron, Kind:Normal},
                                                             Input:["2021-08-19T17:10:03.176934144Z",
                                                             "2021-08-19T17:12:02.645156861Z",
                                                             "ba6cee25-303b-4f4b-bc59-bfc40133aa95"],
                                                             ScheduleToCloseTimeout:0s,
                                                             ScheduleToStartTimeout:0s,
                                                             StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                                             WorkflowTaskCompletedEventId:4,
                                                             RetryPolicy:{InitialInterval:1s,
                                                             BackoffCoefficient:2, MaximumInterval:1m40s,
                                                             MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  2021-08-19T17:12:02Z  ActivityTaskStarted              {ScheduledEventId:5,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:e92d6e1a-ad0a-46ea-bcd8-37c154d0278a,
                                                             Attempt:1}
   7  2021-08-19T17:12:04Z  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                                             Identity:17983@xxxxx@}
   8  2021-08-19T17:12:04Z  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx:9b0f9da1-675f-41ce-b3d8-16aca38b110e,
                                                             Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  2021-08-19T17:22:04Z  WorkflowTaskTimedOut             {ScheduledEventId:8,
                                                             StartedEventId:0,
                                                             TimeoutType:ScheduleToStart}
  10  2021-08-19T17:22:04Z  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                                             Kind:Normal},
                                                             StartToCloseTimeout:2m0s,
                                                             Attempt:1}
  11  2021-08-19T17:22:04Z  WorkflowTaskStarted              {ScheduledEventId:10,
                                                             Identity:17983@xxxxx@,
                                                             RequestId:9e1a7482-f2ae-4d28-acf0-9e18cf39e52b}
  12  2021-08-19T17:22:04Z  WorkflowTaskCompleted            {ScheduledEventId:10, StartedEventId:11,
                                                             Identity:17983@xxxxx@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
  13  2021-08-19T17:22:04Z  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:29ed2dea-95a2-4898-ad8b-ceeb80f69493,
                                                             WorkflowType:{Name:SampleCronWorkflow},
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                                             WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:12,
                                                             BackoffStartInterval:1m56s, Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-19T17:12:02.645156861Z"}]}

@zydovech
Copy link
Author

this is Workflow information that is no longer running。

thisRunTime_include               lastRunTime_exclude            WorkflowID                                                 RunID
2021-08-20 01:18:00.314           2021-08-20 01:16:03.046        temporal_cron2_retry_20ee8b07-60f4-4a7f-b5a6-8871722177e1  14c62b11-9004-4664-b8fa-fec096ad5c53
2021-08-20 01:16:03.046           2021-08-20 01:14:00.079        temporal_cron2_retry_20ee8b07-60f4-4a7f-b5a6-8871722177e1  2cefe642-61c8-4172-88d4-9ff99be26898

the history for temporal_cron2_retry_20ee8b07-60f4-4a7f-b5a6-8871722177e1 without --run_id :

  1  2021-08-20T01:18:02Z  WorkflowExecutionStarted  {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                                      TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                                      WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                                      ContinuedExecutionRunId:14c62b11-9004-4664-b8fa-fec096ad5c53,
                                                      Initiator:CronSchedule,
                                                      LastCompletionResult:[{"RunTime":"2021-08-20T01:18:00.314241887Z"}],
                                                      OriginalExecutionRunId:dcc697b5-b26d-4e02-a715-be84c14b0172,
                                                      FirstExecutionRunId:a8baa25b-a7ba-42c7-b880-f22a227ae050,
                                                      RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                                      MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                                      Attempt:1, CronSchedule:*/2 * * * *, FirstWorkflowTaskBackoff:1m58s,
                                                      PrevAutoResetPoints:{Points:[{BinaryChecksum:92011f96509b0a809928ea71ee045142,
                                                      RunId:a8baa25b-a7ba-42c7-b880-f22a227ae050, FirstWorkflowTaskCompletedId:4,
                                                      CreateTime:2021-08-19 11:04:04.52491094 +0000 UTC, ExpireTime:2021-08-22
                                                      11:04:06.756721775 +0000 UTC, Resettable:true},...3 more]}}
  2  2021-08-20T01:20:00Z  WorkflowTaskScheduled     {TaskQueue:{Name:cron,
                                                      Kind:Normal},
                                                      StartToCloseTimeout:2m0s,
                                                      Attempt:1}

the hitroy for 14c62b11-9004-4664-b8fa-fec096ad5c53 :

   1  2021-08-20T01:16:05Z  WorkflowExecutionStarted         {WorkflowType:{Name:SampleCronWorkflow}, ParentInitiatedEventId:0,
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowExecutionTimeout:0s,
                                                             WorkflowRunTimeout:0s, WorkflowTaskTimeout:2m0s,
                                                             ContinuedExecutionRunId:2cefe642-61c8-4172-88d4-9ff99be26898,
                                                             Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-20T01:16:03.046822451Z"}],
                                                             OriginalExecutionRunId:14c62b11-9004-4664-b8fa-fec096ad5c53,
                                                             FirstExecutionRunId:a8baa25b-a7ba-42c7-b880-f22a227ae050,
                                                             RetryPolicy:{InitialInterval:1s, BackoffCoefficient:2,
                                                             MaximumInterval:1m0s, MaximumAttempts:5, NonRetryableErrorTypes:[]},
                                                             Attempt:1, CronSchedule:*/2 * * * *, FirstWorkflowTaskBackoff:1m55s,
                                                             PrevAutoResetPoints:{Points:[{BinaryChecksum:92011f96509b0a809928ea71ee045142,
                                                             RunId:a8baa25b-a7ba-42c7-b880-f22a227ae050, FirstWorkflowTaskCompletedId:4,
                                                             CreateTime:2021-08-19 11:04:04.52491094 +0000 UTC, ExpireTime:2021-08-22
                                                             11:04:06.756721775 +0000 UTC, Resettable:true},...3 more]}}
   2  2021-08-20T01:18:00Z  WorkflowTaskScheduled            {TaskQueue:{Name:cron,
                                                             Kind:Normal},
                                                             StartToCloseTimeout:2m0s,
                                                             Attempt:1}
   3  2021-08-20T01:18:00Z  WorkflowTaskStarted              {ScheduledEventId:2,
                                                             Identity:17983@xxxxx002@,
                                                             RequestId:feb37887-2a30-4802-a6df-dff50056cc69}
   4  2021-08-20T01:18:00Z  WorkflowTaskCompleted            {ScheduledEventId:2, StartedEventId:3,
                                                             Identity:17983@xxxxx002@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
   5  2021-08-20T01:18:00Z  ActivityTaskScheduled            {ActivityId:5, ActivityType:{Name:DoSomething},
                                                             TaskQueue:{Name:cron, Kind:Normal},
                                                             Input:["2021-08-20T01:16:03.046822451Z",
                                                             "2021-08-20T01:18:00.314241887Z",
                                                             "14c62b11-9004-4664-b8fa-fec096ad5c53"],
                                                             ScheduleToCloseTimeout:0s,
                                                             ScheduleToStartTimeout:0s,
                                                             StartToCloseTimeout:10s, HeartbeatTimeout:0s,
                                                             WorkflowTaskCompletedEventId:4,
                                                             RetryPolicy:{InitialInterval:1s,
                                                             BackoffCoefficient:2, MaximumInterval:1m40s,
                                                             MaximumAttempts:2, NonRetryableErrorTypes:[]}}
   6  2021-08-20T01:18:00Z  ActivityTaskStarted              {ScheduledEventId:5,
                                                             Identity:17983@xxxxx002@,
                                                             RequestId:a8eb8a33-9016-4308-913f-29ffb5d76e80,
                                                             Attempt:1}
   7  2021-08-20T01:18:02Z  ActivityTaskCompleted            {ScheduledEventId:5, StartedEventId:6,
                                                             Identity:17983@xxxxx002@}
   8  2021-08-20T01:18:02Z  WorkflowTaskScheduled            {TaskQueue:{Name:xxxxx002:9b0f9da1-675f-41ce-b3d8-16aca38b110e,
                                                             Kind:Sticky}, StartToCloseTimeout:2m0s, Attempt:1}
   9  2021-08-20T01:18:02Z  WorkflowTaskStarted              {ScheduledEventId:8,
                                                             Identity:17983@xxxxx002@,
                                                             RequestId:a00d408e-8b09-4a5e-a76c-634a44ef931d}
  10  2021-08-20T01:18:02Z  WorkflowTaskCompleted            {ScheduledEventId:8, StartedEventId:9,
                                                             Identity:17983@xxxxx002@,
                                                             BinaryChecksum:9467c09ae66b7f88e29fc4ff6c3a9b35}
  11  2021-08-20T01:18:02Z  WorkflowExecutionContinuedAsNew  {NewExecutionRunId:dcc697b5-b26d-4e02-a715-be84c14b0172,
                                                             WorkflowType:{Name:SampleCronWorkflow},
                                                             TaskQueue:{Name:cron, Kind:Normal}, WorkflowRunTimeout:0s,
                                                             WorkflowTaskTimeout:2m0s, WorkflowTaskCompletedEventId:10,
                                                             BackoffStartInterval:1m58s, Initiator:CronSchedule,
                                                             LastCompletionResult:[{"RunTime":"2021-08-20T01:18:00.314241887Z"}]}

@dnr
Copy link
Member

dnr commented Aug 20, 2021

It looks like something is going wrong with the worker picking up workflow tasks. E.g. in ba6cee25..., event 8 is a WorkflowTaskScheduled (on a sticky queue), but it never gets started (first unexpected thing). The timeout there is supposed to be 2 minutes, but it only happens 10 minutes later (second unexpected thing).

We're trying to figure out how to reproduce this behavior to understand what's going on. Could you give us some more details about how you've set things up? Specifically:

  • Server version (just confirm this is 1.11.4)
  • What is the workflow/activity code? It looks like the cron sample from our sample repo, but have you made any changes?
  • Worker SDK version
  • How many workers are you running?
  • How many instances of the server frontend/history/matching?
  • How many workflows are running at once?
  • Is this behavior correlated with any network disruptions?
  • Can you reproduce this behavior on a fresh dev environment, e.g., a new temporal server setup created with our docker-compose repo?

One more bit of info that might help is to run

tctl --ns your_namespace taskqueue describe --tq main_task_queue_name
tctl --ns your_namespace taskqueue describe --tq sticky_task_queue_name

while it looks like things are stuck, to check that the worker is actually polling on the task queues. The main task queue name is the one that you configured your worker with. The sticky name looks like <hostname>:<uuid>. You can find it in the WorkflowTaskScheduled event that appears to be blocked.

@zydovech
Copy link
Author

  • Server version (just confirm this is 1.11.4)
    • yes，1.11.4
  • What is the workflow/activity code? It looks like the cron sample from our sample repo, but have you made any changes?
    • modified namespace name, taskQueue name, host
func DoSomething(ctx context.Context, lastRunTime, thisRunTime time.Time, runID string) error {
	time.Sleep(2 * time.Second)
	activity.GetLogger(ctx).Info("Cron Local job running.", "lastRunTime_exclude", lastRunTime, "thisRunTime_include", thisRunTime, "info", activity.GetInfo(ctx))
	return nil
}
  • Worker SDK version
    • v1.9.0
  • How many workers are you running?
    • only one
  • How many instances of the server frontend/history/matching?
    • only one
  • How many workflows are running at once?
    • total 100 workflows, 50 worflows with * * * * * , 50 worflows with */2 * * * *
  • Is this behavior correlated with any network disruptions?
    • no
  • Can you reproduce this behavior on a fresh dev environment, e.g., a new temporal server setup created with our docker-compose repo?
    • I ran it on my mac computer and it did not reproduce, which confused me

I have recently been looking at the code related to the temporal server, hoping to find out the corresponding problem, the code has not been understood yet, is there any detailed documentation?

main_task_queue_name info:

       WORKFLOW POLLER IDENTITY        |   LAST ACCESS TIME
  11704@xxx@ | 2021-08-23T09:52:00Z

sticky_task_queue_name info :

        WORKFLOW POLLER IDENTITY        |   LAST ACCESS TIME
  11704@xxx@ | 2021-08-23T09:53:02Z

@zydovech
Copy link
Author

I found the problem. When the task was inserted into the tasks table, the return was successful, but the data was not written successfully, which resulted in the subsequent read failure. There is no such problem after changing the database

@yiminc
Copy link
Member

yiminc commented Aug 25, 2021

@zydovech, could you help us understand this a little bit more?
It would be awesome if we could repro this problem with your help to setup similar server + db.
Were you able to repro with specific database setup? What db did you use, and any special configuration you had for that db?

@yiminc yiminc reopened this Aug 25, 2021
@zydovech
Copy link
Author

zydovech commented Aug 29, 2021 •
edited

i'm so sorry，missed your information,and didn't reply timely，It's a simple mistake. the database , read and write separation. that caused the successful write is not read immediately . I did not update the above reply in time

@samarabbas
Copy link
Contributor

@zydovech thanks for the update. Resolving the issue now.

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

@dnr dnr

Labels
close-after-30-days
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
4 participants
@dnr @samarabbas @zydovech @yiminc