Skip to content

.NET: Use source-generated logging in Foundry Hosting #10122

New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Merged
Roger Barreto (rogerbarreto) merged 3 commits into from
Nov 5, 2026
Merged

.NET: Use source-generated logging in Foundry Hosting #10122

Show file tree
Hide file tree
Changes from all commits
Commits
Show all changes
3 commits
Select commit Hold shift + click to select a range
7bf5699
refactor(logging): generate Foundry log messages
rogerbarreto Nov 5, 2026
cb4cad3
refactor(logging): colocate Foundry messages
rogerbarreto Nov 5, 2026
c01e0ee
fix(logging): restore Foundry event ID zero
rogerbarreto Nov 5, 2026
File filter

Filter by extension

Filter by extension
Conversations
Failed to load comments.
Loading
Jump to
Jump to file
Failed to load files.
Loading
Diff view
Diff view
133 changes: 75 additions & 58 deletions dotnet/src/Microsoft.Agents.AI.Foundry.Hosting/AgentFrameworkResponseHandler.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -27,14 +27,15 @@
using ResponseOutputItemDoneEvent = Azure.AI.AgentServer.Responses.Models.ResponseOutputItemDoneEvent;

namespace Microsoft.Agents.AI.Foundry.Hosting;
#pragma warning disable SYSLIB1006 // Preserve the legacy EventId 0 for every migrated log message.

