.NET webapi某化妆品直播卡死分析

目录

• 一：背景
• 1. 讲故事
• 二：Windbg 分析
• 1. 线程们都怎么了
• 2. 单例写法真的没问题吗
• 3. 验证我的想法
• 4. 后续
• 三：总结

一：背景

1. 讲故事

10月份星球里的一位老朋友找到我，说他们公司的程序在一个网红直播带货下给弄得无响应了，无响应期间有大量的 RabbitMQ 超时，寻求如何找到根源，聊天截图我就不发了。

既然无响应了，那必然是程序的大量线程被主动或者被动的挂起，朋友也很及时的从程序上抽了一管血下来，接下来就上 windbg 一起探究下到底发生了什么？

二：Windbg 分析

1. 线程们都怎么了

要想看所有线程，还是老命令 !t 。

0:000> !t
ThreadCount:      5221
UnstartedThread:  0
BackgroundThread: 5199
PendingThread:    0
DeadThread:       21
Hosted Runtime:   no
                                                                                                            Lock
 DBG   ID     OSID ThreadOBJ           State GC Mode     GC Alloc Context                  Domain           Count Apt Exception
  20    1     74e4 00000276CB778180  202a020 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA
  31    2     42cc 00000276CB6CA830    2b220 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Finalizer)
  32    3     2b40 00000276CB85D1B0  102a220 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Threadpool Worker)
   2    6     bccc 00000276CBA5D2F0    20220 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 Ukn
  33    9     7224 00000276CBA5C0C0  3029220 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 MTA (Threadpool Worker) System.IO.IOException 00000279ccc56cd0
   9   23     29e0 0000027BD86FD180    20220 Preemptive  0000000000000000:0000000000000000 00000276cb77c9d0 -00001 Ukn
...

从简要信息看，当前有 5000+ 的线程，太牛了，一般一台机器的所有进程的线程加起来也没这么多。。。不过我目前看到最多的是 1w + 的线程 ， 就是那种不用线程池，直接用 Thread 造成的一种线程垃圾。

可以看到线程列表中的 9号线程 抛了托管异常，接下来看看是个啥错误, 使用 !wpe 00000279ccc56cd0 命令。

0:000> !wpe 00000279ccc56cd0
Address: 00000279ccc56cd0
Exception Type: System.IO.IOException
Message: Unable to read data from the transport connection: 远程主机强迫关闭了一个现有的连接。.
Inner Exception: 00000279ccc56b20 System.Net.Sockets.SocketException 远程主机强迫关闭了一个现有的连接。
Stack:
SP               IP               Function
000000791b88c970 00007ffd844a1b31 System.Net.Sockets.NetworkStream.Read(Byte[], Int32, Int32)
000000791b88ee80 00007ffd849e6f8a System.IO.BufferedStream.ReadByteSlow()
000000791b88eeb0 00007ffd8312950a RabbitMQ.Client.Impl.InboundFrame.ReadFrom(System.IO.Stream, Byte[])
000000791b88ef40 00007ffd849e6d7d RabbitMQ.Client.Framing.Impl.Connection.MainLoopIteration()
000000791b88efa0 00007ffd8312832f RabbitMQ.Client.Framing.Impl.Connection.MainLoop()
HResult: 80131620

从堆栈信息来看，程序做了一个远程访问 RabbitMQ，结果 tcp 连接被对方关闭了，貌似和朋友说的有大量 RabbitMQ 超时有关。

接下来就是查看各个线程栈，研究下此时这些线程都在干什么，使用 ~*e !clrstack 命令，通过仔细研读线程栈，我发现有大量的方法卡在 xxx.RabbitMq.RabbitMqConnection.GetInstance 方法处。

        Child SP               IP Call Site
