php.exe crashes under Windows 10

[weltling]

Hi,

I work together with @pierrejoye on integrating DrMemory for PHP test suite on Windows. Currently I have an issue on Windows 10 with the DrMemory release from DrMemory-Windows-1.9.0-4.zip. The program being debugged just crashes with no meaningful backtrace.

Error message: Exception thrown at 0x73838FE1 in php.exe: 0xC0000005: Access violation reading location 0x77A1FFFB.

BT:

73838fe1() Unknown
[Frames below may be incorrect and/or missing]
[External Code]

The test files can be found here: http://windows.php.net/downloads/snaps/ostc/drmemory_test/ , the binary includes debug symbols and is linked with vc14 debug. Instead, any PHP release binary (and debug symbols can be used, available under http://windows.php.net/download/ . The test is run like

drmemory -- php.exe bug24312.php

The same command works well on Windows Server 2012. Also the binary itself doesn't crash when run without drmemory. The binary i've linked is built with vc14, but the same is reproduceable with vc11.

Thanks.

[derekbruening]

Please clarify: the title says "program being debugged", and the message "Exception thrown at 0x73838FE1 in php.exe" does not look like a message printed by Dr. Memory. It looks like an expected and handled access violation fault from Dr. Memory's callstack walk or something (drmemorylib is often loaded at 0x73..., and a fault there will either be handled or will be reported as an internal tool crash: it will not be forwarded to the app). Are you sure that's a fatal fault? Please clarify precisely what happens when run outside a debugger.

[weltling]

@derekbruening thanks for the quick response. The program, that popups in the VS debugger is php.exe, not DR. Memory. The exception text descends to VS, not do Dr. Memory.

Please note that the binaries i've linked are debug builds that include debug symbols. When I run just as it, even with application verifier enabled, it finishes with zero exit status. Also, when i run it on server 2012 with the same DrMemory release bins, it shows no issue.

So it seems to be solely win10 and the mentioned DrMemory release bins. If the binary being debugged were potentially crashing, from what were known for valgrind - it would just report an invalid "something" and exit normally. Or, if Dr. Memory would crash itself, i'd not expect debugger showing the program being debugged. So a bit lost about what happens :) At least debugger should show some correct BT and the program, and this seems to not to happen in this constellation.

Please give a tip what could I do to clarify the situation on my side.

Thanks.

[derekbruening]

If you are on win10 TH2 1511 (a major update which should really be called Windows 11), the 1.9.0-4 release does not work there. Xref #1826. Please try a post-fix build such as https://build.chromium.org/p/client.drmemory/builds/DrMemory-Windows-1.9.16822-0x6d06080-sfx.exe

The confusion stems from the title "program being debugged" -- that sounds like the problem only occurs when you run Dr. Memory on your target application inside a debugger such as windbg or the VS debugger. Is that not the case?

[weltling]

Yeah, that's 1511 (os build 10586.63) ... With the build you've linked this is the output i've got

Dr. Memory version 1.9.16822 build 114319488 built on Jan 21 2016 22:25:03
Dr. Memory results for pid 15552: "php.exe"
Application cmdline: "Debug\php.exe ext\standard\tests\strings\bug24312.php"
Recorded 116 suppression(s) from default E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\bin\suppress-default.txt

Error #1: UNADDRESSABLE ACCESS: executing 0x08920000-0x08920005 5 byte(s)
# 0 <not in a module> (0x08920000)
Note: @0:00:00.934 in thread 1564
Note: instruction: push   $0x77a98e30 %esp -> %esp 0xfffffffc(%esp)

Error #2: UNADDRESSABLE ACCESS: executing 0x08920005-0x08920006 1 byte(s)
# 0 <not in a module> (0x08920005)
Note: @0:00:00.950 in thread 1564
Note: instruction: pushf  %esp -> %esp 0xfffffffc(%esp)

Error #3: UNADDRESSABLE ACCESS: executing 0x08920006-0x08920007 1 byte(s)
# 0 <not in a module> (0x08920006)
Note: @0:00:00.950 in thread 1564
Note: instruction: pusha  %esp %eax %ebx %ecx %edx %ebp %esi %edi -> %esp 0xffffffe0(%esp)

Error #4: UNADDRESSABLE ACCESS: executing 0x08920007-0x0892000c 5 byte(s)
# 0 <not in a module> (0x08920007)
Note: @0:00:00.950 in thread 1564
Note: instruction: push   $0x08920014 %esp -> %esp 0xfffffffc(%esp)

Error #5: UNADDRESSABLE ACCESS: executing 0x0892000c-0x08920011 5 byte(s)
# 0 <not in a module> (0x0892000c)
Note: @0:00:00.950 in thread 1564
Note: instruction: call   $0x7612a840 %esp -> %esp 0xfffffffc(%esp)

===========================================================================
FINAL SUMMARY:

DUPLICATE ERROR COUNTS:

SUPPRESSIONS USED:

ERRORS FOUND:
      5 unique,     5 total unaddressable access(es)
      0 unique,     0 total uninitialized access(es)
      0 unique,     0 total invalid heap argument(s)
      0 unique,     0 total GDI usage error(s)
      0 unique,     0 total handle leak(s)
      0 unique,     0 total warning(s)
      0 unique,     0 total,      0 byte(s) of leak(s)
      0 unique,     0 total,      0 byte(s) of possible leak(s)
ERRORS IGNORED:
     11 potential error(s) (suspected false positives)
         (details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.15552.000\potential_errors.txt)
     27 potential leak(s) (suspected false positives)
         (details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.15552.000\potential_errors.txt)
     12 unique,    12 total,  10155 byte(s) of still-reachable allocation(s)
         (re-run with "-show_reachable" for details)
Details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.15552.000\results.txt

So this seems way better than 1.9.0-4, despite it doesn't show the backtraces. But at least no crash and so.

With 1.9.0-4 - nope, I wasn't running drmemory in a debugger, just normally in a console like drmemory -- program.exe. With 1.9.0-4, a prompt asking whether to launch the debugger does popup, which shows things i've described.

Thanks.

[weltling]

What i have to add is that php.exe with the provided test case under that win10 version doesn't crash, when no Dr. Memory is used. Also things like Application Verifier don't show anything.

Thanks.

[derekbruening]

So the only problem left is the series of complaints (in the form of error reports) about the code at 0x08920000? Can you identify whose code that is from the addresses involved there in the call, etc.? It's some kind of generated code related to hooks, perhaps?

[weltling]

Huh, today I run the same command with the same binaries, and have clean output.

Dr. Memory version 1.9.16822 build 114319488 built on Jan 21 2016 22:25:03
Dr. Memory results for pid 7380: "php.exe"
Application cmdline: "Debug\php.exe ext\standard\tests\strings\bug24312.php"
Recorded 116 suppression(s) from default E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\bin\suppress-default.txt

===========================================================================
FINAL SUMMARY:

DUPLICATE ERROR COUNTS:

SUPPRESSIONS USED:

NO ERRORS FOUND:
      0 unique,     0 total unaddressable access(es)
      0 unique,     0 total uninitialized access(es)
      0 unique,     0 total invalid heap argument(s)
      0 unique,     0 total GDI usage error(s)
      0 unique,     0 total handle leak(s)
      0 unique,     0 total warning(s)
      0 unique,     0 total,      0 byte(s) of leak(s)
      0 unique,     0 total,      0 byte(s) of possible leak(s)
ERRORS IGNORED:
     11 potential error(s) (suspected false positives)
         (details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.7380.000\potential_errors.txt)
     27 potential leak(s) (suspected false positives)
         (details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.7380.000\potential_errors.txt)
     12 unique,    12 total,  10155 byte(s) of still-reachable allocation(s)
         (re-run with "-show_reachable" for details)
Details: E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.7380.000\results.txt

Cannot explain why. The same binaries both Dr. Memory and PHP (both binary and script), what only changed is that i closed my laptop's lid yesterday and opened it today :) Any suggestion to check what happened? Maybe things like some reboot, suspend, etc. could affect the way it works?

With your question about dynamic code - the only place in PHP with creation of dynamic code is usage of JIT in the PCRE library. But in this particular run it is not involved. It's probably hard to catch what is exactly on that address because of ASLR. At least today, when i check the running binary, VMMap shows that there's no region in the heap occupied where 0x08920000 could belong to.

Thanks.

[derekbruening]

It may be third-party invasive software using generated code as part of its hooks of Windows API routines (common for security software or malware or even some mouse software, etc.). We log the libraries loaded. Look for "module load event" in E:\local_programs\DrMemory-Windows-1.9.16822-0x6d06080\drmemory\logs\DrMemory-php.exe.15552.000\global.15552.log.

In general, when reproducing, you would run with "-pause_at_error" and then use Process Explorer or a debugger to examine the libraries and what the code at those "UNADDRESSABLE ACCESS: executing ..." addresses is doing and who it belongs to.

