SignalExternalWorkflow hangs with "Workflow task timeout" and "Cached state staled"

I am trying to extend the idea of samples-go/mutex to build a semaphore but I am running into issues of sending signals between workflows.

The following code just shows how I send and receive signals, but I am getting “Task processing failed with error (Error=Workflow task not found.)” and “Cached state staled, new task has unexpected events” for sending both acquire and release signals. Note that the code will eventually completes correctly, but when such error happens, it hangs for about 30 seconds and then replays. I checked the workflow history and see workflow task timeout. In the following code I have 5 workflows sending signals to the mutex/semaphore workflow.

I wonder if I am using the signal correctly. Also I wonder what is the difference between workflow.SignalExternalWorkflow and client.SignalWorkflow.

Here is a log of one run showing the issue:

2021/08/09 00:30:00.210710 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-0 RunID:8668972b-0220-4d9a-bfa7-87e30e994ed5}
2021/08/09 00:30:08.207639 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:08.215341 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:08.223347 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:16.215754 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:16.219663 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:16.228172 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:24.224216 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:24.225362 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:24.232804 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_pollers.go:291: Force RespondWorkflowTaskCompleted. (TaskStartedEventID=3)
2021/08/09 00:30:30.228502 INFO: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_worker_base.go:348: Task processing failed with error (Error=Workflow task not found.)
2021/08/09 00:30:30.241044 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_handlers.go:1117: Cached state staled, new task has unexpected events (CachedPreviousStartedEventID=5, TaskFirstEventID=1, TaskStartedEventID=11, PreviousStartedEventID=0)
2021/08/09 00:30:30.241143 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-0 RunID:8668972b-0220-4d9a-bfa7-87e30e994ed5}
2021/08/09 00:30:30.253971 INFO: fs/distrib/fstemporal/sample.go:70: acquired semaphore for mySampleWorkflow-0
2021/08/09 00:30:30.253997 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_event_handlers.go:556: NewTimer (TimerID=10, Duration=10s)
2021/08/09 00:30:30.259119 INFO: fs/distrib/fstemporal/sample.go:52: level=1
2021/08/09 00:30:30.259141 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-1 RunID:d27a0598-9bac-4315-b16f-8b2d3636e4e0}
2021/08/09 00:30:30.270327 INFO: fs/distrib/fstemporal/sample.go:70: acquired semaphore for mySampleWorkflow-1
2021/08/09 00:30:30.270354 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_event_handlers.go:556: NewTimer (TimerID=10, Duration=10s)
2021/08/09 00:30:30.274580 INFO: fs/distrib/fstemporal/sample.go:52: level=2
2021/08/09 00:30:30.274603 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-2 RunID:48ea46c0-a015-417e-b7df-8fe4dc196eb8}
2021/08/09 00:30:30.287547 INFO: fs/distrib/fstemporal/sample.go:70: acquired semaphore for mySampleWorkflow-2
2021/08/09 00:30:30.287569 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_event_handlers.go:556: NewTimer (TimerID=19, Duration=10s)
2021/08/09 00:30:30.292250 INFO: fs/distrib/fstemporal/sample.go:52: level=3
2021/08/09 00:30:30.292269 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-3 RunID:c3bdea92-11db-4dd4-9b72-36594138e222}
2021/08/09 00:30:30.302242 INFO: fs/distrib/fstemporal/sample.go:70: acquired semaphore for mySampleWorkflow-3
2021/08/09 00:30:30.302278 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_event_handlers.go:556: NewTimer (TimerID=19, Duration=10s)
2021/08/09 00:30:30.306624 INFO: fs/distrib/fstemporal/sample.go:52: level=4
2021/08/09 00:30:30.306657 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-4 RunID:b7d704a3-3287-4f4a-b477-24348ef534e6}
2021/08/09 00:30:30.319115 INFO: fs/distrib/fstemporal/sample.go:70: acquired semaphore for mySampleWorkflow-4
2021/08/09 00:30:30.319140 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_event_handlers.go:556: NewTimer (TimerID=19, Duration=10s)
2021/08/09 00:30:30.323299 INFO: fs/distrib/fstemporal/sample.go:52: level=5
2021/08/09 00:30:40.285448 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-0 RunID:8668972b-0220-4d9a-bfa7-87e30e994ed5}
2021/08/09 00:30:40.285477 INFO: fs/distrib/fstemporal/sample.go:52: level=4
2021/08/09 00:30:40.290560 INFO: fs/distrib/fstemporal/sample.go:77: released semaphore for mySampleWorkflow-0
2021/08/09 00:31:10.296268 INFO: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_worker_base.go:348: Task processing failed with error (Error=Workflow task not found.)
2021/08/09 00:31:10.318938 INFO: fs/distrib/fstemporal/sample.go:77: released semaphore for mySampleWorkflow-2
2021/08/09 00:31:10.323735 INFO: fs/distrib/fstemporal/sample.go:77: released semaphore for mySampleWorkflow-1
2021/08/09 00:31:10.327685 DEBUG: go/pkg/mod/go.temporal.io/sdk@v1.4.1/internal/internal_task_handlers.go:1117: Cached state staled, new task has unexpected events (CachedPreviousStartedEventID=40, TaskFirstEventID=1, TaskStartedEventID=46, PreviousStartedEventID=36)
2021/08/09 00:31:10.327862 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-0 RunID:8668972b-0220-4d9a-bfa7-87e30e994ed5}
2021/08/09 00:31:10.327925 INFO: fs/distrib/fstemporal/sample.go:52: level=1
2021/08/09 00:31:10.327955 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-1 RunID:d27a0598-9bac-4315-b16f-8b2d3636e4e0}
2021/08/09 00:31:10.328045 INFO: fs/distrib/fstemporal/sample.go:52: level=2
2021/08/09 00:31:10.328072 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-2 RunID:48ea46c0-a015-417e-b7df-8fe4dc196eb8}
2021/08/09 00:31:10.328085 INFO: fs/distrib/fstemporal/sample.go:52: level=3
2021/08/09 00:31:10.328094 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-3 RunID:c3bdea92-11db-4dd4-9b72-36594138e222}
2021/08/09 00:31:10.328102 INFO: fs/distrib/fstemporal/sample.go:52: level=4
2021/08/09 00:31:10.328111 INFO: fs/distrib/fstemporal/sample.go:34: received acquire {ID:mySampleWorkflow-4 RunID:b7d704a3-3287-4f4a-b477-24348ef534e6}
2021/08/09 00:31:10.328149 INFO: fs/distrib/fstemporal/sample.go:52: level=5
2021/08/09 00:31:10.328174 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-0 RunID:8668972b-0220-4d9a-bfa7-87e30e994ed5}
2021/08/09 00:31:10.328192 INFO: fs/distrib/fstemporal/sample.go:52: level=4
2021/08/09 00:31:10.328202 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-2 RunID:48ea46c0-a015-417e-b7df-8fe4dc196eb8}
2021/08/09 00:31:10.328210 INFO: fs/distrib/fstemporal/sample.go:52: level=3
2021/08/09 00:31:10.328218 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-1 RunID:d27a0598-9bac-4315-b16f-8b2d3636e4e0}
2021/08/09 00:31:10.328227 INFO: fs/distrib/fstemporal/sample.go:52: level=2
2021/08/09 00:31:10.328236 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-3 RunID:c3bdea92-11db-4dd4-9b72-36594138e222}
2021/08/09 00:31:10.328243 INFO: fs/distrib/fstemporal/sample.go:52: level=1
2021/08/09 00:31:10.328457 INFO: fs/distrib/fstemporal/sample.go:77: released semaphore for mySampleWorkflow-3
2021/08/09 00:31:10.341453 INFO: fs/distrib/fstemporal/sample.go:43: received release {ID:mySampleWorkflow-4 RunID:b7d704a3-3287-4f4a-b477-24348ef534e6}
2021/08/09 00:31:10.341474 INFO: fs/distrib/fstemporal/sample.go:49: level=0; exit
2021/08/09 00:31:10.345524 INFO: fs/distrib/fstemporal/sample.go:77: released semaphore for mySampleWorkflow-4
package fstemporal

