EntityFrameWork Core从零开始,(五)简单的日志记录

最新推荐文章于 2025-03-23 15:13:10 发布

罗马苏丹默罕默德

最新推荐文章于 2025-03-23 15:13:10 发布

阅读量1.6k

点赞数

分类专栏： C#/.NET CORE EFCore 文章标签：数据库 microsoft sql

本文链接：https://blog.youkuaiyun.com/jamenu/article/details/121680517

版权

C#/.NET CORE 同时被 2 个专栏收录

48 篇文章

订阅专栏

EFCore

10 篇文章

订阅专栏

本文详细介绍了如何在EFCore中启用日志记录，观察SQL语句生成与执行过程，以及如何配置事务管理。通过控制台、VS调试窗口和文件记录，掌握关键配置选项，如日志级别和筛选器。

摘要生成于 C知道，由 DeepSeek-R1 满血版支持，前往体验 >

前言:
在配置关联映射的方式全部结束后,然后本应该直接进入的EFCore的查询方面的使用方法.
但是在之前配置关联关系的测试过程中,
我们并不知道EFCore究竟向数据库发出了什么具体的SQL语句,
而在真正的使用过程中像SQL语句,数据库事件的内容都需要记录下来,
并且一定要使用数据库事务
在使用Java时,我们只需要将事务管理器托管给Spring的IOC容器,然后使用它提供的@Transcation注解即可,非常的简洁(其中又是那个经典的AOP原理的故事了…)
但是在阅读官方文档的过程中,笔者发现可以以日志的方式输出SQL语句及一些别的信息,
所以我认为它的优先级是更高的

使用简单日志记录

如果我们只想在控制台看一眼生成和执行的SQL语句和執行信息,则可以使用简单日志记录
它的使用方法很简单,只需要在配置文件中加入一行即可

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(Console.WriteLine);

加上这行配置代码后,

1.实例:

再运行了一下上一个多对多示例的查询代码(可以查看上一篇文章),看看LogTo生成生成了什么日志

static void Main(string[] args)
 {
     MMDbContext context = new MMDbContext();
     var luoxiang = context.studentCopies.Include(s=>s.courses)
                                         .Where<StudentCopy>(s => s.name.Equals("羅翔"))
                                         .First();
     var Lcourse = luoxiang.courses;
     foreach(Course c in Lcourse)
     {
         Console.WriteLine("羅翔選的課為:"+c.course_name+"講師為:"+c.teacher_name);
     }
 }

这些是它生成的日志

dbug: 2021/12/2 17:16:50.602 CoreEventId.ShadowPropertyCreated[10600] (Microsoft.EntityFrameworkCore.Model.Validation)
      The property 'coursesid.CourseStudentCopy (Dictionary<string, object>)' was created in shadow state because there are no eligible CLR members with a matching name.
dbug: 2021/12/2 17:16:50.712 CoreEventId.ShadowPropertyCreated[10600] (Microsoft.EntityFrameworkCore.Model.Validation)
      The property 'studentsid.CourseStudentCopy (Dictionary<string, object>)' was created in shadow state because there are no eligible CLR members with a matching name.
info: 2021/12/2 17:16:51.052 CoreEventId.ContextInitialized[10403] (Microsoft.EntityFrameworkCore.Infrastructure)
      Entity Framework Core 5.0.12 initialized 'MMDbContext' using provider 'Microsoft.EntityFrameworkCore.SqlServer' with options: None
dbug: 2021/12/2 17:16:51.657 CoreEventId.QueryCompilationStarting[10111] (Microsoft.EntityFrameworkCore.Query)
      Compiling query expression:
      'DbSet<StudentCopy>()
          .Include(s => s.courses)
          .Where(s => s.name.Equals("羅翔"))
          .First()'
dbug: 2021/12/2 17:16:51.739 CoreEventId.NavigationBaseIncluded[10112] (Microsoft.EntityFrameworkCore.Query)
      Including navigation: 'StudentCopy.courses'.
