调试CLR挂起

问题描述 投票:12回答:1

我已经上传了WinDBG会话的日志,我将参考该日志:https://pastebin.com/TvYD9500

因此,我正在调试客户报告的挂起。复制器是一个小的C#程序:

using System;
using System.Data.Odbc;
using System.Threading;

namespace ConnectionPoolingTest
{
    class Program
    {
        static void Main(string[] args)
        {
            String connString = "DSN=DotNetUltraLightDSII";
            using (OdbcConnection connnection = new OdbcConnection(connString))
            {
                connnection.Open();
                connnection.Close();
            }
        }
    }
}

我们出售了一个用于构建ODBC驱动程序的框架,而客户正在测试使用该框架构建的ODBC驱动程序。可能相关的一个细节是,他们正在使用一种组件,该组件允许用C#编写其业务逻辑,而该组件是用C ++ / CLI编写的,以便在本机代码和客户代码之间建立桥梁(因此,ODBC驱动程序DLL是一种混合模式的DLL,它向ODBC驱动程序管理器公开C接口。]

((如果需要,我也可以上传驱动程序二进制文件。)

在此复制器中发生的情况(必须在使用的DSN上启用连接池的情况下运行),该过程最终以带有堆栈的单个线程挂起,看起来像:

RetAddr           : Args to Child                                                           : Call Site
000007fe`fcea10dc : 00000000`00470000 00000000`770d0290 00000000`00000000 00000000`009ae8e0 : ntdll!ZwWaitForSingleObject+0xa
000007fe`f0298407 : 00000000`00999a98 00000000`770d5972 00000000`00000000 00000000`00000250 : KERNELBASE!WaitForSingleObjectEx+0x79
000007fe`f0294d04 : 00000000`00999a98 00000000`00a870e0 00000000`00999a68 00000000`00991a10 : comsvcs!UTSemReadWrite::LockWrite+0x90
000007fe`f0294ca8 : 00000000`00999a68 00000000`00999a98 00000000`00999a20 00000000`7717ba58 : comsvcs!CDispenserManager::~CDispenserManager+0x2c
000007fe`f02932a8 : 00000000`00999a20 00000000`00a871c0 00000000`77182e70 00000000`7717ba58 : comsvcs!ATL::CComObjectCached<ATL::CComClassFactorySingleton<CDispenserManager> >::`scalar deleting destructor'+0x68
000007fe`f0293a00 : 000007fe`f0290000 00000000`00000001 00000000`00000001 00000000`00a87198 : comsvcs!ATL::CComObjectCached<ATL::CComClassFactorySingleton<CDispenserManager> >::Release+0x20
000007fe`f02949aa : 00000000`00000000 00000000`00a87188 00000000`00992c20 00000000`00992c30 : comsvcs!ATL::CComModule::Term+0x35
000007fe`f0293543 : 00000000`00000000 00000000`00a87190 00000000`00000001 00000000`00a87278 : comsvcs!`dynamic atexit destructor for 'g_ModuleWrapper''+0x22
000007fe`f029355b : 00000000`00000001 00000000`00000000 000007fe`f0290000 00000000`76f515aa : comsvcs!CRT_INIT+0x96
00000000`7708778b : 000007fe`f0290000 00000000`00000000 00000000`00000001 00000000`7717ba58 : comsvcs!__DllMainCRTStartup+0x187
00000000`7708c1e0 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!LdrShutdownProcess+0x1db
000007fe`efb4ee58 : 00000000`00486b10 00000000`00000001 00000000`00482460 00000000`00000000 : ntdll!RtlExitUserProcess+0x90
000007fe`efb4efd4 : 00000000`00000000 000007fe`efb4efc0 ffffffff`00000000 00000000`004868a0 : mscoreei!RuntimeDesc::ShutdownAllActiveRuntimes+0x287
000007fe`eefa9535 : 00000000`0042f4b8 000007fe`ef53d6c0 00000000`0042f488 00000000`004868a0 : mscoreei!CLRRuntimeHostInternalImpl::ShutdownAllRuntimesThenExit+0x14
000007fe`eefa9495 : 00000000`00000000 00000000`0042f488 00000000`00000000 00000000`00000000 : clr!EEPolicy::ExitProcessViaShim+0x95
000007fe`eee83336 : 00000000`00000006 00000000`0042f870 00000000`00000000 00000000`00000000 : clr!SafeExitProcess+0x9d
000007fe`eee61c51 : 00000000`01000000 00000000`0042f870 00000000`00000000 00000000`00000000 : clr!HandleExitProcessHelper+0x3e
000007fe`eee62034 : ffffffff`ffffffff 000007fe`eee62020 00000000`00000000 00000000`00000000 : clr!_CorExeMainInternal+0x101
000007fe`efb47b2d : 00000000`00000000 00000000`00000091 00000000`00000000 00000000`0042f7c8 : clr!CorExeMain+0x14
000007fe`efbe5b21 : 00000000`00000000 000007fe`eee62020 00000000`00000000 00000000`00000000 : mscoreei!CorExeMain+0x112
00000000`76f4556d : 000007fe`efb40000 00000000`00000000 00000000`00000000 00000000`00000000 : MSCOREE!CorExeMain_Exported+0x57
00000000`770a385d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

我能够找到UTSemReadWrite类的一些源代码(但似乎与我实际运行的代码有所不同:https://github.com/dotnet/coreclr/blob/616fea550548af750b575f3c304d1a9b4b6ef9a6/src/utilcode/utsem.cpp

将断点放入UTSemReadWrite :: LockWrite中,我能够调试挂起的最后一个调用,发现原因是m_dwFlag(用于原子性)不为零,因此它继续等待一个事件(当拥有它的线程在释放它时发出信号),它通过调用UTSemReadWrite :: GetWriteWaiterEvent来实现,但是调用creates事件(并且此时没有其他线程...) ,然后等待。动臂,僵局。

从调试开始,到组装为止,我可以推断出m_dwFlag被偏移了4个字节,然后在UTSemReadWrite :: UTSemReadWrite中设置了一个断点,就可以得到挂起所涉及的UTSemReadWrite实例的地址。 ,然后在m_dwFlag上放置一个数据断点。

[这样做,我确实可以看到,具有线程函数comsvc​​s!PingThread的线程在调用comsvc​​s!UTSemReadWrite :: UnlockRead之前被杀死之前,已调用comsvc​​s!UTSemReadWrite :: LockRead(并大概获得了锁)。我以前见过类似的东西,这是由于未处理的SEH异常杀死了PingThread引起的,但是应用程序使用setunhandledexceptionfilter()阻止了崩溃,所以我认为也许是某些异常正在杀死线程,但是事实证明这是CLR本身!

RetAddr           : Args to Child                                                           : Call Site
00000000`7708c198 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!ZwTerminateProcess+0xa
000007fe`efb4ee58 : 00000000`00486b10 00000000`00000001 00000000`00482460 00000000`00000000 : ntdll!RtlExitUserProcess+0x48
000007fe`efb4efd4 : 00000000`00000000 000007fe`efb4efc0 ffffffff`00000000 00000000`004868a0 : mscoreei!RuntimeDesc::ShutdownAllActiveRuntimes+0x287
000007fe`eefa9535 : 00000000`0042f4b8 000007fe`ef53d6c0 00000000`0042f488 00000000`004868a0 : mscoreei!CLRRuntimeHostInternalImpl::ShutdownAllRuntimesThenExit+0x14
000007fe`eefa9495 : 00000000`00000000 00000000`0042f488 00000000`00000000 00000000`00000000 : clr!EEPolicy::ExitProcessViaShim+0x95
000007fe`eee83336 : 00000000`00000006 00000000`0042f870 00000000`00000000 00000000`00000000 : clr!SafeExitProcess+0x9d
000007fe`eee61c51 : 00000000`01000000 00000000`0042f870 00000000`00000000 00000000`00000000 : clr!HandleExitProcessHelper+0x3e
000007fe`eee62034 : ffffffff`ffffffff 000007fe`eee62020 00000000`00000000 00000000`00000000 : clr!_CorExeMainInternal+0x101
000007fe`efb47b2d : 00000000`00000000 00000000`00000091 00000000`00000000 00000000`0042f7c8 : clr!CorExeMain+0x14
000007fe`efbe5b21 : 00000000`00000000 000007fe`eee62020 00000000`00000000 00000000`00000000 : mscoreei!CorExeMain+0x112
00000000`76f4556d : 000007fe`efb40000 00000000`00000000 00000000`00000000 00000000`00000000 : MSCOREE!CorExeMain_Exported+0x57
00000000`770a385d : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : KERNEL32!BaseThreadInitThunk+0xd
00000000`00000000 : 00000000`00000000 00000000`00000000 00000000`00000000 00000000`00000000 : ntdll!RtlUserThreadStart+0x1d

((这带来了一个问题;因此ntdll!ZwTerminateProcess不会actually终止该进程吗?因为它显然已返回并调用了atexit处理程序...我想这是一个同名的不同函数吗?[C0 ])

所以,我的问题是,我是否在解释调试器正确显示的内容?这实际上是CLR中的错误吗? CLR是否不应该先优雅地结束线程?

引起客户注意的是,如果客户在驱动程序中创建一个线程作为后台线程,则挂起不会发生,这很奇怪,因为在卸载驱动程序时,即使是前台线程也应该很快停止(通过在驱动程序的句柄上调用SQLFreeHandle()的终结器),除非终结器线程因某些原因而变慢,否则我猜是吗?

发送给我们的再现驱动程序中的后台线程基本上是

https://docs.microsoft.com/en-us/windows-hardware/drivers/ddi/content/ntddk/nf-ntddk-zwterminateprocess

和Dispose()被正确调用,退出。

我不确定下一步如何处理。

编辑:阅读public Driver() { this.tokenSource= new CancellationTokenSource(); this.token = this.tokenSource.Token; this.worker= new Thread(this.DoWork) { IsBackground = false }; this.worker.Start(); } public override void Dispose() { this.tokenSource.Cancel(); this.worker.Join(); this.tokenSource.Dispose(); base.Dispose(); } private void DoWork() { while (!this.token.WaitHandle.WaitOne(200)) { log(this.Log, "Doing some work...."); } log(this.Log, "Done with work."); } 之后,我感到这是CLR的错误/“怪癖”。在我的方案中,最后一个前景.NET线程在ODBC驱动程序中。当ODBC驱动程序管理器调用this卸载驱动程序时(不确定是从Windows线程池中的某个线程还是由驱动程序管理器本身拥有的某个线程卸载),这将导致驱动程序终止最后一个前台线程。根据我对从该文章中获得的CLR关闭过程的理解,CLR最终会在它有机会从其实际返回之前终止杀死调用SQLFreeHandle的线程,这是预期的行为。

但是该线程似乎持有该UTSemReadWrite锁,因此稍后在atexit处理期间它将死锁。

我唯一的解决方法,如果这实际上是CLR的错误,那就是在对SQLFreeHandle的最终调用上启动另一个(foreground).NET线程,该线程最终将在超时后终止自身(希望足够长的时间) SQLFreeHandle线程释放它持有的所有锁),以延迟CLR关闭。如果最终导致应用程序关闭,那不是很理想...

编辑:实际上,即使那样的想法也不能真正起作用,因为这意味着ODBC驱动程序管理器实际上可能在线程正在从中执行代码时卸载驱动程序,从而导致崩溃。

c# odbc clr deadlock
1个回答
0
投票

我已经与Microsoft支持人员交谈过,他们已经确认这是comsvc​​s组件的问题,他们可能会在Windows的未来版本中解决此问题。如果他们告诉我他们已解决问题,我将进行更新。

© www.soinside.com 2019 - 2024. All rights reserved.