Bug 200544

Summary:	Valgrind forked children truncate their output when used with --log-file=...
Product:	[Developer tools] valgrind	Reporter:	Timur Iskhodzhanov <timurrrr>
Component:	memcheck	Assignee:	Julian Seward <jseward>
Status:	RESOLVED DUPLICATE
Severity:	normal	CC:	dank, njn
Priority:	NOR
Version:	unspecified
Target Milestone:	---
Platform:	Unlisted Binaries
OS:	Linux
Latest Commit:		Version Fixed In:
Sentry Crash Report:
Attachments:	A fixed version of the verifier script Short reproducer

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 ***