APPCRASH during process detach, using HelloWorld example

[Flora Xiao]

Hello,

Again, I'd like to thank you for the tool first.

I wrote a simple console application called HelloWorld, with no parameters. It started as a stock C# Console Application project in Visual Studio 2015, to which I added the line "Console.Out.WriteLine("Hello World!");" and deleted all imports except "using System;". I compiled it into a x64 Release binary for .NET 4.6.2. I ran the binary from the Developer Command Prompt for VS2015 on Windows 10, which ran fine and exited with no errors. I then ran it from the Command Prompt on Windows Server 2012 R2, which also ran fine and exited with no errors.

Working on the Windows Server machine, I tried to run HelloWorld with drrun.exe. I tried both 6.2.0-2 and 7.0.0-RC1, with no noticeable difference during runtime. It appears not to run, but when I open the Task Manager, I can see the "HelloWorld" process under "Background Processes" briefly, then the "HelloWorld" process disappears from Task Manager and a dialog box displaying "HelloWorld has stopped working" appears, declaring an APPCRASH event. I've attached a screenshot of the expanded problem details.

[Dialog Box Screenshot attached]

The Task Manager and dialog box events happen when I run drrun.exe with "-debug" and "-verbose" as well, but the console gives some more information regarding the error. I've attached a screenshot of the console output.

[Command Prompt Screenshot attached]

This led me to line 1422 of dynamorio_package\core\heap.c, which includes the check "IF_WINDOWS(doing_detach ||)" along with some code about heap memory management. It's a different line number in the repo's master branch online (https://github.com/DynamoRIO/dynamorio/blob/master/core/heap.c#L1403), but the comments give me the impression that there may be something going on there. I'm not familiar with how DynamoRIO handles the detaching process and heap memory; is there some flag or setting I need to run drrun.exe with?

Final note: The same thing happened for a console application with parameters that loaded a library (same build parameters--x64 Release, .NET 4.6.2), so I am using HelloWorld right now to help figure out the problem.

Thank you for your help!

Best,
Flora

[Flora Xiao]

OCR'd and edited the Command Prompt output for easier searching.

---------------------
PS C:\Users\Administrator\Documents> .\DynamoRIO-Windows-6.2.0-2\bin64\drrun.exe -debug -- C:\Users\Administrator\Docume
nts\binaries\HelloWorld\x64\Release\HelloWorld.exe
<Starting application C:\Users\Administrator\Documents\binaries\HelloWorld\x64\Release\HelloWorld.exe (504)>
<Initial options = —no_dynamic_options -code_api —probe_api —stack_size 56K —max_elide.jmp 0 —max_elide_call 0 —no_inlin
e_ignored_sysca11s -native_exec_default-list " -no_native_exec_managed_code -no_indcall2direct -pad_jmps_mark_no_trace
>
<non-syscall, non-int2b 0x21 @ 0x0000008252190047 from 0x0000008252190000>
<Invalid opcode encountered)
<legacy process creation detected: may miss chi1d>
<Stopping application C:\Users\Administrator\Documents\binaries\HelloWorld\x64\Release\HelloWorld.exe (504)>
<Application C:\Users\Administrator\Docunents\binaries\HelloWorld\x64\Release\HelloWorld.exe (504). Internal Error: Dyn
amoRIO debug check failure: D:\dynamorio_package\core\heap.c:1422 IF_WINDOWS(doing_detach || ) heapmgt->vmheap.num_free_
blocks == heapmgt—>vmheap.num_blocks — unfreed_blocks || (ever_beyond_vmm && heapmgt—>vmheap.num_free_blocks >= heapmgt-
>vmheap.num_b10cks - unfreed_b10cks)
(Error occurred @1317 frags)
version 6.2.0, build 2
-no_dynanic_options -code_api -probe_api -stack_size 56K -max_elide_jmp O -max_elide_call O —no_inline_iqnored_syscalls
-native_exec_default_list " -no_native_exec_managed_code -no_indcall2direct -pad_jmps_mark_no_trace
0x00000082526ae388 0x00000081d2262080
OxOOOOOOOOlSBdaQbe Oxccccccccccccc300>
PS C:\Users\Administrator\Documents> .\DynamoRIO—Windows-6.2.0—2\bin64\drrun.exe —verbose —— C:\Users\Administrator\Docu
ments\binaries\HelloWorld\x64\Release\HelloWorld.exe
INFO: targeting application: "C:\Users\Administrator\Documents\binaries\HelloWorld\x64\Release\HelloWorld.exe"
INFO: app cmdline: “C:\Users\Administrator\Documents\binaries\HelloWorld\x64\Release\HelloWorld.exe"
INFO: configuration directory is "C:\Users\Administrator/dynamorio"
INFO: created child with pid 3056 for C:\Users\Administrator\Documents\binaries\HelloWorld\x64\Release\HelloWorld.exe
INFO: waiting forever for app to exit...
---------------------

