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

get_process_exe on windows is_python_bin check #40

Closed
whyzdev opened this issue Sep 20, 2018 · 4 comments
Closed

get_process_exe on windows is_python_bin check #40

whyzdev opened this issue Sep 20, 2018 · 4 comments

Comments

@whyzdev
Copy link

whyzdev commented Sep 20, 2018 •
edited
Loading

Hi,

I am still wondering how to deal with "Couldn't find binary in virtual memory maps". In this case the python executable is moved or renamed on Windows. This happens to me with the latest 0.1.6 after #34.

It looks like Windows somehow caches the old path such as "c:\foo\bar\Python26\python.exe" on Windows 2008 R2. (I know, python26 and Windows 2008 is old, but may be unrelated to the issue here I think.)
It was moved to c:\foo\bar.moved. Then the target process started. Ran py-spy on the target pid.
It seems that utils::get_process_exe and QueryFullProcessImageNameW return the old path "c:\foo\bar" not "c:\foo\bar.moved"

I searched and ran various utilities to find c:\boo\bar and why. Try clear some memory caches and restarted some windows services etc, nothing works. Logout doesn't help.
Only need to restart the machine. Then it found c:\boo\bar.renamed, and worked.

To work aroud, I can change not to move/rename the deployment. But because the "freezing" process is rare, hard to reproduce.
It's difficult to miss the py-spy opportunity and change the process, restart, and reproduce. I also don't have the pdb for the old python26 distribution in order to get the stack trace. So really need to get help by using py-spy.

Also try build a patch and bypass "is_python_bin" check. But it needs Rust on Windows. Have not found scripts eg. for travis, and found no quick Docker images. Is there instruction for building on Windows?

Also wonder if py-spy can analyze a full or mini dump on Windows or core dump on Linux/Mac, rather than monitoring on a live process. Like to this in a separate issue.

Thanks in advance for your help and advice. py-spy is awesome!

Here were the steps:

c:\foo\bar\Python26 was installed.

It was moved to c:\foo\bar.moved\Python26

Then started the target

c:\foo\bar.moved\Python26\python
>>> import os
>>> os.getpid()
4888
>>>

In another admin window cmd:

set RUST_LOG=info
c:\foo\bar.moved\Python26\scripts\py-spy --pid 4888

py-spy logs:

