Thread: Bind on parameters performance problem


Permlink Replies: 0 - Pages: 1
Eric Neilsen

Posts: 82
Registered: 09/12/06
Bind on parameters performance problem
Posted: Apr 17, 2008 3:32 PM
Click to report abuse...   Click to reply to this thread Reply
For some reason when I select bind on parameters in toplink I get a major performance hit for certain queries. I've enabled the toplink performance profiler to log the sql queries.

I wrote a little Java class that executes these queries using a statement and using a preparedstatement. The prepared statement is fast, so I'm thinking something in toplink is slowing it down. Does anyone have any ideas?

With bind:
Begin profile of{ReadAllQuery(model.RKTask)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t1.ID, t1.ESTSTARTDATE, t1.HASMSGS, t1.HASRESOLVABLE, t1.PROGSTAT, t1.CSI, t1.ENTEREDBYID, t1.TASKCONSTRAINT, t1.PLANNEDCOMPLETIONDATE, t1.BILLINGRECORDID, t1.PARENTLAG, t1.HANDOFFDATE, t1.PLANNEDREVENUE, t1.INDENT, t1.LASTNOTEID, t1.ESTCOMPLETIONDATE, t1.DURTYPE, t1.MASTERTASKID, t1.WORKPERDAY, t1.CPI, t1.PLANNEDCOST, t1.GROUPID, t1.WORKINGDAYS, t1.MILESTONEID, t1.NUMOPENOPTASKS, t1.CATEGORYID, t1.ORIGINALDURATION, t1.HASNOTES, t1.HASEXPENSES, t1.TEMPLATETASKID, t1.ACTUALDURMINUTES, t1.ENTRYDATE, t1.ACTUALCOMPLETIONDATE, t1.ISCRITICAL, t1.ACTUALSTARTDATE, t1.PARENTID, t1.PERCENTCOMPLETE, t1.RESOURCESCOPE, t1.LASTUPDATEDATE, t1.PROJECTEDCOMPLETIONDATE, t1.CUSTOMERID, t1.ACTUALCOST, t1.APPROVALID, t1.ORIGINALWORKREQUIRED, t1.URL, t1.DURUNIT, t1.COMPLETIONPENDINGDATE, t1.PLANNEDSTARTDATE, t1.DURMINUTES, t1.EAC, t1.AUDITTYPES, t1.COSTAMOUNT, t1.EXTREFID, t1.RESERVEDTIMEID, t1.NAME, t1.ACTUALREVENUE, t1.PARENTLAGTYPE, t1.COSTTYPE, t1.TASKNUMBER, t1.PRIORITY, t1.ASSIGNEDTOID, t1.HASTIMEDNOTIFICATIONS, t1.PROJECTID, t1.ACTUALWORK, t1.WORKREQUIRED, t1.SPI, t1.LASTUPDATEDBYID, t1.STATUS, t1.APPROVALREQUIRED, t1.ROLEID, t1.NUMBEROFCHILDREN, t1.REVENUETYPE, t1.TRACKINGMODE, t1.HASDOCUMENTS, t1.BILLINGAMOUNT, t1.DESCRIPTION, t1.PROJECTEDSTARTDATE, t1.CONSTRAINTDATE FROM T_PROJECTS t0, T_ASSIGNMENTS t2, T_TASKS t1 WHERE ((((((t0.STATUS = ?) AND (t1.STATUS IN (?, ?))) AND (t1.PLANNEDSTARTDATE <= ?)) AND (t2.ASSIGNEDTOID = ?)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN ? AND ?) AND (t2.ASSIGNEDTOID = ?))) AND ((t0.ID = t1.PROJECTID) AND (t2.TASKID = t1.ID)))
bind => [CUR, NEW, INP, 1207375200000, 21824, 1206943200000, 1207461599999, 21824]
Begin profile of{ReadAllQuery(model.RKAssignment)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t0.ID, t0.PROJECTID, t0.AVGWORKPERDAY, t0.ASSIGNMENTPERCENT, t0.ROLEID, t0.ASSIGNEDTOID, t0.OPTASKID, t0.ISPRIMARY, t0.WORKREQUIRED, t0.WORKINGDAYS, t0.CUSTOMERID, t0.WORKPERDAY, t0.TASKID FROM T_ASSIGNMENTS t3, T_PROJECTS t2, T_TASKS t1, T_ASSIGNMENTS t0 WHERE (((t0.TASKID = t1.ID) AND (((((t2.STATUS = ?) AND (t1.STATUS IN (?, ?))) AND (t1.PLANNEDSTARTDATE <= ?)) AND (t3.ASSIGNEDTOID = ?)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN ? AND ?) AND (t3.ASSIGNEDTOID = ?)))) AND ((t2.ID = t1.PROJECTID) AND (t3.TASKID = t1.ID)))
bind => [CUR, NEW, INP, 1207375200000, 21824, 1206943200000, 1207461599999, 21824]

