Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Subpar Caffeine cache performance (vs Akka HTTP, Play2, ASP.NET Core) #28795

Closed
demming opened this issue Oct 24, 2022 · 34 comments
Closed

Subpar Caffeine cache performance (vs Akka HTTP, Play2, ASP.NET Core) #28795

demming opened this issue Oct 24, 2022 · 34 comments
Labels
area/cache kind/bug Something isn't working

Comments

@demming
Copy link

demming commented Oct 24, 2022

Describe the bug

I've been looking into cache stampede issues across a few microservices that I'm running. I've observed quite meager Caffeine performance on cached endpoints running on Quarkus, and Spring WebFlux alike. As a baseline I'm taking my Akka HTTP cached implementation of the same simple microservice that sanitizes upstream HTML data. My Akka HTTP implementation is based on Scala's sttp/tapir, otherwise pretty bare akka-http underneath. Play2 Framework is close to it but still slower at cached performance and appears to suffer from cache stampede. While Quarkus is sophisticated enough to mitigate by thread locking cache access, the performance I've observed is just a fraction of what's feasible---about one tenth, i.e., an order of magnitude slower, see below.

For load and soak testing among other tools I've used bombardier, for a simple use case as follows

bombardier -c 100 -d 10s -k -l "http://localhost:8090/website?address=http://localhost:8081"

which initiates 100 concurrent connections, runs them for 10s (or any other duration), and implicitly reuses open connections. The upstream endpoint can be anything you like to ingest HTML data from.

Together with Spring WebFlux, my Quarkus microservices are slowest at cached throughput among the services I've been running.

In addition, no Cache-Control HTTP headers are being set (only) by Quarkus. I believe they should be available for being set implicitly from the annotation rather than at compile time from the config---like all other frameworks do.

The figures below are relative to the execution environment. But the relations among the individual framework figures are pretty much constant, that is, Quarkus and Spring WebFlux are 10 times slower at response caching than Akka HTTP, which is twice more efficient than the recent ASP.NET Core and about 50% faster than Play2.

Expected behavior

Since Akka HTTP too uses Caffeine under the hood, I'd expect it to have similar performance at response caching.

Akka HTTP underneath sttp/tapir over 10s:

Statistics        Avg      Stdev        Max
  Reqs/sec      7404.86    1809.11   11954.27
  Latency       13.50ms    18.85ms      0.94s
  Latency Distribution
     50%    11.65ms
     75%    15.83ms
     90%    21.03ms
     95%    25.30ms
     99%    40.44ms
  HTTP codes:
    1xx - 0, 2xx - 74116, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:     4.97GB/s

With proper Cache-Control headers set.

Actual behavior

Quarkus native on GraalVM or JVM alike, production build. Same machine, same workload, randomized tests, 20 runs each in total.
This is the best as it gets over 10s (dev mode about 0.5 GB/s best), with about 0.6 GB/s on average under the given environment.

Statistics        Avg      Stdev        Max
  Reqs/sec      1349.09     531.60    2969.21
  Latency       73.95ms    80.61ms   626.72ms
  Latency Distribution
     50%    27.84ms
     75%   117.27ms
     90%   194.88ms
     95%   237.21ms
     99%   351.59ms
  HTTP codes:
    1xx - 0, 2xx - 13553, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:     0.91GB/s

Without any Cache-Control HTTP headers.

I'm looking into a way to improve it. Not sure how, though. On a side note, I'd like to have a way to choose or plug in other means of mitigation.

How to Reproduce?

Here's a very simple resource, which instead of invoking a remote HTTP call could instead block the fiber for a while. The caching of the result of that endpoint is subject matter here.

@Path("/website")
public
class WebsiteResource {

  @GET
  @Produces(MediaType.TEXT_HTML)
  @CacheResult(cacheName = "get-sanitized-html") //, lockTimeout = 500L)
  public
  String getSanitizedHtml (@QueryParam("address") @CacheKey final String address) throws IOException {
    return new WebsiteSanitizerService().sanitizeUrl(new URL(address));
  }
}

With the following cache config in application.yaml:

quarkus:
  cache:
    caffeine:
      "get-sanitized-html":
        initial-capacity: 100
        maximum-size: 100
        expire-after-write: 90S

Output of uname -a or ver

macOS 16.2, arm64

Output of java -version

OpenJDK 19.0.1

GraalVM version (if different from Java)

graalvm-ce-java17-22.2.0

Quarkus version or git rev

2.13.1.Final

Build tool (ie. output of mvnw --version or gradlew --version)

Gradle 7.5.1

Additional information

The issues of mine that I linked in the first paragraph contain additional links and data points. I hope it's just me missing some obvious configuration in Quarkus that has led to this subpar performance at response caching.

@demming demming added the kind/bug Something isn't working label Oct 24, 2022
@quarkus-bot
Copy link

quarkus-bot bot commented Oct 24, 2022

/cc @gwenneg

@ben-manes
Copy link

I’m not familiar enough, but the first thing I do to investigate the performance of a long running process is to profile. That typically offers enough insight to have a discussion and proof of concept fix, though a proper fix might be different based on the owner’s knowledge of their project.

jcmd JFR.start duration=?m filename=?.jfr settings=profile.jfc

Then open in JMC/JProfiler/Yourkit for the hotspot methods. This requires the jvm, not graal native.

@geoand geoand changed the title [Performance] Subpar Caffeine cache performance (vs Akka HTTP, Play2, ASP.NET Core) Subpar Caffeine cache performance (vs Akka HTTP, Play2, ASP.NET Core) Oct 25, 2022
@geoand
Copy link
Contributor

geoand commented Oct 25, 2022

As @graemerocher mentioned in his comment on the Micronaut issue, you seem to be using the general annotation based method result cache mechanism and expecting to get HTTP cache headers set as well - this is not how things work.

quarkus-cache is independent of the transport protocol and is only used for controlling method caching behavior. If you need HTTP caching header support, I propose looking into the corresponding feature of RESTEasy Reactive (which you should be using anyway instead of RESTEasy Classic).

Furthermore, as @ben-manes says, profiling the application is essential for us to be able to pinpoint any issues and find ways to address them. If you provide us with a sample application that exhibits the behavior you mention, we can certainly do the profiling.

@geoand geoand added the triage/needs-reproducer We are waiting for a reproducer. label Oct 25, 2022
@geoand
Copy link
Contributor

geoand commented Oct 25, 2022

Another thing I should add, is that your throughput / latency comparison is likely not apples to apples, because for the Quarkus use case the request is being offloaded and handled by a worker thread.

If you want an apples to apples comparison of Quarkus with other stacks, you should be using RESTEasy Reactive and either annotated the class / method with @NonBlocking, or return Uni<String> from the getSanitizedHtml method (see this for a detailed explanation)

