如何分析 spring mvc 应用程序的页面请求

Posted 2023-03-06

【中文标题】如何分析 spring mvc 应用程序的页面请求

【英文标题】：how to profile a page request for a spring mvc app

【发布时间】：2010-09-07 18:35:38

【问题描述】：

在 spring mvc 应用程序中我必须使用哪些选项来分析页面请求？

我想详细了解页面请求所需的时间，以及各个阶段，例如渲染 freemarker 模板、休眠数据库调用等所需的时间。

【问题讨论】：

对于负载和性能测试，我建议看看jmeter.apache.org

【参考方案1】：

我们刚刚使用拦截器和自定义标签完成了类似的操作。这个解决方案足够“轻”，可以在生产中使用，它的数据在响应的底部显示为 html cmets，并允许您使用请求参数选择更详细的日志记录。您将下面的拦截器应用于要分析的所有请求路径，并将自定义标记添加到所需页面的底部。自定义标签的位置很重要；它应该在尽可能接近请求处理结束时被调用，因为它只知道在调用之前花费的时间（和加载的对象）。

package com.foo.web.interceptor;

import javax.servlet.http.HttpServletRequest;
import javax.servlet.http.HttpServletResponse;

import org.springframework.web.servlet.ModelAndView;
import org.springframework.web.servlet.handler.HandlerInterceptorAdapter;

public class PageGenerationTimeInterceptor extends HandlerInterceptorAdapter 

    public static final String PAGE_START_TIME = "page_start_time";
    public static final String PAGE_GENERATION_TIME = "page_generation_time";

    public boolean preHandle(HttpServletRequest request, HttpServletResponse response,
            Object handler) throws Exception 
        request.setAttribute(PAGE_START_TIME, new Long(System.currentTimeMillis()));
        return true;
    

    public void postHandle(HttpServletRequest request, HttpServletResponse response,
            Object handler, ModelAndView modelAndView) throws Exception 
        Long startTime = (Long) request.getAttribute(PAGE_START_TIME);
        if (startTime != null) 
            request.setAttribute(PAGE_GENERATION_TIME, new Long(System.currentTimeMillis() - startTime.longValue()));
        
    

自定义标签查找请求属性，并使用它们来计算处理程序时间、查看时间和总时间。它还可以查询当前 Hibernate 会话以获取第一级缓存统计信息，这可以揭示处理程序和视图加载了多少对象。如果不需要 Hibernate 信息，可以删除 if 大块。

package com.foo.web.taglib;

import java.io.IOException;
import java.util.HashMap;
import java.util.Map;
import java.util.SortedSet;
import java.util.TreeSet;

import javax.servlet.ServletContext;
import javax.servlet.jsp.JspException;
import javax.servlet.jsp.JspWriter;
import javax.servlet.jsp.tagext.Tag;
import javax.servlet.jsp.tagext.TryCatchFinally;

import org.apache.log4j.LogManager;
import org.apache.log4j.Logger;
import org.hibernate.Session;
import org.hibernate.SessionFactory;
import org.hibernate.engine.CollectionKey;
import org.hibernate.engine.EntityKey;
import org.hibernate.stat.SessionStatistics;
import org.springframework.beans.factory.BeanFactoryUtils;
import org.springframework.context.ApplicationContext;
import org.springframework.web.bind.ServletRequestUtils;
import org.springframework.web.context.support.WebApplicationContextUtils;
import org.springframework.web.servlet.tags.RequestContextAwareTag;

import com.foo.web.interceptor.PageGenerationTimeInterceptor;

