要不,试试把日志登录调节到 Debug 看看所有的行为?
{ "Using": ["Serilog.Sinks.Console"], "MinimumLevel": { "Default": "Debug", "Override": { "Microsoft": "Debug" } }, "WriteTo": [ { "Name": "Console", "Args": { "outputTemplate": "[{Timestamp:o} {SourceContext} {Level:u3}] {Message:lj}{NewLine}{Exception}" } } ] }当然,这个事情没有直接在正常的生产环境执行。
这里是使用新配置,重新起新实例来操作。
然后我们看到程序启动的时候执行 EFMigration 的时候,
程序和整个数据库交互的完整日志。
[2020-06-05T12:59:56.4147202+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Opening connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4159970+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Opened connection to database 'user_pool' on server 'a'li'yun'. [2020-06-05T12:59:56.4161172+00:00 Microsoft.EntityFrameworkCore.Database.Command DBG] Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30'] SELECT 1 FROM INFORMATION_SCHEMA.TABLES WHERE TABLE_SCHEMA='user_pool' AND TABLE_NAME='__EFMigrationsHistory'; [2020-06-05T12:59:56.4170776+00:00 Microsoft.EntityFrameworkCore.Database.Command INF] Executed DbCommand (1ms) [Parameters=[], CommandType='Text', CommandTimeout='30'] SELECT 1 FROM INFORMATION_SCHEMA.TABLES WHERE TABLE_SCHEMA='user_pool' AND TABLE_NAME='__EFMigrationsHistory'; [2020-06-05T12:59:56.4171630+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Closing connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4172458+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Closed connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4385345+00:00 Microsoft.EntityFrameworkCore.Database.Command DBG] Creating DbCommand for 'ExecuteReader'. [2020-06-05T12:59:56.4386201+00:00 Microsoft.EntityFrameworkCore.Database.Command DBG] Created DbCommand for 'ExecuteReader' (0ms). [2020-06-05T12:59:56.4386763+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Opening connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4400143+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Opened connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4404529+00:00 Microsoft.EntityFrameworkCore.Database.Command DBG] Executing DbCommand [Parameters=[], CommandType='Text', CommandTimeout='30'] SELECT `MigrationId`, `ProductVersion` FROM `__EFMigrationsHistory` ORDER BY `MigrationId`; [2020-06-05T12:59:56.4422387+00:00 Microsoft.EntityFrameworkCore.Database.Command INF] Executed DbCommand (2ms) [Parameters=[], CommandType='Text', CommandTimeout='30'] SELECT `MigrationId`, `ProductVersion` FROM `__EFMigrationsHistory` ORDER BY `MigrationId`; [2020-06-05T12:59:56.4446400+00:00 Microsoft.EntityFrameworkCore.Database.Command DBG] A data reader was disposed. [2020-06-05T12:59:56.4447422+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Closing connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.4447975+00:00 Microsoft.EntityFrameworkCore.Database.Connection DBG] Closed connection to database 'user_pool' on server 'aliyun-rds'. [2020-06-05T12:59:56.5170419+00:00 Microsoft.EntityFrameworkCore.Migrations INF] No migrations were applied. The database is already up to date.看到这里的时候,由于发现我们之前对 DbContext 和 DbConnection 的理解不太好,
想搞清楚究竟是不 db connection 创建的时候有哪些行为,
于是我们找到了 dotnet/efcore Github 的源码开始拜读,
PS: 源码真香,能看源码真好。
尝试通过“Opening connection”找到日志的场景。
想了解这个日志输出的时候代码在做什么样的事情,可能同时会有哪些行为。
在考虑是不是其他的一些行为导致了上面的服务问题?
最终在RelationalConnection.cs确认上面这些数据库相关日志肯定是会输出的,不存在其他的异常行为。