Paho MQTT客户端(Javascript)、Envoy、VerneMQ:调试断开连接的情况
在将picockpit部署到我的服务器后,发现了一个错误:网络前端会以非常有规律的间隔断开连接。
这个问题在本地开发环境中没有出现过。picockpit的用户报告了同样的错误。
我今天对它进行了调试,并应用了一个热修复。事实证明,这是一个时间问题。
TL;DR 如何解决这个问题
为Paho设置一个更短的keepAliveInterval。60秒是默认的,但由于网络延迟,这将导致这些超时。
这是我的连接代码(在pcp-code.js内,由网页加载)。
/* https://www.eclipse.org/paho/files/jsdoc/Paho.MQTT.Client.html */
功能 MQTTconnect_inner(params){
mqtt = new Paho.Client(params.uri, params.clientid); /*设置不需要的参数,因为JS不允许传递命名的位置参数 */
mqtt.onConnectionLost = mqtt_onConnectionLost。
mqtt.onMessageDelivered = mqtt_onMessageDelivered。
mqtt.onMessageArrived = mqtt_onMessageArrived。
mqtt.onConnected = mqtt_onConnect_proper。var options = {
timeout:3, /*如果在3秒内没有连接成功,则被视为失败 */
onSuccess: mqtt_onConnect_connect。
onFailure: mqtt_onConnectFailure_connect。
userName: params.userName。
password: params.password,
keepAliveInterval:30,
useSSL: true,
reconnect: false。
mqttVersion:4
};
mqtt.connect(options)。
}
(也是以图片形式转载)
调试步骤
时间安排
我拿着手机坐下来为超时计时,看看是否有一个模式。
在我的实现中,Paho每隔10秒超时就会被周围的JavaScript代码重新连接。
我们看到Paho javascript MQTT客户端每隔一分钟或两分钟就会失去连接。这已经是一个强有力的迹象,表明这是系统性的,可能是服务器的强制断开连接。
JavaScript控制台
我在控制台看到的错误信息是。
WebSocket已经处于CLOSING或CLOSED状态。
现在回想起来,这可能是Paho试图发送PINGREQ,但只是失败了几秒钟或可能是几微秒,因为服务器已经断开了套接字。
注:为了与公司防火墙等有更好的兼容性。我通过websockets运行Paho。
用其他浏览器验证
我在Chrome(我的主要浏览器)和Firefox都看到过这个问题。因此,这不是由于浏览器的问题。
(我被引导到相信这可能是这个网站的一些浏览器问题。 https://github.com/socketio/socket.io/issues/3259)
调试VerneMQ
另见。
- https://pi3g.com/2019/08/08/vernemq-how-to-disconnect-clients-forceably-per-command-line/
- https://docs.vernemq.com/administration/managing-sessions
显示完整的client_id和mountpoint以避免截断。
vmq-admin session show -mountpoint -client_id
运行一个跟踪。
vmq-admin trace client client-id=js.1567943187982KSWuLXb -mountpoint=5cc72b97a6b76f00013d35d2
正如你所看到的,你将得到一个发送到客户端和从客户端收到的内容的追踪。
开始追踪客户端 "js.1567943187982KSWuLXb "的1个现有会话,PID为
[]
mqtt发送。MP: "5cc72b97a6b76f00013d35d2" CID: "js.1567943187982KSWuLXb" PUBLISH(d0, q0, r0, m0, "pi/000000007eaefc47/com.picockpit/sensors/$state/pi" ) with payload:
{"wlan_signal_info":"Link Quality=61/70 Signal level=-49 dBm", "cpu_load":1.4, "net_io_bytes_received":798582943, "root_partition_used": 2028572672, "net_io_bytes_received":1482989984, "soc_temperatu (truncated)
我还看到一个PINGREQ()和PINGRESP(),在这个跟踪中保持会话的活力。
MQTT RECV: MP: "5cc72b97a6b76f00013d35d2" CID: "js.1567943187982KSWuLXb" PINGREQ(.)
mqtt发送。MP: "5cc72b97a6b76f00013d35d2" CID: "js.1567943187982KSWuLXb" PINGRESP()
以下是断开连接的情况。
mqtt发送。MP: "5cc72b97a6b76f00013d35d2" CID: "js.1567943187982KSWuLXb" PUBLISH(d0, q0, r0, m0, "pi/00000000327f9cbf/com.picockpit/sensors/$state/pi" ) with payload:
{"wlan_signal_info":"Link Quality=68/70 Signal level=-42 dBm", "ram_total_bytes":969392128, "$uuid":“928ca964-d22e-11e9-9e22-dca632007438”, “disk_io_bytes_written”:619947008, "root_partition_tota (truncated)
对js.1567943187982KSWuLXb的跟踪会话停止了
不幸的是,有 无信息 这是由于等待客户端pingreq()的超时造成的。
调试特使
另见。
由于没有信息表明这是由于pingreq超时造成的,因此怀疑envoy由于超时而断开连接(可能由于我没有正确设置一些配置而错误地处理websockets)。
然而,该配置的应用是正确的。
upgrade_configs。
- 升级_类型。"websocket"
enabled: true
为正确的路径(/mqtt)。
除了后端connect_timeout(被设置为不同的值,肯定不是一分钟)之外,没有任何超时。
为了启用envoy的调试输出,你必须在docker-compose.yaml中添加一个环境变量。
环境。
日志级别: debug
作为服务使节的最后一句话
以下是我看到的痕迹。
':状态', '101
'连接', '升级'
'date', 'Sun, 08 Sep 2019 12:08:36 GMT'
'sec-websocket-accept', 'mWAEi6p3RBFflHkNbxTMbnhaG4I='
'sec-websocket-extensions', 'permessessage-deflate; client_max_window_bits=15'
'sec-websocket-protocol', 'mqtt'.
'server', 'envoy'.
'升级', 'websocket'
'content-length', '0
[2019-09-08 12:08:38.757][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:08:43.760][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:08:48.755][1][debug][main] [source/server/server.cc:170] 冲洗统计信息
[2019-09-08 12:08:53.759][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:08:58.762][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:09:03.762][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:09:08.762][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:09:13.765][1][debug][main] [source/server/server.cc:170] 冲洗统计信息
[2019-09-08 12:09:18.766][1][debug][main] [source/server/server.cc:170] 冲洗统计信息
[2019-09-08 12:09:23.766][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
[2019-09-08 12:09:28.765][1][debug][main] [source/server/server.cc:170] 冲洗统计信息
[2019-09-08 12:09:33.766][1][debug][main] [source/server/server.cc:170] 冲洗统计信息
[2019-09-08 12:09:37.190][26][debug][connection] [source/common/network/connection_impl.cc:520] [C9] 远程关闭
[2019-09-08 12:09:37.190][26][debug][connection] [source/common/network/connection_impl.cc:190] [C9] 关闭socket。0
[2019-09-08 12:09:37.190][26][debug][client] [source/common/http/codec_client.cc:82] [C9] 断开连接。重置 1 个待处理请求
[2019-09-08 12:09:37.190][26][debug][client] [source/common/http/codec_client.cc:105] [C9] 请求重置
[2019-09-08 12:09:37.190][26][debug][router] [source/common/router/router.cc:868] [C8][S10834556124828578161] 上游复位:复位原因连接终止
[2019-09-08 12:09:37.190][26][debug][http] [source/common/http/conn_manager_impl.cc:187] [C8][S10834556124828578161] doEndStream()重置流
[2019-09-08 12:09:37.191][26][debug][http] [source/common/http/conn_manager_impl.cc:1596] [C8][S10834556124828578161] stream reset
[2019-09-08 12:09:37.191][26][debug][connection] [source/common/network/connection_impl.cc:101] [C8] closing data_to_write=0 type=2
[2019-09-08 12:09:37.191][26][debug][connection] [source/common/network/connection_impl.cc:653] [C8] 设置延迟关闭定时器,超时1000ms
[2019-09-08 12:09:37.191][26][debug][pool] [source/common/http/http1/conn_pool.cc:129] [C9] client disconnected, failure reason:
[2019-09-08 12:09:38.192][26][debug][connection] [source/common/network/connection_impl.cc:642] [C8] 触发了延迟关闭。
[2019-09-08 12:09:38.192][26][debug][connection] [source/common/network/connection_impl.cc:190] [C8] 关闭socket。1
[2019-09-08 12:09:38.192][26][debug][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:270] [C8] SSL shutdown: rc=0
[2019-09-08 12:09:38.192][26][debug][connection] [source/extensions/transport_sockets/tls/ssl_socket.cc:201] [C8]
[2019-09-08 12:09:38.193][26][debug][main] [source/server/connection_handler_impl.cc:80] [C8] 添加到清理列表中
[2019-09-08 12:09:38.767][1][debug][main] [source/server/server.cc:170] 冲洗统计资料
这与客户端的断开连接相吻合
正如你所看到的,这是由
[C9]远程关闭
在VerneMQ由于超时问题而断开客户端时,这又让人产生怀疑。
Paho的时间选择
阅读MQTT和keep-alives的一个好来源是Steve的互联网指南。
客户端必须发送keepalive数据包(PINGREQ),在没有其他控制数据包的情况下。 并负责 为数据包之间的间隔不超过经纪商上设置的Keep Alive值。
客户端可以提前发送数据包
调查的下一步导致了对Paho和keepalive的关注。我最初担心的是,Paho不会自己发送keepalive,所以我必须运行一个循环并发送它们。
然而,我们发现事实并非如此--Paho实际上自己处理keepalives。
这里是Paho MQTT Javascript的源代码。
第703行及以下有 "Pinger"。
它定义了一个doTimeout函数,该函数反过来返回doPing
doPing是在下面定义的,它运行实际的ping,并设置了一个超时,用this._keepAliveInterval。
this._client.socket.send(pingReq)。
this.timeout = setTimeout(doTimeout(this), this._keepAliveInterval)。
现在,我非常确定,Paho的keepAliveInterval必须从默认的60秒减少。可能是由于网络延迟的原因,在本地对我有效的东西在远程却不再有效了。
我们如何设置不同的时间间隔?
Paho文件。
Paho客户端实例有一个方法connect,它需要一个对象作为其单一参数。
该对象有不同的属性,其中之一是keepAliveInterval。
我把这个keepAliveInterval设置为30秒。这是我目前使用的一组参数。
var options = {
timeout:3, /*如果在3秒内没有连接成功,则被视为失败 */
onSuccess: mqtt_onConnect_connect。
onFailure: mqtt_onConnectFailure_connect。
userName: params.userName。
password: params.password,
keepAliveInterval:30,
useSSL: true,
reconnect: false。
mqttVersion:4
};
mqtt.connect(options)。
mqtt是Paho MQTT客户端的一个实例。