接入 OpenTelemetry 1.17.0，覆盖 HTTP、HttpClient、.NET Runtime 和数据库链路。

新增 EF Core 数据库拦截器，记录耗时、失败数、慢查询数、TraceId、查询标签和 SQL 哈希；默认不记录完整 SQL及参数。未配置 OTLP Collector 时不启动 SDK，避免无收益的性能开销。为课表的作息、课程、灵活课程、考试、实验等六类查询增加稳定标签。增加可配置的 500ms 慢查询阈值，以及生产环境变量示例。 README 补充 MySQL 慢查询与 EXPLAIN ANALYZE 操作规范。
2026-07-31 08:24:27 +08:00
parent a369b4fe02
commit ca7148ab61
9 changed files with 489 additions and 1 deletions
@@ -0,0 +1,281 @@
+using System.Data.Common;
+using System.Diagnostics;
+using System.Diagnostics.Metrics;
+using System.Security.Cryptography;
+using System.Text;
+using Microsoft.EntityFrameworkCore.Diagnostics;
+
+namespace Jiaowu.Api.Infrastructure.Observability;
+
+public sealed class DatabaseCommandTelemetryInterceptor(
+    ObservabilityOptions options,
+    ILogger<DatabaseCommandTelemetryInterceptor> logger)
+    : DbCommandInterceptor
+{
+    public const string ActivitySourceName = "Jiaowu.Api.Database";
+    public const string MeterName = "Jiaowu.Api.Database";
+
+    private static readonly ActivitySource ActivitySource =
+        new(ActivitySourceName);
+    private static readonly Meter Meter = new(MeterName);
+    private static readonly Histogram<double> CommandDuration =
+        Meter.CreateHistogram<double>(
+            "jiaowu.db.command.duration",
+            "ms",
+            "EF Core database command duration");
+    private static readonly Counter<long> SlowCommandCount =
+        Meter.CreateCounter<long>(
+            "jiaowu.db.command.slow",
+            "{command}",
+            "EF Core commands exceeding the configured slow-query threshold");
+    private static readonly Counter<long> FailedCommandCount =
+        Meter.CreateCounter<long>(
+            "jiaowu.db.command.failed",
+            "{command}",
+            "Failed EF Core database commands");
+
+    public override DbDataReader ReaderExecuted(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        DbDataReader result)
+    {
+        Observe(command, eventData.Duration, "reader");
+        return result;
+    }
+
+    public override ValueTask<DbDataReader> ReaderExecutedAsync(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        DbDataReader result,
+        CancellationToken cancellationToken = default)
+    {
+        Observe(command, eventData.Duration, "reader");
+        return ValueTask.FromResult(result);
+    }
+
+    public override int NonQueryExecuted(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        int result)
+    {
+        Observe(command, eventData.Duration, "nonquery");
+        return result;
+    }
+
+    public override ValueTask<int> NonQueryExecutedAsync(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        int result,
+        CancellationToken cancellationToken = default)
+    {
+        Observe(command, eventData.Duration, "nonquery");
+        return ValueTask.FromResult(result);
+    }
+
+    public override object? ScalarExecuted(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        object? result)
+    {
+        Observe(command, eventData.Duration, "scalar");
+        return result;
+    }
+
+    public override ValueTask<object?> ScalarExecutedAsync(
+        DbCommand command,
+        CommandExecutedEventData eventData,
+        object? result,
+        CancellationToken cancellationToken = default)
+    {
+        Observe(command, eventData.Duration, "scalar");
+        return ValueTask.FromResult(result);
+    }
+
+    public override void CommandFailed(
+        DbCommand command,
+        CommandErrorEventData eventData) =>
+        Observe(
+            command,
+            eventData.Duration,
+            "failed",
+            eventData.Exception.GetType().Name);
+
+    public override Task CommandFailedAsync(
+        DbCommand command,
+        CommandErrorEventData eventData,
+        CancellationToken cancellationToken = default)
+    {
+        Observe(
+            command,
+            eventData.Duration,
+            "failed",
+            eventData.Exception.GetType().Name);
+        return Task.CompletedTask;
+    }
+
+    public override void CommandCanceled(
+        DbCommand command,
+        CommandEndEventData eventData) =>
+        Observe(command, eventData.Duration, "canceled", "canceled");
+
+    public override Task CommandCanceledAsync(
+        DbCommand command,
+        CommandEndEventData eventData,
+        CancellationToken cancellationToken = default)
+    {
+        Observe(command, eventData.Duration, "canceled", "canceled");
+        return Task.CompletedTask;
+    }
+
+    private void Observe(
+        DbCommand command,
+        TimeSpan duration,
+        string commandKind,
+        string? errorType = null)
+    {
+        if (!options.Enabled) return;
+
+        var queryName = GetQueryName(command.CommandText);
+        var statementHash = GetStatementHash(command.CommandText);
+        var provider = GetProviderName(command);
+        var traceId = Activity.Current?.TraceId.ToString() ?? "none";
+        var tags = new TagList
+        {
+            { "db.system.name", provider },
+            { "db.operation.name", commandKind },
+            { "db.query.name", queryName }
+        };
+        if (errorType is not null)
+            tags.Add("error.type", errorType);
+
+        var durationMilliseconds = duration.TotalMilliseconds;
+        CommandDuration.Record(durationMilliseconds, tags);
+        if (errorType is not null)
+            FailedCommandCount.Add(1, tags);
+
+        using var activity = ActivitySource.StartActivity(
+            ActivityKind.Client,
+            Activity.Current?.Context ?? default,
+            startTime: DateTimeOffset.UtcNow - duration,
+            name: queryName);
+        if (activity is not null)
+        {
+            activity.SetTag("db.system.name", provider);
+            activity.SetTag("db.operation.name", commandKind);
+            activity.SetTag("db.query.name", queryName);
+            activity.SetTag("db.statement.hash", statementHash);
+            activity.SetTag(
+                "db.namespace",
+                EmptyToNull(command.Connection?.Database));
+            if (options.IncludeSqlText)
+            {
+                activity.SetTag(
+                    "db.query.text",
+                    Truncate(command.CommandText, options.MaximumSqlTextLength));
+            }
+            if (errorType is not null)
+            {
+                activity.SetTag("error.type", errorType);
+                activity.SetStatus(ActivityStatusCode.Error, errorType);
+            }
+            activity.SetEndTime(DateTime.UtcNow);
+        }
+
+        if (errorType is not null)
+        {
+            logger.LogError(
+                "Database command failed after {DurationMs:F1} ms: " +
+                "{QueryName} ({CommandKind}, {Provider}, hash {StatementHash}, " +
+                "error {ErrorType}, trace {TraceId}).",
+                durationMilliseconds,
+                queryName,
+                commandKind,
+                provider,
+                statementHash,
+                errorType,
+                traceId);
+            return;
+        }
+
+        if (durationMilliseconds < options.SlowQueryThresholdMilliseconds)
+            return;
+
+        SlowCommandCount.Add(1, tags);
+        if (options.IncludeSqlText)
+        {
+            logger.LogWarning(
+                "Slow database command took {DurationMs:F1} ms: " +
+                "{QueryName} ({CommandKind}, {Provider}, hash {StatementHash}, " +
+                "trace {TraceId}). " +
+                "SQL template: {SqlTemplate}",
+                durationMilliseconds,
+                queryName,
+                commandKind,
+                provider,
+                statementHash,
+                traceId,
+                Truncate(command.CommandText, options.MaximumSqlTextLength));
+        }
+        else
+        {
+            logger.LogWarning(
+                "Slow database command took {DurationMs:F1} ms: " +
+                "{QueryName} ({CommandKind}, {Provider}, hash {StatementHash}, " +
+                "trace {TraceId}).",
+                durationMilliseconds,
+                queryName,
+                commandKind,
+                provider,
+                statementHash,
+                traceId);
+        }
+    }
+
+    internal static string GetQueryName(string commandText)
+    {
+        using var reader = new StringReader(commandText);
+        while (reader.ReadLine() is { } line)
+        {
+            var trimmed = line.Trim();
+            if (trimmed.Length == 0) continue;
+            if (trimmed.StartsWith("-- ", StringComparison.Ordinal))
+                return Truncate(trimmed[3..].Trim(), 120);
+            return $"{FirstToken(trimmed)}:{GetStatementHash(commandText)}";
+        }
+
+        return $"unknown:{GetStatementHash(commandText)}";
+    }
+
+    internal static string GetStatementHash(string commandText)
+    {
+        var bytes = SHA256.HashData(Encoding.UTF8.GetBytes(commandText));
+        return Convert.ToHexString(bytes.AsSpan(0, 6)).ToLowerInvariant();
+    }
+
+    private static string FirstToken(string value)
+    {
+        var end = value.IndexOfAny([' ', '\t', '\r', '\n', '(']);
+        var token = end < 0 ? value : value[..end];
+        return token.Length == 0
+            ? "command"
+            : token.ToLowerInvariant();
+    }
+
+    private static string GetProviderName(DbCommand command)
+    {
+        var typeName = command.GetType().FullName ?? command.GetType().Name;
+        if (typeName.Contains("MySql", StringComparison.OrdinalIgnoreCase))
+            return "mysql";
+        if (typeName.Contains("Sqlite", StringComparison.OrdinalIgnoreCase))
+            return "sqlite";
+        return "other_sql";
+    }
+
+    private static string? EmptyToNull(string? value) =>
+        string.IsNullOrWhiteSpace(value) ? null : value;
+
+    private static string Truncate(string value, int maximumLength) =>
+        value.Length <= maximumLength
+            ? value
+            : value[..maximumLength];
+}
@@ -0,0 +1,12 @@
+namespace Jiaowu.Api.Infrastructure.Observability;
+
+public sealed class ObservabilityOptions
+{
+    public const string SectionName = "Observability";
+
+    public bool Enabled { get; set; } = true;
+    public string ServiceName { get; set; } = "jiaowu-api";
+    public int SlowQueryThresholdMilliseconds { get; set; } = 500;
+    public bool IncludeSqlText { get; set; }
+    public int MaximumSqlTextLength { get; set; } = 2000;
+}
@@ -28,6 +28,7 @@ public sealed class TimetableDataService(AppDbContext db)
            allowUnpublishedPlan,
            cancellationToken);
        var slots = await db.ScheduleTimeSlots.AsNoTracking()