@demming
Copy link
Author

demming commented Oct 25, 2022

@geoand:

you seem to be using the general annotation based method result cache mechanism and expecting to get HTTP cache headers set as well - this is not how things work.

quarkus-cache is independent of the transport protocol and is only used for controlling method caching behavior

I wasn't aware of that, appreciate. Didn't see it in the docs.

RESTEasy Reactive (which you should be using anyway instead of RESTEasy Classic)

I am.

If you provide us with a sample application that exhibits the behavior you mention, we can certainly do the profiling.

Of course, I'll push the repo to GitHub. Would appreciate learning how you do the profiling too and what exactly to look at primarily.

either annotated the class / method with @NonBlocking, or return Uni from the getSanitizedHtml method

Oh, right, I missed the Mutiny wrapper with Quarkus. Thanks for pointing it out. But the Monos have been there with Spring WebFlux and Micronaut implementations. I've added @NonBlocking, and it resulted in an error: can't block the thread.

Now I've made it more explicit with the four evaluation models as described in the article that you're referring to. The blocking variant proves best in performance here; and it properly locks the cache thread. Adding @NonBlocking as you suggested raises an exception. In contrast, both Uni and CompletionStage induce cache stampede, cache lock doesn't work. In brief:

  1. blocking String: cache thread locked, best performance; twice higher CPU utilization and (sometimes) up to twice greater throughput, with latencies twice lower particularly at the median, so it really serves requests quicker.
  2. blocking String with @NonBlocking controller: exception, see below.
  3. CompletionStage<String>: cache stampede, works after a preliminary cache population
  4. Uni<String>: cache stampede, same as 3.
Cache stampede on fibers for 10 concurrent connections (crashes with 100)
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #2
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #3
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #4
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #5
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #6
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #7
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #8
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #9
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #10
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #11
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #12
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #13
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #14
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #15
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #16
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #17
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #18
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #19
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #20
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #21
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #22
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #23
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #24
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #25
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #26
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #27
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #28
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #29
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlAsync #30
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlAsync #31
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlUni #2
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlUni #2
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlUni #3
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlUni #4
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlUni #5
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlUni #6
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlUni #7
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlUni #8
(vert.x-eventloop-thread-1) >> Service.sanitizeUrlUni #10
(vert.x-eventloop-thread-0) >> Service.sanitizeUrlUni #9
(executor-thread-9) >> Service.sanitizeUrlBlocking #1
@NonBlocking exception
ERROR [org.jbo.res.rea.com.cor.AbstractResteasyReactiveContext] (vert.x-eventloop-thread-1) Request failed: java.lang.IllegalStateException: The current thread cannot be blocked: vert.x-eventloop-thread-1
	at io.smallrye.mutiny.operators.uni.UniBlockingAwait.await(UniBlockingAwait.java:30)
	at io.smallrye.mutiny.groups.UniAwait.atMost(UniAwait.java:65)
	at io.smallrye.mutiny.groups.UniAwait.indefinitely(UniAwait.java:46)
	at io.quarkus.cache.runtime.CacheResultInterceptor.intercept(CacheResultInterceptor.java:119)
	at io.quarkus.cache.runtime.CacheResultInterceptor_Bean.intercept(Unknown Source)
	at io.quarkus.arc.impl.InterceptorInvocation.invoke(InterceptorInvocation.java:42)
	at io.quarkus.arc.impl.AroundInvokeInvocationContext.perform(AroundInvokeInvocationContext.java:41)
	at io.quarkus.arc.impl.InvocationContexts.performAroundInvoke(InvocationContexts.java:33)
	at com.github.demming.experiments.WebsiteResource_Subclass.getSanitizedHtmlNonBlocking(Unknown Source)
	at com.github.demming.experiments.WebsiteResource$quarkusrestinvoker$getSanitizedHtmlNonBlocking_821f8a2cb8414b1c2167a079b2a8054ac4938f24.invoke(Unknown Source)
	at org.jboss.resteasy.reactive.server.handlers.InvocationHandler.handle(InvocationHandler.java:29)
	at io.quarkus.resteasy.reactive.server.runtime.QuarkusResteasyReactiveRequestContext.invokeHandler(QuarkusResteasyReactiveRequestContext.java:115)
	at org.jboss.resteasy.reactive.common.core.AbstractResteasyReactiveContext.run(AbstractResteasyReactiveContext.java:142)
	at org.jboss.resteasy.reactive.server.handlers.RestInitialHandler.beginProcessing(RestInitialHandler.java:51)
	at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:18)
	at org.jboss.resteasy.reactive.server.vertx.ResteasyReactiveVertxHandler.handle(ResteasyReactiveVertxHandler.java:8)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:173)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
	at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:84)
	at io.quarkus.vertx.http.runtime.StaticResourcesRecorder$2.handle(StaticResourcesRecorder.java:71)
	at io.vertx.ext.web.impl.RouteState.handleContext(RouteState.java:1284)
	at io.vertx.ext.web.impl.RoutingContextImplBase.iterateNext(RoutingContextImplBase.java:136)
	at io.vertx.ext.web.impl.RoutingContextImpl.next(RoutingContextImpl.java:140)
	at io.vertx.ext.web.handler.impl.StaticHandlerImpl.lambda$sendStatic$1(StaticHandlerImpl.java:290)
	at io.vertx.core.impl.future.FutureImpl$3.onSuccess(FutureImpl.java:141)
	at io.vertx.core.impl.future.FutureBase.lambda$emitSuccess$0(FutureBase.java:54)
	at io.netty.util.concurrent.AbstractEventExecutor.runTask(AbstractEventExecutor.java:174)
	at io.netty.util.concurrent.AbstractEventExecutor.safeExecute(AbstractEventExecutor.java:167)
	at io.netty.util.concurrent.SingleThreadEventExecutor.runAllTasks(SingleThreadEventExecutor.java:470)
	at io.netty.channel.nio.NioEventLoop.run(NioEventLoop.java:569)
	at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:997)
	at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74)
	at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30)
	at java.base/java.lang.Thread.run(Thread.java:833)

Performance over 10 seconds

The figures certainly depend on the environment. But the ratios don't necessarily.

/websites/blocking
Statistics        Avg      Stdev        Max
  Reqs/sec      1503.76    1025.12    4851.56
  Latency       67.65ms   101.81ms      1.68s
  Latency Distribution
     50%    47.00ms
     75%    74.63ms
     90%   117.76ms
     95%   172.54ms
     99%   633.65ms
  HTTP codes:
    1xx - 0, 2xx - 15089, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:     0.99GB/s