Profile(ReadAllQuery,
class=model.RKAssignment,
number of objects=2,
total time=5742,
local time=5742,
sql prepare=1,
sql execute=5736,
logging=1,
time/object=2871,
)
}End profile

Begin profile of{ReadAllQuery(model.RKPredecessor)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t0.SUCCESSORID, t0.PREDECESSORID, t0.LAGDAYS, t0.DEPENDENCYTYPE, t0.ISCP, t0.LAGTYPE, t0.ISENFORCED FROM T_ASSIGNMENTS t3, T_PROJECTS t2, T_TASKS t1, T_PREDECESSORS t0 WHERE (((t0.SUCCESSORID = t1.ID) AND (((((t2.STATUS = ?) AND (t1.STATUS IN (?, ?))) AND (t1.PLANNEDSTARTDATE <= ?)) AND (t3.ASSIGNEDTOID = ?)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN ? AND ?) AND (t3.ASSIGNEDTOID = ?)))) AND ((t2.ID = t1.PROJECTID) AND (t3.TASKID = t1.ID)))
bind => [CUR, NEW, INP, 1207375200000, 21824, 1206943200000, 1207461599999, 21824]
Profile(ReadAllQuery,
class=model.RKPredecessor,
total time=5754,
local time=5754,
logging=1,
sql execute=5753,
)
}End profile
Profile(ReadAllQuery,
class=model.RKTask,
number of objects=1,
total time=17760,
local time=6264,
profiling time=1,
cache=1,
query prepare=1,
sql execute=6258,
object building=4,
logging=1,
sql generation=3,
time/object=17760,
)
}End profile


Without Bind


Begin profile of{ReadAllQuery( model.RKTask)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t1.ID, t1.ESTSTARTDATE, t1.HASMSGS, t1.HASRESOLVABLE, t1.PROGSTAT, t1.CSI, t1.ENTEREDBYID, t1.TASKCONSTRAINT, t1.PLANNEDCOMPLETIONDATE, t1.BILLINGRECORDID, t1.PARENTLAG, t1.HANDOFFDATE, t1.PLANNEDREVENUE, t1.INDENT, t1.LASTNOTEID, t1.ESTCOMPLETIONDATE, t1.DURTYPE, t1.MASTERTASKID, t1.WORKPERDAY, t1.CPI, t1.PLANNEDCOST, t1.GROUPID, t1.WORKINGDAYS, t1.MILESTONEID, t1.NUMOPENOPTASKS, t1.CATEGORYID, t1.ORIGINALDURATION, t1.HASNOTES, t1.HASEXPENSES, t1.TEMPLATETASKID, t1.ACTUALDURMINUTES, t1.ENTRYDATE, t1.ACTUALCOMPLETIONDATE, t1.ISCRITICAL, t1.ACTUALSTARTDATE, t1.PARENTID, t1.PERCENTCOMPLETE, t1.RESOURCESCOPE, t1.LASTUPDATEDATE, t1.PROJECTEDCOMPLETIONDATE, t1.CUSTOMERID, t1.ACTUALCOST, t1.APPROVALID, t1.ORIGINALWORKREQUIRED, t1.URL, t1.DURUNIT, t1.COMPLETIONPENDINGDATE, t1.PLANNEDSTARTDATE, t1.DURMINUTES, t1.EAC, t1.AUDITTYPES, t1.COSTAMOUNT, t1.EXTREFID, t1.RESERVEDTIMEID, t1.NAME, t1.ACTUALREVENUE, t1.PARENTLAGTYPE, t1.COSTTYPE, t1.TASKNUMBER, t1.PRIORITY, t1.ASSIGNEDTOID, t1.HASTIMEDNOTIFICATIONS, t1.PROJECTID, t1.ACTUALWORK, t1.WORKREQUIRED, t1.SPI, t1.LASTUPDATEDBYID, t1.STATUS, t1.APPROVALREQUIRED, t1.ROLEID, t1.NUMBEROFCHILDREN, t1.REVENUETYPE, t1.TRACKINGMODE, t1.HASDOCUMENTS, t1.BILLINGAMOUNT, t1.DESCRIPTION, t1.PROJECTEDSTARTDATE, t1.CONSTRAINTDATE FROM T_PROJECTS t0, T_ASSIGNMENTS t2, T_TASKS t1 WHERE ((((((t0.STATUS = 'CUR') AND (t1.STATUS IN ('NEW', 'INP'))) AND (t1.PLANNEDSTARTDATE <= 1207375200000)) AND (t2.ASSIGNEDTOID = 21824)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN 1206943200000 AND 1207461599999) AND (t2.ASSIGNEDTOID = 21824))) AND ((t0.ID = t1.PROJECTID) AND (t2.TASKID = t1.ID)))