The fact that Dr. Memory thinks it is unaddressable memory could mean that it is allocated from another process (hence the hook theory, but usually these hooks are put in early enough that we consider their memory legitimate), that it's a bug where it's freed memory or beyond the top of a stack, or possibly that it's legitimate and a bug in Dr. Memory's memory tracking (maybe some new Windows 10 behavior we missed), so we are curious to find out more about it.

[weltling]

Hi, today it's reproducable again.

Here is the stack the process explorer shows when paused on error:

ntdll.dll!ZwRaiseHardError+0x14
wow64.dll!Wow64ValidateUserCallTarget+0xd0d5
wow64.dll!Wow64SystemServiceEx+0x155
wow64cpu.dll!TurboDispatchJumpAddressEnd+0xb
wow64.dll!Wow64LdrpInitialize+0x212
wow64.dll!Wow64LdrpInitialize+0x120
ntdll.dll!EtwEventProviderEnabled+0x1800
ntdll.dll!memset+0x15f25
ntdll.dll!LdrInitializeThunk+0xe

PHP is loaded at 0x8c000. But i currently cannot find the way to view all the addresses through procexp. Procexp seems only to allows to see the start addresses and addresses from the stack, but not the full view ;( Unfortunately i stick at this point.

However, as you've pointed me to the global log, i've looked inside. There is something attracting attention

module load event: "ConEmuHk.dll" 0x7e110000-0x7e183000 modid: 26 C:\Program Files\ConEmu\ConEmu\ConEmuHk.dll
WARNING: unable to load symbols for C:\WINDOWS\SYSTEM32\KERNELBASE.dll
WARNING: unable to load symbols for C:\Program Files\ConEmu\ConEmu\ConEmuHk.dll

module load event: "AppCore.dll" 0x76740000-0x7674c000 modid: 27 C:\Windows\SysWOW64\kernel.appcore.dll
WARNING: unable to load symbols for C:\WINDOWS\SYSTEM32\ucrtbased.dll

Potential Error #1: INVALID HEAP ARGUMENT to free 0x08b45f68
# 0 replace_free    [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706] (0x73820370 <drmemorylib.dll+0x20370>) modid:7
# 1 ucrtbased.dll!unlock_locales (0x089f8014 <ucrtbased.dll+0x98014>) modid:2
# 2 ntdll.dll!RtlProcessFlsData (0x77a709b8 <ntdll.dll+0x509b8>) modid:25
# 3 ntdll.dll!LdrShutdownProcess (0x77a743c3 <ntdll.dll+0x543c3>) modid:25
# 4 ntdll.dll!RtlExitUserProcess (0x77a74926 <ntdll.dll+0x54926>) modid:25
# 5 KERNEL32.dll!ExitProcess  (0x76137b43 <KERNEL32.dll+0x27b43>) modid:12
# 6 ConEmuHk.dll!RequestLocalServer (0x7e1359d9 <ConEmuHk.dll+0x259d9>) modid:26
# 7 ucrtbased.dll!wassert       (0x08a17af8 <ucrtbased.dll+0xb7af8>) modid:2
# 8 ucrtbased.dll!wassert       (0x08a17a8f <ucrtbased.dll+0xb7a8f>) modid:2
# 9 ucrtbased.dll!exit          (0x08a17d62 <ucrtbased.dll+0xb7d62>) modid:2
#10 main    [c:\php-sdk\phpmaster\vc14\x86\php-src\sapi\cli\php_cli.c:1374] (0x008d71b8 <php.exe+0x171b8>) modid:1
Note: @0:35:02.090 in thread 10108
Note: next higher malloc: 0x08b46640-0x08b47264
    error end

I usually work in Conemu. Now, where it points to PHP, it's a place where a setjmp call gets prepared. Now, it looks like a mix of any possible errors :) Well, setjmp itself is used in PHP quite often, but it actually never crash (or only in very bad cases). It's unlikely there were something to report about it. But the presense of Conemu in the BT looks very suspicious to me, could it be that it injects something into a process?

Now i repeated the same test about 10 times using pure cmd and there are only clean runs. I'll continue observing this next days.

Thanks.

[pierrejoye]

Conemu doing its own business with the io and console, I would suggest to
runthe test using pure cmd only.

It could be a conemu bug as well but we will need to investigate that later
:)
On Jan 28, 2016 5:50 PM, "Anatol Belski" [email protected] wrote:

Hi, today it's reproducable again.

Here is the stack the process explorer shows when paused on error:

