NHibernate suddenly very slow - inexplicable behaviour

Question

I know this is a popular issue and various solutions have been proposed to others, but mine is slightly different.

Firstly it started happening suddenly since two days ago and nothing has changed in the NHibernate layer to explain such a change in behaviour.

I used dotTrace and drill down to it and found that certain cached queries take up to 70 seconds to perform (i.e. a GetAllCountries() method that returns a list of country objects).

70 seconds is pretty insane for such a simple query that doesn't have external references.

dotTrace reveals that it called the CachedCountryService which should return the list immediately. Instead it eventually leads to the CountryService which performs the 70 second read.

The database is mySQL.

An attached image of the dotTrace report

The Country object looks like this:

   public class CountryMapping : ClassMap<Country>
    {
        public CountryMapping()
        {
            Table("ma_tbl_country");

            Id(t => t.Id, "id");
            Map(t => t.Code, "code");
            Map(t => t.Name, "name");
            Map(t => t.Match, "`match`");

            References(t => t.RiskGroup).Column("RiskId");

            HasManyToMany(t => t.PaymentOptions)
                .Table("ma_tbl_country_payment_option")
                .ParentKeyColumn("country_id")
                .ChildKeyColumn("payment_option_id").Cascade.SaveUpdate();
        }
    }

The Initializer doesn't affect the country object although Office and Account are used in anoher NHibernate query that performs really poorly (takes 30 seconds).

 public NHibernateInitializer()
        {
            base.
            ExtraConfiguration =
                t =>
                    t.Mappings(s => s.FluentMappings.AddFromAssemblyOf<DAL.Mappings.OfficeMapping>().Conventions.Add(typeof(DisableLazyLoadConvention)))
                    .Mappings(s => s.FluentMappings.AddFromAssemblyOf<AccountMapping>().Conventions.Add(AutoImport.Never()));
        }

And the DefaultLazyConvention is part of an internal library that does this:

  public class DisableLazyLoadConvention : IHibernateMappingConvention, IConvention<IHibernateMappingInspector, IHibernateMappingInstance>, IConvention
  {
    public void Apply(IHibernateMappingInstance instance)
    {
      instance.Not.DefaultLazy();
    }
  }

UPDATE:

I added SQL level profiling and the results are buffling.

I have two different projects running the same almost code and I get 324 sql queries in the slow projects taking 100 seconds to run and then 324 IDENTICAL queries in the other project taking 1 second!

So I believe the problem is NHibernate configuration, rather than code because these two set of queries are identical using the same domain models. They're also using the same database with the same db user.

Answer 1

FINALLY got this resolved.

It wasn't NHibernate related! That's why it was so impossible to resolve.

The problem was caused by this package called Combres. It is installed via Nuget with a lot of dependencies. In one of my projects, one of the dependencies was slightly higher version than it expected.

When I uninstalled it and re-installed it, it put the correct DLL versions in place (the slightly older ones) and that made the project work lightning fast!

If anyone is ever caught in such a difficult problem, I hope this might help them to resolve it.

Answer 2

From your dotTrace screenshot, please notice that InitializeNonLazyCollections is taking almost all of the time.

The DisableLazyLoadConvention is being applied to more than just Office. It is being applied to all ClassMaps in the same assembly as OfficeMapping. Conventions are used to apply mappings in wide paintbrush strokes across your entire application. For example, you can use them to say things like "Whenever you see a DateTime property whose name ends with 'Utc', map it using .CustomType("UtcDateTime")."

If you need to apply special mappings to just one class, do so in the ClassMap (for fluent mappings) or in an IAutoMappingOverride (for auto mapping). If you want to change the mapping for every class, that's when you use conventions.

Remove .Conventions.Add(typeof(DisableLazyLoadConvention)) from your NHibernate initialization code, and replace it with more targeted calls to .Not.LazyLoad() in OfficeMapping.