search

DynamoRIO / dynamorio

Dynamic Instrumentation Tool Platform
Other
2.67k stars 563 forks source link

investigate XP test failures: client.events, client.drsysm_test, etc. #1196

Open derekbruening opened 9 years ago

derekbruening commented 9 years ago

From bruen...@google.com on June 21, 2013 18:19:30

after fixing issue #1195 the xp bot still needs some work: http://build.chromium.org/p/client.dynamorio/builders/win-xp-dr/builds/307/steps/pre-commit%20suite/logs/summary%3A%2016%20failed%2C%201%20flaky%20failed debug-i32-static-ext: build successful; no tests for this build debug-internal-32: 118 tests passed, \ 16 tests failed, of which 1 were flaky: ** unit_tests code_api|security-common.selfmod code_api|security-common.retnonexisting => Application E:\b\build\slave\win-xp-dr\build\build_debug-internal-32\suite\tests\bin\security-common.retnonexisting.exe (3428). Internal Error Internal DynamoRIO Error: ......\dynamorio\core\vmareas.c:8003 !ok || !TEST(MEMPROT_WRITE, prot2) || TEST(FRAG_SELFMOD_SANDBOXED, *flags) code_api|client.events code_api|client.events_cpp code_api|client.large_options code_api|client.drsyms-test code_api|client.pcache-use => Application E:\b\build\slave\win-xp-dr\build\build_debug-internal-32\suite\tests\bin\client.pcache.exe (2424). Internal Error Internal DynamoRIO Error: ......\dynamorio\core\perscache.c:1593 tag != NULL || (instr_opcode_valid(instr) instr_is_cbr(instr)) code_api|sample.instrcalls code_api|api.startstop => Application E:\b\build\slave\win-xp-dr\build\build_debug-internal-32\suite\tests\bin\api.startstop.exe (2900). Internal Error Internal DynamoRIO Error: ......\dynamorio\core\dispatch.c:749 ks-depth 2 stop_not_matching not allowed to clear kstack code_api,opt_memory|client.events code_api,disable_traces|client.events code_api,opt_speed|client.events code_api,thread_private,disable_traces|client.events code_api,thread_private|client.events code_api|client.nudge_ex_FLAKY release-external-32: build successful; no tests for this build vps-debug-internal-32: build successful; no tests for this build

Original issue: http://code.google.com/p/dynamorio/issues/detail?id=1196

derekbruening commented 9 years ago

From bruen...@google.com on June 21, 2013 15:19:38

Labels: GoodContrib

derekbruening commented 9 years ago

From bruen...@google.com on June 26, 2013 16:27:33

\ DONE unit_tests CLOSED: [2013-06-26 Wed 17:12]

This is the first failure:

testing drwinapi kernel32 file-related routines EXPECT failed at D:\derek\dr\git\src\core\win32\drwinapi\kernel32_file.c:2097 in test test_files: !ok && get_last_error() == ERROR_IO_PENDING

On my xp64 VM there's also: testing drwinapi kernel32 file-related routines EXPECT failed at e:\derek\dr\git\src\core\win32\drwinapi\kernel32_file.c:2028 in test test_files: get_last_error() that's just b/c cygwin isn't in c:\cygwin

Allowing ERROR_PATH_NOT_FOUND then hits the same xp32 error.

Running a native app, it seems that asynch i/o on XP and 2K3 will return TRUE with no errno if it went through right away. GetOverlappedResult() still works as on win7.

I checked Vista: it's like win7.

*\ DONE anonymous pipes require names pre-Vista CLOSED: [2013-06-26 Wed 17:06]

EXPECT failed at e:\derek\dr\git\src\core\win32\drwinapi\kernel32_file.c:2193 in test test_pipe: ok

NtCreateNamedPipeFile => c0000033 == STATUS_OBJECT_NAME_INVALID

NtOpenFile asks for the known root name and gets back handle 0x48: 0:000> dds esp 0012fcc4 7d505b66 kernel32!CreatePipe+0xba 0012fcc8 0012fd04 0012fccc 80100000 0012fcd0 0012fd08 0012fcd4 0012fcf0 0012fcd8 00000003 0012fcdc 00000020 0:000> dd 0012fd08 0012fd08 00000018 00000000 0012fd24 00000000 0012fd18 00000000 00000000 0041bc46 00000024 0012fd28 7d505b98 4d55434f 5c317e45 65726564 0:000> du 7d505b98 7d505b98 "\Device\NamedPipe\"

but NtCreateNamedPipeFile includes a name: 0:000> dds esp 0012fca0 7d500861 kernel32!CreatePipe+0x1b0 0012fca4 0012fd20 0012fca8 80100100 0012fcac 0012fd08 0012fcb0 0012fcf0 0012fcb4 00000003 0012fcb8 00000002 0012fcbc 00000020 0012fcc0 00000000 0012fcc4 00000000 0012fcc8 00000000 0012fccc 00000001 0012fcd0 00001000 0012fcd4 00001000 0012fcd8 0012fce8 0:000> dd 0012fd08 0012fd08 00000018 00000048 0012fd24 00000040 0012fd18 00000000 00000000 0041bc46 00000038 0012fd28 0012fd2c 00690057 0033006e 00500032 0:000> du 0012fd2c 0012fd2c "Win32Pipes.000002fc.00000001"

The name comes from here, which uses the PID and a global counter:

7d5007a1 648b1d18000000 mov ebx,fs:[00000018] 7d5007a8 684821567d push 0x7d562148 7d5007ad e82d80fdff call kernel32!InterlockedIncrement (7d4d87df) 7d5007b2 50 push eax 7d5007b3 ff7320 push dword ptr [ebx+0x20] 7d5007b6 8d85f4fdffff lea eax,[ebp-0x20c] 7d5007bc 680c09507d push 0x7d50090c 7d5007c1 50 push eax 7d5007c2 e874010000 call kernel32!swprintf (7d50093b)

0:000> ln 0x7d50090c (7d50090c) kernel32!string' | (7d505b98) kernel32!string' Exact matches: 0:000> du 0x7d50090c 7d50090c "Win32Pipes.%08x.%08x" 0:000> ln 0x7d562148 (7d562148) kernel32!PipeSerialNumber | (7d562180) kernel32!BasepNetMsg Exact matches: kernel32!PipeSerialNumber =

I checked Vista wow64: NtCreateNamedPipeFile is passed NULL for a name.

Passing a name gets past there but we get STATUS_OBJECT_NAME_INVALID opening the write handle! b/c it needs a NULL name.

*\ DONE on xp32, pipe write handle fails to open: requires name again CLOSED: [2013-06-26 Wed 18:43]

getting:

define STATUS_SHARING_VIOLATION ((NTSTATUS)0xC0000043L)

it doesn't pass a parent to NtCreateNamedPipeFile, but just passes: 0:000> dds esp 0012fdb0 7c81d962 kernel32!CreatePipe+0x128 0012fdb4 0012fe34 0012fdb8 80100100 0012fdbc 0012fdfc 0012fdc0 0012fe20 0012fdc4 00000003 0012fdc8 00000002 0012fdcc 00000020 0012fdd0 00000000 0012fdd4 00000000 0012fdd8 00000000 0012fddc 00000001 0012fde0 00001000 0012fde4 00001000 0012fde8 0012fe28 0012fdec 0192f5c4 0:000> dd 0012fdfc
0012fdfc 00000018 00000000 7ffdfbf8 00000040 0012fe0c 00000000 00000000 0012ff60 002f002e 0:000> dd 7ffdfbf8 7ffdfbf8 020a005c 7ffdfc00 0044005c 00760065 0:000> du 7ffdfc00 7ffdfc00 "\Device\NamedPipe\Win32Pipes.000" 7ffdfc40 "00180.00000001"

gets back handle 0x2c

it opens the write handle here, strangely w/o a rootdir: 0:000> dds esp 0012fdd0 7c81d98e kernel32!CreatePipe+0x154 0012fdd4 0012fe30 0012fdd8 40100080 GENERIC_WRITE | SYNCHRONIZE | FILE_READ_ATTRIBUTES 0012fddc 0012fdfc 0012fde0 0012fe20 0012fde4 00000003 FILE_SHARE_READ | FILE_SHARE_WRITE 0012fde8 00000060 0:000> dd 0012fdfc 0012fdfc 00000018 00000000 7ffdfbf8 00000040 0012fe0c 00000000 00000000 0012ff60 002f002e 0:000> dd 7ffdfbf8 7ffdfbf8 020a005c 7ffdfc00 0044005c 00760065 7ffdfc08 00630069 005c0065 0061004e 0065006d 0:000> du 7ffdfc00 7ffdfc00 "\Device\NamedPipe\Win32Pipes.000" 7ffdfc40 "00180.00000001"

it looks like win7 passes the same flags.

passing the name to the OpenFile works.

*\ DONE misc failures CLOSED: [2013-06-26 Wed 17:12]

advapi32 tests: WINDOWS instead of Windows DnsCache instead of DNS

on xp32, just one entry: DnsCache, and no DHCP

derekbruening commented 9 years ago

From bruen...@google.com on June 27, 2013 11:56:46

\ TODO events failures

filter syscall event never called: b/c there are no statically-known syscall #s.

=> going to add back in RUNREGRESSION_XP and other defines so we can have an xp-dependent .template file

Owner: bruen...@google.com

derekbruening commented 9 years ago

From bruen...@google.com on June 27, 2013 13:52:52

\ TODO drsyms and instrcalls failures

