Debugging under UnitRunner halts when step over NHibernate proxied object

I'm using NHibernate 1.2.0.CR1 in a project I'm trying to unit test. Unit testing via UnitRunner works just fine. My problem is while debugging using UnitRunner. Debugging works normally until I attempt to step or go over a line that contains a C# object that is currently a NHibernate DynamicProxy (such as occurs when an object is lazy-loaded).

As soon as I hit a line that contains an NHibernate proxied object, the unit test halts immediately.

This is a real bummer as I was really hoping to standardize on UnitRunner/ReSharper, but this is a blocking issue for me as we use NHibernate heavily.

Has anyone else seen this problem? Are there any workarounds?

Thanks,
Jer

12 comments
Comment actions Permalink

Hello Jeremy,

what do you mean by 'the unit test halts'? Are you seeing any errors?

Thanks.


Dmitry Shaporenkov
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


I'm using NHibernate 1.2.0.CR1 in a project I'm trying to unit test.
Unit testing via UnitRunner works just fine. My problem is while
debugging using UnitRunner. Debugging works normally until I attempt
to step or go over a line that contains a C# object that is currently
a NHibernate DynamicProxy (such as occurs when an object is
lazy-loaded).

As soon as I hit a line that contains an NHibernate proxied object,
the unit test halts immediately.

This is a real bummer as I was really hoping to standardize on
UnitRunner/ReSharper, but this is a blocking issue for me as we use
NHibernate heavily.

Has anyone else seen this problem? Are there any workarounds?

Thanks,
Jer



0
Comment actions Permalink

I don't see any errors in the output window other than some System.ThreadAbortExceptions. When I step over the line with the proxied object, the debugging session stops just as if I had chose to "stop debugging". There is no error popup or other sign of a problem. The test is just reported as failed.

0
Comment actions Permalink

I don't see any errors in the output window other than some System.ThreadAbortExceptions. When I step over the line with the proxied object, the debugging session stops just as if I had chose to "stop debugging". There is no error popup or other sign of a problem. The test is just reported as failed.

0
Comment actions Permalink

Jeremy Remington wrote:

I'm using NHibernate 1.2.0.CR1 in a project I'm trying to unit test.
Unit testing via UnitRunner works just fine. My problem is while
debugging using UnitRunner. Debugging works normally until I attempt
to step or go over a line that contains a C# object that is currently
a NHibernate DynamicProxy (such as occurs when an object is
lazy-loaded).


I doubt it's ReSharper's problem. Try unchecking "Enable property
evaluation and other implicit function calls" in Visual Studio debugging
settings.

Sergey

0
Comment actions Permalink

Hello Jeremy,

could you also please tell us what Unit Test debugging method you're using
(startup project, attaching to the process etc - this can be configured
in ReSharper|Options|Unit Testing) and does changing this method make any
difference? Thanks.


Dmitry Shaporenkov
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


I don't see any errors in the output window other than some
System.ThreadAbortExceptions. When I step over the line with the
proxied object, the debugging session stops just as if I had chose to
"stop debugging". There is no error popup or other sign of a problem.
The test is just reported as failed.



0
Comment actions Permalink

I'm using the ReSharper 2.5.1 unit testing option installation default. I did try each of the vailable unit testing object options, and each yielded the exact same results.

At little more data, as soon as my function returns the proxied object, the IDE freezes for about 20-30 seconds. This does not happen when debugging outside of ReSharper.

I've attached a screenshot of my quickwatch window, when debugging under ReSharper. Note that my quickwatch window shows correct values for all proxied properties when debugging in another unit test environment such as TestDriven.NET.

Note that I can debug this code fine using TestDriven.NET, as well as with Mailframe StudioTools.

By the way, here are the contents of my output window while debugging with ReSharper, up to the point where the debug session just halts:

