Bug fixes for CLI reference handling. Logging cleanup.

ScottArbeit · Dec 12, 2023 · 6e54d5c · 6e54d5c
1 parent 74c1c2b
commit 6e54d5c
Show file tree

Hide file tree

Showing 20 changed files with 95 additions and 92 deletions.
diff --git a/src/Grace.Actors/Branch.Actor.fs b/src/Grace.Actors/Branch.Actor.fs
@@ -98,8 +98,8 @@ module Branch =
                     | Some retrievedDto -> branchDto <- retrievedDto
                     | None -> branchDto <- BranchDto.Default
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         member private this.SetMaintenanceReminder() =
@@ -130,9 +130,9 @@ module Branch =
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
             if String.IsNullOrEmpty(currentCommand) then
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             else
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/BranchName.Actor.fs b/src/Grace.Actors/BranchName.Actor.fs
@@ -32,8 +32,8 @@ module BranchName =
             Task.CompletedTask
 
         override this.OnPostActorMethodAsync(context) =
-            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds * 1000.0).ToString("F0")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/Diff.Actor.fs b/src/Grace.Actors/Diff.Actor.fs
@@ -141,8 +141,8 @@ module Diff =
                     | Some retrievedDto -> diffDto <- retrievedDto
                     | None -> diffDto <- DiffDto.Default
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         override this.OnPreActorMethodAsync(context) =
@@ -152,8 +152,8 @@ module Diff =
             Task.CompletedTask
 
         override this.OnPostActorMethodAsync(context) =
-            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds * 1000.0).ToString("F0")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/DirectoryVersion.Actor.fs b/src/Grace.Actors/DirectoryVersion.Actor.fs
@@ -51,8 +51,8 @@ module DirectoryVersion =
                     log.LogError("{CurrentInstant} Error in {ActorType} {ActorId}.", getCurrentInstantExtended(), this.GetType().Name, host.Id)
                     log.LogError("{CurrentInstant} {ExceptionDetails}", getCurrentInstantExtended(), exc.ToString())
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         override this.OnPreActorMethodAsync(context) =
@@ -62,8 +62,8 @@ module DirectoryVersion =
             Task.CompletedTask
 
         override this.OnPostActorMethodAsync(context) =
-            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds * 1000.0).ToString("F0")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+            let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/Organization.Actor.fs b/src/Grace.Actors/Organization.Actor.fs
@@ -70,8 +70,8 @@ module Organization =
                     | Some retrievedDto -> organizationDto <- retrievedDto
                     | None -> organizationDto <- OrganizationDto.Default
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration)
             } :> Task
 
         member private this.SetMaintenanceReminder() =
@@ -102,9 +102,9 @@ module Organization =
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
             if String.IsNullOrEmpty(currentCommand) then
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             else
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/OrganizationName.Actor.fs b/src/Grace.Actors/OrganizationName.Actor.fs
@@ -34,7 +34,7 @@ module OrganizationName =
 
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; OrganizationName: {OrganizationName}; OrganizationId: {OrganizationId}; Duration: {duration}ms.", 
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; OrganizationName: {OrganizationName}; OrganizationId: {OrganizationId}; Duration: {duration_ms}ms.", 
                 getCurrentInstantExtended(), actorName, context.MethodName, this.Id, (if Option.isSome cachedOrganizationId then cachedOrganizationId.Value else "None"), duration_ms)
             logScope.Dispose()
             Task.CompletedTask

diff --git a/src/Grace.Actors/Owner.Actor.fs b/src/Grace.Actors/Owner.Actor.fs
@@ -70,8 +70,8 @@ module Owner =
                     | Some retrievedDto -> ownerDto <- retrievedDto
                     | None -> ownerDto <- OwnerDto.Default
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         member private this.SetMaintenanceReminder() =
@@ -104,9 +104,9 @@ module Owner =
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
             if String.IsNullOrEmpty(currentCommand) then
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             else
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)    
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)    
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/OwnerName.Actor.fs b/src/Grace.Actors/OwnerName.Actor.fs
@@ -35,7 +35,7 @@ module OwnerName =
 
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; OwnerName: {OwnerName}; OwnerId: {ownerId}; Duration: {duration}ms.", 
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; OwnerName: {OwnerName}; OwnerId: {ownerId}; Duration: {duration_ms}ms.", 
                 getCurrentInstantExtended(), actorName, context.MethodName, this.Id, (if Option.isSome cachedOwnerId then cachedOwnerId.Value else "None"), duration_ms)
             logScope.Dispose()
             Task.CompletedTask

diff --git a/src/Grace.Actors/Reference.Actor.fs b/src/Grace.Actors/Reference.Actor.fs
@@ -39,8 +39,8 @@ module Reference =
                     | Some retrievedDto -> referenceDto <- Some retrievedDto
                     | None -> ()
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         interface IReferenceActor with

diff --git a/src/Grace.Actors/Repository.Actor.fs b/src/Grace.Actors/Repository.Actor.fs
@@ -61,8 +61,8 @@ module Repository =
                     | Some retrievedDto -> repositoryDto <- retrievedDto
                     | None -> repositoryDto <- RepositoryDto.Default
 
-                let duration = getCurrentInstant().Minus(activateStartTime)
-                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration}ms.", getCurrentInstantExtended(), actorName, host.Id, duration.TotalMilliseconds.ToString("F3"))
+                let duration_ms = getCurrentInstant().Minus(activateStartTime).TotalMilliseconds.ToString("F3")
+                log.LogInformation("{CurrentInstant}: Activated {ActorType} {ActorId}. Retrieved from storage in {duration_ms}ms.", getCurrentInstantExtended(), actorName, host.Id, duration_ms)
             } :> Task
 
         override this.OnPreActorMethodAsync(context) =
