Skip to main content
Article

The Aggregate That Did Nothing: Anatomy of a WSO2 EI Memory Leak

8 min read 9 views

Production middleware nodes do not usually fail quietly. A WSO2 Enterprise Integrator 6.6 cluster we were asked to investigate had been restarting itself repeatedly across two nodes, each new JVM lasting only a few minutes before falling over again. The obvious diagnosis was an under-allocated heap. The actual root cause was something subtler: an <aggregate> mediator that had been silently accumulating XML in memory for months, across thousands of scheduled runs, without ever completing.

The first-pass diagnosis was correct but incomplete

The GC logs showed the classic death spiral of a G1 collector under sustained humongous-allocation pressure. With a small heap, G1's default region size is 1 MB, which means any object larger than 512 KB is treated as humongous. Humongous objects skip the young generation, land directly in old generation, cannot be moved or compacted by normal GC, and are only reclaimed by a full collection.

In the minutes before each OOM, the heap was pinned at the ceiling, full GCs were firing back to back within seconds of each other, and each one was reclaiming a negligible fraction of the heap. The JVM was working frantically and getting nothing back.

The textbook answer for this signature is to raise the heap and explicitly set a larger G1 region size:

-Xms8g -Xmx8g
-XX:+UseG1GC
-XX:G1HeapRegionSize=16m
-XX:+HeapDumpOnOutOfMemoryError
-XX:+ExitOnOutOfMemoryError

That change would have stopped the crash storm. It would also have delayed the discovery of the actual bug by weeks. The humongous-allocation symptom was real, but it was a consequence, not a cause.

What the heap dump actually contained

We opened the heap dump in Eclipse Memory Analyzer, ran the Leak Suspects report, and got a result we did not expect.

A single org.apache.synapse.config.SynapseConfiguration instance was holding the clear majority of the live heap. Walking down the dominator tree, the retention path was:

SynapseConfiguration
 └─ localRegistry (ConcurrentHashMap)
     └─ a TemplateMediator
         └─ ArrayList of child mediators
             └─ AggregateMediator
                 └─ activeAggregates (SynchronizedMap)
                     └─ HashMap$Node[]      ← almost all of it lived here

The activeAggregates field on a single AggregateMediator instance was retaining nearly the whole dominated set. The class histogram was overwhelmingly Axiom XML objects: OMElementImpl most numerous, then OMTextImpl, then OMAttributeImpl, in the proportions typical of structured XML records. In integration terms: a very large number of fully-modelled XML records held inside one aggregate, never released.

A second independent heap dump from the cluster's other node showed an identical fingerprint: same retention path, same class composition, same proportional dominance. The same bug was accumulating independently on both nodes simultaneously.

This also explained the original humongous-allocation observation. The HashMap bucket array was itself a humongous object, and as the map grew and rehashed, each new bucket array was also humongous. They piled up in old generation, fragmented it, and the death spiral followed. The GC behaviour was a symptom of the underlying accumulation, not an independent problem.

The aggregate that should not have existed

With the suspect identified, we went back to the source. The integration runs a scheduled task at a fixed interval. Each run dispatches a set of JMS messages (one per configured item) and an <aggregate> mediator collects the responses. The aggregate sequence looked like this:

<sequence name="...Aggregate.v1.0.sq">
    <aggregate id="iterate-items">
        <completeCondition timeout="60">
            <messageCount max="-1" min="-1"/>
        </completeCondition>
        <onComplete enclosingElementProperty="results" expression="json-eval($.)">
            <log category="INFO" level="custom">
                <property name="..." value=" --- all items processed --- "/>
            </log>
        </onComplete>
    </aggregate>
</sequence>

Two things were wrong, and the second one is the punchline.

<messageCount min="-1" max="-1"/> means there is no count condition at all. The aggregate fires only when its inactivity timer (60 seconds) elapses. Under sustained dispatch where responses arrive continuously, the aggregate never sees 60 seconds of silence. It keeps accepting messages from each run, and the next, and the next. The 60-second timer resets on every incoming message, so it never wins.

Worse, the assembled result was never read. The <onComplete> block bundled all accumulated child messages into a property and logged one line. To verify, we grepped the entire repository for any consumer of that property:

