2013-08-17 3 views
0

, учитывая приведенный ниже код, как я могу регистрировать время с запросом, только когда поток заканчивается, чтобы получить только один окончательный RequestTime?Перехватить Thead в веб-приложении

@Override 
public void doFilter(ServletRequest request, ServletResponse response, FilterChain filterChain) throws IOException, ServletException { 
    new ClientRequestContextHolder(); 
    logger.info("request filter ("+ ClientRequestContextHolder.getContext().getAttribute("uniqueId") +") started"); 
    filterChain.doFilter(request, response); 
    logger.info("request filter ("+ ClientRequestContextHolder.getContext().getAttribute("uniqueId") +") finished"); 
    long st = (long)ClientRequestContextHolder.getContext().getAttribute("request_start"); 
    logger.info("RequestTime: " + customFormat("###,###.###",(System.nanoTime() - st)) + "ns"); 

} 

мой текущий результат выглядит следующим образом

INFO : com.app.context.ClientRequestContextHolder - initialized 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 7,958,694ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 12,657,404ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 13,942,554ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 14,579,297ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 16,428,276ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 17,329,786ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) started 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 42,787,490ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 43,226,233ns 
INFO : com.app.filters.ClientRequestFilter - request filter (34) finished 
INFO : com.app.filters.ClientRequestFilter - RequestTime: 45,455,568ns 
+0

Вы говорите, что одно исполнение этого кода вызывает нижний вывод? –

+0

Это другие веб-ресурсы, которые были опрошены –

ответ

0

получил.

поскольку фильтр chaing рекурсивный, я просто добавил к нему глубокий контроль. В финале, если глубокий - 0, я вычисляю результат печати.