четверг, 13 января 2011 г.

Application verifier

Есть множество инструментов, помогающих в отладке программ под Windows. Какие-то лучше, какие-то хуже. Какие-то проще, какие-то сложнее. А можно ли выделить самый простой и полезный способ тестирования программ? Все полезны по-своему и про все стоит рассказать. Но есть категория достаточно простых в использовании инструментов, которые дают, тем не менее, очень ощутимый эффект. Application Verifier как раз из таких...

Самый простой способ активации этого инструмента - это пометить checkbox “Enable Application Verifier” в утилите GFlags из состава Debugging tools for Windows.

Итак, допустим, у нас есть программа. Она работает и не падает, ну разве что очень-очень редко. Уверены ли вы, что программа корректна?

Напишем небольшую тестовую программу для демонстрации принципа (ее я, честно говоря, когда-то где-то стащил в качестве короткого классического демонстрационного примера для отладки):
struct Test
{
char t[100];
char* p;
CRITICAL_SECTION cs;
};

void func_useDeletedMemory()
{
printf("func_useDeletedMemory");
Test* t = new Test;
t->p = new char[100];
delete t;
delete []t->p;
}

void func_deleteMemoryWithCriticalSection()
{
printf("func_deleteMemoryWithCriticalSection");

Test* t = new Test;
InitializeCriticalSection(&t->cs);
delete t;
}

int _tmain(int argc, _TCHAR* argv[])
{
if (argc < 2)
func_useDeletedMemory();
else
func_deleteMemoryWithCriticalSection();
return 0;
}
Если программа запускается без аргументов, то вызывается функция func_useDeletedMemory, а с аргументами в командной строке - func_deleteMemoryWithCriticalSection (аргументы могут быть любые).

Программа компилируется и отрабатывает без ошибок, как ее не запускай. Но ведь ошибки есть?

В функции func_useDeletedMemory мы удалили структуру, а потом пытаемся удалить что-то изнутри структуры.

А в функции func_deleteMemoryWithCriticalSection мы удаляем структуру, в которой содержится неудаленная критическая секция - тут происходит утечка хэндла.

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

Запустим программу GFlags.exe из комплекта Debugging tools for Windows и включим Application Veriifier для нашего тестового приложения. Для этого нужно всего лишь переключиться на вкладку “Image File”, набрать имя приложения, нажать tab, включить одну галочку и нажать OK.

После этого запустим программу без параметров опять и сразу получаем падение!
Подключаем WinDBG (или сначала снимаем дамп, а потом открываем его в WinDBG). Там набираем “!analyze -v” и получаем:
0:001> !analyze -v
*******************************************************************************
* *
* Exception Analysis *
* *
*******************************************************************************

APPLICATION_VERIFIER_CORRUPTED_HEAP_BLOCK (8)
Corrupted heap block.
This is a generic error issued if the corruption in the heap block
cannot be placed in a more specific category.
Arguments:
Arg1: 01681000, Heap handle used in the call.
Arg2: f0f0f0f0, Heap block involved in the operation.
Arg3: 00000000, Size of the heap block.
Arg4: 00000000, Reserved
............

PROCESS_NAME: TestApplicationVerifier.exe

INVALID_HEAP_ADDRESS: f0f0f0f0 (!heap -p -a f0f0f0f0)

ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION} Breakpoint A breakpoint has been reached.

NTGLOBALFLAG: 2000100

APPLICATION_VERIFIER_FLAGS: 6

FAULTING_THREAD: 00000448

STACK_TEXT:
0012f53c 7c90d9ca 7c8645fd d0000144 00000004 ntdll!KiFastSystemCallRet
0012f540 7c8645fd d0000144 00000004 00000000 ntdll!ZwRaiseHardError+0xc
0012f7c4 7c8438fa 0012f7ec 7c839b39 0012f7f4 kernel32!UnhandledExceptionFilter+0x628
0012f7cc 7c839b39 0012f7f4 00000000 0012f7f4 kernel32!BaseProcessStart+0x39
0012f7f4 7c9032a8 0012f8e0 0012ffe0 0012f900 kernel32!_except_handler3+0x61
0012f818 7c90327a 0012f8e0 0012ffe0 0012f900 ntdll!ExecuteHandler2+0x26
0012f8c8 7c90e48a 00000000 0012f900 0012f8e0 ntdll!ExecuteHandler+0x24
0012f8c8 7c90120e 00000000 0012f900 0012f8e0 ntdll!KiUserExceptionDispatcher+0xe
0012fbc8 7c956845 00000008 f0f0f0f0 00000000 ntdll!DbgBreakPoint
0012fbe0 7c96b28c 00000008 7c96b4cc 01681000 ntdll!RtlApplicationVerifierStop+0x160
0012fc5c 7c96c44f 01681000 00000004 f0f0f0f0 ntdll!RtlpDphReportCorruptedBlock+0x92
0012fc80 7c96c652 01681000 01001002 00000020 ntdll!RtlpDphNormalHeapFree+0x2e
0012fcd0 7c96f6f3 01680000 01001002 f0f0f0f0 ntdll!RtlpDebugPageHeapFree+0x79
0012fd44 7c94bc4c 01680000 01001002 f0f0f0f0 ntdll!RtlDebugFreeHeap+0x2c
0012fe2c 7c927573 01680000 01001002 f0f0f0f0 ntdll!RtlFreeHeapSlowly+0x37
0012fefc 5ad127d1 01680000 00000000 f0f0f0f0 ntdll!RtlFreeHeap+0xf9
0012ff14 78134c39 01680000 00000000 f0f0f0f0 verifier!AVrfpRtlFreeHeap+0x15
0012ff60 00401038 f0f0f0f0 01785588 00000064 msvcr80!free+0xcd
0012ff7c 004011e5 00000001 017844c8 01783060 TestApplicationVerifier!main+0x38 [c:\111\testapplicationverifier\testapplicationverifier\testapplicationverifier.cpp @ 35]
0012ffc0 7c817077 d309ee22 01c9c4fa 7ffdd000 TestApplicationVerifier!__tmainCRTStartup+0x10f [f:\sp\vctools\crt_bld\self_x86\crt\src\crtexe.c @ 597]
0012fff0 00000000 0040132e 00000000 78746341 kernel32!BaseProcessStart+0x23