/// <summary>
/// A <see cref="ResponseHandler"/> implementation that bridges the Azure AI Responses Server SDK
/// with agent-framework <see cref="AIAgent"/> instances, enabling agent-framework agents and workflows
/// to be hosted as Azure Foundry Hosted Agents.
/// </summary>
[Experimental(DiagnosticIds.Experiments.AgentsAIExperiments)]
public class AgentFrameworkResponseHandler : ResponseHandler
public partial class AgentFrameworkResponseHandler : ResponseHandler
{
private const string LatestWorkflowCheckpointIdMetadataKey = "_last_checkpoint_id";
private const string UserPartitionName = "user";
Expand Down Expand Up @@ -484,10 +485,7 @@ await PersistWorkflowCheckpointAsync(
// Catch agent execution errors and emit a proper failed event
// with the real error message instead of letting the SDK emit
// a generic "An internal server error occurred."
if (this._logger.IsEnabled(LogLevel.Error))
{
this._logger.LogError(ex, "Agent execution failed for response {ResponseId}.", context.ResponseId);
}
LogAgentExecutionFailed(this._logger, context.ResponseId, ex);

failedEvent = stream.EmitFailed(
ResponseErrorCode.ServerError,
Expand Down Expand Up @@ -549,13 +547,13 @@ await PersistWorkflowCheckpointAsync(
// preserve the existing behavior and emit incomplete.
if (isResilientTurn)
{
this._logger.LogInformation("Shutdown detected on a resilient turn; deferring for recovery.");
LogShutdownDeferredForRecovery(this._logger);
deferredForRecovery = true;
await context.ExitForRecoveryAsync(cancellationToken).ConfigureAwait(false);
yield break;
}

this._logger.LogInformation("Shutdown detected, emitting incomplete response.");
LogShutdownEmittingIncomplete(this._logger);
yield return stream.EmitIncomplete();
yield break;
}
Expand All @@ -566,12 +564,7 @@ await PersistWorkflowCheckpointAsync(
// same conversation. Finish the current response cleanly so Core can drain the
// queued input as a new handler invocation. The MAF AgentSession is saved in the
// outer finally block and becomes the starting state for that invocation.
if (this._logger.IsEnabled(LogLevel.Information))
{
this._logger.LogInformation(
"Steering input detected for response {ResponseId}; completing the active turn.",
context.ResponseId);
}
LogSteeringInputDetected(this._logger, context.ResponseId);
emittedTerminal = true;
yield return stream.EmitCompleted();
yield break;
Expand Down Expand Up @@ -613,13 +606,7 @@ await PersistWorkflowCheckpointAsync(
}
catch (Exception ex) when (ex is not OperationCanceledException)
{
if (this._logger.IsEnabled(LogLevel.Debug))
{
this._logger.LogDebug(
ex,
"Incremental session save was skipped for response {ResponseId}; the end-of-turn save will persist the final state.",
context.ResponseId);
}
LogIncrementalSessionSaveSkipped(this._logger, context.ResponseId, ex);
}
}

Expand Down Expand Up @@ -663,12 +650,7 @@ await sessionStore.SaveSessionAsync(

if (notAllowedStoreUsageDetected)
{
if (this._logger.IsEnabled(LogLevel.Error))
{
this._logger.LogError(
"Agent '{AgentName}' should not have server side storage enabled. This produced a new untracked conversation/response in the server while the hosted agent also generated a conversation for the request of the agent.",
agent.Name);
}
LogServerSideStorageNotAllowed(this._logger, agent.Name);

throw HostedStoredOutputCompatibility.CreateMisconfiguredAgentError();
}
Expand Down Expand Up @@ -702,14 +684,11 @@ await sessionStore.SaveSessionAsync(
}
catch (Exception ex) when (ex is not OperationCanceledException)
{
if (this._logger.IsEnabled(LogLevel.Debug))
{
this._logger.LogDebug(
ex,
"Workflow checkpoint {CheckpointId} was not paired with response {ResponseId} because its AgentSession could not be saved.",
checkpoint.CheckpointId,
context.ResponseId);
}
LogWorkflowCheckpointNotPaired(
this._logger,
checkpoint.CheckpointId,
context.ResponseId,
ex);

return null;
}
Expand Down Expand Up @@ -832,14 +811,7 @@ await toolboxService
}
catch (InvalidOperationException ex)
{
if (this._logger.IsEnabled(LogLevel.Warning))
{
this._logger.LogWarning(
ex,
"Foundry toolbox '{ToolboxName}' could not be resolved for response {ResponseId}.",
name,
responseId);
}
LogToolboxResolutionFailed(this._logger, name, responseId, ex);

// A resolution error fails the request even when earlier markers collected consents.
return new(Tools: [], Consents: [], Error: ex.Message);
Expand Down Expand Up @@ -960,14 +932,11 @@ private bool AreConsentLinksAllowed(IEnumerable<McpConsentInfo> consents, string
{
if (!policy.IsAllowed(consent.ConsentUrl))
{
if (this._logger.IsEnabled(LogLevel.Warning))
{
this._logger.LogWarning(
"OAuth consent request for tool '{ToolName}' in toolbox '{ToolboxName}' was rejected by the consent link policy for response {ResponseId}.",
consent.ToolName,
consent.ToolboxName,
responseId);
}
LogConsentLinkRejected(
this._logger,
consent.ToolName,
consent.ToolboxName,
responseId);

return false;
}
Expand Down Expand Up @@ -1019,10 +988,7 @@ private AIAgent ResolveAgent(CreateResponse request)
return this.PrepareResolvedAgent(agent, storageIdentity);
}

if (this._logger.IsEnabled(LogLevel.Warning))
{
this._logger.LogWarning("Agent '{AgentName}' not found in keyed services. Attempting default resolution.", agentName);
}
LogKeyedAgentNotFound(this._logger, agentName);
}

// Try non-keyed default
Expand Down Expand Up @@ -1072,10 +1038,7 @@ private AgentSessionStore ResolveSessionStore(CreateResponse request)
return sessionStore;
}

if (this._logger.IsEnabled(LogLevel.Warning))
{
this._logger.LogWarning("SessionStore for agent '{AgentName}' not found in keyed services. Attempting default resolution.", agentName);
}
LogKeyedSessionStoreNotFound(this._logger, agentName);
}

// Try non-keyed default
Expand Down Expand Up @@ -1121,4 +1084,58 @@ private readonly record struct ToolboxRequestResolution(
IReadOnlyList<AITool> Tools,
IReadOnlyList<McpConsentInfo> Consents,
string? Error);

[LoggerMessage(
EventId = 0,
Level = LogLevel.Error,
Message = "Agent execution failed for response {ResponseId}.")]
private static partial void LogAgentExecutionFailed(
ILogger logger,
string responseId,
Exception exception);

[LoggerMessage(LogLevel.Information, "Shutdown detected on a resilient turn; deferring for recovery.", EventId = 0)]
private static partial void LogShutdownDeferredForRecovery(ILogger logger);

[LoggerMessage(LogLevel.Information, "Shutdown detected, emitting incomplete response.", EventId = 0)]
private static partial void LogShutdownEmittingIncomplete(ILogger logger);

[LoggerMessage(LogLevel.Information, "Steering input detected for response {ResponseId}; completing the active turn.", EventId = 0)]
private static partial void LogSteeringInputDetected(ILogger logger, string responseId);

[LoggerMessage(LogLevel.Debug, "Incremental session save was skipped for response {ResponseId}; the end-of-turn save will persist the final state.", EventId = 0)]
private static partial void LogIncrementalSessionSaveSkipped(
ILogger logger,
string responseId,
Exception exception);

[LoggerMessage(LogLevel.Error, "Agent '{AgentName}' should not have server side storage enabled. This produced a new untracked conversation/response in the server while the hosted agent also generated a conversation for the request of the agent.", EventId = 0)]
private static partial void LogServerSideStorageNotAllowed(ILogger logger, string? agentName);

[LoggerMessage(LogLevel.Debug, "Workflow checkpoint {CheckpointId} was not paired with response {ResponseId} because its AgentSession could not be saved.", EventId = 0)]
private static partial void LogWorkflowCheckpointNotPaired(
ILogger logger,
string checkpointId,
string responseId,
Exception exception);

[LoggerMessage(LogLevel.Warning, "Foundry toolbox '{ToolboxName}' could not be resolved for response {ResponseId}.", EventId = 0)]
private static partial void LogToolboxResolutionFailed(
ILogger logger,
string toolboxName,
string responseId,
Exception exception);

[LoggerMessage(LogLevel.Warning, "OAuth consent request for tool '{ToolName}' in toolbox '{ToolboxName}' was rejected by the consent link policy for response {ResponseId}.", EventId = 0)]
private static partial void LogConsentLinkRejected(
ILogger logger,
string toolName,
string toolboxName,
string responseId);

[LoggerMessage(LogLevel.Warning, "Agent '{AgentName}' not found in keyed services. Attempting default resolution.", EventId = 0)]
private static partial void LogKeyedAgentNotFound(ILogger logger, string agentName);

[LoggerMessage(LogLevel.Warning, "SessionStore for agent '{AgentName}' not found in keyed services. Attempting default resolution.", EventId = 0)]
private static partial void LogKeyedSessionStoreNotFound(ILogger logger, string agentName);
}
18 changes: 9 additions & 9 deletions dotnet/src/Microsoft.Agents.AI.Foundry.Hosting/FoundryAgentSessionStore.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -51,7 +51,7 @@ namespace Microsoft.Agents.AI.Foundry.Hosting;
/// </para>
/// </remarks>
[Experimental(DiagnosticIds.Experiments.AgentsAIExperiments)]
public sealed class FoundryAgentSessionStore : AgentSessionStore
public sealed partial class FoundryAgentSessionStore : AgentSessionStore
{
/// <summary>
/// The default state-store name used to hold every agent session persisted by this store.
Expand Down Expand Up @@ -211,14 +211,7 @@ await store.DeleteItemAsync(
catch (FoundryStorageNotFoundException ex)
{
// Nothing stored for this key, so deletion remains idempotent.
if (this._logger.IsEnabled(LogLevel.Debug))
{
this._logger.LogDebug(
ex,
"Session '{SessionId}' was not found in the Foundry state store '{StoreName}'. Nothing to delete.",
key.SessionId,
this.StoreName);
}
LogSessionNotFound(this._logger, key.SessionId, this.StoreName, ex);
}
}

Expand All @@ -232,4 +225,11 @@ private ValueTask<FoundryStateStore> GetStoreAsync(CancellationToken cancellatio
private static BinaryData ToBinaryData(JsonElement element) => FoundryStateStoreJson.ToBinaryData(element);

private static BinaryData ToJsonString(string value) => FoundryStateStoreJson.ToJsonString(value);

[LoggerMessage(LogLevel.Debug, "Session '{SessionId}' was not found in the Foundry state store '{StoreName}'. Nothing to delete.", EventId = 0)]
private static partial void LogSessionNotFound(
ILogger logger,
string sessionId,
string storeName,
Exception exception);
}
68 changes: 47 additions & 21 deletions dotnet/src/Microsoft.Agents.AI.Foundry.Hosting/FoundryJsonCheckpointStore.cs
View file
Open in desktop
Original file line number Diff line number Diff line change
Expand Up @@ -18,6 +18,7 @@
using Microsoft.Shared.Diagnostics;

namespace Microsoft.Agents.AI.Foundry.Hosting;
#pragma warning disable SYSLIB1006 // Preserve the legacy EventId 0 for every migrated log message.

/// <summary>
/// Provides a <see cref="JsonCheckpointStore"/> that persists workflow checkpoints through
Expand Down Expand Up @@ -56,7 +57,7 @@ namespace Microsoft.Agents.AI.Foundry.Hosting;
/// </para>
/// </remarks>
[Experimental(DiagnosticIds.Experiments.AgentsAIExperiments)]
public sealed class FoundryJsonCheckpointStore : JsonCheckpointStore
public sealed partial class FoundryJsonCheckpointStore : JsonCheckpointStore
{
/// <summary>
/// The default state-store name used to hold every workflow checkpoint persisted by this store.
Expand Down Expand Up @@ -243,15 +244,15 @@ await store.SetItemAsync(
// Another writer added a checkpoint to the same session between the read and the
// write. The checkpoint item is already stored under its own key, so the next
// attempt simply re-reads the index and appends to the newer list.
if (this._logger?.IsEnabled(LogLevel.Debug) is true)
if (this._logger is { } logger)
{
this._logger.LogDebug(
ex,
"Attempt {Attempt} of {MaxAttempts} to index checkpoint '{CheckpointId}' for session '{SessionId}' lost to another writer. Retrying.",
LogCheckpointIndexRaceRetry(
logger,
attempt + 1,
this._maxIndexUpdateAttempts,
checkpointInfo.CheckpointId,
sessionId);
sessionId,
ex);
}

continue;
Expand Down Expand Up @@ -384,13 +385,13 @@ entry.ParentCheckpointId is null ||
catch (FoundryStorageNotFoundException ex)
{
// Already deleted, by an earlier attempt or another instance.
if (this._logger?.IsEnabled(LogLevel.Debug) is true)
if (this._logger is { } logger)
{
this._logger.LogDebug(
ex,
"Obsolete checkpoint '{CheckpointId}' of session '{SessionId}' was already gone.",
LogObsoleteCheckpointAlreadyGone(
logger,
entry.CheckpointId,
sessionId);
sessionId,
ex);
}
}
}
Expand All @@ -399,12 +400,9 @@ entry.ParentCheckpointId is null ||
{
// Another instance updated the same session index first. Leaving the old items in place
// is safer than deleting against a stale index; a later resume can prune them.
if (this._logger?.IsEnabled(LogLevel.Debug) is true)
if (this._logger is { } logger)
{
this._logger.LogDebug(
ex,
"Pruning obsolete checkpoints of session '{SessionId}' lost to another writer. The old checkpoints remain until a later resume or expiry.",
sessionId);
LogCheckpointPruningRace(logger, sessionId, ex);
}
}
catch (FoundryStorageException ex)
Expand All @@ -414,11 +412,10 @@ entry.ParentCheckpointId is null ||
// so failing the resume over housekeeping would break a conversation that was about to
// carry on. It is reported instead, because left unreported this is how a session's
// checkpoints would silently pile up until the index no longer fits.
this._logger?.LogWarning(
ex,
"Could not prune obsolete checkpoints of session '{SessionId}' in the Foundry state store '{StoreName}'. The resume itself succeeded; the leftovers stay until the store's own expiry removes them.",
sessionId,
this.StoreName);
if (this._logger is { } logger)
{
LogCheckpointPruningFailed(logger, sessionId, this.StoreName, ex);
}
}
}

Expand Down Expand Up @@ -611,4 +608,33 @@ private static string HashKeyParts(params string[] parts)
}

