Small Talks/2009/June/Performance Monitoring of ZK Application

Author
Jiri Bubnik, Project Manager, Datalite, Czech Republic

Date
June 16, 2009

Version
ZK 3.5.x, 3.6.x

Preface

A library for monitoring session runtime information (active desktops, recent requests, timing, call stack) for your ZK application. It is based on ZK PerformanceMeter listener, but provides integration with other frameworks as well.

After monitor is enabled for a session, it collect performance and detail call stack for each request:

• ZK Monitor - ZK PerformanceMeter listener (registered in zk.xml) - it provides basic request timing (client, server, network, javascript on browser) PerformanceMonitor description
• ZK Event listener - intercepts every ZK event and adds event information to call stack with event duration
• Spring AOP interceptor - call stack of spring method invocation (around invoke) with invocation duration
• Toplink essentials logger - adds toplink logs into call stack tree - you can see SQL statements with timing and correct location (e.g. ZK event or Spring bean method)
• LOG4J logger - log appender, you can see any LOG4J log with timing and correct location
• ... you can add your own

You don't need to use all these frameworks - only ZK Monitor is mandatory and provides nice view of ZK PerformanceMeter data. However to leverage full strength and discover performance bottleneck you may find other frameworks useful as well.

Usage

After you add configuration to your application, you can monitor session performance data in your browser. This paragraph uses default page described in this small talk, however you can change it in the configuration.

Open in one browser tab this link: http://yourapp/zk/ZKMonitor and enable session monitoring with "Enable monitor" button.

In other browser tab (with same http session) open your application and work with it for some time. You can always switch to monitor tab, refresh the page and immediately see results.

Example monitor page of running application:

Setup monitor in your application

You will need the DLZKMonitor library to include in classpath. This library provides monitoring capability and the result page. If you want to customize the result page, feel free to change the source code, you can even send me the result.

Download link is in the end of this smalltalk.

Basic ZK monitor

You will need to register ZK PeformanceMonitor listener in zk.xml and create richlet mapping to access monitor result page.

