search

spring-cloud / spring-cloud-gateway

An API Gateway built on Spring Framework and Spring Boot providing routing and more.
http://cloud.spring.io
Apache License 2.0
4.55k stars 3.33k forks source link

High CPU utilization in Spring Cloud Gateway application #1908

Open jacob2221 opened 4 years ago

jacob2221 commented 4 years ago

Hi,

Sample Spring Cloud gateway app used for PST is available at - https://github.com/jacob2221/basic-gateway

Architecture: x86_64 CPU op-mode(s): 32-bit, 64-bit CPU(s): 4 On-line CPU(s) list: 0-3 Thread(s) per core: 1 Core(s) per socket: 1 Socket(s): 4

JRE version used - Java HotSpot(TM) 64-Bit Server VM (build 25.261-b12, mixed mode)

RESULTS

Below command was executed while PST was running

top -n 1 -H -p

Using the hex value of the thread PIDs from above command on search the output of "jstack ", it shows 4 threads each having name like "reactor-http-epoll-*" and stack as below -

"reactor-http-epoll-2" #21 daemon prio=5 os_prio=0 tid=0x00007fcd20005000 nid=0x1b086 runnable [0x00007fcd40a6e000] java.lang.Thread.State: RUNNABLE at io.netty.channel.epoll.Native.epollWait(Native Method) at io.netty.channel.epoll.Native.epollWait(Native.java:148) at io.netty.channel.epoll.Native.epollWait(Native.java:141) at io.netty.channel.epoll.EpollEventLoop.epollWaitNoTimerChange(EpollEventLoop.java:290) at io.netty.channel.epoll.EpollEventLoop.run(EpollEventLoop.java:347) at io.netty.util.concurrent.SingleThreadEventExecutor$4.run(SingleThreadEventExecutor.java:989) at io.netty.util.internal.ThreadExecutorMap$2.run(ThreadExecutorMap.java:74) at io.netty.util.concurrent.FastThreadLocalRunnable.run(FastThreadLocalRunnable.java:30) at java.lang.Thread.run(Thread.java:748)

JVM arguments used for the test

MEM_ARGS="-Xms2048m -Xmx2048m -XX:+UseConcMarkSweepGC -XX:+UseParNewGC -XX:+CMSParallelRemarkEnabled -XX:CMSInitiatingOccupancyFraction=60 -XX:+UseCMSInitiatingOccupanc yOnly -XX:+DisableExplicitGC -XX:+PrintGCDetails -XX:+PrintGCDateStamps -XX:+PrintGCTimeStamps -XX:+UseGCLogFileRotation -XX:NumberOfGCLogFiles=10 -XX:GCLogFileSize=102 40K -Xloggc:$FILENAME -verbose:gc -XX:+HeapDumpOnOutOfMemoryError -XX:HeapDumpPath=$LOGDIR -XX:+PrintStringTableStatistics -Djava.security.egd=file:///dev/./urandom -Dr eactor.netty.http.server.accessLogEnabled=true -Dio.netty.leakDetection.level=advanced"

Could you help advise why these threads are consuming high CPU? Are there any further settings we can do to optimize this?

spencergibb commented 4 years ago

Please try again with boot 2.3.3 and Hoxton.SR7

jacob2221 commented 4 years ago

Hi @spencergibb, I tried again with boot 2.3.3 and Hoxton.SR7 but do not see much difference. Below are some screen shots of "top | grep 18316" command after few minutes of start of PST

18316 lmpserv+ 20 0 5280316 571796 16488 S 52.9 3.5 1:35.54 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 46.8 3.5 1:36.95 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 39.7 3.5 1:38.15 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 45.2 3.5 1:39.51 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 43.2 3.5 1:40.81 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 50.3 3.5 1:42.33 java 18316 lmpserv+ 20 0 5280316 571796 16488 S 42.9 3.5 1:43.62 java 18316 lmpserv+ 20 0 5280316 572060 16488 S 44.7 3.5 1:44.97 java 18316 lmpserv+ 20 0 5280316 572060 16488 S 40.5 3.5 1:46.19 java 18316 lmpserv+ 20 0 5280316 572060 16488 S 43.7 3.5 1:47.51 java 18316 lmpserv+ 20 0 5280316 572060 16488 S 40.9 3.5 1:48.74 java 18316 lmpserv+ 20 0 5280316 572060 16488 S 44.9 3.5 1:50.09 java 18316 lmpserv+ 20 0 5280316 572324 16488 S 41.4 3.5 1:51.34 java 18316 lmpserv+ 20 0 5280316 572324 16488 S 40.5 3.5 1:52.56 java 18316 lmpserv+ 20 0 5280316 572324 16488 S 44.5 3.5 1:53.90 java 18316 lmpserv+ 20 0 5280316 572324 16488 S 39.4 3.5 1:55.09 java 18316 lmpserv+ 20 0 5280316 572588 16488 S 43.2 3.5 1:56.39 java 18316 lmpserv+ 20 0 5280316 572588 16488 S 39.7 3.5 1:57.59 java 18316 lmpserv+ 20 0 5280316 573380 16488 S 44.2 3.5 1:58.92 java

