Skip to content
Closed
Show file tree
Hide file tree
Changes from all commits
Commits
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
4 changes: 4 additions & 0 deletions src/Exceptionless.Core/Utility/AppDiagnostics.cs
Original file line number Diff line number Diff line change
Expand Up @@ -91,6 +91,10 @@ public GaugeInfo(Meter meter, string name)
internal static readonly Counter<int> EventsSubmitted = Meter.CreateCounter<int>("ex.events.submitted", description: "Events submitted to the pipeline to be processed");
internal static readonly Counter<long> AssistantTurns = Meter.CreateCounter<long>("ex.assistant.turns", description: "Assistant turns accepted");
internal static readonly Counter<long> AssistantTurnOutcomes = Meter.CreateCounter<long>("ex.assistant.turn.outcomes", description: "Assistant turn outcomes");
internal static readonly Histogram<double> AssistantTurnDuration = Meter.CreateHistogram<double>("ex.assistant.turn.duration", unit: "ms", description: "Assistant response duration including provider and tool work");
internal static readonly Histogram<double> AssistantFirstTextDuration = Meter.CreateHistogram<double>("ex.assistant.turn.first_text.duration", unit: "ms", description: "Time until the first visible assistant text is emitted");
internal static readonly Histogram<double> AssistantProviderDuration = Meter.CreateHistogram<double>("ex.assistant.provider.duration", unit: "ms", description: "Assistant provider request duration including streaming");
internal static readonly Histogram<double> AssistantToolDuration = Meter.CreateHistogram<double>("ex.assistant.tool.duration", unit: "ms", description: "Assistant tool execution duration");
internal static readonly Counter<long> AssistantTurnsBlocked = Meter.CreateCounter<long>("ex.assistant.turns.blocked", description: "Assistant turns blocked by a usage limit");
internal static readonly Counter<long> AssistantProviderRequests = Meter.CreateCounter<long>("ex.assistant.provider.requests", description: "Assistant provider requests");
internal static readonly Counter<long> AssistantToolCalls = Meter.CreateCounter<long>("ex.assistant.tool.calls", description: "Assistant tool calls");
Expand Down
8 changes: 8 additions & 0 deletions src/Exceptionless.Web/ApmExtensions.cs
Original file line number Diff line number Diff line change
Expand Up @@ -129,6 +129,14 @@ public static IHostBuilder AddApm(this IHostBuilder builder, ApmConfig config)
b.AddRuntimeInstrumentation();
b.AddProcessInstrumentation();

foreach (string name in new[] { "ex.assistant.turn.duration", "ex.assistant.turn.first_text.duration", "ex.assistant.provider.duration", "ex.assistant.tool.duration" })
{
b.AddView(name, new ExplicitBucketHistogramConfiguration
{
Boundaries = [50, 100, 250, 500, 1000, 2500, 5000, 10000, 30000, 60000, 120000]
});
}

