Purpose
In this post, I will demonstrate how to debug the following error when using Feign:
2022-02-18 15:29:38.417 ERROR 44793 --- [nio-8086-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is feign.RetryableException: Read timed out executing GET http://nacos-provider-bswencw1/hello] with root cause
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0( Native Method ) ~ [na:1.8.0_121]
at java.net.SocketInputStream.socketRead( SocketInputStream . java : 116 ) ~ [na:1.8.0_121]
at java.net.SocketInputStream.read( SocketInputStream . java : 171 ) ~ [na:1.8.0_121]
at java.net.SocketInputStream.read( SocketInputStream . java : 141 ) ~ [na:1.8.0_121]
at java.io.BufferedInputStream.fill( BufferedInputStream . java : 246 ) ~ [na:1.8.0_121]
at java.io.BufferedInputStream.read1( BufferedInputStream . java : 286 ) ~ [na:1.8.0_121]
at java.io.BufferedInputStream.read( BufferedInputStream . java : 345 ) ~ [na:1.8.0_121]
at sun.net.www.http.HttpClient.parseHTTPHeader( HttpClient . java : 704 ) ~ [na:1.8.0_121]
at sun.net.www.http.HttpClient.parseHTTP( HttpClient . java : 647 ) ~ [na:1.8.0_121]
2. The solution
2.1 The details of the problem
➜ nacos-feign ./start.sh 8086
[INFO] Scanning for projects...
[INFO] ------------------------------------------------------------------------
[INFO] Building nacos-feign 0.0.1-SNAPSHOT
[INFO] ------------------------------------------------------------------------
[INFO] --- maven-clean-plugin:3.1.0:clean ( default-clean ) @ nacos-feign ---
[INFO] >>> spring-boot-maven-plugin:2.1.18.RELEASE:run ( default-cli ) > test-compile @ nacos-feign >>>
[INFO] --- maven-resources-plugin:3.1.0:resources ( default-resources ) @ nacos-feign ---
[INFO] Using ' UTF-8 ' encoding to copy filtered resources.
[INFO] Copying 1 resource
[INFO] Copying 0 resource
[INFO] --- maven-compiler-plugin:3.8.1:compile ( default-compile ) @ nacos-feign ---
[INFO] Changes detected - recompiling the module !
[INFO] Compiling 4 source files to /Users/bswencaiwen/JavaProjects/SpringCloudLearning202202/nacos-feign/target/classes
[INFO] --- maven-resources-plugin:3.1.0:testResources ( default-testResources ) @ nacos-feign ---
[INFO] Using ' UTF-8 ' encoding to copy filtered resources.
[INFO] skip non existing resourceDirectory /Users/bswencaiwen/JavaProjects/SpringCloudLearning202202/nacos-feign/src/test/resources
[INFO] --- maven-compiler-plugin:3.8.1:testCompile ( default-testCompile ) @ nacos-feign ---
[INFO] Changes detected - recompiling the module !
[INFO] <<< spring-boot-maven-plugin:2.1.18.RELEASE:run ( default-cli ) < test-compile @ nacos-feign <<<
[INFO] --- spring-boot-maven-plugin:2.1.18.RELEASE:run ( default-cli ) @ nacos-feign ---
/\\ / ___ ' _ __ _ _(_)_ __ __ _ \ \ \ \
( ( )\___ | ' _ | '_| | ' _ \/ _` | \ \ \ \
\\ / ___) | | _ ) | | | | | || ( _ | | ) ) ) )
' |____| .__|_| |_|_| |_\__, | / / / /
=========|_|==============|___/=/_/_/_/
:: Spring Boot :: (v2.1.18.RELEASE)
2022-02-18 15:28:49.521 INFO 44793 --- [ main] c.e.nacosfeign.NacosFeignApplication : No active profile set, falling back to default profiles: default
2022-02-18 15:28:52.439 INFO 44793 --- [ main] c.e.nacosfeign.NacosFeignApplication : Started NacosFeignApplication in 5.934 seconds (JVM running for 10.224)
2022-02-18 15:29:38.417 ERROR 44793 --- [nio-8086-exec-1] o.a.c.c.C.[.[.[/].[dispatcherServlet] : Servlet.service() for servlet [dispatcherServlet] in context with path [] threw exception [Request processing failed; nested exception is feign.RetryableException: Read timed out executing GET http://nacos-provider-bswencw1/hello] with root cause
java.net.SocketTimeoutException: Read timed out
at java.net.SocketInputStream.socketRead0(Native Method) ~[na:1.8.0_121]
at java.net.SocketInputStream.socketRead(SocketInputStream.java:116) ~[na:1.8.0_121]
at java.net.SocketInputStream.read(SocketInputStream.java:171) ~[na:1.8.0_121]
at java.net.SocketInputStream.read(SocketInputStream.java:141) ~[na:1.8.0_121]
at java.lang.Thread.run(Thread.java:745) [na:1.8.0_121]
2.2 The debug process
We know that spring boot use feign(ribbon) to access remote services registered in a service registry.
But if some errors occur, how to debug this process?
2.3 The solution
We can create a config class to configure feign:
import org.springframework.context.annotation.Bean ;
public class FeignConfig {
Logger . Level feignLoggerLevel () {
return Logger . Level . FULL ;
Notice the Logger
is instance of the class feign.Logger
. There are 4 levels :
NONE
, No logging (DEFAULT ).
BASIC
, Log only the request method and URL and the response status code and execution time.
HEADERS
, Log the basic information along with request and response headers.
FULL
, Log the headers, body, and metadata for both requests and responses.
If you want to show the request URL(including host of the URL) , you can use BASIC
:
import org.springframework.context.annotation.Bean ;
public class FeignConfig {
Logger . Level feignLoggerLevel () {
return Logger . Level . BASIC ;
Then we can configure FeignClient to use the config:
import com.example.nacosfeign.config.FeignConfig ;
import org.springframework.cloud.openfeign.FeignClient ;
import org.springframework.web.bind.annotation.GetMapping ;
@ FeignClient ( name = " nacos-provider-bswencw1 " , configuration = FeignConfig . class )
public interface DemoClient {
Map < String , Object > hello () ;
At last, we should change our app logging level to DEBUG to show the logs:
Say our app’s package is prefixed by com.example
:
server-addr : 10.1.1.1:8848
org.springframework.web : ERROR
Then run the test again, we got this debug info:
2022-02-18 15:35:45.000 INFO 45588 --- [ main] c.e.nacosfeign.NacosFeignApplication : No active profile set, falling back to default profiles: default
2022-02-18 15:35:47.732 INFO 45588 --- [ main] c.e.nacosfeign.NacosFeignApplication : Started NacosFeignApplication in 4.065 seconds (JVM running for 8.322 )
2022-02-18 15:36:16.404 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] --- > GET http://nacos-provider-/hello HTTP/1.1
2022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] Content-Length: 2
2022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] Content-Type: text/plain; charset = UTF-8
2022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello]
2022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] aa
2022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] --- > END HTTP ( 2-byte body )
2022-02-18 15:36:19.253 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] < --- ERROR SocketTimeoutException: Read timed out ( 2847ms )
2022-02-18 15:36:19.254 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] java.net.SocketTimeoutException: Read timed out
It works!
3. Summary
In this post, I demonstrated how to debug the application that is using feign to access remote servcies, the key point is to change the logging level of feign using spring configuration class . That’s it, thanks for your reading.
Final Words + More Resources
My intention with this article was to help others who might be considering solving such a problem.
So I hope that’s been the case here. If you still have any questions, don’t hesitate to ask me by
email: Email me
Here are also the most important links from this article along with some further resources that will help you in this scope:
Oh, and if you found these resources useful, don’t forget to support me by
starring the repo on GitHub !