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