Reactor Memory Usage Analysis - Part 1

I have been observing the great work that Doug Hughes has been doing on Reactor. "Reactor is an ORM framework (Object Relational Mapper), meaning it transcodes your relational database into objects for you to use in your CF programming". Because of pressure of work I had not been able to be very useful to the project at all.

Recently, Doug had expressed concerns about what appeared to be a memory leak. As we have been working on such issues for Allaire and then Macromedia clients for many years, I volunteered to help.

This is the first blog of what we did and achieved so far and this was already circulated to the Reactor email list.

Here is what I have observed since we made the tweaks to the jvm.config file, shown below, on Doug''s server. Doug restarted a little while ago but I don''t think it was due to low memory in the instance. Here is the memory situation just before the restart:

Total Memory=512768 Free=215700

At this point the instance had been up and running from 05/25 21:47:47 to 05/28 14:16:57, around 2 days 17 hours and the free memory never got dangerously low during that time, in the logs I saw. Disabling those Explicit Full GC''s had a beneficial impact. I feel there are still improvements to be made but I know Doug is also looking at code-level issue at present so will hold off further recommendations at present.

In essence, we did two different things, the first group were related to monitoring or logging. We enabled Verbose Garbage Collection logging using these commands in the jvm.config file:

-XX:+PrintGCDetails -XX:+PrintGCTimeStamps -XX:+PrintHeapAtGC -verbose:gc -Xloggc:reactorgc.log (the last bit -Xloggc:reactorgc.log gives the log a name). This information goes into the jrun4 or runtime bin directory, by default. As a note point, this is not too verbose so the log does not get too big, however it should eventually be disabled. This logging helped us identify that too many Full GC''s were occurring.

We also enabled JRun Metrics Logging which shows us the memory status at a point in time along with thread usage details. We set this to report every 60 seconds.

The most useful piece that I used was SeeFusion which enables us to observe memory and thread behavior in real-time by looking at requests as they literally run. We also wrapped the JDBC driver with SeeFusion which enabled us to monitor database calls, SQL passed and query times.

Moving on the second group of things we did. As a result of looking at this monitor and log data, we observed to many Full GC''s taking place and an difficulty for JRun-CFMX to get up and running "comfortably". As a result, we made these changes to the jvm.config file:

Added these arguments (I have these on separate lines here for clarity but they should be added to the arguments string with a single space between each):

-Xms512m (this sets the memory available to the jvm at start at 512MB which saves the effort of the jvm acquiring it)

-XX:PermSize=128m (this does the same thing as above for the permanent memory space which is what the jvm uses for its own operation).

Note the start settings here must always be either equal to or less that the maximum setting, they cannot be set to higher. Also note, if you only have a single jvm.config file in a single jvm whatever you set in that file will apply to all instances. So if you have 5 JRun/CFMX instances they will each take the start amount of memory when they start up.

-XX:+DisableExplicitGC (this stops all explicitly called Full Garbage Collections) this does not stop all Full GC''s only those called explicitly by something.