Noticed one more thread this time showing in top list of "top -n 1 -H -p 18316" occasionally but mostly it is the 4 "epoll" threads

"AsyncAppender-Worker-async" #14 daemon prio=5 os_prio=0 tid=0x00007f5f5caa9000 nid=0x47a6 waiting on condition [0x00007f5f325c6000] java.lang.Thread.State: WAITING (parking) at sun.misc.Unsafe.park(Native Method)

Below are some of the parameters set in Jmeter JMX file 

    <stringProp name="ThreadGroup.num_threads">500</stringProp>
    <stringProp name="ThreadGroup.ramp_time">1</stringProp>
    <boolProp name="ThreadGroup.scheduler">true</boolProp>
    <stringProp name="ThreadGroup.duration">600</stringProp>
    <stringProp name="ThreadGroup.delay">1</stringProp>
jacob2221 commented 4 years ago

We also have a requirement to log request and response. For that we have the below filter. With this filter in place, the utilization is almost double (~ 80% after the initial few mins of PST start). Its is mostly the 4 epoll threads which show high CPU utilization. This is for an application which is going to production soon. Any timely help would be appreciated as this issue has become a bottleneck

Below is the filter code 

package basic.gateway;

import java.nio.charset.StandardCharsets;

import org.reactivestreams.Publisher;
import org.springframework.cloud.gateway.filter.GatewayFilterChain;
import org.springframework.cloud.gateway.filter.GlobalFilter;
import org.springframework.core.Ordered;
import org.springframework.core.io.buffer.DataBuffer;
import org.springframework.core.io.buffer.DataBufferFactory;
import org.springframework.core.io.buffer.DataBufferUtils;
import org.springframework.http.server.reactive.ServerHttpRequest;
import org.springframework.http.server.reactive.ServerHttpResponse;
import org.springframework.http.server.reactive.ServerHttpResponseDecorator;
import org.springframework.stereotype.Component;
import org.springframework.web.server.ServerWebExchange;

import lombok.extern.slf4j.Slf4j;
import reactor.core.publisher.Flux;
import reactor.core.publisher.Mono;

@Component
@Slf4j
public class RequestResponseLogFilter implements GlobalFilter, Ordered {

    @Override
    public Mono<Void> filter(ServerWebExchange exchange, GatewayFilterChain chain) {
        ServerHttpRequest request = exchange.getRequest();
        logRequest(request, exchange.getAttribute("cachedRequestBodyObject"));
        return chain.filter(exchange.mutate().response(logResponse(exchange)).build());
        //return chain.filter(exchange);

    }

    @Override
    public int getOrder() {
        return Integer.MIN_VALUE;
    }

    private void logRequest(ServerHttpRequest request, String body) {
        if (body != null) {
            log.debug("REQUEST" + body);
        }
    }

    private ServerHttpResponseDecorator logResponse(ServerWebExchange exchange) {
        ServerHttpResponse origResponse = exchange.getResponse();
        DataBufferFactory bufferFactory = origResponse.bufferFactory();
        return new ServerHttpResponseDecorator(origResponse) {
            @Override
            public Mono<Void> writeWith(Publisher<? extends DataBuffer> body) {
                if (body instanceof Flux) {
                    Flux<? extends DataBuffer> fluxBody = (Flux<? extends DataBuffer>) body;
                    return super.writeWith(fluxBody.map(dataBuffer -> {
                        try {
                            byte[] content = new byte[dataBuffer.readableByteCount()];
                            dataBuffer.read(content);
                            String bodyContent = new String(content, StandardCharsets.UTF_8);
                            log.debug("RESPONSE" + bodyContent);
                            return bufferFactory.wrap(content);
                        } finally {
                            DataBufferUtils.release(dataBuffer);
                        }
                    }));
                }
                return super.writeWith(body);
            }
        };

    }
}
jacob2221 commented 4 years ago

