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