You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@openjpa.apache.org by hvieren <he...@gmail.com> on 2013/07/15 16:52:12 UTC
Re: Why is OpenJPA execting select count(*) for a simple select ?
because it involves pagination ?
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..
2013/6/11 Bjørn-Willy Arntzen [via OpenJPA]
<ml...@n2.nabble.com>:
> Ok, found one issue by my self...
>
> The 4 seconds delay is due to a non connection pooling datasource. It is
> quite fast after replacing it with
> org.springframework.jdbc.datasource.SingleConnectionDataSource.
>
> Then only one issue is left :
>
> Why is OpenJPA executing select count(*) for a simple select ?
>
> Med vennlig hilsen / Regards from
>
> Bjørn-Willy Arntzen
>
> -----Opprinnelig melding-----
> Fra: Bjørn-Willy Arntzen [mailto:[hidden email]]
> Sendt: 11. juni 2013 11:26
> Til: [hidden email]
> Emne: Why is OpenJPA execting select count(*) for a simple select ?
>
> 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@10a80b13
> 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@21c98878
> 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
>
>
>
> ________________________________
> If you reply to this email, your message will be added to the discussion
> below:
> http://openjpa.208410.n2.nabble.com/Why-is-OpenJPA-execting-select-count-for-a-simple-select-tp7584109p7584110.html
> To start a new topic under OpenJPA Users, email
> ml-node+s208410n208411h89@n2.nabble.com
> To unsubscribe from OpenJPA Users, click here.
> NAML
--
View this message in context: http://openjpa.208410.n2.nabble.com/Re-Why-is-OpenJPA-execting-select-count-for-a-simple-select-tp7584415.html
Sent from the OpenJPA Users mailing list archive at Nabble.com.