emqx连接频繁断开的问题，每天断开3-5次是否正常

zhuchunmei · 2023 年3 月 17 日 05:40

EMQX 版本：4.3.8
使用过程中，应用服务作为一个客户端连接emqx总是没有见到异常就断开了，emqx服务端的日志也没有发现异常信息。
客户端报错信息
ime="2022-11-18T10:34:57+08:00”leve=error msg="发布消息失败: publsh was broken by timeout 'ime="2022-11-18T10:34:57+08:00” level=info msg=“mqtt下发指令超时，删除指令，队列
05165456734238090 长度: 2”

t1ger · 2023 年3 月 17 日 06:46

你好，一般这类连接、订阅、发布的问题，都可以先追踪一下看看。详见追踪文档。

zhuchunmei · 2023 年3 月 20 日 05:52

您好，您说的这个日志是跟踪服务端的日志吗，我们这边监测了一下断开的时候客户端这边的日志，没有看到明显的异常，请您帮忙看下:
{“log”:“[store] memorystore del: message 30614 was deleted\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966620409Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966624109Z”}
{“log”:“[net] obound from incoming msg to write, type *packets.PubrelPacket ID 12\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966627591Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.96663403Z”}
{“log”:“[net] obound from incoming msg to write, type *packets.PubcompPacket ID 30614\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966636562Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966638962Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966657394Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966662062Z”}
{“log”:“[net] startIncomingComms: received pubrel, id: 30615\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966664493Z”}
{“log”:“[store] memorystore del: message 30615 was deleted\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966666926Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966674472Z”}
{“log”:“[net] obound from incoming msg to write, type *packets.PubcompPacket ID 30615\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966677075Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.96671337Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966726503Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966730531Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966735034Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966737736Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966740314Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966742724Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 30616\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966745077Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966747499Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966749937Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966812019Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966818141Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 30617\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:54.966820641Z”}
{“log”:“time="2023-03-20T07:44:55+08:00" level=info msg="队列为空: 1051664531896768364"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:55.0053013Z”}
{“log”:“time="2023-03-20T07:44:55+08:00" level=info msg="队列为空: 1051671197201911307"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:55.005354474Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005376737Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005384831Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.00538855Z”}
{“log”:“[net] putting pubrec msg on obound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005392443Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.00539613Z”}
{“log”:“[net] done putting pubrec msg on obound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005401102Z”}
{“log”:“time="2023-03-20T07:44:55+08:00" level=info msg="队列为空: 1051671153865944380"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:55.005403816Z”}
{“log”:“[net] obound priority msg to write, type *packets.PubrecPacket\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005405214Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005471349Z”}
{“log”:“[net] putting pubrec msg on obound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005474604Z”}
{“log”:“[net] done putting pubrec msg on obound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005477399Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005480092Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005482471Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005485078Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005487458Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005492166Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005506189Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005508812Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005511333Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005513644Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005515882Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005518248Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005617859Z”}
{“log”:“[net] obound priority msg to write, type *packets.PubrecPacket\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005630589Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.005634456Z”}
{“log”:“time="2023-03-20T07:44:55+08:00" level=info msg="队列为空: 1051669627351438417"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:55.051889804Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051956942Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051974135Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051977086Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051979977Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051982613Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051985153Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.05198742Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.051989913Z”}
{“log”:“[net] logic waiting for msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.10027255Z”}
{“log”:“[net] startIncomingComms: got msg on ibound\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.100311662Z”}
{“log”:“[net] startIncomingComms: received publish, msgId: 0\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.100314803Z”}
{“log”:“[net] startIncoming Received Message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.100318449Z”}
{“log”:“[1,3,0,0,0,50,196,31]\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:55.109138627Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.109219585Z”}
{“log”:“[client] sending publish message, topic: /sys/device/105167618335492745/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.109233715Z”}
{“log”:“[net] obound msg to write 13\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.109236957Z”}
{“log”:“[net] obound wrote msg, id: 13\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.109248423Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:55.109257118Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051670723589690167 长度：0"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.000763516Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051656473257560684 长度：2"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.000809968Z”}
{“log”:“[pinger] ping check 3.893714563\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.003001103Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=error msg="发布消息失败: publish was broken by timeout"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.011279475Z”}
{“log”:“[21,3,0,0,0,50,199,11]\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.011312572Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=error msg="publish was broken by timeout断开 "\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.011327555Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051661581038119819 长度：0"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.011331767Z”}
{“log”:“time="2023-03-20T07:44:59+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051668761355810409 长度：19"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.011336093Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.01138208Z”}
{“log”:“[client] sending publish message, topic: /sys/device/1051656473257560684/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.011387082Z”}
{“log”:“[net] obound msg to write 14\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.011390622Z”}
{“log”:“[net] obound wrote msg, id: 14\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.01139366Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.011396798Z”}
{“log”:“[7,3,0,0,0,50,196,121]\n”,“stream”:“stderr”,“time”:“2023-03-19T23:44:59.019949345Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.020028704Z”}
{“log”:“[client] sending publish message, topic: /sys/device/1051668761355810409/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.020043884Z”}
{“log”:“[net] obound msg to write 15\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.020047638Z”}
{“log”:“[net] obound wrote msg, id: 15\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.020050344Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:44:59.020052895Z”}
{“log”:“[pinger] ping check 4.982959088\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:04.003053418Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：105166158103876562 长度：7"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.000656849Z”}
{“log”:“[pinger] ping check 9.982961921\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.002998868Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=error msg="发布消息失败: publish was broken by timeout"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.011675156Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=error msg="publish was broken by timeout断开 "\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.011712956Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="超时检测，队列为空: 1051661581038119819"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.011718502Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051668761355810409 长度：18"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.011722834Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.011726144Z”}
{“log”:“[client] sending publish message, topic: /sys/device/105166158103876562/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.011744409Z”}
{“log”:“[net] obound msg to write 16\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.011748299Z”}
{“log”:“[6,3,0,0,0,50,197,168]\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.011727308Z”}
{“log”:“[net] obound wrote msg, id: 16\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.011820678Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.011825508Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=error msg="发布消息失败: publish was broken by timeout"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.018155146Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=error msg="publish was broken by timeout断开 "\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.0181741Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="超时检测，队列为空: 1051664421603997972"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.018178472Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：105167618335492745 长度：0"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.018194265Z”}
{“log”:“time="2023-03-20T07:45:09+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：1051640262385496697 长度：20454"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.018223394Z”}
{“log”:“[10,3,0,0,0,50,197,100]\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:09.020102974Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.020144594Z”}
{“log”:“[client] sending publish message, topic: /sys/device/1051668761355810409/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.020161042Z”}
{“log”:“[net] obound msg to write 17\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.020251136Z”}
{“log”:“[net] obound wrote msg, id: 17\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.020263491Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.020266241Z”}
{“log”:“[client] enter Publish\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.023957402Z”}
{“log”:“[client] sending publish message, topic: /sys/device/1051640262385496697/ctrl\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.023973576Z”}
{“log”:“[net] obound msg to write 18\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.023976614Z”}
{“log”:“[net] obound wrote msg, id: 18\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.023979495Z”}
{“log”:“[net] outgoing waiting for an outbound message\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:09.023982649Z”}
{“log”:“[pinger] ping check 4.978952256\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:14.003099736Z”}
{“log”:“time="2023-03-20T07:45:19+08:00" level=info msg="mqtt下发指令超时，删除指令，队列：105166158362649016 长度：1"\n”,“stream”:“stderr”,“time”:“2023-03-19T23:45:19.000813297Z”}
{“log”:“手动检测mqtt存活！\n”,“stream”:“stdout”,“time”:“2023-03-19T23:45:19.001101468Z”}
{“log”:"检测到mqtt断开！++++++++++++++++++++++++++++++++++++