5

Resolved

Intermittent NHibernate session issue

description

On several occasions in the past month our Orchard website (v1.8) has started returning 200 codes with empty responses for all pages on the site that are not in the output cache. Each time, only restarting the site's app pool has resolved the issue. When it happens we are seeing the following entry in the Orchard error log for every request to the site:
2014-06-26 08:44:33,968 [8] Orchard.Exceptions.DefaultExceptionPolicy - Default - An unexpected exception was caught
 http://domain.com/team
System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.ObjectDisposedException: Session is closed!
Object name: 'ISession'.
   at NHibernate.Impl.AbstractSessionImpl.ErrorIfClosed() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\AbstractSessionImpl.cs:line 213
   at NHibernate.Impl.AbstractSessionImpl.CheckAndUpdateSessionStatus() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\AbstractSessionImpl.cs:line 206
   at NHibernate.Impl.SessionImpl.get_PersistenceContext() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1158
   at NHibernate.Event.Default.ProxyVisitor.ReattachCollection(IPersistentCollection collection, CollectionType type) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\ProxyVisitor.cs:line 64
   at NHibernate.Event.Default.WrapVisitor.ProcessCollection(Object collection, CollectionType collectionType) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\WrapVisitor.cs:line 47
   at NHibernate.Event.Default.WrapVisitor.ProcessValue(Int32 i, Object[] values, IType[] types) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\WrapVisitor.cs:line 98
   at NHibernate.Event.Default.AbstractVisitor.ProcessEntityPropertyValues(Object[] values, IType[] types) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractVisitor.cs:line 116
   at NHibernate.Event.Default.DefaultFlushEntityEventListener.OnFlushEntity(FlushEntityEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\DefaultFlushEntityEventListener.cs:line 43
   at NHibernate.Event.Default.AbstractFlushingEventListener.FlushEntities(FlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractFlushingEventListener.cs:line 161
   at NHibernate.Event.Default.AbstractFlushingEventListener.FlushEverythingToExecutions(FlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractFlushingEventListener.cs:line 61
   at NHibernate.Event.Default.DefaultAutoFlushEventListener.OnAutoFlush(AutoFlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\DefaultAutoFlushEventListener.cs:line 32
   at NHibernate.Impl.SessionImpl.AutoFlushIfRequired(ISet`1 querySpaces) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1180
   at NHibernate.Impl.SessionImpl.List(CriteriaImpl criteria, IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1959
   at NHibernate.Impl.CriteriaImpl.List(IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 265
   at NHibernate.Impl.CriteriaImpl.List[T]() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 277
   at Orchard.ContentManagement.DefaultContentManager.GetManyImplementation(QueryHints hints, Action`2 predicate) in c:\Users\Josh\Documents\Orchard\orchard\src\Orchard\ContentManagement\DefaultContentManager.cs:line 359
   at Orchard.ContentManagement.DefaultContentManager.GetMany[T](IEnumerable`1 ids, VersionOptions options, QueryHints hints) in c:\Users\Josh\Documents\Orchard\orchard\src\Orchard\ContentManagement\DefaultContentManager.cs:line 276
   at Orchard.MediaLibrary.Handlers.MediaLibraryPickerFieldHandler.<>c__DisplayClass3.<InitilizeLoader>b__1()
   at System.Lazy`1.CreateValue()
--- End of stack trace from previous location where exception was thrown ---
Has anyone else experienced this issue? It appears to be an issue with the NHibernate session but I'm no expert on NHibernate. Could this be something we've done or is this a bug in Orchard itself?

Any help or advice would be appreciated.

comments

CSADNT wrote Jun 27, 2014 at 6:59 AM

Without any detail on what you are doing, which modules you use, if your own modules what they do, it is very uneasy to have an opinion or try a repro.
I would say, try the last 1.8.1 ?
There are so many threads here on NH failures ...

joshby wrote Jun 27, 2014 at 1:33 PM

Thanks for weighing in. That's the thing, I can't repro it either. It's happened 3 times in about six weeks and when it happens it affects every content item on the site. I could list all the modules I'm using but when it happens it appears to affect everything, even accessing a simple page with nothing else seemingly going on.

I was hoping that someone else had seen it before so I could at least get a clue where to start looking.

CSADNT wrote Jun 27, 2014 at 2:24 PM

Maybe you should have started a discussion before opening an issue.
I got many problems with NH, but not this one, this was working until now ....
I still hope that Orchard will get rid of NH at some version.
What is your database ? Your pb looks more as a database unvailable one than Orchard speciifc.

joshby wrote Jun 27, 2014 at 2:49 PM

After I created the issue I wished I had started a discussion thread instead, but CodePlex doesn't let you delete an issue so I just went with it.

We're using SQL Compact - should have mentioned that. It did occur to me that maybe there was some sort of locking issue going on with the database file. I just don't know enough about NHibernate to know if that's a likely cause for the what is happening. Thoughts?

joshby wrote Jun 27, 2014 at 3:01 PM

I found something else possibly related in the logs. Each time this has happened, I find a series of the exception listed below in the error log. Then the site goes into a state where every request to the site throws the exception I described above.
2014-06-26 08:42:21,859 [16] Orchard.Exceptions.DefaultExceptionPolicy - Default - An unexpected exception was caught
 http://domain.com/products/round-latex-balloon-econo-print-11
System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> System.Reflection.TargetInvocationException: Exception has been thrown by the target of an invocation. ---> NHibernate.HibernateException: Found shared references to a collection: Orchard.ContentManagement.Records.ContentItemRecord.Versions
   at NHibernate.Engine.Collections.ProcessReachableCollection(IPersistentCollection collection, CollectionType type, Object entity, ISessionImplementor session) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Engine\Collections.cs:line 110
   at NHibernate.Event.Default.FlushVisitor.ProcessCollection(Object collection, CollectionType type) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\FlushVisitor.cs:line 40
   at NHibernate.Event.Default.AbstractVisitor.ProcessEntityPropertyValues(Object[] values, IType[] types) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractVisitor.cs:line 116
   at NHibernate.Event.Default.AbstractFlushingEventListener.FlushEntities(FlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractFlushingEventListener.cs:line 161
   at NHibernate.Event.Default.AbstractFlushingEventListener.FlushEverythingToExecutions(FlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\AbstractFlushingEventListener.cs:line 61
   at NHibernate.Event.Default.DefaultAutoFlushEventListener.OnAutoFlush(AutoFlushEvent event) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Event\Default\DefaultAutoFlushEventListener.cs:line 32
   at NHibernate.Impl.SessionImpl.AutoFlushIfRequired(ISet`1 querySpaces) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1180
   at NHibernate.Impl.SessionImpl.List(CriteriaImpl criteria, IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\SessionImpl.cs:line 1959
   at NHibernate.Impl.CriteriaImpl.List(IList results) in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 265
   at NHibernate.Impl.CriteriaImpl.List[T]() in c:\Users\sebros\Documents\My Projects\nhibernate-core\src\NHibernate\Impl\CriteriaImpl.cs:line 277
   at Orchard.ContentManagement.DefaultContentManager.GetManyImplementation(QueryHints hints, Action`2 predicate) in c:\Users\Josh\Documents\Orchard\orchard\src\Orchard\ContentManagement\DefaultContentManager.cs:line 359
   at Orchard.ContentManagement.DefaultContentManager.GetMany[T](IEnumerable`1 ids, VersionOptions options, QueryHints hints) in c:\Users\Josh\Documents\Orchard\orchard\src\Orchard\ContentManagement\DefaultContentManager.cs:line 276
   at Orchard.MediaLibrary.Handlers.MediaLibraryPickerFieldHandler.<>c__DisplayClass3.<InitilizeLoader>b__1()
   at System.Lazy`1.CreateValue()
--- End of stack trace from previous location where exception was thrown ---

Piedone wrote Jun 27, 2014 at 3:01 PM

Disposes are supposed to be working as intended so you getting such an exception is strange. Although I have no idea what the cause could be, generally SQL CE is not advised for anything else then development and super simple sites on super cheap hosting.

CSADNT wrote Jun 27, 2014 at 3:18 PM

Agree with zoltan, with SQLCE it is very difficult to trace something, if you have possibility to move to a real SQL Server it would be easier to see if your application forgets locks in the DB or if the transaction get dropped earlier than it should.
Looking to your exception log I fear your DB being corrupted with several versions of a record when one is expected....
In the Admin mode, does your content items display normally ?

joshby wrote Jun 27, 2014 at 3:45 PM

Thanks for the feedback guys. I understand your point about SQLCE, although the site was running fine for several months before we ever saw this issue. It appears to have started after we upgraded to 1.8. The issue is very intermittent too as I mentioned. Its only happened 3 times in about six weeks and the rest of the time the site has run completely fine.

Content items display normally in the admin except when the issue is happening. When it is happening, every request (including admin requests) throws the exception and the site returns an empty response to the user.

joshby wrote Jun 27, 2014 at 4:51 PM

I spot checked a few of the content items that were requested when the "Found shared references to a collection" exception occurred and they do indeed have multiple version in the Orchard_Framework_ContentItemVersion table but only one of them has Published and Latest set to true. That seems correct to me.

On second thought, I'm not sure how a request to display a content item would throw the "Found shared references to a collection" in the first place. Isn't that an exception caused when an attempt is made to persist more than one entity instance sharing the same collection reference? How would that happen when displaying a content item?

Vifani wrote Aug 30, 2014 at 1:48 PM

Hi guys,
I have found the same issue. If someone is interested you will find more screenshots and log here: http://orchard.codeplex.com/workitem/20895

I hope that this issue will be solved asap.

sebastienros wrote Jan 8, 2015 at 8:57 PM

Please try with the 1.8.x branch as we have improved the sessions lifetimes.

monikasarda wrote Oct 10, 2016 at 2:07 PM

I am facing the same issue with Orchard 1.8.1. Is this issue resolved now?