From 6197ac5ab3048c307394ccae8ff8deb13560a1cf Mon Sep 17 00:00:00 2001
From: hchen <hchen@smsassist.com>
Date: Fri, 1 Dec 2023 11:31:45 -0600
Subject: [PATCH] sequential log.

---
 .../Loggers/IContentGeneratingHook.cs         | 12 +++++++++
 .../BotSharp.Logger/Hooks/VerboseLogHook.cs   |  8 +++---
 .../Providers/ChatCompletionProvider.cs       | 26 ++++++++++++-------
 3 files changed, 34 insertions(+), 12 deletions(-)

diff --git a/src/Infrastructure/BotSharp.Abstraction/Loggers/IContentGeneratingHook.cs b/src/Infrastructure/BotSharp.Abstraction/Loggers/IContentGeneratingHook.cs
index c82e2fc3..44f229ae 100644
--- a/src/Infrastructure/BotSharp.Abstraction/Loggers/IContentGeneratingHook.cs
+++ b/src/Infrastructure/BotSharp.Abstraction/Loggers/IContentGeneratingHook.cs
@@ -11,6 +11,18 @@ public interface IContentGeneratingHook
     /// <returns></returns>
     Task BeforeGenerating(Agent agent, List<RoleDialogModel> conversations) => Task.CompletedTask;
 
+    /// <summary>
+    /// Before function is invoked
+    /// </summary>
+    /// <returns></returns>
+    Task BeforeFunctionInvoked(RoleDialogModel message, TokenStatsModel tokenStats) => Task.CompletedTask;
+
+    /// <summary>
+    /// After function is invoked
+    /// </summary>
+    /// <returns></returns>
+    Task AfterFunctionInvoked(RoleDialogModel message, TokenStatsModel tokenStats) => Task.CompletedTask;
+
     /// <summary>
     /// After content generated.
     /// </summary>
diff --git a/src/Infrastructure/BotSharp.Logger/Hooks/VerboseLogHook.cs b/src/Infrastructure/BotSharp.Logger/Hooks/VerboseLogHook.cs
index f93532d8..00b68d4d 100644
--- a/src/Infrastructure/BotSharp.Logger/Hooks/VerboseLogHook.cs
+++ b/src/Infrastructure/BotSharp.Logger/Hooks/VerboseLogHook.cs
@@ -24,8 +24,10 @@ public class VerboseLogHook : IContentGeneratingHook
         if (!_convSettings.ShowVerboseLog) return;
 
         var dialog = conversations.Last();
-        var log = $"{dialog.Role}: {dialog.Content}";
+        var log = $"[msg_id: {dialog.MessageId}] {dialog.Role}: {dialog.Content}";
         _logger.LogInformation(log);
+
+        await Task.CompletedTask;
     }
 
     public async Task AfterGenerated(RoleDialogModel message, TokenStatsModel tokenStats)
@@ -36,8 +38,8 @@ public class VerboseLogHook : IContentGeneratingHook
         var agent = await agentService.LoadAgent(message.CurrentAgentId);
 
         var log = message.Role == AgentRole.Function ?
-                $"[{agent.Name}]: {message.FunctionName}({message.FunctionArgs})" :
-                $"[{agent.Name}]: {message.Content}";
+                $"[[msg_id: {message.MessageId}] [{agent.Name}]: {message.FunctionName}({message.FunctionArgs})" :
+                $"[[msg_id: {message.MessageId}] [{agent.Name}]: {message.Content}";
 
         _logger.LogInformation(tokenStats.Prompt);
         _logger.LogInformation(log);
diff --git a/src/Plugins/BotSharp.Plugin.AzureOpenAI/Providers/ChatCompletionProvider.cs b/src/Plugins/BotSharp.Plugin.AzureOpenAI/Providers/ChatCompletionProvider.cs
index 0a5a18c2..d2bd08a1 100644
--- a/src/Plugins/BotSharp.Plugin.AzureOpenAI/Providers/ChatCompletionProvider.cs
+++ b/src/Plugins/BotSharp.Plugin.AzureOpenAI/Providers/ChatCompletionProvider.cs
@@ -40,8 +40,10 @@ public class ChatCompletionProvider : IChatCompletion
         var contentHooks = _services.GetServices<IContentGeneratingHook>().ToList();
 
         // Before chat completion hook
-        Task.WaitAll(contentHooks.Select(hook => 
-            hook.BeforeGenerating(agent, conversations)).ToArray());
+        foreach (var hook in contentHooks)
+        {
+            hook.BeforeGenerating(agent, conversations).Wait();
+        }
 
         var client = ProviderHelper.GetClient(_model, _settings);
         var (prompt, chatCompletionsOptions) = PrepareOptions(agent, conversations);
@@ -74,14 +76,16 @@ public class ChatCompletionProvider : IChatCompletion
         }
 
         // After chat completion hook
-        Task.WaitAll(contentHooks.Select(hook =>
+        foreach(var hook in contentHooks)
+        {
             hook.AfterGenerated(responseMessage, new TokenStatsModel
             {
                 Prompt = prompt,
                 Model = _model,
                 PromptCount = response.Value.Usage.PromptTokens,
                 CompletionCount = response.Value.Usage.CompletionTokens
-            })).ToArray());
+            }).Wait();
+        }
 
         return responseMessage;
     }
@@ -94,8 +98,10 @@ public class ChatCompletionProvider : IChatCompletion
         var hooks = _services.GetServices<IContentGeneratingHook>().ToList();
 
         // Before chat completion hook
-        Task.WaitAll(hooks.Select(hook =>
-            hook.BeforeGenerating(agent, conversations)).ToArray());
+        foreach (var hook in hooks)
+        {
+            await hook.BeforeGenerating(agent, conversations);
+        }
 
         var client = ProviderHelper.GetClient(_model, _settings);
         var (prompt, chatCompletionsOptions) = PrepareOptions(agent, conversations);
@@ -111,14 +117,16 @@ public class ChatCompletionProvider : IChatCompletion
         };
 
         // After chat completion hook
-        Task.WaitAll(hooks.Select(hook =>
-            hook.AfterGenerated(msg, new TokenStatsModel
+        foreach (var hook in hooks)
+        {
+            await hook.AfterGenerated(msg, new TokenStatsModel
             {
                 Prompt = prompt,
                 Model = _model,
                 PromptCount = response.Value.Usage.PromptTokens,
                 CompletionCount = response.Value.Usage.CompletionTokens
-            })).ToArray());
+            });
+        }
 
         if (choice.FinishReason == CompletionsFinishReason.FunctionCall)
         {