PRIMARY_PROBLEM_CLASS: STATUS_BREAKPOINT

BUGCHECK_STR: APPLICATION_FAULT_STATUS_BREAKPOINT

FOLLOWUP_IP:
msvcr80!free+cd
78134c39 85c0 test eax,eax

SYMBOL_STACK_INDEX: 11

SYMBOL_NAME: msvcr80!free+cd

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: msvcr80

IMAGE_NAME: msvcr80.dll

DEBUG_FLR_IMAGE_TIMESTAMP: 4889d619

STACK_COMMAND: ~0s ; kb

FAILURE_BUCKET_ID: msvcr80.dll!free_80000003_STATUS_BREAKPOINT

BUCKET_ID: APPLICATION_FAULT_STATUS_BREAKPOINT_msvcr80!free+cd

Followup: MachineOwner
---------
Тут нам сразу готовый callstack с проблемой и примерное описание проблемы - что-то не так с heap'ом. После этого достаточно посмотреть на код, чтобы понять, что не так.

Обычно подсказки от Application Verifier гораздо более информативны. Например, в случае вызова функции func_deleteMemoryWithCriticalSection. Запускаем тестовое приложение с параметрами и получаем опять падение.
Открываем дамп в WInDBG, набираем “!analyze -v” и получаем:
0:001> !analyze -v
*******************************************************************************
* *
* Exception Analysis *
* *
*******************************************************************************

APPLICATION_VERIFIER_LOCK_IN_FREED_HEAP (202)
Freeing heap block containing an active critical section.
This stop is generated if a heap allocation contains a critical section,
the allocation is freed and the critical section has not been deleted.
To debug this stop use the following debugger commands:
$ !cs -s parameter1 - dump information about this critical section.
$ ln parameter1 - to show symbols near the address of the critical section.
This should help identify the leaked critical section.
$ dps parameter2 - to dump the stack trace for this critical section initialization.
$ parameter3 and parameter4 might help understand where was this heap block
allocated (the size of the allocation is probably significant).
Arguments:
Arg1: 017855f8, Critical section address.
Arg2: 004115bc, Critical section initialization stack trace.
Arg3: 01785590, Heap block address.
Arg4: 00000080, Heap block size.

FAULTING_IP:
ntdll!DbgBreakPoint+0
7c90120e cc int 3

EXCEPTION_RECORD: 0012f90c -- (.exr 0x12f90c)
ExceptionAddress: 7c90120e (ntdll!DbgBreakPoint)
ExceptionCode: 80000003 (Break instruction exception)
ExceptionFlags: 00000000
NumberParameters: 3
Parameter[0]: 00000000
Parameter[1]: 7c91ead5
Parameter[2]: 0000003d

DEFAULT_BUCKET_ID: STATUS_BREAKPOINT

PROCESS_NAME: TestApplicationVerifier.exe

CRITICAL_SECTION: 017855f8 -- (!cs -s 017855f8)

ERROR_CODE: (NTSTATUS) 0x80000003 - {EXCEPTION} Breakpoint A breakpoint has been reached.

NTGLOBALFLAG: 2000100

APPLICATION_VERIFIER_FLAGS: 6

FAULTING_THREAD: 00001160

CONTEXT: 0012f92c -- (.cxr 0x12f92c)
eax=00000001 ebx=004115bc ecx=7c91ead5 edx=0000003d esi=00000202 edi=017855f8
eip=7c90120e esp=0012fbf8 ebp=0012fc0c iopl=0 nv up ei pl zr na pe nc
cs=001b ss=0023 ds=0023 es=0023 fs=003b gs=0000 efl=00000246
ntdll!DbgBreakPoint:
7c90120e cc int 3
Resetting default scope

LAST_CONTROL_TRANSFER: from 7c956845 to 7c90120e