/websites/async after preliminary manual cache population
Statistics        Avg      Stdev        Max
  Reqs/sec      1199.14     259.51    3067.54
  Latency       83.01ms    29.00ms   187.19ms
  Latency Distribution
     50%    89.44ms
     75%   108.35ms
     90%   120.04ms
     95%   128.35ms
     99%   138.08ms
  HTTP codes:
    1xx - 0, 2xx - 12094, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   825.10MB/s
/websites/uni after preliminary manual cache population
Statistics        Avg      Stdev        Max
  Reqs/sec      1223.60     261.00    3751.53
  Latency       81.38ms    29.57ms   180.93ms
  Latency Distribution
     50%    86.58ms
     75%   103.77ms
     90%   121.19ms
     95%   130.42ms
     99%   143.18ms
  HTTP codes:
    1xx - 0, 2xx - 12337, 3xx - 0, 4xx - 0, 5xx - 0
    others - 0
  Throughput:   841.45MB/s

@demming
Copy link
Author

demming commented Oct 25, 2022

@ben-manes:

I’m not familiar enough, but the first thing I do to investigate the performance of a long running process is to profile. That typically offers enough insight to have a discussion and proof of concept fix, though a proper fix might be different based on the owner’s knowledge of their project.

jcmd JFR.start duration=?m filename=?.jfr settings=profile.jfc

Then open in JMC/JProfiler/Yourkit for the hotspot methods. This requires the jvm, not graal native.

Thanks, I'll try to look into it. But first someone should really try to replicate it so we can make sure it's not a config issue or the runtime environment being peculiarly unfavorable to it. I'll push my repo and link it here.

@geoand
Copy link
Contributor

geoand commented Oct 25, 2022

@demming interesting. It would be wonderful if you are able to put together a sample we can try.

@demming
Copy link
Author

demming commented Oct 26, 2022

@geoand Hey, just pushed it, https://github.com/demming/cache-stampede-quarkus

@geoand
Copy link
Contributor

geoand commented Oct 26, 2022

Great, thanks

@geoand geoand removed the triage/needs-reproducer We are waiting for a reproducer. label Oct 27, 2022
@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

I started looking at the issue, but I just want to clarify that case no. 2, where you are using @NonBlocking but then using the blocking version of the REST Client in the method body is not expected to work.

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

I took a quick look at this and I believe there is some performance being left on the table in Mutiny.
For example I see this following:

Screenshot from 2022-10-27 10-54-13

Notice the very long UniResponseHandler.handle entry that does not seem to do much.
Diving down deeper, there is also:

Screenshot from 2022-10-27 10-55-21

Notice the Uni related entries taking up a large part of the flamegraph.

@franz1981 I believe that when you have some time, this will be of a lot of interest to you 😉

@franz1981
Copy link
Contributor

franz1981 commented Oct 27, 2022

@geoand it's interesting indeed, although a separate issue, can you try using https://github.com/RedHatPerf/type-pollution-agent to check if it can point to some of the Uni-related methods?
(The reason is that looking at those methods doesn't look they could be that costy, meaning that maybe the real cost is not on the Java code)

And, in addition, I would run an allocation profiling session because of

arraylist default capacity can be just too much for the actual number of elements needed there?

NOTE: in the same arc-related code I see 2 nice instanceof:

if (binding instanceof CacheKeyParameterPositions) {
for (short position : ((CacheKeyParameterPositions) binding).value()) {
cacheKeyParameterPositions.add(position);
}
} else if (interceptorBindingClass.isInstance(binding)) {

That could be a usual (and sad) case of https://bugs.openjdk.org/browse/JDK-8295496

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

@geoand it's interesting indeed, although a separate issue, can you try using https://github.com/RedHatPerf/type-pollution-agent to check if it can point to some of the Uni-related methods?

I already did, nothing came up :). But I'll investigate futher.

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

Scratch the comment above... I ran the agent for something else I was looking at... Not for this use case. I'll do that now.

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

Here are the results:

--------------------------
Type Pollution Statistics:
--------------------------
1:      io.vertx.core.impl.DuplicatedContext
Count:  75103820
Types:
        io.vertx.core.Context
        io.vertx.core.impl.ContextInternal
Traces:
        io.smallrye.common.vertx.VertxContext.isDuplicatedContext(VertxContext.java:114)
                class: io.vertx.core.Context
                count: 40291369
        io.smallrye.common.vertx.VertxContext.isDuplicatedContext(VertxContext.java:115)
                class: io.vertx.core.impl.ContextInternal
                count: 33327244
        io.vertx.core.streams.impl.InboundBuffer.<init>(InboundBuffer.java:95)
                class: io.vertx.core.impl.ContextInternal
                count: 744052
        io.vertx.core.http.impl.Http1xServerConnection.handleMessage(Http1xServerConnection.java:135)
                class: io.vertx.core.impl.ContextInternal
                count: 741155
--------------------------
2:      io.vertx.core.http.impl.AssembledFullHttpResponse
Count:  7139108
Types:
        io.netty.handler.codec.http.HttpResponse
        io.netty.handler.codec.http.FullHttpMessage
        io.netty.handler.codec.http.HttpContent
        io.netty.handler.codec.http.HttpMessage
Traces:
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:196)
                class: io.netty.handler.codec.http.HttpContent
                count: 1350862
        io.netty.handler.codec.http.HttpObjectEncoder.encodeFullHttpMessage(HttpObjectEncoder.java:308)
                class: io.netty.handler.codec.http.HttpMessage
                count: 1327199
        io.netty.handler.codec.http.HttpObjectEncoder.acceptOutboundMessage(HttpObjectEncoder.java:571)
                class: io.netty.handler.codec.http.FullHttpMessage
                count: 1228368
        io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.write(WebSocketServerExtensionHandler.java:104)
                class: io.netty.handler.codec.http.HttpResponse
                count: 927956
        io.netty.handler.codec.http.HttpResponseEncoder.encodeInitialLine(HttpResponseEncoder.java:27)
                class: io.netty.handler.codec.http.HttpResponse
                count: 873909
        io.vertx.core.http.impl.VertxHttpResponseEncoder.isContentAlwaysEmpty(VertxHttpResponseEncoder.java:27)
                class: io.netty.handler.codec.http.HttpResponse
                count: 351481
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:197)
                class: io.netty.handler.codec.http.HttpContent
                count: 277289
        io.netty.handler.codec.http.HttpObjectEncoder.encode(HttpObjectEncoder.java:161)
                class: io.netty.handler.codec.http.FullHttpMessage
                count: 272373
        io.netty.handler.codec.http.HttpResponseEncoder.sanitizeHeadersBeforeEncode(HttpResponseEncoder.java:27)
                class: io.netty.handler.codec.http.HttpResponse
                count: 209778
        io.netty.handler.codec.http.HttpObjectEncoder.encodeFullHttpMessage(HttpObjectEncoder.java:302)
                class: io.netty.handler.codec.http.FullHttpMessage
                count: 198415
        io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler.write(WebSocketServerExtensionHandler.java:105)
                class: io.netty.handler.codec.http.HttpResponse
                count: 121478
