Web lists-archives.org

[Mingw-users] `as.exe' hanging intermittently (SOLVED)




Hi all

I'm running into a rather odd problem with my new mingw+msys install
that has me at my wit's end, and I'm hoping for some help or ideas. Or I was when I initially wrote this - see below.

When I compile programs - even trivial test programs - it usually works
fine, but some of the time gcc/g++ hang indefinitely. A bit of
investigation with Process Explorer revealed that the instance of as.exe
exec'd by gcc is always running when the hang occurs. `ps -aW' also shows it, but interestingly it has a pid of 0, with only the winpid being non 0. Process Explorer suggests that `as.exe' is not using any CPU time, nor is its memory allocation changing at all. I strongly suspect it's deadlocked somewhere. With more testing I found that the hang occurs whether as is run from gcc, or directly from the shell.

Update: while writing this, I appear to have solved the issue. Of all the insane things, the Logitech camera monitor that handles the built-in webcam on this Acer TravelMate 8200 seems to have somehow been interfering with msys, specifically as.exe. It doesn't make sense, but appears to be the case. While running a shell script that loops `make && make clean' in cmd.exe as described below, I noticed the logitech process LVPrcSrv.exe spike in CPU usage, maxing out one core. When it became clear it wasn't going to recover I killed it, and now I can't reproduce the as.exe hang. How utterly weird. The as.exe hang is not typically accompanied by that CPU usage spike; I've only seen it this once. I've re-tested by rebooting and running the as.exe tests under (a) rxvt, (b) cmd.exe without runfirst, (c) cmd.exe with runfirst, and all hung. After killing that process, I can't get any of them to hang anymore. The camera was not used at all.

The services snap-in calls the service associated with LVPrcSrv the "Logitech Process Monitor" ... which is interesting and, in light of these issues, somewhat scary. It's description is "Webcam effects helper". If I start the service again (it having been stopped by my killing its process), I find that as.exe begins to intermittently hang again. Stop the service, and everything is fine.

Killing LVPrcSrv.exe does not cause hung as.exe processes to resume execution, but after it is killed new as.exe processes will not hang.

I don't even want to know what that process is doing such that it can interfere so severely with totally unrelated processes running on the system. Logitech might want to take a good look at this one.

So ... problem solved partly through luck and partly through lots of tedious investigation, and what a weird problem it was. I hope this, and the following, will be informative for you folks.




My original discussion follows, so Google can find it and in case it helps anybody else:

I've seen this hang once with another process that appeared to be
unrelated to as.exe. It was early on, and I can't remember what it was.
Sorry. I'm pretty sure there was a hung as.exe running at the time,
though, or I'd just killed it.

I'm using an Intel Core Duo 2.0GHz laptop with 2GB of RAM running XP SP2
with current security patches. I have the .NET 2.0 runtime and SDK plus
the Windows Platform SDK installed, in case it matters. The version of
as.exe present is 2.15.91 20040904, with gcc 3.4.2 (mingw-special).

I tried to hook gdb up to as.exe, but gdb also hung indefinitely. It
works fine on other tasks. Connecting with windbg was not especially
informative due to the lack of debugging symbols in as.exe, but I've
attached its best-effort stack traces for a hung as.exe and a hung gdb
trying to attach to as.exe in case they're useful.

I'm inexperienced with Windows debugging, especially binaries without
available symbol tables, but I think the windbg stack trace suggests
that `as.exe' may be deadlocked in exit(). This would explain its lack
of a mingw pid.

Interestingly, setting the CPU affinity on `rxvt' and the shell it
spawns before trying to start my build seems to reduce the frequency
with which as.exe hangs, but does not eliminate the problem. It does not
seem to matter whether I run `as.exe' by hand / directly from make or if
I let gcc or g++ invoke it; it'll hang sometimes either way. Setting the
affinity with `runfirst.exe' when invoking a shell script that loops
'make clean && make' from cmd.exe also seems to dramatically reduce the
frequency of hangs.

I can also reproduce this problem working from cmd.exe. Compiling and
assembling a `hello world' test C file with:

gcc -S -o test.S test.c
as -o test.o test.S

works most of the time, but like when it's run in msys will sometimes
just hang in as.exe . At the time `as' hangs there are *no* other
msys/mingw processes running. Under rxvt+bash, control C doesn't affect
the hang - I have to kill as.exe in process explorer - but under cmd.exe
control C kills as.exe .

