eclipse-paho / eclipse-paho/paho.mqtt.java
Significant increase of CPU usage after 1.2.0 to 1.2.1 update
- Dominant language
- Java
- Stars
- 2.3k
- Forks
- 919
- PR merge metrics
- No merged PRs in 30d
Description
Please fill out the form below before submitting, thank you!
- [X ] Bug exists Release Version 1.2.2 ( Master Branch)
- [?] Bug exists in MQTTv3 Client on Snapshot Version 1.2.3-SNAPSHOT (Develop Branch)
- [?] Bug exists in MQTTv5 Client on Snapshot Version 1.2.3-SNAPSHOT (Develop Branch)
This bug did not exist in Release Version 1.2.0.
---
I observe a significant increase of the CPU usage after upgrading the paho driver from version 1.2.0 to 1.2.1.
**Initial Situation**
The observations are made in a system with Java applications that publish and subscribe messages with a rate of about 1200 msg/sec.
The application setup looks like this:
* a Spring Boot 2.2.4 application which runs in 16 instances
* these instances are MQTT-Publisher
* the overall rate of published messages is about 1200/sec
* a Spring Boot 2.2.4 application which runs in 5 instances
* these instances are MQTT Subscriber
* together they subscribe all published messages
* messages are persited in a MongoDB
* a Spring Boot 2.2.4 application instance that runs in 1 instance
* that is a subscriber but gets no messages in the test setup
The applications are build with Java 11 (which is also used as runtime).
The 'G1' Garbage Collector is used without any special configuration.
The hardware used to run all application instances is
* one single linux machine with
* MemTotal: 12,137,840 kB
* 3 processors with 2 cpu cores each
The MQTT Broker (HiveMQ 3.3.4) and MongoDB (3.4.24) are installed on different machines.
**Using paho 1.2.1 (or 1.2.2)**
If the applications use version 1.2.1 (or 1.2.2) of the paho Java driver an extreme utilization of the system ressource (especially CPU) can be observed.
The following screenshot of the top command illustrates the load:

The load average is about 45!
Maybe this is becaus of heavy Garbage Collecting.
The GC-log of one example process is like this:
```
[2020-02-20T09:15:00.590+0000] GC(1348) Pause Full (System.gc()) 134M->16M(256M) 569.747ms
[2020-02-20T09:15:03.123+0000] GC(1349) Pause Young (Normal) (G1 Evacuation Pause) 169M->16M(256M) 6.368ms
[2020-02-20T09:15:06.221+0000] GC(1350) Pause Young (Normal) (G1 Evacuation Pause) 168M->16M(256M) 5.140ms
[2020-02-20T09:15:08.918+0000] GC(1351) Pause Young (Normal) (G1 Evacuation Pause) 168M->16M(256M) 7.980ms
[2020-02-20T09:15:11.823+0000] GC(1352) Pause Young (Normal) (G1 Evacuation Pause) 168M->16M(256M) 2.535ms
[2020-02-20T09:15:14.998+0000] GC(1353) Pause Young (Normal) (G1 Evacuation Pause) 168M->16M(256M) 3.370ms
```
**Using paho 1.2.0**
The average load of the system when using the paho client 1.2.0 in all applications is much nicer:

The average load is about 1.3 and also Garbage collecting does not take that long:
```
[2020-02-20T10:45:00.545+0000] GC(1614) Pause Full (System.gc()) 43M->17M(256M) 537.494ms
[2020-02-20T10:45:03.061+0000] GC(1615) Pause Young (Normal) (G1 Evacuation Pause) 170M->17M(256M) 1.849ms
[2020-02-20T10:45:06.048+0000] GC(1616) Pause Young (Normal) (G1 Evacuation Pause) 169M->17M(256M) 1.602ms
[2020-02-20T10:45:08.889+0000] GC(1617) Pause Young (Normal) (G1 Evacuation Pause) 169M->17M(256M) 1.418ms
[2020-02-20T10:45:11.678+0000] GC(1618) Pause Young (Normal) (G1 Evacuation Pause) 169M->17M(256M) 1.628ms
[2020-02-20T10:45:14.540+0000] GC(1619) Pause Young (Normal) (G1 Evacuation Pause) 169M->17M(256M) 2.673ms
```
**Conclusions**
The update of the paho java client from version 1.2.0 to 1.2.1 has a major impact on the performance of our overall system.
Therefore we are not able to migrate to a current paho version, although relevant bug fixes have been applied.
Why the system behaves this way with the new paho version could not be clarified at this point.
It would be great if there was a solution for our problem.
Otherwise the upgrade path will be blocked for us.
Contributor guide
Assessment
This issue has not been assessed yet.