espertechinc / esper

Esper Complex Event Processing, Streaming SQL and Event Series Analysis
GNU General Public License v2.0
842 stars 259 forks source link

Performance Issues with Esper v8 - Class Loader/Memory Leaking #275

Closed zainchowdhary closed 1 year ago

zainchowdhary commented 1 year ago

Hi,

We're in the process of upgrading Esper to version 8.9.0, having previously been using 5.4. With 8.9, we have been seeing a large increase in both CPU and memory usage and the number of classes that are being loaded over time.

The issues seems to stem from inside the Esper compile function, specifically with the Janino CompileClasses function in the CompilerAbstractionJanino class. Every single time a statement is compiled, we get debug logs which look like the following...

{"timestamp":"2023-06-08T02:00:49.280641371-0600","hostname":"#","level":"DEBUG","message":"About to call \"findIClass(Ljava/lang/Integer;)\"","thread_name":"qtp730575236-51","logger_name":"org.codehaus.janino.IClassLoader"}
{"timestamp":"2023-06-08T02:00:49.280690364-0600","hostname":"#,"level":"DEBUG","message":"clazz=class java.lang.Integer","thread_name":"qtp730575236-51","logger_name":"org.codehaus.janino.ClassLoaderIClassLoader"}
{"timestamp":"2023-06-08T02:00:49.280737034-0600","hostname":"#","level":"DEBUG","message":"Ljava/lang/Integer;: Defined type \"Ljava/lang/Integer;\"","thread_name":"qtp730575236-51","logger_name":"org.codehaus.janino.IClassLoader"}

These 3 log messages are repeated hundreds of times for different classes upon every single statement compilation. Previously when using v5.4, the number of classes loaded and memory used would remain low and fairly consistent. However with v8, the number of classes loaded and objects in memory continues to steadily increase over time eventually causing issues for our service.

Is this class loading behaviour normal? There seems to be an issue with garbage collection. We'd found a temporary work around by manually calling the java function System.gc() directly following the deployment of a statement. Doing this, the number of classes loaded/memory used by the service was reduced back to normal amounts. The question is why are these classes being excessively created in the first place and/or why are they not being automatically garbage collected?

Our compile/deployment process is shown below, and previous deployments are always being undeployed prior to this...

            EPCompiled compiled = compileEsperStatement(statementObject, statementName);
            EPDeployment deployed = deployEsperStatement(compiled);

    private EPCompiled compileEsperStatement(final EPStatementObjectModel statementObject, String statementName) throws EPCompileException
    {
        CompilerArguments args = new CompilerArguments(runtime.getConfigurationDeepCopy());
        args.getPath().add(runtime.getRuntimePath());
        StatementNameOption statementNameOption = env -> statementName;
        args.getOptions().setStatementName(statementNameOption);

        return EPCompilerProvider.getCompiler().compile(statementObject.toEPL(), args);
    }

    private EPDeployment deployEsperStatement(EPCompiled compiled) throws EPDeployException
    {
        DeploymentOptions options = new DeploymentOptions();
        return runtime.getDeploymentService().deploy(compiled, options);
    }
bernhardttom commented 1 year ago

There is always a lot of DEBUG level logging. Turn off when not useful.

A Java application should never call "gc()" and doesn't need to.

Prove an actual memory leak, providing code.