forked from zhongkaifu/TensorSharp
-
Notifications
You must be signed in to change notification settings - Fork 0
Expand file tree
/
Copy pathInferenceTelemetry.cs
More file actions
362 lines (327 loc) · 16.1 KB
/
Copy pathInferenceTelemetry.cs
File metadata and controls
362 lines (327 loc) · 16.1 KB
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
253
254
255
256
257
258
259
260
261
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280
281
282
283
284
285
286
287
288
289
290
291
292
293
294
295
296
297
298
299
300
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325
326
327
328
329
330
331
332
333
334
335
336
337
338
339
340
341
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
358
359
360
361
362
// Copyright (c) Zhongkai Fu. All rights reserved.
// https://github.com/zhongkaifu/TensorSharp
//
// This file is part of TensorSharp.
//
// TensorSharp is licensed under the BSD-3-Clause license found in the LICENSE file in the root directory of this source tree.
//
// TensorSharp is distributed in the hope that it will be useful, but WITHOUT ANY WARRANTY; without even the implied warranty of
// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE. See the BSD-3-Clause License for more details.
using System;
using System.Collections.Generic;
using System.Diagnostics;
using System.IO;
using System.Text.Encodings.Web;
using System.Text.Json;
using System.Text.Json.Serialization;
using Microsoft.Extensions.Logging;
namespace TensorSharp.Server
{
internal sealed class InferenceTelemetry
{
private readonly ILogger _logger;
private const int MaxLoggedMessageChars = 512;
// Reused JSON options for the per-turn input-summary serializer below. Relaxed
// escaping keeps non-ASCII content readable in the log file instead of
// expanding it to \uXXXX escapes; control characters are still escaped by
// JsonSerializer so each entry stays on a single line.
private static readonly JsonSerializerOptions FullInputJsonOptions = new()
{
PropertyNamingPolicy = JsonNamingPolicy.CamelCase,
DefaultIgnoreCondition = JsonIgnoreCondition.WhenWritingNull,
Encoder = JavaScriptEncoder.UnsafeRelaxedJsonEscaping,
};
public InferenceTelemetry(ILogger logger)
{
_logger = logger ?? Microsoft.Extensions.Logging.Abstractions.NullLogger.Instance;
}
public IDisposable BeginInferenceScope(
ChatSession session,
string modelName,
string backend,
string operation)
{
return _logger.BeginScope(new Dictionary<string, object>(StringComparer.Ordinal)
{
[LogScopeKeys.SessionId] = session.Id,
[LogScopeKeys.Model] = modelName ?? "(none)",
[LogScopeKeys.Backend] = backend ?? "(none)",
[LogScopeKeys.Operation] = operation,
});
}
public void LogChatStarted(
string arch,
int maxTokens,
bool enableThinking,
List<ToolFunction> tools,
List<ChatMessage> preparedHistory,
SamplingConfig samplingConfig)
{
if (!_logger.IsEnabled(LogLevel.Information))
return;
int userMessageCount = 0;
int assistantMessageCount = 0;
int systemMessageCount = 0;
int imageAttachments = 0;
int audioAttachments = 0;
int textFileAttachments = 0;
ChatMessage lastUserMessage = null;
if (preparedHistory != null)
{
foreach (var m in preparedHistory)
{
if (m == null) continue;
if (m.Role == "user")
{
userMessageCount++;
lastUserMessage = m;
}
else if (m.Role == "assistant") assistantMessageCount++;
else if (m.Role == "system") systemMessageCount++;
if (m.ImagePaths != null) imageAttachments += m.ImagePaths.Count;
if (m.AudioPaths != null) audioAttachments += m.AudioPaths.Count;
if (m.TextFilePaths != null) textFileAttachments += m.TextFilePaths.Count;
}
}
string lastUserPreview = BuildMessageContentForLog(
lastUserMessage, out _, out _);
string lastUserContent = LoggingExtensions.SanitizeForLog(
lastUserPreview, MaxLoggedMessageChars);
string turnUploads = SerializeUploadsForLog(lastUserMessage);
string fullInput = SerializeMessagesForLog(preparedHistory);
_logger.LogInformation(LogEventIds.ChatStarted,
"chat.start arch={Architecture} maxTokens={MaxTokens} thinking={EnableThinking} tools={ToolCount} messages(user={UserMessages},assistant={AssistantMessages},system={SystemMessages}) attachments(image={ImageCount},audio={AudioCount},textFile={TextFileCount}) uploads={Uploads} sampling(temp={Temperature},topK={TopK},topP={TopP},minP={MinP},seed={Seed}) userInput=\"{LastUserContent}\" fullInput={FullInput}",
arch, maxTokens, enableThinking, tools?.Count ?? 0,
userMessageCount, assistantMessageCount, systemMessageCount,
imageAttachments, audioAttachments, textFileAttachments,
turnUploads,
samplingConfig?.Temperature ?? 0.8f, samplingConfig?.TopK ?? 40,
samplingConfig?.TopP ?? 0.9f, samplingConfig?.MinP ?? 0f, samplingConfig?.Seed ?? 0,
lastUserContent, fullInput);
}
public void LogChatFinished(
bool wasCancelled,
int generatedTokenCount,
int promptTokenCount,
int kvCacheReusedTokens,
double kvCacheReusePercent,
long timeToFirstTokenMs,
double elapsedMs,
double tokensPerSecond,
string finishReason,
string assistantText)
{
string assistantContent = LoggingExtensions.SanitizeForLogFull(assistantText);
if (wasCancelled)
{
_logger.LogWarning(LogEventIds.ChatAborted,
"chat.cancelled tokens={Tokens} promptTokens={PromptTokens} kvReused={KvReusedTokens} kvReusePercent={KvReusePercent:F1} ttftMs={TimeToFirstTokenMs} elapsedMs={ElapsedMs:F1} assistantOutput=\"{AssistantContent}\"",
generatedTokenCount, promptTokenCount, kvCacheReusedTokens, kvCacheReusePercent,
timeToFirstTokenMs, elapsedMs, assistantContent);
}
else
{
_logger.LogInformation(LogEventIds.ChatCompleted,
"chat.complete tokens={Tokens} promptTokens={PromptTokens} kvReused={KvReusedTokens} kvReusePercent={KvReusePercent:F1} ttftMs={TimeToFirstTokenMs} elapsedMs={ElapsedMs:F1} tokensPerSec={TokensPerSec:F2} finishReason={FinishReason} assistantOutput=\"{AssistantContent}\"",
generatedTokenCount, promptTokenCount, kvCacheReusedTokens, kvCacheReusePercent,
timeToFirstTokenMs, elapsedMs, tokensPerSecond, finishReason, assistantContent);
}
}
public void LogGenerateStarted(
string arch,
int maxTokens,
int imageAttachmentCount,
ChatMessage promptMessage,
SamplingConfig samplingConfig)
{
if (!_logger.IsEnabled(LogLevel.Information))
return;
string promptPreview = BuildMessageContentForLog(
promptMessage, out _, out _);
string promptContent = LoggingExtensions.SanitizeForLog(
promptPreview, MaxLoggedMessageChars);
string turnUploads = SerializeUploadsForLog(promptMessage);
_logger.LogInformation(LogEventIds.ChatStarted,
"generate.start arch={Architecture} maxTokens={MaxTokens} imageAttachments={ImageCount} uploads={Uploads} sampling(temp={Temperature},topK={TopK},topP={TopP},seed={Seed}) prompt=\"{Prompt}\"",
arch, maxTokens, imageAttachmentCount, turnUploads,
samplingConfig?.Temperature ?? 0.8f, samplingConfig?.TopK ?? 40,
samplingConfig?.TopP ?? 0.9f, samplingConfig?.Seed ?? 0,
promptContent);
}
public void LogGenerateFinished(
bool wasCancelled,
int generatedTokenCount,
int promptTokenCount,
int kvCacheReusedTokens,
double kvCacheReusePercent,
double elapsedMs,
double tokensPerSecond,
string finishReason,
string completionText)
{
string completionContent = LoggingExtensions.SanitizeForLogFull(completionText);
if (wasCancelled)
{
_logger.LogWarning(LogEventIds.ChatAborted,
"generate.cancelled tokens={Tokens} promptTokens={PromptTokens} kvReused={KvReusedTokens} kvReusePercent={KvReusePercent:F1} elapsedMs={ElapsedMs:F1} completion=\"{Completion}\"",
generatedTokenCount, promptTokenCount, kvCacheReusedTokens, kvCacheReusePercent,
elapsedMs, completionContent);
}
else
{
_logger.LogInformation(LogEventIds.ChatCompleted,
"generate.complete tokens={Tokens} promptTokens={PromptTokens} kvReused={KvReusedTokens} kvReusePercent={KvReusePercent:F1} elapsedMs={ElapsedMs:F1} tokensPerSec={TokensPerSec:F2} finishReason={FinishReason} completion=\"{Completion}\"",
generatedTokenCount, promptTokenCount, kvCacheReusedTokens, kvCacheReusePercent,
elapsedMs, tokensPerSecond, finishReason, completionContent);
}
}
public static long ToNanos(long elapsedTicks)
=> elapsedTicks * (1_000_000_000L / Stopwatch.Frequency);
/// <summary>
/// Serialize a bounded summary of the conversation submitted for this turn.
/// Message bodies are capped so a losslessly uploaded document is not copied
/// wholesale into telemetry (which would add avoidable memory, I/O, and
/// sensitive-content exposure). Original character counts remain available.
/// </summary>
public static string SerializeMessagesForLog(List<ChatMessage> messages)
{
if (messages == null || messages.Count == 0)
return "[]";
var entries = new List<ChatMessageLogEntry>(messages.Count);
foreach (var m in messages)
{
if (m == null) continue;
string contentPreview = BuildMessageContentForLog(
m, out bool contentOmitted, out bool contentTruncated);
entries.Add(new ChatMessageLogEntry
{
Role = m.Role ?? string.Empty,
Content = contentPreview,
ContentChars = m.Content?.Length ?? 0,
ContentOmitted = contentOmitted ? true : (bool?)null,
ContentTruncated = contentTruncated ? true : (bool?)null,
Images = ToPathList(m.ImagePaths),
Audios = ToPathList(m.AudioPaths),
TextFiles = ToPathList(m.TextFilePaths),
IsVideo = m.IsVideo ? true : (bool?)null,
Thinking = string.IsNullOrEmpty(m.Thinking) ? null : LimitStructuredLogValue(m.Thinking),
ToolCallCount = (m.ToolCalls != null && m.ToolCalls.Count > 0) ? m.ToolCalls.Count : (int?)null,
});
}
return JsonSerializer.Serialize(entries, FullInputJsonOptions);
}
/// <summary>
/// Serialize the upload manifest for a single message as a single-line JSON array.
/// </summary>
public static string SerializeUploadsForLog(ChatMessage message)
{
if (message == null)
return "[]";
var entries = new List<UploadLogEntry>();
string imageType = message.IsVideo ? "video_frame" : "image";
AppendUploadEntries(entries, message.ImagePaths, imageType);
AppendUploadEntries(entries, message.AudioPaths, "audio");
AppendUploadEntries(entries, message.TextFilePaths, "text");
return entries.Count == 0
? "[]"
: JsonSerializer.Serialize(entries, FullInputJsonOptions);
}
private static void AppendUploadEntries(List<UploadLogEntry> sink, List<string> paths, string mediaType)
{
if (paths == null || paths.Count == 0)
return;
foreach (var path in paths)
{
if (string.IsNullOrEmpty(path))
continue;
sink.Add(new UploadLogEntry
{
Path = path,
Name = Path.GetFileName(path),
MediaType = mediaType,
});
}
}
private static List<string> ToPathList(List<string> source)
{
if (source == null || source.Count == 0)
return null;
var result = new List<string>(source.Count);
foreach (var p in source)
{
if (!string.IsNullOrEmpty(p))
result.Add(p);
}
return result.Count == 0 ? null : result;
}
private static string LimitStructuredLogValue(string value)
{
if (string.IsNullOrEmpty(value))
return string.Empty;
if (value.Length <= MaxLoggedMessageChars)
return value;
return value.Substring(0, MaxLoggedMessageChars) +
$"...(+{value.Length - MaxLoggedMessageChars} chars)";
}
private static string BuildMessageContentForLog(
ChatMessage message,
out bool contentOmitted,
out bool contentTruncated)
{
contentOmitted = false;
contentTruncated = false;
string content = message?.Content ?? string.Empty;
if (content.Length == 0)
return string.Empty;
const string endMarker = "[End of file]";
int endMarkerIndex = content.LastIndexOf(endMarker, StringComparison.OrdinalIgnoreCase);
bool hasDocumentEnvelope = endMarkerIndex >= 0 &&
(content.IndexOf("[File:", StringComparison.OrdinalIgnoreCase) >= 0 ||
content.IndexOf("[Attached file:", StringComparison.OrdinalIgnoreCase) >= 0);
bool hasTextFilePath = message?.TextFilePaths != null && message.TextFilePaths.Count > 0;
if (hasDocumentEnvelope || (hasTextFilePath && content.Length > MaxLoggedMessageChars))
{
contentOmitted = true;
string summary = $"[attached document omitted from log; {content.Length} chars]";
if (hasDocumentEnvelope)
{
int instructionStart = endMarkerIndex + endMarker.Length;
while (instructionStart < content.Length && char.IsWhiteSpace(content[instructionStart]))
instructionStart++;
if (instructionStart < content.Length)
{
int instructionLength = content.Length - instructionStart;
string instruction = instructionLength <= MaxLoggedMessageChars
? content.Substring(instructionStart, instructionLength)
: content.Substring(instructionStart, MaxLoggedMessageChars) +
$"...(+{instructionLength - MaxLoggedMessageChars} chars)";
summary += " instruction=\"" + instruction + "\"";
}
}
return summary;
}
contentTruncated = content.Length > MaxLoggedMessageChars;
return LimitStructuredLogValue(content);
}
private sealed class ChatMessageLogEntry
{
public string Role { get; init; }
public string Content { get; init; }
public int ContentChars { get; init; }
public bool? ContentOmitted { get; init; }
public bool? ContentTruncated { get; init; }
public List<string> Images { get; init; }
public List<string> Audios { get; init; }
public List<string> TextFiles { get; init; }
public bool? IsVideo { get; init; }
public string Thinking { get; init; }
public int? ToolCallCount { get; init; }
}
private sealed class UploadLogEntry
{
public string Path { get; init; }
public string Name { get; init; }
public string MediaType { get; init; }
}
}
}