Ломается QueryPerformanceCounter. Как такое возможно?! , Странный эффект на пустом месте...

Привет!

Происходит какая-то фигня с QueryPerformanceCounter. У меня есть UtilsR1.dll, которая содержит функцию протоколирования отладочных строк. Эти строки сопровождаются метками времени в секундах с разрешением 10 мкс (показаны в квадратных скобках). Для получения меток времени как раз и используется эта самая QueryPerformanceCounter. Отсчет производится от момента запуска программы. Выглядит это дело примерно так:

[0.00000] UtilsR1.dll (Apr 27 2012 11:38:23): DLL_PROCESS_ATTACH
[0.00063] Debugger.dll (Apr 27 2012 11:30:12): DLL_PROCESS_ATTACH
[0.00182] [PlotEngineR2] CPlotEngine::CPlotEngine: Enter
[0.00204] PlotEngineR2.dll (Apr 27 2012 11:30:54): DLL_PROCESS_ATTACH
[0.00279] USB901R2.dll (Apr 27 2012 11:31:52): DLL_PROCESS_ATTACH
[0.00304] [USB901R2] USB901R2_SetDebugLevel: Set debug level to 0
[0.00333] SCUSBR2.dll (Apr 27 2012 11:31:38): DLL_PROCESS_ATTACH
[0.00355] TxRx64.dll (Mar  1 2011 11:02:06): DLL_PROCESS_ATTACH
[0.00381] Scanner_DRx64.dll (Apr 27 2012 11:28:38): DLL_PROCESS_ATTACH
[0.00401] Kbd801.dll (Apr 27 2012 11:30:25): DLL_PROCESS_ATTACH
[0.00420] [Kbd801] CThread2::CThread2: Shutdown event handle 0x00000174
[0.00442] Kbd1100.dll (Apr 27 2012 11:30:22): DLL_PROCESS_ATTACH
[0.00461] [Kbd1100] CThread2::CThread2: Shutdown event handle 0x00000178
[0.00481] KBDdllR1.dll (Apr 27 2012 11:30:28): DLL_PROCESS_ATTACH
[0.00510] Container.dll (Apr 27 2012 11:30:06): DLL_PROCESS_ATTACH
[0.00542] Ql.dll (Apr 27 2012 11:31:02): DLL_PROCESS_ATTACH
... и т.д.

Однако, после какого-то момента функция QueryPerformanceCounter начинает выдавать время очень грубыми шагами. Мало того, выдаваемое время даже скачет вперед/назад (из-за вывода из разных потоков)! Это можно увидеть в следующем фрагменте:

[0.15671] TRball.dll: DLL_PROCESS_ATTACH
[0.15998] [ScanR2_CFM_Start] CFMThreadReadData: Enter
[0.19485] [PlotEngineR2] CPlotEngine::Init: Enter
[0.19522] [PlotEngineR2] CRenderer::CRenderer: Enter
[0.19546] [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x002906B8, width = 512, height = 512
[0.22257] [PlotEngineR2] CRenderer::Init: OK
[0.22257] [PlotEngineR2] CPaneB::CPaneB: Enter
[0.28507] [PlotEngineR2] CPaneM::CPaneM: Enter
[0.28507] [PlotEngineR2] CPaneG::CPaneG: Enter
[0.28507] [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.28507] Start system init sequence
[0.28507] Program file "C:\1my\_Work\Prog.exe"
[0.28507] Main ini file "C:\1my\_Work\Prog.ini"
[0.28507] TxRxControlR2.dll: Virtual mode disabled
[0.28507] [USB901R2] USB901R2_Init: hWnd = 0x00890584, VID = 0x04B4, PID = 0x8613, endpoints:
[0.28507] [USB901R2] USB901R2_Init: Ctrl OUT = 0x02 IN = 0x84, BData IN = 0x86, CfmData IN = 0x88
[0.28507] Signal "USB901R2_B_xfer_event" registered
[0.28507] Signal "USB901R2_B_frame_event" registered
[0.28507] Signal "USB901R2_M_beam_xfer" registered
[0.28507] Signal "USB901R2_M_beam_event" registered
[0.28507] Signal "USB901R2_CFM_xfer_event" registered
[0.28507] Signal "USB901R2_CFM_1st_block" registered
[0.28507] Signal "USB901R2_CFM_Nth_block" registered
[0.28507] Signal "USB901R2_CFM_frame_event" registered
[0.28507] Signal "USB901R2_D_beam_event" registered
[0.28507] Signal "USB901R2_D_beam_Nth_block" registered
[0.28507] [USB901R2] USB901R2_Init: EP1 present, EP1 OUT = 0x01 EP1 IN = 0x81
[0.28507] [USB901R2] CThread2::CThread2: Shutdown event handle 0x000002EC
[0.28507] [USB901R2] CThread2::CThread2: Shutdown event handle 0x000002F4
[0.29633] [USB901R2] US_data_reading_loop: Enter                          <---------- время больше
[0.29653] [USB901R2] CFM_data_reading_loop: Enter
[0.29671] [USB901R2] US_data_reading_loop: Shutdown event handle 0x000002EC
[0.29697] [USB901R2] CFM_data_reading_loop: Shutdown event handle 0x000002F4
[0.28507] [SCUSBR2] SCUSBR2_Init: Configure SCUSB PLD                     <---------- время опять меньше
[0.28507] [SCUSBR2] SCUSBR2_Init: File "SCUSBR2v28.rbf"
[0.28507] [SCUSBR2] SCUSBR2_PLD_loader_Load: PLD No 0
[0.28507] [SCUSBR2] _pld_loader_load: PLD No 0, data ptr 0x14860048, len 84539
[0.28507] [SCUSBR2] _pld_loader_reset: PLD No 0
[0.28507] [SCUSBR2] _pld_loader_reset: PLD No 0 reset OK
[1.78507] [SCUSBR2] _pld_loader_load: PLD No 0, Load OK (84539 bytes loaded)
[1.78507] [SCUSBR2] _pld_loader_load: SCUSB PLD revision No 28
...

Правда, строки с большим временем поступают из другого потока. Но выдача протокола закрыта критическими секциями и каждая строка записывается путем открытия/записи/закрытия файла протокола. Тут можно видеть и еще одну странность: в этих параллельных потоках QueryPerformanceCounter работает правильно, выдает время с верным разрешением.

И, наконец, последняя странность: после рестарта компьютера работа функции QueryPerformanceCounter снова восстанавливается, и строки протокола начинают опять выдаваться с правильным временем (с правильным временным разрешением). Выполнение Log Off/Log On не помогает. Вот те же места протокола после рестарта компьютера:

Первый кусок:
 
[0.00000] UtilsR1.dll (Apr 27 2012 11:38:23): DLL_PROCESS_ATTACH
[0.00060] Debugger.dll (Apr 27 2012 11:30:12): DLL_PROCESS_ATTACH
[0.00173] [PlotEngineR2] CPlotEngine::CPlotEngine: Enter
[0.00194] PlotEngineR2.dll (Apr 27 2012 11:30:54): DLL_PROCESS_ATTACH
[0.00266] USB901R2.dll (Apr 27 2012 11:31:52): DLL_PROCESS_ATTACH
[0.00292] [USB901R2] USB901R2_SetDebugLevel: Set debug level to 0
[0.00324] SCUSBR2.dll (Apr 27 2012 11:31:38): DLL_PROCESS_ATTACH
[0.00346] TxRx64.dll (Mar  1 2011 11:02:06): DLL_PROCESS_ATTACH
[0.00372] Scanner_DRx64.dll (Apr 27 2012 11:28:38): DLL_PROCESS_ATTACH
[0.00392] Kbd801.dll (Apr 27 2012 11:30:25): DLL_PROCESS_ATTACH
[0.00411] [Kbd801] CThread2::CThread2: Shutdown event handle 0x00000174
[0.00431] Kbd1100.dll (Apr 27 2012 11:30:22): DLL_PROCESS_ATTACH
[0.00449] [Kbd1100] CThread2::CThread2: Shutdown event handle 0x00000178
[0.00469] KBDdllR1.dll (Apr 27 2012 11:30:28): DLL_PROCESS_ATTACH
[0.00497] Container.dll (Apr 27 2012 11:30:06): DLL_PROCESS_ATTACH
[0.00528] Ql.dll (Apr 27 2012 11:31:02): DLL_PROCESS_ATTACH
...
 
Второй кусок:
 
[0.10455] TRball.dll: DLL_PROCESS_ATTACH
[0.10759] [ScanR2_CFM_Start] CFMThreadReadData: Enter
[0.11945] [PlotEngineR2] CPlotEngine::Init: Enter
[0.11980] [PlotEngineR2] CRenderer::CRenderer: Enter
[0.12006] [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x00040470, width = 512, height = 512
[0.17464] [PlotEngineR2] CRenderer::Init: OK
[0.17513] [PlotEngineR2] CPaneB::CPaneB: Enter
[0.17550] [PlotEngineR2] CPaneM::CPaneM: Enter
[0.17574] [PlotEngineR2] CPaneG::CPaneG: Enter
[0.17599] [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.17733] Start system init sequence
[0.17867] Program file "C:\1my\_Work\Prog.exe"
[0.17940] Main ini file "C:\1my\_Work\Prog.ini"
[0.18014] TxRxControlR2.dll: Virtual mode disabled
[0.18148] [USB901R2] USB901R2_Init: hWnd = 0x000404A4, VID = 0x04B4, PID = 0x8613, endpoints:
[0.18172] [USB901R2] USB901R2_Init: Ctrl OUT = 0x02 IN = 0x84, BData IN = 0x86, CfmData IN = 0x88
[0.18197] Signal "USB901R2_B_xfer_event" registered
[0.18221] Signal "USB901R2_B_frame_event" registered
[0.18246] Signal "USB901R2_M_beam_xfer" registered
[0.18270] Signal "USB901R2_M_beam_event" registered
[0.18295] Signal "USB901R2_CFM_xfer_event" registered
[0.18319] Signal "USB901R2_CFM_1st_block" registered
[0.18343] Signal "USB901R2_CFM_Nth_block" registered
[0.18356] Signal "USB901R2_CFM_frame_event" registered
[0.18380] Signal "USB901R2_D_beam_event" registered
[0.18404] Signal "USB901R2_D_beam_Nth_block" registered
[0.19198] [USB901R2] USB901R2_Init: EP1 present, EP1 OUT = 0x01 EP1 IN = 0x81
[0.20052] [USB901R2] CThread2::CThread2: Shutdown event handle 0x000002EC
[0.20101] [USB901R2] CThread2::CThread2: Shutdown event handle 0x000002F4
[0.20185] [USB901R2] US_data_reading_loop: Enter                          <---------- время совершенно нормальное
[0.20199] [USB901R2] CFM_data_reading_loop: Enter
[0.20216] [USB901R2] US_data_reading_loop: Shutdown event handle 0x000002EC
[0.20249] [USB901R2] CFM_data_reading_loop: Shutdown event handle 0x000002F4
[0.20284] [SCUSBR2] SCUSBR2_Init: Configure SCUSB PLD
[0.20321] [SCUSBR2] SCUSBR2_Init: File "SCUSBR2v28.rbf"
[0.20382] [SCUSBR2] SCUSBR2_PLD_loader_Load: PLD No 0
[0.20406] [SCUSBR2] _pld_loader_load: PLD No 0, data ptr 0x14860048, len 84539
[0.20431] [SCUSBR2] _pld_loader_reset: PLD No 0
[0.20687] [SCUSBR2] _pld_loader_reset: PLD No 0 reset OK
[1.81783] [SCUSBR2] _pld_loader_load: PLD No 0, Load OK (84539 bytes loaded)
[1.81869] [SCUSBR2] _pld_loader_load: SCUSB PLD revision No 28
...

Тут можно видеть, что время в других потоках тоже совершенно нормальное.

Как может сломаться функция QueryPerformanceCounter?! Она ведь оперирует аппаратным счетчиком в процессоре!

Я замечал этот дефект на 3-х аппаратных платформах, все они с Интеловскими процессорами (Core 2 Duo и одноядерный Celeron), на всех установлены 32-разрядные Win XP. Пробовал различные варианты доступа к RDTSC с помощью ассемблера или функции rdtsc() - все едино. Как такое возможно?!

Помогите, пожалуйста, побороть этот недуг!

P.S. Функция [0.19546] [PlotEngineR2] CRenderer::Init инициализирует DirectX с помощью функций Direct3DCreate9(D3D_SDK_VERSION), CreateDevice(), создания нужных текстур и т.п. Вот после нее QueryPerformanceCounter для текущего потока и ломается. Другие программы, не использующие DirectX, с помощью той же UtilsR1.dll выдают правильный протокол, без проблем с временем. Выходит, что DirectX портит работу QueryPerformanceCounter?... Не понимаю...

jur
К примеру виртуализация или SMM.

Цитата

Как может сломаться функция QueryPerformanceCounter?! Она ведь оперирует аппаратным счетчиком в процессоре!

QueryPerformanceCounter всего лишь абстракция. А значит подвержена корректировки, есть всякии ускорялки для игр.

Разные ядра имеют разные значения rdtsc.

Минздрав MSDN предупреждает:

Цитата

On a multiprocessor computer, it should not matter which processor is called. However, you can get different results on different processors due to bugs in the basic input/output system (BIOS) or the hardware abstraction layer (HAL). To specify processor affinity for a thread, use the SetThreadAffinityMask function.

Эх, не всё так просто. jur, может быть в этом проблема? На всякий случай у меня на машине GetSystemTimeAdjustment() для своих параметров выдаёт 156255 156250 0 соответственно.

Qraizer
Статья врёт.
Дело не в ошибках резонатора. А в том что кто-то захотел получить 10мс(в современных системах 15мс но не суть важно). А в наличии был таймер PIT с опорной частоты 1193181.(6) Гц и наличие делителя с коэфициентом в диапозоне 1-65536

10 мс =100Гц
100=1193181.(6)/х
х=11931.81

Расчёт для 15 мс
15мс=1000/15 Гц
1000/15=1193181.(6)/х
х=15/1000*1193181.(6)
х=17897,724999

А оно на цело и неделится и получилось бы тогда что таймер убегает или отстает. Вот и решили скорректировать хитрым образом.
Округлили х, а в таймере начали корректировать время.
Вот эту корректировку и зашили в GetTickCount. А реальные цифры в GetSystemTimeAdjustment.


На самом деле внутренний делитель в виндосе подобран так чтобы была частота 1024. А там ошибка как раз и большая.
А потом уже пропускается 15 интервалов таймера.
Да вот так вот все через Ж.. в виндоусе.
Подвиду итог PIT имеет частоту 1193181 делитель выбран как 1165
Итого имем частоту прерывания 1024,189
кант времени равен (16/1024,189)=0,015622




А по поводу ошибок резонатора, в любом генераторе или синтезаторе есть фазовая подстройка частоты. Она и недаёт делать скачки.
А во-вторых rdtsc получается умножением, а не делением. Поэтому тут проблемы с округлением нет.

В досе для time-of-day clock использовался RTC, а в виндоусе PIT
У RTC резонатор имеет частоту 32768 Гц и делитель 32768 Гц чтобы срабатывать раз в секунду. Поэтому время создания файлов в досе имела дискретность в 1 секунду и небыло проблем с делителем.
А в виндоусе использовали уже PIT и получалась разсинхронизация с которой и боролись боролись. А в итоге только хуже сделали.

Сообщение отредактировано: Pavia - 31.05.12, 17:57

Pavia, ты точно читал статью?

P.S. Под DOS я программил достаточно.

Добавлено 31.05.12, 18:41
В любом случае я предложил ещё один вариант, который может иметь место. Что там в коде у jur, мне неведомо.

А в boot.ini проблемной системы /usepmtimer не? По-моему, как раз похоже.

Кстати, да. Вот статья на эту тему.

Qraizer
Читал. Статья 100% ложь.


Vapaamies
По поводу /usepmtimer.
Qraizer дал статю. /usepmtimer это не проблемма а её решение. Как я уже писал QueryPerformanceCounter это абстракция. Для решения проблемы того что таймер HPET или rdtsc имеют разное начальное значения. Использовать один таймер PMTimer.

Меня смущают следующие моменты. Во-первых, как объяснить, что до "CRenderer::Init: OK" все хорошо, а после этого дискрет времени увеличивается на порядки? Как здесь:

[0.19485] [PlotEngineR2] CPlotEngine::Init: Enter
[0.19522] [PlotEngineR2] CRenderer::CRenderer: Enter
[0.19546] [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x002906B8, width = 512, height = 512
 
до этого места хорошо, после - плохо...
 
[0.22257] [PlotEngineR2] CRenderer::Init: OK
[0.22257] [PlotEngineR2] CPaneB::CPaneB: Enter
[0.28507] [PlotEngineR2] CPaneM::CPaneM: Enter
[0.28507] [PlotEngineR2] CPaneG::CPaneG: Enter
[0.28507] [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.28507] Start system init sequence

Во-вторых, если QueryPerformanceCounter обращается к неправильному генератору, то почему в других потоках этот генератор становится правильным? Ведь в них время приращается верно, примерно на 100-200 (иногда чуть меньше) микросекунд за раз.

В-третьих, почему аппаратный 64-разрядный счетчик тиков процессора RDTSC выдает неправильные значения? Ведь он-то вообще ни от чего не зависит! В смысле, от каких-то резонаторов и т.п. Кроме того, этот дефект существует и на одноядерном простеньком Целероне.

В-четвертых, почему после рестарта компа какое-то время все работает хорошо? Я запускал свою программу несколько раз. Каждый запуск показывал правильные значения времени в файле протокола. А через некоторое время все ломается. Вот тот же кусок после рестарта компьютера:

[0.11945] [PlotEngineR2] CPlotEngine::Init: Enter
[0.11980] [PlotEngineR2] CRenderer::CRenderer: Enter
[0.12006] [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x00040470, width = 512, height = 512
[0.17464] [PlotEngineR2] CRenderer::Init: OK
[0.17513] [PlotEngineR2] CPaneB::CPaneB: Enter
[0.17550] [PlotEngineR2] CPaneM::CPaneM: Enter
[0.17574] [PlotEngineR2] CPaneG::CPaneG: Enter
[0.17599] [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.17733] Start system init sequence

Видно, что время отображается совершенно правильно. Поэтому представляется, что ключ /usepmtimer ничего не даст.

Для эксперимента я запускал параллельно две свои тестовые программки, представляющие собой пару клиент/сервер, для проверки передачи данных через механизм Memory mapped file. Эти программки используют все ту же UtilsR1.dll, ведающую выводом протокола. Так в их протоколе все хорошо, время отсчитывается нормально, каждая строка минимум на 100-200 микросекунд позже предыдущей. Разница в программах та, что не используется DirectX.

Темный лес... Всю голову сломал, а она у меня одна... :-)

P.S. Да, забыл сказать. Еще я пробовал SetProcessAffinityMask/SetThreadAffinityMask - все едино, времена вывода строк протокола как заколдованные...

Так и запишем, мол, Pavia за пояс заткнул системщиков из Microsoft.
jur, так ты попробуй. Сначала нужно найти причину, а потом уже искать пути решения.

Цитата Qraizer @ 01.06.12, 09:42

jur, так ты попробуй. Сначала нужно найти причину, а потом уже искать пути решения.

Обязательно попробую. Вот, уже перегрузил комп с этим ключом. Дело немножко осложняется тем, что после перезагрузки эта зараза работает правильно :-) Ну ничего, поковыряюсь, поисследую. (Интересно, вдруг получится?...)

Спасибо за помощь!

Не получилось, все то же самое... Оставил комп работать на ночь, теперь смотрю лог. Включил более детальный вывод протокола. Из него видно, что после инициализации DX Device отсчет времени ломается:

[0.07896] [PlotEngineR2] CPlotEngine::SetDebugLevel: Set debug level to 1
[0.07928] [PlotEngineR2] CPlotEngine::Init: Enter
[0.07949] [PlotEngineR2] CRenderer::CRenderer: Enter
[0.07969] [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x001E060A, width = 512, height = 512
[0.08178] [PlotEngineR2] CRenderer::Init: DX Object   = 0x00173CA0
[0.08202] [PlotEngineR2] CRenderer::Init: GetAdapterDisplayMode() OK
[0.13258] [PlotEngineR2] CRenderer::Init: DX Device   = 0x0017FDC0
[0.14039] [PlotEngineR2] CRenderer::Init: B Texture   = 0x0016F320
[0.14039] [PlotEngineR2] CRenderer::Init: CFM Texture = 0x0020E460
[0.14039] [PlotEngineR2] CRenderer::Init: M Texture   = 0x0020E660
[0.14039] [PlotEngineR2] CRenderer::Init: G Texture   = 0x0020E840
[0.14039] [PlotEngineR2] CRenderer::Init: Gi Texture  = 0x0020EA20
[0.14039] [PlotEngineR2] CRenderer::Init: OK
[0.14039] [PlotEngineR2] CPaneB::CPaneB: Enter
[0.14820] [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.14820] [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.14820] [PlotEngineR2] CPaneM::CPaneM: Enter
[0.14820] [PlotEngineR2] CPaneG::CPaneG: Enter
[0.14820] [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.14820] Start system init sequence

В чем же может крыться причина поломки? Видно, что на это дело как-то влияет DirectX. Но как и почему?!

Ура! С помощью многоуважаемого коллеги Адамантэус наконец-то удалось достичь блистательной Виктории!

Дело оказалось в том, что, как предположил коллега Адамантэус, треклятая DirectX портит режим работы сопроцессора с плавающей точкой. Возможно кому-нибудь окажется полезной информация по преодолению данной проблемы. Ведь если в программе используются вычисления с плавающей точкой повышенной точности, то они будут выполняться неверно.

Вот что я сделал. Сначала я увеличил разрядность выводимого времени и добавил вывод значения счетчика RDTSC. Получил следующий протокол (детализацию для наглядности увеличил):

[0.210631519] 875788055576 [PlotEngineR2] CPlotEngine::Init: Enter
[0.210879316] 875788056462 [PlotEngineR2] CRenderer::CRenderer: Enter
[0.211111189] 875788057293 [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x0007059E, width = 512, height = 512
[0.213896738] 875788067264 [PlotEngineR2] CRenderer::Init: DX Object   = 0x00173E20
[0.214174707] 875788068259 [PlotEngineR2] CRenderer::Init: GetAdapterDisplayMode() OK
 
с этого момента и до закрытия программы сопроцессор работает плохо:
 
[0.250000000] 875788183770 [PlotEngineR2] CRenderer::Init: DX Device   = 0x0017D760
[0.250000000] 875788188668 [PlotEngineR2] CRenderer::Init: B Texture   = 0x0016D7C0
[0.250000000] 875788193673 [PlotEngineR2] CRenderer::Init: CFM Texture = 0x0020C660
[0.250000000] 875788200309 [PlotEngineR2] CRenderer::Init: M Texture   = 0x0020C840
[0.250000000] 875788208381 [PlotEngineR2] CRenderer::Init: G Texture   = 0x0020CA40
[0.250000000] 875788216458 [PlotEngineR2] CRenderer::Init: Gi Texture  = 0x0020CC20
[0.250000000] 875788217774 [PlotEngineR2] CRenderer::Init: OK
[0.250000000] 875788218817 [PlotEngineR2] CPaneB::CPaneB: Enter
[0.250000000] 875788219689 [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.250000000] 875788220592 [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.250000000] 875788221747 [PlotEngineR2] CPaneM::CPaneM: Enter
[0.250000000] 875788222600 [PlotEngineR2] CPaneG::CPaneG: Enter
[0.250000000] 875788223448 [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.250000000] 875788227792 Start system init sequence

Видно, что начиная с момента создания устройства DirecX ("DX Device") время портится. Однако, счетчик приращается нормально, как и раньше.

Это говорит о том, что предположение о влиянии DirecX на сопроцессор подтверждается. Тогда я после создания устройства DirecX вставил простую конструкцию:

  __asm {
    FINIT;
  }

Взглянул на протокол и понял: "Вот она, Виктория!" :-) Это можно видеть по следующему фрагменту:

[0.088878894] 881454515739 [PlotEngineR2] CPlotEngine::Init: Enter
[0.089127529] 881454516629 [PlotEngineR2] CRenderer::CRenderer: Enter
[0.089361078] 881454517465 [PlotEngineR2] CRenderer::Init: Enter, HWND = 0x0009059E, width = 512, height = 512
[0.091818094] 881454526260 [PlotEngineR2] CRenderer::Init: DX Object   = 0x00174040
[0.092081815] 881454527203 [PlotEngineR2] CRenderer::Init: GetAdapterDisplayMode() OK
[0.128233896] 881454656612 [PlotEngineR2] CRenderer::Init: DX Device   = 0x0017D9A0
[0.129625413] 881454661593 [PlotEngineR2] CRenderer::Init: B Texture   = 0x0016D7C0
[0.131077553] 881454666791 [PlotEngineR2] CRenderer::Init: CFM Texture = 0x0020C880
[0.132994836] 881454673654 [PlotEngineR2] CRenderer::Init: M Texture   = 0x0020CA80
[0.135265236] 881454681781 [PlotEngineR2] CRenderer::Init: G Texture   = 0x0020CC60
[0.137500716] 881454689783 [PlotEngineR2] CRenderer::Init: Gi Texture  = 0x0020CE40
[0.137878418] 881454691135 [PlotEngineR2] CRenderer::Init: OK
[0.138167002] 881454692168 [PlotEngineR2] CPaneB::CPaneB: Enter
[0.138410329] 881454693039 [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.138659522] 881454693931 [PlotEngineR2] CPaneB::_calc_convex: Scanning depth 120.0 mm, radius = 60.00 mm, angle = 42.69 deg
[0.138992805] 881454695124 [PlotEngineR2] CPaneM::CPaneM: Enter
[0.139229707] 881454695972 [PlotEngineR2] CPaneG::CPaneG: Enter
[0.139470799] 881454696835 [PlotEngineR2] CPaneGi::CPaneGi: Enter
[0.140687713] 881454701191 Start system init sequence

Все, проблема благополучно решена! Всем спасибо за участие!

:-)

Сообщение отредактировано: jur - 04.06.12, 16:08