应用程序冻结时的奇怪调用堆栈答案

【问题标题】：Weird call stack when application has frozen应用程序冻结时的奇怪调用堆栈
【发布时间】：2011-02-08 23:22:41
【问题描述】：

我的一个应用程序显然存在死锁问题，并开始调查 EurekaLog 堆栈跟踪。这是最近的一个：

调用堆栈信息：
-------------------------------------------------- -------------------------------------------------- ----------------------------------
|地址 |模块 |单元 |类 |过程/方法 |行 |
-------------------------------------------------- -------------------------------------------------- ----------------------------------
|*异常线程：ID=14208；优先级=0；类=; [主要] |
|------------------------------------------------- -------------------------------------------------- ----------------------------------|
|7C82860C|ntdll.dll | | |KiFast 系统调用 | |
|7C827D27|ntdll.dll | | |ZwWaitForSingleObject | |
|77E61C96|kernel32.dll | | |WaitForSingleObjectEx | |
|77E61C88|kernel32.dll | | |等待单个对象 | |
|77E61C7B|kernel32.dll | | |等待单个对象 | |
|004151C4|MyApp.exe |sysutils.pas |TMultiReadExclusiveWriteSynchronizer|WaitForWriteSignal |16740[1] |
|004151BC|MyApp.exe |sysutils.pas |TMultiReadExclusiveWriteSynchronizer|WaitForWriteSignal |16740[1] |
|0041522C|MyApp.exe |sysutils.pas |TMultiReadExclusiveWriteSynchronizer|BeginWrite |16818[57] |
|004323FB|MyApp.exe |Classes.pas |TDataModule |创建 |11357[1] |
|004323C0|MyApp.exe |Classes.pas |TDataModule |创建 |11356[0] |
|007D744D|MyApp.exe |uRORemoteDataModule.pas |TRORemoteDataModule |创建 |163[1] |
|007D7434|MyApp.exe |uRORemoteDataModule.pas |TRORemoteDataModule |创建 |162[0] |
|007DBFAB|MyApp.exe |Senttrol_Impl.pas | |创建_Senttrol |85[1] |
|00646952|MyApp.exe |uROServer.pas |TROInvoker |CustomHandleMessage |726[11] |
|00407BFA|MyApp.exe |system.pas |TInterfacedObject |_AddRef |17972[1] |
|00404934|MyApp.exe |system.pas |TObject |GetInterface |9003[8] |
|00407B1C|MyApp.exe |system.pas | |_IntfClear |17817[1] |
|00404966|MyApp.exe |system.pas |TObject |GetInterface |9009[14] |
|004048E8|MyApp.exe |system.pas |TObject |GetInterface |8995[0] |
|00407BD7|MyApp.exe |system.pas |TInterfacedObject |QueryInterface |17964[1] |
|77E61680|kernel32.dll | | |联锁递减 | |
|00407C10|MyApp.exe |system.pas |TInterfacedObject |_Release |17977[1] |
|00407B2C|MyApp.exe |system.pas | |_IntfClear |17824[8] |
|004067DF|MyApp.exe |system.pas | |_FinalizeArray |15233[100]|
|00407B1C|MyApp.exe |system.pas | |_IntfClear |17817[1] |
|00646577|MyApp.exe |uROServer.pas |TROClassFactoryList |FindClassFactoryByInterfaceName|619[17] |
|77E6166C|kernel32.dll | | |互锁增量 | |
|00407BFA|MyApp.exe |system.pas |TInterfacedObject |_AddRef |17972[1] |
|00646B72|MyApp.exe |uROServer.pas |TROInvoker |HandleMessage |758[1] |
|006460C5|MyApp.exe |uROServer.pas | |主进程消息 |512[98] |
|00645BAC|MyApp.exe |uROServer.pas | |MainProcessMessage |414[0] |
|00647184|MyApp.exe |uROServer.pas |TROMessageDispatcher |ProcessMessage |929[2] |
|00647130|MyApp.exe |uROServer.pas |TROMessageDispatcher |ProcessMessage |927[0] |
|00647BCF|MyApp.exe |uROServer.pas |TROServer |IntDispatchMessage |1328[27] |
|00647ABC|MyApp.exe |uROServer.pas |TROServer |IntDispatchMessage |1301[0] |
|0064782F|MyApp.exe |uROServer.pas |TROServer |DispatchMessage |1170[11] |
|006477B4|MyApp.exe |uROServer.pas |TROServer |DispatchMessage |1159[0] |
|006477A9|MyApp.exe |uROServer.pas |TROServer |DispatchMessage |1152[1] |
|0064779C|MyApp.exe |uROServer.pas |TROServer |DispatchMessage |1151[0] |
|00659CB6|MyApp.exe |uROLocalServer.pas |TROLocalServer |SendRequest |57[1] |
|00659CA4|MyApp.exe |uROLocalServer.pas |TROLocalServer |SendRequest |56[0] |
|0065A009|MyApp.exe |uROLocalChannel.pas |TROLocalChannel |IntDispatch |99[10] |
|005EE540|MyApp.exe |uROClient.pas |TROTransportChannel |Dispatch |1884[36] |
|005EE3FC|MyApp.exe |uROClient.pas |TROTransportChannel |Dispatch |1848[0] |
|005EEC8F|MyApp.exe |uROClient.pas |TROTransportChannel |调度 |2134[27] |
|00616EC8|MyApp.exe |PCCS_Intf.pas |TSentrol_Proxy |GetNewValues |6585[7] |
|007CBDB9|MyApp.exe |ETAROConnectionForm.pas |TROConnectionForm |SyncSentrolUpdateTimerTimer |855[16] |
|7C82ABE5|ntdll.dll | | |RtlTimeToTime 字段 | |
|004D5D9C|MyApp.exe |Controls.pas |TControl |WndProc |5063[0] |
|004DA05B|MyApp.exe |Controls.pas |TWinControl |WndProc |7304[111] |
|7C81A3AB|ntdll.dll | | |RtlLeaveCriticalSection | |
|0042659C|MyApp.exe |Classes.pas |TThreadList |UnlockList |3359[1] |
|00426598|MyApp.exe |Classes.pas |TThreadList |UnlockList |3359[1] |
|004935BC|MyApp.exe |Graphics.pas | |FreeMemoryContexts |5060[12] |
|00493524|MyApp.exe |Graphics.pas | |FreeMemoryContexts |5048[0] |
|004D9799|MyApp.exe |Controls.pas |TWinControl |MainWndProc |7076[6] |
|004329F4|MyApp.exe |Classes.pas | |StdWndProc |11583[8] |
|7739C09A|USER32.dll | | |CallNextHookEx | |
|004B1343|MyApp.exe |ExtCtrls.pas |TTimer |计时器 |2281[1] |
|00404A30|MyApp.exe |system.pas | |_CallDynaInst |9159[1] |
|004B1227|MyApp.exe |ExtCtrls.pas |TTimer |WndProc |2239[4] |
|004329F4|MyApp.exe |Classes.pas | |StdWndProc |11583[8] |
|7739C42C|USER32.dll | | |获取父母 | |
|7739C45C|USER32.dll | | |获取父母 | |
|773A16E0|USER32.dll | | |调度消息A | |
|773A16D6|USER32.dll | | |调度消息A | |
|004CC234|MyApp.exe |Forms.pas |TApplication |ProcessMessage |8105[23] |
|004CC138|MyApp.exe |Forms.pas |TApplication |ProcessMessage |8082[0] |
|004CC26E|MyApp.exe |Forms.pas |TApplication |HandleMessage |8124[1] |
|004CC264|MyApp.exe |Forms.pas |TApplication |HandleMessage |8123[0] |
|004CC563|MyApp.exe |Forms.pas |TApplication |运行 |8223[20] |
|004CC4B0|MyApp.exe |Forms.pas |TApplication |运行 |8203[0] |
|007F18B3|MyApp.exe |MyApp.dpr | | |215[65] |

