Return-Path: Delivered-To: apmail-ibatis-user-java-archive@www.apache.org Received: (qmail 16829 invoked from network); 21 Mar 2006 14:08:04 -0000 Received: from hermes.apache.org (HELO mail.apache.org) (209.237.227.199) by minotaur.apache.org with SMTP; 21 Mar 2006 14:08:04 -0000 Received: (qmail 59543 invoked by uid 500); 21 Mar 2006 14:08:02 -0000 Delivered-To: apmail-ibatis-user-java-archive@ibatis.apache.org Received: (qmail 59527 invoked by uid 500); 21 Mar 2006 14:08:02 -0000 Mailing-List: contact user-java-help@ibatis.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: user-java@ibatis.apache.org Delivered-To: mailing list user-java@ibatis.apache.org Received: (qmail 59516 invoked by uid 99); 21 Mar 2006 14:08:02 -0000 Received: from asf.osuosl.org (HELO asf.osuosl.org) (140.211.166.49) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 21 Mar 2006 06:08:02 -0800 X-ASF-Spam-Status: No, hits=0.3 required=10.0 tests=HTML_MESSAGE,MAILTO_TO_SPAM_ADDR,UNPARSEABLE_RELAY X-Spam-Check-By: apache.org Received-SPF: pass (asf.osuosl.org: local policy) Received: from [192.18.98.36] (HELO brmea-mail-4.sun.com) (192.18.98.36) by apache.org (qpsmtpd/0.29) with ESMTP; Tue, 21 Mar 2006 06:08:01 -0800 Received: from fe-amer-01.sun.com ([192.18.108.175]) by brmea-mail-4.sun.com (8.12.10/8.12.9) with ESMTP id k2LE7euf022760 for ; Tue, 21 Mar 2006 07:07:40 -0700 (MST) Received: from conversion-daemon.mail-amer.sun.com by mail-amer.sun.com (Sun Java System Messaging Server 6.2-4.02 (built Sep 9 2005)) id <0IWH00M01DTTNK00@mail-amer.sun.com> (original mail from Nathan.Maves@Sun.COM) for user-java@ibatis.apache.org; Tue, 21 Mar 2006 07:07:40 -0700 (MST) Received: from [192.168.5.100] ([24.8.39.65]) by mail-amer.sun.com (Sun Java System Messaging Server 6.2-4.02 (built Sep 9 2005)) with ESMTPSA id <0IWH00B9LDWRVUN3@mail-amer.sun.com> for user-java@ibatis.apache.org; Tue, 21 Mar 2006 07:07:40 -0700 (MST) Date: Tue, 21 Mar 2006 07:06:06 -0700 From: Nathan Maves Subject: Re: Very slow query In-reply-to: <1142944993.13224.55.camel@isol16.vilspa.esa.int> Sender: Nathan.Maves@Sun.COM To: user-java@ibatis.apache.org Message-id: <57C49BC9-9233-4713-94AF-E2C38E67EAF4@sun.com> MIME-version: 1.0 X-Mailer: Apple Mail (2.746.3) Content-type: multipart/alternative; boundary="Boundary_(ID_Qle8UuTh+lMn3koocq2HIQ)" References: <1142615625.13224.34.camel@isol16.vilspa.esa.int> <441AF262.3010001@pandora.be> <16178eb10603200804s3e25cbk80665c700bc5e3df@mail.gmail.com> <1142944993.13224.55.camel@isol16.vilspa.esa.int> X-Virus-Checked: Checked by ClamAV on apache.org X-Spam-Rating: minotaur.apache.org 1.6.2 0/1000/N --Boundary_(ID_Qle8UuTh+lMn3koocq2HIQ) Content-type: text/plain; format=flowed; delsp=yes; charset=US-ASCII Content-transfer-encoding: 7BIT Nicolas, I am guessing that there is a type mismatch from your db to your parameter. Please post both the table definition and your bean. if the DB field is a VARCHAR and your parameter is an Integer it can cause problems. id = '123' will have a different performance then id = 123 If that is the case then use some thing like id = #id:VARCHAR# to insure that quotes are used with a varchar column. Nathan On Mar 21, 2006, at 5:43 AM, Nicolas Fajersztejn wrote: > Hi again, > > I have tried all these things you are suggesting: > - setting cacheModelsEnabled to false > - run the query several times in a loop > - disable logging. > > and still I get the same result. > > > But to me this question is very simple. If I change #value# for the > actual number (i.e. 100) in the query > > SELECT > obsid obsID, > inst inst, > epic_filter epicFilter > FROM xsa..exposures > WHERE > obsid = 100 > > (rather than obsid=#value#) > > it takes only 50ms rather than 1500ms. So, if I am passing an > Integer it seems very clear to me that all this time is spent in > the conversion of the parameter into the actual value. Isn't that > correct? > > Have you guys tried to measure how long it takes in your > applications to do this type of conversion? It seems very weird to > me that it can take so long just a simple thing. I noticed because > I need to execute this query about 1000 times for different obsid's > and it is obviously not an acceptable time to wait 1500 seconds. > With straight JDBC it only takes 8ms per query... > > Any suggestions or comments? > > Thanks, > Nicolas. > > > > > On Mon, 2006-03-20 at 09:04 -0700, Clinton Begin wrote: >> >> Also make sure logging is disabled. >> >> Clinton >> >> On 3/17/06, Larry Meadors wrote: >> Also, run the query several times, because on the first pass, it is >> setting up the parameterMap. >> >> long t1,t2; >> t1 = System.currentTimeMillis(); >> for(int i = 0; i++; i < 10) sqlMap.queryForList >> ("getExposuresForObsId", obsID); >> t2 = System.currentTimeMillis(); >> System.out.println("time to run queryForList 10x is " + (t2-t1)); >> >> Larry >> >> >> On 3/17/06, Sven Boden wrote: >> > >> > The pool query is not used as Pool.PingEnabled is false. ;-) >> > >> > Try rerunning it setting cacheModelsEnabled to false (for a >> performance >> > run, in a real system if you have a cache hit the cache speeds up >> > processing, for a single run a cache slows down), and switch off >> > debugging if you have it on. >> > >> > Regards, >> > Sven >> > >> > Larry Meadors wrote: >> > >> > > >> > > >> > >What is "data_set", and how long does "select * from data_set" >> take to run? >> > > >> > >Larry >> > > >> > > >> > >On 3/17/06, Nicolas Fajersztejn >> wrote: >> > > >> > > >> > >> Hi, >> > >> >> > >> I'm new to iBatis. I have been using it for a couple of >> months and really >> > >>like it. >> > >> >> > >> However, now I am having problems with a very simple query. >> This is the >> > >>mapping I have: >> > >> >> > >> >> > >> >> > >> >> > >> obsid is a numeric value. I am passing an Integer as >> parameter and this >> > >>query takes about 1400 ms to execute!!! >> > >> The same query run with explicit value (obsid = 100 for >> example) takes only >> > >>48 ms. >> > >> >> > >> Does it really take so much time to convert an Integer and >> build up the >> > >>query or am I missing something? >> > >> >> > >> This is my config file in case it helps: >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> > value="10"/> >> > >> >> > >> > value="120000"/> >> > >> >> > >> >> > >> >> > >> >> > >> > value="0"/> >> > >> >> > >> >> > >> >> > >> > > >> cacheModelsEnabled="true" >> > >> enhancementEnabled="true" >> > >> lazyLoadingEnabled="true" >> > >> maxRequests="32" >> > >> maxSessions="10" >> > >> maxTransactions="5" >> > >> useStatementNamespaces="false" >> > >> /> >> > >> >> > >> >> > >> And the Java code: >> > >> >> > >> public static List getExposuresForObsId(Integer obsID) { >> > >> SqlMapClient sqlMap = XATSqlConfig.getSqlMapInstance(); >> > >> List exposureList = null; >> > >> try { >> > >> long t1 = System.currentTimeMillis (); >> > >> exposureList = sqlMap.queryForList >> ("getExposuresForObsId", >> > >>obsID); >> > >> long t2 = System.currentTimeMillis(); >> > >> System.out.println("time queryForList is " + (t2- >> t1)); >> > >> >> > >> } >> > >> catch (SQLException e) { >> > >> logger.log(Level.WARNING, "SQLException getting >> exposures list: >> > >>" + e); >> > >> } >> > >> return exposureList; >> > >> } >> > >> >> > >> >> > >> >> > >> I would gladly appreciate your help. >> > >> >> > >> Thanks. >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > >> >> > > >> > > >> > > >> > > >> > >> > >> --Boundary_(ID_Qle8UuTh+lMn3koocq2HIQ) Content-type: text/html; charset=ISO-8859-1 Content-transfer-encoding: QUOTED-PRINTABLE Nicolas,

