How to debug feign client read time out exception or error?
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] at
2. The solution
2.1 The details of the problem
➜ nacos-feign ./start.sh 8086[INFO] Scanning for projects...[INFO][INFO] ------------------------------------------------------------------------[INFO] Building nacos-feign 0.0.1-SNAPSHOT[INFO] ------------------------------------------------------------------------[INFO][INFO] --- maven-clean-plugin:3.1.0:clean (default-clean) @ nacos-feign ---[INFO][INFO] >>> spring-boot-maven-plugin:2.1.18.RELEASE:run (default-cli) > test-compile @ nacos-feign >>>[INFO][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][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][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][INFO] --- maven-compiler-plugin:3.8.1:testCompile (default-testCompile) @ nacos-feign ---[INFO] Changes detected - recompiling the module![INFO][INFO] <<< spring-boot-maven-plugin:2.1.18.RELEASE:run (default-cli) < test-compile @ nacos-feign <<<[INFO][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: default2022-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 feign.Logger;import org.springframework.context.annotation.Bean;
public class FeignConfig { @Bean 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 feign.Logger;import org.springframework.context.annotation.Bean;
public class FeignConfig { @Bean 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;
import java.util.Map;
@FeignClient(name="nacos-provider-bswencw1", configuration = FeignConfig.class)public interface DemoClient { @GetMapping("hello") 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: port: 8086spring: application: name: nacos-feign cloud: nacos: discovery: server-addr: 10.1.1.1:8848logging: level: root: ERROR org.springframework.web: ERROR com.example: DEBUG
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: default2022-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.12022-02-18 15:36:16.405 DEBUG 45588 --- [nio-8086-exec-1] c.example.nacosfeign.clients.DemoClient : [DemoClient#hello] Content-Length: 22022-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-82022-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] aa2022-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!