ntdll.dll!ZwRaiseHardError+0x14
wow64.dll!Wow64ValidateUserCallTarget+0xd0d5
wow64.dll!Wow64SystemServiceEx+0x155
wow64cpu.dll!TurboDispatchJumpAddressEnd+0xb
wow64.dll!Wow64LdrpInitialize+0x212
wow64.dll!Wow64LdrpInitialize+0x120
ntdll.dll!EtwEventProviderEnabled+0x1800
ntdll.dll!memset+0x15f25
ntdll.dll!LdrInitializeThunk+0xe

PHP is loaded at 0x8c000. But i currently cannot find the way to view all
the addresses through procexp. Procexp seems only to allows to see the
start addresses and addresses from the stack, but not the full view ;(
Unfortunately i stick at this point.

However, as you've pointed me to the global log, i've looked inside. There
is something attracting attention

module load event: "ConEmuHk.dll" 0x7e110000-0x7e183000 modid: 26 C:\Program Files\ConEmu\ConEmu\ConEmuHk.dll
WARNING: unable to load symbols for C:\WINDOWS\SYSTEM32\KERNELBASE.dll
WARNING: unable to load symbols for C:\Program Files\ConEmu\ConEmu\ConEmuHk.dll

module load event: "AppCore.dll" 0x76740000-0x7674c000 modid: 27 C:\Windows\SysWOW64\kernel.appcore.dll
WARNING: unable to load symbols for C:\WINDOWS\SYSTEM32\ucrtbased.dll

Potential Error #1: INVALID HEAP ARGUMENT to free 0x08b45f68

0 replace_free [e:\b\build\slave\win-builder\drmemory\common\alloc_replace.c:2706](0x73820370 <drmemorylib.dll+0x20370) modid:7

1 ucrtbased.dll!unlock_locales (0x089f8014 <ucrtbased.dll+0x98014>) modid:2

2 ntdll.dll!RtlProcessFlsData (0x77a709b8 <ntdll.dll+0x509b8>) modid:25

3 ntdll.dll!LdrShutdownProcess (0x77a743c3 <ntdll.dll+0x543c3>) modid:25

4 ntdll.dll!RtlExitUserProcess (0x77a74926 <ntdll.dll+0x54926>) modid:25

5 KERNEL32.dll!ExitProcess (0x76137b43 <KERNEL32.dll+0x27b43>) modid:12

6 ConEmuHk.dll!RequestLocalServer (0x7e1359d9 <ConEmuHk.dll+0x259d9>) modid:26

7 ucrtbased.dll!wassert (0x08a17af8 <ucrtbased.dll+0xb7af8>) modid:2

8 ucrtbased.dll!wassert (0x08a17a8f <ucrtbased.dll+0xb7a8f>) modid:2

9 ucrtbased.dll!exit (0x08a17d62 <ucrtbased.dll+0xb7d62>) modid:2

#10 main [c:\php-sdk\phpmaster\vc14\x86\php-src\sapi\cli\php_cli.c:1374](0x008d71b8 <php.exe+0x171b8) modid:1
Note: @0:35:02.090 in thread 10108
Note: next higher malloc: 0x08b46640-0x08b47264
error end

I usually work in Conemu. Now, where it points to PHP, it's a place where
a setjmp call gets prepared. Now, it looks like a mix of any possible
errors :) Well, setjmp itself is used in PHP quite often, but it actually
never crash (or only in very bad cases). It's unlikely there were something
to report about it. But the presense of Conemu in the BT looks very
suspicious to me, could it be that it injects something into a process?

Now i repeated the same test about 10 times using pure cmd and there are
only clean runs. I'll continue observing this next days.

Thanks.

—
Reply to this email directly or view it on GitHub
#1854 (comment)
.

[derekbruening]

ConEmu is relatively invasive: it injects a library into all processes you run in its shell and inserts many hooks. Xref DynamoRIO/dynamorio#1597. I'm curious about how the unaddressable memory was allocated as I haven't seen those errors in prior ConEmu testing. In any case, I'm going to close this issue and if the unaddrs show up again and we get more info on them we can open a new issue.

[weltling]

@pierrejoye yeah, that's my conclusion as well, pure cmd runs clean with 1.9.16822, now after 8 hours. ConEmu appearing in the trace where it has nothing to do with is a big sign.

@derekbruening many thanks for supporting by this case. ConEmu issues are out of this tickets scope anyway. They only provide beta/alpha and (i guess :) also no one fetches debug symbols for it.

I'll be verifying this next days and will report back, if the experience is different. But now, 8 hours later - cmd shows no issues while conemu still shows the same crash. I haven't close my laptop's lid yet :)

Cheers.

[weltling]

@derekbruening ah, i'm runnnig a x64 conemu on x64 win10, could it make some diff?

Thanks.