shenyu icon indicating copy to clipboard operation
shenyu copied to clipboard

[BUG] divide plugin webclient throw exception: The connection observed an error,io.netty.handler.timeout.ReadTimeoutException: null

Open dongxl123 opened this issue 4 years ago • 7 comments
trafficstars

Is there an existing issue for this?

  • [X] I have searched the existing issues

Current Behavior

2021-11-04 10:58:29 [XNIO-1 I/O-3] INFO org.apache.shenyu.plugin.httpclient.WebClientPlugin - The request urlPath is /api/v1/query?query=rate%28recv_packet_total%7Bsource%21%3D%22cffex%22%2Ctarget%3D~%22cffex.%2A%22%7D%5B5m%5D

%29&time=2021-11-04T02%3A58%3A28.564680692Z, retryTimes is 3 2021-11-04 10:58:32 [reactor-http-epoll-3] WARN reactor.netty.http.client.HttpClientConnect - [id: 0xa0255f85, L:/10.201.220.93:34256 - R:product.thanos.10jqka.com.cn/172.20.208.115:80] The connection observed an error io.netty.handler.timeout.ReadTimeoutException: null 2021-11-04 10:58:32 [reactor-http-epoll-3] ERROR org.apache.shenyu.plugin.httpclient.WebClientPlugin - null io.netty.handler.timeout.ReadTimeoutException: null 2021-11-04 10:58:32 [reactor-http-epoll-3] ERROR org.apache.shenyu.web.handler.GlobalErrorHandler - [e9ba400] Resolved [ReadTimeoutException: null] for HTTP GET /prometheus/api/v1/query 2021-11-04 10:58:32 [reactor-http-epoll-3] ERROR org.springframework.boot.autoconfigure.web.reactive.error.AbstractErrorWebExceptionHandler - [e9ba400] 500 Server Errorfor HTTP GET "/prometheus/api/v1/query?query=rate

%28recv_packet_total%7Bsource%21%3D%22cffex%22%2Ctarget%3D~%22cffex.%2A%22%7D%5B5m%5D%29&time=2021-11-04T02%3A58%3A28.564680692Z" io.netty.handler.timeout.ReadTimeoutException: null 2021-11-04 10:58:32 [reactor-http-epoll-3] ERROR reactor.core.publisher.Operators - Operator called default onErrorDropped java.lang.NullPointerException: null 2021-11-04 10:58:32 [reactor-http-epoll-3] WARN io.netty.channel.AbstractChannelHandlerContext - An exception 'reactor.core.Exceptions$BubblingException: java.lang.NullPointerException' [enable DEBUG level for full stacktrace] was

thrown by a user handler's exceptionCaught() method while handling the following exception: io.netty.handler.timeout.ReadTimeoutException: null 10:58:39,277 |-INFO in ReconfigureOnChangeTask(born:1634129949276) - Empty watch file list. Disabling

Expected Behavior

No response

Steps To Reproduce

No response

Environment

ShenYu version(s):2.4.0

Debug logs

No response

Anything else?

No response

dongxl123 avatar Nov 05 '21 03:11 dongxl123

I have the same problem.

MarsOu1995 avatar Nov 08 '21 02:11 MarsOu1995

config this, or use 2.4.1

shenyu:
#  httpclient:
#    strategy: webClient
#    connectTimeout: 45000
#    readTimeout: 3000
#    writeTimeout: 3000
#    wiretap: false
#    pool:
#      type: ELASTIC
#      name: proxy
#      maxConnections: 16
#      acquireTimeout: 45000
#    proxy:
#      host:
#      port:
#      username:
#      password:
#      nonProxyHostsPattern:
#    ssl:
#      useInsecureTrustManager: false
#      trustedX509Certificates:
#      handshakeTimeout:
#      closeNotifyFlushTimeout:
#      closeNotifyReadTimeout:
#      defaultConfigurationType:

yu199195 avatar Nov 08 '21 03:11 yu199195

see this : https://github.com/apache/incubator-shenyu/issues/1730

yu199195 avatar Nov 08 '21 03:11 yu199195

config this, or use 2.4.1

shenyu:
#  httpclient:
#    strategy: webClient
#    connectTimeout: 45000
#    readTimeout: 3000
#    writeTimeout: 3000
#    wiretap: false
#    pool:
#      type: ELASTIC
#      name: proxy
#      maxConnections: 16
#      acquireTimeout: 45000
#    proxy:
#      host:
#      port:
#      username:
#      password:
#      nonProxyHostsPattern:
#    ssl:
#      useInsecureTrustManager: false
#      trustedX509Certificates:
#      handshakeTimeout:
#      closeNotifyFlushTimeout:
#      closeNotifyReadTimeout:
#      defaultConfigurationType:

the latest version(2.4.2-SNAPSHOT) also has this same bug,I'll try with this configuration...

shenzulun avatar Nov 11 '21 07:11 shenzulun

@shenzulun Have you solved it?

qicz avatar Dec 30 '21 10:12 qicz

2.4.3 also has this same bug

haitun521 avatar Jul 04 '22 09:07 haitun521

Just in case it helps.

I had the same error in a personal project and I was able to solve it. I was using webClient ('org.springframework.boot:spring-boot-starter-webflux:2.7.1') for async calls and getting this annoying errors polluting stderr:

14:39:38.128 [reactor-http-nio-4] ERROR r.n.http.client.HttpClientConnect - [id: 0x05f49b52, L::60850 - R:] The connection observed an error
io.netty.handler.timeout.ReadTimeoutException: null

This code was throwing the errors:

return webClient.get().uri(url).retrieve().bodyToFlux(String.class)
        .timeout(timeout); // <---- The problem is here, it is throwing ReadTimeoutException logging the error.

It is possible to manually solve the error for each timeout, in the code it is done with:

.timeout(duration, Mono.error(new TimeoutException("Response took longer than timeout: " + duration)))

Adding this line to the application.properties file(s) will prevent all these logs by default (we can log the exception with flux methods like onErrorContinue, ...):

logging.level.reactor.netty.http.client.HttpClient=OFF

I have searched in this project and there are several timeouts: timeoouts-in-project I think that this issue can be solved by checking all the usages of WebClient and timeouts and/or disabling netty logs.

See the pull request.

Rubenmp avatar Jul 08 '22 16:07 Rubenmp

@dongxl123 @MarsOu1995 @haitun521 Please try the latest code, and if there are still questions, please submit a new issue.

loongs-zhang avatar Aug 04 '22 14:08 loongs-zhang