[Bug 34865] 64-bit mingw toolchain from Rtools fails to execute (cygwin 1.7.15-1, queued user APC not executed for signal handling)
wine-bugs at winehq.org
wine-bugs at winehq.org
Sun Nov 10 18:04:54 CST 2013
http://bugs.winehq.org/show_bug.cgi?id=34865
Anastasius Focht <focht at gmx.net> changed:
What |Removed |Added
----------------------------------------------------------------------------
Keywords| |download, win64
Status|UNCONFIRMED |NEW
URL| |http://cran.rstudio.com/bin
| |/windows/base/R-3.0.2-win.e
| |xe
CC| |focht at gmx.net
Summary|Can't execute mingw |64-bit mingw toolchain from
|toolchain provided by |Rtools fails to execute
|Rtools |(cygwin 1.7.15-1, queued
| |user APC not executed for
| |signal handling)
Ever Confirmed|0 |1
--- Comment #1 from Anastasius Focht <focht at gmx.net> 2013-11-10 18:04:54 CST ---
Hello folks,
confirming.
Run it with 'wineconsole' to avoid messed up tty and see more diagnostics ...
You initial analysis seems somewhat right, it's about signal delivery between
processes through named pipes (this is what cygwin uses).
Actually the real problem seems to be delivery on the _same_ process :-)
Getting trace log:
--- snip ---
$ pwd
/home/focht/.wine-rtools/drive_c/Program Files/R/R-3.0.2/bin/x64
$ WINEDEBUG=+tid,+seh,+loaddll,+process,+relay wine ./R.exe --verbose
--vanilla CMD INSTALL "C:\\kimisc-master" --no-multiarch -d
...
002c:Call KERNEL32.CreateProcessW(0062dd30
L"C:\\Rtools\\bin\\make.exe",00220692 L"C:\\Rtools\\bin\\make.exe -f
\"Makevars.win\" -f \"C:/PROG~FBU/R/R-3_~NRD.2/etc/x64/Makeconf\" -f
\"C:/PROG~FBU/R/R-3_~NRD.2/share/make/winshlib.mk\"
SHLIB_LDFLAGS='$(SHLIB_CXXLDFLAGS)' SHLIB_LD='$(SHLIB_CXXLD)'
SHLIB=\"kimisc.dll\" DEBUG=T WIN=64 TCLBIN=64 OBJECTS=\"rcpp_hello_world.o
RcppExports.o\"",00000000,00000000,00000001,04000020,00000000,00000000,0062fd30,0062fd74)
ret=6110d206
...
002c:trace:process:create_process_impl starting L"C:\\Rtools\\bin\\make.exe" as
Win32 binary (0x400000-0x425000)
...
002e:Call KERNEL32.__wine_kernel_init() ret=7bc5968d
...
002c:trace:process:create_process_impl started process pid 002d tid 002e
002c:Ret KERNEL32.CreateProcessW() retval=00000001 ret=6110d206
...
--- snip ---
Child 'make' (pid=0x2e) creates name pipe and event creation for signal
communication:
Pipe handle to observe: 0x0000009c
(secondary) signal thread though user APC
--- snip ---
002e:Call KERNEL32.CreateNamedPipeA(0062f78c
"\\\\.\\pipe\\cygwin-2b6b078c083f2559-45-",00000001,00000004,00000001,000000a4,000000a4,00000000,0062f8d0)
ret=610b1b29
002e:Ret KERNEL32.CreateNamedPipeA() retval=00000098 ret=610b1b29
002e:Call KERNEL32.CreateFileA(0062f78c
"\\\\.\\pipe\\cygwin-2b6b078c083f2559-45-",40000080,00000000,0062f8d0,00000003,00000000,00000000)
ret=610b1a11
002e:Ret KERNEL32.CreateFileA() retval=0000009c ret=610b1a11
002e:Call ntdll.NtCreateEvent(0062f62c,001f0003,0062f60c,00000001,00000000)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
002e:Call KERNEL32.QueueUserAPC(61003db0,fffffffe,61188380) ret=610daa42
002e:Ret KERNEL32.QueueUserAPC() retval=00000001 ret=610daa42
002e:Call KERNEL32.TlsAlloc() ret=6107f46c
002e:Ret KERNEL32.TlsAlloc() retval=00000000 ret=6107f46c
002e:Ret PE DLL (proc=0x6107f390,module=0x61000000
L"cygwin1.dll",reason=PROCESS_ATTACH,res=0x1) retval=1
002e:Starting process L"C:\\Rtools\\bin\\make.exe" (entryproc=0x401000)
002e:Call KERNEL32.GetModuleHandleA(00000000) ret=0041edba
002e:Ret KERNEL32.GetModuleHandleA() retval=00400000 ret=0041edba
002e:Call ntdll.NtCreateEvent(0062a864,001f0003,0062a844,00000001,00000000)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
--- snip ---
--- snip ---
002e:Call
ntdll.NtWriteFile(000000b8,00000000,00000000,00000000,00629360,20042918,000000f3,611d0210,00000000)
ret=6103442c
g++ -m64 -I"C:/PROG~FBU/R/R-3_~NRD.2/include" -DNDEBUG -I"C:/Program
Files/R/R-3.0.2/library/Rcpp/include"
-I"d:/RCompile/CRANpkg/extralibs64/local/include" -O2 -Wall -gdwarf-2
-mtune=core2 -c rcpp_hello_world.cpp -o rcpp_hello_world.o
002e:Ret ntdll.NtWriteFile() retval=00000000 ret=6103442c
002e:Call ntdll.NtCreateEvent(00629494,001f0003,00629474,00000001,00000000)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
...
002e:Call KERNEL32.CreateNamedPipeA(00629824
"\\\\.\\pipe\\cygwin-2b6b078c083f2559-45-pipe-0x1",40000001,00000004,00000001,00010000,00010000,00000000,6119a7e0)
ret=610b1b29
002e:Ret KERNEL32.CreateNamedPipeA() retval=000000e0 ret=610b1b29
002e:Call KERNEL32.CreateFileA(00629824
"\\\\.\\pipe\\cygwin-2b6b078c083f2559-45-pipe-0x1",40000080,00000000,6119a7e0,00000003,40000000,00000000)
ret=610b1a11
002e:Ret KERNEL32.CreateFileA() retval=000000e8 ret=610b1a11
002e:Call
KERNEL32.DuplicateHandle(ffffffff,00000000,ffffffff,61279f28,00000000,00000001,00000002)
ret=6117c75e
002e:Ret KERNEL32.DuplicateHandle() retval=00000000 ret=6117c75e
002e:Call
KERNEL32.DuplicateHandle(ffffffff,00000000,ffffffff,6127a208,00000000,00000001,00000002)
ret=6117c75e
002e:Ret KERNEL32.DuplicateHandle() retval=00000000 ret=6117c75e
002e:Call ntdll.NtCreateEvent(00629684,001f0003,00629664,00000000,00000001)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
002e:Call ntdll.NtCreateEvent(00629684,001f0003,00629664,00000000,00000001)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
...
002e:Call KERNEL32.SetEvent(000000f0) ret=610389b6
002e:Ret KERNEL32.SetEvent() retval=00000001 ret=610389b6
002e:Call KERNEL32.CloseHandle(000000f0) ret=610389c4
002e:Ret KERNEL32.CloseHandle() retval=00000001 ret=610389c4
002e:Call KERNEL32.CloseHandle(000000e8) ret=61033f9a
002e:Ret KERNEL32.CloseHandle() retval=00000001 ret=61033f9a
002e:Call KERNEL32.SetHandleInformation(000000e0,00000001,00000000)
ret=61033d58
002e:Ret KERNEL32.SetHandleInformation() retval=00000001 ret=61033d58
002e:Call ntdll.NtCreateEvent(00629664,001f0003,00629644,00000001,00000000)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
002e:Call
KERNEL32.DuplicateHandle(ffffffff,ffffffff,ffffffff,00629974,00000000,00000001,00000002)
ret=610dc0f8
002e:Ret KERNEL32.DuplicateHandle() retval=00000001 ret=610dc0f8
002e:Call ntdll.NtCreateEvent(006294d4,001f0003,006294b4,00000001,00000000)
ret=6107f9f4
002e:Ret ntdll.NtCreateEvent() retval=00000000 ret=6107f9f4
002e:Call KERNEL32.WriteFile(0000009c,00629778,000000a4,0062981c,00000000)
ret=610daef0
002e:Ret KERNEL32.WriteFile() retval=00000001 ret=610daef0
002e:Call KERNEL32.WaitForSingleObject(000000f4,0000ea60) ret=610db059
002a:Ret KERNEL32.WaitForSingleObject() retval=00000102 ret=6c71a3b1
...
002e:Call KERNEL32.CloseHandle(000000f4) ret=610db06b
002e:Ret KERNEL32.CloseHandle() retval=00000001 ret=610db06b
...
002e:Call KERNEL32.GetStdHandle(fffffff4) ret=610e221d
002e:Ret KERNEL32.GetStdHandle() retval=000000bc ret=610e221d
002e:Call KERNEL32.WriteFile(000000bc,00621794,00000068,00629794,00000000)
ret=610e2245
60014615 [main] make 45 sig_send: wait for sig_complete event failed, signal
-40, rc 258, Win32 error 0
002e:Ret KERNEL32.WriteFile() retval=00000001 ret=610e2245
...
--- snip ---
Write a "signal" packet to pipe 0x0000009c and wait for event 0x000000f4 to be
signaled.
The event 0x000000f4 ought to be signaled from the other end of pipe - either
by another process or from same process using a signal handling thread.
Well, guess ... cygwin queues a user APC for that.
Main thread waits 60 sec for 0x000000f4 to become signaled and runs into
WAIT_TIMEOUT (0x102 -> 258).
Using Winedbg we can figure out who calls this (NOTE: pids don't match, another
run just to illustrate):
--- snip ---
Wine-dbg>info process
pid threads executable (all id:s are in hex)
00000033 1 'wineconsole.exe'
00000035 1 \_ 'R.exe'
00000037 1 \_ 'cmd.exe'
00000039 2 \_ 'Rterm.exe'
0000003c 1 \_ 'make.exe'
0000003e 1 \_ 'make.exe'
0000002c 1 'make.exe'
00000021 1 'explorer.exe'
0000000e 5 'services.exe'
0000001b 3 \_ 'plugplay.exe'
00000012 4 \_ 'winedevice.exe'
...
<attach to highest child pid>
...
Backtrace:
=>0 0xf777742e __kernel_vsyscall+0xe() in [vdso].so (0x00629328)
1 0xf756c233 __libc_read+0x22() in libpthread.so.0 (0x00629328)
2 0x7bc7e876 wait_select_reply+0x30(cookie=0x62940c)
[/home/focht/projects/wine/wine-git/dlls/ntdll/server.c:333] in ntdll
(0x00629328)
3 0x7bc7f65d server_select+0x182(select_op=0x629464, size=0x8, flags=0x2,
timeout=0x6295a8) [/home/focht/projects/wine/wine-git/dlls/ntdll/server.c:597]
in ntdll (0x00629438)
4 0x7bc88bdb NtWaitForMultipleObjects+0xd4(count=0x1, handles=0x6295b0,
wait_all=0, alertable=0, timeout=0x6295a8)
[/home/focht/projects/wine/wine-git/dlls/ntdll/sync.c:835] in ntdll
(0x00629578)
5 0x7b875dc0 WaitForMultipleObjectsEx+0x160(count=<couldn't compute
location>, handles=<couldn't compute location>, wait_all=<couldn't compute
location>, timeout=<couldn't compute location>, alertable=<couldn't compute
location>) [/home/focht/projects/wine/wine-git/dlls/kernel32/sync.c:188] in
kernel32 (0x006296d8)
6 0x7b875ba7 WaitForSingleObject+0x45(handle=<couldn't compute location>,
timeout=<couldn't compute location>)
[/home/focht/projects/wine/wine-git/dlls/kernel32/sync.c:128] in kernel32
(0x00629718)
7 0x610db059 in cygwin1 (+0xdb058) (0x00629840)
8 0x610db897 in cygwin1 (+0xdb896) (0x00629910)
9 0x6107835e in cygwin1 (+0x7835d) (0x00629aa0)
10 0x610d50f5 in cygwin1 (+0xd50f4) (0x00629af0)
11 0x0040b0f5 in make (+0xb0f4) (0x00629b20)
12 0x0040b51c in make (+0xb51b) (0x00629b70)
...
24 0x0040efb8 in make (+0xefb7) (0x0062a970)
25 0x61007128 in cygwin1 (+0x7127) (0x0062ab70)
--- snip ---
The child 'make' process has only one main thread.
Using the info from callstack and a disassembler on "cygwin1.dll" we can deduce
where this binary comes from:
--- snip ---
/home/corinna/src/cygwin/cygwin-1.7.15/cygwin-1.7.15-1/src/cygwin-1.7.15/winsup/cygwin/sigproc.cc
--- snip ---
Source to CVS HEAD:
http://cygwin.com/cgi-bin/cvsweb.cgi/src/winsup/cygwin/sigproc.cc?cvsroot=src
Checking if a tag exists for "cygwin-1.7.15-x":
--- snip ---
Revision 1.384 / (download) - annotate - [select for diffs] , Wed May 2
16:39:39 2012 UTC (18 months, 1 week ago) by cgf
Branch: MAIN
CVS Tags: cygwin-1_7_15-release
--- snip ---
Looking at the CVS commit history there seem to be lots of bugfixes and partial
rewrite (merge) _after_ that tag (18 months old).
Source to CVS tag:
http://cygwin.com/cgi-bin/cvsweb.cgi/src/winsup/cygwin/sigproc.cc?rev=1.384&content-type=text/x-cvsweb-markup&cvsroot=src&only_with_tag=cygwin-1_7_15-release
You can cross-check between source code of "sig_send" function and looking at
Wine trace log API calls.
For me it looks like the user APC which ought to handle the other pipe
end/signalling is not called in between WriteFile() and WaitForSingleObject()
because the main thread didn't enter an alertable state.
The be in alertable state, the (main) thread has to call SleepEx,
SignalObjectAndWait, WaitForSingleObjectEx, WaitForMultipleObjectsEx, or
MsgWaitForMultipleObjectsEx.
WaitForSingleObject() -> WaitForMultipleObjectsEx( ... bAlertable = FALSE)
Can standard WriteFile() cause queued APC to be executed? I don't know.
Regards
--
Configure bugmail: http://bugs.winehq.org/userprefs.cgi?tab=email
Do not reply to this email, post in Bugzilla using the
above URL to reply.
------- You are receiving this mail because: -------
You are watching all bug changes.
More information about the wine-bugs
mailing list