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

另见。

显示完整的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客户端的一个实例。