Важность дополнительной информации при анализе крешдампов

IRQL_NOT_LESS_OR_EQUAL (a)
An attempt was made to access a pageable (or completely invalid) address at an
interrupt request level (IRQL) that is too high. This is usually
caused by drivers using improper addresses.
If a kernel debugger is available get the stack backtrace.
Arguments:
Arg1: e25393ec, memory referenced
Arg2: 0000001c, IRQL
Arg3: 00000000, bitfield
Arg4: 804fac65, address which referenced memory

Debugging Details:

---

READ_ADDRESS: e25393ec Paged pool

CURRENT_IRQL: 1c 

Именно такой BSOD начал вылезать на winXP sp2 в моем драйвере.

Анализ крешдампа проблему падения драйвера не решил, напротив, возникли новые, еще более интересные вопросы =]

Итак, из крешдампа стало ясно, что при вызове системой ф-ции KeWaitForSingleObject происходил доступ к выгружаемой памяти на высоком IRQL.

И все бы ничего, кроме двух мистических вещей.

Первая заключалась в том, что память к которой было обращение принадлежала первому параметру ф-ции KeWaitForSingleObject, а именно объекту.
Причем память эта была выгружаемой, а как известно, объекты ядра находятся в невыгружаемой памяти. Т.е. память явно не принадлежала объекту, что и подтвердила команда !object.

Вторая мистическая вещь - это запредельный IRQL, равный CLOCK LEVEL.

Самым очевидным выводом всей этой истории было предположение, что проблема в железе.

Однако спустя некоторое время у меня появился другой дамп, тоже с этим же багчеком, но стек вызовов был другим, уже без вызова KeWaitForSingleObject:

a334fbc4 804f9fdb badb0d00 e24801bc 804f9fbe ntKiTrap0E+0x238
a334fc40 806e498e e24801b4 00000000 00000000 ntKeSetEventBoostPriority+0x1f
a334fc50 80569d29 e243a4e0 e2480198 805593a0 halExReleaseFastMutex+0x1a
a334fc64 80569d77 e2480198 a334fc80 00000000 ntCmpCheckRecursionAndRecordThreadInfo+0x47
a334fc94 80634f9c 0000000e a334fcb8 00000000 ntCmpCallCallBacks+0x3b
a334fcb0 805b9e2d e38818f8 00000000 e38818e0 ntCmpDeleteKeyObject+0x22
a334fccc 805257b8 e38818f8 00000000 000004fc ntObpRemoveObjectRoutine+0xdf
a334fce4 805bad03 883a3020 e32ebc58 879c8020 ntObfDereferenceObject+0x4c
a334fcfc 805bad99 e32ebc58 e38818f8 000004fc ntObpCloseHandleTableEntry+0x155
a334fd44 805baed1 000004fc 00000001 00000000 ntObpCloseHandle+0x87
a334fd58 8054060c 000004fc 04e1fe10 7c90eb94 ntNtClose+0x1d
a334fd58 7c90eb94 000004fc 04e1fe10 7c90eb94 ntKiFastCallEntry+0xfc
04e1fdfc 7c90d592 77dc6bcc 000004fc 00000000 ntdllKiFastSystemCallRet
04e1fe00 77dc6bcc 000004fc 00000000 04e1fe1c ntdllZwClose+0xc

Дальше было просто, вместо отладчика я открыл...google! Да-да, он иногда бывает полезнее отладчика. И через несколько минут нашел решение своей проблемы: http://support.microsoft.com/kb/936456/ - виноват был не драйвер, а система.

Но вопрос о высоком IRQL оставался открытым.

Изучение ядерного дампа,  ничего не изменило, проблема оставалась.
Оставалось смотреть внутренности KeWaitForSingleObject и там я обнаружил одну интересную вещь, а именно, ф-цию KiUnlockDispatcherDatabase.

Однако захват и освобождение базы данных диспатчера делались на DISPATCH LEVEL'е.
Я знал, что решение где-то рядом, поэтому следующим шагом был обзор всех подобных ф-ций, и через определенное время забрежжил свет в конце туннеля. Нашлась ф-ция KeRaiseIrqlToSynchLevel, которая задирала IRQL до SYNCH_LEVEL.

#define IPI_LEVEL 29
#define POWER_LEVEL 30
#define HIGH_LEVEL 31
#define SYNCH_LEVEL (IPI_LEVEL-1) <= как раз 28 или 1Ch

Казалось, кусочки паззла наконец встали на свои места, для уверенности я полез в hal.dll, и увидел там совсем не то, что ожидал:

.text:80012700 @KeAcquireSpinLockRaiseToSynch@4 proc near
.text:80012700                 mov     edx, ds:0FFFE0080h
.text:80012706                 mov     eax, edx
.text:80012708                 shr     eax, 4
.text:8001270B                 movzx   eax, ds:_HalpVectorToIRQL[eax]
.text:80012712                 mov     dword ptr ds:0FFFE0080h, 41h <=== APIC[TASK PRIORITY REGISTER] = DPC VECTOR
.text:8001271C                 retn
.text:8001271C @KeAcquireSpinLockRaiseToSynch@4 endp

Никакого SYNCH_LEVEL'a не было и в помине...

Однако, открыв полный дамп с машины на которой был бсод, увидел следующее:

hal!KeAcquireSpinLockRaiseToSynch:
806e4870 mov     edx,dword ptr ds:[0FFFE0080h]
806e4876 mov     eax,edx
806e4878 shr     eax,4
806e487b movzx   eax,byte ptr hal!HalpVectorToIRQL (806ef218)[eax]
806e4882 test    dword ptr [ecx],1
806e4888 jne     hal!KeAcquireSpinLockRaiseToSynch+0x34 (806e48a4)
806e488a mov dword ptr ds:[0FFFE0080h],0D1h        <=== APIC[TASK PRIORITY REGISTER] = CLOCK VECTOR

Т.е. реализации hal также как и ядра, различаются на однопроцессорных и многопроцессорных системах, и вначале я смотрел однопроцессорную версию, в которой DISPATCH LEVEL'a вполне достаточно.

Теперь все встало на свои места, система действительно может вызывать код на запредельном IRQL( на MP системах ) и к поломке железа мой бсод не имел никакого отношения.

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

End of story... =]