Add logs to debug timer tasks

cadence-workflow · Jan 5, 2024 · b025913 · b025913
1 parent c693399
commit b025913
Show file tree

Hide file tree

Showing 3 changed files with 39 additions and 4 deletions.
diff --git a/common/dynamicconfig/constants.go b/common/dynamicconfig/constants.go
@@ -1919,6 +1919,9 @@ const (
 	// Value type: Bool
 	// Default value: true
 	EnableShardIDMetrics
+
+	EnableTimerDebugLogByDomainID
+
 	// LastBoolKey must be the last one in this const group
 	LastBoolKey
 )
@@ -4124,6 +4127,12 @@ var BoolKeys = map[BoolKey]DynamicBool{
 		Description:  "Enable shardId metrics in persistence client",
 		DefaultValue: true,
 	},
+	EnableTimerDebugLogByDomainID: DynamicBool{
+		KeyName:      "history.enableTimerDebugLogByDomainID",
+		Filters:      []Filter{DomainID},
+		Description:  "Enable log for debugging timer task issue by domain",
+		DefaultValue: false,
+	},
 }
 
 var FloatKeys = map[FloatKey]DynamicFloat{

diff --git a/service/history/config/config.go b/service/history/config/config.go
@@ -317,8 +317,9 @@ type Config struct {
 	ActivityMaxScheduleToStartTimeoutForRetry dynamicconfig.DurationPropertyFnWithDomainFilter
 
 	// Debugging configurations
-	EnableDebugMode             bool // note that this value is initialized once on service start
-	EnableTaskInfoLogByDomainID dynamicconfig.BoolPropertyFnWithDomainIDFilter
+	EnableDebugMode               bool // note that this value is initialized once on service start
+	EnableTaskInfoLogByDomainID   dynamicconfig.BoolPropertyFnWithDomainIDFilter
+	EnableTimerDebugLogByDomainID dynamicconfig.BoolPropertyFnWithDomainIDFilter
 
 	// Hotshard stuff
 	SampleLoggingRate                     dynamicconfig.IntPropertyFn
@@ -566,8 +567,9 @@ func New(dc *dynamicconfig.Collection, numberOfShards int, maxMessageSize int, s
 
 		ActivityMaxScheduleToStartTimeoutForRetry: dc.GetDurationPropertyFilteredByDomain(dynamicconfig.ActivityMaxScheduleToStartTimeoutForRetry),
 
-		EnableDebugMode:             dc.GetBoolProperty(dynamicconfig.EnableDebugMode)(),
-		EnableTaskInfoLogByDomainID: dc.GetBoolPropertyFilteredByDomainID(dynamicconfig.HistoryEnableTaskInfoLogByDomainID),
+		EnableDebugMode:               dc.GetBoolProperty(dynamicconfig.EnableDebugMode)(),
+		EnableTaskInfoLogByDomainID:   dc.GetBoolPropertyFilteredByDomainID(dynamicconfig.HistoryEnableTaskInfoLogByDomainID),
+		EnableTimerDebugLogByDomainID: dc.GetBoolPropertyFilteredByDomainID(dynamicconfig.EnableTimerDebugLogByDomainID),
 
 		SampleLoggingRate:                     dc.GetIntProperty(dynamicconfig.SampleLoggingRate),
 		EnableShardIDMetrics:                  dc.GetBoolProperty(dynamicconfig.EnableShardIDMetrics),

diff --git a/service/history/task/timer_active_task_executor.go b/service/history/task/timer_active_task_executor.go
@@ -203,6 +203,30 @@ Loop:
 			return err
 		}
 		updateMutableState = true
+
+		if t.config.EnableDebugMode && t.config.EnableTimerDebugLogByDomainID(task.DomainID) {
+			t.logger.Info("User timer fired",
+				tag.WorkflowDomainID(task.DomainID),
+				tag.WorkflowID(task.WorkflowID),
+				tag.WorkflowRunID(task.RunID),
+				tag.TaskType(task.TaskType),
+				tag.TaskID(task.TaskID),
+				tag.WorkflowTimerID(timerInfo.TimerID),
+				tag.WorkflowScheduleID(timerInfo.StartedID),
+				tag.WorkflowNextEventID(mutableState.GetNextEventID()),
+			)
+		} else {
+			t.logger.Debug("User timer fired",
+				tag.WorkflowDomainID(task.DomainID),
+				tag.WorkflowID(task.WorkflowID),
+				tag.WorkflowRunID(task.RunID),
+				tag.TaskType(task.TaskType),
+				tag.TaskID(task.TaskID),
+				tag.WorkflowTimerID(timerInfo.TimerID),
+				tag.WorkflowScheduleID(timerInfo.StartedID),
+				tag.WorkflowNextEventID(mutableState.GetNextEventID()),
+			)
+		}
 	}
 
 	if !updateMutableState {