$ grep -rn "get-property.*results\|\$ctx:results" . --include="*.xml"
$

Nothing. No downstream mediator ever read it. The actual work (dispatching the JMS messages) had already happened before the aggregate was entered. The aggregate existed solely as a synchronisation barrier to log "completed". It was holding an ever-growing XML structure in memory, on every run, indefinitely, to print one line.

The log evidence made the scale undeniable

Once the code-level finding was clear, we went back to the archived logs to quantify it. A zgrep across every rotated log file on both nodes counted how many times the scheduled task had started:

zgrep -c "number of items found in config table" wso2carbon.log* \
  | awk -F: '{sum += $2} END {print "Total runs:", sum}'

Thousands of runs on each node. A corresponding grep for the aggregate's completion log line returned nothing at all: not one onComplete event had fired on either node across the entire log retention window. Every dispatched callback from every one of those runs was still holding XML payload in memory.

That is the whole explanation for the heap dumps. The only days the counts dropped to zero were JVM restart days, when the aggregate started empty again and the accumulation cycle began anew.

The fix

There are two correct responses to this. Both have their place.

For an emergency deploy, bound every aggregate so it cannot grow without limit:

<completeCondition timeout="60">
    <messageCount min="1" max="50"/>
</completeCondition>

Setting max to a value comfortably above the realistic message count for the flow means the aggregate force-fires when it hits the ceiling, regardless of response timing. The completion log line now fires per batch rather than per run, which is a minor cosmetic regression, but the JVM survives.

Once there is room to do it properly, the right answer is to delete the aggregates altogether. The dispatch work happens before the aggregate is entered; the aggregate adds nothing to the data flow. If the "completed" log line is genuinely useful for operational visibility, it moves to the outer sequence, where it costs nothing, with no aggregation barrier and no in-memory accumulation.

Either fix should be paired with the JVM settings from the first-pass diagnosis. Those settings are not a fix, but they produce a slower and more diagnosable failure mode: if a similar bug is introduced in future, the JVM will produce a clean heap dump rather than restart-storm itself across a business morning.

The broader pattern

A grep for the same max="-1" min="-1" pattern across the codebase returned dozens of files spread over multiple integrations. Every one of them is a potential crash candidate under the right load conditions. The aggregators visible in the heap dumps were simply the busiest at the time the snapshots were taken; any of the others will exhibit the same behaviour under sufficient load.

This is not an obscure edge case. It is a consequence of Synapse's defaults being unsafe for production use. min="-1" max="-1" is the path of least resistance when writing an iterate-then-aggregate sequence, because it requires no knowledge of how many messages will be dispatched. The cost of that convenience accumulates silently in old generation until one morning the GC logs start filling with Full GC events that reclaim nothing.

What we check on every incident now

Three habits came out of this investigation.

For any heap analysis on Synapse-based runtimes, check the dominator tree for SynapseConfiguration retention before anything else. If a single instance dominates the heap, the cause is almost always something being attached to the registry or to a long-lived mediator and never cleaned up.

For any <aggregate> in production code, audit the complete condition. If messageCount has no real upper bound, or there is no timeout, the aggregate is one traffic burst away from a leak. The defaults are unsafe.

For any aggregate whose <onComplete> block does not transform the assembled result and pass it onward, ask whether the aggregate is doing anything the calling sequence could not do directly. In several years of looking at integration code, we have yet to find one that survived this question.

Raising -Xmx would have made the symptoms go away. It would not have made the bug go away. That is the difference between a fix and a deferral, and it is worth a few hours with Eclipse Memory Analyzer to know which one you are buying.

Where this fits

The full diagnostic path (from "the JVM keeps crashing" to a named mediator in a named file, in fourteen steps you can repeat on your own incident) is written up as a companion white paper, Diagnosing JVM Memory Leaks in WSO2 Enterprise Integrator. The tooling side, running Eclipse MAT on a heap dump too large for a laptop, is covered in Heap Analysis Without Leaving the Browser.

Pinuno's integration practice supports WSO2 Enterprise Integrator, Micro Integrator and API Manager in production. If you are looking at a restart loop, a growing heap, or a middleware node nobody wants to touch, see what our consultancy engagements cover or tell us what you are seeing.

C

Chrystal Akyempon

Related Articles