@@ -82,9 +82,9 @@ module Repository =
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
             if String.IsNullOrEmpty(currentCommand) then
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, this.Id, duration_ms)
             else
-                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
+                log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; Command: {Command}; Id: {Id}; Duration: {duration_ms}ms.", getCurrentInstantExtended(), actorName, context.MethodName, currentCommand, this.Id, duration_ms)
             logScope.Dispose()
             Task.CompletedTask
 

diff --git a/src/Grace.Actors/RepositoryName.Actor.fs b/src/Grace.Actors/RepositoryName.Actor.fs
@@ -35,7 +35,7 @@ module RepositoryName =
 
         override this.OnPostActorMethodAsync(context) =
             let duration_ms = (getCurrentInstant().Minus(actorStartTime).TotalMilliseconds).ToString("F3")
-            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; RepositoryName: {RepositoryName}; RepositoryId: {RepositoryId}; Duration: {duration}ms.", 
+            log.LogInformation("{CurrentInstant}: Finished {ActorName}.{MethodName}; RepositoryName: {RepositoryName}; RepositoryId: {RepositoryId}; Duration: {duration_ms}ms.", 
                 getCurrentInstantExtended(), actorName, context.MethodName, this.Id, (if Option.isSome cachedRepositoryId then cachedRepositoryId.Value else "None"), duration_ms)
             logScope.Dispose()
             Task.CompletedTask

diff --git a/src/Grace.Actors/Services.Actor.fs b/src/Grace.Actors/Services.Actor.fs
@@ -957,7 +957,7 @@ module Services =
                 let mutable requestCharge = 0.0
                 let mutable clientElapsedTime = TimeSpan.Zero
 
-                // In order to build the IN clause, we need to create a parameter for each referenceId. (I tried just using string concatenation, it didn't work for some reason.)
+                // In order to build the IN clause, we need to create a parameter for each referenceId. (I tried just using string concatenation, it didn't work for some reason. Anyway...)
                 // The query starts with:
                 let queryText = StringBuilder(@"SELECT TOP @maxCount c[""value""] FROM c WHERE c[""value""].Class = @class and c[""value""].ReferenceId IN (")
                 // Then we add a parameter for each referenceId.
@@ -968,7 +968,7 @@ module Services =
                 // Create the query definition.
                 let queryDefinition = QueryDefinition(queryText.ToString())
                                         .WithParameter("@maxCount", referenceIds.Count())
-                                        .WithParameter("@class", "ReferenceDto")
+                                        .WithParameter("@class", nameof(ReferenceDto))
 
                 // Add a .WithParameter for each referenceId.
                 referenceIds |> Seq.iteri (fun i referenceId -> queryDefinition.WithParameter($"@referenceId{i}", $"{referenceId}") |> ignore)
@@ -987,7 +987,12 @@ module Services =
                     results.Resource |> Seq.iter (fun refDto -> queryResults.Add(refDto.value.ReferenceId, refDto.value))
 
                 // Add the results to the list in the same order as the supplied referenceIds.
-                referenceIds |> Seq.iter (fun referenceId -> referenceDtos.Add(queryResults[referenceId]))
+                referenceIds |> Seq.iter (fun referenceId -> 
+                    if referenceId <> ReferenceId.Empty then 
+                        referenceDtos.Add(queryResults[referenceId]) 
+                    else
+                        // In case the caller supplied an empty referenceId, add a default ReferenceDto.
+                        referenceDtos.Add(ReferenceDto.Default))
 
                 Activity.Current.SetTag("referenceDtos.Count", $"{referenceDtos.Count}")
                                 .SetTag("clientElapsedTime", $"{clientElapsedTime}")

diff --git a/src/Grace.CLI/Command/Branch.CLI.fs b/src/Grace.CLI/Command/Branch.CLI.fs
@@ -1835,9 +1835,9 @@ module Branch =
                                         $"  None"
                                     else
                                         if parseResult |> verbose then
-                                            $"  {getShortenedSha256Hash referenceDto.Sha256Hash} - {ago referenceDto.CreatedAt} - {instantToLocalTime referenceDto.CreatedAt} [{Colors.Deemphasized}]- {referenceDto.ReferenceId} - {referenceDto.DirectoryId}[/]"
+                                            $"  {getShortSha256Hash referenceDto.Sha256Hash} - {ago referenceDto.CreatedAt} - {instantToLocalTime referenceDto.CreatedAt} [{Colors.Deemphasized}]- {referenceDto.ReferenceId} - {referenceDto.DirectoryId}[/]"
                                         else
-                                            $"  {getShortenedSha256Hash referenceDto.Sha256Hash} - {ago referenceDto.CreatedAt} - {instantToLocalTime referenceDto.CreatedAt} [{Colors.Deemphasized}]- {referenceDto.ReferenceId}[/]"
+                                            $"  {getShortSha256Hash referenceDto.Sha256Hash} - {ago referenceDto.CreatedAt} - {instantToLocalTime referenceDto.CreatedAt} [{Colors.Deemphasized}]- {referenceDto.ReferenceId}[/]"
 
                                 let permissions (branchDto: Dto.Branch.BranchDto) =
                                     let sb = StringBuilder()