'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_32\mscorlib\2.0.0.0__b77a5c561934e089\mscorlib.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.ReSharper.UnitTestRunner.exe', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.ReSharper.Shell.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.ReSharper.UnitTestSupport.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System.Windows.Forms\2.0.0.0__b77a5c561934e089\System.Windows.Forms.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System\2.0.0.0__b77a5c561934e089\System.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System.Drawing\2.0.0.0__b03f5f7f11d50a3a\System.Drawing.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.ReSharper.Util.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System.Xml\2.0.0.0__b77a5c561934e089\System.Xml.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System.Runtime.Remoting\2.0.0.0__b77a5c561934e089\System.Runtime.Remoting.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.dotTrace.Api.dll', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Program Files\JetBrains\ReSharper\VS2005\bin\JetBrains.ReSharper.UnitTestSupport.NUnit.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\381bb6fe\4ab4b12c_785fc701\Dodson.Data.Hibernate.Test.DLL', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\nunit.framework\2.2.9.0__96d09a1eb7f44a77\nunit.framework.dll', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_MSIL\System.Configuration\2.0.0.0__b03f5f7f11d50a3a\System.Configuration.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\2148e65e\0096112e_2754c601\log4net.DLL', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\d1d122b8\76d23ebb_6a5cc701\Dodson.Data.Core.DLL', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\55274f56\984a8536_695cc701\Dodson.Log.DLL', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\99dd9846\c80a9b97_6b5cc701\Dodson.Data.Hibernate.DLL', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\9d3f2a5f\00393179_ca56c701\NHibernate.DLL', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_32\System.Data\2.0.0.0__b77a5c561934e089\System.Data.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\9c898b49\00b29d75_ca56c701\Iesi.Collections.DLL', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\Documents and Settings\jremington\Local Settings\Application Data\assembly\dl3\2T3NXHLX.C4T\71VQGVX9.QYK\1de8448a\002f7ec2_e013c701\Castle.DynamicProxy.DLL', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_32\System.Transactions\2.0.0.0__b77a5c561934e089\System.Transactions.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_32\System.EnterpriseServices\2.0.0.0__b03f5f7f11d50a3a\System.EnterpriseServices.dll', Symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'DynamicAssemblyProxyGen', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'DynamicAssemblyProxyGen', No symbols loaded.
'JetBrains.ReSharper.UnitTestRunner.exe' (Managed): Loaded 'C:\WINDOWS\assembly\GAC_32\ISymWrapper\2.0.0.0__b03f5f7f11d50a3a\ISymWrapper.dll', Symbols loaded.
A first chance exception of type 'System.Threading.ThreadAbortException' occurred in System.Runtime.Remoting.dll
A first chance exception of type 'System.Threading.ThreadAbortException' occurred in mscorlib.dll
A first chance exception of type 'System.Threading.ThreadAbortException' occurred in mscorlib.dll
The program '[4268] JetBrains.ReSharper.UnitTestRunner.exe: Managed' has exited with code -532459699 (0xe0434f4d).



Attachment(s):
ReSharperNHibernateProxyProblem.png
0
Comment actions Permalink

I do believe that the problem is at least ReSharper related, because I only experience this problem when using ReSharper 2.5.1.

Note that when debugging the exact same code using TestDriven.NET, or the Mailframe Studio Tools products, I do not experience this problem at all.

I did try your suggestion, however. I turned off "Enable property evaluation and other implicit function calls" in Visual Studio debugging settings as you suggested. Turning this off prevented the debugger session from aborting, so this provides a possible work-around, although I would consider this much less-than-ideal.

This is a non-ideal workaround because it does not allow me to ever see the values of proxied objects in the debugger. When I try to view a property via the proxied object, instead of the actual value being loaded on-demand, Visual Studio now displays the message "Implicit function evaluation is turned off by user" when I try to view the properties via the in-debugger pop-up window. Note that if I try to use QuickWatch, I get the 20-30 second IDE lock up, after which QuickWatch comes up but the proxied properties are still not displayed, but now with a different message (see attached screenshot).



Attachment(s):
ReSharperNHibernateProxyProblem2.png
0
Comment actions Permalink

Actually, this workaround only prevents the debugger from halting as long as I do not use QuickWatch to try and inspect the proxied object.

