Hello, does anyone notice a problem that the lines of the logging are written over each other as in the attached log? My system has an AMD Phenom(tm) II X2 550 Processor on a NVIDIA GeForce 8300 Chipset running running Debian Lenny 32 bit Is this a know problem? Is a work around available? -- Stefan
On 28 January 2010 22:39, Stefan Leichter <Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.
2010/1/29 Henri Verbeet <hverbeet(a)gmail.com>:
On 28 January 2010 22:39, Stefan Leichter <Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.
Wait, is this really a "known problem" or is it just that he was using the standard ">" redirect, which is *expected* to overwrite the file?
On 29 January 2010 00:14, Ben Klein <shacklein(a)gmail.com> wrote:
2010/1/29 Henri Verbeet <hverbeet(a)gmail.com>:
On 28 January 2010 22:39, Stefan Leichter <Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.
Wait, is this really a "known problem" or is it just that he was using the standard ">" redirect, which is *expected* to overwrite the file?
The problem isn't the file being overwritten, it's multiple threads writing (mostly unsynchronized) to the same file.
On 01/28/2010 10:59 PM, Henri Verbeet wrote:
On 28 January 2010 22:39, Stefan Leichter<Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course. That won't workaround the problem. The problem is that there are multiple threads/programs that write at the same time to stdout/stderr. I have seen it with fixme/err/warn messages too; even with crash dumps.
For the winefixme collector i have the luxury to be able to ignore the mangled output lines; not so much for the wineoops crash collector. bye michael
On 01/29/2010 12:23 AM, Nikolay Sivov wrote: > On 1/29/2010 02:21, Michael Stefaniuc wrote: >> For the winefixme collector i have the luxury to be able to ignore the >> mangled output lines; not so much for the wineoops crash collector. >> > Btw, are they ready and hosted somewhere already? winefixme is "production": - The first report "Wine FIXME Report 2009 Aug - Dec" was sent to wine-devel (see http://www.winehq.org/pipermail/wine-devel/2010-January/080965.html). I have done some improvements to the winefixme collector and DB but I still need to wrap those up and restate that report; not that it would matter much but to serve as a baseline for the next report. - The second report for 2010 January is due next week. - The data (the sqlite DB, the report itself and the SQL used to generate the report) are public on http://people.redhat.com/mstefani/winefixme/reports/ - The code is in git but I didn't focus on making it publishable nor where to publish it (it will probably end in the Wine project on sf.net now that they support git). wineoops is still in demo quality code state and my presentation at the last WineConf is the only public available info about it. After the January issue of the winefixme report I'll focus again (if time permits) on wineoops. bye michael
On 29 January 2010 00:21, Michael Stefaniuc <mstefani(a)redhat.com> wrote:
On 01/28/2010 10:59 PM, Henri Verbeet wrote:
On 28 January 2010 22:39, Stefan Leichter<Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.
That won't workaround the problem.
Seems to work for me.
Am Friday 29 January 2010 01:20:24 schrieb Henri Verbeet:
On 29 January 2010 00:21, Michael Stefaniuc <mstefani(a)redhat.com> wrote:
On 01/28/2010 10:59 PM, Henri Verbeet wrote:
On 28 January 2010 22:39, Stefan Leichter<Stefan.Leichter(a)camline.com>
wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course.
That won't workaround the problem.
Seems to work for me.
For me too Thanks for the tip
On Jan 28, 2010, at 5:21 PM, Michael Stefaniuc wrote:
On 01/28/2010 10:59 PM, Henri Verbeet wrote:
On 28 January 2010 22:39, Stefan Leichter<Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course. That won't workaround the problem. The problem is that there are multiple threads/programs that write at the same time to stdout/stderr. I have seen it with fixme/err/warn messages too; even with crash dumps.
Using >> in the shell causes the stdout file descriptor to be opened with O_APPEND. Using 2>&1 makes stderr dup the file descriptor, so it gets the same flag. With O_APPEND, the kernel ensures that all writes append to the file. Multiple threads or programs using an O_APPEND descriptor can't overwrite each other. If the code uses multiple writes for a single line, then those multiple writes can be interleaved, but can't overwrite. And, for the most part, Wine's debug logging uses single writes so it won't even interleave. Regards, Ken
Ken Thomases wrote:
On Jan 28, 2010, at 5:21 PM, Michael Stefaniuc wrote:
On 01/28/2010 10:59 PM, Henri Verbeet wrote:
On 28 January 2010 22:39, Stefan Leichter<Stefan.Leichter(a)camline.com> wrote:
Is this a know problem? Is a work around available?
Yeah, that's a known problem. As a workaround you can use ">>" (append) instead of ">" to redirect to the file. You'll still need the "2>&1" to redirect stderr to stdout, of course. That won't workaround the problem. The problem is that there are multiple threads/programs that write at the same time to stdout/stderr. I have seen it with fixme/err/warn messages too; even with crash dumps.
Using >> in the shell causes the stdout file descriptor to be opened with O_APPEND. Using 2>&1 makes stderr dup the file descriptor, so it gets the same flag.
With O_APPEND, the kernel ensures that all writes append to the file. Multiple threads or programs using an O_APPEND descriptor can't overwrite each other. If the code uses multiple writes for a single line, then those multiple writes can be interleaved, but can't overwrite. Right, Henri and I talked about that on irc. The "overwrite" corruption is fixed by using ">>". So yes, when writting to a log file redirecting with ">>" is better.
And, for the most part, Wine's debug logging uses single writes so it won't even interleave. Incorrect. Wine doesn't use write(2) but vfprintf(3) which operates on FILE handles; the output is buffered aka a vfprintf call won't translate 1:1 to a write(2) system call. But even if it would directly use write(2), that system call isn't atomic. A lot of people consider a write smaller/equal the PAGE_SIZE to be atomic but it isn't; one can get a short write because of an EINTR.
The ">>" redirection fixes the overwriting corruption but not the interleaving one. With multiple threads and enough debug output the chances are high to get a few interleaving corruption; i see it regularly in the output of winetest.exe runs. bye michael
Michael Stefaniuc <mstefani(a)redhat.com> writes:
Incorrect. Wine doesn't use write(2) but vfprintf(3) which operates on FILE handles; the output is buffered aka a vfprintf call won't translate 1:1 to a write(2) system call. But even if it would directly use write(2), that system call isn't atomic. A lot of people consider a write smaller/equal the PAGE_SIZE to be atomic but it isn't; one can get a short write because of an EINTR.
The ">>" redirection fixes the overwriting corruption but not the interleaving one. With multiple threads and enough debug output the chances are high to get a few interleaving corruption; i see it regularly in the output of winetest.exe runs.
No, Wine explicitly uses write(2) for debug output, and is careful about writing only complete lines precisely to avoid the interleaving issue. It does require O_APPEND to ensure that the writes don't step over each other, which is why you need ">>". It definitely makes a difference. -- Alexandre Julliard julliard(a)winehq.org
Alexandre Julliard wrote:
Michael Stefaniuc <mstefani(a)redhat.com> writes:
Incorrect. Wine doesn't use write(2) but vfprintf(3) which operates on FILE handles; the output is buffered aka a vfprintf call won't translate 1:1 to a write(2) system call. But even if it would directly use write(2), that system call isn't atomic. A lot of people consider a write smaller/equal the PAGE_SIZE to be atomic but it isn't; one can get a short write because of an EINTR.
The ">>" redirection fixes the overwriting corruption but not the interleaving one. With multiple threads and enough debug output the chances are high to get a few interleaving corruption; i see it regularly in the output of winetest.exe runs.
No, Wine explicitly uses write(2) for debug output, and is careful about writing only complete lines precisely to avoid the interleaving issue. Hmm ... I have looked at libs/wine/debug.c and not at NTDLL_dbg_vprintf().
Anyway the usage of write(2) in NTDLL_dbg_vprintf() is *wrong* as it doesn't check for short writes nor errors. It is good enough for debug output and better than using the FILE * functions but not good enough to prevent interleaving. It even introduces an opportunity for parts of a line to be overwritten in the case of short writes.
It does require O_APPEND to ensure that the writes don't step over each other, which is why you need ">>". It definitely makes a difference. Yes it does; it didn't disagree with this fact.
bye michael
Michael Stefaniuc <mstefani(a)redhat.com> writes:
Anyway the usage of write(2) in NTDLL_dbg_vprintf() is *wrong* as it doesn't check for short writes nor errors. It is good enough for debug output and better than using the FILE * functions but not good enough to prevent interleaving. It even introduces an opportunity for parts of a line to be overwritten in the case of short writes.
The usage is correct, checking for short writes or errors in debug output would be much more wrong, and O_APPEND does a fine job at preventing interleaving. More importantly, there's no other sane way to do it. And I doubt you'd be able to trigger short writes in practice when writing to a log file. -- Alexandre Julliard julliard(a)winehq.org
participants (7)
-
Alexandre Julliard -
Ben Klein -
Henri Verbeet -
Ken Thomases -
Michael Stefaniuc -
Nikolay Sivov -
Stefan Leichter