0000008B8A9ED6A8 00007ffdf5246594 [HelperMethodFrame_1OBJ: 0000008b8a9ed6a8] System.Threading.Monitor.ReliableEnter(System.Object, Boolean ByRef)
0000008B8A9ED800 00007ffd84a6a4a9 xxx.RabbitMq.RabbitMqConnection.GetInstance(Microsoft.Extensions.Options.IOptions`1<xxx.RabbitMq.RabbitMqConfig>, Microsoft.Extensions.Logging.ILogger`1<System.Object>)
0000008B8A9ED860 00007ffd84a6a317 xxx.RabbitMq.RabbitMqProducer..ctor(Microsoft.Extensions.Options.IOptionsSnapshot`1<xxx.RabbitMq.RabbitMqConfig>, Microsoft.Extensions.Logging.ILogger`1<xxx.RabbitMq.RabbitMqProducer>)
0000008B8A9ED8A0 00007ffd8334817b DynamicClass.ResolveService(ILEmitResolverBuilderRuntimeContext, Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope)
0000008B8A9ED930 00007ffd83347d76 DynamicClass.ResolveService(ILEmitResolverBuilderRuntimeContext, Microsoft.Extensions.DependencyInjection.ServiceLookup.ServiceProviderEngineScope)
0000008B8A9EDE90 00007ffd844f3cb3 Microsoft.Extensions.DependencyInjection.ActivatorUtilities.GetService(System.IServiceProvider, System.Type, System.Type, Boolean) [/_/src/libraries/Common/src/Extensions/ActivatorUtilities/ActivatorUtilities.cs @ 173]
DynamicClass.lambda_method196(System.Runtime.CompilerServices.Closure, System.IServiceProvider, System.Object[])
0000008B8A9EDF20 00007ffd84a0fc9c Microsoft.AspNetCore.Mvc.Controllers.ControllerFactoryProvider+c__DisplayClass5_0.g__CreateController|0(Microsoft.AspNetCore.Mvc.ControllerContext)
0000008B8A9EDF70 00007ffd8452ce7f Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ControllerActionInvoker.cs @ 285]
0000008B8A9EE030 00007ffd84a0fac8 Microsoft.AspNetCore.Mvc.Infrastructure.ControllerActionInvoker.InvokeInnerFilterAsync() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ControllerActionInvoker.cs @ 490]
0000008B8A9EE0B0 00007ffd845346cd Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 883]
0000008B8A9EE240 00007ffd84a0f9ad Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextExceptionFilterAsync() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 1024]
0000008B8A9EE2C0 00007ffd84534272 Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.Next(State ByRef, Scope ByRef, System.Object ByRef, Boolean ByRef) [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 883]
0000008B8A9EE450 00007ffd84a0f850 Microsoft.AspNetCore.Mvc.Infrastructure.ResourceInvoker.InvokeNextResourceFilter() [/_/src/Mvc/Mvc.Core/src/Infrastructure/ResourceInvoker.cs @ 976]
...

从调用栈信息看，源头是一个http请求，然后在 GetInstance 下的 lock 处被冻结，这就激发了我很大的好奇心，接下来根据 IP 导出源码看看。

public sealed class RabbitMqConnection
{
    public static RabbitMqConnection GetInstance(IOptions<RabbitMqConfig> options, ILogger<dynamic> logger)
    {
        if (_uniqueInstance == null || _uniqueInstance.Connection == null || !_uniqueInstance.Connection.IsOpen)
        {
            lock (_objLock)
            {
                if (_uniqueInstance == null || _uniqueInstance.Connection == null || !_uniqueInstance.Connection.IsOpen)
                {
                    _uniqueInstance = new RabbitMqConnection(options.Value, logger);
                }
            }
        }
        return _uniqueInstance;
    }
	private RabbitMqConnection(RabbitMqConfig config, ILogger<dynamic> logger)
	{
		Policy.Handle<SocketException>().Or<BrokerUnreachableException>().WaitAndRetry(6, (int retryAttempt) => TimeSpan.FromSeconds(1.0), delegate (Exception ex, TimeSpan time, int retryCount, Context content)
		{
			if (6 == retryCount)
			{
				throw ex;
			}
			_logger.LogError(ex, $"{retryCount}:{ex.Message}");
		})
			.Execute(delegate
			{
				Connection = factory.CreateConnection();
			});
	}
}

从代码逻辑看，朋友用了 双检锁 来给 RabbitMQ 实例做单例化，如果实例创建失败还会有 6 次 1s 的尝试，这种写法乍一看没什么问题。

2. 单例写法真的没问题吗

如果单例写法没问题的话，为什么有大量的线程卡在 lock 处呢？ 既然是 单例 那肯定是 rabbitmq 第一次被实例化后，后人直接乘凉就好了哈，带着这个疑问再次检查 双检索 写法，尼玛，在判断单例的时候居然做了 _uniqueInstance.Connection.IsOpen 判断，大家知道这意味着什么吗？

这意味着，一旦 rabbitmq 在某个时刻挂掉了，单例条件就被破防了，无数的线程排队来做 RabbimtMQ 的实例化，要知道这都是些不实例出来不罢休的勇士，继而导致程序挂死...