Seeing below in log file....Could this have anything to do with issue

[2020-08-21 13:45:38,537] [] [15854] [main] [DEBUG] [i.n.u.internal.NativeLibraryLoader] - Unable to load the library 'netty_transport_native_epoll_x86_64', trying other loading mechanism.
java.lang.UnsatisfiedLinkError: no netty_transport_native_epoll_x86_64 in java.library.path

[2020-08-21 13:45:38,567] [] [15884] [main] [DEBUG] [i.n.u.internal.NativeLibraryLoader] - Successfully loaded the library /tmp/libnetty_transport_native_epoll_x86_6488
16793540849624173.so
[2020-08-21 13:45:38,568] [] [15885] [main] [DEBUG] [r.netty.resources.DefaultLoopEpoll] - Default Epoll support : true
[2020-08-21 13:45:38,569] [] [15886] [main] [DEBUG] [r.netty.resources.DefaultLoopKQueue] - Default KQueue support : false
[2020-08-21 13:45:38,581] [] [15898] [main] [DEBUG] [i.n.c.MultithreadEventLoopGroup] - -Dio.netty.eventLoopThreads: 12
lkolisko commented 4 years ago

The library has been successfully loaded. The - Unable to load the library 'netty_transport_native_epoll_x86_64', trying other loading mechanism. java.lang.UnsatisfiedLinkError: no netty_transport_native_epoll_x86_64 in java.library.path is just a netty DEBUG message. Therefore this has nothing to do with the issue.

violetagg commented 4 years ago

If I remember correctly this issue is related to logging usage https://stackoverflow.com/questions/63517483/spring-cloud-gateway-high-cpu-utilization-on-rhel-possible-to-switch-from-ep

lkolisko commented 4 years ago

We are experiencing the same issue. Our stack is on 2.3.3.RELEASE, Hoxton.SR7. The gateway is running in a docker container on top of Centos 7.8.2003 with AdoptOpenJdk (build 11.0.8+10).

I tried to experiment with both nio and epoll, different sizes of the selector, and worker thread pools, but the results are practically the same. We are migrating from Zuul gateway and the CPU usage is > ~2x higher under the same load.