c:\foo\bar.moved\Python26>Scripts\py-spy.exe --pid 4888
INFO 2018-09-19T15:23:58Z: py_spy: Command line args: ArgMatches { args: {"duration": MatchedArg { occurs: 0, indices: [4], vals: ["2"] }, "rate": MatchedArg { occurs: 0
: ["200"] }, "pid": MatchedArg { occurs: 1, indices: [2], vals: ["4888"] }}, subcommand: None, usage: Some("USAGE:\n    py-spy.exe [FLAGS] [OPTIONS] --pid <pid> [python_p
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Found process binary @ 'c:\foo\bar\Python26\python.exe'
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Got virtual memory maps from pid 4888:
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001d000000-000000001d00b000 rwx c:\foo\bar.moved\Python26\python.exe
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077190000-000000007733a000 rwx C:\Windows\SYSTEM32\ntdll.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000076f70000-000000007708f000 rwx C:\Windows\system32\kernel32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd250000-000007fefd2ba000 rwx C:\Windows\system32\KERNELBASE.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefced0000-000007fefcf50000 rwx C:\Windows\system32\ctiuser.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd890000-000007fefd8dd000 rwx C:\Windows\system32\WS2_32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd950000-000007fefd9ef000 rwx C:\Windows\system32\msvcrt.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd9f0000-000007fefdb1d000 rwx C:\Windows\system32\RPCRT4.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff040000-000007feff048000 rwx C:\Windows\system32\NSI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077360000-0000000077367000 rwx C:\Windows\system32\PSAPI.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefce20000-000007fefce29000 rwx C:\Windows\system32\FLTLIB.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077090000-000000007718a000 rwx C:\Windows\system32\USER32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd8e0000-000007fefd947000 rwx C:\Windows\system32\GDI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff030000-000007feff03e000 rwx C:\Windows\system32\LPK.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd380000-000007fefd44b000 rwx C:\Windows\system32\USP10.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff3c0000-000007feff49b000 rwx C:\Windows\system32\ADVAPI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdfd0000-000007fefdfef000 rwx C:\Windows\SYSTEM32\sechost.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001e000000-000000001e2b4000 rwx c:\foo\bar.moved\Python26\python26.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefe2a0000-000007feff02a000 rwx C:\Windows\system32\SHELL32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdb20000-000007fefdb91000 rwx C:\Windows\system32\SHLWAPI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000072d90000-0000000072e33000 rwx C:\Windows\WinSxS\amd64_microsoft.vc90.crt_1fc8b3b9a1e18e3b_9.0.30729.6161_none
VCR90.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdba0000-000007fefdbce000 rwx C:\Windows\system32\IMM32.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff210000-000007feff319000 rwx C:\Windows\system32\MSCTF.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Failed to connect to process, retrying. Error: Couldn't find binary in virtual memory maps
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Found process binary @ 'c:\foo\bar\Python26\python.exe'
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Got virtual memory maps from pid 4888:
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001d000000-000000001d00b000 rwx c:\foo\bar.moved\Python26\python.exe
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077190000-000000007733a000 rwx C:\Windows\SYSTEM32\ntdll.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000076f70000-000000007708f000 rwx C:\Windows\system32\kernel32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd250000-000007fefd2ba000 rwx C:\Windows\system32\KERNELBASE.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefced0000-000007fefcf50000 rwx C:\Windows\system32\ctiuser.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd890000-000007fefd8dd000 rwx C:\Windows\system32\WS2_32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd950000-000007fefd9ef000 rwx C:\Windows\system32\msvcrt.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd9f0000-000007fefdb1d000 rwx C:\Windows\system32\RPCRT4.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff040000-000007feff048000 rwx C:\Windows\system32\NSI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077360000-0000000077367000 rwx C:\Windows\system32\PSAPI.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefce20000-000007fefce29000 rwx C:\Windows\system32\FLTLIB.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077090000-000000007718a000 rwx C:\Windows\system32\USER32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd8e0000-000007fefd947000 rwx C:\Windows\system32\GDI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff030000-000007feff03e000 rwx C:\Windows\system32\LPK.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd380000-000007fefd44b000 rwx C:\Windows\system32\USP10.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff3c0000-000007feff49b000 rwx C:\Windows\system32\ADVAPI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdfd0000-000007fefdfef000 rwx C:\Windows\SYSTEM32\sechost.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001e000000-000000001e2b4000 rwx c:\foo\bar.moved\Python26\python26.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefe2a0000-000007feff02a000 rwx C:\Windows\system32\SHELL32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdb20000-000007fefdb91000 rwx C:\Windows\system32\SHLWAPI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000072d90000-0000000072e33000 rwx C:\Windows\WinSxS\amd64_microsoft.vc90.crt_1fc8b3b9a1e18e3b_9.0.30729.6161_none
VCR90.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdba0000-000007fefdbce000 rwx C:\Windows\system32\IMM32.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff210000-000007feff319000 rwx C:\Windows\system32\MSCTF.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Failed to connect to process, retrying. Error: Couldn't find binary in virtual memory maps
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Found process binary @ 'c:\foo\bar\Python26\python.exe'
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: Got virtual memory maps from pid 4888:
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001d000000-000000001d00b000 rwx c:\foo\bar.moved\Python26\python.exe
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077190000-000000007733a000 rwx C:\Windows\SYSTEM32\ntdll.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000076f70000-000000007708f000 rwx C:\Windows\system32\kernel32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd250000-000007fefd2ba000 rwx C:\Windows\system32\KERNELBASE.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefced0000-000007fefcf50000 rwx C:\Windows\system32\ctiuser.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd890000-000007fefd8dd000 rwx C:\Windows\system32\WS2_32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd950000-000007fefd9ef000 rwx C:\Windows\system32\msvcrt.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd9f0000-000007fefdb1d000 rwx C:\Windows\system32\RPCRT4.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff040000-000007feff048000 rwx C:\Windows\system32\NSI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077360000-0000000077367000 rwx C:\Windows\system32\PSAPI.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefce20000-000007fefce29000 rwx C:\Windows\system32\FLTLIB.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000077090000-000000007718a000 rwx C:\Windows\system32\USER32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd8e0000-000007fefd947000 rwx C:\Windows\system32\GDI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff030000-000007feff03e000 rwx C:\Windows\system32\LPK.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefd380000-000007fefd44b000 rwx C:\Windows\system32\USP10.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff3c0000-000007feff49b000 rwx C:\Windows\system32\ADVAPI32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdfd0000-000007fefdfef000 rwx C:\Windows\SYSTEM32\sechost.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000000001e000000-000000001e2b4000 rwx c:\foo\bar.moved\Python26\python26.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefe2a0000-000007feff02a000 rwx C:\Windows\system32\SHELL32.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdb20000-000007fefdb91000 rwx C:\Windows\system32\SHLWAPI.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 0000000072d90000-0000000072e33000 rwx C:\Windows\WinSxS\amd64_microsoft.vc90.crt_1fc8b3b9a1e18e3b_9.0.30729.6161_none
VCR90.dll
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007fefdba0000-000007fefdbce000 rwx C:\Windows\system32\IMM32.DLL
INFO 2018-09-19T15:23:58Z: py_spy::python_spy: map: 000007feff210000-000007feff319000 rwx C:\Windows\system32\MSCTF.dll
Error: Couldn't find binary in virtual memory maps

c:\foo\bar.moved\Python26>
@whyzdev whyzdev mentioned this issue Sep 20, 2018
Closed
@benfred
Copy link
Owner

benfred commented Sep 20, 2018

Thanks for the detailed bug report! This shouldn't be all that hard to handle, it's just not something that I've tested (the earliest version of windows I've tested with is windows7, and I'm not sure if this problem will also exist there).

I think the best solution here is to fall back to matching the filename (python.exe or similar) if we can't find an exact match on the process exe. The exact match should work most of the time, and it lets us support embedded python enviroments like uwsgi etc. We can't just skip matching against the virtual memory maps because we need the memory offset that it's mapped into to handle ASLR (which probably doesn't apply to windows 2008, but still is important in general ).

The CI script for windows is here: https://github.com/benfred/py-spy/blob/master/appveyor.yml - this does more than you strictly need to just build, installing rust and then going 'cargo build --release' should be enough to get building.

I will probably have a fix for this tomorrow -

benfred added a commit that referenced this issue Sep 22, 2018
@benfred
fallback when failing to find exe in memory maps
6ccee1f 
If we failed to find the executable in the virtual memory maps, just take the
first file we find. Sometimes on windows get_process_exe returns stale info =(
#40
and on all operating systems I've tried, the exe is the first region in the maps
@benfred
Copy link
Owner

benfred commented Sep 22, 2018

I didn't manage to reproduce this, but I believe the last commit there will fix this issue.

@benfred
Copy link
Owner

benfred commented Sep 22, 2018

fix is in 0.1.8

@benfred benfred closed this as completed Sep 22, 2018
@whyzdev
Copy link
Author

whyzdev commented Sep 23, 2018 •
edited
Loading

Thanks very much. 0.1.8 helps. Given the example above, got the fallback message in log. But then it seems trying to open the old path (c:\foo\bar\python26\python.exe) and failed. Copied c:\foo\bar.moved\python26 back to old c:\foo\bar\python26, and ran py-spy again. Then it works!

WARN 2018-09-23T03:57:43Z: py_spy::python_spy: Failed to find 'c:\foo\bar\python26\python.exe' in virtual memory maps, falling back to first map region
Error: The system cannot find the path specified. (os error 3)

I will look more later. And maybe just copy python.exe works rather than the full python dir.

Btw, tried to build Rust nightly, Python 2.6/2.7, VC for python 2.7 on windows 10 vm. It was mostly not hard and smooth, but got stuck on proc-macro2, which seems to be an rust/dll issue something to do with msvcr90.dll. Have not made it work yet. Maybe need visual studio 2015 which is quite heavy.

   Compiling proc-macro2 v0.4.19
error: failed to run custom build command for `proc-macro2 v0.4.19`
process didn't exit successfully: `C:\dev\py-spy\target\release\build\proc-macro2-4ed2eeee3868e33a\build-script-build` (exit code: 3221225781)

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@benfred @whyzdev