--------------------------
3:      io.netty.channel.DefaultChannelPipeline$HeadContext
Count:  3749858
Types:
        io.netty.channel.ChannelOutboundHandler
        io.netty.channel.ChannelInboundHandler
Traces:
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 1009887
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
                class: io.netty.channel.ChannelInboundHandler
                count: 838267
        io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
                class: io.netty.channel.ChannelOutboundHandler
                count: 778200
        io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
                class: io.netty.channel.ChannelOutboundHandler
                count: 705349
        io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686)
                class: io.netty.channel.ChannelOutboundHandler
                count: 417991
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRegistered(AbstractChannelHandlerContext.java:166)
                class: io.netty.channel.ChannelInboundHandler
                count: 41
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230)
                class: io.netty.channel.ChannelInboundHandler
                count: 33
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 25
        io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
                class: io.netty.channel.ChannelOutboundHandler
                count: 20
        io.netty.channel.AbstractChannelHandlerContext.invokeClose(AbstractChannelHandlerContext.java:622)
                class: io.netty.channel.ChannelOutboundHandler
                count: 11
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 11
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelUnregistered(AbstractChannelHandlerContext.java:198)
                class: io.netty.channel.ChannelInboundHandler
                count: 9
        io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:346)
                class: io.netty.channel.ChannelInboundHandler
                count: 7
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
                class: io.netty.channel.ChannelInboundHandler
                count: 6
        io.netty.channel.AbstractChannelHandlerContext.invokeBind(AbstractChannelHandlerContext.java:506)
                class: io.netty.channel.ChannelOutboundHandler
                count: 1
--------------------------
4:      java.util.ImmutableCollections$SetN
Count:  2773433
Types:
        java.util.Set
        java.util.Collection
Traces:
        io.smallrye.context.impl.cdi.SmallRyeCurrentThreadContextInterceptor.manageCurrentContext(SmallRyeCurrentThreadContextInterceptor.java:27)
                class: java.util.Collection
                count: 1301616
        io.quarkus.arc.runtime.InterceptorBindings.getInterceptorBindings(InterceptorBindings.java:14)
                class: java.util.Set
                count: 1193618
        io.quarkus.arc.impl.ContextDataMap.<init>(ContextDataMap.java:39)
                class: java.util.Set
                count: 213283
        io.smallrye.context.impl.cdi.SmallRyeCurrentThreadContextInterceptor.manageCurrentContext(SmallRyeCurrentThreadContextInterceptor.java:28)
                class: java.util.Collection
                count: 64916
--------------------------
5:      io.quarkus.cache.runtime.CacheKeyParameterPositions_Shared_AnnotationLiteral
Count:  2664768
Types:
        io.quarkus.cache.runtime.CacheKeyParameterPositions
        java.lang.annotation.Annotation
Traces:
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:73)
                class: io.quarkus.cache.runtime.CacheKeyParameterPositions
                count: 1372389
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:72)
                class: java.lang.annotation.Annotation
                count: 1272549
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:74)
                class: io.quarkus.cache.runtime.CacheKeyParameterPositions
                count: 19829
        javax.enterprise.util.AnnotationLiteral.equals(AnnotationLiteral.java:194)
                class: java.lang.annotation.Annotation
                count: 1
--------------------------
6:      io.quarkus.cache.CacheResult_Shared_AnnotationLiteral
Count:  2617094
Types:
        io.quarkus.cache.CacheResult
        java.lang.annotation.Annotation
Traces:
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:77)
                class: io.quarkus.cache.CacheResult
                count: 1317989
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:72)
                class: java.lang.annotation.Annotation
                count: 1257344
        io.quarkus.cache.runtime.CacheResultInterceptor.intercept(CacheResultInterceptor.java:47)
                class: io.quarkus.cache.CacheResult
                count: 41760
        javax.enterprise.util.AnnotationLiteral.equals(AnnotationLiteral.java:194)
                class: java.lang.annotation.Annotation
                count: 1
--------------------------
7:      io.quarkus.vertx.http.runtime.ResumingRequestWrapper
Count:  2609876
Types:
        io.vertx.core.http.impl.HttpServerRequestInternal
        io.vertx.core.http.HttpServerRequest
Traces:
        io.vertx.ext.web.impl.HttpServerRequestWrapper.<init>(HttpServerRequestWrapper.java:43)
                class: io.vertx.core.http.impl.HttpServerRequestInternal
                count: 1318768
        io.vertx.ext.web.impl.RouterImpl.handle(RouterImpl.java:37)
                class: io.vertx.core.http.HttpServerRequest
                count: 1291108
--------------------------
8:      io.smallrye.context.api.CurrentThreadContext_Shared_AnnotationLiteral
Count:  2354134
Types:
        java.lang.annotation.Annotation
        io.smallrye.context.api.CurrentThreadContext
Traces:
        io.quarkus.cache.runtime.CacheInterceptor.getArcCacheInterceptionContext(CacheInterceptor.java:72)
                class: java.lang.annotation.Annotation
                count: 1211548
        io.smallrye.context.impl.cdi.SmallRyeCurrentThreadContextInterceptor.manageCurrentContext(SmallRyeCurrentThreadContextInterceptor.java:29)
                class: io.smallrye.context.api.CurrentThreadContext
                count: 1125943
        io.smallrye.context.impl.cdi.SmallRyeCurrentThreadContextInterceptor.manageCurrentContext(SmallRyeCurrentThreadContextInterceptor.java:30)
                class: io.smallrye.context.api.CurrentThreadContext
                count: 16642
        javax.enterprise.util.AnnotationLiteral.equals(AnnotationLiteral.java:194)
                class: java.lang.annotation.Annotation
                count: 1
--------------------------
9:      io.vertx.core.http.impl.Http1xServerRequest
Count:  2227454
Types:
        io.vertx.core.http.impl.HttpServerRequestInternal
        io.vertx.core.http.HttpServerRequest
Traces:
        io.quarkus.vertx.http.runtime.AbstractRequestWrapper.<init>(AbstractRequestWrapper.java:37)
                class: io.vertx.core.http.impl.HttpServerRequestInternal
                count: 1144837
        io.vertx.core.http.impl.Http1xServerRequestHandler.handle(Http1xServerRequestHandler.java:30)
                class: io.vertx.core.http.HttpServerRequest
                count: 718264
        io.quarkus.vertx.http.runtime.VertxHttpRecorder$15.handle(VertxHttpRecorder.java:589)
                class: io.vertx.core.http.HttpServerRequest
                count: 333615
        io.quarkus.vertx.http.runtime.VertxHttpRecorder$1.handle(VertxHttpRecorder.java:160)
                class: io.vertx.core.http.HttpServerRequest
                count: 30738
