使用Perf4J对Liferay进行性能分析和监控

      Liferay的性能一直都让大家关注，运行他的demo，也许每个版本都会给人一点惊喜，包括后台的一些变化，也许你看到他的速度似乎是变快了，而我觉得从4.4开始，速度并没有太大的变化（表现形式强了不少），但是还是可以接受的。而我们更需要关注的应该是稳定性方面的问题，因为在发布到生产环境的时候性能经常会不可思议的大幅下降。更糟糕的是，应用程序平时运行正常，老板或者重要客户或碰上大规模操作应用的时候却反应缓慢，甚至出错down掉。详细的日志记录和分析对于追踪这些间歇性的性能瓶颈尤为重要。所以在这里介绍用Perf4j去完成liferay来进行性能分析和监控工作。也许你会说用Jprofiler或Jprobe，或者用LR来对程序进行监控和测试，但是这些工具总是耗时而且当你只想监控某个方法的时候，这些工具是显得如此的笨重，特别在生产环境下，通过网络，很难对其进行监控。所以选择了Perf4J对日常的操作进行监控。

     在Liferay中配置Perf4J并不困难，配合Log4J来使用，为了使用异步的Appender，所以Log4j的配置用xml文件。
步骤如下：

 

1）添加所需的jar包到/WEB-INF/lib中

2）配置log4j.xml

<log4j:configuration xmlns:log4j="http://jakarta.apache.org/log4j/">


<appender name="CONSOLE" class="org.apache.log4j.ConsoleAppender">


<layout class="org.apache.log4j.PatternLayout">


<param name="ConversionPattern" value="%d{ABSOLUTE} %-5p [%c{1}:%L] %m%n" />


</layout>


</appender>


<!-- Perf4J appenders -->


<!--


This AsyncCoalescingStatisticsAppender groups StopWatch log messages


into GroupedTimingStatistics messages which it sends on the


downstream appenders defined below


-->


<appender name="CoalescingStatistics"


class="org.perf4j.log4j.AsyncCoalescingStatisticsAppender">


<!--


The TimeSlice option is used to determine the time window for which


all received StopWatch logs are aggregated to create a single


GroupedTimingStatistics log. Here we set it to 10 seconds, overriding


the default of 30000 ms


-->


<param name="TimeSlice" value="10000"/>


<appender-ref ref="fileAppender"/>


<!--


Note how the GraphingStatisticsAppenders have been attached to the


CoalescingStatistics here.


-->


<appender-ref ref="graphExecutionTimes"/>


<appender-ref ref="graphExecutionTPS"/>


</appender>


<!-- This file appender is used to output aggregated performance statistics -->


<appender name="fileAppender" class="org.apache.log4j.DailyRollingFileAppender">


<param name="File" value="${catalina.base}/logs/liferay/perfStats.log"/>


<layout class="org.apache.log4j.PatternLayout">


<param name="ConversionPattern" value="%m%n"/>


</layout>


</appender>


<!--


This first GraphingStatisticsAppender graphs Mean execution times for the


firstBlock and secondBlock tags


-->


<appender name="graphExecutionTimes"


class="org.perf4j.log4j.GraphingStatisticsAppender">


<!-- Possible GraphTypes are Mean, Min, Max, StdDev, Count and TPS -->


<param name="GraphType" value="Mean"/>


<appender-ref ref="graphsFileAppender"/>


</appender>


<!--


This second GraphingStatisticsAppender graphs transactions per second


for the firstBlock and secondBlock tags


-->


<appender name="graphExecutionTPS"


class="org.perf4j.log4j.GraphingStatisticsAppender">


<param name="GraphType" value="TPS"/>


<appender-ref ref="graphsFileAppender"/>


</appender>


<!--


This file appender is used to output the graph URLs generated


by the GraphingStatisticsAppenders


-->


<appender name="graphsFileAppender" class="org.apache.log4j.DailyRollingFileAppender">


<param name="File" value="${catalina.base}/logs/liferay/perfGraphs.log"/>


<layout class="org.apache.log4j.PatternLayout">


<param name="ConversionPattern" value="%m%n"/>


</layout>


</appender>


<logger name="org.perf4j.TimingLogger" additivity="false">


<level value="INFO"/>


<appender-ref ref="CoalescingStatistics"/>


</logger>

 3)如果要在运行中查看监控图片，则需要在web.xml中添加

<servlet>


<servlet- name>perf4j</servlet- name>


<servlet- class>org.perf4j.log4j.servlet.GraphingServlet</servlet-class>


<init-param>


<param- name>graphNames</param-name>