import (
	"context"
	"fmt"
	"go.temporal.io/api/enums/v1"
	"go.temporal.io/sdk/client"
	"go.temporal.io/sdk/interceptors"
	"go.temporal.io/sdk/worker"
	"go.temporal.io/sdk/workflow"
	"time"
)

const (
	namespace         = "sample"
	taskQueue         = "sample-tq"
	acquireSignalName = "acquire"
	acquiredSignalName = "acquired"
	releaseSignalName = "release"
	semaphoreWorkflowId = "mySemaphoreWorkflow"
	contextKeyClient = "temporalClient"
)

func mySemaphoreWorkflow(ctx workflow.Context) error {
	logger := workflow.GetLogger(ctx)
	acquireChannel := workflow.GetSignalChannel(ctx, acquireSignalName)
	releaseChannel := workflow.GetSignalChannel(ctx, releaseSignalName)
	level := 0

	s := workflow.NewSelector(ctx)
	var we workflow.Execution
	s.AddReceive(acquireChannel, func(c workflow.ReceiveChannel, more bool) {
		c.Receive(ctx, &we)
		logger.Info(fmt.Sprintf("received acquire %+v", we))
		if err := workflow.SignalExternalWorkflow(ctx, we.ID, we.RunID, acquiredSignalName, "ok").Get(ctx, nil); err != nil {
			logger.Error(fmt.Sprintf("failed to signal acquired to %+v", we))
		} else {
			level++
		}
	})
	s.AddReceive(releaseChannel, func(c workflow.ReceiveChannel, more bool) {
		c.Receive(ctx, &we)
		logger.Info(fmt.Sprintf("received release %+v", we))
		level--
	})
	for {
		s.Select(ctx)
		if level == 0 {
			logger.Info(fmt.Sprintf("level=0; exit"))
			break
		} else {
			logger.Info(fmt.Sprintf("level=%d", level))
		}
	}
	return nil
}

