Hi DJ, so I'm back on this thread with new informations. My DB / Java guru told me that with hibernate a typical problem is lazy loading, so we took some traces with an almost empty database to see if the numger of calls is much higher as the entries in the tables which would be a hint that lazy loading is loading every value with a new call:
select count(*) for every table (all other tables are empty): databasechangeloglock 1 distpoller 1 qrtz_job_details 1 alarms 3 qrtz_locks 5 assets 6 categories 6 node 6 service 15 acks 35 notifications 82 usersnotified 82 databasechangelog 121 ipinterface 146 ifservices 563 snmpinterface 771 events 1098. One of the selects taking so much time at startup seems to be in called when somewhere below /opennms/KSC/index.htm. The trace could not hold everything in memory so there were more calls than reported, but it counted up to about 60.000 calls, much more than the size of any table above. Due to that we think it is either an "unhappy" piece of code or a lacy loading problem. The decompiled source code we found from opennms is below. All other methods around this are from springframework, hibernate and something with org.extremecomponents.table.filter.AbstractExportFilter. /* StoreRequestPropertiesFilter - Decompiled by JODE * Visit http://jode.sourceforge.net/ */ package org.opennms.web; import java.io.IOException; import javax.servlet.Filter; import javax.servlet.FilterChain; import javax.servlet.FilterConfig; import javax.servlet.ServletException; import javax.servlet.ServletRequest; import javax.servlet.ServletResponse; import javax.servlet.http.HttpServletRequest; public class StoreRequestPropertiesFilter implements Filter { private String m_servletPathAttribute; private String m_relativeServletPathAttribute; public void init(FilterConfig config) throws ServletException { m_servletPathAttribute = config.getInitParameter("servletPathAttribute"); m_relativeServletPathAttribute = config.getInitParameter("relativeServletPathAttribute"); } public void doFilter(ServletRequest request, ServletResponse response, FilterChain chain) throws IOException, ServletException { HttpServletRequest httpRequest = request; if (m_servletPathAttribute != null) request.setAttribute(m_servletPathAttribute, httpRequest.getServletPath()); if (m_relativeServletPathAttribute != null) { String servletPath = httpRequest.getServletPath(); if (servletPath != null && servletPath.length() > 0 && servletPath.charAt(0) == '/') servletPath = servletPath.substring(1); request.setAttribute(m_relativeServletPathAttribute, servletPath); } chain.doFilter(request, response); } public void destroy() { /* empty */ } } Node Details for the Class org.extremecomponents.table.filter.AbstractExportFilter Method: doFilter(javax.servlet.ServletRequest request, javax.servlet.ServletResponse response, javax.servlet.FilterChain chain) Class: org.extremecomponents.table.filter.AbstractExportFilter Argument: Return: Agent: open...@xxxxx:27733 API: Servlet Thread Name: 13611...@qtp-22770742-14 <13611191> Time [ms]: 0.96 Level: 15 Entry Hops: 19 Exit Hops: 142319 Time Details Total Exec % Execution Time [ms]: 21284.52 0.11 0.00 Execution CPU Time [ms]: 8140.00 0.00 0.00 Sync Time [ms]: - - - Wait Time [ms]: - - - Runtime Suspension Time [ms]: 467.72 - - Virtualization Suspension Time [ms]: - - - Source Information File Name: - Line: 41 Web Requests Details URI: /opennms/KSC/index.htm Query: - HTTP Tag: - Bytes Sent: - Bytes Rcvd: - which will call Node Details Method: doGet(javax.servlet.http.HttpServletRequest request, javax.servlet.http.HttpServletResponse response) Class: org.springframework.web.servlet.FrameworkServlet Argument: Return: Agent: open...@xxxxx:27733 API: Servlet Thread Name: 13611...@qtp-22770742-14 <13611191> Time [ms]: 1.04 Level: 16 Entry Hops: 20 Exit Hops: 142318 Time Details Total Exec % Execution Time [ms]: 21284.41 - - Execution CPU Time [ms]: 8140.00 - - Sync Time [ms]: - - - Wait Time [ms]: - - - Runtime Suspension Time [ms]: 467.72 28.57 5.07 Virtualization Suspension Time [ms]: - - - Source Information File Name: - Line: 548 Runtime Suspension Details Start: Duration [ms]: Reason: 2010-09-03 14:21:59.955 28.57 Garbage Collection Web Requests Details URI: /opennms/KSC/index.htm Query: - HTTP Tag: - Bytes Sent: - Bytes Rcvd: - The sql query for this seems to be: Database Details Platform: Java SQL Statement: select ipinterfac0_.nodeId as nodeId1_, ipinterfac0_.id as id1_, ipinterfac0_.id as id4_0_, ipinterfac0_.ipAddr as ipAddr4_0_, ipinterfac0_.ipHostName as ipHostName4_0_, ipinterfac0_.ipLastCapsdPoll as ipLastCa4_4_0_, ipinterfac0_.isManaged as isManaged4_0_, ipinterfac0_.isSnmpPrimary as isSnmpPr6_4_0_, ipinterfac0_.nodeId as nodeId4_0_, ipinterfac0_.snmpInterfaceId as snmpInte8_4_0_ from ipInterface ipinterfac0_ where ipinterfac0_.nodeId=? Bind Values: - ExecCount: 8555 Preparations: 8556 Rows Manipulated: 0 Time Details Avg Min Max Sum Execution Time [ms]: 0.36 0.24 111.83 3052.30 Execution CPU Time [ms]: 0.00 0.00 0.56 33.70 Preparation Time [ms]: 0.06 0.05 7.18 485.15 Preparation CPU Time [ms]: 0.00 0.00 0.42 0.60 which was called quite often for having only 146 entries in ipinterface and 563 in ifservices. And it's the same one that was called more than 90,000 times on our production system on startup as stated in my first mail in this thread. The other sql query I mentioned in the first mail seems to be in the same piece of code: Web Requests Details URI: /opennms/KSC/index.htm Query: - HTTP Tag: - Bytes Sent: - Bytes Rcvd: - Database Details Platform: Java SQL Statement: select onmsassetr0_.id as id1_0_, onmsassetr0_.address1 as address2_1_0_, onmsassetr0_.address2 as address3_1_0_, onmsassetr0_.assetNumber as assetNum4_1_0_, onmsassetr0_.autoenable as autoenable1_0_, onmsassetr0_.building as building1_0_, onmsassetr0_.category as category1_0_, onmsassetr0_.circuitId as circuitId1_0_, onmsassetr0_.city as city1_0_, onmsassetr0_.comment as comment1_0_, onmsassetr0_.connection as connection1_0_, onmsassetr0_.dateInstalled as dateIns12_1_0_, onmsassetr0_.department as department1_0_, onmsassetr0_.description as descrip14_1_0_, onmsassetr0_.displayCategory as display15_1_0_, onmsassetr0_.division as division1_0_, onmsassetr0_.enable as enable1_0_, onmsassetr0_.floor as floor1_0_, onmsassetr0_.userLastModified as userLas19_1_0_, onmsassetr0_.lastModifiedDate as lastMod20_1_0_, onmsassetr0_.lease as lease1_0_, onmsassetr0_.leaseExpires as leaseEx22_1_0_, onmsassetr0_.maintContractExpires as maintCo23_1_0_, onmsassetr0_.maintContract as maintCo24_1_0_, onmsassetr0_.managedObjectInstance as managed25_1_0_, onmsassetr0_.managedObjectType as managed26_1_0_, onmsassetr0_.manufacturer as manufac27_1_0_, onmsassetr0_.modelNumber as modelNu28_1_0_, onmsassetr0_.nodeId as nodeId1_0_, onmsassetr0_.notifyCategory as notifyC29_1_0_, onmsassetr0_.operatingSystem as operati30_1_0_, onmsassetr0_.password as password1_0_, onmsassetr0_.pollerCategory as pollerC32_1_0_, onmsassetr0_.port as port1_0_, onmsassetr0_.rack as rack1_0_, onmsassetr0_.region as region1_0_, onmsassetr0_.room as room1_0_, onmsassetr0_.serialNumber as serialN37_1_0_, onmsassetr0_.slot as slot1_0_, onmsassetr0_.state as state1_0_, onmsassetr0_.supportPhone as support40_1_0_, onmsassetr0_.thresholdCategory as thresho41_1_0_, onmsassetr0_.username as username1_0_, onmsassetr0_.vendor as vendor1_0_, onmsassetr0_.vendorAssetNumber as vendorA44_1_0_, onmsassetr0_.vendorFax as vendorFax1_0_, onmsassetr0_.vendorPhone as vendorP46_1_0_, onmsassetr0_.zip as zip1_0_ from assets onmsassetr0_ where onmsassetr0_.nodeId=? Bind Values: - ExecCount: 8598 Preparations: 8599 Rows Manipulated: 0 Time Details Avg Min Max Sum Execution Time [ms]: 0.66 0.45 192.33 5648.60 Execution CPU Time [ms]: 0.01 0.00 5.19 83.09 Preparation Time [ms]: 0.17 0.13 19.21 1488.58 Preparation CPU Time [ms]: 0.00 0.00 0.37 4.85 To get more information about this my guru told me I have to install some framework (probably I will take eclipse) and load the source code of opennms so we might be able to find the point where this comes from. But this might take a few weeks before I have the time to do this as of friday I will be off office for some weeks.... - Michael ------------------------------------------------------------------------------ Start uncovering the many advantages of virtual appliances and start using them to simplify application deployment and accelerate your shift to cloud computing. http://p.sf.net/sfu/novell-sfdev2dev _______________________________________________ Please read the OpenNMS Mailing List FAQ: http://www.opennms.org/index.php/Mailing_List_FAQ opennms-devel mailing list To *unsubscribe* or change your subscription options, see the bottom of this page: https://lists.sourceforge.net/lists/listinfo/opennms-devel
