steveohara / j2mod

Enhanced Modbus library implemented in the Java programming language
Apache License 2.0
267 stars 111 forks source link

Debug logger messages causing garbage collections even when DEBUG mode is not enabled #53

Closed ippodamia closed 7 years ago

ippodamia commented 7 years ago

I made a little benchmark to compare the memory performance of j2mod and another Modbus library (jlibmodbus). I read 6 holding registers with a repetition period of 20ms and 100.000 repetitions. I saw that the j2mod test caused 27 garbage collections (young space minor GCs) while the jlibmodbus test caused only 6 garbage collections in the 31,5 minutes that the benchmark was running.

I investigated why j2mod is causing more garbage collections and I found out that temporary char arrays (i.e. Strings) are filling the young space. In my test the most of these char arrays are allocated by the ModbusUtil.toHex method which is called by the ModbusTCPTransport class as shown in the following allocation call tree: image

I saw that the calls of the ModbusUtil.toHex method in the ModbusTCPTransport class are made from logger.debug calls so I added the isDebugEnabled() check in the 3 calls of the logger.debug method:

 if(logger.isDebugEnabled())
                logger.debug(...);

After the change I repeated the benchmark and the garbage collections of j2mod test were only 7.

As explained here https://stackoverflow.com/a/29561054 when building one of the parameters of the debug message might be expensive, you would still want to use isDebugEnabled() even with SLF4J.

So you could consider adding the isDebugEnabled check in all your debug messages.

steveohara commented 7 years ago

Good idea, thanks for the suggestion

steveohara commented 7 years ago

Added to snapshot 2.3.6