--------------------------
10:     io.netty.handler.timeout.IdleStateHandler
Count:  1907913
Types:
        io.netty.channel.ChannelInboundHandler
        io.netty.channel.ChannelOutboundHandler
Traces:
        io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
                class: io.netty.channel.ChannelOutboundHandler
                count: 942972
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 739568
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
                class: io.netty.channel.ChannelInboundHandler
                count: 225326
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 24
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 11
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRegistered(AbstractChannelHandlerContext.java:166)
                class: io.netty.channel.ChannelInboundHandler
                count: 10
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230)
                class: io.netty.channel.ChannelInboundHandler
                count: 2
--------------------------
11:     io.netty.handler.codec.http.websocketx.extensions.WebSocketServerExtensionHandler
Count:  1770222
Types:
        io.netty.channel.ChannelInboundHandler
        io.netty.channel.ChannelOutboundHandler
Traces:
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 888193
        io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
                class: io.netty.channel.ChannelOutboundHandler
                count: 881962
        io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
                class: io.netty.channel.ChannelOutboundHandler
                count: 32
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 28
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 7
--------------------------
12:     java.util.ArrayList
Count:  1519784
Types:
        java.lang.Iterable
        java.util.List
        java.util.Collection
Traces:
        io.vertx.ext.web.impl.RoutingContextImpl.getQueryParams(RoutingContextImpl.java:462)
                class: java.lang.Iterable
                count: 761561
        org.jboss.resteasy.reactive.server.mapping.RequestMapper.map(RequestMapper.java:62)
                class: java.util.List
                count: 757704
        io.vertx.core.http.impl.SharedClientHttpStreamEndpoint.lambda$checkExpired$4(SharedClientHttpStreamEndpoint.java:117)
                class: java.util.List
                count: 216
        org.jboss.resteasy.reactive.common.util.MultivaluedTreeMap.putAll(MultivaluedTreeMap.java:185)
                class: java.util.List
                count: 75
        org.jboss.resteasy.reactive.common.jaxrs.AbstractResponseBuilder.setAllHeaders(AbstractResponseBuilder.java:135)
                class: java.util.List
                count: 62
        org.jboss.resteasy.reactive.client.handlers.ClientSendRequestHandler.setVertxHeaders(ClientSendRequestHandler.java:522)
                class: java.lang.Iterable
                count: 50
        org.jboss.resteasy.reactive.client.impl.ClientRequestHeaders.asMap(ClientRequestHeaders.java:158)
                class: java.util.List
                count: 47
        org.jboss.resteasy.reactive.common.util.MultivaluedTreeMap.get(MultivaluedTreeMap.java:159)
                class: java.util.List
                count: 43
        io.smallrye.config.Converters$CollectionConverter.convert(Converters.java:729)
                class: java.util.Collection
                count: 7
        io.smallrye.config.ProfileConfigSourceInterceptor.convertProfile(ProfileConfigSourceInterceptor.java:107)
                class: java.util.List
                count: 6
        io.vertx.core.http.impl.HttpClientImpl.<init>(HttpClientImpl.java:157)
                class: java.util.List
                count: 4
        org.jboss.resteasy.reactive.common.jaxrs.ConfigurationImpl.getResponseFilters(ConfigurationImpl.java:452)
                class: java.util.List
                count: 3
        org.jboss.resteasy.reactive.common.jaxrs.ConfigurationImpl.getRequestFilters(ConfigurationImpl.java:441)
                class: java.util.List
                count: 2
        io.quarkus.rest.client.reactive.runtime.MicroProfileRestClientRequestFilter.filter(MicroProfileRestClientRequestFilter.java:87)
                class: java.util.List
                count: 2
        org.jboss.resteasy.reactive.server.core.startup.RuntimeMappingDeployment.buildMethodMapper(RuntimeMappingDeployment.java:107)
                class: java.util.List
                count: 1
        io.quarkus.rest.client.reactive.runtime.MicroProfileRestClientRequestFilter.filter(MicroProfileRestClientRequestFilter.java:41)
                class: java.util.List
                count: 1
--------------------------
13:     io.netty.util.concurrent.ScheduledFutureTask
Count:  1850
Types:
        io.netty.util.internal.PriorityQueueNode
        java.lang.Runnable
Traces:
        io.netty.util.internal.DefaultPriorityQueue.offer(DefaultPriorityQueue.java:31)
                class: io.netty.util.internal.PriorityQueueNode
                count: 929
        io.netty.util.concurrent.SingleThreadEventExecutor.pollTaskFrom(SingleThreadEventExecutor.java:216)
                class: java.lang.Runnable
                count: 897
        io.netty.util.concurrent.SingleThreadEventExecutor.lazyExecute0(SingleThreadEventExecutor.java:831)
                class: java.lang.Runnable
                count: 16
        io.netty.util.internal.DefaultPriorityQueue.removeTyped(DefaultPriorityQueue.java:31)
                class: io.netty.util.internal.PriorityQueueNode
                count: 8
--------------------------
14:     io.netty.handler.codec.http.DefaultHttpContent
Count:  1391
Types:
        io.netty.handler.codec.http.HttpContent
        io.netty.handler.codec.http.HttpObject
Traces:
        io.vertx.core.http.impl.Http1xClientConnection.validateMessage(Http1xClientConnection.java:694)
                class: io.netty.handler.codec.http.HttpObject
                count: 680
        io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:745)
                class: io.netty.handler.codec.http.HttpContent
                count: 676
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:196)
                class: io.netty.handler.codec.http.HttpContent
                count: 10
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:197)
                class: io.netty.handler.codec.http.HttpContent
                count: 8
        io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:714)
                class: io.netty.handler.codec.http.HttpObject
                count: 7
        io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:715)
                class: io.netty.handler.codec.http.HttpObject
                count: 4
        io.vertx.core.http.impl.Http1xClientConnection.validateMessage(Http1xClientConnection.java:695)
                class: io.netty.handler.codec.http.HttpObject
                count: 4
        io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:746)
                class: io.netty.handler.codec.http.HttpContent
                count: 2
--------------------------
15:     io.quarkus.arc.impl.ParameterizedTypeImpl
Count:  1116
Types:
        java.lang.reflect.ParameterizedType
        java.lang.reflect.Type
Traces:
        io.quarkus.arc.impl.BeanTypeAssignabilityRules.matches(BeanTypeAssignabilityRules.java:29)
                class: java.lang.reflect.Type
                count: 558
        io.quarkus.arc.impl.BeanTypeAssignabilityRules.matchesNoBoxing(BeanTypeAssignabilityRules.java:46)
                class: java.lang.reflect.ParameterizedType
                count: 558