func mySampleWorkflow(ctx workflow.Context) error {
	logger := workflow.GetLogger(ctx)

	activityCtx := workflow.WithLocalActivityOptions(ctx, workflow.LocalActivityOptions{
		ScheduleToCloseTimeout: time.Minute,
		RetryPolicy: nil,
	})
	we := workflow.GetInfo(ctx).WorkflowExecution
	if err := workflow.ExecuteLocalActivity(activityCtx, acquireActivity, semaphoreWorkflowId, we).Get(ctx, nil); err != nil {
		return err
	}
	workflow.GetSignalChannel(ctx, acquiredSignalName).Receive(ctx, nil)
	logger.Info(fmt.Sprintf("acquired semaphore for %s", we.ID))

	workflow.Sleep(ctx, 10 * time.Second)

	if err := workflow.SignalExternalWorkflow(ctx, semaphoreWorkflowId, "", releaseSignalName, we).Get(ctx, nil); err != nil {
		return err
	}
	logger.Info(fmt.Sprintf("released semaphore for %s", we.ID))

	return nil
}

func acquireActivity(ctx context.Context, semaphoreWorkflowId string, workflowExecution workflow.Execution) error {
	options := client.StartWorkflowOptions{
		TaskQueue: taskQueue,
		ID:        semaphoreWorkflowId,
		RetryPolicy: nil,
	}
	temporal := ctx.Value(contextKeyClient).(client.Client)
	_, err := temporal.SignalWithStartWorkflow(ctx, semaphoreWorkflowId, acquireSignalName, workflowExecution, options, mySemaphoreWorkflow)
	return err
}