b.AddView(
"http.server.request.duration",
new ExplicitBucketHistogramConfiguration
Expand Down
40 changes: 40 additions & 0 deletions src/Exceptionless.Web/Assistant/AssistantProviderTiming.cs
Original file line number Diff line number Diff line change
@@ -0,0 +1,40 @@
using System.Diagnostics;

namespace Exceptionless.Web.Assistant;

internal sealed class AssistantProviderTiming(
ILogger<AssistantService> logger,
TimeProvider timeProvider,
AssistantChatRequest request,
string model) : IDisposable
{
private readonly long _started = timeProvider.GetTimestamp();
private bool _completed;
private bool _disposed;

public double ElapsedMilliseconds => timeProvider.GetElapsedTime(_started).TotalMilliseconds;
public double? HeadersDuration { get; set; }
public double? FirstChunkDuration { get; set; }
public string? GenerationId { get; set; }
public string? ProviderName { get; set; }

public void Complete()
{
_completed = true;
Dispose();
}

public void Dispose()
{
if (_disposed)
return;

_disposed = true;
double duration = ElapsedMilliseconds;
AppDiagnostics.AssistantProviderDuration.Record(duration, new KeyValuePair<string, object?>("model", model));
logger.LogInformation(
"Assistant provider timing: duration={DurationMs} ms headers={HeadersDurationMs} ms first_chunk={FirstChunkDurationMs} ms stream_completed={ProviderStreamCompleted} model={Model} provider={ProviderName} generation={ProviderGenerationId} organization={OrganizationId} conversation={ConversationId} trace={TraceId}",
duration, HeadersDuration, FirstChunkDuration, _completed, model, ProviderName, GenerationId,
request.OrganizationId, request.ConversationId, Activity.Current?.TraceId.ToString());
}
}
193 changes: 162 additions & 31 deletions src/Exceptionless.Web/Assistant/AssistantService.cs
Original file line number Diff line number Diff line change
@@ -1,3 +1,4 @@
using System.Diagnostics;
using System.Net.Http.Json;
using System.Runtime.CompilerServices;
using System.Text;
Expand Down Expand Up @@ -41,9 +42,41 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
string userId,
AssistantPlanOptions planOptions,
[EnumeratorCancellation] CancellationToken cancellationToken = default)
{
long started = timeProvider.GetTimestamp();
double? firstTextDuration = null;
string? model = null;
try
{
model = (await assistantModelSettingsService.GetAsync()).Model;
await foreach (var item in StreamCoreAsync(request, userId, planOptions, model, cancellationToken))
{
if (firstTextDuration is null && item.Type == "text_delta" && !String.IsNullOrEmpty(item.Text))
{
firstTextDuration = timeProvider.GetElapsedTime(started).TotalMilliseconds;
AppDiagnostics.AssistantFirstTextDuration.Record(firstTextDuration.Value, new KeyValuePair<string, object?>("model", model));
}
yield return item;
}
}
finally
{
double duration = timeProvider.GetElapsedTime(started).TotalMilliseconds;
AppDiagnostics.AssistantTurnDuration.Record(duration, new KeyValuePair<string, object?>("model", model));
logger.LogInformation(
"Assistant response timing: duration={DurationMs} ms first_text={FirstTextDurationMs} ms model={Model} organization={OrganizationId} conversation={ConversationId} trace={TraceId}",
duration, firstTextDuration, model, request.OrganizationId, request.ConversationId, Activity.Current?.TraceId.ToString());
}
}