<param- value>graphExecutionTimes,graphExecutionTPS</param-value>


</init-param>


</servlet>


<servlet-mapping>


<servlet- name>perf4j</servlet- name>


<url- pattern>/perf4j</url- pattern>


</servlet- mapping>

 4)Liferay中调用perf4j，三种方式：

①编码方式，侵入性强，但是可以在任何地方调用，我觉得liferay的编码有点乱，而且很多写在页面上，所以这种方式挺适合liferay的

StopWatch stopWatch = new Slf4JStopWatch();


……


……


……


stopWatch.stop("loginCheck");

 

②Annotation方式

配置
<aop:aspectj-autoproxy/>
<!--
Declare the TimingAspect that we want to weave into the other beans
defined in this config file.
-->
<bean id="timingAspect" class="org.perf4j.log4j.aop.TimingAspect"/>

 注：在liferay的主程序中，定义bean timingAspect，你会发现tomcat启动的时候会在读取bean之后停住不往下进行，没花太多的时间去找原因，有兴趣的朋友可以看看是不是有这个情况并找找原因和大家分享。而这个配置在liferay插件形式开发的插件上定义，完全运行良好。

@Profiled(tag = "getCompanies")
public List getCompanies() throws SystemException {
return companyPersistence.findAll();
}

应用条件
* Any objects to be woven must exist as Spring-managed beans declared in the Spring container. This is necessary because, in order to wrap object instances with the required proxies, the Spring container needs to control the lifecycle of your objects.
* Any method being @Profiled MUST be a public method.
* If you have a method on your spring bean that calls another @Profiled method directly, then that method will NOT be timed as you will not be going through the Spring proxy to make the call. Note this is NOT the case when using AspectJ directly. The Spring documentation explains the effect proxies have on AOP-enabled methods.

③Aop拦截器方式，当你想对某一些类每个方法进行监控的时候，上面两个方式显然工作量很大，所以写个拦截器（完全是懒人的做法，一般不会每个方法都监控，测试时候也许会这样玩玩）
spring定义

<bean id="perf4jInterceptor" class="com.liferay.portal.interceptor.Perf4jInterceptor"/>
<bean class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
<property name="beanNames">
<list>
<value>*Finder.impl</value>
</list>
</property>
<property name="interceptorNames">
<list>
<value>perf4jInterceptor</value>
</list>
</property>
</bean>

 拦截器编写(tag名为"className_methodName")

public class Perf4jInterceptor implements MethodBeforeAdvice, AfterReturningAdvice {
private Map<String, StopWatch> watches = new HashMap<String, StopWatch>();
public void before(Method method, Object[] args, Object target) throws Throwable {
String completeMethodName = getCompleteMethodName(target, method);
// 创建性能日志记录器
StopWatch stopWatch;
if (watches.containsKey(completeMethodName)) {
stopWatch = watches.get(completeMethodName);
stopWatch.start();
} else {
stopWatch = new Slf4JStopWatch(completeMethodName, Arrays.toString(args));
watches.put(completeMethodName, stopWatch);
}
}
public void afterReturning(Object returnValue, Method method, Object[] args, Object target) throws Throwable {
String completeMethodName = getCompleteMethodName(target, method);
// 记录性能
if (watches.containsKey(completeMethodName)) {
StopWatch stopWatch = watches.get(completeMethodName);
stopWatch.stop();
}
}
/**
* 根据目标对象与方法获取方法完整名称.
* @param target 目标对象
* @param method 方法
* @return 方法完整名称
*/
private String getCompleteMethodName(Object target, Method method) {
String className = "";
if (target != null) {
className = target.toString();
int loc = className.indexOf("@");
if (loc >= 0) {
className = className.substring(className.lastIndexOf(".") + 1, loc);
}
}
return className + "_" + method.getName();
}
}

 

监控结果：
Log文件：

图形界面：

有兴趣的朋友不妨配置试试，但工具只能给我们分析问题时候带来方便和可能，而真正重要的还是分析这些数据的能力，然后才能具备解决问题的能力。有兴趣的朋友也来和大家分享一下经验吧！

评论

2 楼 rosanu 2013-10-15  

您好，请问Log文件怎么生成图形界面呢？

1 楼 javaray 2010-07-13  

遨豪(大连)科技有限公司自 2007年与Liferay,Inc合作，并帮助其建立Liferay中国分公司及支持中心，同时也是中国目前第一家唯一合作伙伴，主要负责 Liferay产品的本地化服务，包括本地化培训和Liferay企业版服务，研发中心位于大连市高新技术产业园区。www.aukcell.com