func SampleStart(ctx context.Context) error {
	temporal, err := NewDefaultClient(ctx, DataPlatformTemporalCluster, namespace)
	if err != nil {
		return err
	}
	defer temporal.Close()

	count := 5
	for i := 0; i < count; i++ {
		id := fmt.Sprintf("mySampleWorkflow-%d", i)
		options := client.StartWorkflowOptions{
			ID:        id,
			TaskQueue: taskQueue,
			WorkflowIDReusePolicy:                    enums.WORKFLOW_ID_REUSE_POLICY_ALLOW_DUPLICATE,
			WorkflowExecutionErrorWhenAlreadyStarted: false,
			RetryPolicy: nil,
		}
		if _, err := temporal.ExecuteWorkflow(ctx, options, mySampleWorkflow); err != nil {
			return err
		}
	}
	return nil
}

func SampleWorker(ctx context.Context) error {
	temporal, err := NewDefaultClient(ctx, DataPlatformTemporalCluster, namespace)
	if err != nil {
		return err
	}
	defer temporal.Close()

	ctx = context.WithValue(ctx, contextKeyClient, temporal)
	w := worker.New(temporal, taskQueue, worker.Options{
		BackgroundActivityContext: ctx,
		WorkflowInterceptorChainFactories: []interceptors.WorkflowInterceptor{
			NewLoggerInterceptor(ctx),
		},
	})
	w.RegisterWorkflow(mySemaphoreWorkflow)
	w.RegisterWorkflow(mySampleWorkflow)
	return w.Run(worker.InterruptCh())
}

