various fixes to tracing (#84)

microsoft · Oct 20, 2021 · fae606f · fae606f
1 parent 55e7b2f
commit fae606f
Show file tree

Hide file tree

Showing 20 changed files with 339 additions and 173 deletions.
diff --git a/...eTask.Netherite/Events/PartitionEvents/External/FromClients/ClientTaskMessagesReceived.cs b/...eTask.Netherite/Events/PartitionEvents/External/FromClients/ClientTaskMessagesReceived.cs
@@ -13,6 +13,9 @@ class ClientTaskMessagesReceived : ClientRequestEvent
         [DataMember]
         public TaskMessage[] TaskMessages { get; set; }
 
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.TaskMessages[0].OrchestrationInstance.InstanceId;
+
         public override void DetermineEffects(EffectTracker effects)
         {
             effects.Add(TrackedObjectKey.Sessions);

diff --git a/...ableTask.Netherite/Events/PartitionEvents/External/FromClients/CreationRequestReceived.cs b/...ableTask.Netherite/Events/PartitionEvents/External/FromClients/CreationRequestReceived.cs
@@ -32,11 +32,13 @@ class CreationRequestReceived : ClientRequestEventWithPrefetch
 
         [IgnoreDataMember]
         public string InstanceId => this.ExecutionStartedEvent.OrchestrationInstance.InstanceId;
+
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
 
         [IgnoreDataMember]
         public override TrackedObjectKey Target => TrackedObjectKey.Instance(this.InstanceId);
 
-
         public override bool OnReadComplete(TrackedObject target, Partition partition)
         {
             // Use this moment of time as the creation timestamp, replacing the original timestamp taken on the client.

diff --git a/...ableTask.Netherite/Events/PartitionEvents/External/FromClients/DeletionRequestReceived.cs b/...ableTask.Netherite/Events/PartitionEvents/External/FromClients/DeletionRequestReceived.cs
@@ -22,10 +22,7 @@ class DeletionRequestReceived : ClientRequestEventWithPrefetch
         [IgnoreDataMember]
         public override TrackedObjectKey? Prefetch => TrackedObjectKey.History(this.InstanceId);
 
-        protected override void ExtraTraceInformation(StringBuilder s)
-        {
-            s.Append(' ');
-            s.Append(this.InstanceId);
-        }
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
     }
 }
diff --git a/...rableTask.Netherite/Events/PartitionEvents/External/FromClients/HistoryRequestReceived.cs b/...rableTask.Netherite/Events/PartitionEvents/External/FromClients/HistoryRequestReceived.cs
@@ -16,11 +16,8 @@ class HistoryRequestReceived : ClientReadonlyRequestEvent
         [IgnoreDataMember]
         public override TrackedObjectKey ReadTarget => TrackedObjectKey.History(this.InstanceId);
 
-        protected override void ExtraTraceInformation(StringBuilder s)
-        {
-            s.Append(' ');
-            s.Append(this.InstanceId);
-        }
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
 
         public override void OnReadComplete(TrackedObject target, Partition partition)
         {

diff --git a/...DurableTask.Netherite/Events/PartitionEvents/External/FromClients/StateRequestReceived.cs b/...DurableTask.Netherite/Events/PartitionEvents/External/FromClients/StateRequestReceived.cs
@@ -21,6 +21,9 @@ class StateRequestReceived : ClientReadonlyRequestEvent
         [IgnoreDataMember]
         public override TrackedObjectKey ReadTarget => TrackedObjectKey.Instance(this.InstanceId);
 
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
+
         protected override void ExtraTraceInformation(StringBuilder s)
         {
             s.Append(' ');

diff --git a/src/DurableTask.Netherite/Events/PartitionEvents/External/FromClients/WaitRequestReceived.cs b/src/DurableTask.Netherite/Events/PartitionEvents/External/FromClients/WaitRequestReceived.cs
@@ -16,8 +16,12 @@ class WaitRequestReceived : ClientRequestEventWithPrefetch
         [DataMember]
         public string ExecutionId { get; set; }
 
+        [IgnoreDataMember]
         public override TrackedObjectKey Target => TrackedObjectKey.Instance(this.InstanceId);
 
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
+
         protected override void ExtraTraceInformation(StringBuilder s)
         {
             s.Append(' ');

diff --git a/src/DurableTask.Netherite/Events/PartitionEvents/Internal/BatchProcessed.cs b/src/DurableTask.Netherite/Events/PartitionEvents/Internal/BatchProcessed.cs
@@ -63,6 +63,9 @@ public enum PersistFirstStatus {  NotRequired, Required, Done };
         [IgnoreDataMember]
         public override EventId EventId => EventId.MakePartitionInternalEventId(this.PersistFirst == PersistFirstStatus.Done ? this.WorkItemId + "P" : this.WorkItemId);
 
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.InstanceId;
+
         IEnumerable<TrackedObjectKey> IRequiresPrefetch.KeysToPrefetch
         {
             get
@@ -112,9 +115,6 @@ protected override void ExtraTraceInformation(StringBuilder s)
                 s.Append(' ');
                 s.Append(this.State.OrchestrationStatus);
             }
-
-            s.Append(' ');
-            s.Append(this.InstanceId);
         }
     }
 }
diff --git a/src/DurableTask.Netherite/Events/PartitionEvents/Internal/TimerFired.cs b/src/DurableTask.Netherite/Events/PartitionEvents/Internal/TimerFired.cs
@@ -30,6 +30,10 @@ class TimerFired : PartitionUpdateEvent
         [IgnoreDataMember]
         public override EventId EventId => EventId.MakePartitionInternalEventId(this.WorkItemId);
 
+        [IgnoreDataMember]
+        public override string TracedInstanceId => this.TaskMessage.OrchestrationInstance.InstanceId;
+
+
         public override void DetermineEffects(EffectTracker effects)
         {
             effects.Add(TrackedObjectKey.Sessions);

diff --git a/src/DurableTask.Netherite/Events/PartitionEvents/PartitionEvent.cs b/src/DurableTask.Netherite/Events/PartitionEvents/PartitionEvent.cs
@@ -30,6 +30,12 @@ abstract class PartitionEvent : Event
         [IgnoreDataMember]
         public double IssuedTimestamp { get; set; }
 
+        /// <summary>
+        /// For tracing purposes. Subclasses can override this to provide the instance id.
+        /// </summary>
+        [IgnoreDataMember]
+        public virtual string TracedInstanceId => string.Empty;
+
         // some events trigger some processing immediately upon receive (e.g. prefetches or queries)
         public virtual void OnSubmit(Partition partition) { }
 

diff --git a/src/DurableTask.Netherite/LoadMonitor/LoadMonitor.cs b/src/DurableTask.Netherite/LoadMonitor/LoadMonitor.cs
@@ -69,7 +69,7 @@ public LoadMonitor(
             TransportAbstraction.ISender batchSender)
         {
             this.host = host;
-            this.traceHelper = new LoadMonitorTraceHelper(host.Logger, host.Settings.LogLevelLimit, host.StorageAccountName, host.Settings.HubName);
+            this.traceHelper = new LoadMonitorTraceHelper(host.TraceHelper.Logger, host.Settings.LogLevelLimit, host.StorageAccountName, host.Settings.HubName);
             this.BatchSender = batchSender;
             this.LoadInfo = new SortedDictionary<uint, Info>();
             this.PendingOnSource = new List<TransferCommandReceived>();

diff --git a/src/DurableTask.Netherite/OrchestrationService/Client.cs b/src/DurableTask.Netherite/OrchestrationService/Client.cs
@@ -49,7 +49,7 @@ public Client(
             this.host = host;
             this.ClientId = clientId;
             this.taskHubGuid = taskHubGuid;
-            this.traceHelper = new ClientTraceHelper(host.Logger, host.Settings.LogLevelLimit, host.StorageAccountName, host.Settings.HubName, this.ClientId);
+            this.traceHelper = new ClientTraceHelper(host.TraceHelper.Logger, host.Settings.LogLevelLimit, host.StorageAccountName, host.Settings.HubName, this.ClientId);
             this.workItemTraceHelper = workItemTraceHelper;
             this.account = host.StorageAccountName;
             this.BatchSender = batchSender;