--------------------------
16:     io.netty.handler.ssl.SslHandler
Count:  1042
Types:
        io.netty.channel.ChannelOutboundHandler
        io.netty.channel.ChannelInboundHandler
        io.netty.channel.ChannelHandler
Traces:
        io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686)
                class: io.netty.channel.ChannelOutboundHandler
                count: 439
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 272
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
                class: io.netty.channel.ChannelInboundHandler
                count: 181
        io.vertx.core.http.impl.HttpChannelConnector.wrap(HttpChannelConnector.java:100)
                class: io.netty.channel.ChannelHandler
                count: 40
        io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
                class: io.netty.channel.ChannelOutboundHandler
                count: 30
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 24
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 23
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelActive(AbstractChannelHandlerContext.java:230)
                class: io.netty.channel.ChannelInboundHandler
                count: 20
        io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
                class: io.netty.channel.ChannelOutboundHandler
                count: 7
        io.netty.channel.AbstractChannelHandlerContext.invokeConnect(AbstractChannelHandlerContext.java:548)
                class: io.netty.channel.ChannelOutboundHandler
                count: 5
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelInactive(AbstractChannelHandlerContext.java:262)
                class: io.netty.channel.ChannelInboundHandler
                count: 1
--------------------------
17:     io.netty.handler.codec.http.HttpClientCodec
Count:  779
Types:
        io.netty.channel.ChannelInboundHandler
        io.netty.channel.ChannelOutboundHandler
Traces:
        io.netty.channel.AbstractChannelHandlerContext.invokeRead(AbstractChannelHandlerContext.java:686)
                class: io.netty.channel.ChannelOutboundHandler
                count: 364
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 249
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
                class: io.netty.channel.ChannelInboundHandler
                count: 113
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 27
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 20
        io.netty.channel.AbstractChannelHandlerContext.invokeWrite0(AbstractChannelHandlerContext.java:717)
                class: io.netty.channel.ChannelOutboundHandler
                count: 3
        io.netty.channel.AbstractChannelHandlerContext.invokeFlush0(AbstractChannelHandlerContext.java:750)
                class: io.netty.channel.ChannelOutboundHandler
                count: 2
        io.netty.channel.AbstractChannelHandlerContext.invokeUserEventTriggered(AbstractChannelHandlerContext.java:346)
                class: io.netty.channel.ChannelInboundHandler
                count: 1
--------------------------
18:     io.vertx.core.http.impl.AssembledFullHttpRequest
Count:  298
Types:
        io.netty.handler.codec.http.FullHttpMessage
        io.netty.handler.codec.http.HttpRequest
        io.netty.handler.codec.http.HttpMessage
        io.netty.handler.codec.http.HttpContent
Traces:
        io.netty.handler.codec.http.HttpClientCodec$Encoder.encode(HttpClientCodec.java:199)
                class: io.netty.handler.codec.http.HttpRequest
                count: 51
        io.netty.handler.codec.http.HttpObjectEncoder.encodeFullHttpMessage(HttpObjectEncoder.java:308)
                class: io.netty.handler.codec.http.HttpMessage
                count: 50
        io.netty.handler.codec.http.HttpObjectEncoder.encode(HttpObjectEncoder.java:161)
                class: io.netty.handler.codec.http.FullHttpMessage
                count: 50
        io.netty.handler.codec.http.HttpObjectEncoder.acceptOutboundMessage(HttpObjectEncoder.java:571)
                class: io.netty.handler.codec.http.FullHttpMessage
                count: 50
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:196)
                class: io.netty.handler.codec.http.HttpContent
                count: 49
        io.netty.handler.codec.http.HttpRequestEncoder.encodeInitialLine(HttpRequestEncoder.java:28)
                class: io.netty.handler.codec.http.HttpRequest
                count: 48
--------------------------
19:     io.netty.handler.codec.http.LastHttpContent$1
Count:  213
Types:
        io.netty.handler.codec.http.HttpContent
        io.netty.handler.codec.http.LastHttpContent
        io.netty.handler.codec.http.HttpObject
Traces:
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:196)
                class: io.netty.handler.codec.http.HttpContent
                count: 57
        io.vertx.core.http.impl.Http1xClientConnection.validateMessage(Http1xClientConnection.java:694)
                class: io.netty.handler.codec.http.HttpObject
                count: 51
        io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:750)
                class: io.netty.handler.codec.http.LastHttpContent
                count: 51
        io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:745)
                class: io.netty.handler.codec.http.HttpContent
                count: 49
        io.vertx.core.http.impl.AssembledFullHttpRequest.trailingHeaders(AssembledFullHttpRequest.java:94)
                class: io.netty.handler.codec.http.LastHttpContent
                count: 2
        io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:714)
                class: io.netty.handler.codec.http.HttpObject
                count: 1
        io.vertx.core.http.impl.Http1xConnectionBase.sizeOf(Http1xConnectionBase.java:197)
                class: io.netty.handler.codec.http.HttpContent
                count: 1
        io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:715)
                class: io.netty.handler.codec.http.HttpObject
                count: 1
--------------------------
20:     com.github.benmanes.caffeine.cache.PSWMW
Count:  212
Types:
        com.github.benmanes.caffeine.cache.AccessOrderDeque$AccessOrder
        com.github.benmanes.caffeine.cache.WriteOrderDeque$WriteOrder
Traces:
        com.github.benmanes.caffeine.cache.AccessOrderDeque.contains(AccessOrderDeque.java:34)
                class: com.github.benmanes.caffeine.cache.AccessOrderDeque$AccessOrder
                count: 106
        com.github.benmanes.caffeine.cache.WriteOrderDeque.contains(WriteOrderDeque.java:34)
                class: com.github.benmanes.caffeine.cache.WriteOrderDeque$WriteOrder
                count: 106
--------------------------
21:     io.netty.handler.codec.http.DefaultHttpResponse
Count:  204
Types:
        io.netty.handler.codec.http.HttpResponse
        io.netty.handler.codec.http.HttpObject
Traces:
        io.vertx.core.http.impl.Http1xClientConnection.validateMessage(Http1xClientConnection.java:694)
                class: io.netty.handler.codec.http.HttpObject
                count: 51
        io.vertx.core.http.impl.Http1xClientConnection.validateMessage(Http1xClientConnection.java:699)
                class: io.netty.handler.codec.http.HttpResponse
                count: 51
        io.vertx.core.http.impl.Http1xClientConnection.handleHttpMessage(Http1xClientConnection.java:732)
                class: io.netty.handler.codec.http.HttpResponse
                count: 51
        io.vertx.core.http.impl.Http1xClientConnection.handleMessage(Http1xClientConnection.java:714)
                class: io.netty.handler.codec.http.HttpObject
                count: 51
