[BUG] Remote Logging generates too large messages, killing communication between Gateway and TB

[rduivenvoorde]

Running Gateway 2.8 and Thingsboard 3.3.1

When enabling Remote Logging (DEBUG level) on the gateway as described here: https://thingsboard.io/docs/iot-gateway/guides/how-to-enable-remote-logging/

The communication between Gateway and Thingsboard stops (acutally disabling all sensors) with a message that the (logging) message is too large (see below).

WIthout logging all works fine. We have to restart both TB and Gateway (and disable logging there) to make things work again. Others have Remote Logging (via mqtt) working?

2021-10-27 07:24:24,200 [sql-log-1-thread-1] INFO  o.t.s.dao.sql.TbSqlBlockingQueue - Queue-0 [TS] queueSize [0] totalAdded [12] totalSaved [12] totalFailed [0]
2021-10-27 07:24:24,424 [sql-log-1-thread-1] INFO  o.t.s.dao.sql.TbSqlBlockingQueue - Queue-0 [TS Latest] queueSize [0] totalAdded [12] totalSaved [12] totalFailed [0]
2021-10-27 07:24:27,033 [queue-scheduler-11-thread-1] INFO  o.t.s.q.u.DefaultTbApiUsageClient - Reporting API usage statistics for 2 tenants and customers
2021-10-27 07:24:30,095 [nioEventLoopGroup-4-6] INFO  o.t.s.t.mqtt.MqttTransportHandler - [032b9280-7f21-4aab-856d-1e6667d40bd0] Processing connect msg for client: !
2021-10-27 07:24:30,095 [nioEventLoopGroup-4-6] INFO  o.t.s.t.mqtt.MqttTransportHandler - [032b9280-7f21-4aab-856d-1e6667d40bd0] Processing connect msg for client with user name: *SNIP*
2021-10-27 07:24:30,098 [DefaultTransportService-2-18] INFO  o.t.s.t.mqtt.MqttTransportHandler - [032b9280-7f21-4aab-856d-1e6667d40bd0] Client connected!
2021-10-27 07:24:30,114 [nioEventLoopGroup-4-6] ERROR o.t.s.t.mqtt.MqttTransportHandler - [032b9280-7f21-4aab-856d-1e6667d40bd0] Message decoding failed: too large message: 110874 bytes
2021-10-27 07:24:30,114 [nioEventLoopGroup-4-6] INFO  o.t.s.t.mqtt.MqttTransportHandler - [032b9280-7f21-4aab-856d-1e6667d40bd0] Client disconnected!
2021-10-27 07:24:33,260 [sql-log-1-thread-1] INFO  o.t.s.dao.sql.TbSqlBlockingQueue - Queue-0 [Attributes] queueSize [0] totalAdded [4] totalSaved [4] totalFailed [0]
2021-10-27 07:24:33,442 [TB-Scheduling-1] INFO  o.t.s.s.s.DefaultTbEntityDataSubscriptionService - Stats: regularQueryInvocationCnt = [6], regularQueryInvocationTime = [10], dynamicQueryCnt = [4] dynamicQueryInvocationCnt = [6], dynamicQueryInvocationTime = [10], alarmQueryInvocationCnt = [0], alarmQueryInvocationTime = [0]

The actual 'messages' as copied from Telemetry tab is:

log.zip

A part:

2021-10-27 07:10:34,110 - DEBUG - [tb_gateway_service.py] - tb_gateway_service - 439 - Reading events: ['{"deviceName": "currentThingsBoardGateway", "telemetry": {"ts": 1635318634081, "values": {"LOGS": "2021-10-27 07:10:34,077 - DEBUG - [tb_gateway_service.py] - tb_gateway_service - 439 - Reading events: [\'{\\"deviceName\\": \\"currentThingsBoardGateway\\", \\"telemetry\\": {\\"ts\\": 1635318634041, \\"values\\": {\\"LOGS\\": \\"2021-10-27 07:10:34,038 - DEBUG - [tb_gateway_service.py] - tb_gateway_service - 439 - Reading events: [\\\\\'{\\\\\\\\\\"deviceName\\\\\\\\\\": \\\\\\\\\\"currentThingsBoardGateway\\\\\\\\\\", \\\\\\\\\\"telemetry\\\\\\\\\\": {\\\\\\\\\\"ts\\\\\\\\\\": 1635318633997, \\\\\\\\\\"values\\\\\\\\\\": {\\\\\\\\\\"LOGS\\\\\\\\\\": \\\\\\\\\\"2021-10-27 07:10:33,996 - DEBUG - [tb_gateway_service.py] - tb_gateway_service - 439 - Reading events: [\\\\\\\\\\\\\\\\\\\\\'{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"deviceName\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\": \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"currentThingsBoardGateway\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\", \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"telemetry\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\": {\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"ts\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\": 1635318633974, \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"values\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\": {\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"LOGS\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\": \\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"2021-10-27 07:10:33,974 - DEBUG - [tb_gateway_service.py] - tb_gateway_service - 439 - Reading events: [\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\'{\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\"deviceName\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\\

To me it looks like there are several (more) log lines in the message? Could this become too large? I though mqtt could handle super large messages...

Versions (please complete the following information):

• OS: docker images on Centos7
• Gateway 2.8 (MQTT connector and Thingsboard 3.3.1
• Python version 3.7.12

[imbeacon]

Hi @rduivenvoorde ,

Thank you for your interest in ThingsBoard IoT gateway. It is a ne bug, we will fix it and let you know. Thanks for information.

[imbeacon]

@rduivenvoorde ,

This issue is fixed in the master branch, you may try it or wait for release. Also, this issue only appeared on DEBUG logging level, you may change it to INFO as a workaround until you update the gateway.

[rduivenvoorde]

@zbeacon thanks for fixing and the work around. Will wait for new release.

Note: we also see a high python cpu on the gateway recently... is/was that related?

[imbeacon]

We are investigating this issue.