From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: (qmail 16472 invoked by alias); 11 Jun 2009 01:56:22 -0000 Received: (qmail 16458 invoked by uid 48); 11 Jun 2009 01:56:21 -0000 Date: Thu, 11 Jun 2009 01:56:00 -0000 From: "ppluzhnikov at google dot com" To: gdb-prs@sourceware.org Message-ID: <20090611015619.10261.ppluzhnikov@google.com> Reply-To: sourceware-bugzilla@sourceware.org Subject: [Bug breakpoints/10261] New: Excessive filesystem access when inferior binary uses absolute path to sources X-Bugzilla-Reason: CC Mailing-List: contact gdb-prs-help@sourceware.org; run by ezmlm Precedence: bulk List-Id: List-Subscribe: List-Archive: List-Post: List-Help: , Sender: gdb-prs-owner@sourceware.org X-SW-Source: 2009-q2/txt/msg00161.txt.bz2 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.