.Net: More telemetry for Sequential, Action and Stepwise planners

dotnet/samples/ApplicationInsightsExample/ApplicationInsightsExample.csproj

@@ -20,8 +20,13 @@
 
   <ItemGroup>
     <ProjectReference Include="..\..\src\Extensions\Planning.SequentialPlanner\Planning.SequentialPlanner.csproj" />
+    <ProjectReference Include="..\..\src\Extensions\Planning.ActionPlanner\Planning.ActionPlanner.csproj" />
+    <ProjectReference Include="..\..\src\Extensions\Planning.StepwisePlanner\Planning.StepwisePlanner.csproj" />
     <ProjectReference Include="..\..\src\Connectors\Connectors.AI.OpenAI\Connectors.AI.OpenAI.csproj" />
     <ProjectReference Include="..\..\src\SemanticKernel\SemanticKernel.csproj" />
+    <ProjectReference Include="..\..\src\Skills\Skills.Core\Skills.Core.csproj" />
+    <ProjectReference Include="..\..\src\Skills\Skills.Web\Skills.Web.csproj" />
+    <ProjectReference Include="..\NCalcSkills\NCalcSkills.csproj" />
   </ItemGroup>
 
 </Project>

dotnet/samples/ApplicationInsightsExample/Program.cs

@@ -13,7 +13,13 @@
 using Microsoft.Extensions.Logging.ApplicationInsights;
 using Microsoft.SemanticKernel;
 using Microsoft.SemanticKernel.Planning;
+using Microsoft.SemanticKernel.Planning.Action;
 using Microsoft.SemanticKernel.Planning.Sequential;
+using Microsoft.SemanticKernel.Planning.Stepwise;
+using Microsoft.SemanticKernel.Skills.Core;
+using Microsoft.SemanticKernel.Skills.Web;
+using Microsoft.SemanticKernel.Skills.Web.Bing;
+using NCalcSkills;
 
 /// <summary>
 /// Example of telemetry in Semantic Kernel using Application Insights within console application.
@@ -43,7 +49,7 @@ public static async Task Main()
         ConfigureTracing(activityListener, telemetryClient);
 
         var kernel = GetKernel(logger);
