more debugging logs

temporalio · Sep 14, 2022 · 7c4bdaf · 7c4bdaf
1 parent 9f7c100
commit 7c4bdaf
Show file tree

Hide file tree

Showing 3 changed files with 43 additions and 0 deletions.
diff --git a/service/history/queues/queue_base.go b/service/history/queues/queue_base.go
@@ -310,6 +310,9 @@ func (p *queueBase) processNewRange() {
 		p.monitor,
 		newReadScope,
 	)
+	if p.category.ID() == tasks.CategoryIDTimer {
+		p.logger.Info("Merging new slice with range", tag.Value(newSlice.Scope()))
+	}
 
 	reader, ok := p.readerGroup.ReaderByID(DefaultReaderId)
 	if !ok {
@@ -381,6 +384,10 @@ func (p *queueBase) rangeCompleteTasks(
 	if p.category.Type() == tasks.CategoryTypeScheduled {
 		oldExclusiveDeletionHighWatermark.TaskID = 0
 		newExclusiveDeletionHighWatermark.TaskID = 0
+		p.logger.Info("Range completing tasks",
+			tag.MinQueryLevel(oldExclusiveDeletionHighWatermark.FireTime),
+			tag.MaxQueryLevel(newExclusiveDeletionHighWatermark.FireTime),
+		)
 	}
 
 	ctx, cancel := newQueueIOContext()

diff --git a/service/history/queues/queue_scheduled.go b/service/history/queues/queue_scheduled.go
@@ -98,6 +98,17 @@ func NewScheduledQueue(
 			// during processing. To compensate for that, add 1ms back when scheduling the task in reader.go.
 			for _, task := range resp.Tasks {
 				task.SetVisibilityTime(task.GetVisibilityTime().Truncate(scheduledTaskPrecision))
+				if retryTimerTask, ok := task.(*tasks.ActivityRetryTimerTask); ok {
+					logger.Info("Loaded activity retry timer",
+						tag.WorkflowNamespaceID(task.GetNamespaceID()),
+						tag.WorkflowID(task.GetWorkflowID()),
+						tag.WorkflowRunID(task.GetRunID()),
+						tag.WorkflowScheduledEventID(retryTimerTask.EventID),
+						tag.Attempt(retryTimerTask.Attempt),
+						tag.TaskVisibilityTimestamp(task.GetVisibilityTime()),
+						tag.TaskID(task.GetTaskID()),
+					)
+				}
 			}
 
 			for len(resp.Tasks) > 0 && !r.ContainsKey(resp.Tasks[0].GetKey()) {

diff --git a/service/history/shard/context_impl.go b/service/history/shard/context_impl.go
@@ -1343,6 +1343,31 @@ func (s *ContextImpl) allocateTaskIDsLocked(
 				visibilityTs := task.GetVisibilityTime()
 				s.contextTaggedLogger.Debug("Assigning new timer",
 					tag.Timestamp(visibilityTs), tag.TaskID(task.GetTaskID()), tag.MaxQueryLevel(readCursorTS))
+				if retryTimerTask, ok := task.(*tasks.ActivityRetryTimerTask); ok {
+					s.contextTaggedLogger.Info("Generating activity retry timer",
+						tag.WorkflowNamespaceID(namespaceEntry.ID().String()),
+						tag.WorkflowID(workflowID),
+						tag.WorkflowRunID(task.GetRunID()),
+						tag.WorkflowScheduledEventID(retryTimerTask.EventID),
+						tag.Attempt(retryTimerTask.Attempt),
+						tag.Timestamp(visibilityTs),
+						tag.TaskID(task.GetTaskID()),
+						tag.CursorTimestamp(readCursorTS),
+					)
+				}
+				if workflowTaskTimeoutTask, ok := task.(*tasks.WorkflowTaskTimeoutTask); ok &&
+					workflowTaskTimeoutTask.TimeoutType == enums.TIMEOUT_TYPE_SCHEDULE_TO_START {
+					s.contextTaggedLogger.Info("Generating workflow task timeout timer",
+						tag.WorkflowNamespaceID(namespaceEntry.ID().String()),
+						tag.WorkflowID(workflowID),
+						tag.WorkflowRunID(task.GetRunID()),
+						tag.WorkflowScheduledEventID(workflowTaskTimeoutTask.EventID),
+						tag.Attempt(workflowTaskTimeoutTask.ScheduleAttempt),
+						tag.Timestamp(visibilityTs),
+						tag.TaskID(task.GetTaskID()),
+						tag.CursorTimestamp(readCursorTS),
+					)
+				}
 			}
 		}
 	}