最近在阿里雲上轉用 skynet built in https 後，出現奇怪的 socket 問題

[tomlau10]

抱歉因為這個問題奇怪非常
無法定位到問題在哪裡，很難作出精簡的描述
請容我用比較長的篇幅做描述 🙏

---

背景

• skynet 版本: 1.3.0rc release tag 的 commit
• 我們的項目
  在國外使用 google kubernetes engine (GKE)
  在國內使用阿里雲 container kubernetes (ACK)
• 在早期由於 skynet 框架沒有 https 支援
  我們額外用 nodejs 寫了個 https proxy micro service 在另外的 container 跑
  並將 server 所有 http / https request 都用 http request + 改 header host 方式
  先發到這個 https proxy
  GKE 及 ACK 2邊也是這樣使用，一直正常
• 針對 http(s) request，我們是有個 httpc skynet service 來集中做管理
  並限制並發連接數上限 256
  超過的話，http request 會在該 service 排隊處理
  不過正常情況下，最大並發連接多數 < 5的
• 到7月左右我們修改了提到的 httpc service 的代碼
  可以直接使用 skynet built in https
  去掉 nodejs proxy 的使用
  並且測試通過後於 8月底 server 更新版本推出
  奇怪的 socket 情況就開始出現了。。。

問題

• GKE 上的 server 一直正常 (直到今天也正常)
• 但是 ACK 上偶爾會有大量玩家回報 lag / 爆 ping
  (幾乎是全個服，客服從當前世界頻截圖得出這樣的判斷)
• 不論人多還是人少 / 早上下午或凌晨都曾出現
  一開始是週末才出現，嚴重時一天可以爆 ping 幾次
  後來是隔天就出現一次
• 當出現問題時，server log 會有一堆 socket error / closed 的 msg

2020-09-13 13:40:54.051721 [:00000013] socket: error on 107963 Connection reset by peer
2020-09-13 13:40:54.057327 [:00000013] socket: error on 107965 Connection reset by peer
2020-09-13 13:40:54.059430 [:00000013] fd = 107963, [Socket Error]
2020-09-13 13:40:54.060925 [:00000013] fd = 107965, [Socket Error]
2020-09-13 13:41:20.986025 [:00000013] socket: error on 108220 Connection reset by peer
2020-09-13 13:41:20.988263 [:00000013] socket: error on 108222 Connection reset by peer
2020-09-13 13:41:20.994423 [:00000013] fd = 108220, [Socket Error]
2020-09-13 13:41:20.996318 [:00000013] fd = 108222, [Socket Error]
...

這裡 service 13 是我們的 httpd service
做法是參考 skynet/example/simpleweb.lua
用另外端口來監聽外部 command
eg shutdown / reboot / gm 後台對 server 做操作
且這個端口跟 game client 連接端口不相同
(下個部分再解釋為什麼這 httpd service 會經常有這麼多 socket 嘗試連接)

早期的測試

• 由於 GKE 並沒有出現問題，所以最初懷疑跟 ACK 有關
  ACK 的 loadbalancer 針對 exposed tcp port 有個 不能關掉的 health check
  loadbalancer 會不斷做 health check，這解釋了 httpd service 經常都會有 socket connect
  而當連接失敗被判 unhealthy，loadbalancer 就會不再 route 該端口 的 traffic 到該 instance
• 上邊的 service 13 socket error log
  應該就是 health check 的 connection
  而出現 error 感覺 是果不是因
  即 network 異常，所有 connection 都被 pause / close 了
  因此 log 才會出現 error
  而並非 health check error 導致 container network 被中斷
• 上點提到 httpd 端口跟 server 端口不相同
  若果單純 httpd 端口出異常，理應不影響 game client 端口的
  但當爆 ping 情況出現時，總有上述的 error log 相伴
  所以暫時能解釋的，要麼是 skynet 框架中的 socket 處理有異常
  要麼是 ACK 中 game server container 網絡有異常
  單純到這裡來看，後者概率較高
  因為同份代碼，在 GKE 下用相近 deployment 方式都沒有異常
• 所以我們試著修改 ACK deployment 中的 health check interval
  和加大 unhealthy 判定的 threshold
  但完全沒有改善到問題。。。

後期的測試

