ISSUE-292 Prevent SPI calls at runtime

[chibenwa]

Closes #292

[wbeckler]

What's the issue this addresses?

[wbeckler]

Ah I see it here: #292

[reta]

@chibenwa please sign with DCO (commit with--signoff)

[dblock]

Can we please add a unit test for this, too?

[chibenwa]

Can you describe which test you want?

I expect existing test suite to cover functionnal behaviour. And testing "preventing spi calls" might require additionnal levels of indirection which i would consider harmful.

Maybe a jmh bench?

[wbeckler]

I think it makes sense that this would go testless. On the other hand, it would be awesome if you could open an issue suggesting an ongoing approach to performance, to perhaps detect other low hanging fruit.

…

On Tue, Dec 20, 2022 at 9:01 AM Benoit TELLIER ***@***.***> wrote: Can you describe which test you want? I expect existing test suite to cover functionnal behaviour. And testing "preventing spi calls" might require additionnal levels of indirection which i would consider harmful. Maybe a jmh bench? — Reply to this email directly, view it on GitHub <#293 (comment)>, or unsubscribe <https://github.com/notifications/unsubscribe-auth/AA5PRLRL7BZBCP3UAB4W7SLWOG327ANCNFSM6AAAAAAS7MFNM4> . You are receiving this because you commented.Message ID: ***@***.***>

[chibenwa]

Next week i'll propose a JMH bench for this changeset.

Regarding "detection of low hanging fruits" I use asyncprofiler on my workloads (memory & cpu). Can't recall other massive painpoints but I will get a second look, and share flame graphs here too.

Happy new year,

Regards,

Benoit

[chibenwa]

opensearch_2.4.0.zip

Here is the flame graph I diagnosed this issue from. Taken with https://github.com/jvm-profiling-tools/async-profiler :

./profiler -d 120 -e itimer -f opensearch_2.4.0.html 1

(From within my applicative container)

Then searching opensearch (top left) gives you:

• The driver thread (on the right) with the httpclient event loop
• Applicatives calls to the driver from applicative threads (small stacktraces in the center)

Observations for the driver event loop:

• Call to the SPI are very easy to notice CF issue. Not only it eats CPU/heap allocations but also does it blocks the HTTP event loop, which is catastrophic (my app is not OpenSearch heavy so that is not a big issue to me).
• 0.5% of my application CPU (and 5% of the eventLoop CPU - similar footprint on heap allocation) is eaten by HTTP-client basic auth caching... :-( Likely a low hanging fruit, shall I create an issue for this one?
• Unsurprisingly JSON parsing takes ~11% of the drivers CPU and 24% of heap allocation.
• Event loop busyness (push stuff to the kernel network stack, SSL) takes around 60% of the event loop CPU, 25% of heap allocations, which again feels normal to me.
• 2.3% of the event loop CPU is our binding to Reactor reactive library, which, again is normal: converting futures and enqueuing tasks takes time.

[chibenwa]

JMH output backing this change

Before

Benchmark                Mode  Cnt   Score   Error  Units
JMHFieldBench.jsonBench  avgt    5  71.790 ± 2.125  us/op

After

Benchmark                Mode  Cnt  Score   Error  Units
JMHFieldBench.jsonBench  avgt    5  1.418 ± 0.024  us/op

Conclusion

x50 fastening of the JSOn parsing by getting rid of the SPI lookups, not event taking into account blocking operations... Huge win!

Code of the benchmark

package org.apache.james.backends.opensearch;

import java.io.IOException;
import java.util.concurrent.TimeUnit;

import org.apache.james.backends.opensearch.json.jackson.JacksonJsonpParser;
import org.junit.Test;
import org.openjdk.jmh.annotations.Benchmark;
import org.openjdk.jmh.annotations.Mode;
import org.openjdk.jmh.infra.Blackhole;
import org.openjdk.jmh.runner.Runner;
import org.openjdk.jmh.runner.options.Options;
import org.openjdk.jmh.runner.options.OptionsBuilder;
import org.openjdk.jmh.runner.options.TimeValue;

import com.fasterxml.jackson.core.JsonParser;
import com.fasterxml.jackson.databind.ObjectMapper;

public class JMHFieldBench {

    public static final ObjectMapper OBJECT_MAPPER = new ObjectMapper();

    @Test
    public void launchBenchmark() throws Exception {
        Options opt = new OptionsBuilder()
            .include(this.getClass().getName() + ".*")
            .mode (Mode.AverageTime)
            .timeUnit(TimeUnit.MICROSECONDS)
            .warmupTime(TimeValue.seconds(5))
            .warmupIterations(3)
            .measurementTime(TimeValue.seconds(2))
            .measurementIterations(5)
            .threads(1)
            .forks(1)
            .shouldFailOnError(true)
            .shouldDoGC(true)
            .build();

        new Runner(opt).run();
    }

    @Benchmark
    public void jsonBench(Blackhole bh) throws IOException {
        final JsonParser parser = OBJECT_MAPPER.createParser("[\"a\",\"b\"]");
        try {
            bh.consume(new JacksonJsonpParser(parser).getArrayStream());
        } catch (Exception e) {
            // do nothing
        } finally {
            parser.close();
        }
    }
}

The bench was applied before/after the backport of this PR on top of Apache James CF apache/james-project@d5af3a5

(Note this backport is uggly and I would like to drop it as fast as possible!)

[reta]

It is known that ObjectMapper is expensive to create, making it static certainly helps

[chibenwa]

It is known that ObjectMapper is expensive to create, making it static certainly helps

I do not see how this affects this benchmark

[reta]

It is known that ObjectMapper is expensive to create, making it static certainly helps

I do not see how this affects this benchmark

Apologies, your benchmark checks the impact of changing the JsonProvider.provider() initialization (instance -> static), for some reason I thought that JsonProvider.provider() was instantiating ObjectMapper instances (which is not correct).

[wbeckler]

Would you be up for adding a change to the changelog?

[opensearch-trigger-bot]

The backport to 2.x failed:

The process '/usr/bin/git' failed with exit code 1

To backport manually, run these commands in your terminal:

# Fetch latest updates from GitHub
git fetch
# Create a new working tree
git worktree add .worktrees/backport-2.x 2.x
# Navigate to the new working tree
cd .worktrees/backport-2.x
# Create a new branch
git switch --create backport/backport-293-to-2.x
# Cherry-pick the merged commit of this pull request and resolve the conflicts
git cherry-pick -x --mainline 1 a8df7e7c26ccc644811539c4fea57d97f1031aaa
# Push it to GitHub
git push --set-upstream origin backport/backport-293-to-2.x
# Go back to the original working tree
cd ../..
# Delete the working tree
git worktree remove .worktrees/backport-2.x

Then, create a pull request where the base branch is 2.x and the compare/head branch is backport/backport-293-to-2.x.