--------------------------
22:     io.netty.channel.AdaptiveRecvByteBufAllocator
Count:  191
Types:
        io.netty.channel.RecvByteBufAllocator
        io.netty.channel.MaxMessagesRecvByteBufAllocator
Traces:
        io.netty.channel.DefaultChannelConfig.setRecvByteBufAllocator(DefaultChannelConfig.java:313)
                class: io.netty.channel.RecvByteBufAllocator
                count: 96
        io.netty.channel.DefaultChannelConfig.setRecvByteBufAllocator(DefaultChannelConfig.java:326)
                class: io.netty.channel.MaxMessagesRecvByteBufAllocator
                count: 94
        io.netty.channel.DefaultChannelConfig.setRecvByteBufAllocator(DefaultChannelConfig.java:327)
                class: io.netty.channel.MaxMessagesRecvByteBufAllocator
                count: 1
--------------------------
23:     io.netty.channel.nio.NioEventLoop
Count:  126
Types:
        io.netty.channel.EventLoop
        io.netty.util.concurrent.EventExecutor
Traces:
        io.netty.channel.MultithreadEventLoopGroup.next(MultithreadEventLoopGroup.java:78)
                class: io.netty.channel.EventLoop
                count: 63
        io.netty.util.concurrent.DefaultPromise.<init>(DefaultPromise.java:83)
                class: io.netty.util.concurrent.EventExecutor
                count: 58
        io.netty.resolver.SimpleNameResolver.<init>(SimpleNameResolver.java:39)
                class: io.netty.util.concurrent.EventExecutor
                count: 4
        io.netty.resolver.AbstractAddressResolver.<init>(AbstractAddressResolver.java:54)
                class: io.netty.util.concurrent.EventExecutor
                count: 1
--------------------------
24:     io.vertx.core.impl.future.PromiseImpl
Count:  114
Types:
        io.vertx.core.impl.future.PromiseInternal
        io.vertx.core.impl.future.FutureInternal
        io.netty.util.concurrent.GenericFutureListener
        io.vertx.core.impl.future.Listener
Traces:
        io.vertx.core.impl.ContextInternal.promise(ContextInternal.java:84)
                class: io.vertx.core.impl.future.PromiseInternal
                count: 44
        io.vertx.core.impl.future.Composition.onSuccess(Composition.java:38)
                class: io.vertx.core.impl.future.FutureInternal
                count: 38
        io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:552)
                class: io.netty.util.concurrent.GenericFutureListener
                count: 31
        io.vertx.core.impl.future.SucceededFuture.onComplete(SucceededFuture.java:76)
                class: io.vertx.core.impl.future.Listener
                count: 1
--------------------------
25:     io.vertx.core.net.impl.VertxHandler
Count:  110
Types:
        io.netty.channel.ChannelInboundHandler
        io.netty.channel.ChannelHandler
        io.netty.channel.ChannelOutboundHandler
Traces:
        io.vertx.core.http.impl.HttpChannelConnector.wrap(HttpChannelConnector.java:100)
                class: io.netty.channel.ChannelHandler
                count: 28
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelReadComplete(AbstractChannelHandlerContext.java:410)
                class: io.netty.channel.ChannelInboundHandler
                count: 28
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:123)
                class: io.netty.channel.ChannelOutboundHandler
                count: 27
        io.netty.channel.AbstractChannelHandlerContext.invokeChannelRead(AbstractChannelHandlerContext.java:379)
                class: io.netty.channel.ChannelInboundHandler
                count: 21
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 6
--------------------------
26:     io.smallrye.mutiny.operators.uni.UniOnItemTransformToUni$UniOnItemTransformToUniProcessor
Count:  101
Types:
        io.smallrye.mutiny.subscription.UniSubscriber
        org.reactivestreams.Subscription
        io.smallrye.mutiny.subscription.UniSubscription
Traces:
        io.smallrye.mutiny.operators.uni.UniOperatorProcessor.<init>(UniOperatorProcessor.java:24)
                class: io.smallrye.mutiny.subscription.UniSubscriber
                count: 50
        io.smallrye.mutiny.helpers.UniCallbackSubscriber.onItem(UniCallbackSubscriber.java:70)
                class: org.reactivestreams.Subscription
                count: 49
        io.smallrye.mutiny.operators.uni.UniOperatorProcessor.getAndSetUpstreamSubscription(UniOperatorProcessor.java:77)
                class: io.smallrye.mutiny.subscription.UniSubscription
                count: 2
--------------------------
27:     org.slf4j.impl.Slf4jLogger
Count:  95
Types:
        org.slf4j.spi.LocationAwareLogger
        org.slf4j.Logger
Traces:
        io.netty.util.internal.logging.Slf4JLoggerFactory.wrapLogger(Slf4JLoggerFactory.java:54)
                class: org.slf4j.spi.LocationAwareLogger
                count: 47
        org.slf4j.impl.Slf4jLoggerFactory.getLogger(Slf4jLoggerFactory.java:39)
                class: org.slf4j.Logger
                count: 47
        io.vertx.core.logging.SLF4JLogDelegate.log(SLF4JLogDelegate.java:179)
                class: org.slf4j.spi.LocationAwareLogger
                count: 1
--------------------------
28:     java.util.Collections$SingletonList
Count:  89
Types:
        java.util.Collection
        java.util.List
Traces:
        io.quarkus.arc.impl.ArcContainerImpl.getActiveContext(ArcContainerImpl.java:220)
                class: java.util.Collection
                count: 45
        io.quarkus.arc.impl.ArcContainerImpl.getContexts(ArcContainerImpl.java:238)
                class: java.util.List
                count: 44
--------------------------
29:     io.netty.channel.DefaultChannelPromise
Count:  66
Types:
        io.netty.channel.ChannelFuture
        io.netty.channel.ChannelPromise
Traces:
        io.netty.channel.DelegatingChannelPromiseNotifier.<init>(DelegatingChannelPromiseNotifier.java:43)
                class: io.netty.channel.ChannelPromise
                count: 32
        io.netty.channel.DelegatingChannelPromiseNotifier.operationComplete(DelegatingChannelPromiseNotifier.java:31)
                class: io.netty.channel.ChannelFuture
                count: 30
        io.netty.handler.timeout.IdleStateHandler$1.operationComplete(IdleStateHandler.java:103)
                class: io.netty.channel.ChannelFuture
                count: 3
        io.netty.handler.ssl.SslHandler.closeOutboundAndChannel(SslHandler.java:1953)
                class: io.netty.channel.ChannelPromise
                count: 1
