background

A common question in Java Web/Spring Boot development is:

  • Page 404, why not access?
  • Login failed, request return 401, which Filter is blocking my request?

This is often a headache, especially in an online environment.

This article describes using Arthas, Alibaba’s open source Java diagnostic tool, to quickly locate such Web request 404/401 problems.

  • Github.com/alibaba/art…

The process by which a request is processed in the Java Web

Before we get down to business, let’s review our knowledge. A typical Java Web request processing flow might look something like this:

Request  -> Filter1 -> Filter2 ... -> Servlet
                                        |
Response <- Filter1 <- Filter2 ... <- Servlet
Copy the code

Demo

The introduction of this article is based on a very simple Demo: github.com/hengyunabc/…

  • Visit http://localhost:8080/, return to 200, and print Welconme information as normal
  • Visit http://localhost:8080/a.txt, back to 404
  • Visit http://localhost:8080/admin, back to 401

Which Servlet returned 404?

The Demo starts, visit: http://localhost:8080/a.txt, return 404:

$ curl http://localhost:8080/a.txt
{"timestamp": 1546790485831,"status": 404,"error":"Not Found"."message":"No message available"."path":"/a.txt"}
Copy the code

We know that an HTTP Request is most often handled by a Servlet, so which Servlet returns 404?

We use Arthas’s trace command to locate:

$ trace javax.servlet.Servlet *
Press Ctrl+C to abort.
Affect(class-cnt:7 , method-cnt:185) cost in 1018 ms.
Copy the code

And then visit http://localhost:8080/a.txt, Arthas will print out the request tree, the complete output is too long, here only capture a key output:

+ -- -- -13.087083ms] org.springframework.web.servlet.DispatcherServlet:resolveViewName()
|   `---[13.020984ms] org.springframework.web.servlet.DispatcherServlet:resolveViewName()
|       +---[0.002777ms] java.util.List:iterator()
|       +---[0.001955ms] java.util.Iterator:hasNext()
|       +---[0.001739ms] java.util.Iterator:next()
|       `---[12.891979ms] org.springframework.web.servlet.ViewResolver:resolveViewName()
|           +---[0.089811ms] javax.servlet.GenericServlet:<init>()
|           +---[min=0.037696ms,max=0.054478ms,total=0.092174ms,count=2] org.springframework.web.servlet.view.freemarker.FreeMarkerView$GenericServletAdapter:<init>()
Copy the code

As you can see, the request is processed by Spring MVC’s DispatcherServlet and eventually dispatched by the ViewResolver to FreeMarkerView$GenericServletAdapter. So we know that the request is ultimately handled by FreeMarker. Check the FreeMarker configuration later.

How does this amazing trace javax.servlet.Servlet * work?

Arthas actually matches all classes in the JVM that implement Javax.servlet. servlet and then traces all of their functions, so the HTTP request is printed out.

Leave a little problem here, why only visited http://localhost:8080/a.txt, but the trace of Arthas command to print out the two requests tree?

Which Filter returns 401?

In the Demo, go to http://localhost:8080/admin and will return to 401, which have no jurisdiction. So which Filter intercepts the request?

$ curl http://localhost:8080/admin
{"timestamp": 1546794743674,"status": 401,"error":"Unauthorized"."message":"admin filter error."."path":"/admin"}
Copy the code

Arthas trace is used again, but this time javax.servlet.filter is traced:

$ trace javax.servlet.Filter *
Press Ctrl+C to abort.
Affect(class-cnt:13 , method-cnt:75) cost in 278 ms.
Copy the code

Go to Admin again, and in Arthas, print the entire request as a tree through which filters are processed. Here’s the key excerpt:

+ -- -- -0.704625ms] org.springframework.web.filter.OncePerRequestFilter:doFilterInternal()
|   `---[0.60387ms] org.springframework.web.filter.RequestContextFilter:doFilterInternal()
|       +---[0.022704ms] org.springframework.web.context.request.ServletRequestAttributes:<init>()
|       +---[0.217636ms] org.springframework.web.filter.RequestContextFilter:initContextHolders()
|       |   `---[0.180323ms] org.springframework.web.filter.RequestContextFilter:initContextHolders()
|       |       +---[0.034656ms] javax.servlet.http.HttpServletRequest:getLocale()
|       |       +---[0.0311ms] org.springframework.context.i18n.LocaleContextHolder:setLocale()
|       |       +---[0.008691ms] org.springframework.web.context.request.RequestContextHolder:setRequestAttributes()
|       |       `---[0.014918ms] org.apache.commons.logging.Log:isDebugEnabled()
|       +---[0.215481ms] javax.servlet.FilterChain:doFilter()
|       |   `---[0.072186ms] com.example.demo404401.AdminFilterConfig$AdminFilter:doFilter()
|       |       `---[0.021945ms] javax.servlet.http.HttpServletResponse:sendError()
Copy the code

Can see HTTP Request is ultimately be com. Example. Demo404401. AdminFilterConfig $AdminFilter processing.

conclusion

  • You can quickly locate Java Web problems by tracing Servlet/Filter
  • Trace is a great tool for understanding how your application executes, as long as you trace it to a key interface or class
  • Looking closely at the results of the trace, you can learn that Spring MVC handles the details of Web requests

link

  • Github.com/alibaba/art…
  • Alibaba. Making. IO/arthas/trac…

Arthas is soliciting users and your use is our greatest support. If Arthas can help you troubleshoot problems, please register under this Issue and become Arthas Contributor within 30 minutes:

Github.com/alibaba/art…