我正在使用 Spring Boot 编写一个 Web Rest web 服务。
我想记录我的网络服务处理请求所花费的时间。 我还想记录标题、方法和调用的 URI。
几个月前我在我的球衣网络服务中使用ContainerRequestFilter and ContainerResponseFilter filter() method.做了类似的事情
另外，AOP 更好还是过滤？
【问题讨论】：
spring-boot-actuator，它已经为您记录了。
标签： java spring logging spring-boot
你试过这样的基本过滤器吗？
import java.io.IOException;
import javax.servlet.*;
import javax.servlet.annotation.WebFilter;
import javax.servlet.http.HttpServletRequest;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
@Component
@WebFilter("/*")
public class StatsFilter implements Filter {
private static final Logger LOGGER = LoggerFactory.getLogger(StatsFilter.class);
@Override
public void init(FilterConfig filterConfig) throws ServletException {
// empty
}
@Override
public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain) throws IOException, ServletException {
long time = System.currentTimeMillis();
try {
chain.doFilter(req, resp);
} finally {
time = System.currentTimeMillis() - time;
LOGGER.trace("{}: {} ms ", ((HttpServletRequest) req).getRequestURI(), time);
}
}
@Override
public void destroy() {
// empty
}
}
已编辑：（感谢@suren-aznauryan）
现在，它使用Instant 和Duration 并避免System.currentTimeMillis()。
import java.io.IOException;
import java.time.Duration;
import java.time.Instant;
import javax.servlet.*;
import javax.servlet.annotation.WebFilter;
import javax.servlet.http.HttpServletRequest;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
@Component
@WebFilter("/*")
public class StatsFilter implements Filter {
private static final Logger LOGGER = LoggerFactory.getLogger(StatsFilter.class);
@Override
public void init(FilterConfig filterConfig) throws ServletException {
// empty
}
@Override
public void doFilter(ServletRequest req, ServletResponse resp, FilterChain chain) throws IOException, ServletException {
Instant start = Instant.now();
try {
chain.doFilter(req, resp);
} finally {
Instant finish = Instant.now();
long time = Duration.between(start, finish).toMillis();
LOGGER.trace("{}: {} ms ", ((HttpServletRequest) req).getRequestURI(), time);
}
}
@Override
public void destroy() {
// empty
}
}
【讨论】：
@Order(Ordered.HIGHEST_PRECEDENCE)docs.spring.io/spring-framework/docs/current/javadoc-api/org/…
System.currentTimeMillis() 不是测量经过时间的安全方法（请参阅this post）
我们可以通过覆盖add()方法来使用Springboot InMemoryHttpTraceRepository
public class MyCustomTraceRepository extends InMemoryHttpTraceRepository {
@Override
public void add(HttpTrace trace) {
log(trace);
super.add(trace);
}
//Log only you interested in
public void log(HttpTrace trace) {
Map<String, Object> traceMap = new LinkedHashMap<>();
traceMap.put("status", trace.getResponse().getStatus());
traceMap.put("method", trace.getRequest().getMethod());
traceMap.put("uri", trace.getRequest().getUri().getPath());
traceMap.put("timeTaken", trace.getTimeTaken());
logger.info(traceMap)
}
}
//will Result into
{status=<>, method=<>, uri=/<>, timeTaken=<>}
@查看更多请求和响应跟踪选项：https://docs.spring.io/spring-boot/docs/current/actuator-api/html/#http-trace
【讨论】：
Spring boot：日志拦截器
public class ApiLogger extends HandlerInterceptorAdapter {
private static final Logger logger = LoggerFactory
.getLogger(ApiLogger.class);
@Override
public boolean preHandle(HttpServletRequest request, HttpServletResponse response, Object handler) throws Exception {
String requestId = UUID.randomUUID().toString();
log(request,response, requestId);
long startTime = System.currentTimeMillis();
request.setAttribute("startTime", startTime);
request.setAttribute("requestId", requestId);
return true;
}
@Override
public void afterCompletion(HttpServletRequest request, HttpServletResponse response, Object handler, Exception ex) throws Exception {
super.afterCompletion(request, response, handler, ex);
long startTime = (Long)request.getAttribute("startTime");
long endTime = System.currentTimeMillis();
long executeTime = endTime - startTime;
logger.info("requestId {}, Handle :{} , request take time: {}",request.getAttribute("requestId"), handler, executeTime);
}
private void log(HttpServletRequest request, HttpServletResponse response, String requestId) {
logger.info("requestId {}, host {} HttpMethod: {}, URI : {}",requestId, request.getHeader("host"),
request.getMethod(), request.getRequestURI() );
}
}
注册拦截器：
@Configuration
@EnableWebMvc
public class AppConfig extends WebMvcConfigurerAdapter {
@Override
public void addInterceptors(InterceptorRegistry registry) {
registry.addInterceptor(new ApiLogger()).addPathPatterns("/api/v1/*");
}
}
【讨论】：
"/api/v1/**"
如果您的控制器是异步的，请使用 Aspect 获得正确且完整的执行时间。
import org.aspectj.lang.ProceedingJoinPoint;
import org.aspectj.lang.annotation.Around;
import org.aspectj.lang.annotation.Aspect;
import org.slf4j.Logger;
import org.slf4j.LoggerFactory;
import org.springframework.stereotype.Component;
import org.springframework.web.context.request.RequestContextHolder;
import org.springframework.web.context.request.ServletRequestAttributes;
import javax.servlet.http.HttpServletRequest;
import java.util.Arrays;
import java.util.UUID;
@Aspect
@Component
public class LoggingAspect {
static Logger log = LoggerFactory.getLogger(LoggingAspect.class);
@Around("execution(* com.aakchoo.api.controller..*(..))")
public Object profileExecutionTime(ProceedingJoinPoint joinPoint) throws Throwable {
long start = System.currentTimeMillis();
String className = joinPoint.getSignature().getDeclaringTypeName();
String methodName = joinPoint.getSignature().getName();
String apiName = className + "."+ methodName;
HttpServletRequest request =
((ServletRequestAttributes) RequestContextHolder.currentRequestAttributes()).getRequest();
String requestId = UUID.randomUUID().toString();
log.info("----->>>>>\nREQUESTED_ID: {}\nHOST: {} HttpMethod: {}\nURI: {}\nAPI: {}\nArguments: {}\n",
requestId,
request.getHeader("host"),
request.getMethod(),
request.getRequestURI(),
apiName,
Arrays.toString(joinPoint.getArgs()));
Object result = joinPoint.proceed();
long elapsedTime = System.currentTimeMillis() - start;
log.info("<<<<<-----\nExecution Time: {} ms [REQUESTED_ID: {}] [API: {}]", elapsedTime,requestId,apiName);
return result;
}
}
将@EnableAspectJAutoProxy 添加到您的应用程序类
@EnableAsync
@SpringBootApplication
@EnableAspectJAutoProxy
public class Application {
public static void main(String[] args) {
SpringApplication.run(Application.class, args);
}
}
您的 build.gradle 将需要以下内容
compile 'org.aspectj:aspectjweaver:1.8.10'
compile 'org.springframework.boot:spring-boot-starter-aop'
【讨论】：
joinPoint.proceed() 抛出异常怎么办？
David 的回答是正确的 - 过滤器是在 Spring Boot 中实现此类功能的好方法。
Spring Boot 有一个 built-in endpoint，它返回有关最近 100 个请求的信息，如下所示：
[{
"timestamp": 1394343677415,
"info": {
"method": "GET",
"path": "/trace",
"headers": {
"request": {
"Accept": "text/html,application/xhtml+xml,application/xml;q=0.9,*/*;q=0.8",
"Connection": "keep-alive",
"Accept-Encoding": "gzip, deflate",
"User-Agent": "Mozilla/5.0 Gecko/Firefox",
"Accept-Language": "en-US,en;q=0.5",
"Cookie": "_ga=GA1.1.827067509.1390890128; ..."
"Authorization": "Basic ...",
"Host": "localhost:8080"
},
"response": {
"Strict-Transport-Security": "max-age=31536000 ; includeSubDomains",
"X-Application-Context": "application:8080",
"Content-Type": "application/json;charset=UTF-8",
"status": "200"
}
}
}
},{
"timestamp": 1394343684465,
...
}]
如果您的应用程序正在调用其他服务或查询数据库，请考虑使用Sniffy 进行分析 - 它不仅会显示您在服务器上花费的时间，还会显示调用下游系统所花费的时间。观看现场演示 here（检查顶部底部角落的黑色小部件）。
免责声明：我是Sniffy的作者
【讨论】：