it's b/c the system dbghelp, which we use for these tests (unlike drmem we don't have our own copy of dbghelp), doesn't have SymEnumLines:

92: <Application C:\derek\dr\git\build_x86_dbg_tests\suite\tests\bin\client.drsyms-test.exe (2936). Unable to load client library: import SymEnumLines not found in DBGHELP.dll.>

added in 2003: % for i in find . -name dbghelp.dll; do echo $i; dumpbin /exports $i | grep SymEnumLines; done ./5.00.2195.1620-NTDDK/dbghelp.dll ./5.00.2195.6613-Win2K/dbghelp.dll ./5.1.2600.5512-XP32/dbghelp.dll ./5.2.3790.1830-XP64/dbghelp.dll 31 1E 0001D54F SymEnumLines ./5.2.3790.1830-XP64/x64/dbghelp.dll 29 1C 0002C350 SymEnumLines ./6.0.6001.18000-Vista/dbghelp.dll 39 25 000289D9 SymEnumLines 40 26 00028A46 SymEnumLinesW ./6.0.6001.18000-Vista/x64/dbghelp.dll 38 24 00015664 SymEnumLines 39 25 00015730 SymEnumLinesW ./6.1.7601.17514-Win7/dbghelp.dll 44 2A 00032FA1 SymEnumLines 45 2B 00033018 SymEnumLinesW ./6.1.7601.17514-Win7/x64/dbghelp.dll 43 29 00016C44 SymEnumLines 44 2A 00016D2C SymEnumLinesW ./6.11.0000.305-DDK7600.16385.1/dbghelp.dll 44 2A 00036A20 SymEnumLines 45 2B 00036AD0 SymEnumLinesW ./6.11.0000.305-DDK7600.16385.1/x64/dbghelp.dll 43 29 00046590 SymEnumLines 44 2A 00046680 SymEnumLinesW ./6.11.0001.402-DDK/dbghelp.dll 44 2A 00036B10 SymEnumLines 45 2B 00036BC0 SymEnumLinesW ./6.12.0002.633-DDK7600.16385.1/x64/dbghelp.dll 43 29 00048C80 SymEnumLines 44 2A 00048D70 SymEnumLinesW ./6.2.9200.16384-Win8/dbghelp.dll 47 2D 0003112C SymEnumLines 48 2E 000311AE SymEnumLinesW ./6.2.9200.16384-Win8/x64/dbghelp.dll 46 2C 00029698 SymEnumLines 47 2D 00029760 SymEnumLinesW ./6.3.0016.1-DDK3790.1830/dbghelp.dll 38 23 0002EBC0 SymEnumLines 39 24 0002EC50 SymEnumLinesW ./6.3.0017.0-DTFW/dbghelp.dll 38 23 0002ED80 SymEnumLines 39 24 0002EE10 SymEnumLinesW ./6.5.003.7-VS2005/dbghelp.dll 38 24 00031BC0 SymEnumLines 39 25 00031C60 SymEnumLinesW ./6.6.0003.3-DDK6000/dbghelp.dll 39 25 00033E30 SymEnumLines 40 26 00033ED0 SymEnumLinesW

solution choices: A] have DR config go find a more recent dbghelp? B] have drsyms dynamically look up this import -- and change test to allow failure or skip tests of that feature

drsyms today documents it needs a more recent dbghelp than xp's system one so no other reason to do B.

I did A, and then instrcalls passes and the output looks right.

But drsyms test fails:

ASSERT FAILURE: C:\derek\dr\git\src\suite\tests\client-interface\drsyms-test.dll.cpp:678: type->id == out->type_id || (type->kind == DRSYM_TYPE_OTHER && type->id == 0) || strstr(out->name, "__") == out->name () 12:45 PM ~/dr/git/build_x86_dbg_tests

comparing id=2029 32 kind=1 name=TrailDownVec @0x000074c0-0x000074c4 kind == DRSYM_TYPE_INT

0:000> x *!TrailDownVec 100074c0 client_drsyms_test_appdll!TrailDownVec = 0x100074d0 1000d870 client_drsyms_test_appdll!TrailDownVec = 0x1000d880 0:000> ln 100074c0 f:\dd\vctools\crt_bld\SELF_X86\crt\src\INTEL\memcpy.asm(549)+0x9 (100074c0) client_drsyms_test_appdll!TrailDownVec | (10007515) client_drsyms_test_appdll!__security_check_cookie Exact matches: client_drsyms_test_appdll!TrailDownVec = 0x100074d0 0:000> ln 100074d0 f:\dd\vctools\crt_bld\SELF_X86\crt\src\INTEL\memcpy.asm(558) (100074c0) client_drsyms_test_appdll!TrailDownVec+0x10 | (10007515) client_drsyms_test_appdll!__security_check_cookie

