《.NET 5.0 背锅案》第2集：码中的小窟窿，背后的大坑，发现重要嫌犯 EnyimMemcachedCore

在第1集的剧情中，主角是“.NET 5.0 正式版 docker 镜像”，它有幸入选第1位嫌疑对象，不是因为它的嫌疑最大，而是它的验证方法最简单，只需要再进行一次发布即可。我们在周五晚上（11月13日）进行了发布验证，发布后没有出现故障，docker 镜像的嫌疑指数下降，但这不能100%证明它的清白，因为可能是因为周五晚上的并发量不够触发故障。

在这一集中，主角是 memcached 客户端 EnyimMemcachedCore，它是到目前为止我们发现的最大嫌疑对象，它是我们从 .NET Framework 版的 EnyimMemcached 迁移到 .NET Core 的，修修补补、补补修修了好几年，最大的改动是实现异步化（async/await）。

在 review EnyimMemcachedCore 源代码的过程中，在 Enyim.Caching.Memcached.MemcachedNode.InternalPoolImpl 的 AcquireAsync() 方法中发现下面这行代码：

retval.Reset();

这行代码的作用是从 EnyimMemcachedCore 维护的 socket pool 中拿到空闲 socket 连接之后，对该连接进行重置，就比如你在餐厅等到一个空闲位置后，就坐之前服务员会将餐桌清理干净。

当看到这个方法的方法名之后没有 Async 之后，我们当时头脑中就嗡的一声，怎么会，怎么会，这个地方怎么会没有调用异步方法？在我们对 EnyimMemcached 进行异步化改造时竟然漏掉了这个地方，罪过罪过，这个错值得关禁闭1个月。

继续追查案件，看看 PooledSocket.Reset 方法的实现代码

public void Reset()
{
    // discard any buffered data
    _inputStream.Flush();

    int available = _socket.Available;

    if (available > 0)
    {
        if (_logger.IsEnabled(LogLevel.Warning))
            _logger.LogWarning(
                "Socket bound to {0} has {1} unread data! This is probably a bug in the code. InstanceID was {2}.",
                _socket.RemoteEndPoint, available, this.InstanceId);

        byte[] data = new byte[available];

        this.Read(data, 0, available);

        if (_logger.IsEnabled(LogLevel.Warning))
            _logger.LogWarning(Encoding.ASCII.GetString(data));
    }
}

从表面上看，这个方法的实现意图简单明了，就是清除 Socket NetworkStream 的内部缓冲数据，如果清除之后，Socket 中还有数据，就读取这些数据并在日志中记录。

F12查看一下 NetworkStream.Flush 注释

// Summary:
//     Flushes data from the stream. This method is reserved for future use.
public override void Flush();

不看不知道，一看吓一跳，这个方法竟然是个摆设，什么也没实现，真的是这样吗？github 上查看 .NET 5.0 的源代码确认一下，找到 NetworkStream.cs#L743

// Flushes data from the stream.  This is meaningless for us, so it does nothing.
public override void Flush()
{
}

public override Task FlushAsync(CancellationToken cancellationToken)
{
    return Task.CompletedTask;
}

千真万确，而且这是5年前就已经发生的事实

微软为什么放这样一个摆设？这个摆设会带来副作用吗？在 NetworkStream.Flush 的帮助文档中找到了答案：

原来 NetworkSteam 是一个与众不同的 Stream，它没有 buffered 数据，Flush 操作对它本来就没有意义，所以这是一个无伤大雅的摆设。

既然 NetworkStream.Flush 是摆设，那 EnyimMemcachedCore 的 Reset 方法中调用 NetworkStream.Flush 也是摆设，也是无伤大雅，这里是否调用异步方法没有影响，坑不在这里。

继续追查，来看后面读取 _socket.Available 的代码

byte[] data = new byte[available];
this.Read(data, 0, available);

以及对应的 Read 方法实现代码

public void Read(byte[] buffer, int offset, int count)
{
    this.CheckDisposed();

    int read = 0;
    int shouldRead = count;

    while (read < count)
    {
        try
        {
            int currentRead = _inputStream.Read(buffer, offset, shouldRead);
            if (currentRead == count)
                break;
            if (currentRead < 1)
                throw new IOException("The socket seems to be disconnected");

            read += currentRead;
            offset += currentRead;
            shouldRead -= currentRead;
        }
        catch (Exception ex)
        {
            if (ex is IOException || ex is SocketException)
            {
                _isAlive = false;
            }
            throw;
        }
    }
}

坑在这里！Read 方法中通过 NetworkStream.Read 同步方法从 socket 读取数据会阻塞线程，如果有很多线程在进行这个操作，会造成线程池中的线程不够用，在高并发场景下足以致命。

我们来设想一下掉进这个大坑里的情形。正常情况下，EnyimMemcachedCore 维护着一个 socket 连接池，处理请求的线程通过连接池中的某个 socket 连接与 memacahed 服务器传输数据，当发生某种异常情况造成客户端很多连接突然断开，很多没有完成数据传输的连接被放回 socket pool，这些连接被后续的线程拿到，由于连接是客户端突发断开的，拿到 socket 连接的线程发现 socket 中还有数据，就在 Reset 方法中读掉这些数据，对于 tcp 连接，如果想重用它，必须这么干（参考NetworkStream doesn't flush data）。在高并发的场景下，当有大量的线程忙于这个，如果是异步方法，需要读取 socket 数据的线程线程会被释放出来，不会带来大的影响，而如果是同步方法，大量线程阻塞在这里等待读取 socket 数据，线程池中的线程就不够用，而对于 web 应用，每1个请求都需要1个线程来处理，线程不够用就会造成请求排队等分配线程，从用户侧看就是打开页面缓慢。

从目前来看，我们遇到的四次故障（一、二、三、四）很可能就掉进了这个大坑，但现在不能确认它就是罪魁祸首，需要进一步验证。

上个周末我们已经实现了异步的 ResetAsync 并发布上线

public async Task ResetAsync()
{
    int available = _socket.Available;

    if (available > 0)
    {
        if (_logger.IsEnabled(LogLevel.Warning))
        {
            _logger.LogWarning(
                "Socket bound to {0} has {1} unread data! This is probably a bug in the code. InstanceID was {2}.",
                _socket.RemoteEndPoint, available, this.InstanceId);
        }

        var data = new byte[available];

        await ReadAsync(data, 0, available);
    }
}

今天晚上8点左右会进行一次发布操作，看是否还会出现故障。

对于这个验证工作，需要至少5次工作日晚上的发布验证。

留下的疑问：这个坑埋在园码中多年，为什么最近才多次掉进去？而且恰恰是在我们将博客系统升级到 .NET 5.0，是什么样的巧合造成让 .NET 5.0 背锅的尴尬？

【更新】晚上的发布情况见第3集-剧情反转：EnyimMemcachedCore 无罪，.NET 5.0 继续背锅