Workflow history if helpful

   1  WorkflowExecutionStarted                  {WorkflowType:{Name:mySemaphoreWorkflow},                                            
                                                ParentInitiatedEventId:0,                                                            
                                                TaskQueue:{Name:sample-tq, Kind:Normal},                                             
                                                WorkflowExecutionTimeout:0s, WorkflowRunTimeout:0s,                                  
                                                WorkflowTaskTimeout:10s, Initiator:Unspecified,                                      
                                                OriginalExecutionRunId:a73cced5-2827-4107-8112-a9c4cd0af2ac,                         
                                                Identity:85678@shan@,                                                                
                                                FirstExecutionRunId:a73cced5-2827-4107-8112-a9c4cd0af2ac,                            
                                                Attempt:1, FirstWorkflowTaskBackoff:0s}                                              
   2  WorkflowExecutionSignaled                 {SignalName:acquire,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-0","RunID":"8668972b-0220-4d9a-bfa7-87e30e994ed5"}],  
                                                Identity:85678@shan@}                                                                
   3  WorkflowTaskScheduled                     {TaskQueue:{Name:sample-tq,                                                          
                                                Kind:Normal},                                                                        
                                                StartToCloseTimeout:10s,                                                             
                                                Attempt:1}                                                                           
   4  WorkflowExecutionSignaled                 {SignalName:acquire,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-1","RunID":"d27a0598-9bac-4315-b16f-8b2d3636e4e0"}],  
                                                Identity:85678@shan@}                                                                
   5  WorkflowTaskStarted                       {ScheduledEventId:3, Identity:85678@shan@,                                           
                                                RequestId:dae68e8f-fb21-4a77-be52-ffb41a0d859d}                                      
   6  WorkflowTaskTimedOut                      {ScheduledEventId:3,                                                                 
                                                StartedEventId:5,                                                                    
                                                TimeoutType:StartToClose}                                                            
   7  WorkflowExecutionSignaled                 {SignalName:acquire,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-2","RunID":"48ea46c0-a015-417e-b7df-8fe4dc196eb8"}],  
                                                Identity:85678@shan@}                                                                
   8  WorkflowExecutionSignaled                 {SignalName:acquire,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-3","RunID":"c3bdea92-11db-4dd4-9b72-36594138e222"}],  
                                                Identity:85678@shan@}                                                                
   9  WorkflowExecutionSignaled                 {SignalName:acquire,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-4","RunID":"b7d704a3-3287-4f4a-b477-24348ef534e6"}],  
                                                Identity:85678@shan@}                                                                
  10  WorkflowTaskScheduled                     {TaskQueue:{Name:sample-tq,                                                          
                                                Kind:Normal},                                                                        
                                                StartToCloseTimeout:10s,                                                             
                                                Attempt:1}                                                                           
  11  WorkflowTaskStarted                       {ScheduledEventId:10, Identity:85678@shan@,                                          
                                                RequestId:9ce6f2de-35cc-40ec-8039-7c7c3bf2ff8c}                                      
  12  WorkflowTaskCompleted                     {ScheduledEventId:10,                                                                
                                                StartedEventId:11, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  13  SignalExternalWorkflowExecutionInitiated  {WorkflowTaskCompletedEventId:12,                                                    
                                                Namespace:sample,                                                                    
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-0,                                    
                                                RunId:8668972b-0220-4d9a-bfa7-87e30e994ed5},                                         
                                                SignalName:acquired, Input:["ok"],                                                   
                                                Control:13, ChildWorkflowOnly:false}                                                 
  14  ExternalWorkflowExecutionSignaled         {InitiatedEventId:13, Namespace:sample,                                              
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-0,                                    
                                                RunId:8668972b-0220-4d9a-bfa7-87e30e994ed5},                                         
                                                Control:13}                                                                          
  15  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  16  WorkflowTaskStarted                       {ScheduledEventId:15, Identity:85678@shan@,                                          
                                                RequestId:f79af656-8d59-407f-b215-4115aa0ef3e5}                                      
  17  WorkflowTaskCompleted                     {ScheduledEventId:15,                                                                
                                                StartedEventId:16, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  18  SignalExternalWorkflowExecutionInitiated  {WorkflowTaskCompletedEventId:17,                                                    
                                                Namespace:sample,                                                                    
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-1,                                    
                                                RunId:d27a0598-9bac-4315-b16f-8b2d3636e4e0},                                         
                                                SignalName:acquired, Input:["ok"],                                                   
                                                Control:18, ChildWorkflowOnly:false}                                                 
  19  ExternalWorkflowExecutionSignaled         {InitiatedEventId:18, Namespace:sample,                                              
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-1,                                    
                                                RunId:d27a0598-9bac-4315-b16f-8b2d3636e4e0},                                         
                                                Control:18}                                                                          
  20  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  21  WorkflowTaskStarted                       {ScheduledEventId:20, Identity:85678@shan@,                                          
                                                RequestId:a479d6a2-761f-4c64-80b3-8cd8dddf102e}                                      
  22  WorkflowTaskCompleted                     {ScheduledEventId:20,                                                                
                                                StartedEventId:21, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  23  SignalExternalWorkflowExecutionInitiated  {WorkflowTaskCompletedEventId:22,                                                    
                                                Namespace:sample,                                                                    
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-2,                                    
                                                RunId:48ea46c0-a015-417e-b7df-8fe4dc196eb8},                                         
                                                SignalName:acquired, Input:["ok"],                                                   
                                                Control:23, ChildWorkflowOnly:false}                                                 
  24  ExternalWorkflowExecutionSignaled         {InitiatedEventId:23, Namespace:sample,                                              
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-2,                                    
                                                RunId:48ea46c0-a015-417e-b7df-8fe4dc196eb8},                                         
                                                Control:23}                                                                          
  25  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  26  WorkflowTaskStarted                       {ScheduledEventId:25, Identity:85678@shan@,                                          
                                                RequestId:ffee374c-0538-42ba-815b-22b328ab03e1}                                      
  27  WorkflowTaskCompleted                     {ScheduledEventId:25,                                                                
                                                StartedEventId:26, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  28  SignalExternalWorkflowExecutionInitiated  {WorkflowTaskCompletedEventId:27,                                                    
                                                Namespace:sample,                                                                    
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-3,                                    
                                                RunId:c3bdea92-11db-4dd4-9b72-36594138e222},                                         
                                                SignalName:acquired, Input:["ok"],                                                   
                                                Control:28, ChildWorkflowOnly:false}                                                 
  29  ExternalWorkflowExecutionSignaled         {InitiatedEventId:28, Namespace:sample,                                              
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-3,                                    
                                                RunId:c3bdea92-11db-4dd4-9b72-36594138e222},                                         
                                                Control:28}                                                                          
  30  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  31  WorkflowTaskStarted                       {ScheduledEventId:30, Identity:85678@shan@,                                          
                                                RequestId:c87caf82-02d0-420c-985f-8c7365da4b42}                                      
  32  WorkflowTaskCompleted                     {ScheduledEventId:30,                                                                
                                                StartedEventId:31, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  33  SignalExternalWorkflowExecutionInitiated  {WorkflowTaskCompletedEventId:32,                                                    
                                                Namespace:sample,                                                                    
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-4,                                    
                                                RunId:b7d704a3-3287-4f4a-b477-24348ef534e6},                                         
                                                SignalName:acquired, Input:["ok"],                                                   
                                                Control:33, ChildWorkflowOnly:false}                                                 
  34  ExternalWorkflowExecutionSignaled         {InitiatedEventId:33, Namespace:sample,                                              
                                                WorkflowExecution:{WorkflowId:mySampleWorkflow-4,                                    
                                                RunId:b7d704a3-3287-4f4a-b477-24348ef534e6},                                         
                                                Control:33}                                                                          
  35  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  36  WorkflowTaskStarted                       {ScheduledEventId:35, Identity:85678@shan@,                                          
                                                RequestId:578aa99e-5aad-4c58-8d2e-832c1a5a0ec2}                                      
  37  WorkflowTaskCompleted                     {ScheduledEventId:35,                                                                
                                                StartedEventId:36, Identity:85678@shan@,                                             
                                                BinaryChecksum:6fea92e791ef2b95307aad61ea64fa28}                                     
  38  WorkflowExecutionSignaled                 {SignalName:release,                                                                 
                                                Input:[{"ID":"mySampleWorkflow-0","RunID":"8668972b-0220-4d9a-bfa7-87e30e994ed5"}],  
                                                Identity:history-service}                                                            
  39  WorkflowTaskScheduled                     {TaskQueue:{Name:shan:c37c6d4f-5a64-4495-8afd-fbf836568eae,                          
                                                Kind:Sticky}, StartToCloseTimeout:10s, Attempt:1}                                    
  40  WorkflowTaskStarted                       {ScheduledEventId:39, Identity:85678@shan@,                                          
                                                RequestId:1cc3ac97-34dd-4e89-a154-d392f544c4c0}                                      
  41  WorkflowTaskTimedOut                      {ScheduledEventId:39,                                                                
                                                StartedEventId:40,                                                                   
                                                TimeoutType:StartToClose}                                                            
  42  WorkflowExecutionSignaled  ....

Thanks.

This may be a set up issue, there is errors in the server log:

{"level":"error","ts":"2021-08-09T18:13:25.661Z","msg":"Operation failed with internal error.","service":"history","error":"applyWorkflowMutationTx failed. Error: updateBufferedEvents operation failed. Error: pq: permission denied for sequence buffered_events_id_seq","metric-scope":5

The issue seems to go away when the permission is fixed. I tried to increase workflows to 20 at the same time, and it gives the following server error:

{"level":"error","ts":"2021-08-09T18:31:15.336Z","msg":"Persistent store operation failure","service":"history","shard-id":4,"address":"127.0.0.1:9284","shard-item":"0xc000177800","component":"history-engine","wf-id":"mySemaphoreWorkflow","wf-run-id":"146026d9-ea73-47c2-90d0-e976b62acb10","wf-namespace-id":"28b18fe6-f654-4eaa-b8d5-5d92a77a1941","store-operation":"create-wf-execution","error":"Workflow execution creation condition failed. WorkflowId: mySemaphoreWorkflow, State: Running, Expected: Completed"

Though workflows run fine. Looks like some optimistic error.