The only issue I was able to spot is with the lookup of ReactorLoadBalancer in the ReactiveLoadBalancerClientFilter (#1941), but I do not think this explains the whole story.

We are using plain Netty or Spring WebFlux (on netty-reactor) in different microservices (using the same underlying jvm, os, and infra), but we did not run into this issue.

spencergibb commented 4 years ago

@jacob2221 did the logging hint help?

xinghui322 commented 4 years ago

I had the same problem before, and I've resolved it by remove usage of org.springframework.util.MimeTypeUtils in NettyWriteResponseFilter .
MimeTypeUtils may still has performance problem ，although the fix of https://github.com/spring-projects/spring-framework/issues/24671 @spencergibb

spencergibb commented 4 years ago

@lkolisko have you upgraded to Hoxton.SR8 and boot 2.3.4?

lkolisko commented 4 years ago

We migrated to Hoxton.SR8 and boot 2.3.4 recently. I did some preliminary performance testing and did not see any change in the CPU utilization metric based on the upgrade. However, I was able to lower CPU utilization disabling Spring Sleuth https://github.com/spring-cloud/spring-cloud-sleuth/issues/1397 and implementing ReactiveLoadBalancerClientFilter lookup fix (#1941).

OlgaMaciaszek commented 4 years ago

1941 was already merged into Hoxton, it will be coming in SR9. However, when it comes to Sleuth, unfortunately, the improvements will come only in 2020.0.0.

spring-projects-issues commented 4 years ago

If you would like us to look at this issue, please provide the requested information. If the information is not provided within the next 7 days this issue will be closed.

spring-projects-issues commented 4 years ago

Closing due to lack of requested feedback. If you would like us to look at this issue, please provide the requested information and we will re-open the issue.

paskos commented 3 years ago

Hi,

We're seeing the same issue using spring-cloud (Hoxton.SR9), spring-boot (2.3.6.RELEASE) including spring-cloud-sleuth propagation enabled and spring.sleuth.reactor.decorate-on-each=false. Our load test is relateively simple:

  1. Gatling client sending one type of request (PUT with small json payload).
  2. Spring-cloud-gateway (later referred to as standalone-gateway) with k8s service discovery and spring-cloud-loadbalancer routes request to a downstream service.
  3. The downstream service (later referred to as embedded-gateway) uses an embedded spring-cloud-gateway to route the request to an external http service configured by its hostname.

standalone-gateway and embedded-gateway both have exactly the same spring-cloud-sleuth configurations regarding reactor decoration, correlation fields, local fields and remote fields. They both use the same logback-spring.xml file. Both have 2 CPUs and 2 Gig of Heap.

Load test starts by gradually ramping up to 180 req per seconds and maintaining that rate for 5 minutes. standalone-gateway goes up to 70% CPU usage and settles down to an average of 40%. embedded-gateway goes up to 45% CPU usage and settles down to an average of 25%.

We increase the load to 240 req/secs for 5 minutes standalone-gateway averages 60% CPU usage. embedded-gateway averages 35%.

We increase the load to 300 req/secs for 10 minutes standalone-gateway averages 80% CPU usage. embedded-gateway averages 40%.

We try to increase the load to 400 req/secs standalone-gateway CPU usage rapidly shots to 100% and k8s service gets restarted because the liveness probe times out. embedded-gateway averages 50%.

The main differences between standalone-gateway and embedded-gateway I've managed to see are:

I hope it helps.

qqeasonchen commented 3 years ago

Hi, the same issue using spring-cloud-gateway 3.0.1-SNAPSHOT, 8 cores vm. you can see as below, every reactor-http-epoll-* goes up to 96% CPU

image

flyonce commented 3 years ago

We also met this issue env:

The cpu utilization of "XNIO-1 I/O-2" and "XNIO-1 I/O-4" up bound to 99% image

by analysing the trace log below, you can found the AbstractListenerWriteProcessor.state never change to COMPLETED or RECEIVED after it change from RECEIVED to REQUESTED in method onWritePossible of State.RECEIVED. So it always firing the empty implemention onWritePossible of State.REQUESTED

2021-03-12 14:43:16.073 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.074 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.075 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> COMPLETED
2021-03-12 14:43:16.087 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:16.088 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:432] - [232a638] RECEIVED writeComplete
2021-03-12 14:43:16.090 [reactor-http-epoll-3] TRACE [UndertowServerHttpResponse.java:281] - [232a638] flush
2021-03-12 14:43:16.091 [reactor-http-epoll-3] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:16.104 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] RECEIVED -> REQUESTED
2021-03-12 14:43:16.116 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> COMPLETED
2021-03-12 14:43:16.135 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:56.645 [XNIO-1 I/O-4] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.645 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] UNSUBSCRIBED -> SUBSCRIBING
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:258] - [232a638] 9223372036854775807 requested
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] SUBSCRIBING -> DEMAND
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] DEMAND -> READING
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [UndertowServerHttpRequest.java:186] - [232a638] Read -1
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] READING -> COMPLETED
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:200] - [232a638] No more data to read
2021-03-12 14:43:56.676 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.690 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:101] - [232a638] Received onNext publisher
2021-03-12 14:43:56.693 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.695 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.698 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:115] - [232a638] Item to write
2021-03-12 14:43:56.700 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.702 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.701 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:290] - [232a638] isWritePossible: false
2021-03-12 14:43:56.706 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> WRITING
2021-03-12 14:43:56.707 [XNIO-1 I/O-4] TRACE [UndertowServerHttpResponse.java:210] - [232a638] Wrote 3728 of 3728 bytes
2021-03-12 14:43:56.709 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] WRITING -> REQUESTED
2021-03-12 14:43:56.715 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: org.springframework.http.server.reac
2021-03-12 14:43:56.716 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.718 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:125] - [232a638] Received onComplete
2021-03-12 14:43:56.720 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: reactor.core.publisher.MonoNext$Next
2021-03-12 14:43:56.725 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.727 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.728 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.737 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.739 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.742 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.745 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.747 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.748 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.750 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.752 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.760 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.761 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.762 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.765 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.766 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.767 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.769 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.770 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.778 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.781 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.785 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.791 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.793 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.794 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.801 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.802 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.804 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.805 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.807 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.809 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.810 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.812 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
flyonce commented 3 years ago

@qqeasonchen Hi, have you already found out the cause of the issue and solve it ?

qqeasonchen commented 3 years ago

Hi, not yet.

