Bug 388017

Summary:	Callgrind produces empty log for pulseaudio
Product:	[Developer tools] valgrind	Reporter:	Konstantin Kharlamov <Hi-Angel>
Component:	callgrind	Assignee:	Josef Weidendorfer <josef.weidendorfer>
Status:	RESOLVED NOT A BUG
Severity:	normal	CC:	philippe.waroquiers
Priority:	NOR
Version First Reported In:	3.13.0
Target Milestone:	---
Platform:	Arch Linux
OS:	Linux
Latest Commit:		Version Fixed In:
Sentry Crash Report:

Description Konstantin Kharlamov 2017-12-18 19:55:22 UTC

Steps to reproduce:
1. Make sure pulseaudio is not running
2. Execute valgrind --tool=callgrind pulseaudio
3. Force pulseaudio to quit in any of three ways: press Ctrl+c, or kill pulseaudio with `kill` command, or execute `pulseaudio -k`.

Expected:
Having callgrind.out.pid file with some content

Actual:
The file is present but empty.

Additional info:
The problem seems to be exclusive to pulseaudio — every other command I tried does produce the output. When pulseaudio quits, valgrind does not even produce the usual on-quit statistics.

Comment 1 Philippe Waroquiers 2017-12-20 20:48:35 UTC

Several things can be tried to get some more info.

* I suppose pulseaudio will daemonize itself.
  So, you should run with --trace-children=yes
  Also, to be sure that the output goes to a known place, you should use
     --log-file=/some/abs/filename%p
   (you should use %p to have filenames containing the pid)

* Try with other tools, e.g. --tool=none and memchec, and use from a shell
   the command   'vgdb v.info scheduler'
  to check what is happening

* Run with -v -v -v -d -d -d --trace-syscalls=yes --trace-signals=yes

Comment 2 Konstantin Kharlamov 2017-12-22 01:28:34 UTC

(In reply to Philippe Waroquiers from comment #1)
> Several things can be tried to get some more info.
> 
> * I suppose pulseaudio will daemonize itself.
>   So, you should run with --trace-children=yes
>   Also, to be sure that the output goes to a known place, you should use
>      --log-file=/some/abs/filename%p
>    (you should use %p to have filenames containing the pid)
> 
> * Try with other tools, e.g. --tool=none and memchec, and use from a shell
>    the command   'vgdb v.info scheduler'
>   to check what is happening
> 
> * Run with -v -v -v -d -d -d --trace-syscalls=yes --trace-signals=yes

Amazing, thanks, the `--trace-children=yes` did the trick! I guess, this bug can be closed, not sure about the wording — "RESOLVED"? "NOTABUG"?

On an irrelevant note, I also tried running under valgrind and Wine a PE binary compiled with MinGW — it resulted in valgrind quitting with these lines:

	preloader: Warning: failed to reserve range 00110000-68000000
	preloader: Warning: failed to reserve range 7f000000-82000000

	valgrind: m_debuginfo/debuginfo.c:551 (check_CFSI_related_invariants): Assertion 'cfsi_fits' failed.

…and then stacktrace follows. I'm wondering if it's something known or should it be reported.

Comment 3 Philippe Waroquiers 2017-12-23 11:42:39 UTC

(In reply to Konstantin Kharlamov from comment #2)
> (In reply to Philippe Waroquiers from comment #1)
> > Several things can be tried to get some more info.
> > 
> > * I suppose pulseaudio will daemonize itself.
> >   So, you should run with --trace-children=yes
> >   Also, to be sure that the output goes to a known place, you should use
> >      --log-file=/some/abs/filename%p
> >    (you should use %p to have filenames containing the pid)
> > 
> > * Try with other tools, e.g. --tool=none and memchec, and use from a shell
> >    the command   'vgdb v.info scheduler'
> >   to check what is happening
> > 
> > * Run with -v -v -v -d -d -d --trace-syscalls=yes --trace-signals=yes
> 
> Amazing, thanks, the `--trace-children=yes` did the trick! I guess, this bug
> can be closed, not sure about the wording — "RESOLVED"? "NOTABUG"?
Closing the bug now as INVALID.

> 
> On an irrelevant note, I also tried running under valgrind and Wine a PE
> binary compiled with MinGW — it resulted in valgrind quitting with these
> lines:
> 
> 	preloader: Warning: failed to reserve range 00110000-68000000
> 	preloader: Warning: failed to reserve range 7f000000-82000000
> 
> 	valgrind: m_debuginfo/debuginfo.c:551 (check_CFSI_related_invariants):
> Assertion 'cfsi_fits' failed.
> 
> …and then stacktrace follows. I'm wondering if it's something known or
> should it be reported.
That looks like a bug, yes.
So, better to report it as a new bug, with some more info.
Someone more knowledgeable about wine/windows/... might then jump on it.

E.g. attach the output of running the above with -v -v -v -d -d -d
(i.e. the general debugging of valgrind).

Possibly other debug --trace-cfi=yes --trace-symtab ... might give some hints
but these will produce a lot more info.

Thanks

Comment 4 Josef Weidendorfer 2018-01-11 11:16:05 UTC

Good to see that `--trace-children=yes` worked!

Just as remark:

Callgrind opens a file descriptor at start to allow output
to be written to the directory which was the current working
directory at prgoram start. The motivation was that a program
could change to arbitrary directories during run, and it may be
difficult for an user to find the callgrind output.

Now if an application wildly closes all kind of file descriptors
before termination, it also may close this descriptor and leave callgrind
without writing output (this could be detected...).

However, you always can ask callgrind to dump output during the
program run using callgrind_control.