在第一次 TTimer 调用之前，堆栈跟踪似乎没问题，之后它包含一些垃圾（？），但最后包含似乎持有主线程的锁。

我可以信任这个堆栈跟踪吗？如果不是，是什么原因造成的？如何避免？

关于基于此堆栈跟踪的死锁有什么想法吗？我不太明白创建数据模块如何死锁..

我使用的是 Delphi 2007。

编辑：我发现了一种情况，其中 DbExpress 连接在主线程和 RemObjects 创建的线程之间共享。在修复了这个问题和一些小问题之后，应用程序现在已经运行了 12 个小时以上，没有出现任何问题。我会等一两天，看看问题是否真的消失了。

【问题讨论】：

您的应用程序中有多少个线程？
它动态改变请求 RemObjects 服务器的数量，但根据任务管理器通常为 10-20。
您是否尝试过定义“DEBUG_MREWS”并查看调试输出？
不行，重新编译VCL/RTL相当极端。
您是否有来自其他线程的调用堆栈可用？你是怎么得到这个调用堆栈的？通过使用防冻功能或其他方式？

标签： delphi delphi-2007

【解决方案1】：

我在关闭我的应用程序并在另一个线程中创建 TForm 或 TDatamodule 时遇到了同样的问题：因为应用程序正在终止，所以 GlobalNameSpace（请参阅其他答案）被锁定（！），所以我的 TRORemoteDataModule 在另一个线程被锁定。因为我使用了另一个锁来等待那个线程，所以我遇到了死锁:-(。

在您的情况下，您必须查看其他线程，以找到已放置锁的线程（并且可能正在等待，否则您不会出现死锁）。我看到一个“SyncSentrolUpdateTimerTimer”：也许你在另一个线程中创建一个 TDatamodule 时做了一个 TThread.Synchronize？

编辑：如果你想在死锁中查看其他线程的堆栈：

尝试进程资源管理器 -> 进程 -> 线程 -> 堆栈（但您需要 map2dbg.exe 将 Delphi .map 文件转换为 Microsoft .dbg 文件以查看调试符号）
http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx
@ 987654322@
试试我的开源 AsmProfiler（采样模式）：它有一个“实时视图”来查看所有线程的堆栈，它使用 Delphi 调试符号（.map、.jdbg 等），所以你不需要 map2dbg .exe（顺便说一句：我制作了这个实时视图，因为我经常使用进程资源管理器并且每次都使用 map2dbg 很恼火）
http://code.google.com/p/asmprofiler/wiki/ProcessStackViewer

【讨论】：

“我试图避免同步调用” - 实际上，这可能是问题的原因。例如，如果您尝试“太努力” - 您可能会从非主线程访问 VCL，这是挂起的一个很好的理由。

【解决方案2】：

你能在调试器下重现这个挂起吗？如果是 - 然后在 GlobalNameSpace 的 Begin/EndWrite/Read 方法上设置断点。输入每个断点的高级属性并打开“Break”选项并打开“Log call stack”选项。

现在，运行您的应用程序并让它挂起。检查事件窗口。您将看到 GlobalNameSpace 调用的完整历史记录。分析一下。一定是某处打错了电话。大概，最后一个。

或者，如果您使用的是 Vista 及更高版本，您可以使用等待链遍历功能，但我忘记了，哪个 Delphi 有它。让您的应用程序挂起并查看线程窗口：应该有阻塞的原因。

在极少数情况下，内存损坏可能会导致挂起。例如，错误的代码可能会擦除/损坏“空闲”/“忙碌”标志，因此第一个尝试获取锁的代码将永远等待，因为没有人释放锁（因为它没有被锁定，它已损坏）。

【讨论】：

我无法在调试器或开发环境中重现此问题。
你有没有复制它？在客户端机器上？

【解决方案3】：

最后一次调用在 TMultiReadExclusiveWriteSynchronizer 中，但没有显示在哪个方法中。那里可能正在调用 Windows 同步功能，并在那里被阻止。你在使用 RemObjects 库吗？那里正在发生一些事情。您可以使用配置为下载 Windows 符号并在进程运行时检查堆栈跟踪的 SysInternals Process Explorer，如果您将 Delphi 符号转换为 .dbg 格式，您将拥有整个显式调用堆栈。

【讨论】：

是的，我正在使用 RemObjects。如果我们可以信任堆栈跟踪，则在创建 TRODataModule 时调用 TMultiReadExclusiveWriteSynchronizer，它继承自 TDataModule，在创建期间获取 GlobalNameSpace 锁。

【解决方案4】：

据我所知，EurekaLog 应该是可靠的。如果包含函数地址映射的信息与可执行文件的版本不同，则堆栈跟踪可能不正确。

我使用 JCL 进行堆栈跟踪日志记录，并使用它来记录 map/jdbg 文件。如果您更改可执行文件并保留相同的映射文件，您的堆栈日志将不正确，因为函数地址将不同。所以也许唯一的原因可能是这个。您还必须区分上一次函数调用的真实堆栈跟踪和“调用历史”。我使用调用历史记录，它还列出了在记录时调用的所有函数。就像您的 TTimer 一样。

典型的堆栈跟踪仅包含导致最后一个函数的函数调用。另一方面，“调用历史”包含在特定时间范围内被调用的所有函数。如果您在主线程（如 TTimer）之外还有辅助线程，它也会记录它们的动作。我忘记了它在 JCL 中是如何调用的，但是如果你在 stRawMode 中跟踪，它是默认行为。

最后我可以从堆栈跟踪中看到 WaitForSingleObject 被调用，最好使用 INFINITE 参数，这样它就永远不会超时。然后，WaitForSingleObject 发出信号的条件永远不会完全满足。

检查“TRORemoteDataModule”以及它在构造函数中的作用。因为看起来它只继承自 TDataModule 并添加了一些自己的逻辑。这应该是导致死锁的原因。

编辑：

好的，我检查了 TDataModule 代码：

constructor TDataModule.Create(AOwner: TComponent);
begin
  GlobalNameSpace.BeginWrite;
  try
    CreateNew(AOwner);
    if (ClassType <> TDataModule) and not (csDesigning in ComponentState) then
    begin
      if not InitInheritedComponent(Self, TDataModule) then
        raise EResNotFound.CreateFmt(SResNotFound, [ClassName]);
      if OldCreateOrder then DoCreate;
    end;
  finally
    GlobalNameSpace.EndWrite;
  end;
end;

它使用“GlobalNameSpace”单例接口，其定义和实现如下：

var
  GlobalNameSpace: IReadWriteSync;

initialization
{$IFDEF MSWINDOWS}
  GlobalNameSpace := TMultiReadExclusiveWriteSynchronizer.Create;
{$ENDIF}
...

所以这是你的锁。现在有趣的是为什么会这样？它看起来像是一段标准的 VCL 代码。也许您可以分享更多关于应用程序正在做什么的信息。

此外，您还可以查找调试输出。这是在类中定义的：

procedure TMultiReadExclusiveWriteSynchronizer.BeginRead;
var
  Thread: PThreadInfo;
  WasRecursive: Boolean;
  SentValue: Integer;
begin
{$IFDEF DEBUG_MREWS}
  Debug('Read enter');
{$ENDIF}
...

因此，如果定义了“DEBUG_MREWS”，您将通过“OutputDebugString”获得调试信息。它应该对这个问题有所了解。对我来说，这看起来像是一个组件初始化竞争条件。 :)

【讨论】：

EurekaLog 使用某种后处理器来添加函数地址映射，所以它应该是最新的。 TRORemoteDataModule 的第一行是“继承的”，所以在调用 TDataModule.Create 之前没有调用自定义逻辑。
然后其他东西称为“BeginWrite”。问题显然始于“TMultiReadExclusiveWriteSynchronizer.BeginWrite”。您能否检查该函数调用的所有应用程序代码。也许它是并行或后台运行的。
如果您启用 DEBUG_MREWS - 这将不起作用，直到您重新编译 RTL 和 VCL，这......非常痛苦。一种更简单的方法是设置日志记录断点，正如我在回答中所描述的那样。您设置了 4 个断点并运行您的应用程序。无需重新编译 RTL/VCL。虽然我的方法有局限性：仅限新的 Delphi（不支持在 D7 中记录断点），应启用使用调试 DCUs 选项并且没有运行时包。
嗯，忘了你必须重新编译 RTL/VCL。我同意这比它的价值更麻烦。