• 這個問題一直沒進展 😓
  直到9月底左右，回想起問題是於 8月底更新 才出現
  背景中提到當時 改用了 built in https
  由於十一假期臨近，想到什麼方式也只能試試
  於是抱著測試的心態，revert 了上述改動，轉回原有的 https proxy 方式
  結果竟然問題就消失了
• 然後就這樣過了愉快的十一假期 😐
  到上週六早上 server 例行重啟前
  我嘗試再改回去用 built in https
  結果不到一天再次出現爆 ping 情況 ...
  server log 情況同前

2020-10-10 18:37:14.192075 [:00000013] socket: error on 127594 Connection reset by peer
2020-10-10 18:37:14.200870 [:00000013] socket: error on 127596 Connection reset by peer
2020-10-10 18:37:14.202783 [:00000013] fd = 127594, [Socket Error]
2020-10-10 18:37:14.203821 [:00000013] fd = 127596, [Socket Error]
2020-10-10 20:25:45.290115 [:00000013] socket: error on 135587 Connection reset by peer
2020-10-10 20:25:45.290139 [:00000013] socket closed
2020-10-10 23:18:56.362953 [:00000013] socket: error on 149113 Connection reset by peer
2020-10-10 23:18:56.363672 [:00000013] socket: error on 149115 Connection reset by peer
2020-10-10 23:18:56.363847 [:00000013] fd = 149113, [Socket Error]
2020-10-10 23:18:56.364811 [:00000013] fd = 149115, [Socket Error]
...

嚇得我慌忙又換回去 https proxy 的做法 😑
然後週日就又回復正常了

暫時結論

• 貌似只有使用 skynet built in https 時，才會在 ACK 出現這個問題
  => skynet 問題，ACK 未必有問題
• 然而 GKE 上同一套代碼，無論運行 https proxy 還是 skynet built in https 都沒事
  => skynet 沒問題，是 ACK 問題
• 但以上2點好像又互相予盾
  因而無從判斷究竟是單純 skynet https 還是單純 ACK 的問題
  又或是 ACK + skynet https 才會出問題。。。
  並且目前也沒有進一步訊息判斷 哪一個環節 出問題

---

請問各位有遇過這種奇怪情況嗎?
有沒有 debug 方向建議?
個人還是希望能用上 skynet https 的
這樣 server 架構可以簡潔點，去掉 nodejs https proxy 🤔

[cloudwu]

skynet 并没有 1.3.0rc 这个 tag ，不知道准确版本是什么？

另外，8 月份的 a4dc6b9 增加了一个 pause 的特性，这个今天查出来是有 bug 的。因为原意是在客户端到服务器上行流量超过了处理能力后，可以暂停接收数据。但是这个 pause 同时把下行也中断了，导致在 pause 发生时，无法写出数据。

这个 bug 在今天 f3acbe4 修复。

但我看不出这个 bug 和这里有什么关系？

上行过载本身是比较罕见的事情，一般不会触发。如果使用了该版本，可以通过修改 https://github.com/cloudwu/skynet/blob/master/lualib/skynet/socket.lua#L6 BUFFER_LIMIT 为一个极大的数值来避免触发。目前是 128K ，即，如果单条连接上堆积了超过 128K 数据未被读取，那么会主动 pause 上行数据（但 bug 会导致下行写出的数据也同时被 pause ）。

你可以去掉 build-in https ，而用最新 skynet 代码，看看是否还有问题。

[cloudwu]

我理解是：玩家走的 https 协议的通道上并没有出错信息，但有 lag 延迟。
ACK 会出现 error 信息是因为某种超时机制导致请求方主动断开？

看文档介绍，ACK 走的是 http 协议，而不是 https 协议。是不是 ACK 用 http 请求去请求了 https 端口？能不能在 httpd 服务中加入更多的 log 观察 ACK 发送了怎样的数据包？

[cloudwu]

想到一种解释：

因为你限制了最大连接数 256 ，如果被占满，会导致 ACK 请求被搁置。一旦超时，ACK 会任务不健康，然后转而不再转发。

建议：

1. 给 ACK 的 IP 设立白名单 。
2. 到达最大连接数后增加 log 。
3. 排除潜在的服务过载问题（找出超出 256 的可能性）。

[tomlau10]

skynet 并没有 1.3.0rc 这个 tag ，不知道准确版本是什么？

