This is the mail archive of the
gdb-prs@sourceware.org
mailing list for the GDB project.
[Bug breakpoints/10261] New: Excessive filesystem access when inferior binary uses absolute path to sources
- From: "ppluzhnikov at google dot com" <sourceware-bugzilla at sourceware dot org>
- To: gdb-prs at sourceware dot org
- Date: 11 Jun 2009 01:56:21 -0000
- Subject: [Bug breakpoints/10261] New: Excessive filesystem access when inferior binary uses absolute path to sources
- Reply-to: sourceware-bugzilla at sourceware dot org
Discovered this as extreme slowdown in debugging GCC, using
GNU gdb (GDB) 6.8.50.20090610-cvs
It appears that GDB performs bazillion of lstat() calls when sources are
compiled via absolute path.
I have two identical builds of gcc, except one was configured with
../configure
and the other with
/abs/path/to/gcc-svn/configure
Results for "relative" build:
-----------------------------
time ./gdb -q -ex 'rbreak emit_' -ex run -ex quit --args
/usr/local/gcc-svn-install/libexec/gcc/x86_64-unknown-linux-gnu/4.5.0/cc1 /dev/null
...
Breakpoint 47, init_emit_once (line_numbers=0) at ../../gcc/emit-rtl.c:5382
5382 {
real 0m2.050s
user 0m1.928s
sys 0m0.112s
strace -c ./gdb -q -ex 'rbreak emit_' -ex run -ex quit --args
/usr/local/gcc-svn-install/libexec/gcc/x86_64-unknown-linux-gnu/4.5.0/cc1 /dev/null
...
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
83.99 0.043842 83 529 read
8.90 0.004644 141 33 14 wait4
6.85 0.003576 3576 1 clone
0.11 0.000057 0 4092 1 ptrace
0.07 0.000035 0 122 mmap
0.05 0.000028 0 285 brk
0.04 0.000020 0 41 pread
0.00 0.000000 0 261 write
0.00 0.000000 0 137 18 open
0.00 0.000000 0 119 close
0.00 0.000000 0 17 7 stat
0.00 0.000000 0 49 fstat
0.00 0.000000 0 48 2 lstat
Results for "absolute" build:
-----------------------------
time ./gdb -q -ex 'rbreak emit_' -ex run -ex quit --args
/usr/local/gcc-svn-install-abspath/libexec/gcc/x86_64-unknown-linux-gnu/4.5.0/cc1 /dev/null
...
Breakpoint 47, init_emit_once (line_numbers=0) at
/home/ppluzhnikov/Archive/gcc-svn/gcc/emit-rtl.c:5382
5382 {
real 0m11.126s
user 0m3.108s
sys 0m7.908s
It's 5 times slower! Strace shows:
% time seconds usecs/call calls errors syscall
------ ----------- ----------- --------- --------- ----------------
38.99 0.051544 0 2881691 2 lstat
31.62 0.041798 80 524 read
16.44 0.021727 0 728617 18 open
4.47 0.005903 0 728599 close
3.85 0.005091 189 27 11 wait4
3.03 0.004000 4000 1 clone
0.78 0.001034 0 25093 23827 stat
0.30 0.000393 79 5 mremap
0.22 0.000295 295 1 execve
0.18 0.000237 0 2425 readlink
0.06 0.000084 0 261 write
0.03 0.000037 0 622 brk
0.02 0.000021 0 56 ioctl
0.02 0.000021 1 15 2 access
0.01 0.000010 0 4092 1 ptrace
0.00 0.000000 0 49 fstat
Where did the extra 2.9 million calls to lstat(), 700K+ calls to open/close
come from?
This also becomes significantly more pronounced when the source is nested
more deeply, that is when the path to emit-rtl.c is something like
/usr/local/google/tmp/build-v13/gcc-4.4.0-glibc-2.3.6-grte/rpmbuild/BUILD/ppluzhnikov-gcc-4.4.0-glibc-2.3.6/i686-unknown-linux-gnu/gcc-4.4.0/gcc/emit-rtl.c
strace shows long chains like this:
...
write(1, "Breakpoint 1, init_emit_once (li"..., 115) = 115
stat("/usr/local/google/ppluzhnikov/Archive/gcc-svn/gcc/emit-rtl.c",
{st_mode=S_IFREG|0640, st_size=150634, ...}) = 0
open("/usr/local/google/ppluzhnikov/Archive/gcc-svn/gcc/emit-rtl.c", O_RDONLY) = 5
lstat("/usr", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local", {st_mode=S_IFDIR|0755, st_size=4096, ...}) = 0
lstat("/usr/local/google", {st_mode=S_IFDIR|S_ISVTX|0777, st_size=4096, ...}) = 0
lstat("/usr/local/google/ppluzhnikov", {st_mode=S_IFDIR|0750, st_size=4096,
...}) = 0
lstat("/usr/local/google/ppluzhnikov/Archive", {st_mode=S_IFDIR|0755,
st_size=4096, ...}) = 0
lstat("/usr/local/google/ppluzhnikov/Archive/gcc-svn", {st_mode=S_IFDIR|0750,
st_size=4096, ...}) = 0
lstat("/usr/local/google/ppluzhnikov/Archive/gcc-svn/gcc",
{st_mode=S_IFDIR|0750, st_size=20480, ...}) = 0
fstat(5, {st_mode=S_IFREG|0640, st_size=150634, ...}) = 0
mmap(NULL, 151552, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f651bfce000
read(5, "/* Emit RTL for the GCC expander"..., 150634) = 150634
brk(0x10c1000) = 0x10c1000
brk(0x10bd000) = 0x10bd000
munmap(0x7f651bfce000, 151552) = 0
brk(0x10bb000) = 0x10bb000
lseek(5, 140035, SEEK_SET) = 140035
fcntl(5, F_GETFL) = 0x8000 (flags O_RDONLY|O_LARGEFILE)
fstat(5, {st_mode=S_IFREG|0640, st_size=150634, ...}) = 0
mmap(NULL, 4096, PROT_READ|PROT_WRITE, MAP_PRIVATE|MAP_ANONYMOUS, -1, 0) =
0x7f651cedf000
lseek(5, 0, SEEK_CUR) = 140035
read(5, "{\n int i;\n enum machine_mode m"..., 4096) = 4096
write(1, "5382\t{\n", 7) = 7
close(5) = 0
--
Summary: Excessive filesystem access when inferior binary uses
absolute path to sources
Product: gdb
Version: 6.8
Status: UNCONFIRMED
Severity: normal
Priority: P2
Component: breakpoints
AssignedTo: unassigned at sourceware dot org
ReportedBy: ppluzhnikov at google dot com
CC: gdb-prs at sourceware dot org
GCC build triplet: x86_64-unknown-linux-gnu
GCC host triplet: x86_64-unknown-linux-gnu
GCC target triplet: x86_64-unknown-linux-gnu
http://sourceware.org/bugzilla/show_bug.cgi?id=10261
------- You are receiving this mail because: -------
You are on the CC list for the bug, or are watching someone who is.