STACK_TEXT:
0012f568 7c90d9ca 7c8645fd d0000144 00000004 ntdll!KiFastSystemCallRet
0012f56c 7c8645fd d0000144 00000004 00000000 ntdll!ZwRaiseHardError+0xc
0012f7f0 7c8438fa 0012f818 7c839b39 0012f820 kernel32!UnhandledExceptionFilter+0x628
0012f7f8 7c839b39 0012f820 00000000 0012f820 kernel32!BaseProcessStart+0x39
0012f820 7c9032a8 0012f90c 0012ffe0 0012f92c kernel32!_except_handler3+0x61
0012f844 7c90327a 0012f90c 0012ffe0 0012f92c ntdll!ExecuteHandler2+0x26
0012f8f4 7c90e48a 00000000 0012f92c 0012f90c ntdll!ExecuteHandler+0x24
0012f8f4 7c90120e 00000000 0012f92c 0012f90c ntdll!KiUserExceptionDispatcher+0xe
0012fbf4 7c956845 00256488 017855f8 01785590 ntdll!DbgBreakPoint
0012fc0c 7c944172 00000202 7c944214 017855f8 ntdll!RtlApplicationVerifierStop+0x160
0012fc70 7c96c461 01785590 00000080 00000000 ntdll!RtlpCheckForCriticalSectionsInMemoryRange+0xe5
0012fc90 7c96c652 01681000 01001002 00000000 ntdll!RtlpDphNormalHeapFree+0x40
0012fce0 7c96f6f3 01680000 01001002 01785590 ntdll!RtlpDebugPageHeapFree+0x79
0012fd54 7c94bc4c 01680000 01001002 01785590 ntdll!RtlDebugFreeHeap+0x2c
0012fe3c 7c927573 01680000 01001002 01785590 ntdll!RtlFreeHeapSlowly+0x37
0012ff0c 5ad127d1 01680000 00000000 01785590 ntdll!RtlFreeHeap+0xf9
0012ff24 78134c39 01680000 00000000 01785590 verifier!AVrfpRtlFreeHeap+0x15
0012ff70 00401069 01785590 00000001 004011e5 msvcr80!free+0xcd
0012ff7c 004011e5 00000002 017844c8 01783060 TestApplicationVerifier!main+0x69 [c:\111\testapplicationverifier\testapplicationverifier\testapplicationverifier.cpp @ 37]
0012ffc0 7c817077 d309ee22 01c9c4fa 7ffda000 TestApplicationVerifier!__tmainCRTStartup+0x10f [f:\sp\vctools\crt_bld\self_x86\crt\src\crtexe.c @ 597]
0012fff0 00000000 0040132e 00000000 78746341 kernel32!BaseProcessStart+0x23

PRIMARY_PROBLEM_CLASS: STATUS_BREAKPOINT

BUGCHECK_STR: APPLICATION_FAULT_STATUS_BREAKPOINT

FOLLOWUP_IP:
msvcr80!free+cd
78134c39 85c0 test eax,eax

SYMBOL_STACK_INDEX: 11

SYMBOL_NAME: msvcr80!free+cd

FOLLOWUP_NAME: MachineOwner

MODULE_NAME: msvcr80

IMAGE_NAME: msvcr80.dll

DEBUG_FLR_IMAGE_TIMESTAMP: 4889d619

STACK_COMMAND: ~0s ; kb

FAILURE_BUCKET_ID: msvcr80.dll!free_80000003_STATUS_BREAKPOINT

BUCKET_ID: APPLICATION_FAULT_STATUS_BREAKPOINT_msvcr80!free+cd

Followup: MachineOwner
---------

0:000> !cs -s 017855f8
-----------------------------------------
Critical section = 0x017855f8 (+0x17855F8)
DebugInfo = 0x00256480
NOT LOCKED
LockSemaphore = 0x0
SpinCount = 0x00000000

Stack trace for DebugInfo = 0x00256480:

0x7c911583: ntdll!RtlInitializeCriticalSectionAndSpinCount+0xC9
0x7c91162c: ntdll!RtlInitializeCriticalSection+0xF
0x7c809f9f: kernel32!InitializeCriticalSection+0xE
0x00401063: TestApplicationVerifier!main+0x63
0x7c817077: kernel32!BaseProcessStart+0x23
Обратите внимание на подсказку: Freeing heap block containing an active critical section. и дальнейшие подсказки.

Всё настолько просто и очевидно, что даже думать не надо! Один из советов - набрать “!cs -s 017855f8″, что я и сделал в конце. Эта команда позволяет с включенным Application Verifier увидеть - кто и когда создавал и удалял нужную критическую секцию.

Если вы думаете, что это помогает только в таких тестовых случаях, то вы сильно неправы - подобные результаты с легкостью можно получить и на "боевых" приложениях. По слухам, Lingvo 12 в свое время такой проверки сходу не выдержал :-)
Сам я этого не проверял, но про наш флагманский продукт могу сказать то же самое - удалось выявить целую серию мелких ошибок и ошибочек...

Да, нельзя не отметить, что эта бесплатная мощь не совсем бесплатна - работа приложения довольно сильно замедляется. Но на этапе тестирования, думаю, с этим можно мириться...

Комментариев нет: