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


Reply via email to