On Mon, Mar 22, 2021 at 1:44 PM flyonce @.***> wrote:

@qqeasonchen https://github.com/qqeasonchen Hi, have you already found out the cause the issue and solve it ?

— You are receiving this because you were mentioned. Reply to this email directly, view it on GitHub https://github.com/spring-cloud/spring-cloud-gateway/issues/1908#issuecomment-803778185, or unsubscribe https://github.com/notifications/unsubscribe-auth/AGH3J5OWEW3ZCMUY5AMLFDTTE3KLDANCNFSM4QE4YIEA .

flyonce commented 3 years ago

In my case, the trace log looks like issues mentioned in: https://github.com/spring-projects/spring-framework/issues/26434 https://bugs.openjdk.java.net/browse/JDK-8263243

To add timeout on handling request, it help to me to recover from the high cpu utilization. But the issue still there

    private static class HttpHandlerDecorator implements HttpHandler {
        private final HttpHandler delegate;
        public HttpHandlerDecorator(HttpHandler delegate) {
            this.delegate = delegate;
        }
        @Override
        public Mono<Void> handle(ServerHttpRequest request, ServerHttpResponse response) {
            Long requestStartTime = System.currentTimeMillis();
            return this.delegate.handle(request, response).timeout(Duration.ofSeconds(65))
                .onErrorResume(TimeoutException.class, timeout -> this.timeoutFallback(requestStartTime, timeout, request, response));
        }
       ...
}
xiaoyuwang1987 commented 1 year ago

We also met this issue env:

  • Spring-Boot 2.3.3.RELEASE, Spring-Cloud Hoxton.SR9, Undertow 2.0.9.Final
  • Spring-Boot 2.4.2, Spring-Cloud 2020.0.1, Undertow 2.0.9.Final

The cpu utilization of "XNIO-1 I/O-2" and "XNIO-1 I/O-4" up bound to 99% image

by analysing the trace log below, you can found the AbstractListenerWriteProcessor.state never change to COMPLETED or RECEIVED after it change from RECEIVED to REQUESTED in method onWritePossible of State.RECEIVED. So it always firing the empty implemention onWritePossible of State.REQUESTED

2021-03-12 14:43:16.073 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.074 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.075 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> COMPLETED
2021-03-12 14:43:16.087 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:16.088 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:432] - [232a638] RECEIVED writeComplete
2021-03-12 14:43:16.090 [reactor-http-epoll-3] TRACE [UndertowServerHttpResponse.java:281] - [232a638] flush
2021-03-12 14:43:16.091 [reactor-http-epoll-3] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:16.104 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] RECEIVED -> REQUESTED
2021-03-12 14:43:16.116 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> COMPLETED
2021-03-12 14:43:16.135 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:56.645 [XNIO-1 I/O-4] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.645 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] UNSUBSCRIBED -> SUBSCRIBING
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:258] - [232a638] 9223372036854775807 requested
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] SUBSCRIBING -> DEMAND
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] DEMAND -> READING
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [UndertowServerHttpRequest.java:186] - [232a638] Read -1
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] READING -> COMPLETED
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:200] - [232a638] No more data to read
2021-03-12 14:43:56.676 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.690 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:101] - [232a638] Received onNext publisher
2021-03-12 14:43:56.693 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.695 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.698 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:115] - [232a638] Item to write
2021-03-12 14:43:56.700 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.702 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.701 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:290] - [232a638] isWritePossible: false
2021-03-12 14:43:56.706 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> WRITING
2021-03-12 14:43:56.707 [XNIO-1 I/O-4] TRACE [UndertowServerHttpResponse.java:210] - [232a638] Wrote 3728 of 3728 bytes
2021-03-12 14:43:56.709 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] WRITING -> REQUESTED
2021-03-12 14:43:56.715 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: org.springframework.http.server.reac
2021-03-12 14:43:56.716 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.718 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:125] - [232a638] Received onComplete
2021-03-12 14:43:56.720 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: reactor.core.publisher.MonoNext$Next
2021-03-12 14:43:56.725 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.727 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.728 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.737 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.739 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.742 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.745 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.747 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.748 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.750 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.752 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.760 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.761 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.762 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.765 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.766 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.767 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.769 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.770 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.778 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.781 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.785 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.791 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.793 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.794 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.801 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.802 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.804 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.805 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.807 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.809 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.810 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.812 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible

Is the problem solved? Have you tried to change the tomcat?

