Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

func_view test fails on Appveyor with access violation #4155

Closed
derekbruening opened this issue Mar 4, 2020 · 2 comments · Fixed by #4157
Closed

func_view test fails on Appveyor with access violation #4155

derekbruening opened this issue Mar 4, 2020 · 2 comments · Fixed by #4157
Assignees
@derekbruening
Labels
Bug-DRCrash Component-DrMemtrace OpSys-Windows

Comments

@derekbruening
Copy link
Contributor

My func_view test from PR #4150 for #4083 works on Windows locally (ran 20x in a row on each of 2 different 1909 machines) but on Appveyor it has a mysterious crash:

[00:24:03] 205: Running postcmd |C:/projects/dynamorio/build/build_debug-internal-64/clients/bin64/drcachesim.exe;-indir;C:/projects/dynamorio/build/build_debug-internal-64/suite/tests/tool.drcacheoff.func_view.common.fib.exe.07132.7209.dir;-simulator_type;func_view|
[00:24:03] 205: CMake Error at C:/projects/dynamorio/suite/tests/runmulti.cmake:106 (message):
[00:24:03] 205:   *** postcmd failed (Access violation): ***
[00:24:03] 205: 
[00:24:03] 205: Call Stack (most recent call first):
[00:24:03] 205:   C:/projects/dynamorio/suite/tests/runmulti.cmake:118 (process_cmdline)
[00:24:03] 205: 
[00:24:03] 205: 
[00:24:03] 205/239 Test #205: code_api|tool.drcacheoff.func_view ...........................***Failed   14.80 sec

For now I'm disabling the test on Windows.
derekbruening added a commit that referenced this issue Mar 4, 2020
@derekbruening
i#4083 func trace: Add func_view tool (#4150)
f4c1085 
Adds a new func_view tool for visualizing and analyzing function calls
recorded in a drcachesim trace.  It does two things in its initial
form: it reports the summary count of calls and returns for every
function traced, and if a new option op_show_func_trace is set (on by
default), it prints a linear sequence of every call and return with
return addresses, argument values, and return values.  Each is
indented to enable a clear picture of the call sequence.

Adds a new option op_funclist_file to specify the file's path, though
normally it will be auto-found.

Adds raw2trace_directory_t support for parsing the funclist file.

Adds example output for the new tool to the docs.  Adds a brief
section to the docs on function tracing in general, which was
previously missing.

Adds a func_view test which runs fib(5) and ensures we get the nested
function trace correct.

Disables the test on Windows due to unreproducible-locally Appveyor failures.
#4155 covers figuring that out later.

Issue: #4155
Fixes #4083
@derekbruening derekbruening self-assigned this Mar 4, 2020
@derekbruening
Copy link
Contributor Author

I did manage to reproduce on a VM I have, about one in 5 runs. It is a crash in raw2trace. It is unclear how it relates to func_view: it may not and just be related to fib.exe. I am trying to get a verbose log but it is slow on this VM.

@derekbruening
Copy link
Contributor Author

Does not reproduce at -verbose 3+.
But it does reproduce at lower verbosity.
It is in a worker thread:

(100c.1cf8): Access violation - code c0000005 (first chance)
First chance exceptions are reported before any exception handling.
This exception may be expected and handled.
dynamorio!os_wait_event+0x143:
00000000`15379a73 488bb8e0040000  mov     rdi,qword ptr [rax+4E0h] ds:00000000`000004df=????????????????
0:004> kn
 # Child-SP          RetAddr           Call Site
00 00000006`597fe5b0 00000000`1536bb30 dynamorio!os_wait_event+0x143 [c:\derek\dr\git\src\core\win32\os.c @ 8449] 
01 00000006`597fe8a0 00000000`150fe2a5 dynamorio!mutex_wait_contended_lock+0xd0 [c:\derek\dr\git\src\core\win32\os.c @ 8576] 
02 00000006`597fe8e0 00000000`150fe7ad dynamorio!d_r_mutex_lock_app+0xb5 [c:\derek\dr\git\src\core\utils.c @ 894] 
03 00000006`597fe920 00000000`150fe5c5 dynamorio!acquire_recursive_app_lock+0x4d [c:\derek\dr\git\src\core\utils.c @ 1021] 
04 00000006`597fe950 00000000`151ab33b dynamorio!acquire_recursive_lock+0x15 [c:\derek\dr\git\src\core\utils.c @ 1030] 
05 00000006`597fe980 00000000`15192990 dynamorio!common_global_heap_free+0x6b [c:\derek\dr\git\src\core\heap.c @ 3470] 
06 00000006`597fe9c0 00000000`1523a39a dynamorio!heap_reachable_free+0x90 [c:\derek\dr\git\src\core\heap.c @ 4807] 
07 00000006`597fea20 00007ff6`80d43c86 dynamorio!dr_global_free+0x2a [c:\derek\dr\git\src\core\lib\instrument.c @ 2938] 
08 00000006`597fea50 00007ff6`80d43c27 drcachesim!dr_allocator_t<std::_Container_proxy>::deallocate+0x26 [c:\derek\dr\git\src\clients\drcachesim\tracer\dr_allocator.h @ 71] 
09 00000006`597fea80 00007ff6`80d41433 drcachesim!std::_Normal_allocator_traits<dr_allocator_t<std::_Container_proxy> >::deallocate+0x27 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\xmemory0 @ 760] 
0a 00000006`597feab0 00007ff6`80d42e68 drcachesim!std::_Deallocate_plain<dr_allocator_t<std::_Container_proxy>,0>+0x23 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\xmemory0 @ 1214] 
0b 00000006`597feae0 00007ff6`80d4210c drcachesim!std::_Vector_alloc<std::_Vec_base_types<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0>,dr_allocator_t<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0> > > >::_Free_proxy+0x58 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\list @ 539] 
0c 00000006`597feb20 00007ff6`80d42197 drcachesim!std::_Vector_alloc<std::_Vec_base_types<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0>,dr_allocator_t<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0> > > >::~_Vector_alloc<std::_Vec_base_types<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0>,dr_allocator_t<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0> > > >+0x1c [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\vector @ 461] 
0d 00000006`597feb60 00007ff6`80d4207a drcachesim!std::vector<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0>,dr_allocator_t<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0> > >::~vector<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0>,dr_allocator_t<std::_List_unchecked_const_iterator<std::_List_val<std::_List_simple_types<unsigned short> >,std::_Iterator_base0> > >+0x27 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\vector @ 895] 
0e 00000006`597feba0 00007ff6`80d42163 drcachesim!std::_Hash<std::_Uset_traits<unsigned short,std::_Uhash_compare<unsigned short,std::hash<unsigned short>,std::equal_to<unsigned short> >,dr_allocator_t<unsigned short>,0> >::~_Hash<std::_Uset_traits<unsigned short,std::_Uhash_compare<unsigned short,std::hash<unsigned short>,std::equal_to<unsigned short> >,dr_allocator_t<unsigned short>,0> >+0x1a
0f 00000006`597febd0 00007ff6`80d3fe26 drcachesim!std::unordered_set<unsigned short,std::hash<unsigned short>,std::equal_to<unsigned short>,dr_allocator_t<unsigned short> >::~unordered_set<unsigned short,std::hash<unsigned short>,std::equal_to<unsigned short>,dr_allocator_t<unsigned short> >+0x13
10 00000006`597fec00 00007ff6`80d393e0 drcachesim!offline_instru_t::identify_elidable_addresses+0x5c6 [c:\derek\dr\git\src\clients\drcachesim\tracer\instru_offline.cpp @ 769] 
11 00000006`597feed0 00007ff6`80d3a281 drcachesim!trace_converter_t<raw2trace_t>::analyze_elidable_addresses+0x250 [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.h @ 793] 
12 00000006`597ff190 00007ff6`80d3d0a0 drcachesim!trace_converter_t<raw2trace_t>::append_bb_entries+0x411 [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.h @ 934] 
13 00000006`597ff500 00007ff6`80d2f703 drcachesim!trace_converter_t<raw2trace_t>::process_offline_entry+0x5b0 [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.h @ 671] 
14 00000006`597ff830 00007ff6`80d30d9d drcachesim!raw2trace_t::process_next_thread_buffer+0x5a3 [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.cpp @ 522] 
15 00000006`597ff950 00007ff6`80d312ff drcachesim!raw2trace_t::process_thread_file+0x10d [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.cpp @ 538] 
16 00000006`597ffb80 00007ff6`80d3184d drcachesim!raw2trace_t::process_tasks+0x20f [c:\derek\dr\git\src\clients\drcachesim\tracer\raw2trace.cpp @ 591] 
17 00000006`597ffc20 00007ff6`80d34ea9 drcachesim!std::_Invoker_pmf_pointer::_Call<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *>+0x4d
18 00000006`597ffc60 00007ff6`80d32645 drcachesim!std::invoke<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *>+0x69
19 00000006`597ffcc0 00007ff6`80d383a5 drcachesim!std::_LaunchPad<std::unique_ptr<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *>,std::default_delete<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *> > > >::_Execute<0,1,2>+0x65 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\thr\xthread @ 239] 
1a 00000006`597ffd00 00007ff6`80d380e3 drcachesim!std::_LaunchPad<std::unique_ptr<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *>,std::default_delete<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *> > > >::_Run+0x55 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\thr\xthread @ 245] 
1b 00000006`597ffd50 00007ff6`80c1bc78 drcachesim!std::_LaunchPad<std::unique_ptr<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *>,std::default_delete<std::tuple<void (__cdecl raw2trace_t::*)(std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *),raw2trace_t *,std::vector<raw2trace_t::raw2trace_thread_data_t *,std::allocator<raw2trace_t::raw2trace_thread_data_t *> > *> > > >::_Go+0x13 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\thr\xthread @ 231] 
1c 00000006`597ffd80 00007ff6`80ca30c8 drcachesim!std::_Pad::_Call_func+0x18 [c:\program files (x86)\microsoft visual studio\2017\professional\vc\tools\msvc\14.16.27023\include\thr\xthread @ 209] 
1d 00000006`597ffdb0 00007ff6`80ca2dd1 drcachesim!invoke_thread_procedure+0x28 [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 92] 
1e 00000006`597ffdf0 00007ffa`54667bd4 drcachesim!thread_start<unsigned int (__cdecl*)(void * __ptr64)>+0x91 [minkernel\crts\ucrt\src\appcrt\startup\thread.cpp @ 115] 
1f 00000006`597ffe40 00007ffa`55a6ced1 KERNEL32!BaseThreadInitThunk+0x14
20 00000006`597ffe70 00000000`00000000 ntdll!RtlUserThreadStart+0x21

standalone_library is true, but we only go to malloc inside DR for static linkage.

We use dr_allocator_t for under-DR usage which is why it's using
dr_global_alloc. While it would be nice to expand the use of malloc for
raw2trace outside of static linkage: I think the simpler approach is to
check for GLOBAL_DCONTEXT in the kstats code.

derekbruening added a commit that referenced this issue Mar 4, 2020
@derekbruening
i#4155: Fix raw2trace crash on Windows
b673745 
Adds a check for the current dcontext being GLOBAL_DCONTEXT in the
kstats code to avoid a raw2trace crash.

Enables the func_view test on Windows.

Fixes #4155
@derekbruening derekbruening mentioned this issue Mar 4, 2020
Merged
derekbruening added a commit that referenced this issue Mar 4, 2020
@derekbruening
i#4155: Fix raw2trace crash on Windows (#4157)
1649914 
Adds a check for the current dcontext being GLOBAL_DCONTEXT in the
kstats code to avoid a raw2trace crash.

Enables the func_view test on Windows.

Fixes #4155
@derekbruening derekbruening mentioned this issue Aug 14, 2020
Merged
Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees

@derekbruening derekbruening

Labels
Bug-DRCrash Component-DrMemtrace OpSys-Windows
Projects
None yet
Milestone
No milestone
Development

Successfully merging a pull request may close this issue.

i#4155: Fix raw2trace crash on Windows DynamoRIO/dynamorio
1 participant
@derekbruening