Bug 200544 - Valgrind forked children truncate their output when used with --log-file=...
Summary: Valgrind forked children truncate their output when used with --log-file=...
Status: RESOLVED DUPLICATE of bug 191069
Alias: None
Product: valgrind
Classification: Developer tools
Component: memcheck (show other bugs)
Version: unspecified
Platform: Unlisted Binaries Linux
: NOR normal
Target Milestone: ---
Assignee: Julian Seward
URL:
Keywords:
Depends on:
Blocks:
 
Reported: 2009-07-17 12:57 UTC by Timur Iskhodzhanov
Modified: 2009-07-23 08:16 UTC (History)
2 users (show)

See Also:
Latest Commit:
Version Fixed In:


Attachments
A fixed version of the verifier script (482 bytes, text/x-python)
2009-07-17 13:05 UTC, Timur Iskhodzhanov
Details
Short reproducer (3.61 KB, text/plain)
2009-07-17 14:41 UTC, Timur Iskhodzhanov
Details

Note You need to log in before you can comment on or make changes to this bug.
Description Timur Iskhodzhanov 2009-07-17 12:57:21 UTC
svn r10482

Reproduce:
* Get and build chromium's base_unittests (see http://code.google.com/p/chromium/wiki/LinuxBuildInstructions + do "hammer -C build base_unittests")
// I'll try to create a shorter reproducer soon
* Put the attached python script into chromium/src directory
* ./tools/valgrind/valgrind.sh --log-file=VG_OUT ./sconsbuild/Debug/base_unittests --gtest_filter="Process*"; echo "================"; cat VG_OUT | ./valgrind_report_verifier.py

The script tracks different PIDs in the log file and checks that every PID has "ERROR SUMMARY" line. The experiments show this doesn't hold.
Comment 1 Timur Iskhodzhanov 2009-07-17 12:59:43 UTC
The same happens without --log-file:
./tools/valgrind/valgrind.sh ./sconsbuild/Debug/base_unittests --gtest_filter="Process*" 2>VG_OUT; echo "================"; cat VG_OUT | ./valgrind_report_verifier.py

Also, if the output format is XML this may result in a wrong XML structure
Comment 2 Timur Iskhodzhanov 2009-07-17 13:05:41 UTC
Created attachment 35413 [details]
A fixed version of the verifier script

Oops, sorry, the script was a bit wrong...
Comment 3 Timur Iskhodzhanov 2009-07-17 14:41:46 UTC
Created attachment 35416 [details]
Short reproducer

valgrind --trace-children=yes --log-file=VG_OUT ./a.out; cat VG_OUT | ./valgrind_report_verifier.py
Comment 4 Dan Kegel 2009-07-17 20:54:18 UTC
This is important for chrome... you can see it firing every time in the 
test_shell test logs at
http://build.chromium.org/buildbot/waterfall.fyi/builders/Webkit%20Linux%20(valgrind)
the line
11:55:20 memcheck_analyze.py [WARNING] valgrind didn't finish writing 4 files?!
always appears because of this.
Comment 5 Dan Kegel 2009-07-17 20:59:33 UTC
This is related to bug 162848 in that anyone who wants fork to work needs both fixed, I think.
Comment 6 Dan Kegel 2009-07-18 18:18:46 UTC
The short repro recipe looks wrong to me.  
It works fine if I do --log-file=VG_OUT-%p.log
I suspect we'll have to keep looking.
Comment 7 Nicholas Nethercote 2009-07-20 05:38:53 UTC
It sounds an awful lot like bug 162848.
Comment 8 Timur Iskhodzhanov 2009-07-20 12:21:43 UTC
Sorry, the reproducer is wrong.
The problem the current reproducer shows is exec in child - it closes parent's log. So the reproducer is connected with the bug 162848.

The bug I was trying to reproduce was a bit different.
Even with --log-file=VG_OUT-%p and our patch (attached to 162848) the logs for child processes are often truncated. I'll try to find another reproducer...
Comment 9 Timur Iskhodzhanov 2009-07-23 08:16:54 UTC
We've resolved what's happening.
If a process does fork/exec under valgrind without --trace-childer=yes, the log of the child process isn't finished (with "ERROR SUMMARY" or "</valgrindoutput>".
The proposed solution is attached to https://bugs.kde.org/show_bug.cgi?id=162848 and Dan asked for it at https://bugs.kde.org/show_bug.cgi?id=191069

*** This bug has been marked as a duplicate of bug 191069 ***