2 Replies Latest reply on Dec 2, 2010 4:18 PM by gonzalad

    Utility to assert Hibernate performance

    gonzalad

      Hello,


      I've built a little utility inspirated by this post : http://josephmarques.wordpress.com/tag/hibernate/



      Basically it' just a Seam component monitors hibernate statistics for each JSF request (uses Hibernate statistics), and verify at the end of each request performance rules assertion.


      If one or more performance rules are broken, the following information is logged (DEBUG level) :



      1. view-id postacked and rendered.

      2. name en El of the broken rules.

      3. hibernate statistics.

      4. list of SQL queries executed during the request (ordered by cost).





      Configuring the component



      components.xml


      To enable this component, just adds this configuration into your components.xml :


      <component class="tmp.pag.jsf.hibernate.HibernatePerformanceMonitor">
            <property name="rulesAsMap">
                 <key>too many transactions ?</key><value>#{watch.transactionCount>10}</value>
                 <key>N+1 issue ?</key><value>#{(watch.connectCount / watch.queryExecutionCount) >= 5.0}</value>
                 <key>transaction nesting ?</key><value>#{(watch.transactionCount / watch.queryExecutionCount) >= 5.0}</value>
                 <key>slowness ?</key><value>#{watch.time > 3000}</value>
                 <key>too many queries ?</key><value>#{watch.queryExecutionCount >= 10}</value>
            </property>
            <property name="disabled">#{!debugEnabled}</property>
      </component>
      



      As you can see, you can adapt / extend performance rules by editing rulesAsMap property.


      watch variable is of type HibernateStatisticsStopWatch - you can access hibernate statistics from there.


      log4j.xml or similar


      Verify that DEBUG level is enabled for tmp.pag.jsf.hibernate.HibernatePerformanceMonitor.


      Using log4j.xml :


           <appender name="FILE_PERFORMANCE" class="org.apache.log4j.FileAppender">
                <param name="File" value="C:/Program Files/Developpements/logs/aws-performance.log"/>
                <param name="Append" value="true"/>
                <layout class="org.apache.log4j.PatternLayout">
                     <param name="ConversionPattern" value="%d %-5p %-40c - %m%n"/>
                </layout>
           </appender>
           <logger name="tmp.pag.jsf.hibernate.HibernatePerformanceMonitor">
                <level value="DEBUG" />
                <appender-ref ref="FILE_PERFORMANCE"/>
           </logger>
      



      Sample output



      2010-11-30 12:49:21,353 DEBUG tmp.pag.jsf.hibernate.HibernatePerformanceMonitor - [postback-view-id=/views/demonstrations/jsf/j_free_chart/j_free_chart_bar_desc.jspx] [render-view-id=/views/charge/report_charge.jspx]
      Failed rules :
      [ 1] name=     slowness ? value-expression=#{watch.time > 3000}
      [ 2] name=too many queries ? value-expression=#{watch.queryExecutionCount >= 10}
      Details : 
      Stats[ queryExecutionCount=11, transactionCount=2, entityLoadCount=0, connectCount=1, time=54797
      , queryStatistics=QueryStats[
                [10 x SELECT count(contrats), charge.nom FROM ChargeClientele charge JOIN charge.clients clients JOIN clients.contrats contrats WHERE contrats.dateSignature BETWEEN :dateMinSignature AND :dateMaxSignature AND charge.nom = :chargeClienteleNom GROUP BY charge.nom, executionAvgTime=3498]
                [1 x SELECT count(contrats), charge.nom FROM ChargeClientele charge JOIN charge.clients clients JOIN clients.contrats contrats WHERE contrats.dateSignature > :dateSignature GROUP BY charge.nom ORDER BY count(contrats) DESC, executionAvgTime=8969]
      ] ]
      



      This is a first rough version, let me know if you find it usefull.


      Code



      package tmp.pag.jsf.hibernate;
      
      import java.util.ArrayList;
      import java.util.List;
      import java.util.Map;
      
      import javax.annotation.PostConstruct;
      import javax.faces.event.PhaseEvent;
      import javax.faces.event.PhaseId;
      import javax.persistence.EntityManager;
      
      import org.apache.commons.logging.Log;
      import org.apache.commons.logging.LogFactory;
      import org.hibernate.Session;
      import org.hibernate.SessionFactory;
      import org.jboss.seam.Component;
      import org.jboss.seam.ScopeType;
      import org.jboss.seam.annotations.Install;
      import org.jboss.seam.annotations.Name;
      import org.jboss.seam.annotations.Scope;
      import org.jboss.seam.annotations.Startup;
      import org.jboss.seam.annotations.intercept.BypassInterceptors;
      import org.jboss.seam.contexts.Contexts;
      import org.jboss.seam.core.Events;
      import org.jboss.seam.core.Expressions.ValueExpression;
      
      import tmp.pag.integration.hibernate.HibernateStatisticsStopWatch;
      
      @Name("hibernatePerformanceMonitor")
      @BypassInterceptors
      @Scope(ScopeType.APPLICATION)
      @Install(value=false,precedence = Install.FRAMEWORK)
      @Startup(depends = { "org.jboss.seam.core.events" })
      public class HibernatePerformanceMonitor {
           private boolean disabled;
           private SessionFactory sessionFactory;
           private String WATCH_ATTRIBUTE_NAME = "__hibernatePerformanceMonitor.watch";
           private static final Log log = LogFactory
                     .getLog(HibernatePerformanceMonitor.class);
           private List<Rule> rules = new ArrayList<Rule>();
           private String watchName = "watch";
      
           /**
            * Retrieves SessionFactory from SMPC.
            */
           @PostConstruct
           public void create() {
                if (isDisabled()) {
                     return;
                }
                // attach to Seam events
                Events.instance().addListener("org.jboss.seam.beforePhase",
                          "#{hibernatePerformanceMonitor.beforePhase}", PhaseEvent.class);
                Events.instance().addListener("org.jboss.seam.afterPhase",
                          "#{hibernatePerformanceMonitor.afterPhase}", PhaseEvent.class);
                Events.instance().addListener("org.jboss.seam.preDestroyContext.EVENT",
                          "#{hibernatePerformanceMonitor.preDestroyEventContext}");
           }
      
           public Object getPersistenceContext() {
                return Component.getInstance(getPersistenceContextName());
           }
      
           protected String getPersistenceContextName() {
                return "entityManager";
           }
      
           // Start watch done before PHASE 2 (postback) or 6 (no-postback)
           public void beforePhase(PhaseEvent aEvent) {
                if (aEvent.getPhaseId() == PhaseId.APPLY_REQUEST_VALUES) {
                     createAndStartWatch();
                     getStopWatchEntry().setPostBackViewId(
                               aEvent.getFacesContext().getViewRoot().getViewId());
                } else if (aEvent.getPhaseId() == PhaseId.RENDER_RESPONSE) {
                     if (! aEvent.getFacesContext().getRenderKit().getResponseStateManager().isPostback(aEvent.getFacesContext())) {
                          createAndStartWatch();
                     }
                }
           }
           
           private void createAndStartWatch() {
                getSessionFactory().getStatistics().setStatisticsEnabled(true);
                StopWatchEntry lEntry = newStopWatchEntry();
                setStopWatchEntry(lEntry);
                getStopWatchEntry().getStopWatch().start();
           }
      
           // Start watch done after PHASE 1
           public void afterPhase(PhaseEvent aEvent) {
                if (aEvent.getPhaseId() == PhaseId.APPLY_REQUEST_VALUES) {
                     getStopWatchEntry().setPostBackViewId(
                               aEvent.getFacesContext().getViewRoot().getViewId());
                } else if (aEvent.getPhaseId() == PhaseId.RENDER_RESPONSE) {
                     getStopWatchEntry().setRenderViewId(
                               aEvent.getFacesContext().getViewRoot().getViewId());
                }
           }
      
           public void preDestroyEventContext() {
      
                // check we're called in a jsf context
                StopWatchEntry lStopWatchEntry = getStopWatchEntry();
                if (lStopWatchEntry == null) {
                     return;
                }
      
                try {
                     // preliminary test : verify at least 1 query has been executed
                     HibernateStatisticsStopWatch lStopWatch = lStopWatchEntry
                               .getStopWatch();
                     lStopWatch.stop();
                     if (lStopWatch.getQueryExecutionCount() == 0L) {
                          return;
                     }
           
                     // exporting StopWatch under watchName makes rule writing in
                     // components.xml easier
                     boolean lHasPreviousValue = Contexts.getEventContext().isSet(
                               getWatchName());
                     Object lPreviousValue = Contexts.getEventContext().get(getWatchName());
           
                     List<Rule> lFailedRules = new ArrayList<Rule>();
                     try {
                          Contexts.getEventContext().set(getWatchName(), lStopWatch);
                          for (Rule lRule : getRules()) {
                               if (lRule.getRule().getValue()) {
                                    lFailedRules.add(lRule);
                               }
                          }
                          if (lFailedRules.size() > 0) {
                               onFailedRules(lFailedRules);
                          }
                     } finally {
                          if (lHasPreviousValue) {
                               Contexts.getEventContext().set(getWatchName(), lPreviousValue);
                          } else {
                               Contexts.getEventContext().remove(getWatchName());
                          }
                     }
                } finally {
                     removeStopWatchEntry();
                }
           }
      
           /**
            * Méthode appelée lorsque des règles de performances n'ont pas été
            * respectées.
            * 
            * @param aFailedRules
            *            règles n'ayant pas étré respectées (jamais vide)
            */
           protected void onFailedRules(List<Rule> aFailedRules) {
                StopWatchEntry lEntry = getStopWatchEntry();
                StringBuilder lBuilder = new StringBuilder().append(String.format(
                          "[postback-view-id=%1$10s] [render-view-id=%2$10s]", lEntry
                                    .getPostBackViewId(), lEntry.getRenderViewId()));
                lBuilder.append("\n");
                lBuilder.append("Failed rules :");
                lBuilder.append("\n");
                for (int i = 0; i < aFailedRules.size(); i++) {
                     Rule lRule = (Rule) aFailedRules.get(i);
                     lBuilder.append(String.format(
                               "[%1$2s] name=%2$15s value-expression=%3$20s", i + 1, lRule
                                         .getName(), lRule.getRule().getExpressionString()));
                     lBuilder.append("\n");
                }
                lBuilder.append("Details : ").append("\n")
                          .append(lEntry.getStopWatch());
                log.debug(lBuilder.toString());
           }
      
           private StopWatchEntry getStopWatchEntry() {
                return (StopWatchEntry) org.jboss.seam.contexts.Contexts
                          .getEventContext().get(WATCH_ATTRIBUTE_NAME);
           }
      
           private void setStopWatchEntry(StopWatchEntry aStopWatchEntry) {
                Object lStopWatchEntry = org.jboss.seam.contexts.Contexts
                          .getEventContext().get(WATCH_ATTRIBUTE_NAME);
                if (lStopWatchEntry != null) {
                     log.debug("Request attribute " + WATCH_ATTRIBUTE_NAME
                               + " already set : " + lStopWatchEntry + ", removing it...");
                     if (lStopWatchEntry instanceof StopWatchEntry) {
                          HibernateStatisticsStopWatch lStopWatch = ((StopWatchEntry) aStopWatchEntry)
                                    .getStopWatch();
                          if (lStopWatch != null) {
                               ((HibernateStatisticsStopWatch) lStopWatch).stop();
                          }
                     }
                }
                org.jboss.seam.contexts.Contexts.getEventContext().set(
                          WATCH_ATTRIBUTE_NAME, aStopWatchEntry);
           }
      
           private void removeStopWatchEntry() {
                org.jboss.seam.contexts.Contexts.getEventContext().remove(WATCH_ATTRIBUTE_NAME);
           }
      
           protected StopWatchEntry newStopWatchEntry() {
                StopWatchEntry lWatch = new StopWatchEntry();
                lWatch.setStopWatch(new HibernateStatisticsStopWatch(getSessionFactory()));
                return lWatch;
           }
      
           
           // ////////////////////////////////////////////////////////////////////
           // Attributes //
           // ////////////////////////////////////////////////////////////////////
      
           public SessionFactory getSessionFactory() {
                if (sessionFactory != null) {
                     return sessionFactory;
                }
                Object lPersistenceContext = getPersistenceContext();
                if (lPersistenceContext instanceof Session) {
                     return ((Session) lPersistenceContext).getSessionFactory();
                }
                if (lPersistenceContext instanceof EntityManager) {
                     EntityManager lEntityManager = (EntityManager) lPersistenceContext;
                     if (lEntityManager.getDelegate() instanceof Session) {
                          return ((Session) lEntityManager.getDelegate()).getSessionFactory();
                     }
                } 
                throw new IllegalStateException(
                               "sessionFactory should not be null. Be sure to use SMPC, Hibernate or set sessionFactory property or override getPersistenceContextName().");
           }
      
           public void setSessionFactory(SessionFactory sessionFactory) {
                this.sessionFactory = sessionFactory;
           }
      
           public boolean isDisabled() {
                return disabled;
           }
      
           public void setDisabled(boolean disabled) {
                this.disabled = disabled;
           }
      
           public List<Rule> getRules() {
                return rules;
           }
      
           public void setRules(List<Rule> rules) {
                this.rules = rules;
           }
      
           public String getWatchName() {
                return watchName;
           }
      
           public void setWatchName(String watchName) {
                this.watchName = watchName;
           }
      
           /**
            * Use in components.xml configuration.
            */
           public void setRulesAsMap(Map<String, ValueExpression<Boolean>> aRules) {
                for (Map.Entry<String, ValueExpression<Boolean>> lRuleAsEl : aRules
                          .entrySet()) {
                     Rule lRule = new Rule(lRuleAsEl.getKey(), lRuleAsEl.getValue());
                     getRules().add(lRule);
                }
           }
      
           // ////////////////////////////////////////////////////////////////////
           // Helper classes //
           // ////////////////////////////////////////////////////////////////////
      
           public static class StopWatchEntry {
                private String postBackViewId;
                private String renderViewId;
                private HibernateStatisticsStopWatch stopWatch;
      
                public String getPostBackViewId() {
                     return postBackViewId;
                }
      
                public void setPostBackViewId(String postBackViewId) {
                     this.postBackViewId = postBackViewId;
                }
      
                public String getRenderViewId() {
                     return renderViewId;
                }
      
                public void setRenderViewId(String renderViewId) {
                     this.renderViewId = renderViewId;
                }
      
                public HibernateStatisticsStopWatch getStopWatch() {
                     return stopWatch;
                }
      
                public void setStopWatch(HibernateStatisticsStopWatch stopWatch) {
                     this.stopWatch = stopWatch;
                }
           }
      
           public static class Rule {
                private ValueExpression<Boolean> rule;
                private String name;
      
                public Rule() {
                }
      
                public Rule(String aName, ValueExpression<Boolean> aRule) {
                     rule = aRule;
                     name = aName;
                }
      
                public ValueExpression<Boolean> getRule() {
                     return rule;
                }
      
                public void setRule(ValueExpression<Boolean> aRule) {
                     rule = aRule;
                }
      
                public String getName() {
                     return name;
                }
      
                public void setName(String aName) {
                     name = aName;
                }
      
                public String toString() {
                     return super.toString() + "{name=" + getName() + ",rule="
                               + getRule().getExpressionString() + "}";
                }
           }
      }
      



      package tmp.pag.integration.hibernate;
      
      import java.util.ArrayList;
      import java.util.Collections;
      import java.util.Comparator;
      import java.util.HashMap;
      import java.util.List;
      import java.util.Map;
      
      import org.hibernate.SessionFactory;
      import org.hibernate.stat.QueryStatistics;
      import org.hibernate.stat.Statistics;
      
      public class HibernateQueryStatisticsStopWatch {
           private Map<String, QueryStatistics2> queryStatistics;
           private SessionFactory sessionFactory;
      
           public HibernateQueryStatisticsStopWatch(SessionFactory aSessionFactory) {
                sessionFactory = aSessionFactory;
           }
      
           public void start() {
                queryStatistics = getAllQueryStatistics();
           }
      
           public void stop() {
                Map<String, QueryStatistics2> lStopQueryStatistics = getAllQueryStatistics();
                Map<String, QueryStatistics2> lStartQueryStatistics = queryStatistics;
                queryStatistics = new HashMap<String, QueryStatistics2>();
                for (String lQuery : lStopQueryStatistics.keySet()) {
                     QueryStatistics2 lStart = lStartQueryStatistics.get(lQuery);
                     QueryStatistics2 lStop = lStopQueryStatistics.get(lQuery);
                     if (lStop != null && (lStart == null || ! lStart.equals(lStop))) {
                          queryStatistics.put(lQuery, lStop.minus(lStart));
                     }
                }
           }
      
           protected Statistics getStatistics() {
                return getSessionFactory().getStatistics();
           }
      
           protected Map<String, QueryStatistics2> getAllQueryStatistics() {
                Statistics lStatistics = getSessionFactory().getStatistics();
                Map<String, QueryStatistics2> lAllQueryStatistics = new HashMap<String, QueryStatistics2>();
                for (String lQuery : lStatistics.getQueries()) {
                     lAllQueryStatistics.put(lQuery,
                               new QueryStatistics2(lStatistics.getQueryStatistics(lQuery)));
                }
                return lAllQueryStatistics;
           }
      
           public SessionFactory getSessionFactory() {
                return sessionFactory;
           }
      
           public String toString() {
                List<String> lList = new ArrayList<String>(queryStatistics.keySet());
                Collections.sort(lList, new Comparator<String>() {
                     public int compare(String aO1, String aO2) {
                          QueryStatistics2 lStatisticsO1 = queryStatistics.get(aO1);
                          long lWeightO1 = lStatisticsO1.getExecutionCount() * lStatisticsO1.getExecutionAvgTime();
                          QueryStatistics2 lStatisticsO2 = queryStatistics.get(aO2);
                          long lWeightO2 = lStatisticsO2.getExecutionCount() * lStatisticsO2.getExecutionAvgTime();
                          if (lWeightO1 < lWeightO2) {
                               return 1;
                          } else if (lWeightO1 == lWeightO2) {
                               return 0;
                          } else {
                               return -1;
                          }
                     }
                });
                StringBuilder lBuilder = new StringBuilder();
                String lSeparator = "\n\t\t";
                for (int i = 0; i < lList.size(); i++) {
                     String lQuery = lList.get(i);
                     QueryStatistics2 lQueryStatistics = queryStatistics.get(lQuery);
                     long lExecutionCount = lQueryStatistics.getExecutionCount();
                     lBuilder.append(lSeparator).append("[").append(lExecutionCount).append(
                               " x ").append(lQuery).append(", executionAvgTime="+lQueryStatistics.getExecutionAvgTime()+"]");
                }
              return "QueryStats"
                  + "[" +lBuilder.toString()+"\n]";
          }
      
           /**
            * Duplicates Hibernate QueryStatistics since constructor is package protected
            * and adds some utilities.
            */
           public static class QueryStatistics2 {
                
                public QueryStatistics2(String aQuery) {
                     query = aQuery;
                }
                
                public QueryStatistics2(QueryStatistics aStatistics) {
                     this(aStatistics.getCategoryName());
                     setCacheHitCount(aStatistics.getCacheHitCount());
                     setCacheMissCount(aStatistics.getCacheMissCount());
                     setCachePutCount(aStatistics.getCachePutCount());
                     setExecutionAvgTime(aStatistics.getExecutionAvgTime());
                     setExecutionCount(aStatistics.getExecutionCount());
                     setExecutionMaxTime(aStatistics.getExecutionMaxTime());
                     setExecutionMinTime(aStatistics.getExecutionMinTime());
                     setExecutionRowCount(aStatistics.getExecutionRowCount());
                }
                
                public QueryStatistics2 minus(QueryStatistics2 aStatistics) {
                     if (aStatistics == null) {
                          return this;
                     }
                     if (! getQuery().equals(aStatistics.getQuery())) {
                          throw new IllegalArgumentException ("Can substract only 2 statistics on the same query : "+aStatistics.getQuery());
                     }
                     QueryStatistics2 lQueryStatistics = new QueryStatistics2(getQuery());
                     lQueryStatistics.setCacheHitCount(getCacheHitCount() - aStatistics.getCacheHitCount());
                     lQueryStatistics.setCacheMissCount(getCacheMissCount() - aStatistics.getCacheMissCount());
                     lQueryStatistics.setCachePutCount(getCachePutCount() - aStatistics.getCachePutCount());
                     lQueryStatistics.setExecutionAvgTime((getExecutionAvgTime() + aStatistics.getExecutionAvgTime())/2);
                     lQueryStatistics.setExecutionCount(getExecutionCount() - aStatistics.getExecutionCount());
                     lQueryStatistics.setExecutionMaxTime(Math.max(getExecutionMaxTime(), aStatistics.getExecutionMaxTime()));
                     lQueryStatistics.setExecutionMinTime(Math.min(getExecutionMinTime(), aStatistics.getExecutionMinTime()));
                     lQueryStatistics.setExecutionRowCount(getExecutionRowCount() - aStatistics.getExecutionRowCount());
                     return lQueryStatistics;
                }
      
                public long getExecutionCount() {
                     return executionCount;
                }
      
                public long getCacheHitCount() {
                     return cacheHitCount;
                }
      
                public long getCachePutCount() {
                     return cachePutCount;
                }
      
                public long getCacheMissCount() {
                     return cacheMissCount;
                }
      
                public long getExecutionRowCount() {
                     return executionRowCount;
                }
      
                public long getExecutionAvgTime() {
                     return executionAvgTime;
                }
      
                public long getExecutionMaxTime() {
                     return executionMaxTime;
                }
      
                public long getExecutionMinTime() {
                     return executionMinTime;
                }
      
                public void setCacheHitCount(long cacheHitCount) {
                     this.cacheHitCount = cacheHitCount;
                }
      
                public void setCacheMissCount(long cacheMissCount) {
                     this.cacheMissCount = cacheMissCount;
                }
      
                public void setCachePutCount(long cachePutCount) {
                     this.cachePutCount = cachePutCount;
                }
      
                public void setExecutionCount(long executionCount) {
                     this.executionCount = executionCount;
                }
                
                public String getQuery() {
                     return query;
                }
      
                public void setExecutionRowCount(long executionRowCount) {
                     this.executionRowCount = executionRowCount;
                }
      
                public void setExecutionAvgTime(long executionAvgTime) {
                     this.executionAvgTime = executionAvgTime;
                }
      
                public void setExecutionMaxTime(long executionMaxTime) {
                     this.executionMaxTime = executionMaxTime;
                }
      
                public void setExecutionMinTime(long executionMinTime) {
                     this.executionMinTime = executionMinTime;
                }
                
                public boolean equals(Object aObject) {
                     if (! (aObject instanceof QueryStatistics2) || aObject == null) {
                          return false;
                     }
                     QueryStatistics2 lStatistics = (QueryStatistics2) aObject;
                     if (! lStatistics.getQuery().equals(getQuery())) {
                          return false;
                     }
                     if (lStatistics.getExecutionCount() != getExecutionCount()) {
                          return false;
                     }
                     return true;
                }
      
                public String toString() {
                     return "QueryStatistics" + "[query=" + query
                               + ",executionCount=" + executionCount
                               + ",cacheHitCount=" + cacheHitCount
                               + ",cacheMissCount=" + cacheMissCount + ",cachePutCount="
                               + cachePutCount 
                               + ",executionRowCount=" + executionRowCount
                               + ",executionAvgTime=" + executionAvgTime
                               + ",executionMaxTime=" + executionMaxTime
                               + ",executionMinTime=" + executionMinTime + ']';
                }
      
                long cacheHitCount;
                long cacheMissCount;
                long cachePutCount;
                private long executionCount;
                private long executionRowCount;
                private long executionAvgTime;
                private long executionMaxTime;
                private long executionMinTime;
                private String query;
           }
      }
      



      package tmp.pag.integration.hibernate;
      
      import org.hibernate.SessionFactory;
      import org.hibernate.stat.Statistics;
      
      public class HibernateStatisticsStopWatch {
      
          private SessionFactory sessionFactory;
      
          // some interesting metrics
          private long queryExecutionCount;
          private long transactionCount;
          private long entityLoadCount;
          private long connectCount;
          private long time;
          private long closeStatementCount;
          private long collectionFetchCount;
          private long collectionLoadCount;
          private long collectionRecreateCount;
          private long collectionRemoveCount;
          private long collectionUpdateCount;
          private long entityDeleteCount;
          private long entityFetchCount;
          private long entityInsertCount;
          private long entityUpdateCount;
          private long flushCount;
          private long optimisticFailureCount;
          private long prepareStatementCount;
          private long queryCacheHitCount;
          private long queryCacheMissCount;
          private long queryCachePutCount;
          private long secondLevelCacheHitCount;
          private long secondLevelCacheMissCount;
          private long secondLevelCachePutCount;
          private long sessionCloseCount;
          private long sessionOpenCount;
          private long successfulTransactionCount;
          private HibernateQueryStatisticsStopWatch queryStatisticsStopWatch;
      
      
          public HibernateStatisticsStopWatch(SessionFactory aSessionFactory) {
               sessionFactory = aSessionFactory;
               queryStatisticsStopWatch = new HibernateQueryStatisticsStopWatch(aSessionFactory);
          }
      
          public void start() {
              queryExecutionCount = -getStatistics().getQueryExecutionCount();
              transactionCount = -getStatistics().getTransactionCount();
              entityLoadCount = -getStatistics().getEntityLoadCount();
              connectCount = -getStatistics().getConnectCount();
              time = -System.currentTimeMillis();
              closeStatementCount = -getStatistics().getCloseStatementCount();
              collectionFetchCount = -getStatistics().getCollectionFetchCount();
              collectionLoadCount = -getStatistics().getCollectionLoadCount();
              collectionRecreateCount = -getStatistics().getCollectionRecreateCount();
              collectionRemoveCount = -getStatistics().getCollectionRemoveCount();
              collectionUpdateCount = -getStatistics().getCollectionUpdateCount();
              entityDeleteCount = -getStatistics().getEntityDeleteCount();
              entityFetchCount = -getStatistics().getEntityFetchCount();
              entityInsertCount = -getStatistics().getEntityInsertCount();
              entityUpdateCount = -getStatistics().getEntityUpdateCount();
              flushCount = -getStatistics().getFlushCount();
              optimisticFailureCount = -getStatistics().getOptimisticFailureCount();
              prepareStatementCount = -getStatistics().getPrepareStatementCount();
              queryCacheHitCount = -getStatistics().getQueryCacheHitCount();
              queryCacheMissCount = -getStatistics().getQueryCacheMissCount();
              queryCachePutCount = -getStatistics().getQueryCachePutCount();
              secondLevelCacheHitCount = -getStatistics().getSecondLevelCacheHitCount();
              secondLevelCacheMissCount = -getStatistics().getSecondLevelCacheMissCount();
              secondLevelCachePutCount = -getStatistics().getSecondLevelCachePutCount();
              sessionCloseCount = -getStatistics().getSessionCloseCount();
              sessionOpenCount = -getStatistics().getSessionOpenCount();
              successfulTransactionCount = -getStatistics().getSuccessfulTransactionCount();
              queryStatisticsStopWatch.start();
          }
      
          public void stop() {
              queryExecutionCount += getStatistics().getQueryExecutionCount();
              transactionCount += getStatistics().getTransactionCount();
              entityLoadCount += getStatistics().getEntityLoadCount();
              connectCount += getStatistics().getConnectCount();
              time += System.currentTimeMillis();
              closeStatementCount += getStatistics().getCloseStatementCount();
              collectionFetchCount += getStatistics().getCollectionFetchCount();
              collectionLoadCount += getStatistics().getCollectionLoadCount();
              collectionRecreateCount += getStatistics().getCollectionRecreateCount();
              collectionRemoveCount += getStatistics().getCollectionRemoveCount();
              collectionUpdateCount += getStatistics().getCollectionUpdateCount();
              entityDeleteCount += getStatistics().getEntityDeleteCount();
              entityFetchCount += getStatistics().getEntityFetchCount();
              entityInsertCount += getStatistics().getEntityInsertCount();
              entityUpdateCount += getStatistics().getEntityUpdateCount();
              flushCount += getStatistics().getFlushCount();
              optimisticFailureCount += getStatistics().getOptimisticFailureCount();
              prepareStatementCount += getStatistics().getPrepareStatementCount();
              queryCacheHitCount += getStatistics().getQueryCacheHitCount();
              queryCacheMissCount += getStatistics().getQueryCacheMissCount();
              queryCachePutCount += getStatistics().getQueryCachePutCount();
              secondLevelCacheHitCount += getStatistics().getSecondLevelCacheHitCount();
              secondLevelCacheMissCount += getStatistics().getSecondLevelCacheMissCount();
              secondLevelCachePutCount += getStatistics().getSecondLevelCachePutCount();
              sessionCloseCount += getStatistics().getSessionCloseCount();
              sessionOpenCount += getStatistics().getSessionOpenCount();
              successfulTransactionCount += getStatistics().getSuccessfulTransactionCount();
              queryStatisticsStopWatch.stop();
          }
          
          protected Statistics getStatistics() {
               return getSessionFactory().getStatistics();
          }
      
          // getter methods for various delta metrics
      
          public long getQueryExecutionCount() {
                return queryExecutionCount;
           }
      
           public void setQueryExecutionCount(long queryExecutionCount) {
                this.queryExecutionCount = queryExecutionCount;
           }
      
           public long getTransactionCount() {
                return transactionCount;
           }
      
           public void setTransactionCount(long transactionCount) {
                this.transactionCount = transactionCount;
           }
      
           public long getEntityLoadCount() {
                return entityLoadCount;
           }
      
           public void setEntityLoadCount(long entityLoadCount) {
                this.entityLoadCount = entityLoadCount;
           }
      
           public long getConnectCount() {
                return connectCount;
           }
      
           public void setConnectCount(long connectCount) {
                this.connectCount = connectCount;
           }
      
           public long getTime() {
                return time;
           }
      
           public void setTime(long time) {
                this.time = time;
           }
      
           public SessionFactory getSessionFactory() {
                return sessionFactory;
           }
      
           public long getCloseStatementCount() {
                return closeStatementCount;
           }
      
           public long getCollectionFetchCount() {
                return collectionFetchCount;
           }
      
           public long getCollectionLoadCount() {
                return collectionLoadCount;
           }
      
           public long getCollectionRecreateCount() {
                return collectionRecreateCount;
           }
      
           public long getCollectionRemoveCount() {
                return collectionRemoveCount;
           }
      
           public long getCollectionUpdateCount() {
                return collectionUpdateCount;
           }
      
           public long getEntityDeleteCount() {
                return entityDeleteCount;
           }
      
           public long getEntityFetchCount() {
                return entityFetchCount;
           }
      
           public long getEntityInsertCount() {
                return entityInsertCount;
           }
      
           public long getEntityUpdateCount() {
                return entityUpdateCount;
           }
      
           public long getFlushCount() {
                return flushCount;
           }
      
           public long getOptimisticFailureCount() {
                return optimisticFailureCount;
           }
      
           public long getPrepareStatementCount() {
                return prepareStatementCount;
           }
      
           public long getQueryCacheHitCount() {
                return queryCacheHitCount;
           }
      
           public long getQueryCacheMissCount() {
                return queryCacheMissCount;
           }
      
           public long getQueryCachePutCount() {
                return queryCachePutCount;
           }
      
           public long getSecondLevelCacheHitCount() {
                return secondLevelCacheHitCount;
           }
      
           public long getSecondLevelCacheMissCount() {
                return secondLevelCacheMissCount;
           }
      
           public long getSecondLevelCachePutCount() {
                return secondLevelCachePutCount;
           }
      
           public long getSessionCloseCount() {
                return sessionCloseCount;
           }
      
           public long getSessionOpenCount() {
                return sessionOpenCount;
           }
      
           public long getSuccessfulTransactionCount() {
                return successfulTransactionCount;
           }
      
           public String toString() {
              return "Stats"
                  + "[ queryExecutionCount=" + queryExecutionCount
                  + ", transactionCount=" + transactionCount
                  + ", entityLoadCount=" + entityLoadCount
                  + ", connectCount=" + connectCount
                  + ", time=" + time + "\n"
                   + ", queryStatistics=" + queryStatisticsStopWatch + " ]";
          }
      }