dbug: 2021/12/2 17:16:52.261 CoreEventId.QueryExecutionPlanned[10107] (Microsoft.EntityFrameworkCore.Query)
      Generated query execution expression:
      'queryContext => new SingleQueryingEnumerable<StudentCopy>(
          (RelationalQueryContext)queryContext,
          RelationalCommandCache.SelectExpression(
              Projection Mapping:
              SELECT t.id, t.age, t.name, t0.coursesid, t0.studentsid, t0.id, t0.course_name, t0.teacher_name
              FROM Projection Mapping:
              (
                  SELECT TOP(1) s.id, s.age, s.name
                  FROM studentCopies AS s
                  WHERE s.name == N'羅翔'
              ) AS t
              LEFT JOIN Projection Mapping:
              (
                  SELECT c.coursesid, c.studentsid, c0.id, c0.course_name, c0.teacher_name
                  FROM CourseStudentCopy AS c
                  INNER JOIN courses AS c0 ON c.coursesid == c0.id
              ) AS t0 ON t.id == t0.studentsid
              ORDER BY t.id ASC, t0.coursesid ASC, t0.studentsid ASC, t0.id ASC),
          Func<QueryContext, DbDataReader, ResultContext, SingleQueryResultCoordinator, StudentCopy>,
          EFCoreOneToMany.ManyToMany.MMDbContext,
          False,
          False
      )
          .Single()'
dbug: 2021/12/2 17:16:52.403 RelationalEventId.CommandCreating[20103] (Microsoft.EntityFrameworkCore.Database.Command)
      Creating DbCommand for 'ExecuteReader'.
dbug: 2021/12/2 17:16:52.408 RelationalEventId.CommandCreated[20104] (Microsoft.EntityFrameworkCore.Database.Command)
      Created DbCommand for 'ExecuteReader' (106ms).
dbug: 2021/12/2 17:16:52.412 RelationalEventId.ConnectionOpening[20000] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opening connection to database 'EFCoreTest' on server '.'.
dbug: 2021/12/2 17:16:54.236 RelationalEventId.ConnectionOpened[20001] (Microsoft.EntityFrameworkCore.Database.Connection)
      Opened connection to database 'EFCoreTest' on server '.'.
dbug: 2021/12/2 17:16:54.250 RelationalEventId.CommandExecuting[20100] (Microsoft.EntityFrameworkCore.Database.Command)
      Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [t].[id], [t].[age], [t].[name], [t0].[coursesid], [t0].[studentsid], [t0].[id], [t0].[course_name], [t0].[teacher_name]
      FROM (
          SELECT TOP(1) [s].[id], [s].[age], [s].[name]
          FROM [studentCopies] AS [s]
          WHERE [s].[name] = N'羅翔'
      ) AS [t]
      LEFT JOIN (
          SELECT [c].[coursesid], [c].[studentsid], [c0].[id], [c0].[course_name], [c0].[teacher_name]
          FROM [CourseStudentCopy] AS [c]
          INNER JOIN [courses] AS [c0] ON [c].[coursesid] = [c0].[id]
      ) AS [t0] ON [t].[id] = [t0].[studentsid]
      ORDER BY [t].[id], [t0].[coursesid], [t0].[studentsid], [t0].[id]
info: 2021/12/2 17:16:54.314 RelationalEventId.CommandExecuted[20101] (Microsoft.EntityFrameworkCore.Database.Command)
      Executed DbCommand (73ms) [Parameters=[], CommandType='Text', CommandTimeout='30']
      SELECT [t].[id], [t].[age], [t].[name], [t0].[coursesid], [t0].[studentsid], [t0].[id], [t0].[course_name], [t0].[teacher_name]
      FROM (
          SELECT TOP(1) [s].[id], [s].[age], [s].[name]
          FROM [studentCopies] AS [s]
          WHERE [s].[name] = N'羅翔'
      ) AS [t]
      LEFT JOIN (
          SELECT [c].[coursesid], [c].[studentsid], [c0].[id], [c0].[course_name], [c0].[teacher_name]
          FROM [CourseStudentCopy] AS [c]
          INNER JOIN [courses] AS [c0] ON [c].[coursesid] = [c0].[id]
      ) AS [t0] ON [t].[id] = [t0].[studentsid]
      ORDER BY [t].[id], [t0].[coursesid], [t0].[studentsid], [t0].[id]
..............

请暂时无视那些debug和Info开头的日志,可以清楚的看到EFCore为了查询这个多对多关系发送了三条SQL语句

//1第一条----------------------------------
 SELECT t.id, t.age, t.name, t0.coursesid, t0.studentsid, t0.id, t0.course_name, t0.teacher_name
 FROM Projection Mapping:
 (
     SELECT TOP(1) s.id, s.age, s.name
     FROM studentCopies AS s
     WHERE s.name == N'羅翔'
 ) AS t
 LEFT JOIN Projection Mapping:
 (
     SELECT c.coursesid, c.studentsid, c0.id, c0.course_name, c0.teacher_name
     FROM CourseStudentCopy AS c
     INNER JOIN courses AS c0 ON c.coursesid == c0.id
 ) AS t0 ON t.id == t0.studentsid
 ORDER BY t.id ASC, t0.coursesid ASC, t0.studentsid ASC, t0.id ASC)


//2第二条----------------------------------
SELECT [t].[id], [t].[age], [t].[name], [t0].[coursesid], [t0].[studentsid], [t0].[id], [t0].[course_name], [t0].[teacher_name]
      FROM (
          SELECT TOP(1) [s].[id], [s].[age], [s].[name]
          FROM [studentCopies] AS [s]
          WHERE [s].[name] = N'羅翔'
      ) AS [t]
      LEFT JOIN (
          SELECT [c].[coursesid], [c].[studentsid], [c0].[id], [c0].[course_name], [c0].[teacher_name]
          FROM [CourseStudentCopy] AS [c]
          INNER JOIN [courses] AS [c0] ON [c].[coursesid] = [c0].[id]
      ) AS [t0] ON [t].[id] = [t0].[studentsid]
      ORDER BY [t].[id], [t0].[coursesid], [t0].[studentsid], [t0].[id]



//3第三条---------------------------
SELECT [t].[id], [t].[age], [t].[name], [t0].[coursesid], [t0].[studentsid], [t0].[id], [t0].[course_name], [t0].[teacher_name]
      FROM (
          SELECT TOP(1) [s].[id], [s].[age], [s].[name]
          FROM [studentCopies] AS [s]
          WHERE [s].[name] = N'羅翔'
      ) AS [t]
      LEFT JOIN (
          SELECT [c].[coursesid], [c].[studentsid], [c0].[id], [c0].[course_name], [c0].[teacher_name]
          FROM [CourseStudentCopy] AS [c]
          INNER JOIN [courses] AS [c0] ON [c].[coursesid] = [c0].[id]
      ) AS [t0] ON [t].[id] = [t0].[studentsid]
      ORDER BY [t].[id], [t0].[coursesid], [t0].[studentsid], [t0].[id]

很明显这些查询都是准确的查询属性,并不查询整张表的数据,
第一条语句对应我们的测试查询中的第一个LINQ查询,但仔细看,它并没有去查我们的关联属性courses
,后面的两条查询是测试程序在遍历输出学生对应的课程信息时才发的,
这只说明了一点,
EFCore默认是懒加载的

2.简单日志记录的可选参数

一.记录位置

1.控制台:(上例中)

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    var Connection = "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX";
    optionsBuilder.UseSqlServer(Connection);
    optionsBuilder.LogTo(Console.WriteLine);
}

2.VisualStudio的调试窗口

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    var Connection = "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX";
    optionsBuilder.UseSqlServer(Connection);
    optionsBuilder.LogTo(message => Debug.WriteLine(message));
}

3.记录到文件
(当DbContext关闭时也需要把文件流关闭,故需要重写Dispose方法)

private readonly StreamWriter _logStream = new StreamWriter("mylog.txt", append: true);

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(_logStream.WriteLine);

public override void Dispose()
{
    base.Dispose();
    _logStream.Dispose();
}

public override async ValueTask DisposeAsync()
{
    await base.DisposeAsync();
    await _logStream.DisposeAsync();
}

二.获取异常中的详细信息

EFCore的异常默认不会包括具体的数据信息,如需查看以方便调试,需要开启以下设置

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
{
    var Connection = "XXXXXXXXXXXXXXXXXXXXXXXXXXXXXXX";
    optionsBuilder.UseSqlServer(Connection);
    optionsBuilder.LogTo(message => Debug.WriteLine(message));
    optionsBuilder.EnableSensitiveDataLogging();
}

三.日志级别

在EFCore中日志有五个级别,分别是

Trace
Debug
Information
Errors
Warnning
Critical
None
除了None外,所有的等级都是递增的,
可以在Logto中设置几句哪一个等级以上的日志

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(Console.WriteLine, LogLevel.Information);

四.获取特定信息

如果需要记录某些特定的信息:如数据库上下文的创建于销毁,…
参考CoreEventId 类或 RelationalEventId 类
LogTo 可以配置为仅记录与一个或多个事件 ID 关联的消息

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(Console.WriteLine, new[] { CoreEventId.ContextDisposed, CoreEventId.ContextInitialized });

五.自定义筛选器

如果需要将多个特殊的情况添加在一起,
则他们推荐使用自定义的筛选器,而不是在方法里一个劲的塞参数
例如，若要记录 Information 级别或更高级别的任何消息，以及有关打开和关闭连接的消息：

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder
        .LogTo(
            Console.WriteLine,
            (eventId, logLevel) => logLevel >= LogLevel.Information
                                   || eventId == RelationalEventId.ConnectionOpened
                                   || eventId == RelationalEventId.ConnectionClosed);

3.日志消息的格式设置

LogTo 中的默认内容跨多行设置格式。第一行包含消息元数据：

LogLevel，作为四字符前缀
本地时间戳，针对当前区域性设置格式
EventId，采用可以复制/粘贴以从 CoreEventId 或其他类之一获取成员的格式，外加原始 ID 值
事件类别，如上所述。

在Oncongfiguring配置方法中使用DbContextLoggerOptions枚举类来控制日志消息的格式


    [Flags]
    public enum DbContextLoggerOptions
    {
        //
        // 摘要: 日志消息不带任何数据和格式
       
        None = 0,
        //
        // 摘要: 日志消息呈单行的形式输出
        SingleLine = 1,
        //
        // 摘要:   包括了Extensions.Logging.LogLevel中的使用事件
        //     Include the event Microsoft.Extensions.Logging.LogLevel in each log message.
        //     The level is included by default.
        Level = 2,
        //
        // 摘要:
        //     Includes the event Microsoft.EntityFrameworkCore.DbLoggerCategory in each message.
        //     The category is included by default.
        Category = 4,
        //
        // 摘要:
        //     Includes the Microsoft.Extensions.Logging.EventId in each message. The event
        //     ID is included by default.
        Id = 8,
        //
        // 摘要:
        //     Includes a UTC timestamp in each message. The local time is included by default.
        //     Use Microsoft.EntityFrameworkCore.Diagnostics.DbContextLoggerOptions.DefaultWithUtcTime
        //     to include all default options but change timestamps to UTC.
        UtcTime = 16,
        //
        // 摘要:默认使用UTC时间
        DefaultWithUtcTime = 30,
        //
        // 摘要:使用本地时间
        LocalTime = 32,
        //
        // 摘要:
        DefaultWithLocalTime = 46
    }

protected override void OnConfiguring(DbContextOptionsBuilder optionsBuilder)
    => optionsBuilder.LogTo(
        Console.WriteLine,
        LogLevel.Debug,
        DbContextLoggerOptions.UtcTime | DbContextLoggerOptions.SingleLine);

2020-10-06T17:52:45.7320362Z -> Executed DbCommand (0ms) [Parameters=[], CommandType='Text', CommandTimeout='30']CREATE TABLE "Blogs" (    "Id" INTEGER NOT NULL CONSTRAINT "PK_Blogs" PRIMARY KEY AUTOINCREMENT,    "Name" INTEGER NOT NULL);
2020-10-06T17:52:45.7320531Z -> Committing transaction.
2020-10-06T17:52:45.7339441Z -> Committed transaction.