To enable richlets in your application, add this configuration into WEB-INF/web.xml file. Ideal place will be near other zkLoader mappings for zul pages.

   <servlet-mapping>
          <servlet-name>zkLoader</servlet-name>
          <url-pattern>/zk/*</url-pattern>
   </servlet-mapping>

This will map http://yourapp/zk/* requests to customrichlet. You can use any arbitrary path instead of /zk/*.

To add richlet mapping to ZKMonitor result page and register the monitor listener add this configuration into WEB-INF/zk.xml file:

   <richlet>
       <richlet-name>ZKMonitor</richlet-name>
       <richlet-class>cz.datalite.zkspring.monitor.ZKMonitorRichlet</richlet-class>
   </richlet>

   <richlet-mapping>
       <richlet-name>ZKMonitor</richlet-name>
       <url-pattern>/ZKMonitor</url-pattern>
   </richlet-mapping>

    <listener>
       <description>ZK performance monitor</description>
        <listener-class>cz.datalite.zkspring.monitor.ZKPerformanceMeter</listener-class>
   </listener>

The url pattern will match target address, you can change it to your needs.

And that is it!

After the application start-up, you can navigate to http://yourapp/zk/ZKMonitor address and enable the monitor.

This configuration should be working itself, however, you may find useful other more advance monitoring in latter chapters.

Please let me know if anything went wrong.

Spring bean monitor

We implemented simple Spring AOP interceptor to run around bean method invocation, add info to call stack and measure method duration. To use this configuration, you can simply register this interceptor and with AOP pointcut intercept your beans.

Example of our file applicationContext-zkmonitor.xml: <?xml version="1.0" encoding="UTF-8"?> <beans xmlns="http://www.springframework.org/schema/beans"

   xmlns:xsi="http://www.w3.org/2001/XMLSchema-instance"
   xsi:schemaLocation="http://www.springframework.org/schema/beans http://www.springframework.org/schema/beans/spring-beans-2.0.xsd">

  <bean name="springPerformanceInterceptor" class="cz.datalite.zkspring.monitor.ZKSpringPerformanceInterceptor" />

   <bean name="proxyCreator" class="org.springframework.aop.framework.autoproxy.BeanNameAutoProxyCreator">
       <property name="beanNames" value="*Controller, *Service, *DAO"/>
       <property name="interceptorNames">
           <list>
               <value>springPerformanceInterceptor</value>
           </list>
       </property>
   </bean>

</beans>

This configuration uses simple Spring proxy creator to intercept all beans with name like *Controller, *Service and *DAO.

Because this is only a object proxy, you will see only calls from outside the object (see Spring AOP documentation, calls like this.method() won't be intercept). This should be no problem for service and DAO layer, however if you use GenericForwardComposer and MVC design pattern, you will not see your controller event methods. Maybe you can add classloader weaving agent and intercept all calls, but we did not tested this solution.

Monitor for Toplink essentials

Toplink essentials is a JPA provider (database access). You can add this configuration to see all logs (including timing, SQL string and parameter binding) in appropriate place of call stack.

Register custom logger in persistence.xml file (persistence unit properties):

  <property name="toplink.logging.logger" value="cz.datalite.zkspring.monitor.ZKToplinkMonitor"/>

To change default level (and actually see detail debug information), increase debug level to FINE in the same file:

  <property name="toplink.logging.level" value="FINE"/>

Unlike previous filters, this is log only - so we do not have statement duration information. However you will see log time information including millisecond part, which will give you good overview what happens in your application regarding database.

Monitor for LOG4J

Similarly to Toplink logger, you can use LOG4J appender to add any log information into call stack tree. Just register ZKMonitor appender:

 log4j.appender.ZKMonitor=cz.datalite.zkspring.monitor.ZKLog4jAppender

Example configuration for Hibernate, which will output all SQL commands with binding information into call stack tree (very verbose).

 ### log SQL ###
 log4j.logger.org.hibernate.SQL=DEBUG, ZKMonitor
 ### log JDBC bind parameters ###
 log4j.logger.org.hibernate.type=TRACE, ZKMonitor
 ### log HQL query parser activity
 log4j.logger.org.hibernate.cache=INFO, ZKMonitor

Architecture

The main part of this library is a set of different listeners, which collect information about method, event and log invocation around the application. You can easily use your listener to add additional data.

Library holds all performance data in session scope for whole history (while enabled)! So you should enable monitoring only when you use it.

Current request call stack is in request scope, this is how each listener knows where to add monitor data (use ZKRequestMonitor.currentInvocationStack).

ZK Performance Meter

Main listener is ZK PerformanceMeter [1], which provides detail information about each phase.

How does ZK know about timing on client? It sends these data with next request. It holds data on server in desktop - with this information you shouldn't be surprised, that not or timing data are available:

First request -> start at client time is missing
Between -> All times are set
Last request -> received at client and complete at client is missing

Time on server and client can be different, so it makes no sense to compare these. ZKRequestMonitor object (which holds monitor data for one request) provides convenience methods, which use calculates timing based on difference server and client duration:

• getOverallDuration - approximate overall duration - this is always set and can be used for statistics
• getNetworkLatency - network latency calculated as client overall time minus server time. This time is not set if any timing is missing
• getBrowserExecution - client execution time. This time is not set if any timing is missing

ZK Event listener

Performance meter automatically adds event listener to the desktop, so you can't switch this level off. Library listener ZKPerformanceEventInterceptor is used to intercept before event and after event calls.

Spring interceptor

Spring AOP method interceptor, implemented by ZKSpringPerformanceInterceptor.

Toplink Essentials logger

Implemented by ZKToplinkMonitor.

Log4J appender

Implemented by ZKLog4jAppender.

Download

JAR file (put it on your classpath). This file also includes all source codes.

DLZKMonitor.jar

(Please can someone transfer it to more appropriate place?)

--- Ryan Wu : I upload the file to SourceForge :)

Copyright © Jiri Bubnik, Datalite. This article is licensed under GNU Free Documentation License.