+            .TagWith("Timetable.LoadTimeSlots")
            .Where(x => x.AcademicTermId == term.Id && x.IsEnabled)
            .OrderBy(x => x.PeriodNumber)
            .Select(x => new TimetableSlotDto(
@@ -76,6 +77,7 @@ public sealed class TimetableDataService(AppDbContext db)
            }

            entries = await source
+                .TagWith("Timetable.LoadScheduleEntries")
                .OrderBy(x => x.DayOfWeek)
                .ThenBy(x => x.StartPeriod)
                .ThenBy(x => x.TeachingTask!.Course!.Code)
@@ -283,6 +285,7 @@ public sealed class TimetableDataService(AppDbContext db)
        }

        return await source
+            .TagWith("Timetable.LoadFlexibleCourses")
            .OrderBy(x => x.Course!.Code)
            .ThenBy(x => x.TaskNumber)
            .Select(x => new FlexibleCourseDto(
@@ -326,6 +329,7 @@ public sealed class TimetableDataService(AppDbContext db)
            legacyQuery, resourceType, resourceId, studentId);

        var legacySessions = await legacyQuery
+            .TagWith("Timetable.LoadLegacyExamEntries")
            .OrderBy(x => x.ExamDate)
            .ThenBy(x => x.StartPeriod)
            .Select(x => new ExamSessionProjection(
@@ -416,6 +420,7 @@ public sealed class TimetableDataService(AppDbContext db)
            db,
            studentId.Value);
        var sessions = await db.ExperimentSessions.AsNoTracking()
+            .TagWith("Timetable.LoadExperimentEntries")
            .AsSplitQuery()
            .Where(x =>
                x.ExperimentProject!.TeachingTask!.AcademicTermId == term.Id &&
@@ -31,6 +31,11 @@
    </PackageReference>
    <PackageReference Include="Microsoft.EntityFrameworkCore.Sqlite" Version="10.0.10" />
    <PackageReference Include="MySql.EntityFrameworkCore" Version="10.0.7" />
+    <PackageReference Include="OpenTelemetry.Exporter.OpenTelemetryProtocol" Version="1.17.0" />
+    <PackageReference Include="OpenTelemetry.Extensions.Hosting" Version="1.17.0" />
+    <PackageReference Include="OpenTelemetry.Instrumentation.AspNetCore" Version="1.17.0" />
+    <PackageReference Include="OpenTelemetry.Instrumentation.Http" Version="1.17.0" />
+    <PackageReference Include="OpenTelemetry.Instrumentation.Runtime" Version="1.17.0" />
    <PackageReference Include="QRCoder" Version="1.8.0" />
    <PackageReference Include="RabbitMQ.Client" Version="7.2.1" />
    <PackageReference Include="SkiaSharp" Version="3.119.2" />
@@ -7,6 +7,7 @@ using Jiaowu.Api.Infrastructure.Auth;
 using Jiaowu.Api.Infrastructure.Caching;
 using Jiaowu.Api.Infrastructure.Exams;
 using Jiaowu.Api.Infrastructure.Middleware;
+using Jiaowu.Api.Infrastructure.Observability;
 using Jiaowu.Api.Infrastructure.OfficialDocuments;
 using Jiaowu.Api.Infrastructure.Operations;
 using Jiaowu.Api.Infrastructure.Persistence;
@@ -19,6 +20,9 @@ using Microsoft.EntityFrameworkCore;
 using Microsoft.Extensions.Caching.Distributed;
 using Microsoft.IdentityModel.Tokens;
 using Microsoft.OpenApi.Models;
+using OpenTelemetry.Metrics;
+using OpenTelemetry.Resources;
+using OpenTelemetry.Trace;
 using System.Threading.RateLimiting;

 EnvironmentFile.Load();
@@ -78,6 +82,9 @@ var backgroundJobOptions = builder.Configuration
 var operationsOptions = builder.Configuration
    .GetSection(OperationsOptions.SectionName)
    .Get<OperationsOptions>() ?? new OperationsOptions();
+var observabilityOptions = builder.Configuration
+    .GetSection(ObservabilityOptions.SectionName)
+    .Get<ObservabilityOptions>() ?? new ObservabilityOptions();
 var rabbitMqOptions = builder.Configuration
    .GetSection(RabbitMqOptions.SectionName)
    .Get<RabbitMqOptions>() ?? new RabbitMqOptions();
@@ -110,6 +117,24 @@ if (databaseOptions.CommandTimeoutSeconds is < 5 or > 300)
        "Database:CommandTimeoutSeconds 必须在 5 到 300 秒之间。");
 }

+if (string.IsNullOrWhiteSpace(observabilityOptions.ServiceName) ||
+    observabilityOptions.ServiceName.Length > 100 ||
+    observabilityOptions.SlowQueryThresholdMilliseconds is < 1 or > 60000 ||
+    observabilityOptions.MaximumSqlTextLength is < 256 or > 20000)
+{
+    throw new InvalidOperationException(
+        "Observability 服务名、慢查询阈值或 SQL 文本长度超出允许范围。");
+}
+
+var otlpEndpoint = builder.Configuration["OTEL_EXPORTER_OTLP_ENDPOINT"];
+if (!string.IsNullOrWhiteSpace(otlpEndpoint) &&
+    (!Uri.TryCreate(otlpEndpoint, UriKind.Absolute, out var parsedOtlpEndpoint) ||
+     parsedOtlpEndpoint.Scheme is not ("http" or "https")))
+{
+    throw new InvalidOperationException(
+        "OTEL_EXPORTER_OTLP_ENDPOINT 必须是有效的 HTTP 或 HTTPS 绝对地址。");
+}
+
 if (cacheOptions.ReferenceExpirationMinutes is < 1 or > 1440 ||
    cacheOptions.TimetableExpirationMinutes is < 1 or > 1440 ||
    cacheOptions.AnalyticsExpirationMinutes is < 1 or > 1440 ||
@@ -193,11 +218,16 @@ builder.Services.AddSingleton(cacheOptions);
 builder.Services.AddSingleton(officialDocumentOptions);
 builder.Services.AddSingleton(backgroundJobOptions);
 builder.Services.AddSingleton(operationsOptions);
+builder.Services.AddSingleton(observabilityOptions);
 builder.Services.AddSingleton(rabbitMqOptions);
+builder.Services.AddSingleton<DatabaseCommandTelemetryInterceptor>();
 builder.Services.Configure<OfficialDocumentOptions>(
    builder.Configuration.GetSection(OfficialDocumentOptions.SectionName));
-builder.Services.AddDbContextPool<AppDbContext>(options =>
+builder.Services.AddDbContextPool<AppDbContext>((services, options) =>
 {
+    options.AddInterceptors(
+        services.GetRequiredService<DatabaseCommandTelemetryInterceptor>());
+
    if (databaseOptions.Provider.Equals("SQLite", StringComparison.OrdinalIgnoreCase))
    {
        var sqliteConnectionString = builder.Configuration.GetConnectionString("SQLite")
@@ -240,6 +270,28 @@ builder.Services.AddDbContextPool<AppDbContext>(options =>
        });
 });

+if (observabilityOptions.Enabled &&
+    !string.IsNullOrWhiteSpace(otlpEndpoint))
+{
+    builder.Services
+        .AddOpenTelemetry()
+        .ConfigureResource(resource =>
+            resource.AddService(observabilityOptions.ServiceName))
+        .WithMetrics(metrics => metrics
+            .AddAspNetCoreInstrumentation()
+            .AddHttpClientInstrumentation()
+            .AddRuntimeInstrumentation()
+            .AddMeter(DatabaseCommandTelemetryInterceptor.MeterName))
+        .WithTracing(tracing => tracing
+            .AddAspNetCoreInstrumentation(options =>
+                options.Filter = context =>
+                    !context.Request.Path.StartsWithSegments("/health/live"))
+            .AddHttpClientInstrumentation()
+            .AddSource(DatabaseCommandTelemetryInterceptor.ActivitySourceName))
+        .WithMetrics(metrics => metrics.AddOtlpExporter())
+        .WithTracing(tracing => tracing.AddOtlpExporter());
+}
+
 var redisConnectionString = builder.Configuration.GetConnectionString("Redis");
 if (cacheOptions.Enabled && !string.IsNullOrWhiteSpace(redisConnectionString))
 {
@@ -19,6 +19,13 @@
    "AnalyticsLocalExpirationSeconds": 30,
    "MaximumPayloadKilobytes": 2048
  },
+  "Observability": {
+    "Enabled": true,
+    "ServiceName": "jiaowu-api",
+    "SlowQueryThresholdMilliseconds": 500,
+    "IncludeSqlText": false,
+    "MaximumSqlTextLength": 2000
+  },
  "Operations": {
    "BackupDirectory": "data/backups",
    "BackupWarningHours": 24,