public class PageInfoTag extends RequestContextAwareTag implements TryCatchFinally 
    private static final long serialVersionUID = -8448960221093136401L;
    private static final Logger LOGGER = LogManager.getLogger(PageInfoTag.class);
    public static final String SESSION_STATS_PARAM_NAME = "PageInfoTag.SessionStats";

    @Override
    public int doStartTagInternal() throws JspException 
        try 
            JspWriter out = pageContext.getOut();
            Long startTime = (Long)pageContext.getRequest().getAttribute(PageGenerationTimeInterceptor.PAGE_START_TIME);
            Long handlerTime = (Long)pageContext.getRequest().getAttribute(PageGenerationTimeInterceptor.PAGE_GENERATION_TIME);
            if (startTime != null && handlerTime != null) 
                long responseTime = System.currentTimeMillis() - startTime.longValue();
                long viewTime = responseTime - handlerTime;
                out.append(String.format("<!-- total: %dms, handler: %dms, view: %dms -->", responseTime, handlerTime, viewTime));
            
            if (ServletRequestUtils.getBooleanParameter(pageContext.getRequest(), SESSION_STATS_PARAM_NAME, false)) 
                //write another long HTML comment with information about contents of Hibernate first-level cache
                ServletContext servletContext = pageContext.getServletContext();
                ApplicationContext context =  WebApplicationContextUtils.getRequiredWebApplicationContext(servletContext);
                String[] beans = BeanFactoryUtils.beanNamesForTypeIncludingAncestors(context,
                        SessionFactory.class, false, false);

                if (beans.length > 0) 
                    SessionFactory sessionFactory = (SessionFactory) context.getBean(beans[0]);
                    Session session = sessionFactory.getCurrentSession();
                    SessionStatistics stats = session.getStatistics();
                    Map<String, NamedCount> entityHistogram = new HashMap<String, NamedCount>();
                    out.append("\n<!-- session statistics:\n");
                    out.append("\tObject keys (").append(String.valueOf(stats.getEntityCount())).append("):\n");
                    for (Object obj: stats.getEntityKeys()) 
                        EntityKey key = (EntityKey)obj;
                        out.append("\t\t").append(key.getEntityName()).append("#").append(key.getIdentifier().toString()).append("\n");
                        increment(entityHistogram, key.getEntityName());
                    
                    out.append("\tObject key histogram:\n");
                    SortedSet<NamedCount> orderedEntityHistogram = new TreeSet<NamedCount>(entityHistogram.values());
                    for (NamedCount entry: orderedEntityHistogram) 
                        out.append("\t\t").append(entry.name).append(": ").append(String.valueOf(entry.count)).append("\n");
                    
                    Map<String, NamedCount> collectionHistogram = new HashMap<String, NamedCount>();
                    out.append("\tCollection keys (").append(String.valueOf(stats.getCollectionCount())).append("):\n");
                    for (Object obj: stats.getCollectionKeys()) 
                        CollectionKey key = (CollectionKey)obj;
                        out.append("\t\t").append(key.getRole()).append("#").append(key.getKey().toString()).append("\n");
                        increment(collectionHistogram, key.getRole());
                    
                    out.append("\tCollection key histogram:\n");
                    SortedSet<NamedCount> orderedCollectionHistogram = new TreeSet<NamedCount>(collectionHistogram.values());
                    for (NamedCount entry: orderedCollectionHistogram) 
                        out.append("\t\t").append(entry.name).append(": ").append(String.valueOf(entry.count)).append("\n");
                    
                    out.append("-->");
                
            
         catch (IOException e) 
            LOGGER.error("Unable to write page info tag");
            throw new RuntimeException(e);
        
        return Tag.EVAL_BODY_INCLUDE;
    

    protected void increment(Map<String, NamedCount> histogram, String key) 
        NamedCount count = histogram.get(key);
        if (count == null) 
            count = new NamedCount(key);
            histogram.put(key, count);
        
        count.count++;
    

    class NamedCount implements Comparable<NamedCount>  
        public String name;
        public int count;

        public NamedCount(String name) 
            this.name = name;
            count = 0;
        

        @Override
        public int compareTo(NamedCount other) 
            //descending count, ascending name
            int compared = other.count - this.count;
            if (compared == 0) 
                compared = this.name.compareTo(other.name);
            
            return compared;
        
    

【参考方案2】：

看这里：

Profiling with Eclipse and remote profile agents on Linux

Tutorial: Profiling with TPTP and Tomcat

An introduction to profiling Java applications using TPTP

TPTP = Eclipse 测试和性能工具平台

堆栈的更多链接：

Open Source Profilers in Java