drwrap-test failure

[derekbruening]

From [email protected] on June 04, 2012 13:29:07

$ ctest -V -I 68,68
UpdateCTestConfiguration from :D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/DartConfiguration.tcl
Parse Config file:D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/DartConfiguration.tcl
UpdateCTestConfiguration from :D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/DartConfiguration.tcl
Parse Config file:D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/DartConfiguration.tcl
Test project D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64
Constructing a list of tests
Done constructing a list of tests
Checking test dependency graph...
Checking test dependency graph end
test 68
Start 68: code_api|client.drwrap-test

68: Test command: D:\src\cygwin\home\zhaoqin\Workspace\DynamoRIO\builds\build_debug-internal-64\bin64\drrun.exe "-s" "60" "-quiet" "-exit0" "-ops" "-stderr_mask 0xC -msgbox_mask 0 -dumpcore_mask 0xfd -staged -code_api -client_lib 'D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/suite/tests/bin/client.drwrap-test.dll.dll;0;' -code_api " "-use_dll" "D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/lib64/debug/dynamorio.dll" "D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/suite/tests/bin/client.drwrap-test.exe" "D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/suite/tests/bin/client.drwrap-test.appdll.dll"
68: Test timeout computed to be: 1500
68: thread.appdll process init
68:
68: in level0 42
68:
68: in level1 42 1111
68: <pre-makes_tailcall>
68:
68: in level2 1153
68:
68: <post-makes_tailcall>
68:
68: level1 returned -4
68:
68: level0 returned 42
68:
68: skipme returned 7 and x=3
68: replaceme returned 0 and x=6
68: replaceme2 returned 1 and x=999
68:
68: in preonly
68: in postonly
68:
68: in skipme
68: in postonly
68: in runlots 1024
68:
68:
68: long0 A
68:
68:
68: long1 A
68:
68:
68: long2 A
68:
68:
68: long3 A
68:
68:
68:
68:
68:
68:
68:
68:
68: longdone
68: loaded library
68: thread.appdll process init
68:
68: in level0 42
68:
68: in level1 42 1111
68: <pre-makes_tailcall>
68:
68: in level2 1153
68:
68: <post-makes_tailcall>
68:
68: level1 returned -4
68:
68: level0 returned 42
68:
68: skipme returned 7 and x=3
68: replaceme returned 0 and x=6
68: replaceme2 returned 1 and x=999
68:
68: in preonly
68: in postonly
68:
68: in skipme
68: in postonly
68: in runlots 1024
68:
68: long0 A
68:
68: long1 A
68:
68: long2 A
68:
68: long3 A
68:
68:
68:
68:
68: longdone
68: loaded library
68: thank you for testing the client interface
68: all done
?/1 Test #68: code_api|client.drwrap-test ......***Failed Required regular expression not found.Regex=[^] 1.51 sec

0% tests passed, 1 tests failed out of 1

Total Test time (real) = 2.06 sec

The following tests FAILED:
68 - code_api|client.drwrap-test (Failed)
Errors while running CTest

The failure also starts showing in bots http://build.chromium.org/p/client.drmemory/builders/win-vista_x64-dr/builds/1729/steps/Build&#37;20and&#37;20test&#37;20DR/logs/stdio

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

[derekbruening]

From [email protected] on June 04, 2012 10:31:38

A run from command line, however, works fine:

$ ./bin64/drrun.exe -debug -ops "-stderr_mask 0xC -msgbox_mask 0 -dumpcore_mask 0xfd -staged" -client ./suite/tests/bin/client.drwrap-test.dll.dll 0 "" -- ./suite/tests/bin/client.drwrap-test.exe "D:/src/cygwin/home/zhaoqin/Workspace/DynamoRIO/builds/build_debug-internal-64/suite/tests/bin/client.drwrap-test.appdll.dll"
thread.appdll process init

in level0 42

in level1 42 1111
<pre-makes_tailcall>

in level2 1153

<post-makes_tailcall>

level1 returned -4

level0 returned 42

skipme returned 7 and x=3
replaceme returned 0 and x=6
replaceme2 returned 1 and x=999

in preonly
in postonly

in skipme
in postonly
in runlots 1024


long0 A


long1 A


long2 A


long3 A








longdone
loaded library
thread.appdll process init

in level0 42

in level1 42 1111
<pre-makes_tailcall>

in level2 1153

<post-makes_tailcall>

level1 returned -4

level0 returned 42

skipme returned 7 and x=3
replaceme returned 0 and x=6
replaceme2 returned 1 and x=999

in preonly
in postonly

in skipme
in postonly
in runlots 1024

long0 A

long1 A

long2 A

long3 A




longdone
loaded library
thank you for testing the client interface
all done

[derekbruening]

From [email protected] on June 04, 2012 10:43:59

On bot, the drutil also failed, but cannot reproduce locally. http://build.chromium.org/p/client.drmemory/builders/win-vista_x64-dr/builds/1732/steps/Build%20and%20test%20DR/logs/summary%3A%209%20failed%2C%203%20flaky%20failed http://build.chromium.org/p/client.drmemory/builders/win-vista_x64-dr/builds/1732

[derekbruening]

From [email protected] on September 07, 2012 14:39:13

drwrap-test fails for me on ia32 reliably. Under gdb, it stops here:

Program received signal SIGTRAP, Trace/breakpoint trap.
0x5483d124 in ?? ()
(gdb) bt
#0 0x5483d124 in ?? ()
#1 0xf7723426 in ?? ()
#2 0xf774de9b in ?? () from /lib/ld-linux.so.2
#3 0xf774df84 in ?? () from /lib/ld-linux.so.2
#4 0xf7751f96 in ?? () from /lib/ld-linux.so.2
#5 0xf774dcbf in ?? () from /lib/ld-linux.so.2
#6 0xf77517e4 in ?? () from /lib/ld-linux.so.2
#7 0xf770cbe9 in dlopen_doit (a=0xffb15140) at dlopen.c:67
#8 0xf774dcbf in ?? () from /lib/ld-linux.so.2
#9 0xf770d33a in _dlerror_run (operate=0xf770cb50 <dlopen_doit>, args=0xffb15140) at dlerror.c:164
#10 0xf770cc97 in __dlopen (file=0xffb165c3 "./suite/tests/bin/libclient.drwrap-test.appdll.so", mode=1) at dlopen.c:88
#11 0x08048c2d in load_library (path=0xffb165c3 "./suite/tests/bin/libclient.drwrap-test.appdll.so") at ../../suite/tests/client-interface/drwrap-test.c:50
#12 0x08048caf in main (argc=2, argv=0xffb15244) at ../../suite/tests/client-interface/drwrap-test.c:75
(gdb) x/12i $pc - 1
0x5483d123: int3
=> 0x5483d124: int3
0x5483d125: int3
0x5483d126: int3
0x5483d127: int3
0x5483d128: int3
0x5483d129: int3
0x5483d12a: int3
0x5483d12b: int3
0x5483d12c: int3
0x5483d12d: int3
0x5483d12e: int3

Weird! If I revert r1539 , the test passes. Continuing to look into it.

Owner: [email protected]

[derekbruening]

From [email protected] on September 07, 2012 15:29:07

Looks like we end up flushing the fragment that the clean call is trying to return to:

#0 flush_fragments_in_region_start(base=0xf7787faa size=1)
#1 0xf7098a4b in flush_fragments_from_region
#2 0xf72704d7 in dr_unlink_flush_region
#3 0xf7597408 in drwrap_flush_func
#4 0xf759850c in drwrap_after_callee_func
#5 0xf7598e72 in drwrap_in_callee_check_unwind
#6 0xf7597947 in drwrap_in_callee
#7 0x4a385123 in ?? # note the retaddr

#0 flush_fragments_in_region_start(base=0xf7787f32 size=1)
#1 0xf7098a4b in flush_fragments_from_region
#2 0xf72704d7 in dr_unlink_flush_region
#3 0xf7597408 in drwrap_flush_func
#4 0xf759850c in drwrap_after_callee_func
#5 0xf7598e72 in drwrap_in_callee_check_unwind
#6 0xf7597947 in drwrap_in_callee
#7 0x4a385123 in ??

And then we hit a breakpoint after continuing:
(gdb) x/5i $pc - 1
0x4a385123: int3
=> 0x4a385124: int3
0x4a385125: int3
0x4a385126: int3
0x4a385127: int3

[derekbruening]

From [email protected] on September 11, 2012 08:11:04

This issue was closed by revision r1576 .

Status: Fixed