Begin profile of{ReadAllQuery( model.RKAssignment)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t0.ID, t0.PROJECTID, t0.AVGWORKPERDAY, t0.ASSIGNMENTPERCENT, t0.ROLEID, t0.ASSIGNEDTOID, t0.OPTASKID, t0.ISPRIMARY, t0.WORKREQUIRED, t0.WORKINGDAYS, t0.CUSTOMERID, t0.WORKPERDAY, t0.TASKID FROM T_ASSIGNMENTS t3, T_PROJECTS t2, T_TASKS t1, T_ASSIGNMENTS t0 WHERE (((t0.TASKID = t1.ID) AND (((((t2.STATUS = 'CUR') AND (t1.STATUS IN ('NEW', 'INP'))) AND (t1.PLANNEDSTARTDATE <= 1207375200000)) AND (t3.ASSIGNEDTOID = 21824)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN 1206943200000 AND 1207461599999) AND (t3.ASSIGNEDTOID = 21824)))) AND ((t2.ID = t1.PROJECTID) AND (t3.TASKID = t1.ID)))
Profile(ReadAllQuery,
class=model.RKAssignment,
number of objects=2,
total time=178,
local time=178,
sql execute=153,
logging=11,
time/object=89,
objects/second=11,
)
}End profile


Begin profile of{ReadAllQuery( model.RKPredecessor)
INFO [Log4JSessionLog.log()]: SELECT DISTINCT t0.SUCCESSORID, t0.PREDECESSORID, t0.LAGDAYS, t0.DEPENDENCYTYPE, t0.ISCP, t0.LAGTYPE, t0.ISENFORCED FROM T_ASSIGNMENTS t3, T_PROJECTS t2, T_TASKS t1, T_PREDECESSORS t0 WHERE (((t0.SUCCESSORID = t1.ID) AND (((((t2.STATUS = 'CUR') AND (t1.STATUS IN ('NEW', 'INP'))) AND (t1.PLANNEDSTARTDATE <= 1207375200000)) AND (t3.ASSIGNEDTOID = 21824)) OR ((t1.ACTUALCOMPLETIONDATE BETWEEN 1206943200000 AND 1207461599999) AND (t3.ASSIGNEDTOID = 21824)))) AND ((t2.ID = t1.PROJECTID) AND (t3.TASKID = t1.ID)))
Profile(ReadAllQuery,
class=model.RKPredecessor,
total time=91,
local time=91,
logging=1,
sql execute=90,
)
}End profile
Profile(ReadAllQuery,
class=model.RKTask,
number of objects=1,
total time=336,
local time=67,
profiling time=2,
query prepare=1,
sql execute=62,
object building=3,
logging=1,
sql generation=2,
time/object=336,
objects/second=2,
)
}End profile

Legend
Guru Guru : 2500 - 1000000 pts
Expert Expert : 1000 - 2499 pts
Pro Pro : 500 - 999 pts
Journeyman Journeyman : 200 - 499 pts
Newbie Newbie : 0 - 199 pts
Oracle ACE Director
Oracle ACE Member
Oracle Employee ACE
Helpful Answer (5 pts)
Correct Answer (10 pts)

Point your RSS reader here for a feed of the latest messages in all forums