Unfortunately, my current method of accessing my VM does not allow me to directly copy text.

[Derek Bruening]

The int 0x21 and "Invalid opcode encountered" do not look good.  Are those inside a library, the 0x0000008252190047 address?  What is the disassembly around there?  Does that look like code or did control go off to a bogus address?  Since the app is small, running `-loglevel 3` should provide the answers.

--
You received this message because you are subscribed to the Google Groups "DynamoRIO Users" group.
To unsubscribe from this group and stop receiving emails from it, send an email to dynamorio-users+unsubscribe@googlegroups.com.
To post to this group, send email to dynamorio-users@googlegroups.com.
Visit this group at https://groups.google.com/group/dynamorio-users.
For more options, visit https://groups.google.com/d/optout.

[Flora Xiao]

Hello! 

Thanks for your reply. I ran it with -loglevel 3 and attached the screenshot here. The only library I imported was the System library. The address seems to change every time--I'm not sure why. It could possibly be a bogus address, but I'm not sure how it managed to do that since the only thing the program is supposed to do is print "Hello World!" and exit. I can send you the HelloWorld binary I'm using, if you like.

Best,

Flora

To unsubscribe from this group and stop receiving emails from it, send an email to dynamorio-use...@googlegroups.com.
To post to this group, send email to dynamor...@googlegroups.com.

[Derek Bruening]

Look in the log dir's log.0.* file for the invalid opcode and non-int2b 0x21 messages and look at the code around them.  If you're less familiar with x86 assembly, please provide the log files and we can try to see why that code is off.  Maybe it's best to file an issue in our tracker at this point and attach the log files there.

To unsubscribe from this group and stop receiving emails from it, send an email to dynamorio-users+unsubscribe@googlegroups.com.
To post to this group, send email to dynamorio-users@googlegroups.com.

[Flora Xiao]

Hello! 

I have attached the log to this email. I created an issue here, as well: https://github.com/ivanfratric/winafl/issues/67.

Thank you!

Best,

Flora

[Felix Mößbauer]

Hi,

did you find a workaround for this issue? Even the most-recent DR (7.1.17963) is not able to run Dotnet CLR managed applications.

I already opened an issue, but I'm still waiting for a response: https://github.com/DynamoRIO/dynamorio/issues/3046

The errors seem to start a bit earlier (see log) and seems to be related to a messed-up heap:

d_r_dispatch: target = 0x00000181fb710000
Reached image entry point 0x00000181fb710000
WARNING: make_writable 0x00000000154e9000: param size 0x42000 vs. mbi size 0x2d000 base 0x00000000154e9000
make_writable: pc 0x00000000154e9000-0x0000000015516000, currently r--- committed
WARNING: make_writable 0x0000000015516000: param size 0x15000 vs. mbi size 0x9000 base 0x0000000015516000
make_writable: pc 0x0000000015516000-0x000000001551f000, currently r-x- committed
make_writable: pc 0x000000001551f000-0x000000001552b000, currently r--- committed
WARNING: make_unwritable 0x00000000154e9000: param size 0x42000 vs. mbi size 0x2d000 base 0x00000000154e9000
make_unwritable: pc 0x00000000154e9000-0x0000000015516000, currently rw-- committed
WARNING: make_unwritable 0x0000000015516000: param size 0x15000 vs. mbi size 0x9000 base 0x0000000015516000
make_unwritable: pc 0x0000000015516000-0x000000001551f000, currently rwx- committed
make_unwritable: pc 0x000000001551f000-0x000000001552b000, currently rw-- committed

interp: start_pc = 0x00000181fb710000
stack vs 0x00000181fb710000: official 0x000000424ae00000..0x000000424b200000, esp 0x000000424b1ff9d8
new shared vm area: 0x00000181fb710000-0x00000181fb711000 ---- unexpected vm area TestCS_CLR.exe
  0x00000181fb710000  4d 5a                pop    %rsp (%rsp)[8byte] -> %r10 %rsp
  0x00000181fb710002  90                   nop
  0x00000181fb710003  00 03                add    %al (%rbx)[1byte] -> (%rbx)[1byte]
  0x00000181fb710005  00 00                add    %al (%rax)[1byte] -> (%rax)[1byte]
  0x00000181fb710007  00 04 00             add    %al (%rax,%rax)[1byte] -> (%rax,%rax)[1byte]
  0x00000181fb71000a  00 00                add    %al (%rax)[1byte] -> (%rax)[1byte]
