http://bugs.winehq.org/show_bug.cgi?id=19125
Summary: log file corruption on dual-core MacOS Product: Wine Version: 1.1.24 Platform: PC OS/Version: Mac OS X 10.5 Status: UNCONFIRMED Severity: normal Priority: P2 Component: wineserver AssignedTo: wine-bugs@winehq.org ReportedBy: hoehle@users.sourceforge.net
Created an attachment (id=22088) --> (http://bugs.winehq.org/attachment.cgi?id=22088) excerpts of +reg traces
The attached log snippet reveals how 2 simultaneous threads (one for font, one for desktop entries) access the registry. This somehow causes buffer contention (maybe a static buffer is used somewhere, instead of a stack-allocated one?) and garbage is printed to the log.
trace:reg:NtEnumerateValueKey (0xe4,95,1,0x74d6bc,256) e 4096, minappaddr 0x10000, maxappaddr 0x7ffeffff, act.cpumask 3, numcpus 2, CPU type 586, allocgran. 65536, CPU level 6, CPU rev 5898 ^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@trace:reg:NtCreateKey (0x0,L"Machine\Hardware\Description\System",<null>,0,f003f,0x32fc48)
This snippet might give a clue about where the bogus comes from, as "maxappaddr" normally does not occur in a registry trace. OTOH, it may be random buffer content.
Nothing was traced but WINEDEBUG=+reg in the attached log. It's been produced with "The Westerner" v1.3.
Maybe this buffer reuse is specific to MacOS. OTOH, maybe it's caused by the dual core Intel? I had never seen this before on a single core Ubuntu system.
http://bugs.winehq.org/show_bug.cgi?id=19125
Vitaliy Margolen vitaliy@kievinfo.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Severity|normal |trivial
http://bugs.winehq.org/show_bug.cgi?id=19125
--- Comment #1 from Jörg Höhle hoehle@users.sourceforge.net 2009-06-30 02:37:12 --- The same NUL-byte pattern appeared outside of Wine's trace log in the \windows\temp\res*.tmp file produced by running winetest-1.1.24.exe: notification.c:80: Test failed: 373: expected function 3 got 6 notification.c:79: Test failed: 379: expected status 0x00000002 got 0x00000800 notification.c:80: Test failed: (0 marked as todo, 26 failures), 0 skipped. ^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@^@6356416: expected function 3 got 8 winhttp:notification done (27) winhttp:url start dlls/winhttp/tests/url.c -
sock.c:604: simple_client (c4): server ready sock.c:505: select_server (c2): accepting client connection sock.c:505: simple_client (c3) connected ^@^@^@^@^@^@^@^@^@^@^@^@select_server (c2): accepting client connection sock.c:616: simple_client (c4) connected
And many more in pipe.c. I.e. in those situations where concurrency (e.g. client+server are running) matters.
This ain't a trivial bug. World-wide IT depends on the quality of logfiles ;) If you can't trust your logfiles, what can you trust?
http://bugs.winehq.org/show_bug.cgi?id=19125
--- Comment #2 from Alexandre Julliard julliard@winehq.org 2009-06-30 05:03:47 --- That's a kernel race. You can avoid it by redirecting in append mode (2>>logfile).
http://bugs.winehq.org/show_bug.cgi?id=19125
Dmitry Timoshkov dmitry@codeweavers.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|UNCONFIRMED |RESOLVED Component|wineserver |-unknown Resolution| |INVALID
--- Comment #3 from Dmitry Timoshkov dmitry@codeweavers.com 2009-07-09 11:37:08 --- Invalid then.
http://bugs.winehq.org/show_bug.cgi?id=19125
Dmitry Timoshkov dmitry@codeweavers.com changed:
What |Removed |Added ---------------------------------------------------------------------------- Status|RESOLVED |CLOSED
--- Comment #4 from Dmitry Timoshkov dmitry@codeweavers.com 2009-07-09 11:37:30 --- Closing invalid.
http://bugs.winehq.org/show_bug.cgi?id=19125
--- Comment #5 from Jörg Höhle hoehle@users.sourceforge.net 2010-01-29 03:31:35 --- On 2010-01-28, Stefan Leichter reported a similar problem with AMD Phenom(tm) II X2 550 Processor on a NVIDIA GeForce 8300 Chipset running running Debian Lenny 32 bit http://www.winehq.org/pipermail/wine-devel/2010-January/081406.html
The work-around on Debian is the same as on MacOS: Use ">>" to open the log in append mode.
So log write contention is not a MacOS-specific issue. However, Stefan does not notice NUL-bytes in the log. Instead, log line endings are cut off, so 2 logs appear on the same line like this: 003b:Call KERNEL32.lstrlenW(01812a90 L"C:\windows\temp\PCULog0.0038:Call user32.Un003b:Ret KERNEL32.lstrlenW() retval=0000001b ret=01523b41
http://bugs.winehq.org/show_bug.cgi?id=19125
Austin English austinenglish@gmail.com changed:
What |Removed |Added ---------------------------------------------------------------------------- OS/Version|Mac OS X 10.5 |Mac OS X
-
wine-bugs＠winehq.org