一次依赖注入不慎引发的一连串事故
起因和现象偶尔会看到线上服务启动的时候第一波流量进来之后,
迟迟没有任何的响应,同时服务的监控检查接口正常,
所以 K8S 集群认为服务正常,继续放入流量。
查看日志基本如下:
[2020-06-05T13:00:30.7080743+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:30.7081525+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type [2020-06-05T13:00:31.7074253+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR21" started. [2020-06-05T13:00:31.7077051+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:31.7077942+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type [2020-06-05T13:00:32.2103440+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR22" started. [2020-06-05T13:00:32.2118432+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:32.2125894+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-ba'lan'ce does not match a supported file type [2020-06-05T13:00:33.2223942+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR23" started. [2020-06-05T13:00:33.2238736+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:33.2243808+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type [2020-06-05T13:00:34.2177528+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR24" started. [2020-06-05T13:00:34.2189073+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:34.2193483+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type [2020-06-05T13:00:35.2169806+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR25" started. [2020-06-05T13:00:35.2178259+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [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 [2020-06-05T13:00:36.2183025+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR26" started. [2020-06-05T13:00:36.2195050+00:00 Microsoft.AspNetCore.Hosting.Diagnostics INF] Request starting HTTP/1.0 GET [2020-06-05T13:00:36.2199702+00:00 Microsoft.AspNetCore.StaticFiles.StaticFileMiddleware DBG] The request path /v1/user/test/account-balance does not match a supported file type [2020-06-05T13:00:37.2373822+00:00 Microsoft.AspNetCore.Server.Kestrel DBG] Connection id "0HM09A1MAAR27" started. 引发的几种后果 客户端调用超时经过了 30S 甚至更长时间后看到大量的数据库连接被初始化,然后开始集中式返回。
此时可能对于客户端调用来说这一批请求都是超时的,
严重影响用户体验和某些依赖于此的其他接口。
数据库连接暴涨因为同时进入大量数据库查询请求触发数据库 DbContextPool 大量创建,
连接数随之暴涨,数据库查询性能急速下降,可能引发其他的应用问题。
引发服务“雪崩”效应,服务不可用请求堆积的情况下,
health-check 接口响应异常,
导致 k8s 主动重启服务,重启后继续上述情况,
不断恶化最后导致服务不可用。
排查问题 数据库的问题 ?当然,首先怀疑的就是数据库了。
存在性能瓶颈?慢查询导致不响应?发布期间存在其他的异常?
这类的问题都意义排查起来了。
最后发现,
这种情况发生的时候,数据库监控里面一片祥和。
数据库 IO、CPU、内存都正常,
连接数暴涨是这种情况发生的时候带来的,
而不是连接数暴涨之后导致了此情况。
数据库驱动或者 EF Core 框架的问题?是的,
这个怀疑一直都存在于脑海中。
最终,
昨天带着“被挨骂的情况”去问了下“Pomelo.EntityFrameworkCore.MySql”的作者。
春天的熊 18:34:08 柚子啊,我这边的.NET Core服务刚起来,建立MySQL连接的时候好慢,然后同一批请求可能无法正常响应,这个有什么好的解决思路吗? Yuko丶柚子 18:34:29 Min Pool Size = 200 Yuko丶柚子 18:34:32 放连接字符串里 春天的熊 18:34:53 这个字段支持了吗? Yuko丶柚子 18:35:07 一直都支持 春天的熊 18:35:56 等等, public static IServiceCollection AddDbContextPool<TContext>([NotNullAttribute] this IServiceCollection serviceCollection, [NotNullAttribute] Action<DbContextOptionsBuilder> optionsAction, int poolSize = 128) where TContext : DbContext; 春天的熊 18:36:13 这里不是默认最大的128么? Yuko丶柚子 18:36:18 你这个pool size是dbcontext的 Yuko丶柚子 18:36:21 我说的是mysql连接字符串的 Yuko丶柚子 18:36:28 dbcontext的pool有什么用 春天的熊 18:43:13 我问个讨打的问题,dbcontext 是具体的链接实例,EF用的,Min Pool Size 指的是这一个实例上面的连接池吗“? Yuko丶柚子 18:44:07 你在说什么。。。 Yuko丶柚子 18:45:58 放到mysql的连接字符串上 Yuko丶柚子 18:46:14 这样第一次调用MySqlConnection的时候就会建立200个连接 春天的熊 18:46:56 默认是多少来的?100吗? Yuko丶柚子 18:48:33 0 Yuko丶柚子 18:48:40 max默认是100 Yuko丶柚子 18:52:50 DbContextPool要解决的问题你都没搞清楚 春天的熊 18:53:23 DbContextPool要解决的是尽量不去重复创建DbContext Yuko丶柚子 18:53:34 为什么不要重复创建DbContext 春天的熊 18:53:50 因为每个DbContext创建的代价很高,而且很慢 Yuko丶柚子 18:54:01 创建DbContext有什么代价 Yuko丶柚子 18:54:03 哪里慢了 Yuko丶柚子 18:54:06 都是毫秒级的 Yuko丶柚子 18:54:20 他的代价不在于创建 而在于回收 Yuko丶柚子 18:54:25 DbContextPool要解决的问题是 因为DbContext属于较大的对象,而且是频繁被new,而且经常失去引用导致GC频繁工作。Yuko 大大说的情况感觉会是一个思路,
所以第一反应就是加了参数控制连接池。
不过,无果。
5 个实例,
有 3 个实例正常启动,
2 个实例会重复“雪崩”效应,最终无法正常启动。
这个尝试操作重复了好多次,
根据文档和 Yuko 大大指导继续加了不少 MySQL 链接参数,
最后,
重新学习了一波链接参数的优化意义,
无果。
究竟数据库驱动有没有问题?没什么好的思路了,
远程到容器里面 Debug 基本不太现实(重新打包 + 容器化打包 + k8s + 人肉和服务器垮大洋),