WARNING: make_writable 0x00000000154e9000: param size 0x42000 vs. mbi size 0x2d000 base 0x00000000154e9000
make_writable: pc 0x00000000154e9000-0x0000000015516000, currently r--- committed
WARNING: make_writable 0x0000000015516000: param size 0x15000 vs. mbi size 0x9000 base 0x0000000015516000
make_writable: pc 0x0000000015516000-0x000000001551f000, currently r-x- committed
make_writable: pc 0x000000001551f000-0x000000001552b000, currently r--- committed
WARNING: make_unwritable 0x00000000154e9000: param size 0x42000 vs. mbi size 0x2d000 base 0x00000000154e9000
make_unwritable: pc 0x00000000154e9000-0x0000000015516000, currently rw-- committed
WARNING: make_unwritable 0x0000000015516000: param size 0x15000 vs. mbi size 0x9000 base 0x0000000015516000
make_unwritable: pc 0x0000000015516000-0x000000001551f000, currently rwx- committed
make_unwritable: pc 0x000000001551f000-0x000000001552b000, currently rw-- committed
SYSLOG_WARNING: Invalid opcode encountered
Invalid opcode @0x00000181fb71000c: 0xff0027
decode: invalid instr at 0x00000181fb71000c
  0x00000181fb71000c  ff ff...??           <INVALID>

[.....]

Error decoding 0x00000181fb710041 == 0x1f
decode: invalid instr at 0x00000181fb710041

Attached you will find the complete log. I hope that helps.
The system is a windows 10-1083 x64 without AV. DR version is 7.1.17963-0

Best regards,
Felix

[Derek Bruening]

The log says that your app's image entry point contains invalid code and thus crashes.  I would suggest running it natively and examining the code.  Having the whole-process log file would help to see the address space discovery that DR did.  Is this memory read-only?  I recall that in the past .NET would hackily clobber the app's image entry to point to mscoree!_CorExeMain, though then we'd see a jump or something, not invalid code.

--

[Felix Mößbauer]

Hi Derek,

thanks for your quick response. Attached the requested information:

The faulting address is located in the managed module (addresses change a bit as obtained by a second native run)
DR Process log:
=> adding 0x00000181fb710000-0x00000181fb716000
    module <no name> segment [0x00000181fb710000,0x00000181fb716000] added

(Full log is attached)

WindBg log:
ModLoad: 000001f5`8fa00000 000001f5`8fa06000   TestCS_CLR.exe
ModLoad: 00007ff9`a4d90000 00007ff9`a4f71000   ntdll.dll
ModLoad: 00007ff9`8d920000 00007ff9`8d984000   C:\WINDOWS\SYSTEM32\MSCOREE.DLL

# Disassembly around entry point:
0:000> u $exentry
*** WARNING: Unable to verify checksum for TestCS_CLR.exe
TestCS_CLR!Main [C:\Users\felix\source\repos\TestCS_CLR\TestCS_CLR\Program.cs @ 13]:
000001f5`8fa00000 4d5a            pop     r10
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0x2):
000001f5`8fa00002 90              nop
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0x3):
000001f5`8fa00003 0003            add     byte ptr [rbx],al
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0x5):
000001f5`8fa00005 0000            add     byte ptr [rax],al
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0x7):
000001f5`8fa00007 000400          add     byte ptr [rax+rax],al
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0xa):
000001f5`8fa0000a 0000            add     byte ptr [rax],al
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0xc):
000001f5`8fa0000c ff              ???
TestCS_CLR!COM+_Entry_Point  (TestCS_CLR+0xd):
000001f5`8fa0000d ff00            inc     dword ptr [rax]

Dissasembly for TestCS_CLR:
See TestCS_CLR.asm (Note due to a privacy policy at Siemens, I replaced the user in the path by Z0000ABC).

If you need further information, please do not hesitate to ask.
I am willing to put time into the analysis and debugging of this issue.
Unfortunately, missing CLR support currently prevents us from migrating our tools from PIN to dynamorio.

Best regards,
Felix

[Felix Mößbauer]

Update:

The CLR indeed clobbers the entry point to mscoree!_CorExeMain. We do not see a jump here, as the entry point points to the MZ-Header of TestCS_CLR.exe. DynamoRIO then tries to decode the header to instructions, which obviously does not work. This should be fixable by checking if the module is managed and manually clobbering the entry point. However according to the load-order of the modules this has to be delayed until MSCOREE is loaded.

@Derek: Can you point me to the logic in DR where this loading is performed?

Best, Felix

Am Freitag, 7. Juli 2017 17:55:16 UTC+2 schrieb Flora Xiao:

[Derek Bruening]

It is probably best to continue detailed conversation in the issue https://github.com/DynamoRIO/dynamorio/issues/3046 rather than this list.

The summary here (details in the issue) is that without a client DR can correctly run these apps on win10 today by setting some options for earlier injection; with a client though requires a tweak to the late injection code.

--