heaohao commented 1 year ago

We also met this issue env:

  • Spring-Boot 2.3.3.RELEASE, Spring-Cloud Hoxton.SR9, Undertow 2.0.9.Final
  • Spring-Boot 2.4.2, Spring-Cloud 2020.0.1, Undertow 2.0.9.Final

The cpu utilization of "XNIO-1 I/O-2" and "XNIO-1 I/O-4" up bound to 99% image by analysing the trace log below, you can found the AbstractListenerWriteProcessor.state never change to COMPLETED or RECEIVED after it change from RECEIVED to REQUESTED in method onWritePossible of State.RECEIVED. So it always firing the empty implemention onWritePossible of State.REQUESTED

2021-03-12 14:43:16.073 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.074 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:16.075 [reactor-http-epoll-3] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> COMPLETED
2021-03-12 14:43:16.087 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:16.088 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:432] - [232a638] RECEIVED writeComplete
2021-03-12 14:43:16.090 [reactor-http-epoll-3] TRACE [UndertowServerHttpResponse.java:281] - [232a638] flush
2021-03-12 14:43:16.091 [reactor-http-epoll-3] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:16.104 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] RECEIVED -> REQUESTED
2021-03-12 14:43:16.116 [reactor-http-epoll-3] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> COMPLETED
2021-03-12 14:43:16.135 [reactor-http-epoll-3] TRACE [WriteResultPublisher.java:82] - [232a638] SUBSCRIBED publishComplete
2021-03-12 14:43:56.645 [XNIO-1 I/O-4] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.645 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] UNSUBSCRIBED -> SUBSCRIBING
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:258] - [232a638] 9223372036854775807 requested
2021-03-12 14:43:56.646 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] SUBSCRIBING -> DEMAND
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:117] - [232a638] onDataAvailable
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] DEMAND -> READING
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [UndertowServerHttpRequest.java:186] - [232a638] Read -1
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:126] - [232a638] onAllDataRead
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:211] - [232a638] READING -> COMPLETED
2021-03-12 14:43:56.647 [reactor-http-epoll-1] TRACE [AbstractListenerReadPublisher.java:200] - [232a638] No more data to read
2021-03-12 14:43:56.676 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.690 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:101] - [232a638] Received onNext publisher
2021-03-12 14:43:56.693 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:203] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.695 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] UNSUBSCRIBED -> REQUESTED
2021-03-12 14:43:56.698 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:115] - [232a638] Item to write
2021-03-12 14:43:56.700 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] REQUESTED -> RECEIVED
2021-03-12 14:43:56.702 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.701 [reactor-http-epoll-1] TRACE [AbstractListenerWriteProcessor.java:290] - [232a638] isWritePossible: false
2021-03-12 14:43:56.706 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] RECEIVED -> WRITING
2021-03-12 14:43:56.707 [XNIO-1 I/O-4] TRACE [UndertowServerHttpResponse.java:210] - [232a638] Wrote 3728 of 3728 bytes
2021-03-12 14:43:56.709 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:265] - [232a638] WRITING -> REQUESTED
2021-03-12 14:43:56.715 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: org.springframework.http.server.reac
2021-03-12 14:43:56.716 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.718 [reactor-http-epoll-1] TRACE [AbstractListenerWriteFlushProcessor.java:125] - [232a638] Received onComplete
2021-03-12 14:43:56.720 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:72] - [232a638] UNSUBSCRIBED subscribe: reactor.core.publisher.MonoNext$Next
2021-03-12 14:43:56.725 [reactor-http-epoll-1] TRACE [WriteResultPublisher.java:117] - [232a638] SUBSCRIBING request: 9223372036854775807
2021-03-12 14:43:56.727 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.728 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.737 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.739 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.742 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.745 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.747 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.748 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.750 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.752 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.760 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.761 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.762 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.765 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.766 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.767 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.769 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.770 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.771 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.772 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.778 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.781 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.785 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.786 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.787 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.789 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.791 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.793 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.794 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.795 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.801 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.802 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.804 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.805 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.807 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.809 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.810 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible
2021-03-12 14:43:56.812 [XNIO-1 I/O-4] TRACE [AbstractListenerWriteProcessor.java:151] - [232a638] onWritePossible

Is the problem solved? Have you tried to change the tomcat?

After the stress test, I encountered the same problem as you, and now I solved it. Check to see if spring-boot-starter-undertow is introduced in your pom. If so, exclude it.