private sealed record IndexEntry(string CheckpointId, string? ParentCheckpointId, bool HasParentMetadata);

[LoggerMessage(LogLevel.Debug, "Attempt {Attempt} of {MaxAttempts} to index checkpoint '{CheckpointId}' for session '{SessionId}' lost to another writer. Retrying.", EventId = 0)]
private static partial void LogCheckpointIndexRaceRetry(
ILogger logger,
int attempt,
int maxAttempts,
string checkpointId,
string sessionId,
Exception exception);

[LoggerMessage(LogLevel.Debug, "Obsolete checkpoint '{CheckpointId}' of session '{SessionId}' was already gone.", EventId = 0)]
private static partial void LogObsoleteCheckpointAlreadyGone(
ILogger logger,
string checkpointId,
string sessionId,
Exception exception);

[LoggerMessage(LogLevel.Debug, "Pruning obsolete checkpoints of session '{SessionId}' lost to another writer. The old checkpoints remain until a later resume or expiry.", EventId = 0)]
private static partial void LogCheckpointPruningRace(
ILogger logger,
string sessionId,
Exception exception);

[LoggerMessage(LogLevel.Warning, "Could not prune obsolete checkpoints of session '{SessionId}' in the Foundry state store '{StoreName}'. The resume itself succeeded; the leftovers stay until the store's own expiry removes them.", EventId = 0)]
private static partial void LogCheckpointPruningFailed(
ILogger logger,
string sessionId,
string storeName,
Exception exception);
}
Loading
Loading