I have this quite simple query with OpenJPA 2.0.1:

@Query("SELECT y FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3")
Page<Shadow> findByInsurerAndOrgNumberAndUnitNumber(String insurer, String orgNumber, String unitNumber, Pageable pageable);


But is take very long time to execute. If I executes the generated SQL query in DBVizualizer is runs for just a couple of milliseconds.

But is I run it in my Jetty environment it takes 10 seconds ...

My log4j setting is trace all:
   <category name="openjpa" additivity="false">
       <priority value="trace" />
      <appender-ref ref="stdout" />
   </category>

Below is my trace :



1)    Why is my JPA executing a select count(*) ?

2)    Why is it taking over 4 seconds from the 11:09:24,395 DEBUG Query:73 to 11:09:29,034 DEBUG SQL:73 ?

3)    And a another 4 seconds from 11:09:29,086 DEBUG SQLDiag:73 to 11:09:33,620 DEBUG SQL:73 ?

4)    The actually DB2 executing seems to take less than 100 ms ...

11:09:24,226 DEBUG Runtime:73 - Found datasource1: datasource 140254981 from configuration. StoreContext: org.apache.openjpa.kernel.BrokerImpl@(protected)
11:09:24,355 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:24,360 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:24,362 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:24,394 DEBUG Runtime:73 - Query "select count(y) FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" is cached."
11:09:24,395 DEBUG Query:73 - Executing query: [select count(y) FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3] with parameters: {1=1000, 2=00106, 3=001}

11:09:29,034 DEBUG SQL:73 - <t 831357506, conn 1183016620> executing prepstmnt 1880763659 SELECT COUNT(*) FROM T40008 t0 WHERE (t0.k_fgiv_refid = ? AND t0.org_nbr = ? AND t0.unt_nbr = ?) optimize for 1 row [params=?, ?, ?]
11:09:29,057 DEBUG SQL:73 - <t 831357506, conn 1183016620> [23 ms] spent
11:09:29,071 DEBUG JDBC:73 - <t 831357506, conn 1183016620> [11 ms] close
11:09:29,073 DEBUG Runtime:73 - Query "select count(y) FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" is removed from cache excluded permanently. Query "select count(y) FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" is not cached because it returns a single value rather than a list. A query that returns single value can not be cached. .
11:09:29,074 DEBUG Runtime:73 - Found datasource1: datasource 140254981 from configuration. StoreContext: org.apache.openjpa.kernel.BrokerImpl@(protected)
11:09:29,076 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:29,078 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:29,079 DEBUG MetaData:73 - Parsing class "java.lang.String".
11:09:29,080 DEBUG Runtime:73 - Query "SELECT y FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" is cached."
11:09:29,080 DEBUG Query:73 - Executing query: [SELECT y FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3] with parameters: {1=1000, 2=00106, 3=001}
11:09:29,086 DEBUG SQLDiag:73 - Eager relations: [no.klp.nettpensjon.bp.dao.entities.Shadow.nameAddress]
11:09:33,620 DEBUG SQL:73 - <t 831357506, conn 2125031061> executing prepstmnt 1103958842 SELECT t0.K_KATEGORI, t0.sos_sec_nbr, t0.org_nbr, t0.rsk_cmy_id, t0.L_SEKVENSNR, t0.unt_nbr, t0.agelimit, t0.b_hovedlonn, t0.PEN_SPM_SAL_AMT, t0.K_YTELSE, t0.BEST_ART, t0.K_KUND_ANSATTNR, t0.K_AVDELINGSNR, t0.eff_dt, t0.ocp_cd, t0.emp_pct, t0.k_fgiv_refid, t0.K_MEDL_ANSATTNR, t1.sos_sec_nbr, t1.adr_1, t1.fst_nm, t1.lst_nm, t1.post_cd, t0.K_FORS_TAKER, t0.sal_grd_cd, t0.status FROM T40008 t0 LEFT OUTER JOIN T40007 t1 ON t0.sos_sec_nbr = t1.sos_sec_nbr WHERE (t0.k_fgiv_refid = ? AND t0.org_nbr = ? AND t0.unt_nbr = ?) FETCH FIRST 50 ROWS ONLY [params=?, ?, ?]
11:09:33,677 DEBUG SQL:73 - <t 831357506, conn 2125031061> [57 ms] spent
11:09:33,753 DEBUG JDBC:73 - <t 831357506, conn 2125031061> [11 ms] close
11:09:33,755 DEBUG Runtime:73 - Query "SELECT y FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" is removed from cache excluded permanently. This query "SELECT y FROM Shadow y WHERE y.insurer = ?1 AND y.orgNumber = ?2 AND y.unitNumber = ?3" involves pagination and is not cached..


Any suggestions would be appreciated.

Med vennlig hilsen / Regards from

Bjørn-Willy Arntzen
Seniorkonsulent IT
Kommunal Landspensjonskasse gjensidig forsikringsselskap
Dronning Eufemias gate 10, 0191 Oslo, Pb 400, Sentrum, 0103 Oslo
Mob: +4797759007
www.klp.no<http://www.klp.no/>

Vennligst tenk på miljøet før du skriver ut denne e-posten