https://bugs.kde.org/show_bug.cgi?id=377006
--- Comment #3 from zephyrus00jp <[email protected]> --- Description of log directory archive. [1] Description of log files under 4.7.0.1 There are a group of files. (N being 2,3,4,5) - logN-main.txt, - logN-gdb-dddd.txt, - logN-gdb-dddd'.txt - logN-stra.out.gz - logN-crash.txt I ran ~/bin/run-valgrind-test.sh which contains the following command strace -f -o /tmp/stra.out valgrind --verbose --trace-signals=yes --show-mismatched-frees=no --vgdb=yes --vgdb-error=0 --trace-children=yes ~/objdir-tb3/dist/bin/thunderbird-bin strace is used to capture what system calls valgrind was issueing. I used -vgdb=yes, and --vgdb-error=0 to attach to the thunderbird binary that is monitied by thunderbird binary. It turns out that thunderbird binary runs an external program (by fork()) about the time it segfaulted and so I added --tracechildren=yes. (However, I found that the crash occurs on the original process). Anyway, logN-main.txt recorded the log output from the above command line. One of the logN-dddd.txt and logN-dddd'.txt contains the first instance of gdb that is attached to the thunderbird process under valgrind/memcheck. I set a few breakpoints at main and at fork, and let it run. I dumped the mmap layout by printing /proc/PID/maps (PID being the process id of the thunderbird process). logN-stra.out.gz contains the recoding from strace. logN-crash.txt contains the last part of the strace output (logN-stra.out.gz) and a few comments regarding the particular test run. Under the particular version of 4.7.0.1 (which is Debian-supplied), valgrind invokes another process by fork(), and when it happens, valgrind suggests that I attach another gdb to the sibling process. (--vgdb=yes --vgdb=error), and I do so and run the sibling process under gdb. However, the sibling does not seem to be the culprit. But the original parent process or rather the original valgrind that runs the original thunderbird binary seemed to crash. (But note the comment about gdb showing three SIGSEGV and the first two (2) are for stack fault and handled by valgrind, and only the third one being the fatal SIGSEGV later in this post. (In the discussion of 4-9-x-dir/log5-main.txt ) Anyway, you can see that valgrind experiences SIGSEGV eventually. I did not include the case where I stepped through the parent valgrind+thunderbird execution by stepping using "c" for continue and "fun" for function level trace. In one case, the crash did not happen and thunderbird ran to completion without experiencing the crash. So the issue is timing-related and race condition exists somewhere in the code (on the valgrind side as well.) [2] log under 4.9.x kernel test runs There are files (N=1,2,3,4) - logN-main.txt - logN-error.txt - logN-stra.out.dddd.gz - logN-gdb-ddd.txt logN-main.txt contains the log/print from running the following command line: strace -ff -o /tmp/stra.out valgrind --verbose --trace-signals=yes --show-mismatched-frees=no --vgdb=yes --vgdb-error=0 --trace-children=yes /NREF-COMM-CENTRAL/objdir-tb3/dist/bin/thunderbird-bin (Sorry, this is on a different machine with different file layout. this is on 4 core machine.) logN-gdb-ddd.txt: logN-gdb-ddd.txt contains the log from the attaching gdb. Since the SIGSEGV occurs way before the child process is forked(), there is only one log from the instance of gdb that is attached to the thunderbird binary monitored under valgrind/memcheck. As in the case of kernel 4.7.0.1, I set breakpoint on main, fork and in a few cases, dlopen, but under kernel 4.7.0.1, valgrind crashes way before fork is called and thus I only dumped /proc/PID/maps at the breakpoint placed at the entry of main(). logN-stra.out.dddd.gz: this contains the strace output. logN-error.txt: (I am afraid I emptied log2-error.txt by mistake....) This contains the last part of logN-stra.out.ddd.gz and a comment. For example, log1-error.txt contains this. --- begin quote valgrind crashed even before I had chance to place a breakpoint, i.e., before --vgdb-error=0 took effect!? gettid() = 2851 mmap(0x803041000, 16384, PROT_READ|PROT_WRITE|PROT_EXEC, MAP_PRIVATE|MAP_FIXED|MAP_ANONYMOUS, 0, 0) = 0x803041000 getpid() = 2851 write(1027, "--2851-- REDIR: 0x52e68b0 (libst"..., 115) = 115 --- SIGSEGV {si_signo=SIGSEGV, si_code=SEGV_MAPERR, si_addr=0xffeffa24c} --- +++ killed by SIGSEGV +++ --- end quote So the situation is highly timing dependent / racy. log5-main.txt: this is very interesting. I ran valgrind under gdb. And then issued to gdb run --verbose --trace-signals=yes --show-mismatched-frees=no --vgdb=yes --vgdb-error=0 --trace-children=yes /NREF-COMM-CENTRAL/objdir-tb3/dist/bin/thunderbird-bin With this log, you can see that valgrind DOES experience SIGSEGV, but it uses SIGSEGV internally to catch stack over(?)/under(?) flow and adjust the stack and continue. (I came to recognize this after I saw the signal tracking log lines from valgrind.) Previously, as soon as I saw SIGSEGV, I gave up. (And the stack trace is that of signal handler for SIGSEGV (???), and it is not printed as in the usual case???. That prompted my giving up also.) In this log file, log5-main.txt, for the first two SIGSEGV cases, I dumped stack and register (info register), and then continued with "c" for cont. To my surprise, valgrind happily continued. Only at the third SIGSEGV, valgrind crashes. This may give us some clue on the nature of the crash? [3] 3.19.5 log from successful runs. This was captured under 3.19.5 kernel. This shows the success runs and what messages ought to be printed by successful valgrind run. There are files (N=1,2,3) logN-main.txt: co I ran the following command. strace -ff -o /tmp/stra.out valgrind --verbose --trace-signals=yes --show-mismatched-frees=no --vgdb=yes --vgdb-error=0 --trace-children=yes /NREF-COMM-CENTRAL/objdir-tb3/dist/bin/thunderbird-bin Under the kernel 3.19.5 which I used, valgrind does not crash, and thus the initial run of log1-main.txt had to be interrupted midway because the strace output became too large: it had to be removed from the upload, too. But for the two subsequent runs, log2-main.txt and log3-main.txt, I exited thunderbird runs after the initial profile selection menu comes up: I simply exited from there. By that time, though, the sibling process to probe the graphics adaptor was invoked and exited successfully. logN-gdb-ddd.txt, logN-gdb-ddd'.txt: I attach gdb to the initial thunderbird process and the subsequent sibling process that is forked from the original process. logN-stra.out.ddd.gz: the strace output for the initial valgrind process. There are only two of them: 3-19-5-dir/log2-stra.out.10447.gz 3-19-5-dir/log3-stra.out.10973.gz For the first test run, it became too large since I followed the execution until initial windows came up. I had to drop it before uploading. The immediate change you will notice is the slight change of mmap. Somehow the initial process's stack is NOT at the end, but somewhere earlier. The successful case shows many signal handling dump. I wondery why we do not see them in the failed cases. That may be related to the root cause(s) of the crash. Hope this helps someone in figuring out the true nature of the bug or in suggesting some tips for further debugging on my end. TIA -- You are receiving this mail because: You are watching all bug changes.