確實沒有這個 tag，估計是我看錯 commit msg 成 release tag 了。。。
準確 commit hash 是 a6293f27cd08cbe33b5dc99b561e54659d544d54
是 2019 年 11月中左右
換句話應該後提到的 增加了一个 pause 的特性 無關 🤔
(因為 skynet 版本還未去到這 commit)

我理解是：玩家走的 https 协议的通道上并没有出错信息，但有 lag 延迟。

理解有誤，客戶端是直接用 socket 跟 server 做數據交互
跟 https 無關
上文提到的 httpc service 是 server 自身發 http request 所使用的

• eg server 收到客戶端 socket 傳來 login(param)
• 玩家可能是用 weixin login
• server 需要通過 weixin api 驗證 token => server 就會透過 httpc service 來發 http request
• server 收到 http reply 後，再 socket write data 給客戶端

看文档介绍，ACK 走的是 http 协议

是的
可能上文寫得太長，我表達得不清晰 🙈
我們項目中是有這麼 2個 service

• httpc => server 集中管理 自身對外發 http request 之用，限制了 server 同時最多發 256 request
  這個 service 可按我們的 deployment config，去選擇
  • 是否 所有 request 都通過 nodejs proxy
    使用時 url 會改成 httpc.request("http://<nodejs-proxy>/<path/...>") 並透過改 header host 傳原本的 host
  • 還是單純用 skynet 的 httpc.request("原有url") 來處理所有 request
• httpd (上邊的 service 13) => server 用來接收外部 http request command，eg reboot / shutdown

這2個 service 都不是面向客戶端的
前者只是類 http connection pool 管理
後者則因為要接收外部 http request 而 expose 了端口到 ACK loadbalancer
繼而 ACK loadbalancer 會對這端口做 http health check

以上 2個 service，功能上及代碼上都完全隔離，貌似沒什麼關聯
而目前是 httpc service 在使用 httpc.request() 處理所有 https request 時
偶爾 會導致 整個 container 所有 network 異常 的情況

• 影響玩家普通的 socket 傳輸
• 也影響 httpd ACK 的 health check reply

假如是跟 skynet 有關，2者共通的部分就只有 socket 層 (?) 🤔

---

ACK 会出现 error 信息是因为某种超时机制导致请求方主动断开？

同意
ACK 的 health check 有 timeout 選項，我們配置了 10s
理論上 server 應該可以秒回的
除非是 container network 出異常，又或 skynet 框架 socket 層出了異常 (讀不到 / 寫不到 socket)

是不是 ACK 用 http 请求去请求了 https 端口？

按上邊 httpc 跟 httpd 是2個分開 service 的解釋
應該不會出現這問題
httpd service 自身只會回應 http 而不回應 https 的

能不能在 httpd 服务中加入更多的 log 观察 ACK 发送了怎样的数据包？

對方是發一個 HEAD http request 過來
HEAD /test.html HTTP/1.0\r\n\r\n
然後我們的 httpd service 能用 httpd.read_request() 正確 decode
接著 httpd.write_response() 200 ok 回敬他

[tomlau10]

你可以去掉 build-in https

我前文表述有誤。。。
轉用 built in https 後出問題 並非指 compile skynet 加上 TLS_MODULE=ltls 就會造成問題
我們目前 GKE 和 ACK 上的 skynet 都是 compile 帶有 TLS_MODULE=ltls flag 的

經測試後，發現造成 ACK 上的問題
是 業務邏輯，會否將 https request 傳入 httpc.request()

上邊提到我們最初架構是用 nodejs https proxy
就是 轉化業務邏輯所有 request (http / https)
都改成 httpc.request("http://nodejs-proxy/path...", { host = "原host", proxy_https = 0/1 })
然後由 nodejs 應用按 header.proxy_https == 1 來轉換成 https，並返回 reply 給 server
這種情況下，server 代碼就 不會觸發到任何 "http.tlshelper" library 的代碼
server 不會有偶爾爆 ping / 任何 network 問題

但若是直接讓業務邏輯上的 https request
經由 httpc.request("https://原host/path...") 方式處理
就會偶爾出現 network 問題 🤔

但暫時無法解釋為何相同的代碼 (GKE / ACK 都使用相同 server docker image)
在 GKE 上不會引起問題。。。

[cloudwu]

我觉得你可以在 http.tlshelper 模块内多加一些 log 帮助分析到底发生了什么事情，收发了怎样的数据。

