Hello,
I'm not sure if what I'm about to explain is a bug but it certainly seems odd.
I have a simple class hierarchy using the joined inheritence strategy and when
I do an update on one of the subclasses which involves fields from a subclass
as well as the superclass there are some very strange select statements that
run before the actual updates. The one that concerns me most is a select that
does a LEFT OUTTER JOIN on of every class in the hierarchy (even the other
subclasses which are not involved in the update). I can see no reason for this
select and I can see it being a performance problem as the inheritence chain
grows.
Below I'll include a simple class hierarchy and the logs that are generated
from an update on a subclass. In the update I change BudgetedEmployee.test,
Employee.firstName, and Employee.gender. Notice the first select statment in
the logs also joins to VolunteerEmployee for no apparent reason. The logs I
have provided are abreviated to show only the relevant sql that is run; I can
provide the full log if needed.
<-------------------------------------THE
CLASSES------------------------------------------>
@Entity
@Table(name = "employee")
@Inheritance(strategy = InheritanceType.JOINED)
@DiscriminatorColumn(name = "type", discriminatorType =
DiscriminatorType.STRING)
public abstract class Employee {
protected Long id;
protected String firstName;
protected String middleName;
protected String lastName;
protected String suffixName;
protected String preferredName;
protected String ssn;
protected Date birthDate;
protected Gender gender;
protected Date licenseExpiration;
protected Long optLock;
// constructors, getters, setters, etc...
}
<------------------------------------------------------------------->
@Entity
@Table(name = "budgeted_employee")
@DiscriminatorValue("budgeted")
public class BudgetedEmployee extends Employee {
private String test;
// constructors, getters, setters, etc...
}
<------------------------------------------------------------------->
@Entity
@Table(name = "volunteer_employee")
@DiscriminatorValue("volunteer")
public class VolunteerEmployee extends Employee {
private String volTest;
// constructors, getters, setters, etc...
}
<-------------------------------------THE
LOG------------------------------------------>
...
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - SQL Cache missed with
key: org.piercecountywa.sdms.model.Employee in class
org.apache.openjpa.jdbc.kernel.JDBCStoreManager
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> executing prepstmnt 16678414 SELECT t0.type, t0.opt_lock, t0.birthDate,
t0.first_name, t0.gender, t0.last_name, t0.licenseExpiration, t0.middle_name,
t0.preferred_name, t0.ssn, t0.suffix_name, t1.test, t2.volTest FROM employee t0
LEFT OUTER JOIN budgeted_employee t1 ON t0.employee_id = t1.employee_id LEFT
OUTER JOIN volunteer_employee t2 ON t0.employee_id = t2.employee_id WHERE
t0.employee_id = ? [params=(long) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> [0 ms] spent
...
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - SQL Cache missed with
key: org.piercecountywa.sdms.model.BudgetedEmployee in class
org.apache.openjpa.jdbc.kernel.JDBCStoreManager
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
22036972> executing prepstmnt 30273569 SELECT t0.type, t0.opt_lock,
t0.birthDate, t0.first_name, t0.last_name, t0.licenseExpiration,
t0.middle_name, t0.preferred_name, t0.suffix_name, t1.test FROM
budgeted_employee t1 INNER JOIN employee t0 ON t1.employee_id = t0.employee_id
WHERE t1.employee_id = ? [params=(long) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
22036972> [0 ms] spent
...
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - SQL Cache hit with
key: org.piercecountywa.sdms.model.BudgetedEmployee in class
org.apache.openjpa.jdbc.kernel.JDBCStoreManager
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
22190454> executing prepstmnt 3670806 SELECT t0.type, t0.opt_lock,
t0.birthDate, t0.first_name, t0.last_name, t0.licenseExpiration,
t0.middle_name, t0.preferred_name, t0.suffix_name, t1.test FROM
budgeted_employee t1 INNER JOIN employee t0 ON t1.employee_id = t0.employee_id
WHERE t1.employee_id = ? [params=(long) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
22190454> [0 ms] spent
...
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.Runtime - Updating sequence
values.
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.Runtime - Getting current
sequence values.
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
20274937> executing prepstmnt 23100199 SELECT SEQUENCE_VALUE FROM seed_table
WHERE ID = ? FOR UPDATE WITH RR [params=(String) audit_id]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
20274937> [0 ms] spent
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - <t 11890430, conn
20274937> [0 ms] commit
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - <t 11890430, conn
20274937> [0 ms] close
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.Runtime - Inserting row for this
mapping into sequence table.
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
5463591> executing prepstmnt 9299816 INSERT INTO seed_table (ID,
SEQUENCE_VALUE) VALUES (?, ?) [params=(String) audit_id, (int) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
5463591> [16 ms] spent
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - <t 11890430, conn
5463591> [0 ms] close
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.Runtime - Updating sequence
values.
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.Runtime - Getting current
sequence values.
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
28453564> executing prepstmnt 20820733 SELECT SEQUENCE_VALUE FROM seed_table
WHERE ID = ? FOR UPDATE WITH RR [params=(String) audit_id]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
28453564> [0 ms] spent
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
28453564> executing prepstmnt 21982545 UPDATE seed_table SET SEQUENCE_VALUE = ?
WHERE ID = ? AND SEQUENCE_VALUE = ? [params=(long) 100005, (String) audit_id,
(long) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
28453564> [0 ms] spent
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - <t 11890430, conn
28453564> [0 ms] commit
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - <t 11890430, conn
28453564> [0 ms] close
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.JDBC - The batch limit is
set to 0.
09/05/2008 18:26:06 [btpool0-3] DEBUG org.piercecountywa.sdms.model.Employee -
Setting optLock to 2
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> executing prepstmnt 12153077 UPDATE employee SET first_name = ?,
opt_lock = ? WHERE employee_id = ? AND opt_lock = ? [params=(String) Jane,
(int) 2, (long) 100000, (int) 1]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> [0 ms] spent
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> executing prepstmnt 23764234 UPDATE budgeted_employee SET test = ?
WHERE employee_id = ? [params=(String) changed, (long) 100000]
09/05/2008 18:26:06 [btpool0-3] DEBUG openjpa.jdbc.SQL - <t 11890430, conn
386128> [0 ms] spent
...
Thanks,
Reece