Error log from ReflectHelper.TypeFromAssembly() on Linq query

[cremor]

Since I updated to version 5.3.9 my application logs this error the first time a specific Linq query is executed:

Could not load type mappedcust2_.IS_LEAD_CUSTOMER, mappedcust2_.CUST_ID.Customer.
System.IO.FileNotFoundException: Could not load file or assembly 'mappedcust2_.CUST_ID.Customer' or one of its dependencies. Das System kann die angegebene Datei nicht finden.
File name: 'mappedcust2_.CUST_ID.Customer'
   at System.Reflection.RuntimeAssembly._nLoad(AssemblyName fileName, String codeBase, Evidence assemblySecurity, RuntimeAssembly locationHint, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean throwOnFileNotFound, Boolean forIntrospection, Boolean suppressSecurityChecks)
   at System.Reflection.RuntimeAssembly.nLoad(AssemblyName fileName, String codeBase, Evidence assemblySecurity, RuntimeAssembly locationHint, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean throwOnFileNotFound, Boolean forIntrospection, Boolean suppressSecurityChecks)
   at System.Reflection.RuntimeAssembly.InternalLoadAssemblyName(AssemblyName assemblyRef, Evidence assemblySecurity, RuntimeAssembly reqAssembly, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean throwOnFileNotFound, Boolean forIntrospection, Boolean suppressSecurityChecks)
   at System.Reflection.RuntimeAssembly.InternalLoad(String assemblyString, Evidence assemblySecurity, StackCrawlMark& stackMark, IntPtr pPrivHostBinder, Boolean forIntrospection)
   at System.Reflection.RuntimeAssembly.InternalLoad(String assemblyString, Evidence assemblySecurity, StackCrawlMark& stackMark, Boolean forIntrospection)
   at System.Reflection.Assembly.Load(String assemblyString)
   at NHibernate.Util.ReflectHelper.TypeFromAssembly(AssemblyQualifiedTypeName name, Boolean throwOnError)

=== Pre-bind state information ===
LOG: DisplayName = mappedcust2_.CUST_ID.Customer
 (Partial)
WRN: Partial binding information was supplied for an assembly:
WRN: Assembly Name: mappedcust2_.CUST_ID.Customer | Domain ID: 1
WRN: A partial bind occurs when only part of the assembly display name is provided.
WRN: This might result in the binder loading an incorrect assembly.
WRN: It is recommended to provide a fully specified textual identity for the assembly,
WRN: that consists of the simple name, version, culture, and public key token.
WRN: See whitepaper http://go.microsoft.com/fwlink/?LinkId=109270 for more information and common solutions to this issue.
LOG: Appbase = file:///C:/.../Debug/
LOG: Initial PrivatePath = NULL
Calling assembly : NHibernate, Version=5.3.0.0, Culture=neutral, PublicKeyToken=aa95f207798dfdb4.
===
LOG: This bind starts in default load context.
LOG: Using application configuration file: C:\...\Debug\App.exe.Config
LOG: Using host configuration file: 
LOG: Using machine configuration file from C:\Windows\Microsoft.NET\Framework\v4.0.30319\config\machine.config.
LOG: Policy not being applied to reference at this time (private, custom, partial, or location-based assembly bind).
LOG: The same bind was seen before, and was failed with hr = 0x80070002.

I haven't yet reduced the query to a minimal reproducable sample, but the query is something like this:

public int GetCountOfChangeEntries(User user) {
   var customerQuery = session.Query<Project>()
      .Where(x =>
         !x.State.Completed &&
         x.User == user &&
         ((SpecificProject)x).Successor == null
      )
      .SelectMany(x => x.CustomerRelations)
      .Select(x => x.Customer);

   return session.Query<ChangeEntry>()
      .Count(x => customerQuery.Contains(x.Customer) && x.State == ChangeEntryState.Unhandled);
}

Maybe there are more queries that log that error, but I've only noticed it for this one until now.
The query seems to work fine even with the error.

The properties/columns mentioned in the error message (mappedcust2_.IS_LEAD_CUSTOMER, mappedcust2_.CUST_ID.Customer) are contained in a relation-component that is used via the CustomerRelations property in the query. It's mapped as a component collection on both sides (Customer and Project) and contains two references (one parent reference and one to the other entity) and a simple bool property (with the column name IS_LEAD_CUSTOMER).

When I downgrade to 5.3.8 the error doesn't happen any more. The Linq query produces the same SQL with both versions.

[bahusoid]

It's definitely caused by #2810 Error is logged when probing if provided path is entity join vs association join. It's just a log - it shouldn't affect behavior in any way. Not sure how to fix it...

Existing test that logs this error: OneToOneCompositeQuerySelectProjection

[hazzik]

@cremor is there further stack trace? Who calls NHibernate.Util.ReflectHelper.TypeFromAssembly?

[cremor]

@hazzik I posted the full stack trace that is logged. But if I disable "just my code" and break at first chance exceptions, I get this in the VS call stack window:

System.Reflection.RuntimeAssembly.nLoad(System.Reflection.AssemblyName fileName, string codeBase, System.Security.Policy.Evidence assemblySecurity, System.Reflection.RuntimeAssembly locationHint, ref System.Threading.StackCrawlMark stackMark, System.IntPtr pPrivHostBinder, bool throwOnFileNotFound, bool forIntrospection, bool suppressSecurityChecks)
System.Reflection.RuntimeAssembly.InternalLoadAssemblyName(System.Reflection.AssemblyName assemblyRef, System.Security.Policy.Evidence assemblySecurity, System.Reflection.RuntimeAssembly reqAssembly, ref System.Threading.StackCrawlMark stackMark, System.IntPtr pPrivHostBinder, bool throwOnFileNotFound, bool forIntrospection, bool suppressSecurityChecks)
System.Reflection.RuntimeAssembly.InternalLoad(string assemblyString, System.Security.Policy.Evidence assemblySecurity, ref System.Threading.StackCrawlMark stackMark, System.IntPtr pPrivHostBinder, bool forIntrospection)
System.Reflection.RuntimeAssembly.InternalLoad(string assemblyString, System.Security.Policy.Evidence assemblySecurity, ref System.Threading.StackCrawlMark stackMark, bool forIntrospection)
System.Reflection.Assembly.Load(string assemblyString)
NHibernate.Util.ReflectHelper.TypeFromAssembly(NHibernate.Util.AssemblyQualifiedTypeName name, bool throwOnError)
NHibernate.Util.ReflectHelper.ClassForFullNameOrNull(string classFullName)
NHibernate.Impl.SessionFactoryImpl.GetImplementors(string entityOrClassName)
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.ResolveEntityJoinReferencedPersister(NHibernate.Hql.Ast.ANTLR.Tree.IASTNode path)
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.CreateFromJoinElement(NHibernate.Hql.Ast.ANTLR.Tree.IASTNode path, NHibernate.Hql.Ast.ANTLR.Tree.IASTNode alias, int joinType, NHibernate.Hql.Ast.ANTLR.Tree.IASTNode fetchNode, NHibernate.Hql.Ast.ANTLR.Tree.IASTNode propertyFetch, NHibernate.Hql.Ast.ANTLR.Tree.IASTNode with)
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.joinElement()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.fromElement()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.fromElementList()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.fromClause()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.unionedQuery()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.query()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.collectionFunctionOrSubselect()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.inRhs()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.comparisonExpr()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.logicalExpr()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.logicalExpr()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.whereClause()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.unionedQuery()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.query()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.selectStatement()
NHibernate.Hql.Ast.ANTLR.HqlSqlWalker.statement()
NHibernate.Hql.Ast.ANTLR.HqlSqlTranslator.Translate()
NHibernate.Hql.Ast.ANTLR.QueryTranslatorImpl.Analyze(string collectionRole)
NHibernate.Hql.Ast.ANTLR.QueryTranslatorImpl.DoCompile(System.Collections.Generic.IDictionary<string, string> replacements, bool shallow, string collectionRole)
NHibernate.Hql.Ast.ANTLR.ASTQueryTranslatorFactory.CreateQueryTranslators(NHibernate.IQueryExpression queryExpression, NHibernate.Hql.Ast.ANTLR.Tree.IASTNode ast, string queryIdentifier, string collectionRole, bool shallow, System.Collections.Generic.IDictionary<string, NHibernate.IFilter> filters, NHibernate.Engine.ISessionFactoryImplementor factory)
NHibernate.Hql.Ast.ANTLR.ASTQueryTranslatorFactory.CreateQueryTranslators(NHibernate.IQueryExpression queryExpression, string collectionRole, bool shallow, System.Collections.Generic.IDictionary<string, NHibernate.IFilter> filters, NHibernate.Engine.ISessionFactoryImplementor factory)
NHibernate.Engine.Query.QueryPlanCache.GetHQLQueryPlan(NHibernate.IQueryExpression queryExpression, bool shallow, System.Collections.Generic.IDictionary<string, NHibernate.IFilter> enabledFilters)
NHibernate.Impl.AbstractSessionImpl.GetHQLQueryPlan(NHibernate.IQueryExpression queryExpression, bool shallow)
NHibernate.Impl.AbstractSessionImpl.CreateQuery(NHibernate.IQueryExpression queryExpression)
NHibernate.Linq.DefaultQueryProvider.PrepareQuery(System.Linq.Expressions.Expression expression, out NHibernate.IQuery query)
NHibernate.Linq.DefaultQueryProvider.Execute(System.Linq.Expressions.Expression expression)
NHibernate.Linq.DefaultQueryProvider.Execute<int>(System.Linq.Expressions.Expression expression)
System.Linq.Queryable.Count<MyEntityType>(System.Linq.IQueryable<MyEntityType> source, System.Linq.Expressions.Expression<System.Func<MyEntityType, bool>> predicate)
<my code here>

[hazzik]

Not sure how to fix it...

Reduce the log level from error to warning if throwOnError is true?

[cremor]

How would that change anything? throwOnError is false in this case (called from ClassForFullNameOrNull).
And even if it was true: Then I would have a confusing warning in my log 😉

About how to fix this: Maybe check the given entityName against the names of all mapped entities before calling GetImplementors()? An entity that isn't mapped can't have an implementor, right?

[bahusoid]

An entity that isn't mapped can't have an implementor, right?

Nope. Not mapped interface/base class can have implementors (mapped classes implementing this interface). That's exactly why this change was introduced - to support joins on unmapped interface.

[cremor]

It's not very nice, but a possibility would be to add a logOnError optional parameter (or overload) to TypeFromAssembly(). That could be set to false when called from ClassForFullNameOrNull().

At least as I understand the method ClassForFullNameOrNull() it isn't an error when no type is found, so not logging it would be fine.

[bahusoid]

As a workaround you can just disable logging from NHibernate.Util.ReflectHelper there is really nothing useful logged there for end user.

add a logOnError optional parameter

I agree - it's not very nice :)

This GetImpelementors call is "side-effecty" - it caches results (so only one exception per query is logged). And I don't really like that now it caches such random parts of query. Ideally we should avoid this call if possible...