我们最近一年用 skynet 做了一些内部用的非常高负荷高流量高并发连接的服务，暂时没有发现网络层有什么 bug 。我认为可以信任网络层的实现。

倒是在处理高流量复杂的业务时，需要做一些流量控制操作，避免把数据堆积在网络层造成 OOM (out of memory) 问题，这就是最近新添的 api 的作用。

倒是 tls 可以多测试一下。但是有好些朋友使用基于 tsl 的 websocket 服务，似乎没有类似反馈。

我倾向于认为首先是 ACK 出错，导致阿里云判断健康有问题，从而停止了端口转发，继而造成玩家 lag 。

[tomlau10]

啊~ 另外有一個觀察
不確定會否有關

我們的業務會用到 zendesk 來處理客服相關
server 會調用到 zendesk 相關 api
而 ACK 上由於有 GFW 的關係
zendesk api 調用偶爾會抽風
短則 <30s，長則抽5分鐘
GKE 上則不會有抽風情況

當 ACK 出現相關 api request 抽風時
在 container 內，另外跑 curl -vvv <zendesk> 看到是卡在 client hello 1步

/app # curl -vvv https://test.zendesk.com/api/v2/tickets/show_many.json
*   Trying 104.16.51.111...
* TCP_NODELAY set
* Connected to test.zendesk.com (104.16.51.111) port 443 (#0)
* ALPN, offering h2
* ALPN, offering http/1.1
* successfully set certificate verify locations:
*   CAfile: none
  CApath: /etc/ssl/certs
* (304) (OUT), TLS handshake, Client hello (1):

卡了良久 (1分鐘左右?) 後會彈出 ssl error syscall

* OpenSSL SSL_connect: SSL_ERROR_SYSCALL in connection to test.zendesk.com:443
* stopped the pause stream!
* Closing connection 0
curl: (35) OpenSSL SSL_connect: SSL_ERROR_SYSCALL in connection to test.zendesk.com:443
/app #

---

• server 在有使用 nodejs https proxy 架構下
  對於 server 來說，socket.connect() 是正常的
  (因為只是 connect 到 https proxy container 而已)
  而由於用 proxy 機制下，所有 request 皆轉換成 http
  就不會調用到 httpc.request() 中的 interface.init()

• 若然 server 不使用 nodejs https proxy 架構
  等同於 server 自己跟 https 打交道
  => 會執行 interface.init() (也就會轉到 c層 lts.c 的 _ltls_context_handshake() 之類)

請教一下
若按上邊 curl verbose 的卡在 client tls handshake 這步的情況
skynet https 若也卡在這步的話
c 層調用會否出現任何問題? (eg blocking) 🤔

[cloudwu]

lts.c 问题需要 @lvzixun 来看。
不过该模块是一个纯 C 模块，不涉及网络 api ，它只负责处理数据。也就是说，不应该在 C 模块内部有任何阻塞。如果能增加更多 log 显示 lts.c 的内部的信息可能可以帮助排查问题。

阻塞一定发生在 lua 层，任何 c 层次的阻塞都会触发监控 log 。这个现象更像是 lts.c 模块需要的网络数据没有收全，导致 block 在 lua 层的 socket.read 上。

[cloudwu]

我建议可以把 https://github.com/cloudwu/skynet/blob/master/lualib/http/tlshelper.lua#L7 这里这个 socket.readfunc 包装一层，单独加上额外的 log ，观察在阻塞发生的时候的数据流。

[aceyin]

记录一下：

我们在2021.12.15也出现过大量 http/https 调用失败的问题， 具体原因还在查。
表现是：所有从skynet 请求外部的 http/https 全部超时，甚至根本就没发出去，持续时间有10多分钟，后来不知什么原因自行恢复。
这段时间运维监控上来看， 外部http接口都是正常的。
同时受影响的还有 mysql 服务， 数据不能写入mysql，mysql 服务的消息堆积很多。

skynet 版本: 1.3.0

[cloudwu]

1.3.0 版本 socket 没有 pause/resume 机制，在两端收发不对等时，容易出问题；另外，没有对半关闭状态妥善处理。

ps. skynet 版本更迭很少破坏兼容性，所以提倡尽量用 github 最新版本，勤更新比长期大更新更少出问题。现在没有维护特定稳定版的计划。