佳佳的博客

Appearance

CSRedis RedisClientException : Connection was not opened ​

🏷️ CSRedis

线上生产 .NET Core 项目偶尔会报如下错误：

txt
CSRedis.RedisClientException: Connection was not opened
   at CSRedis.CSRedisClient.GetAndExecute[T](RedisClientPool pool, Func\`2 handler, Int32 jump)
   at CSRedis.CSRedisClient.ExecuteScalar[T](String key, Func\`3 hander)
   at CSRedis.CSRedisClient.Set(String key, Object value, Int32 expireSeconds, Nullable\`1 exists)
   at Framework.Utils.RedisProvider.Set[T](String key, T value, Int32 minutes)

CSRedisCore 的版本号是 3.0.0 。

2019/02/01 追记 ​

经过查看源码、线下模拟最终怀疑是创建 Socket 连接的时候发生了未知的问题导致创建连接失败，最终引发了这个异常。
这个未知的问题是什么？我也不知道。

先说下 CSRedis，它的连接字符串有一个属性叫 preheat 预热，该属性默认为 true。
启用预热时，会自动创建连接至池中的最大值（poolsize）。poolsize 设置的是 50，我感觉对于 Redis 来说这个值其实并不高。
连接创建后会放回到连接池中待用，此时若超过一定时间未使用，则该连接会被关闭。这个时间由 Redis 的超时时间 (timeout) 设置决定。

问题就出在创建连接时，多个服务同时启动时，会触发 n * 50 次创建连接的请求。短时间创建的连接过多导致更容易引发上述异常。

然而，在线下的测试环境中模拟短时间创建大量连接时并没有出现该异常。只有在较长时间重复创建连接到一定数量后（至少 1w 以上）有可能发生该异常。
因为模拟了好多种情况，总共出现过如下几种异常：

  1. ERR max number of clients reached

    这个估计是达到了 Redis 服务器的连接数上限导致的。

    txt
    RedisSocket.Connect endpoint : 192.168.0.66:8000
RedisSocket.Connect method cost 00:00:00.1314587
【192.168.0.66:8000/0】仍然不可用，下一次恢复检查
时间：01/29/2019 13:58:23，错误：(ERR max number of clients reached)

  2. 您的主机中的软件中止了一个已建立的连接

    这个应该是创建的连接过多导致本机的端口号耗尽导致的。这种情况应该不会发生在线上，不可能有那么多的请求量。

    txt
    ---> (Inner Exception #93) System.IO.IOException:
Unable to write data to the transport connection:
您的主机中的软件中止了一个已建立的连接。. ---> System.Net.Sockets.SocketException: 您的主机中的软件
中止了一个已建立的连接。
  at System.Net.Sockets.NetworkStream.Write(Byte[] buffer, Int32 offset, Int32 size)
  --- End of inner exception stack trace ---
  at OctToolServices.Controllers.CSRedisController.<>c__DisplayClass8_0.<TestConnectionMultiThread>b__0() in D:\middleware\octmiddlewarenet\OctApiService\OctToolServices\Controllers\CSRedisController.cs:line 157
  at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
  at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)<---

  3. Connection was not opened

    个人认为这个错误是最接近线上情况的。
    其中打印的时间就是创建 Socket 连接所消耗的时间。正常值都是在 1ms 以下，但这是显示超过了 20s。
    另外的两行的控制台消息不确定是哪边打印出来的。
    另外这个也是在大量创建连接时发生的异常，但大部分时候是报（您的主机中的软件中止了一个已建立的连接）的错误消息。

    txt
    RedisSocket.Connect method cost 00:00:21.0015986
【192.168.0.76:8000/0】仍然不可用，下一次恢复检查时间：01/29/2019 13:27:21，错误：(Connection was not opened)
RedisSocket.Connect method cost 00:00:21.1406340
【192.168.0.76:8000/0】仍然不可用，下一次恢复检查时间：01/29/2019 13:27:23，错误：(Connection was not opened)

  4. 状态不可用，等待后台检查程序恢复方可使用。Connection was not opened

    这个应该是和上面的 3 是同一个错误。

    txt
    ---> (Inner Exception #49) System.Exception: 【192.168.0.66:8000/0】状态不可用，等待后台检查程序恢复方可使用。Connection was not opened
  at OctToolServices.Controllers.CSRedisController.<>c__DisplayClass9_1.<CreateTestData>b__0() in D:\middleware\octmiddlewarenet\OctApiService\OctToolServices\Controllers\CSRedisController.cs:line 218
  at System.Threading.ExecutionContext.RunInternal(ExecutionContext executionContext, ContextCallback callback, Object state)
--- End of stack trace from previous location where exception was thrown ---
  at System.Threading.Tasks.Task.ExecuteWithThreadLocal(Task& currentTaskSlot)<---

根据上面的测试结果，比较大的可能性在于创建 Socket 连接的时候出了问题导致的。在 Java 建立 Socket 慢的问题 里说了一个建立 Socket 慢的原因。

使用 HostName 查找主机 IP 时可能会因为要查询 DNS 服务器，所以导致了连接缓慢。

由于这里使用的 IP 应该不会有这个问题才对。官方的一个 bug 修复 v3.0.33 解决域名访问，同时开启 ssl 无法连接的 bug 里正好有类似的改动。

修改前：

csharp
public RedisClient OnCreate() {
    var ips = Dns.GetHostAddresses(_ip);
    if (ips.Length == 0) throw new Exception($"无法解析“{_ip}”");
    var client = new RedisClient(new IPEndPoint(ips[0], _port), _ssl, 100, _writebuffer);
    // ...
}

修改后：

csharp
public RedisClient OnCreate() {
    RedisClient client = null;
    if (IPAddress.TryParse(_ip, out var tryip)) {
        client = new RedisClient(new IPEndPoint(tryip, _port), _ssl, 100, _writebuffer);
    } else {
        var ips = Dns.GetHostAddresses(_ip);
        if (ips.Length == 0) throw new Exception($"无法解析“{_ip}”");
        client = new RedisClient(_ip, _port, _ssl, 100, _writebuffer);
    }
    // ...
}

修改前使用 Dns.GetHostAddresses 函数来获取 Redis 服务器地址，其 MSDN Dns.GetHostAddresses(String) Method 上的说明如下：

GetHostAddresses 方法将查询与主机名关联的 IP 地址的 DNS 子系统。如果 hostNameOrAddress 是 IP 地址，而无需查询 DNS 服务器返回此地址。
如果为空字符串作为传递 hostNameOrAddress 参数，则此方法返回本地主机的 IPv4 和 IPv6 地址。
Pv6 地址进行筛选的结果中的 GetHostAddresses 方法如果本地计算机没有安装 IPv6。因此，很可能返回一个空 IPAddress 只要 IPv6 结果已可供 hostNameOrAddress 参数。

修改后明确的判断 IP 优先。

最终的解决方案 ​

  1. 按照上面 Dns.GetHostAddresses 的说明上面的补丁效果应该是一样的。为了以防万一还是打上了这个补丁。
  2. 关闭了 CSRedis 的预热（preheat）功能。
  3. 调低了 CSRedis 的 poolsize （原为 50 降到 5）。

从更新补丁上线到现在 2 天了，暂时还没有再出现该异常。

2019/03/11 追记 ​

╮(╯﹏╰)╭
非常残念的是从更新到现在 40 天的时间里还是出现了 2 次这个异常。