crt-VS2008/src/intel/memcpy.asm:TrailDownVec dd TrailDown0, TrailDown1, TrailDown2, TrailDown3

comparing id=2029 32 kind=1 name=TrailDownVec comparing id=2031 32 kind=1 name=TrailDownVec ... comparing id=2056 32 kind=1 name=UnwindUpVec comparing id=2058 32 kind=1 name=UnwindUpVec ... comparing id=2068 32 kind=1 name=LeadUpVec comparing id=2070 32 kind=1 name=LeadUpVec ... comparing id=32 32 kind=1 name=__flsindex

I don't understand that 32 type id. Going to exclude.

Also: comparing id=2035 55 kind=2 name=lastTZ @0x0001ca30-0x0001ca34 comparing id=2051 94 kind=5 name=dststart @0x0001bbc0-0x0001bbcc comparing id=2077 171 kind=2 name=term_action @0x0001c610-0x0001c614 comparing id=2082 179 kind=5 name=GS_ContextRecord @0x0001c6b0-0x0001c97c comparing id=2111 181 kind=2 name=g_pfnRtlGenRandom @0x0001c618-0x0001c61c comparing id=2125 15 kind=1 name=DebuggerWasPresent @0x0001c6a8-0x0001c6ac comparing id=2127 15 kind=1 name=fSystemSet @0x0001c2c4-0x0001c2c8 comparing id=2135 15 kind=1 name=ErrnoNoMem @0x0001b908-0x0001b90c comparing id=2137 230 kind=5 name=tzinfo @0x0001c980-0x0001ca2c comparing id=2154 171 kind=2 name=abort_action @0x0001c60c-0x0001c610 comparing id=2158 171 kind=2 name=ctrlbreak_action @0x0001c608-0x0001c60c comparing id=2164 15 kind=1 name=ConsoleCtrlHandler_Installed @0x0001c614-0x0001c618 comparing id=2168 288 kind=2 name=_ctype_loc_style @0x0001b188-0x0001b18c comparing id=2180 316 kind=5 name=GS_ExceptionPointers @0x00019328-0x00019330 comparing id=2208 380 kind=5 name=GS_ExceptionRecord @0x0001c658-0x0001c6a8 comparing id=2217 177 kind=2 name=ntdll_handle @0x0001bfe0-0x0001bfe4 comparing id=2224 15 kind=1 name=tzapiused @0x0001ca2c-0x0001ca30 comparing id=2228 171 kind=2 name=ctrlc_action @0x0001c604-0x0001c608 comparing id=2241 94 kind=5 name=dstend @0x0001bbcc-0x0001bbd8 comparing id=2275 442 kind=2 name=pinit @0x00017310-0x00017314 comparing id=2279 442 kind=2 name=pinit @0x0001730c-0x00017310 comparing id=2283 442 kind=2 name=pinit @0x00017314-0x00017318 comparing id=2300 32 kind=1 name=DoserrorNoMem @0x0001b90c-0x0001b910

I copied client.drsyms-test.appdll.dll to win7: works fine. I copied this dbghelp.dll: same assert! version: 6.8.0004.0 (debuggers(dbg).070515-1751) from VS2008 Express: Microsoft Visual Studio 9.0/Common7/IDE/dbghelp.dll

VS2008 Prof: 6.9.0003.113 (debuggers(dbg).080320-1813) => same assert as Express

win7 system32: 6.1.7601.17514 (win7sp1_rtm.101119-1850) => works

w/ dbghelp from DTFW 6.3: ASSERT FAILURE: C:\derek\dr\git\src\suite\tests\client-interface\drsyms-test.dll.cpp:650: strlen(out->name) == out->name_available_size () name=__newclmap, len=10, avail=11

they're all off by one. bug? terminating null?

I guess older dbghelp is just flaky.

I'm going to pick VS over DTFW, and for now I may just relax the enum type check for <= XP b/c that's the only place we use VS dbghelp.

derekbruening commented 9 years ago

From bruen...@google.com on June 27, 2013 14:19:57

\ TODO pcache-use

ASSERT FAILURE: C:\derek\dr\git\src\suite\tests\client-interface\pcache.dll.c:147: ((app_pc)he->key) == ((app_pc)he->payload) ()

0:000> U @@(he->key) ntdll!ZwMapViewOfSection: 7c90d51e b86c000000 mov eax,0x6c 0:000> db @@(he->payload) 1e92ef10 e9 ab ab ab bc bc bc bc-1e d5 90 7c 10 ef 92 1e ...........|....

must have been hooked

vm_area_delay_load_coarse_units() is called before callback_interception_init_finish(), probably for a reason for coarse units: I don't recall all the complexities of hooks there. I'm not going to mess w/ that here.

Can't store 1st raw byte to fix: hooked instr has no raw bits.

=> just relax assert for now.