use InterpolatedStringHandler to move values to CustomDimensions Tags instead of keeping them in the error message

src/ApiService/ApiService/Functions/AgentCanSchedule.cs

@@ -30,8 +30,9 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         var canScheduleRequest = request.OkV;
 
         var node = await _context.NodeOperations.GetByMachineId(canScheduleRequest.MachineId);
+
         if (node == null) {
-            _log.Warning($"Unable to find node {canScheduleRequest.MachineId}");
+            _log.Warning($"Unable to find {canScheduleRequest.MachineId:Tag:MachineId}");
             return await _context.RequestHandling.NotOk(
                 req,
                 new Error(
@@ -52,14 +53,14 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         var workStopped = task == null || task.State.ShuttingDown();
 
         if (workStopped) {
-            _log.Info($"Work stopped {canScheduleRequest.MachineId}");
+            _log.Info($"Work stopped for: {canScheduleRequest.MachineId:Tag:MachineId} and {canScheduleRequest.TaskId:Tag:TaskId}");
             allowed = false;
         }
 
         if (allowed) {
             var scp = await _context.NodeOperations.AcquireScaleInProtection(node);
             if (!scp.IsOk) {
-                _log.Warning($"Failed to acquire scale in protection due to {scp.ErrorV}");
+                _log.Warning($"Failed to acquire scale in protection for: {node.MachineId:Tag:MachineId} in: {node.PoolName:Tag:PoolName} due to {scp.ErrorV:Tag:Error}");
             }
             allowed = scp.IsOk;
         }

src/ApiService/ApiService/Functions/AgentCommands.cs

@@ -38,7 +38,7 @@ private async Async.Task<HttpResponseData> Get(HttpRequestData req) {
             var envelope = new NodeCommandEnvelope(command, messageId);
             return await RequestHandling.Ok(req, new PendingNodeCommand(envelope));
         } else {
-            _log.WithTag("Command", "GET").Verbose($"failed to find machine id {nodeCommand.MachineId}");
+            _log.WithTag("HttpRequest", "GET").Verbose($"failed to find {nodeCommand.MachineId:Tag:MachineId}");
             return await RequestHandling.Ok(req, new PendingNodeCommand(null));
         }
     }
@@ -54,7 +54,7 @@ private async Async.Task<HttpResponseData> Delete(HttpRequestData req) {
         if (message != null) {
             await _context.NodeMessageOperations.Delete(message).IgnoreResult();
         } else {
-            _log.WithTag("Command", "DELETE").Verbose($"failed to find machine id {nodeCommand.MachineId} for message {nodeCommand.MessageId}");
+            _log.WithTag("HttpRequest", "DELETE").Verbose($"failed to find {nodeCommand.MachineId:Tag:MachineId} for {nodeCommand.MessageId:Tag:MessageId}");
         }
 
         return await RequestHandling.Ok(req, new BoolResult(true));

src/ApiService/ApiService/Functions/AgentEvents.cs

@@ -29,7 +29,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         }
 
         var envelope = request.OkV;
-        _log.Info($"node event: machine_id: {envelope.MachineId} event: {EntityConverter.ToJsonString(envelope)}");
+        _log.WithTag("HttpRequest", "POST").Info($"node event: {envelope.MachineId:Tag:MachineId} {EntityConverter.ToJsonString(envelope):Tag:Event}");
 
         var error = envelope.Event switch {
             NodeStateUpdate updateEvent => await OnStateUpdate(envelope.MachineId, updateEvent),
@@ -66,20 +66,20 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
     private async Async.Task<Error?> OnStateUpdate(Guid machineId, NodeStateUpdate ev) {
         var node = await _context.NodeOperations.GetByMachineId(machineId);
         if (node is null) {
-            _log.Warning($"unable to process state update event. machine_id:{machineId} state event:{ev}");
+            _log.Warning($"unable to process state update event. {machineId:Tag:MachineId} {ev:Tag:Event}");
             return null;
         }
 
         if (ev.State == NodeState.Free) {
             if (node.ReimageRequested || node.DeleteRequested) {
-                _log.Info($"stopping free node with reset flags: {machineId}");
+                _log.Info($"stopping free node with reset flags: {machineId:Tag:MachineId}");
                 // discard result: node not used after this point
                 _ = await _context.NodeOperations.Stop(node);
                 return null;
             }
 
             if (await _context.NodeOperations.CouldShrinkScaleset(node)) {
-                _log.Info($"stopping free node to resize scaleset: {machineId}");
+                _log.Info($"stopping free node to resize scaleset: {machineId:Tag:MachineId}");
                 // discard result: node not used after this point
                 _ = await _context.NodeOperations.SetHalt(node);
                 return null;
@@ -88,7 +88,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
 
         if (ev.State == NodeState.Init) {
             if (node.DeleteRequested) {
-                _log.Info($"stopping node (init and delete_requested): {machineId}");
+                _log.Info($"stopping node (init and delete_requested): {machineId:Tag:MachineId}");
                 // discard result: node not used after this point
                 _ = await _context.NodeOperations.Stop(node);
                 return null;
@@ -103,11 +103,11 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
             return null;
         }
 
-        _log.Info($"node state update: {machineId} from {node.State} to {ev.State}");
+        _log.Info($"node state update: {machineId:Tag:MachineId} from {node.State:Tag:FromState} to {ev.State:Tag:ToState}");
         node = await _context.NodeOperations.SetState(node, ev.State);
 
         if (ev.State == NodeState.Free) {
-            _log.Info($"node now available for work: {machineId}");
+            _log.Info($"node now available for work: {machineId:Tag:MachineId}");
         } else if (ev.State == NodeState.SettingUp) {
             if (ev.Data is NodeSettingUpEventData settingUpData) {
                 if (!settingUpData.Tasks.Any()) {
@@ -124,7 +124,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
                             Errors: new string[] { $"unable to find task: {taskId}" });
                     }
 
-                    _log.Info($"node starting task.  machine_id: {machineId} job_id: {task.JobId} task_id: {task.TaskId}");
+                    _log.Info($"node starting task. {machineId:Tag:MachineId} {task.JobId:Tag:JobId} {task.TaskId:Tag:TaskId}");
 
                     // The task state may be `running` if it has `vm_count` > 1, and
                     // another node is concurrently executing the task. If so, leave
@@ -142,7 +142,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
                         State: NodeTaskState.SettingUp);
                     var r = await _context.NodeTasksOperations.Replace(nodeTask);
                     if (!r.IsOk) {
-                        _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace node task {task.TaskId}");
+                        _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace node task {task.TaskId:Tag:TaskId}");
                     }
                 }
             }
@@ -152,7 +152,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
                 if (doneData.Error is not null) {
                     var errorText = EntityConverter.ToJsonString(doneData);
                     error = new Error(ErrorCode.TASK_FAILED, Errors: new string[] { errorText });
-                    _log.Error($"node 'done' with error: machine_id:{machineId}, data:{errorText}");
+                    _log.Error($"node 'done' {machineId:Tag:MachineId} - {errorText:Tag:Error}");
                 }
             }
 
@@ -208,15 +208,15 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
             State: NodeTaskState.Running);
         var r = await _context.NodeTasksOperations.Replace(nodeTask);
         if (!r.IsOk) {
-            _log.WithHttpStatus(r.ErrorV).Error($"failed to replace node task {nodeTask.TaskId}");
+            _log.WithHttpStatus(r.ErrorV).Error($"failed to replace node task {nodeTask.TaskId:Tag:TaskId}");
         }
 
         if (task.State.ShuttingDown()) {
-            _log.Info($"ignoring task start from node. machine_id:{machineId} job_id:{task.JobId} task_id:{task.TaskId} (state: {task.State})");
+            _log.Info($"ignoring task start from node. {machineId:Tag:MachineId} {task.JobId:Tag:JobId} {task.TaskId:Tag:TaskId} ({task.State:Tag:State})");
             return null;
         }
 
-        _log.Info($"task started on node. machine_id:{machineId} job_id:{task.JobId} task_id:{task.TaskId}");
+        _log.Info($"task started on node. {machineId:Tag:MachineId} {task.JobId:Tag:JobId} {task.TaskId:Tag:TaskId}");
         task = await _context.TaskOperations.SetState(task, TaskState.Running);
 
         var taskEvent = new TaskEvent(
@@ -225,7 +225,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
             EventData: new WorkerEvent(Running: running));
         r = await _context.TaskEventOperations.Replace(taskEvent);
         if (!r.IsOk) {
-            _log.WithHttpStatus(r.ErrorV).Error($"failed to replace taskEvent for task with id {taskEvent.TaskId}");
+            _log.WithHttpStatus(r.ErrorV).Error($"failed to replace taskEvent {taskEvent.TaskId:Tag:TaskId}");
         }
 
         return null;
@@ -255,15 +255,15 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         };
 
         if (done.ExitStatus.Success) {
-            _log.Info($"task done. {task.JobId}:{task.TaskId} status:{done.ExitStatus}");
+            _log.Info($"task done. {task.JobId:Tag:JobId}:{task.TaskId:Tag:TaskId} {done.ExitStatus:Tag:Status}");
             await _context.TaskOperations.MarkStopping(task);
 
             // keep node if keep-on-completion is set
             if (task.Config.Debug?.Contains(TaskDebugFlag.KeepNodeOnCompletion) == true) {
                 node = node with { DebugKeepNode = true };
                 var r = await _context.NodeOperations.Replace(node);
                 if (!r.IsOk) {
-                    _log.WithHttpStatus(r.ErrorV).Error($"keepNodeOnCompletion: failed to replace node {node.MachineId} when setting debug keep node to true");
+                    _log.WithHttpStatus(r.ErrorV).Error($"keepNodeOnCompletion: failed to replace node {node.MachineId:Tag:MachineId} when setting debug keep node to true");
                 }
             }
         } else {
@@ -283,22 +283,22 @@ await _context.TaskOperations.MarkFailed(
                 node = node with { DebugKeepNode = true };
                 var r = await _context.NodeOperations.Replace(node);
                 if (!r.IsOk) {
-                    _log.WithHttpStatus(r.ErrorV).Error($"keepNodeOnfFailure: failed to replace node {node.MachineId} when setting debug keep node to true");
+                    _log.WithHttpStatus(r.ErrorV).Error($"keepNodeOnfFailure: failed to replace node {node.MachineId:Tag:MachineId} when setting debug keep node to true");
                 }
             }
         }
 
         if (!node.DebugKeepNode) {
             var r = await _context.NodeTasksOperations.Delete(new NodeTasks(machineId, done.TaskId));
             if (!r.IsOk) {
-                _log.WithHttpStatus(r.ErrorV).Error($"failed to deleting node task since DebugKeepNode is false");
+                _log.WithHttpStatus(r.ErrorV).Error($"failed to deleting node task {done.TaskId:Tag:TaskId} for: {machineId:Tag:MachineId} since DebugKeepNode is false");
             }
         }
 
         var taskEvent = new TaskEvent(done.TaskId, machineId, new WorkerEvent { Done = done });
         var r1 = await _context.TaskEventOperations.Replace(taskEvent);
         if (!r1.IsOk) {
-            _log.WithHttpStatus(r1.ErrorV).Error($"failed to update task event for done task {done.TaskId}");
+            _log.WithHttpStatus(r1.ErrorV).Error($"failed to update task event for done task {done.TaskId:Tag:TaskId}");
         }
         return null;
     }

src/ApiService/ApiService/Functions/AgentRegistration.cs

@@ -109,7 +109,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
 
         var version = uri["version"] ?? "1.0.0";
 
-        _log.Info($"registration request: machine_id: {machineId} pool_name: {poolName} scaleset_id: {scalesetId} version: {version}");
+        _log.Info($"registration request: {machineId:Tag:MachineId} {poolName:Tag:PoolName} {scalesetId:Tag:ScalesetId} {version:Tag:Version}");
         var poolResult = await _context.PoolOperations.GetByName(poolName);
         if (!poolResult.IsOk) {
             return await _context.RequestHandling.NotOk(
@@ -136,7 +136,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
 
         var r = await _context.NodeOperations.Replace(node);
         if (!r.IsOk) {
-            _log.WithHttpStatus(r.ErrorV).WithTag("MachineId", node.MachineId.ToString()).Error("failed to replace node operations for node {MachineId}");
+            _log.WithHttpStatus(r.ErrorV).Error($"failed to replace node operations for {node.MachineId:Tag:MachineId}");
         }
 
         return await RequestHandling.Ok(req, await CreateRegistrationResponse(pool));

src/ApiService/ApiService/Functions/Containers.cs

@@ -74,7 +74,7 @@ private async Async.Task<HttpResponseData> Delete(HttpRequestData req) {
         }
 
         var delete = request.OkV;
-        _logger.Info($"container - deleting {delete.Name}");
+        _logger.Info($"deleting {delete.Name:Tag:ContainerName}");
         var container = await _context.Containers.FindContainer(delete.Name, StorageType.Corpus);
 
         var deleted = false;
@@ -92,7 +92,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         }
 
         var post = request.OkV;
-        _logger.Info($"container - creating {post.Name}");
+        _logger.Info($"creating {post.Name:Tag:ContainerName}");
         var sas = await _context.Containers.CreateContainer(
             post.Name,
             StorageType.Corpus,

src/ApiService/ApiService/Functions/InstanceConfig.cs

@@ -61,7 +61,7 @@ public async Async.Task<HttpResponseData> Post(HttpRequestData req) {
         await _context.ConfigOperations.Save(request.OkV.config, false, false);
         if (updateNsg) {
             await foreach (var nsg in _context.NsgOperations.ListNsgs()) {
-                _log.Info($"Checking if nsg: {nsg.Data.Location!} ({nsg.Data.Name}) owned by OneFuzz");
+                _log.Info($"Checking if nsg: {nsg.Data.Location!:Tag:Location} ({nsg.Data.Name:Tag:NsgName}) owned by OneFuzz");
                 if (nsg.Data.Location! == nsg.Data.Name) {
                     var result = await _context.NsgOperations.SetAllowedSources(new Nsg(nsg.Data.Location!, nsg.Data.Location!), request.OkV.config.ProxyNsgConfig!);
                     if (!result.IsOk) {

src/ApiService/ApiService/Functions/Jobs.cs

@@ -70,7 +70,7 @@ private async Task<HttpResponseData> Post(HttpRequestData req) {
         job = job with { Config = job.Config with { Logs = logContainerUri.ToString() } };
         var r = await _context.JobOperations.Insert(job);
         if (!r.IsOk) {
-            _logTracer.WithHttpStatus(r.ErrorV).Error($"failed to insert job {job.JobId}");
+            _logTracer.WithTag("HttpRequest", "POST").WithHttpStatus(r.ErrorV).Error($"failed to insert job {job.JobId:Tag:JobId}");
         }
         return await RequestHandling.Ok(req, JobResponse.ForJob(job));
     }
@@ -96,7 +96,7 @@ private async Task<HttpResponseData> Delete(HttpRequestData req) {
             job = job with { State = JobState.Stopping };
             var r = await _context.JobOperations.Replace(job);
             if (!r.IsOk) {
-                _logTracer.WithHttpStatus(r.ErrorV).Error($"Failed to replace job {job.JobId}");
+                _logTracer.WithTag("HttpRequest", "DELETE").WithHttpStatus(r.ErrorV).Error($"Failed to replace job {job.JobId:Tag:JobId}");
             }
         }
 

src/ApiService/ApiService/Functions/Node.cs

@@ -142,7 +142,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
 
         var r = await _context.NodeOperations.Replace(node);
         if (!r.IsOk) {
-            _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace node {node.MachineId}");
+            _log.WithTag("HttpRequest", "POST").WithHttpStatus(r.ErrorV).Error($"Failed to replace node {node.MachineId:Tag:MachineId}");
         }
         return await RequestHandling.Ok(req, true);
     }
@@ -176,7 +176,7 @@ private async Async.Task<HttpResponseData> Delete(HttpRequestData req) {
         if (node.DebugKeepNode) {
             var r = await _context.NodeOperations.Replace(node with { DebugKeepNode = false });
             if (!r.IsOk) {
-                _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace node {node.MachineId}");
+                _log.WithTag("HttpRequest", "DELETE").WithHttpStatus(r.ErrorV).Error($"Failed to replace node {node.MachineId:Tag:MachineId}");
             }
         }
 

src/ApiService/ApiService/Functions/Notifications.cs

@@ -16,7 +16,7 @@ public Notifications(ILogTracer log, IEndpointAuthorization auth, IOnefuzzContex
     }
 
     private async Async.Task<HttpResponseData> Get(HttpRequestData req) {
-        _log.Info("Notification search");
+        _log.WithTag("HttpRequest", "GET").Info($"Notification search");
         var request = await RequestHandling.ParseUri<NotificationSearch>(req);
         if (!request.IsOk) {
             return await _context.RequestHandling.NotOk(req, request.ErrorV, "notification search");
@@ -32,7 +32,7 @@ private async Async.Task<HttpResponseData> Get(HttpRequestData req) {
 
 
     private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
-        _log.Info("adding notification hook");
+        _log.WithTag("HttpRequest", "POST").Info($"adding notification hook");
         var request = await RequestHandling.ParseRequest<NotificationCreate>(req);
         if (!request.IsOk) {
             return await _context.RequestHandling.NotOk(req, request.ErrorV, "notification create");

src/ApiService/ApiService/Functions/Proxy.cs

@@ -114,7 +114,7 @@ private async Async.Task<HttpResponseData> Post(HttpRequestData req) {
             var updated = forwardResult.OkV with { ProxyId = proxy.ProxyId };
             var r = await _context.ProxyForwardOperations.Replace(updated);
             if (!r.IsOk) {
-                _log.WithHttpStatus(r.ErrorV).Error($"failed to update proxy forward with machine id {updated.MachineId} with new proxy id {proxy.ProxyId}");
+                _log.WithTag("HttpRequest", "POST").WithHttpStatus(r.ErrorV).Error($"failed to update proxy forward with {updated.MachineId:Tag:MachineId} with new {proxy.ProxyId:Tag:ProxyId}");
             }
             await _context.ProxyOperations.SaveProxyConfig(proxy);
         }

src/ApiService/ApiService/Functions/QueueFileChanges.cs

@@ -55,7 +55,7 @@ private async Async.Task FileAdded(ILogTracer log, JsonDocument fileChangeEvent,
         var container = parts[0];
         var path = string.Join('/', parts.Skip(1));
 
-        log.Info($"file added container: {container} - path: {path}");
+        log.Info($"file added : {container:Tag:Container} - {path:Tag:Path}");
         await _notificationOperations.NewFiles(Container.Parse(container), path, failTaskOnTransientError);
     }
 }

src/ApiService/ApiService/Functions/QueueNodeHeartbeat.cs

@@ -22,20 +22,17 @@ public async Async.Task Run([QueueTrigger("node-heartbeat", Connection = "AzureW
         var events = _context.Events;
 
         var hb = JsonSerializer.Deserialize<NodeHeartbeatEntry>(msg, EntityConverter.GetJsonSerializerOptions()).EnsureNotNull($"wrong data {msg}");
-
         var node = await nodes.GetByMachineId(hb.NodeId);
 
-        var log = _log.WithTag("NodeId", hb.NodeId.ToString());
-
         if (node == null) {
-            log.Warning("invalid node id");
+            _log.Warning($"invalid {hb.NodeId:Tag:NodeId}");
             return;
         }
 
         var newNode = node with { Heartbeat = DateTimeOffset.UtcNow };
         var r = await nodes.Replace(newNode);
         if (!r.IsOk) {
-            log.WithHttpStatus(r.ErrorV).Error($"Failed to replace heartbeat");
+            _log.WithHttpStatus(r.ErrorV).Error($"Failed to replace heartbeat: {hb.NodeId:Tag:NodeId}");
         }
 
         // TODO: do we still send event if we fail do update the table ?