一次依赖注入不慎引发的一连串事故 (3)

PS:不用细看,我们认真浏览了代码之后确认 DbContext 正常初始化,

/// <summary> /// Asynchronously opens the connection to the database. /// </summary> /// <param> Indicate if the connection errors are expected and should be logged as debug message. </param> /// <param> /// A <see cref="CancellationToken" /> to observe while waiting for the task to complete. /// </param> /// <returns> /// A task that represents the asynchronous operation, with a value of <see langword="true"/> if the connection /// was actually opened. /// </returns> public virtual async Task<bool> OpenAsync(CancellationToken cancellationToken, bool errorsExpected = false) { if (DbConnection.State == ConnectionState.Broken) { await DbConnection.CloseAsync().ConfigureAwait(false); } var wasOpened = false; if (DbConnection.State != ConnectionState.Open) { if (CurrentTransaction != null) { await CurrentTransaction.DisposeAsync().ConfigureAwait(false); } ClearTransactions(clearAmbient: false); await OpenDbConnectionAsync(errorsExpected, cancellationToken).ConfigureAwait(false); wasOpened = true; } _openedCount++; HandleAmbientTransactions(); return wasOpened; } private async Task OpenDbConnectionAsync(bool errorsExpected, CancellationToken cancellationToken) { var startTime = DateTimeOffset.UtcNow; var stopwatch = Stopwatch.StartNew(); // 日志输出在这里 var interceptionResult = await Dependencies.ConnectionLogger.ConnectionOpeningAsync(this, startTime, cancellationToken) .ConfigureAwait(false); try { if (!interceptionResult.IsSuppressed) { await DbConnection.OpenAsync(cancellationToken).ConfigureAwait(false); } // 日志输出在这里 await Dependencies.ConnectionLogger.ConnectionOpenedAsync(this, startTime, stopwatch.Elapsed, cancellationToken) .ConfigureAwait(false); } catch (Exception e) { await Dependencies.ConnectionLogger.ConnectionErrorAsync( this, e, startTime, stopwatch.Elapsed, errorsExpected, cancellationToken) .ConfigureAwait(false); throw; } if (_openedCount == 0) { _openedInternally = true; } }

当然,我们同时也去看了一眼 MySqlConnector的源码,

确认它自身是维护了数据库连接池的。到这里基本确认不会是数据库驱动导致的上述问题。

某种猜测 肯定是有什么奇怪的行为阻塞了当前服务进程, 导致数据库连接的日志也没有输出。 锁? 异步等同步?资源初始化问题?

周五晚上查到了这里已经十一点了,

于是先下班回家休息了。

于是,

周六练完车之后 Call 了一下小伙伴,

又双双开始了愉快的 Debug。

插曲

小伙伴海林回公司前发了个朋友圈。

“ 咋们继续昨天的 bug,

特此立 flag:修不好直播吃 bug

反正不是你死就是我亡…”

我调侃评论说:

你等下,我打包下代码去楼下打印出来待会当晚饭

开始锁定问题 中间件导致的吗? [2020-06-05T13:00:35.2181055+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type

我们对着这个日志思考了一会人生,

然后把引用此中间件的代码注释掉了,

不过,无果。

自定义 filters 导致的吗? [2020-06-05T13:01:05.3126001+00:00 Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker DBG] Execution plan of exception filters (in the following order): ["None"] [2020-06-05T13:01:05.3126391+00:00 Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker DBG] Execution plan of result filters (in the following order): ["Microsoft.AspNetCore.Mvc.ViewFeatures.Filters.SaveTempDataFilter", "XXX.Filters.HTTPHeaderAttribute (Order: 0)"] [2020-06-05T13:01:05.3072206+00:00 Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker DBG] Execution plan of authorization filters (in the following order): ["None"]

看到这个日志我们考虑了一下,

是不是因为 filters 导致了问题。

毕竟在 HTTPHeaderAttribute 我们还还做了 ThreadLocal<Dictionary<string, string>> CurrentXHeaders

这里怀疑是不是我们的实现存在锁机制导致“假死问题”。

尝试去掉。

不过,

无果。

尝试使用 ptrace

没什么很好的头绪了,要不上一下 ptrace 之类的工具跟一下系统调用?

最早在去年就尝试过使用 ptrace 抓进程数据看系统调用,

后来升级到.NET Core3.0 之后,官方基于 Events + LTTng 之类的东西做了 dotnet-trace 工具,

官网说明:dotnet-trace performance analysis utility

内容版权声明:除非注明,否则皆为本站原创文章。

转载注明出处:https://www.heiqu.com/wpzwpj.html