From b0259134e42afabef69ba567775b437b4ea5e13a Mon Sep 17 00:00:00 2001
From: Zijian <Shaddoll@users.noreply.github.com>
Date: Fri, 5 Jan 2024 11:27:05 -0800
Subject: [PATCH] Add logs to debug timer tasks

---
 common/dynamicconfig/constants.go             |  9 +++++++
 service/history/config/config.go              | 10 ++++----
 .../task/timer_active_task_executor.go        | 24 +++++++++++++++++++
 3 files changed, 39 insertions(+), 4 deletions(-)

diff --git a/common/dynamicconfig/constants.go b/common/dynamicconfig/constants.go
index b1297a86dbf..f25fb01e745 100644
--- 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
index c550d5dd8cf..686c2169962 100644
--- 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
index e2b604ee19e..7c8267013b5 100644
--- 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 {