|
From: Christian P. <chr...@gm...> - 2015-02-01 20:39:19
|
Hi Josef, thanks a lot for your reply! 2015-02-01 15:44 GMT+00:00 <val...@li...>: > > Date: Sat, 31 Jan 2015 21:50:35 +0100 > From: Josef Weidendorfer <Jos...@gm...> > Subject: Re: [Valgrind-users] Enabling instrumentation with > callgrind_control not working > To: val...@li... > Message-ID: <54C...@gm...> > Content-Type: text/plain; charset=windows-1252 > > Am 31.01.2015 um 14:49 schrieb Christian Priebe: > > Apparently callgrind_control hangs on a read system call waiting for > > some output from vgdb. > > Since Valgrind 3.9 or 3.10, callgrind_control is just a wrapper around > vgdb. > When mysql is running under callgrind, just call "vgdb -l" (sudo as > needed). > This gives something like > > use --pid=28503 for ... > > and then run "vgdb --pid=28503 help" to see the commands you can send > to callgrind, e.g. "vgdb --pid=28503 instrumentation on". > > Does this work? > It unfortunately does not work. I receive the following message: "vgdb error: no FIFO found matching pid 5803" "5803" is the pid as reported by vgdb -l. Thanks again, Christian > > Josef > > > If I shudown callgrind_control it outputs the > > following: > > > > "syscall failed: Interrupted system call > > error opening /tmp/vgdb-pipe-to-vgdb-from-19680-by-root-on-??? read cmd > > result from pid" > > > > The specified file does exist under /tmp. mysqld does not respond to > > MySQL clients trying to connect to it while callgrind_control is in that > > hanging state and once I shutdown callgrind_control mysqld shuts down as > > well. Does anyone have an idea about what is going on exactly or what to > > do to resolve this? Running callgrind on mysqld with instrumentation > > enabled from the beginning works perfectly fine for me. The valgrind and > > callgrind version used is 3.10.1. > > > > > > Thanks in advance, > > Christian > |
|
From: Philippe W. <phi...@sk...> - 2015-02-01 20:53:17
|
On Sun, 2015-02-01 at 20:39 +0000, Christian Priebe wrote:
>
> It unfortunately does not work. I receive the following message:
>
> "vgdb error: no FIFO found matching pid 5803"
>
>
> "5803" is the pid as reported by vgdb -l.
can you do
vgdb -d -d -d -l
and then
vgdb -d -d -d --pid=12345 help
(assuming 12345 is the pid of the mysql process).
That should give detailed tracing about which FIFOs are found
and/or tried by both vgdb commands.
Note that you have to run vgdb in a context
which is similar to the context of the process you
are trying to contact.
Typically, TMPDIR and the user launching vgdb must be the same
as TMPDIR value and user of the process you are trying to contact.
Philippe
|
|
From: Christian P. <chr...@gm...> - 2015-02-01 23:00:48
|
2015-02-01 20:54 GMT+00:00 Philippe Waroquiers < phi...@sk...>: > On Sun, 2015-02-01 at 20:39 +0000, Christian Priebe wrote: > > > > > It unfortunately does not work. I receive the following message: > > > > "vgdb error: no FIFO found matching pid 5803" > > > > > > "5803" is the pid as reported by vgdb -l. > > can you do > vgdb -d -d -d -l > and then > vgdb -d -d -d --pid=12345 help > (assuming 12345 is the pid of the mysql process). > That should give detailed tracing about which FIFOs are found > and/or tried by both vgdb commands. > > Note that you have to run vgdb in a context > which is similar to the context of the process you > are trying to contact. > Typically, TMPDIR and the user launching vgdb must be the same > as TMPDIR value and user of the process you are trying to contact. > Thanks! I actualy made a mistake and ran mysqld under a different user. I'm back to the previous issue that callgrind_control or more specifically vgdb hangs. This is the output I get when running vgdb -d -d -d -pid=... instrumentation on I get the following output: 1422830987.435580 vgdb: using /tmp/vgdb-pipe-from-vgdb-to-7052-by-root-on-??? /tmp/vgdb-pipe-to-vgdb-from-7052-by-root-on-??? /tmp/vgdb-pipe-shared-mem-vgdb-7052-by-root-on-??? 1422830987.435677 opening /tmp/vgdb-pipe-from-vgdb-to-7052-by-root-on-??? write to pid 1422830987.435720 written_by_vgdb_before_sleep 0 seen_by_valgrind_before_sleep 0 1422830987.435720 opened /tmp/vgdb-pipe-from-vgdb-to-7052-by-root-on-??? write to pid fd 4 1422830987.435796 writing write \003 to wake up len 1 notify: 1 1422830987.435811 opening /tmp/vgdb-pipe-to-vgdb-from-7052-by-root-on-??? read cmd result from pid 1422830987.536904 written_by_vgdb_before_sleep 1 seen_by_valgrind_before_sleep 0 1422830987.638022 after sleep written_by_vgdb 1 seen_by_valgrind 0 invoked_written -1 1422830987.638111 attach to 'main' pid 7052 1422830987.638153 attach main pid PTRACE_ATTACH pid 7052 1422830987.638428 waitstopped attach main pid before waitpid signal_expected 19 1422830987.638704 after waitpid pid 7052 p 7052 status 0x137f WIFSTOPPED 19 1422830987.639102 found tid 1 status VgTs_WaitSys lwpid 7052 ... 1422830987.645251 getregs regs_bsz 216 1422830987.645275 getregs PTRACE_GETREGS 1422830987.645289 detected a working PTRACE_GETREGS 1422830987.645302 push bad_return return address ptrace_write_memory 1422830987.645315 Writing 0000000000000000 to 0x804390d18 1422830987.645395 setregs regs_bsz 216 1422830987.645409 setregs PTRACE_SETREGS 1422830987.645424 PTRACE_CONT to invoke 1422830987.645461 waitstopped waitpid status after PTRACE_CONT to invoke before waitpid signal_expected 19 and then it stops doing anything. Thanks, Christian > > Philippe > > > > > |
|
From: Josef W. <Jos...@gm...> - 2015-02-02 10:43:27
|
Am 02.02.2015 um 00:00 schrieb Christian Priebe: > I'm back to the previous issue that callgrind_control or more > specifically vgdb hangs. This is the output I get when running vgdb -d > ... Hmm. Then it looks like a hang in the vgdb handler in callgrind, but I have no idea why. Can you first check if the hang also appears with another callgrind request such as "vgdb --pid=XXX zero", and with another tool (e.g. none) and another vgdb request, like "vgdb --pid=XXX v.wait 500" ? If that works, it would be interesting to see the last lines of Callgrind debug output with "... --ct-verbose=2 ..." (or 3...), but warning: this can be huge, and should be directed to a file (eg. with --log-file=XX). Josef |
|
From: Christian P. <chr...@gm...> - 2015-02-02 11:49:42
|
2015-02-02 10:42 GMT+00:00 Josef Weidendorfer <Jos...@gm...>: > Am 02.02.2015 um 00:00 schrieb Christian Priebe: > > I'm back to the previous issue that callgrind_control or more > > specifically vgdb hangs. This is the output I get when running vgdb -d > > ... > > Hmm. Then it looks like a hang in the vgdb handler in callgrind, but I > have no idea why. > > Can you first check if the hang also appears with another callgrind > request such as > "vgdb --pid=XXX zero", and with another tool (e.g. none) and another vgdb > request, like "vgdb --pid=XXX v.wait 500" ? > > Ok, two observations regarding the zero and instrumentation requests. First of all, the vgdb --pid=XXX zero request behaves the same as the ... instrumentation on request. Second, I occasionally get a different debug output from vgdb which looks like the following: 1422876588.712688 vgdb: using /tmp/vgdb-pipe-from-vgdb-to-1800-by-root-on-??? /tmp/vgdb-pipe-to-vgdb-from-1800-by-root-on-??? /tmp/vgdb-pipe-shared-mem-vgdb-1800-by-root-on-??? 1422876588.712838 opening /tmp/vgdb-pipe-from-vgdb-to-1800-by-root-on-??? write to pid 1422876588.712882 opened /tmp/vgdb-pipe-from-vgdb-to-1800-by-root-on-??? write to pid fd 4 1422876588.712915 writing write \003 to wake up len 1 notify: 1 1422876588.712998 opening /tmp/vgdb-pipe-to-vgdb-from-1800-by-root-on-??? read cmd result from pid 1422876588.712916 written_by_vgdb_before_sleep 0 seen_by_valgrind_before_sleep 0 1422876588.815261 written_by_vgdb_before_sleep 1 seen_by_valgrind_before_sleep 0 1422876588.917737 written_by_vgdb_before_sleep 1 seen_by_valgrind_before_sleep 1 1422876589.020165 written_by_vgdb_before_sleep 1 seen_by_valgrind_before_sleep 1 1422876589.120366 written_by_vgdb_before_sleep 1 seen_by_valgrind_before_sleep 1 ... The same line repeats until I shutdown vgdb. Ok, running "vgdb --pid=XXX v.wait 500" without any tool (i.e. "valgrind bin/mysqld") results in the same output as before: ... 1422877084.623194 getregs regs_bsz 216 1422877084.623215 getregs PTRACE_GETREGS 1422877084.623229 detected a working PTRACE_GETREGS 1422877084.623238 push bad_return return address ptrace_write_memory 1422877084.623248 Writing 0000000000000000 to 0x804792d18 1422877084.623329 setregs regs_bsz 216 1422877084.623338 setregs PTRACE_SETREGS 1422877084.623352 PTRACE_CONT to invoke 1422877084.623827 waitstopped waitpid status after PTRACE_CONT to invoke before waitpid signal_expected 19 So, apparently this has nothing to do with callgrind but with valgrind (or my setup) in general. Thanks again, Christian > If that works, it would be interesting to see the last lines of > Callgrind debug output > with "... --ct-verbose=2 ..." (or 3...), but warning: this can be huge, > and should be > directed to a file (eg. with --log-file=XX). > |
|
From: Josef W. <Jos...@gm...> - 2015-02-02 13:51:54
|
Am 02.02.2015 um 12:49 schrieb Christian Priebe: > The same line repeats until I shutdown vgdb. Ok, running "vgdb --pid=XXX > v.wait 500" without any tool (i.e. "valgrind bin/mysqld") Without a tool specified, the default is memcheck. > So, apparently this has nothing to do with callgrind but with valgrind > (or my setup) in general. Ok, perhaps Philippe has an idea what's going wrong. It is probably good if you could add a bug report. Thanks, Josef |
|
From: Philippe W. <phi...@sk...> - 2015-02-02 21:25:39
|
On Mon, 2015-02-02 at 14:51 +0100, Josef Weidendorfer wrote:
> Am 02.02.2015 um 12:49 schrieb Christian Priebe:
> > The same line repeats until I shutdown vgdb. Ok, running "vgdb --pid=XXX
> > v.wait 500" without any tool (i.e. "valgrind bin/mysqld")
>
> Without a tool specified, the default is memcheck.
>
> > So, apparently this has nothing to do with callgrind but with valgrind
> > (or my setup) in general.
>
> Ok, perhaps Philippe has an idea what's going wrong.
>From the vgdb traces, it looks like all is working at vgdb side,
and that it is the valgrind side that does not properly replies
back to vgdb.
At this stage, I do not see too much what is going wrong.
So, let's capture some more data.
On what distro/platform/... are you running ?
Can you also do the following experiments ?
1. under your user account (so no sudo, etc), do
# in one window:
valgrind sleep 100
# then in another window
vgdb --pid=xxxxxx help
This last help command should output the list of commands supported
by valgrind gdbserver
If that does not work (i.e. vgdb blocks), redo the same but
giving -v -v -v -d -d -d options to valgrind
and -d -d -d option to vgdb
and send the traces
2. If the above works, do the same operations, but with the technique
you use to launch mysql
IIUC, use sudo in one window to launch valgrind
and sudo in another window to launch vgdb
(I am not too sure what the --user=mysql option does/means for mysqld
so no idea if you can really simulate what that does easily).
Again, if that does not work, redo with the -v/-d args as above
3. If the above works, then give options -v/-d to
valgrind that runs mysql
and to the vgdb
As suggested by Josef, you might create a bug in bugzilla so as to
attach the traces (compressed if too big) of the first failing
experiment.
Thanks
Philippe
|
|
From: Christian P. <chr...@gm...> - 2015-02-02 22:23:38
|
2015-02-02 21:26 GMT+00:00 Philippe Waroquiers < phi...@sk...>: > On Mon, 2015-02-02 at 14:51 +0100, Josef Weidendorfer wrote: > > Am 02.02.2015 um 12:49 schrieb Christian Priebe: > > > The same line repeats until I shutdown vgdb. Ok, running "vgdb > --pid=XXX > > > v.wait 500" without any tool (i.e. "valgrind bin/mysqld") > > > > Without a tool specified, the default is memcheck. > > > > > So, apparently this has nothing to do with callgrind but with valgrind > > > (or my setup) in general. > > > > Ok, perhaps Philippe has an idea what's going wrong. > > >From the vgdb traces, it looks like all is working at vgdb side, > and that it is the valgrind side that does not properly replies > back to vgdb. > > At this stage, I do not see too much what is going wrong. > So, let's capture some more data. > > On what distro/platform/... are you running ? > Thanks again to both of you for helping! The "experiments" are run on 64bit Ubuntu 14.04. > > Can you also do the following experiments ? > > 1. under your user account (so no sudo, etc), do > # in one window: > valgrind sleep 100 > # then in another window > vgdb --pid=xxxxxx help > This last help command should output the list of commands supported > by valgrind gdbserver > If that does not work (i.e. vgdb blocks), redo the same but > giving -v -v -v -d -d -d options to valgrind > and -d -d -d option to vgdb > and send the traces > Works fine. > > 2. If the above works, do the same operations, but with the technique > you use to launch mysql > IIUC, use sudo in one window to launch valgrind > and sudo in another window to launch vgdb > (I am not too sure what the --user=mysql option does/means for mysqld > so no idea if you can really simulate what that does easily). > > Again, if that does not work, redo with the -v/-d args as above > > Works fine. The --user=mysql option would result in mysqld being run under the mysql user, but I haven't used this option in any of the recent test runs so it shouldn't matter. > 3. If the above works, then give options -v/-d to > valgrind that runs mysql > and to the vgdb > > As suggested by Josef, you might create a bug in bugzilla so as to > attach the traces (compressed if too big) of the first failing > experiment. > I created a bug report here: https://bugs.kde.org/show_bug.cgi?id=343715 Thanks Christian > > Thanks > > Philippe > > > |