It typically takes somewhere in the vein of four to eight invocations of
`as.exe' to get a hang, but this does vary.

In addition to the backtraces from windbg, I grabbed thread backtraces
from Process Explorer. Strangely, they're different. Here's the
backtrace from `as.exe' run under rxvt from make, when hung, as reported
be process explorer:

Thread 12156:
ntkrnlpa.exe!KiUnexpectedInterrupt+0x121
ntkrnlpa.exe!NtWaitForSingleObject+0x9a
ntkrnlpa.exe!KeReleaseInStackQueuedSpinLockFromDpcLevel+0xb74
ntdll.dll!KiFastSystemCallRet
ntdll.dll!RtlEnterCriticalSection+0x46
ntdll.dll!LdrGetDllHandleEx+0x12c
ntdll.dll!LdrGetDllHandle+0x18
!GetModuleHandleW+0x57
!GetModuleHandleW+0x16f
!GetModuleHandleW+0x1f
!GetModuleHandleA+0x1f
!strerror+0x2b29
!initterm+0x111
!exit+0x12
!RegisterWaitForInputIdle+0x49

thread 12168:
ntkrnlpa.exe!KiUnexpectedInterrupt+0x121
ntkrnlpa.exe!ZwYieldExecution+0x1c56
ntkrnlpa.exe!ZwYieldExecution+0x2538
ntkrnlpa.exe!NtWaitForSingleObject+0x9a
ntkrnlpa.exe!KeReleaseInStackQueuedSpinLockFromDpcLevel+0xb74
ntdll.dll!KiFastSystemCallRet
ntdll.dll!RtlEnterCriticalSection+0x46
!strerror+0x2b58
!CoGetComCatalog+0x22bc
!CoGetComCatalog+0x2289
!CoGetComCatalog+0x2275
!CoGetComCatalog+0x21db
!CoTaskMemAlloc+0x91
ntdll.dll!LdrInitializeThunk+0x29
ntdll.dll!LdrFindResourceDirectory_U+0x276
ntdll.dll!RtlValidateUnicodeString+0x506
ntdll.dll!LdrLoadDll+0x110
!LoadLibraryExW+0xc8
!LoadLibraryExA+0x1f
!LoadLibraryA+0x2d

thread 9468:
ntkrnlpa.exe!KiUnexpectedInterrupt+0x121
ntkrnlpa.exe!NtWaitForSingleObject+0x9a
ntkrnlpa.exe!KeReleaseInStackQueuedSpinLockFromDpcLevel+0xb74
ntdll.dll!KiFastSystemCallRet
ntdll.dll!RtlEnterCriticalSection+0x46
ntdll.dll!KiUserApcDispatcher+0x7

Before I start trying to rebuild gcc - with a dodgy compiler - to get
debugging symbols, I'm hoping someone has a .pdb file (is that what's
needed on Windows for symbols?) or a version of as or the compiler suite
with debugging symbols that I can drop into place to investigate this
further. Even better, maybe somebody knows what might be going on, or
what more information I can collect to help.

I've also attached a typical process list for this system while running
normally (process_list.txt).

The test project I've been using, which was created while investigating
the exact asm output by auto_ptr use vs manual allocation/deallocation
in simple classes, is:

Makefile:
=========
ALL_ASM=auto.S manual.S
ALL_DUMP=auto.dump manual.dump
ALL_EXE=auto.exe manual.exe
ALL_OBJ=auto.o manual.o

all: $(ALL_ASM) $(ALL_OBJ) $(ALL_EXE) $(ALL_DUMP)
exe: $(ALL_EXE)
asm: $(ALL_ASM)
obj: $(ALL_OBJ)
dump: $(ALL_DUMP)

%.S: %.cpp
	g++ -S $< -o $@

%.o: %.S
	as $< -o $@

%.exe: %.o
	g++ $< -o $@

%.dump: %.exe
	objdump -d -w -S $< > $@

clean:
	rm -f $(ALL_ASM) $(ALL_DUMP) $(ALL_EXE) $(ALL_OBJ) Makefile~

auto.c:
=======
#include <memory>

class Dummy {
	char buf[200];
};

class Sample {

	std::auto_ptr<Dummy> dummy_ptr;
	
public:
	Sample() : dummy_ptr(new Dummy()) { }
	~Sample() { }
};

int main() {
	Sample sa;
}

manual.cpp
==========
class Dummy {
	char buf[200];
};

class Sample {

	Dummy * const dummy_ptr;

public:
	Sample() : dummy_ptr(new Dummy()) { }
	~Sample() { delete dummy_ptr; }
};

int main() {
	Sample sm;
}

I've also confirmed that a trivial hello world in C, compiled with `gcc'
not g++, will exhibit the problem.

--
Craig Ringer

Microsoft (R) Windows Debugger  Version 6.6.0003.5
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: SRV**http://msdl.microsoft.com/download/symbols
Executable search path is: 
ModLoad: 00400000 004a3000   c:\mingw\bin\as.exe
ModLoad: 7c900000 7c9b0000   C:\WINDOWS\system32\ntdll.dll
ModLoad: 7c800000 7c8f4000   C:\WINDOWS\system32\kernel32.dll
ModLoad: 77c10000 77c68000   C:\WINDOWS\system32\msvcrt.dll
ModLoad: 10000000 10016000   C:\Program Files\Common Files\Logitech\LVMVFM\LVPrcInj.dll
ModLoad: 77d40000 77dd0000   C:\WINDOWS\system32\USER32.dll
ModLoad: 77f10000 77f57000   C:\WINDOWS\system32\GDI32.dll
ModLoad: 774e0000 7761d000   C:\WINDOWS\system32\ole32.dll
ModLoad: 77dd0000 77e6b000   C:\WINDOWS\system32\ADVAPI32.dll
ModLoad: 77e70000 77f01000   C:\WINDOWS\system32\RPCRT4.dll
ModLoad: 76390000 763ad000   C:\WINDOWS\system32\IMM32.DLL
ModLoad: 629c0000 629c9000   C:\WINDOWS\system32\LPK.DLL
ModLoad: 74d90000 74dfb000   C:\WINDOWS\system32\USP10.dll
Break-in sent, waiting 30 seconds...
WARNING: Break-in timed out, suspending.
         This is usually caused by another thread holding the loader lock
(888.cb4): Wake debugger - code 80000007 (first chance)
eax=00401000 ebx=00000000 ecx=77c112bc edx=7c90eb94 esi=7c97c0d8 edi=00000000
eip=7c90eb94 esp=0022f884 ebp=0022f90c iopl=0         nv up ei pl zr na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=003b  gs=0000             efl=00000246
ntdll!KiFastSystemCallRet:
7c90eb94 c3               ret
*** ERROR: Module load completed but symbols could not be loaded for c:\mingw\bin\as.exe
0:000> kb
ChildEBP RetAddr  Args to Child              
0022f880 7c90e9c0 7c91901b 000007e8 00000000 ntdll!KiFastSystemCallRet
0022f884 7c91901b 000007e8 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
0022f90c 7c90104b 0197c0d8 7c914859 7c97c0d8 ntdll!RtlpWaitForCriticalSection+0x132
0022f914 7c914859 7c97c0d8 00000000 0022fa14 ntdll!RtlEnterCriticalSection+0x46
0022f950 7c9166d3 00000000 00000000 0022f994 ntdll!LdrLockLoaderLock+0x146
0022f9c4 7c91659e 00000001 00000001 00000000 ntdll!LdrGetDllHandleEx+0x8b
0022f9e0 7c80e693 00000001 00000000 0022fa64 ntdll!LdrGetDllHandle+0x18
0022fa30 7c80e7ab 0022fa64 003dcf78 00000001 kernel32!GetModuleHandleForUnicodeString+0x1d
0022feb4 7c80e65b 00000001 00000002 7ffddc00 kernel32!BasepGetModuleHandleExW+0x18e
0022fecc 7c80b548 7ffddc00 0022fee4 77c39d23 kernel32!GetModuleHandleW+0x29
0022fed8 77c39d23 77c140a4 0022fef4 77c39e78 kernel32!GetModuleHandleA+0x2d
0022fee4 77c39e78 00000000 ffffffff 0022ff08 msvcrt!__crtExitProcess+0x10
0022fef4 77c39e90 00000000 00000000 00000001 msvcrt!_cinit+0xee
0022ff08 0046e1aa 00000000 ffffffff 0022ff78 msvcrt!exit+0x12
WARNING: Stack unwind information not available. Following frames may be wrong.
0022ff18 0040394d 00000000 00000000 00000001 as+0x6e1aa
0022ff78 004011e6 00000002 003dcf70 003d2d20 as+0x394d
0022ffb0 00401238 00000001 00000009 0022fff0 as+0x11e6
0022ffc0 7c816d4f 0000000c 00000000 7ffde000 as+0x1238
0022fff0 00000000 00401220 00000000 78746341 kernel32!BaseProcessStart+0x23
0:001> kb
ChildEBP RetAddr  Args to Child              
005ff74c 7c90e9c0 7c91901b 000007c0 00000000 ntdll!KiFastSystemCallRet
005ff750 7c91901b 000007c0 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
005ff7d8 7c90104b 00c61ae8 77c3a5eb 77c61ae8 ntdll!RtlpWaitForCriticalSection+0x132
005ff7e0 77c3a5eb 77c61ae8 77531218 005ff830 ntdll!RtlEnterCriticalSection+0x46
005ff7f0 77c39d52 00000008 77c34e62 00000000 msvcrt!_lock+0x30
005ff7f8 77c34e62 00000000 77531218 774e0000 msvcrt!_lockexit+0x7
005ff830 775312d4 77531edf 776062f8 776062f4 msvcrt!__dllonexit+0x11
005ff844 775312a1 77531edf 005ff864 7753128d ole32!_onexit+0x27
005ff850 7753128d 77531edf 77c39d7a 00000000 ole32!atexit+0xd
005ff858 77c39d7a 00000000 005ff878 775311f3 ole32!MesBufferHandleReset+0x73
005ff864 775311f3 77531200 7753124c 00000001 msvcrt!_initterm+0x13
005ff878 774fd0d9 774e0000 00000001 00000000 ole32!_CRT_INIT+0x61
005ff898 7c9011a7 774e0000 00000001 00000000 ole32!_DllMainCRTStartup+0x42
005ff8b8 7c91cbab 774fd0a1 774e0000 00000001 ntdll!LdrpCallInitRoutine+0x14
005ff9c0 7c916178 00000000 c0150008 00000000 ntdll!LdrpRunInitializeRoutines+0x344
005ffc6c 7c9162da 00000000 00243788 005fff60 ntdll!LdrpLoadDll+0x3e5
005fff14 7c801bb9 00243788 005fff60 005fff40 ntdll!LdrLoadDll+0x230
005fff7c 7c801d6e 7ffdcc00 00000000 00000000 kernel32!LoadLibraryExW+0x18e
005fff90 7c801da4 003f000f 00000000 00000000 kernel32!LoadLibraryExA+0x1f
005fffac 003f000c 003f000f 7c80b50b 00000000 kernel32!LoadLibraryA+0x94
0:002> kb
ChildEBP RetAddr  Args to Child              
00c1fc0c 7c90e9c0 7c91901b 000007e8 00000000 ntdll!KiFastSystemCallRet
00c1fc10 7c91901b 000007e8 00000000 00000000 ntdll!ZwWaitForSingleObject+0xc
00c1fc98 7c90104b 0197c0d8 7c927357 7c97c0d8 ntdll!RtlpWaitForCriticalSection+0x132
00c1fca0 7c927357 7c97c0d8 00c1fd2c 00000004 ntdll!RtlEnterCriticalSection+0x46
00c1fd18 7c90eac7 00c1fd2c 7c900000 00000000 ntdll!_LdrpInitialize+0xf0
00000000 00000000 00000000 00000000 00000000 ntdll!KiUserApcDispatcher+0x7
Microsoft (R) Windows Debugger  Version 6.6.0003.5
Copyright (c) Microsoft Corporation. All rights reserved.

*** wait with pending attach
Symbol search path is: SRV**http://msdl.microsoft.com/download/symbols
Executable search path is: 
ModLoad: 00400000 005d6000   c:\mingw\bin\gdb.exe
ModLoad: 7c900000 7c9b0000   C:\WINDOWS\system32\ntdll.dll
ModLoad: 7c800000 7c8f4000   C:\WINDOWS\system32\kernel32.dll
ModLoad: 77dd0000 77e6b000   C:\WINDOWS\system32\ADVAPI32.DLL
ModLoad: 77e70000 77f01000   C:\WINDOWS\system32\RPCRT4.dll
ModLoad: 77c10000 77c68000   C:\WINDOWS\system32\msvcrt.dll
ModLoad: 77d40000 77dd0000   C:\WINDOWS\system32\USER32.dll
ModLoad: 77f10000 77f57000   C:\WINDOWS\system32\GDI32.dll
ModLoad: 76390000 763ad000   C:\WINDOWS\system32\IMM32.DLL
ModLoad: 629c0000 629c9000   C:\WINDOWS\system32\LPK.DLL
ModLoad: 74d90000 74dfb000   C:\WINDOWS\system32\USP10.dll
ModLoad: 10000000 10016000   C:\Program Files\Common Files\Logitech\LVMVFM\LVPrcInj.dll
ModLoad: 774e0000 7761d000   C:\WINDOWS\system32\ole32.dll
ModLoad: 73ee0000 73ee4000   C:\WINDOWS\system32\KsUser.dll
ModLoad: 76bf0000 76bfb000   C:\WINDOWS\system32\psapi.dll
(230.e4c): Break instruction exception - code 80000003 (first chance)
eax=7ffde000 ebx=00000001 ecx=00000002 edx=00000003 esi=00000004 edi=00000005
eip=7c901230 esp=00c5ffcc ebp=00c5fff4 iopl=0         nv up ei pl zr na po nc
cs=001b  ss=0023  ds=0023  es=0023  fs=0038  gs=0000             efl=00000246
ntdll!DbgBreakPoint:
7c901230 cc               int     3
*** ERROR: Module load completed but symbols could not be loaded for c:\mingw\bin\gdb.exe
0:000> kb
ChildEBP RetAddr  Args to Child              
0022f9f0 7c90e996 7c95072b 000007b8 00000001 ntdll!KiFastSystemCallRet
0022f9f4 7c95072b 000007b8 00000001 0022fa80 ntdll!NtWaitForDebugEvent+0xc
0022fa0c 7c85a289 0022fa20 0022fa80 0022fb30 ntdll!DbgUiWaitStateChange+0x1e
0022fa88 0045910b 005bd770 000003e8 00000020 kernel32!WaitForDebugEvent+0x21
WARNING: Stack unwind information not available. Following frames may be wrong.
0022fad8 0045807e ffffffff 0022fb30 00000000 gdb+0x5910b
0022fb08 00467da3 0022fb74 ffffffff 00000000 gdb+0x5807e
0022fbd8 00459a31 00000888 005d1c80 0022fc08 gdb+0x67da3
0022fbe8 004582c0 00000888 00b60f00 005bd850 gdb+0x59a31
0022fc08 0045d048 003d3e74 00000001 00b52490 gdb+0x582c0
0022fc38 00415ce1 003d3e74 00000001 00000000 gdb+0x5d048
0022fc68 0040b1c3 003d3e74 00000001 77c5fca0 gdb+0x15ce1
0022fc88 0040a5cf 0022fd70 0022fca8 0022ffe0 gdb+0xb1c3
0022fca8 0040b19d 00b60c50 0022fd68 00000000 gdb+0xa5cf
0022fd38 0040a67a 0040a5c0 00b60c50 0022fd68 gdb+0xb19d
0022fd88 00402755 00415cb0 003d3e74 00000001 gdb+0xa67a
0022fe58 0040a5cf 0022ff68 57434347 452d3233 gdb+0x2755
0022fe78 0040b19d 005b35a0 0022ff40 00000000 gdb+0xa5cf
0022ff08 0040a616 0040a5c0 005b35a0 0022ff40 gdb+0xb19d
0022ff48 00401375 00401de0 0022ff68 0040133d gdb+0xa616
0022ff70 00401165 00000004 003d3ec8 003d2d00 gdb+0x1375
0:001> kb
ChildEBP RetAddr  Args to Child              
00c5ffc8 7c9507a8 00000005 00000004 00000001 ntdll!DbgBreakPoint
00c5fff4 00000000 00000000 00000000 00000000 ntdll!DbgUiRemoteBreakin+0x2d