--------------------------
30:     io.netty.channel.DelegatingChannelPromiseNotifier
Count:  65
Types:
        io.netty.util.concurrent.GenericFutureListener
        io.netty.channel.ChannelFutureListener
Traces:
        io.netty.util.concurrent.DefaultPromise.notifyListenersNow(DefaultPromise.java:552)
                class: io.netty.util.concurrent.GenericFutureListener
                count: 33
        io.netty.channel.AbstractCoalescingBufferQueue.remove(AbstractCoalescingBufferQueue.java:157)
                class: io.netty.channel.ChannelFutureListener
                count: 32
--------------------------
31:     io.vertx.core.net.impl.ChannelProvider$2
Count:  33
Types:
        io.netty.channel.ChannelHandler
        io.netty.channel.ChannelInboundHandler
Traces:
        io.netty.bootstrap.AbstractBootstrap.handler(AbstractBootstrap.java:368)
                class: io.netty.channel.ChannelHandler
                count: 17
        io.netty.channel.ChannelHandlerMask.mask0(ChannelHandlerMask.java:94)
                class: io.netty.channel.ChannelInboundHandler
                count: 16
--------------------------
32:     io.vertx.core.impl.VertxImpl
Count:  27
Types:
        io.vertx.core.impl.VertxInternal
        io.vertx.core.Vertx
Traces:
        io.vertx.core.http.impl.Http1xServerRequest.handleBegin(Http1xServerRequest.java:159)
                class: io.vertx.core.impl.VertxInternal
                count: 14
        org.jboss.resteasy.reactive.client.impl.ClientImpl.<init>(ClientImpl.java:111)
                class: io.vertx.core.Vertx
                count: 13
--------------------------
33:     org.jboss.resteasy.reactive.server.providers.serialisers.ServerStringMessageBodyHandler
Count:  21
Types:
        org.jboss.resteasy.reactive.server.spi.ServerMessageBodyWriter
        javax.ws.rs.ext.MessageBodyWriter
Traces:
        org.jboss.resteasy.reactive.server.core.startup.RuntimeResourceDeployment.buildResourceMethod(RuntimeResourceDeployment.java:427)
                class: org.jboss.resteasy.reactive.server.spi.ServerMessageBodyWriter
                count: 11
        org.jboss.resteasy.reactive.server.core.startup.RuntimeResourceDeployment.buildResourceMethod(RuntimeResourceDeployment.java:424)
                class: javax.ws.rs.ext.MessageBodyWriter
                count: 10
--------------------------

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

So our caching layers does suffer from this problem...

@franz1981
Copy link
Contributor

And not only @geoand : I see that's using a version of Netty that doesn't contain my fix, that's "tricking" the JIT (I know, it's unfair) and partially fixing it

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

Yeah, there are multiple things that are concerning, but for this specific use case I'm just focusing on the cache part.
Any idea on how to overcome it?

@demming
Copy link
Author

demming commented Oct 27, 2022

@geoand :

I started looking at the issue, but I just want to clarify that case no. 2, where you are using @nonblocking but then using the blocking version of the REST Client in the method body is not expected to work.

Oh, I see, then I must have misunderstood what you were suggesting back then:

If you want an apples to apples comparison of Quarkus with other stacks, you should be using RESTEasy Reactive and either annotated the class / method with @NonBlocking, or return Uni<String> from the getSanitizedHtml method (see this for a detailed explanation)

Notice the very long UniResponseHandler.handle entry that does not seem to do much.

Oh, right, I'm not well-versed in Mutiny. Are getArcCacheInterceptionContext on CacheInterceptor and UniCreate.completionStage supposed to wait for so long or are there actions hidden from the debugger? It appears like it's subjugating Caffeine.

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

They should not be waiting so long, so we likely have some hidden performance issue that is not related to Caffeine

@demming
Copy link
Author

demming commented Oct 27, 2022

@franz1981 :

arraylist default capacity can be just too much for the actual number of elements needed there?

Would it make sense to try to initialize it to the initial size of the cache as per application.yml?

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

It's unrelated

@demming
Copy link
Author

demming commented Oct 27, 2022

Alright, I see, thank you

@Sanne
Copy link
Member

Sanne commented Oct 27, 2022

@geoand FYI, looking at your report the top consumer is io.vertx.core.impl.DuplicatedContext - be aware I've already fixed that one, it's pending a release of smallrye/smallrye-common#190

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

Thanks @Sanne. I am aware of that fix

@Sanne
Copy link
Member

Sanne commented Oct 27, 2022

Cool - I see Roberto released it, it's included in #28886 - looking forward to see that merged.

@geoand
Copy link
Contributor

geoand commented Oct 27, 2022

Excellent 👌.

I have similar fix that might help with the caching code.

@geoand
Copy link
Contributor

geoand commented Nov 1, 2022

The type pollution fix for cache does indeed give a small performance boost, but nothing earth shattering.

@franz1981
Copy link
Contributor

franz1981 commented Nov 1, 2022

Just curious @geoand : you tested a version including smallrye/smallrye-common#190 as well?
If the small change in the less offending part give a small but still visible boost, it could be a CPU bound situation, and worth checking the most offending types, probably.

I see it's not still using the latest Netty version as well: I suggest to run something that fix the above mentioned by Sanne and forces the latest Netty version (that's including the fixes of scalability for the channel pipeline, including IdleStateHandler)

@geoand
Copy link
Contributor

geoand commented Nov 1, 2022

Nope, just my fix

@geoand
Copy link
Contributor

geoand commented Nov 2, 2022

@franz1981 we'll need to test all the fixes together to see what kind of performance boost they all provide

@franz1981
Copy link
Contributor

I have sent a change to vertx addressing something similar too: eclipse-vertx/vert.x#4520

And the change I am proposing there will be real ie JIT won't optimize it :(
Hope this will be soon merged

@franz1981
Copy link
Contributor

franz1981 commented Feb 27, 2023

I haven't forgotten this :)
I strongly suggest to disable metrics @geoand @Sanne @demming
I'm performing some cleanup on Vert-x to get rid of expensive type checks (both harming scalability and single-threaded performance quite bad) - see eclipse-vertx/vert.x#4629

In the meantime @demming could run the reproducer over the last version of quarkus with

-Dvertx.disableMetrics=true

that should improve things a bit

@geoand
Copy link
Contributor

geoand commented Mar 20, 2023

I think we can close this as it has pretty much turned into a general performance improvement thread that we already do anyway lead by @franz1981 :)

@geoand geoand closed this as not planned Won't fix, can't repro, duplicate, stale Mar 20, 2023
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
area/cache kind/bug Something isn't working
Projects
None yet
Development

No branches or pull requests

5 participants