I am guessing that there is a type m= ismatch from your db to your parameter.=A0 Please post both the table= definition and your bean.

if the DB field is a VARCHAR and your parameter is a= n Integer it can cause problems.

id =3D '123' will have a different performance= then id =3D 123

If that is the case then use some thing like

=09id =3D #id:VARCHAR#

to insure that quot= es are used with a varchar column.


=
Nathan

On Mar 21, 2006, at 5:43 AM, Nico= las Fajersztejn wrote:

<= BLOCKQUOTE type=3D"cite"> Hi again,

I have tried all these = things you are suggesting:
- setting cach= eModelsEnabled to false
- run the = query several times in a loop
- disable logging.

= and still I get the same result.


But to me this questio= n is very simple. If I change #value# for the actual number (i.e. 100= ) in the query

=09=09SELECT
=09=A0=A0=A0 =09obsid obsID,=
=09=A0=A0=A0 =09inst inst,
=09=A0=A0=A0 =09epic_filter epicF= ilter
=09=09FROM xsa..exposures
=09=09WHERE
=A0=A0=A0= =A0=A0=A0=A0=A0=A0=A0=A0 obsid =3D 100=A0=A0=A0

(rather tha= n obsid=3D#value#)

it takes only 50ms rather than 1500ms. So= , if I am passing an Integer it seems very clear to me that all this = time is spent in the conversion of the parameter into the actual valu= e. Isn't that correct?

Have you guys tried to measure how lo= ng it takes in your applications to do this type of conversion? It se= ems very weird to me that it can take so long just a simple thing. I = noticed because I need to execute this query about 1000 times for dif= ferent obsid's and it is obviously not an acceptable time to wait 150= 0 seconds. With straight JDBC it only takes 8ms per query...

= Any suggestions or comments?

Thanks,
Nicolas.

=


On Mon, 2006-03-20 at 09:04 -0700, Clinton Begin wrote= :

A= lso make sure logging is disabled.

Clinton

On= 3/17/06, Larry Meadors<= FONT color=3D"#000000"> <lm= eadors@apache.org> wrote:
Also, run the query several times, because on t= he first pass, it is
settin= g up the parameterMap.

long t1,t2;
t1= =3D System.currentTimeMillis();
for(int i =3D 0; i++; i < 10) sqlMap.queryForList("getExposu= resForObsId", obsID);
t2 = =3D System.currentTimeMillis();
System.out.println("time to run queryForList 10x is " + (t2-t1))= ;

Larry=


On 3/17/0= 6, Sven Boden <list123@pando= ra.be> wrote:
>
> The pool query is not u= sed as Pool.PingEnabled is false. ;-)
>
> Try = rerunning it setting cacheModelsEnabled to false (for a performance <= /FONT>
> run, in a real system = if you have a cache hit the cache speeds up
> processing, for a single run a cache slows down= ), and switch off
> debu= gging if you have it on.
&g= t;
> Regards,
= > Sven
>
> L= arry Meadors wrote:
>
> ><property name= =3D"Pool.PingQuery" value=3D"select * from data_set"/>
= > >
> >What is "data_set", and how long does "select = * from data_set" take to run?
> >
> >Larr= y
> >
= > >
> >On 3/17/06, Nicolas Fajersztejn <Nicolas.Fajersztejn@sc= iops.esa.int> wrote:
> >
> >=
> >> Hi,
= > >>
> >> I'm new to iBatis. I have been using it f= or a couple of months and really
> >>like it.
> >>
> >>= ; However, now I am having problems with a very simple query. This is= the
> >>mapping = I have:
> >>
> >> <select id=3D"g= etExposuresForObsId"
> &= gt;>resultClass=3D"xat.proprietarydates.objects.Exposure">
> >>=A0=A0=A0=A0SELECT=
> >>=A0=A0=A0= =A0 obsid obsID,
> >&= gt;=A0=A0=A0=A0 inst inst,
= > >>=A0=A0=A0=A0 epic_filter epicFilter
> >> FROM xsa..exposures
= > >> WHERE
> >>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0= =A0=A0 obsid =3D #value#
&g= t; >> </select>
> >>
> >&g= t;
> >> obsid is a= numeric value. I am passing an Integer as parameter and this<= BR> > >>query takes about 140= 0 ms to execute!!!
> >= ;> The same query run with explicit value (obsid =3D 100 for examp= le) takes only
> >&g= t;48 ms.
> >>
> >> Does it really ta= ke so much time to convert an Integer and build up the
= > >>query or am I missing someth= ing?
> >> > >> This is my config fil= e in case it helps:
> &= gt;>
> >>=A0= =A0=A0=A0 <transactionManager type=3D"JDBC">
= > >>=A0=A0=A0=A0=A0=A0 <dataSourc= e type=3D"SIMPLE">
> = >>=A0=A0=A0=A0=A0=A0 <property name=3D"JDBC.Driver" value= =3D"${driver}"/>
> &= gt;>=A0=A0=A0=A0=A0=A0 <property name=3D"JDBC.ConnectionURL" va= lue=3D"${url}"/>
> &g= t;>=A0=A0=A0=A0=A0=A0 <property name=3D"JDBC.Username" value= =3D"${username}"/>
> = >>=A0=A0=A0=A0=A0=A0 <property name=3D" JDBC.Password" value= =3D"${password}"/>
> = >>=A0=A0=A0=A0=A0=A0 <property name=3D"JDBC.DefaultAutocommi= t" value=3D"true"/>
>= >>=A0=A0=A0=A0=A0=A0 <!-- The following are optional -->=
> >>=A0=A0=A0= =A0=A0=A0 <property name=3D"Pool.MaximumActiveconnections" value= =3D"10"/>
> >>= =A0=A0=A0=A0=A0=A0 <property name=3D"Pool.MaximumIdleConnections" = value=3D"5"/>
> >&= gt;=A0=A0=A0=A0=A0=A0 <property name=3D" Pool.MaximumCheckoutTime"= value=3D"120000"/>
>= >>=A0=A0=A0=A0=A0=A0 <property name=3D"Pool.TimeToWait" val= ue=3D"10000"/>
> >= >=A0=A0=A0=A0=A0=A0 <property name=3D"Pool.PingQuery" value= =3D"select * from data_set"/>
> >>=A0=A0=A0=A0=A0=A0 <property name=3D"Pool.Ping= Enabled" value=3D"false"/>
> >>=A0=A0=A0=A0=A0=A0 <property name=3D"Pool.PingConn= ectionOlderThan" value=3D"0"/>
> >>=A0=A0=A0=A0=A0=A0 <property name=3D" Pool.Pin= gConnectionNotUsedFor" value=3D"0"/>
> >>=A0=A0=A0=A0=A0=A0 </dataSource>
> >>=A0=A0=A0=A0 </= transactionManager>
>= >>
> >> <= ;settings
> >> cac= heModelsEnabled=3D"true"
&= gt; >> enhancementEnabled=3D"true"
> >> lazyLoadingEnabled=3D"true"
= > >> maxRequests=3D"32"<= BR> > >> maxSessions=3D"10"
> >> maxTransaction= s=3D"5"
> >> useS= tatementNamespaces=3D"false"
> >> />
> = >>
> >>
> >> And the Java code= :
> >>
= > >>=A0=A0=A0=A0 public stati= c List getExposuresForObsId(Integer obsID) {
> >>=A0=A0=A0=A0=A0=A0=A0=A0 SqlMapClient= sqlMap =3D XATSqlConfig.getSqlMapInstance();
> >>=A0=A0=A0=A0=A0=A0=A0=A0 List exposur= eList =3D null;
> >&g= t;=A0=A0=A0=A0=A0=A0=A0=A0 try {
> >>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 long t1 =3D S= ystem.currentTimeMillis ();
> >>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 exposureList =3D s= qlMap.queryForList("getExposuresForObsId",
> >>obsID);
> >>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 long t= 2 =3D System.currentTimeMillis();
> >>=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 System.out.p= rintln("time queryForList is " + (t2-t1));
> >>
> >>=A0=A0=A0=A0=A0=A0=A0=A0 }
> >>=A0=A0=A0=A0=A0=A0=A0=A0 catch (SQLExcep= tion e) {
> >>= =A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0=A0 logger.log(Level.WARNING, "SQLEx= ception getting exposures list:
> >>" + e);
= > >>=A0=A0=A0=A0=A0=A0=A0=A0 }
> >>=A0=A0=A0=A0=A0=A0=A0=A0 return exposureLis= t;
> >>=A0=A0=A0= =A0 }
> >><= BR> > >>
> >>
> >> I would gladly appreciate your help.
> >>
= > >> Thanks.
> >>
> >>
> &= gt;>
> >>
> >>
= > >>
> >>
= > >
> ><= BR> > >
> >
>
>
<= /BLOCKQUOTE>

--Boundary_(ID_Qle8UuTh+lMn3koocq2HIQ)--