Argh ! I attempted to clean up my mappings in order to produce a more readable SQL output. In the process, I must have broken some piece of magic, because now I am getting N+1 selects again:
Code:
2006-10-20 14:51:06,733 [2532] DEBUG NHibernate.Hql.QueryTranslator - HQL: from Crs.NHibernate.NHGdnaAnnot a left join fetch a.Frags where a.Method = :method and a.IsActive = 1 and a.RunId = :runId order by a.Id
2006-10-20 14:51:06,733 [2532] DEBUG NHibernate.Hql.QueryTranslator - SQL: select nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, frags1_.ANNOT_ID as ANNOT_ID1_, frags1_.FRAG_NO as FRAG_NO1_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_, frags1_.STRAND as STRAND1_, frags1_.FRAG_TYPE as FRAG_TYPE1_, frags1_.END_POS as END_POS1_, frags1_.START_POS as START_POS1_, frags1_.ANNOT_ID as ANNOT_ID__, frags1_.FRAG_NO as FRAG_NO__ from GDNA_ANNOT nhgdnaanno0_, GDNA_ANNOT_FRAG frags1_ where nhgdnaanno0_.ANNOT_ID=frags1_.ANNOT_ID(+) and ((nhgdnaanno0_.METHOD=:?)and(nhgdnaanno0_.IS_ACTIVE=1)and(nhgdnaanno0_.RUN_ID=:?)) order by nhgdnaanno0_.ANNOT_ID, frags1_.FRAG_NO asc
2006-10-20 14:51:06,749 [2532] DEBUG NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands :1
2006-10-20 14:51:06,749 [2532] DEBUG NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: select nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, frags1_.ANNOT_ID as ANNOT_ID1_, frags1_.FRAG_NO as FRAG_NO1_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_, frags1_.STRAND as STRAND1_, frags1_.FRAG_TYPE as FRAG_TYPE1_, frags1_.END_POS as END_POS1_, frags1_.START_POS as START_POS1_, frags1_.ANNOT_ID as ANNOT_ID__, frags1_.FRAG_NO as FRAG_NO__ from GDNA_ANNOT nhgdnaanno0_, GDNA_ANNOT_FRAG frags1_ where nhgdnaanno0_.ANNOT_ID=frags1_.ANNOT_ID(+) and ((nhgdnaanno0_.METHOD=:p00)and(nhgdnaanno0_.IS_ACTIVE=1)and(nhgdnaanno0_.RUN_ID=:p10)) order by nhgdnaanno0_.ANNOT_ID, frags1_.FRAG_NO asc
2006-10-20 14:51:06,765 [2532] DEBUG NHibernate.Type.AnsiStringType - binding 'OCDNA' to parameter: 0
2006-10-20 14:51:06,765 [2532] DEBUG NHibernate.Type.Int32Type - binding '180824' to parameter: 1
2006-10-20 14:51:06,765 [2532] INFO NHibernate.Loader.Loader - select nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, frags1_.ANNOT_ID as ANNOT_ID1_, frags1_.FRAG_NO as FRAG_NO1_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_, frags1_.STRAND as STRAND1_, frags1_.FRAG_TYPE as FRAG_TYPE1_, frags1_.END_POS as END_POS1_, frags1_.START_POS as START_POS1_, frags1_.ANNOT_ID as ANNOT_ID__, frags1_.FRAG_NO as FRAG_NO__ from GDNA_ANNOT nhgdnaanno0_, GDNA_ANNOT_FRAG frags1_ where nhgdnaanno0_.ANNOT_ID=frags1_.ANNOT_ID(+) and ((nhgdnaanno0_.METHOD=:p0)and(nhgdnaanno0_.IS_ACTIVE=1)and(nhgdnaanno0_.RUN_ID=:p1)) order by nhgdnaanno0_.ANNOT_ID, frags1_.FRAG_NO asc
2006-10-20 14:51:06,765 [2532] DEBUG NHibernate.SQL - select nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, frags1_.ANNOT_ID as ANNOT_ID1_, frags1_.FRAG_NO as FRAG_NO1_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_, frags1_.STRAND as STRAND1_, frags1_.FRAG_TYPE as FRAG_TYPE1_, frags1_.END_POS as END_POS1_, frags1_.START_POS as START_POS1_, frags1_.ANNOT_ID as ANNOT_ID__, frags1_.FRAG_NO as FRAG_NO__ from GDNA_ANNOT nhgdnaanno0_, GDNA_ANNOT_FRAG frags1_ where nhgdnaanno0_.ANNOT_ID=frags1_.ANNOT_ID(+) and ((nhgdnaanno0_.METHOD=:p0)and(nhgdnaanno0_.IS_ACTIVE=1)and(nhgdnaanno0_.RUN_ID=:p1)) order by nhgdnaanno0_.ANNOT_ID, frags1_.FRAG_NO asc
2006-10-20 14:51:06,765 [2532] DEBUG NHibernate.SQL - :p0 = 'OCDNA'
2006-10-20 14:51:06,765 [2532] DEBUG NHibernate.SQL - :p1 = '180824'
2006-10-20 14:51:06,781 [2532] DEBUG NHibernate.Impl.BatcherImpl - Opened Reader, open Readers :1
2006-10-20 14:51:06,781 [2532] DEBUG NHibernate.Loader.Loader - processing result set
2006-10-20 14:51:12,105 [2532] DEBUG NHibernate.Type.Int32Type - returning '1772692' as column: ANNOT_ID0_
2006-10-20 14:51:12,105 [2532] DEBUG NHibernate.Type.Int32Type - returning '1772692' as column: ANNOT_ID1_
2006-10-20 14:51:12,105 [2532] DEBUG NHibernate.Type.Int32Type - returning '1' as column: FRAG_NO1_
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Impl.SessionImpl - loading [NHGdnaAnnot#1772692]
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Impl.SessionImpl - attempting to resolve [NHGdnaAnnot#1772692]
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Impl.SessionImpl - object not resolved in any cache [Crs.NHibernate.NHGdnaAnnot#1772692]
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Persister.EntityPersister - Materializing entity: Crs.NHibernate.NHGdnaAnnot#1772692
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Impl.BatcherImpl - Opened new IDbCommand, open IDbCommands :2
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Impl.BatcherImpl - Building an IDbCommand object for the SqlString: SELECT nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_ FROM GDNA_ANNOT nhgdnaanno0_ WHERE nhgdnaanno0_.ANNOT_ID=:ANNOT_ID
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.Type.Int32Type - binding '1772692' to parameter: 0
2006-10-20 14:51:12,121 [2532] INFO NHibernate.Loader.Loader - SELECT nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_ FROM GDNA_ANNOT nhgdnaanno0_ WHERE nhgdnaanno0_.ANNOT_ID=:p0
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.SQL - SELECT nhgdnaanno0_.ANNOT_ID as ANNOT_ID0_, nhgdnaanno0_.SCORE as SCORE0_, nhgdnaanno0_.IS_ACTIVE as IS_ACTIVE0_, nhgdnaanno0_.ANNOT_END as ANNOT_END0_, nhgdnaanno0_.RUN_ID as RUN_ID0_, nhgdnaanno0_.METHOD as METHOD0_, nhgdnaanno0_.GDNA_ID as GDNA_ID0_, nhgdnaanno0_.IS_WRONG as IS_WRONG0_, nhgdnaanno0_.ANNOT_START as ANNOT_ST7_0_, nhgdnaanno0_.STRAND as STRAND0_ FROM GDNA_ANNOT nhgdnaanno0_ WHERE nhgdnaanno0_.ANNOT_ID=:p0
2006-10-20 14:51:12,121 [2532] DEBUG NHibernate.SQL - :p0 = '1772692'
2006-10-20 14:51:12,707 [2532] DEBUG NHibernate.Impl.BatcherImpl - Opened Reader, open Readers :2
2006-10-20 14:51:12,707 [2532] DEBUG NHibernate.Loader.Loader - processing result set
2006-10-20 14:51:12,707 [2532] DEBUG NHibernate.Loader.Loader - result row: 1772692
2006-10-20 14:51:12,723 [2532] DEBUG NHibernate.Loader.Loader - Initializing object from DataReader: 1772692
NHGdnaAnnot is the parent; NHGdnaAnnotFrag is the child. It uses a composite primary key. I realize that this is not recommended by the NHibernate docs, but I'm using a legacy data model, and changing the DB is not an option.
Here is my mapping file:
Code:
<?xml version="1.0" encoding="utf-8" ?>
<hibernate-mapping xmlns="urn:nhibernate-mapping-2.0"
namespace="Crs.NHibernate" assembly="Crs">
<class name="NHGdnaAnnot" table="GDNA_ANNOT">
<id name="Id" column="ANNOT_ID">
<generator class="sequence">
<param name="sequence">ANNOT_ID_SEQ</param>
</generator>
</id>
<property name="RunId" column="RUN_ID"/>
<property name="GdnaId" column="GDNA_ID" not-null="true"/>
<property name="Method" type="AnsiString" column="METHOD"/>
<property name="Score" column="SCORE"/>
<property name="Strand" type="AnsiString" column="STRAND"/>
<property name="AnnotStart" column="ANNOT_START"/>
<property name="AnnotEnd" column="ANNOT_END"/>
<property name="IsActive" column="IS_ACTIVE"/>
<property name="IsWrong" column="IS_WRONG"/>
<set name="Frags" order-by="FRAG_NO asc" lazy="true">
<key column="ANNOT_ID"/>
<one-to-many class="NHGdnaAnnotFrag"/>
</set>
</class>
<class name="NHGdnaAnnotFrag" table="GDNA_ANNOT_FRAG">
<composite-id>
<key-many-to-one name="GdnaAnnot" class="NHGdnaAnnot" column="ANNOT_ID"></key-many-to-one>
<key-property name="FragNo" column="FRAG_NO"></key-property>
</composite-id>
<property name="FragType" column="FRAG_TYPE" type="AnsiString" not-null="true"/>
<property name="StartPos" column="START_POS" not-null="true"/>
<property name="EndPos" column="END_POS" not-null="true"/>
<property name="Strand" column="STRAND" type="AnsiString" not-null="true"/>
</class>
</hibernate-mapping>
And here is the C# code:
Code:
public static IList Select(String hql, params object[] args) {
IQuery query = currentSession.CreateQuery(hql);
for(int i=0; i<args.Length; i+=2) {
string name = (string)args[i];
object value = args[i + 1];
if (value is string) {
query.SetAnsiString(name, (string)value); // Gets around the OCI error
} else {
query.SetParameter(name, value);
}
}
return query.List();
}
...
foreach (NHGdnaAnnot annot in Select("from NHGdnaAnnot a left join fetch a.Frags where " +
" a.Method = :method and a.IsActive = 1 and a.RunId = :runId order by a.Id",
"method", AnnotMethods.OCDNA,
"runId", 180824)) {
...
}
So, why is it that I get N+1 selects with this code ? I am getting fairly frustrated by all the magic surrounding NHibernate :-(