Странный стек вызовов, когда приложение зависло
По-видимому, у меня возникла проблема с блокировкой в одном из моих приложений, и я начал исследовать следы стека EurekaLog. Вот один недавний:
Информация о стеке вызовов: -------------------------------------------------------------------------------------------------------------------------------------- | Адрес | Модуль | Модуль | Класс | Процедура / метод | Линия | -------------------------------------------------------------------------------------------------------------------------------------- |* Тема исключения: ID=14208; Приоритет =0; Класс =; [Главная] | |------------------------------------------------------------------------------------------------------------------------------------| |7C82860C|ntdll.dll | | |KiFastSystemCall | | |7C827D27|ntdll.dll | | |ZwWaitForSingleObject | | |77E61C96|kernel32.dll | | |WaitForSingleObjectEx | | |77E61C88|kernel32.dll | | |WaitForSingleObject | | |77E61C7B|kernel32.dll | | |WaitForSingleObject | | |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 |Sentrol_Impl.pas | |Create_Sentrol |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 | | InterlockedDecrement | | |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 | | |InterlockedIncrement | | |00407BFA|MyApp.exe |system.pas |TInterfacedObject |_AddRef |17972[1] | |00646B72|MyApp.exe |uROServer.pas |TROInvoker |HandleMessage |758[1] | |006460C5|MyApp.exe |uROServer.pas | |MainProcessMessage |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 | Отправка |1884[36] | |005EE3FC|MyApp.exe |uROClient.pas |TROTransportChannel | Отправка |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 | | |RtlTimeToTimeFields | | |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 | | |GetParent | | |7739C45C|USER32.dll | | |GetParent | | |773A16E0|USER32.dll | | |DispatchMessageA | | |773A16D6|USER32.dll | | |DispatchMessageA | | |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 часов без проблем. Я подожду день или два, чтобы увидеть, действительно ли проблема исчезла.
4 ответа
У меня была такая же проблема с закрытием моего приложения и созданием модуля TForm или TDatamodule в другом потоке: поскольку приложение завершается, GlobalNameSpace (см. Другой ответ) заблокирован (!), Поэтому создание моего модуля TRORemoteDataModule в другом потоке было заперта. Поскольку я использовал другую блокировку для ожидания этого потока, у меня возникла тупиковая ситуация:-(.
В вашем случае вы должны взглянуть на другие потоки, чтобы найти тот, который установил блокировку (и, вероятно, ожидает, иначе у вас не будет тупика). Я вижу "SyncSentrolUpdateTimerTimer": может быть, вы делаете TThread.Synchronize при создании TDatamodule в другом потоке?
РЕДАКТИРОВАТЬ: если вы хотите посмотреть на стек других потоков в тупике:
- Попробуйте Process Explorer -> process -> thread -> stack (но вам нужен map2dbg.exe, чтобы преобразовать файл Delphi .map в файл Microsoft .dbg, чтобы увидеть символы отладки).
http://technet.microsoft.com/en-us/sysinternals/bb896653.aspx
http://code.google.com/p/map2dbg/ - Попробуйте мой AsmProfiler с открытым исходным кодом (режим сэмплирования): он имеет "живое представление" для просмотра стека всех потоков и использует символы отладки Delphi (.map, .jdbg и т. Д.), Поэтому вам не нужен map2dbg.exe (Кстати, я сделал это Live View, потому что я часто использую Проводник процессов и был раздражен, чтобы использовать map2dbg каждый раз)
http://code.google.com/p/asmprofiler/wiki/ProcessStackViewer
Последний вызов находится в TMultiReadExclusiveWriteSynchronizer, но он не показывает, в каком методе. Там он, вероятно, вызывает функции синхронизации окон, и он там блокируется. Вы используете библиотеки RemObjects? Там что-то происходит. Вы можете использовать SysInternals Process Explorer, сконфигурированный для загрузки символов Windows и проверки трассировки стека во время выполнения процесса. Если вы конвертируете символы Delphi в формат.dbg, у вас будет весь стек вызовов explict.
Можете ли вы воспроизвести это зависание под отладчиком? Если да - тогда установите точки останова в методах Begin/EndWrite/Read GlobalNameSpace. Введите расширенные свойства каждой точки останова, включите опцию "Break" и включите опцию "Log call stack".
Теперь запустите ваше приложение и дайте ему повиснуть. Проверьте окно событий. Вы увидите полную историю вызова GlobalNameSpace. Проанализируйте это. Должен быть какой-то неправильный звонок где-то. Вероятно, последний.
В качестве альтернативы, если вы работаете в Vista и выше, вы можете использовать функцию Wait Chain Traversal, но я забыл, какая у Delphi есть. Просто дайте приложению повиснуть и увидите окно Threads: должна быть причина для блокировки.
В редких случаях зависание может быть вызвано повреждением памяти. Например, плохой код может стереть / повредить флаг "Свободен"/"Занят", поэтому первый код, который попытается получить блокировку, будет ждать вечно, так как некому снять блокировку (поскольку она не была заблокирована, было повреждено).
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". Это должно пролить свет на проблему. Для меня это выглядит как состояние гонки инициализации компонентов.:)