As I mentioned previously, bringing up QuickWatch on the proxied object results in the 20-30 second IDE lock-up, before displaying the watch window.

Once the watch window is dismissed, any attempt to step or go in the debugger immediately results in the debugger abort previously described.

So turning off explicit evaluation works fine as long you don't attempt to QuickWatch the object and don't need to inspect proxied properties in the debugger.

0
Comment actions Permalink

"Jeremy Remington" <jremington@gmail.com> wrote in message
news:18324786.1173136429205.JavaMail.itn@is.intellij.net...

Actually, this workaround only prevents the debugger from halting as long
as I do not use QuickWatch to try and inspect the proxied object.

>

As I mentioned previously, bringing up QuickWatch on the proxied object
results in the 20-30 second IDE lock-up, before displaying the watch
window.

>

Once the watch window is dismissed, any attempt to step or go in the
debugger immediately results in the debugger abort previously described.

>

So turning off explicit evaluation works fine as long you don't attempt to
QuickWatch the object and don't need to inspect proxied properties in the
debugger.


I'd suggest you take a look at your ReSharper log to see what's been going
on recently. Maybe it was ReSharper that was executing during that 20-30
second hang.

John


0
Comment actions Permalink

I believe it is ReSharper that is executing during the 20-30 second hang, as this only happens in this particular scenario when running with ReSharper.

My ReSharper log shows that this time is spent doing lots, and lots, and lots of document locking or something. Here's a snippet from the log:

10:53:52 PM.287: Thread:1: +OnAfterFirstDocumentLock, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: +OnRegisterTextBuffer, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: OnRegisterTextBuffer:adding mapping, doc info:, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398, projectFile:\BasicEntityTest.cs 10:53:52 PM.287: Thread:1: -OnRegisterTextBuffer, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: -OnAfterFirstDocumentLock, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: +OnBeforeLastDocumentUnlock, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: -OnBeforeLastDocumentUnlock, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: +OnAfterFirstDocumentLock, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: +OnRegisterTextBuffer, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398 10:53:52 PM.287: Thread:1: OnRegisterTextBuffer:adding mapping, doc info:, docCookie:269075216, fileName:\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398, projectFile:\BasicEntityTest.cs 10:53:52 PM.287: Thread:1: -OnRegisterTextBuffer, docCookie:269075216, fileName:]]>\Data.Hibernate.Test\BasicEntityTest.cs, text buffer:20103398

0
Comment actions Permalink

Hello Jeremy,

does disabling ReSharper (Tools|Add-In Manager) help to get rid of these
delays? Thanks.


Dmitry Shaporenkov
JetBrains, Inc
http://www.jetbrains.com
"Develop with pleasure!"


I believe it is ReSharper that is executing during the 20-30 second
hang, as this only happens in this particular scenario when running
with ReSharper.

My ReSharper log shows that this time is spent doing lots, and lots,
and lots of document locking or something. Here's a snippet from the
log:

10:53:52 PM.287: Thread:1: +OnAfterFirstDocumentLock,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: +OnRegisterTextBuffer,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: OnRegisterTextBuffer:adding mapping,
doc info:, docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398, projectFile:<Data.Hibernate.Test>\BasicEntityTest.cs
10:53:52 PM.287: Thread:1: -OnRegisterTextBuffer,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: -OnAfterFirstDocumentLock,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: +OnBeforeLastDocumentUnlock,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: -OnBeforeLastDocumentUnlock,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: +OnAfterFirstDocumentLock,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: +OnRegisterTextBuffer,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398
10:53:52 PM.287: Thread:1: OnRegisterTextBuffer:adding mapping,
doc info:, docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398, projectFile:<Data.Hibernate.Test>\BasicEntityTest.cs
10:53:52 PM.287: Thread:1: -OnRegisterTextBuffer,
docCookie:269075216,
fileName:<pathremoved>\Data.Hibernate.Test\BasicEntityTest.cs, text
buffer:20103398



0
Comment actions Permalink

Yes. These delays do not occur when ReSharper is disabled, or when I'm debugging the same code with TestDriven.NET

0

Please sign in to leave a comment.