-        var planner = GetPlanner(kernel, logger);
+        var planner = GetSequentialPlanner(kernel, logger);
 
         try
         {
@@ -98,7 +104,9 @@ private static void ConfigureApplicationInsightsTelemetry(ServiceCollection serv
 
     private static IKernel GetKernel(ILogger logger)
     {
-        string folder = RepoFiles.SampleSkillsPath();
+        var folder = RepoFiles.SampleSkillsPath();
+        var bingConnector = new BingConnector(Env.Var("Bing__ApiKey"));
+        var webSearchEngineSkill = new WebSearchEngineSkill(bingConnector);
 
         var kernel = new KernelBuilder()
             .WithLogger(logger)
@@ -110,10 +118,14 @@ private static IKernel GetKernel(ILogger logger)
 
         kernel.ImportSemanticSkillFromDirectory(folder, "SummarizeSkill", "WriterSkill");
 
+        kernel.ImportSkill(webSearchEngineSkill, "WebSearch");
+        kernel.ImportSkill(new LanguageCalculatorSkill(kernel), "advancedCalculator");
+        kernel.ImportSkill(new TimeSkill(), "time");
+
         return kernel;
     }
 
-    private static ISequentialPlanner GetPlanner(
+    private static ISequentialPlanner GetSequentialPlanner(
         IKernel kernel,
         ILogger logger,
         int maxTokens = 1024)
@@ -123,6 +135,28 @@ private static ISequentialPlanner GetPlanner(
         return new SequentialPlanner(kernel, plannerConfig).WithInstrumentation(logger);
     }
 
+    private static IActionPlanner GetActionPlanner(
+        IKernel kernel,
+        ILogger logger)
+    {
+        return new ActionPlanner(kernel).WithInstrumentation(logger);
+    }
+
+    private static IStepwisePlanner GetStepwisePlanner(
+        IKernel kernel,
+        ILogger logger,
+        int minIterationTimeMs = 1500,
+        int maxTokens = 2000)
+    {
+        var plannerConfig = new StepwisePlannerConfig
+        {
+            MinIterationTimeMs = minIterationTimeMs,
+            MaxTokens = maxTokens
+        };
+
+        return new StepwisePlanner(kernel, plannerConfig).WithInstrumentation(logger);
+    }
+
     /// <summary>
     /// Example of metering configuration in Application Insights
     /// using <see cref="MeterListener"/> to attach for <see cref="Meter"/> recordings.

dotnet/src/Extensions/Planning.ActionPlanner/ActionPlanner.cs

@@ -30,7 +30,7 @@ namespace Microsoft.SemanticKernel.Planning;
 /// The rationale is currently available only in the prompt, we might include it in
 /// the Plan object in future.
 /// </summary>
-public sealed class ActionPlanner
+public sealed class ActionPlanner : IActionPlanner
 {
     private const string StopSequence = "#END-OF-PLAN";
     private const string SkillName = "this";
@@ -78,6 +78,7 @@ public ActionPlanner(
         this._context = kernel.CreateNewContext();
     }
 
+    /// <inheritdoc />
     public async Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellationToken = default)
     {
         if (string.IsNullOrEmpty(goal))

dotnet/src/Extensions/Planning.ActionPlanner/ActionPlannerExtensions.cs

@@ -0,0 +1,21 @@
+// Copyright (c) Microsoft. All rights reserved.
+
+using Microsoft.Extensions.Logging;
+
+namespace Microsoft.SemanticKernel.Planning.Action;
+
+/// <summary>
+/// Extension methods for <see cref="ActionPlanner"/> class.
+/// </summary>
+public static class ActionPlannerExtensions
+{
+    /// <summary>
+    /// Returns decorated instance of <see cref="IActionPlanner"/> with enabled instrumentation.
+    /// </summary>
+    /// <param name="planner">Instance of <see cref="IActionPlanner"/> to decorate.</param>
+    /// <param name="logger">Optional logger.</param>
+    public static IActionPlanner WithInstrumentation(this IActionPlanner planner, ILogger? logger = null)
+    {
+        return new InstrumentedActionPlanner(planner, logger);
+    }
+}

dotnet/src/Extensions/Planning.ActionPlanner/IActionPlanner.cs

@@ -0,0 +1,21 @@
+// Copyright (c) Microsoft. All rights reserved.
+
+using System.Threading;
+using System.Threading.Tasks;
+
+namespace Microsoft.SemanticKernel.Planning.Action;
+
+/// <summary>
+/// Interface for planner that uses a set of semantic functions to select one function out of many and create a plan.
+/// </summary>
+public interface IActionPlanner
+{
+    /// <summary>
+    /// Create a plan for a goal.
+    /// </summary>
+    /// <param name="goal">The goal to create a plan for.</param>
+    /// <param name="cancellationToken">The <see cref="CancellationToken"/> to monitor for cancellation requests. The default is <see cref="CancellationToken.None"/>.</param>
+    /// <returns>The plan.</returns>
+    /// <exception cref="PlanningException">Thrown when the plan cannot be created.</exception>
+    Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellationToken = default);
+}

dotnet/src/Extensions/Planning.ActionPlanner/InstrumentedActionPlanner.cs

@@ -0,0 +1,103 @@
+// Copyright (c) Microsoft. All rights reserved.
+
+using System;
+using System.Diagnostics;
+using System.Diagnostics.Metrics;
+using System.Threading;
+using System.Threading.Tasks;
+using Microsoft.Extensions.Logging;
+using Microsoft.Extensions.Logging.Abstractions;
+
+namespace Microsoft.SemanticKernel.Planning.Action;
+
+/// <summary>
+/// Instrumented planner that uses set of semantic functions to select one function out of many and create a plan.
+/// Captures planner-related logs and metrics.
+/// </summary>
+public class InstrumentedActionPlanner : IActionPlanner
+{
+    /// <summary>
+    /// Initialize a new instance of the <see cref="InstrumentedActionPlanner"/> class.
+    /// </summary>
+    /// <param name="planner">Instance of <see cref="IActionPlanner"/> to decorate.</param>
+    /// <param name="logger">Optional logger.</param>
+    public InstrumentedActionPlanner(
+        IActionPlanner planner,
+        ILogger? logger = null)
+    {
+        this._planner = planner;
+        this._logger = logger ?? NullLogger.Instance;
+    }
+
+    /// <inheritdoc />
+    public async Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellationToken = default)
+    {
+        using var activity = s_activitySource.StartActivity($"{PlannerType}.CreatePlan");
+
+        this._logger.LogInformation("{PlannerType}: Plan creation started.", PlannerType);
+
+        // Sensitive data, logging as trace, disabled by default
+        this._logger.LogTrace("{PlannerType}: Plan Goal: {Goal}", PlannerType, goal);
+
+        var stopwatch = new Stopwatch();
+
+        try
+        {
+            stopwatch.Start();
+
+            var plan = await this._planner.CreatePlanAsync(goal, cancellationToken).ConfigureAwait(false);
+
+            stopwatch.Stop();
+
+            this._logger.LogInformation("{PlannerType}: Plan creation status: {Status}", PlannerType, "Success");
+
+            this._logger.LogInformation("{PlannerType}: Created plan: \n {Plan}", PlannerType, plan.ToSafePlanString());
+
+            // Sensitive data, logging as trace, disabled by default
+            this._logger.LogTrace("{PlannerType}: Created plan with details: \n {Plan}", PlannerType, plan.ToPlanString());
+
+            return plan;
+        }
+        catch (Exception ex)
+        {
+            this._logger.LogInformation("{PlannerType}: Plan creation status: {Status}", PlannerType, "Failed");
+            this._logger.LogError(ex, "{PlannerType}: Plan creation exception details: {Message}", PlannerType, ex.Message);
+
+            throw;
+        }
+        finally
+        {
+            this._logger.LogInformation("{PlannerType}: Plan creation finished in {ExecutionTime}ms.", PlannerType, stopwatch.ElapsedMilliseconds);
+
+            s_createPlanExecutionTime.Record(stopwatch.ElapsedMilliseconds);
+        }
+    }
+
+    #region private ================================================================================
+
+    private const string PlannerType = nameof(ActionPlanner);
+
+    private readonly IActionPlanner _planner;
+    private readonly ILogger _logger;
+
+    /// <summary>
+    /// Instance of <see cref="ActivitySource"/> for planner-related activities.
+    /// </summary>
+    private static ActivitySource s_activitySource = new(typeof(InstrumentedActionPlanner).FullName);
+
+    /// <summary>
+    /// Instance of <see cref="Meter"/> for planner-related metrics.
+    /// </summary>
+    private static Meter s_meter = new(typeof(InstrumentedActionPlanner).FullName);
+
+    /// <summary>
+    /// Instance of <see cref="Histogram{T}"/> to record plan creation execution time.
+    /// </summary>
+    private static Histogram<double> s_createPlanExecutionTime =
+        s_meter.CreateHistogram<double>(
+            name: $"SK.{PlannerType}.CreatePlan.ExecutionTime",
+            unit: "ms",
+            description: "Execution time of plan creation");
+
+    #endregion
+}

dotnet/src/Extensions/Planning.SequentialPlanner/ISequentialPlanner.cs

@@ -6,7 +6,7 @@
 namespace Microsoft.SemanticKernel.Planning.Sequential;
 
 /// <summary>
-/// Interface for planner that uses semantic function to create a sequential plan.
+/// Interface for planner that uses a set of semantic functions to create a sequential plan.
 /// </summary>
 public interface ISequentialPlanner
 {

dotnet/src/Extensions/Planning.SequentialPlanner/InstrumentedSequentialPlanner.cs

@@ -32,12 +32,12 @@ public InstrumentedSequentialPlanner(
     /// <inheritdoc />
     public async Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellationToken = default)
     {
-        using var activity = s_activitySource.StartActivity("SequentialPlanner.CreatePlan");
+        using var activity = s_activitySource.StartActivity($"{PlannerType}.CreatePlan");
 
-        this._logger.LogInformation("Plan creation started.");
+        this._logger.LogInformation("{PlannerType}: Plan creation started.", PlannerType);
 
         // Sensitive data, logging as trace, disabled by default
-        this._logger.LogTrace("Plan Goal: {Goal}", goal);
+        this._logger.LogTrace("{PlannerType}: Plan Goal: {Goal}", PlannerType, goal);
 
         var stopwatch = new Stopwatch();
 
@@ -49,32 +49,34 @@ public async Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellat
 
             stopwatch.Stop();
 
-            this._logger.LogInformation("Plan creation status: {Status}", "Success");
+            this._logger.LogInformation("{PlannerType}: Plan creation status: {Status}", PlannerType, "Success");
 
-            this._logger.LogInformation("Created plan: \n {Plan}", plan.ToSafePlanString());
+            this._logger.LogInformation("{PlannerType}: Created plan: \n {Plan}", PlannerType, plan.ToSafePlanString());
 
             // Sensitive data, logging as trace, disabled by default
-            this._logger.LogTrace("Created plan with details: \n {Plan}", plan.ToPlanString());
+            this._logger.LogTrace("{PlannerType}: Created plan with details: \n {Plan}", PlannerType, plan.ToPlanString());
 
             return plan;
         }
         catch (Exception ex)
         {
-            this._logger.LogInformation("Plan creation status: {Status}", "Failed");
-            this._logger.LogError(ex, "Plan creation exception details: {Message}", ex.Message);
+            this._logger.LogInformation("{PlannerType}: Plan creation status: {Status}", PlannerType, "Failed");
+            this._logger.LogError(ex, "{PlannerType}: Plan creation exception details: {Message}", PlannerType, ex.Message);
 
             throw;
         }
         finally
         {
-            this._logger.LogInformation("Plan creation finished in {ExecutionTime}ms.", stopwatch.ElapsedMilliseconds);
+            this._logger.LogInformation("{PlannerType}: Plan creation finished in {ExecutionTime}ms.", PlannerType, stopwatch.ElapsedMilliseconds);
 
             s_createPlanExecutionTime.Record(stopwatch.ElapsedMilliseconds);
         }
     }
 
     #region private ================================================================================
 
+    private const string PlannerType = nameof(SequentialPlanner);
+
     private readonly ISequentialPlanner _planner;
     private readonly ILogger _logger;
 
@@ -93,7 +95,7 @@ public async Task<Plan> CreatePlanAsync(string goal, CancellationToken cancellat
     /// </summary>
     private static Histogram<double> s_createPlanExecutionTime =
         s_meter.CreateHistogram<double>(
-            name: "SK.SequentialPlanner.CreatePlan.ExecutionTime",
+            name: $"SK.{PlannerType}.CreatePlan.ExecutionTime",
             unit: "ms",
             description: "Execution time of plan creation");
 

dotnet/src/Extensions/Planning.StepwisePlanner/IStepwisePlanner.cs

@@ -0,0 +1,17 @@
+// Copyright (c) Microsoft. All rights reserved.
+
+namespace Microsoft.SemanticKernel.Planning.Stepwise;
+
+/// <summary>
+/// Interface for planner that creates a Stepwise plan using Mrkl systems.
+/// </summary>
+public interface IStepwisePlanner
+{
+    /// <summary>
+    /// Create a plan for a goal.
+    /// </summary>
+    /// <param name="goal">The goal to create a plan for.</param>
+    /// <returns>The plan.</returns>
+    /// <exception cref="PlanningException">Thrown when the plan cannot be created.</exception>
+    Plan CreatePlan(string goal);
+}