Locks and Waits analysis AV on SetEvent

[Patrick_Frants]

Hi,

When using the Locks and Waits analysis, the tpsstool hooks the SetEvent API. During startup of our application not too much is happening in parallel and everything works. At some stage the application starts receiving and processing a lot of data in parallel (8 threads) and then the hook indirectly causes an access violation and the unhandled exception handler is called:

MSVCR80!_CxxFrameHandler3+0x180
MSVCR80!_CxxExceptionFilter+0x2db
MSVCR80!_CxxExceptionFilter+0xafb
MSVCR80!_CxxExceptionFilter+0xd3b
MSVCR80!_CxxFrameHandler3+0x77
ntdll!RtlDecodePointer+0xbd
ntdll!RtlUnwindEx+0xbbf
ntdll!KiUserExceptionDispatcher+0x2e
ntdll!RtlAcquireSRWLockExclusive+0x13
ntdll!RtlDeregisterWaitEx+0x62
KERNELBASE!UnregisterWaitEx+0x1b
tpsstool!tpss_tp___itt_model_disable_push_post_cbk_impl+0x139daa
tpsstool!tpss_tp___itt_model_disable_push_post_cbk_impl+0x13a7f3
<Our code calls SetEvent()>

I tried both Update 4 and 5 and got the same result and it's completely reproducable. HotSpots analysis is working fine. Would have expected ERROR_INVALID_HANDLE in case there was a problem with the lifetime of the event object. Alltough I have never seen any evidence of our handling of mutexes there probably is a problem. Before spending another N days on this I want to know wether anybody recognized the callstack above? If so, what was the problem/fix in your case?

Running Windows Server 2008 R2 SP1, x64 and Xeon E5-4640 processor.

Patrick

[SergeyKostrov]

>>...At some stage the application starts receiving and processing a lot of data in parallel (8 threads) and then the hook >>indirectly causes an access violation and the unhandled exception handler is called... I'd like to confirm that: - Your application works without any problems when VTune is Not used - Your application works without any problems when VTune's HotSpots Analysis is used - Your application crashes ( with some exception ) when VTune's Locks and Waits Analysis is used Is that correct? Thanks in advance.

[Patrick_Frants]

That's correct. The third case happens when multiple (in my test 8) threads have been running at 100% for about 5-10 seconds.

Found an old (2005) post by Doug Harisson MVP, saying that some API functions use structured exception handling as part of their design. I hope that's not the case with SetEvent and it does not explain why it only happens with Locks and Wait analysis. So I consider this a dead end.

Patrick

[Bernard]

Hi Patrick, Does this function "tpsstool!tpss_tp___itt_model_disable_push_post_cbk_impl" makes a blocking call to UnregisterWaitEx() routine?

[SergeyKostrov]

>>Found an old (2005) post by Doug Harisson MVP, saying that some API functions use structured exception handling as part of >>their design. I hope that's not the case with SetEvent and it does not explain why it only happens with Locks and Wait analysis. It is really hard to tell what exactly could be wrong and if you manage to create a reproducer for Intel software engineers that would help. I think it could be ( possibly ) a bug in VTune.

[Bernard]

By looking at the call stack snippet I can see that RtlAcquireSRWLockExclusive is throwing an exception which is caught by KiUserExceptionDispatcher both of these functions are executing in kernel mode because some of the synchronization is done by the kernel.It is interesting if the exception is caused by lock acquiring function?

[Bernard]

This is follow up.

One of the user-mode slim reader-writer functions will throw an exception when the lock can not be acquired.Could this be the situation in your case?

[Patrick_Frants]

@Iliya: The tppstool callstack entries belong to the tppstool hooks injected by VTune.

The story continues. I typed this over from a console window because the "... has stopeed working" dialog. Note that this is update 4.

Assertion 'attach_notification_result == tpss_er_success' failed [ASSERTION CONTEXT]attach_notification_result = 14[CONTEXT END] Please contact te

And one of the threads:

KERNELBASE!DebugBreak+0x3
tpsstool!tpss_tp___itt_model_init+0x2360a
tpsstool!tpss_tp___itt_model_disable_push_post_cbk_impl+0x148ca
tpsstool!main+0x181
tpsstool!LEVEL_PINCLIENT::ClientInt+0x5f7e
pinvm!PinWinMain+0xa5a
tpsstool!main+0x11c
pinvm!PinWinMain+0x1563
pinvm!PinWinMain+0x1911
Unable to read dynamic function table entry at 000007feeb032230
Unable to read dynamic function table entry at 000007feeb032270
pinvm+0x22614
Unable to read dynamic function table entry at 000007feeb0322b0
Unable to read dynamic function table entry at 000007feeb0322f0
Unable to read dynamic function table entry at 000007feeb032330
Unable to read dynamic function table entry at 000007feeb032370
Unable to read dynamic function table entry at 000007feeb0323b0
0x00000003`9fc20080
Unable to read dynamic function table entry at 000007feeb0323f0
Unable to read dynamic function table entry at 000007feeb032230
Unable to read dynamic function table entry at 000007feeb032270
Unable to read dynamic function table entry at 000007feeb0322b0
0x00000004`78b1f9e0
Unable to read dynamic function table entry at 000007feeb0322f0
pinvm!PinWinMain+0x15af
pinvm!NativeTlsSetValue+0x7f523

Don't know what to think. Even if the Tls callstack entry is correct, we do check the return value of TlsAlloc. Assertion indicates a VTune logic bug?

Patrick

[Bernard]

Can you run your application under windbg and reproduce the access violation error?

[Bernard]

Patrick

MSDN explains that UnregisterWaitEx() should not be called when caller is blocking.By inspecting your first call stack I think that hook injected by VTune is blocking while waiting on some event.One of the approaches would be to put breakpoint on this function  "tpsstool!tpss_tp___itt_model_disable_push_post_cbk_impl+0x139daa" and  backward disassemble in order to look for any calls to WaitFor functions.

[Patrick_Frants]

iliyapolak wrote:

Can you run your application under windbg and reproduce the access violation error?

• Application ==> No problem
• WinDbg + Application ==> No problem
• Application+VTune Locks and Waits ==> Problem
• WinDbg + Application+VTune Locks and Waits ==> pinvm.dll and tpsstool.dll are loaded and 35 threads are started. Terminate process called from pinvm. Amplifier UI: "There is no viewpoint applicable" commandline: "database interface error"

Patrick

[Patrick_Frants]

Sergey Kostrov wrote:

>>Found an old (2005) post by Doug Harisson MVP, saying that some API functions use structured exception handling as part of
>>their design. I hope that's not the case with SetEvent and it does not explain why it only happens with Locks and Wait analysis.

It is really hard to tell what exactly could be wrong and if you manage to create a reproducer for Intel software engineers that would help. I think it could be ( possibly ) a bug in VTune.

I can only see my own issues in Premier Support. Is there any other place where I can search for open issues on the VTune products?

Patrick

[Patrick_Frants]

Just realized that we previously used MEM_TOP_DOWN with VirtualAlloc and changed the call to not use MEM_TOP_DOWN anymore:

• MEM_TOP_DOWN ==> No problems
• NO MEM_TOP_DOWN ==> Problem.

Now I need to figure out whether it's our code or VTune injection code that is affected by the different VirtualAlloc behaviour. Somehow I would expect that reusing (MEM_TOP_DOWN) virtual address space would be more likely to cause problems.
Patrick

[SergeyKostrov]

>>...Just realized that we previously used MEM_TOP_DOWN with VirtualAlloc and changed the call to not use >>MEM_TOP_DOWN anymore... I would consider it as an important change in codes and it is interesting that it created a problem. Thanks for the update. >>...I can only see my own issues in Premier Support. Is there any other place where I can search for open issues >>on the VTune products? That forum is a right place to ask any questions about VTune and Premier Support needs to be considered as well.

[Bernard]

>>>Application+VTune Locks and Waits ==> Problem>>>

I think that your first post (call stack) can give some clue.I assume that this thread has the faulting ip.

>>>Terminate process called from pinvm>>>

It would be interesting to put a breakpoint on TerminateProcess() function and inspect its parameters I mean what routine and why passed a handle of process which is about  be terminated.

[SergeyKostrov]

>>...It would be interesting to put a breakpoint on TerminateProcess() function and inspect its parameters I mean what >>routine and why passed a handle of process which is about be terminated... Could you explain how VirtualAlloc and TerminateProcess are related to each other when MEM_TOP_DOWN is Not used?

[Bernard]

>>>Could you explain how VirtualAlloc and TerminateProcess are related to each other when MEM_TOP_DOWN is Not used?>>> I'm referring to this >>>Terminate process called from pinvm.>>> and not to the case when developer tested MEM_TOP_DOWN parameter. Without the call stack and the without indentifying the caller and logic which trigerred the call to TerminateProcess() is not an easy task.By putting a breakpoint and going backward(stack backtrace) you can check for occurrence of some conditions that lead to process termination.