private async IAsyncEnumerable<AssistantStreamEvent> StreamCoreAsync(
AssistantChatRequest request,
string userId,
AssistantPlanOptions planOptions,
string model,
[EnumeratorCancellation] CancellationToken cancellationToken)
{
var options = appOptions.AssistantOptions;
string model = (await assistantModelSettingsService.GetAsync()).Model;
AssistantConversationState? conversationState = null;
if (!String.IsNullOrWhiteSpace(request.OrganizationId) && !String.IsNullOrWhiteSpace(request.ConversationId))
{
Expand Down Expand Up @@ -101,6 +134,8 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(

var toolCalls = new Dictionary<int, PendingToolCall>();
var assistantContent = new StringBuilder();
var assistantReasoning = new StringBuilder();
var assistantReasoningDetails = new List<JsonElement>();
// A streamed response cannot be retracted after malformed provider markup reaches the
// browser, so hold this provider round until its content is known to be safe.
var assistantContentChunks = new List<string>();
Expand All @@ -114,10 +149,13 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
}

await using var providerRequest = await assistantUsageService.StartProviderRequestAsync(request.OrganizationId, providerInputCharacters);
using var response = await SendRequestAsync(messages, options, model, allowTools, request, cancellationToken);
using var providerTiming = new AssistantProviderTiming(logger, timeProvider, request, model);
using var response = await SendRequestAsync(messages, options, model, allowTools, request, providerTiming, cancellationToken);
providerRequest.MarkAccepted();
await using var stream = await response.Content.ReadAsStreamAsync(cancellationToken);
using var reader = new StreamReader(stream);
string? generationId = null;
string? providerName = null;

while (await reader.ReadLineAsync(cancellationToken) is { } line)
{
Expand All @@ -128,9 +166,17 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
if (payload.Length == 0 || payload == "[DONE]")
continue;

providerTiming.FirstChunkDuration ??= providerTiming.ElapsedMilliseconds;
using var document = JsonDocument.Parse(payload);
generationId = GetProviderValue(document.RootElement, "id") ?? generationId;
providerName = GetProviderValue(document.RootElement, "provider") ?? providerName;
providerTiming.GenerationId = generationId;
providerTiming.ProviderName = providerName;
if (document.RootElement.TryGetProperty("error", out var error))
{
LogProviderFailure(response, document.RootElement, model, request, generationId, providerName);
throw new AssistantProviderException(GetProviderError(error));
}

if (!usageRecorded && TryGetProviderUsage(document.RootElement, out var usage))
{
Expand All @@ -151,6 +197,20 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
continue;

var delta = choices[0].GetProperty("delta");
if ((delta.TryGetProperty("reasoning", out var reasoning) || delta.TryGetProperty("reasoning_content", out reasoning))
&& reasoning.ValueKind == JsonValueKind.String)
{
assistantReasoning.Append(reasoning.GetString());
}

if (delta.TryGetProperty("reasoning_details", out var reasoningDetails) && reasoningDetails.ValueKind == JsonValueKind.Array)
{
foreach (var detail in reasoningDetails.EnumerateArray())
{
assistantReasoningDetails.Add(detail.Clone());

Copy link
Copy Markdown

Choose a reason for hiding this comment

The reason will be displayed to describe this comment to others. Learn more.

P2 Badge Merge streamed reasoning-detail fragments by block index

When a provider streams one reasoning_details block across multiple deltas, those fragments carry the same block index and may split text, encrypted data, or a final signature. Appending every fragment as a separate array element produces a different, duplicate-index structure in the follow-up assistant message, so providers that validate signed reasoning can reject the tool continuation or lose its context. Reassemble fragments by index before replaying the block; the added test only covers distinct indexes and therefore misses this common streaming case.

Useful? React with 👍 / 👎.

}
}

if (delta.TryGetProperty("content", out var content) && content.ValueKind == JsonValueKind.String)
{
string? text = content.GetString();
Expand Down Expand Up @@ -186,6 +246,9 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
}
}

// Stop before yielding text or running tools so provider time excludes that work.
providerTiming.Complete();

if (s_rawDsmlPattern.IsMatch(assistantContent.ToString()))
{
if (malformedResponseRetries < AssistantLimits.MaximumMalformedResponseRetries)
Expand Down Expand Up @@ -269,17 +332,7 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
}

pendingSuggestedActions = suggestedActions;
messages.Add(new
{
role = "assistant",
content = (string?)null,
tool_calls = suggestedActionCalls.Select(call => new
{
id = call.Id,
type = "function",
function = new { name = call.Name, arguments = call.Arguments.ToString() }
}).ToArray()
});
messages.Add(CreateAssistantToolMessage(suggestedActionCalls, assistantContent, assistantReasoning, assistantReasoningDetails));

string suggestionResult = JsonSerializer.Serialize(new
{
Expand All @@ -300,17 +353,7 @@ public async IAsyncEnumerable<AssistantStreamEvent> StreamAsync(
// let the model offer fresh suggestions with its final answer after the tool results.
pendingSuggestedActions = [];
await assistantUsageService.RecordToolCallsAsync(request.OrganizationId, executableToolCalls.Length);
messages.Add(new
{
role = "assistant",
content = assistantContent.Length == 0 ? null : assistantContent.ToString(),
tool_calls = executableToolCalls.Select(call => new
{
id = call.Id,
type = "function",
function = new { name = call.Name, arguments = call.Arguments.ToString() }
}).ToArray()
});
messages.Add(CreateAssistantToolMessage(executableToolCalls, assistantContent, assistantReasoning, assistantReasoningDetails));

var conversationToolResults = new List<AssistantConversationToolResult>();
foreach (var toolCall in executableToolCalls)
Expand Down Expand Up @@ -384,7 +427,7 @@ await assistantConversationService.AppendToolResultsAsync(
}
}

private async Task<HttpResponseMessage> SendRequestAsync(List<object> messages, AssistantOptions options, string model, bool allowTools, AssistantChatRequest chatRequest, CancellationToken cancellationToken)
private async Task<HttpResponseMessage> SendRequestAsync(List<object> messages, AssistantOptions options, string model, bool allowTools, AssistantChatRequest chatRequest, AssistantProviderTiming timing, CancellationToken cancellationToken)
{
var client = httpClientFactory.CreateClient(nameof(AssistantService));
using var providerRequest = new HttpRequestMessage(HttpMethod.Post, options.Endpoint);
Expand All @@ -407,27 +450,75 @@ private async Task<HttpResponseMessage> SendRequestAsync(List<object> messages,
}
}
};
if (allowTools)
payload["tools"] = AssistantToolDefinitions.Create(tools, chatRequest);
// Tool results still require their schemas when the model must produce a final answer.
payload["tools"] = AssistantToolDefinitions.Create(tools, chatRequest);
if (!allowTools)
{
payload["tool_choice"] = "none";
}

providerRequest.Content = JsonContent.Create(payload);

var response = await client.SendAsync(providerRequest, HttpCompletionOption.ResponseHeadersRead, cancellationToken);
timing.HeadersDuration = timing.ElapsedMilliseconds;
if (response.IsSuccessStatusCode)
return response;

string detail = await response.Content.ReadAsStringAsync(cancellationToken);
logger.LogWarning("Assistant provider returned {StatusCode}: {Detail}", (int)response.StatusCode, detail);
response.Dispose();
using (response)
{
try
{
using var document = await JsonDocument.ParseAsync(await response.Content.ReadAsStreamAsync(cancellationToken), cancellationToken: cancellationToken);
LogProviderFailure(response, document.RootElement, model, chatRequest);
}
catch (JsonException)
{
// Proxy/HTML errors still need their HTTP status and correlation IDs.
LogProviderFailure(response, default, model, chatRequest);
}
}
throw new AssistantProviderException($"The AI provider returned status {(int)response.StatusCode}.");
}

private static Dictionary<string, object?> CreateAssistantToolMessage(
PendingToolCall[] toolCalls,
StringBuilder content,
StringBuilder reasoning,
List<JsonElement> reasoningDetails)
{
var message = new Dictionary<string, object?>
{
["role"] = "assistant",
["content"] = content.Length == 0 ? null : content.ToString(),
["tool_calls"] = toolCalls.Select(call => new
{
id = call.Id,
type = "function",
function = new { name = call.Name, arguments = call.Arguments.ToString() }
}).ToArray()
};

// Reasoning belongs only to this turn's provider conversation. Never send it to the
// browser or persist it with tool results. Structured blocks retain signatures and order.
if (reasoningDetails.Count > 0)
{
message["reasoning_details"] = reasoningDetails;
}
else if (reasoning.Length > 0)
{
message["reasoning"] = reasoning.ToString();
}

return message;
}

private async Task<string> ExecuteToolAsync(
string name,
string arguments,
AssistantChatRequest request,
CancellationToken cancellationToken)
{
using var toolTimer = AppDiagnostics.AssistantToolDuration.StartTimer();
cancellationToken.ThrowIfCancellationRequested();
using var _ = assistantToolContext.BeginTools(request.OrganizationId);
using var document = ParseArguments(arguments);
Expand Down Expand Up @@ -692,7 +783,47 @@ private static int GetBoundedInt32(JsonElement element, int defaultValue, int ma
}

private static string GetProviderError(JsonElement error)
=> error.TryGetProperty("message", out var message) ? message.GetString() ?? "The AI provider returned an error." : "The AI provider returned an error.";
=> error.ValueKind == JsonValueKind.Object && error.TryGetProperty("message", out var message) && message.ValueKind == JsonValueKind.String
? message.GetString() ?? "The AI provider returned an error." : "The AI provider returned an error.";

private void LogProviderFailure(HttpResponseMessage response, JsonElement body, string model, AssistantChatRequest request,
string? generationId = null, string? providerName = null)
{
var error = body.ValueKind == JsonValueKind.Object && body.TryGetProperty("error", out var value) ? value : default;
var metadata = error.ValueKind == JsonValueKind.Object && error.TryGetProperty("metadata", out value) ? value : default;
generationId = GetProviderValue(body, "id") ?? generationId;
if (generationId is null && response.Headers.TryGetValues("X-Generation-Id", out var ids))
{
generationId = ids.FirstOrDefault();
}

// Keep known error fields. Arbitrary metadata.raw/flagged_input can include request content.
logger.LogWarning(
"Assistant provider failed: model={Model} status={ProviderStatusCode} code={ProviderErrorCode} type={ProviderErrorType} upstream_code={UpstreamErrorCode} provider={ProviderName} generation={ProviderGenerationId} organization={OrganizationId} conversation={ConversationId} message={ProviderMessage}",
model, (int)response.StatusCode, GetProviderValue(error, "code"),
GetProviderValue(metadata, "error_type") ?? GetProviderValue(error, "type"),
GetProviderValue(metadata, "provider_code") ?? GetProviderValue(metadata, "provider_error_code"),
GetProviderValue(metadata, "provider_name") ?? GetProviderValue(body, "provider") ?? providerName,
generationId, request.OrganizationId, request.ConversationId, GetProviderError(error));
}

private static string? GetProviderValue(JsonElement element, string name)
{
if (element.ValueKind != JsonValueKind.Object || !element.TryGetProperty(name, out var property))
{
return null;
}

string? value = property.ValueKind switch
{
JsonValueKind.String => property.GetString(),
JsonValueKind.Number => property.GetRawText(),
_ => null
};
return value is { Length: > 0 and <= 128 }
&& value.All(character => Char.IsAsciiLetterOrDigit(character) || character is ' ' or '-' or '_' or '.' or '/' or ':')
? value : null;
}

private sealed class PendingToolCall
{
Expand Down
Loading
Loading