Excessive startup times following libtool upgrade
Peter Jeremy
peterjeremy at optushome.com.au
Fri Mar 10 09:45:17 UTC 2006
I have rebuilt gnucash following the libtool upgrade (admittedly, I
had to downgrade guile to avoid an slib problem). After which gnucash
takes 15 minutes of system time to start (it used to take about a
minute), issuing a ridiculous number of syscalls (30K/sec). I've done
some poking around with ktrace and gdb and believe that the problem is
libtool trying to load shared libraries.
The following excerpt from ktrace show that something isn't taking
"ENOENT" as an answer (and it tried to load libm several times with
similar numbers of attempts). In total, there are just over 24e6
NAMI entries whilst guile starts.
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca1560,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4ed0,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4ed0,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4ed0,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4ed0,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4e80,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4e80,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4e80,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4e80,0,0x1b6)
96506 guile NAMI "/usr/local/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca4e80,0,0x1b6)
96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca5300,0,0x1b6)
96506 guile NAMI "/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xac9f1e0,0,0x1b6)
96506 guile NAMI "/usr/lib/libm.la"
96506 guile RET open -1 errno 2 No such file or directory
96506 guile CALL open(0xaca57c0,0,0x1b6)
96506 guile NAMI "libm.la"
96506 guile RET open -1 errno 2 No such file or directory
When I grep out the NAMI's and count them, the list starts:
2072639 96506 guile NAMI "/usr/local/lib/libm.so"
2072639 96506 guile NAMI "/usr/local/lib/libm.la"
1498371 96506 guile NAMI "/usr/local/lib/libcrypt.so"
1498371 96506 guile NAMI "/usr/local/lib/libcrypt.la"
1133084 96506 guile NAMI "/usr/X11R6/lib/libm.so"
1133084 96506 guile NAMI "/usr/X11R6/lib/libm.la"
975864 96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.so"
975864 96506 guile NAMI "/usr/X11R6/lib/gnucash/libm.la"
788832 96506 guile NAMI "/usr/X11R6/lib/libcrypt.so"
788832 96506 guile NAMI "/usr/X11R6/lib/libcrypt.la"
674658 96506 guile NAMI "/usr/X11R6/lib/gnucash/libcrypt.so"
674658 96506 guile NAMI "/usr/X11R6/lib/gnucash/libcrypt.la"
368497 96506 guile NAMI "/usr/local/lib/libglib-12.la"
223501 96506 guile NAMI "/usr/X11R6/lib/libglib-12.la"
211784 96506 guile NAMI "/usr/local/lib/libz.so"
211784 96506 guile NAMI "/usr/local/lib/libz.la"
199652 96506 guile NAMI "/usr/lib/libm.so"
199651 96506 guile NAMI "libm.la"
...
These numbers strike me as excessive - by 5-6 orders of magnitude.
An arbitrary backtrace within gdb shows that lt_dlopen() is being
fairly extensively recursively called. Whilst it's nice that
shared library dependencies are checked, the algorithm used is
somewhat inefficient:
#3 0x281d0a9c in reallocf () from /lib/libc.so.6
#4 0x281d1f29 in free () from /lib/libc.so.6
#5 0x281249c2 in foreach_dirinpath (search_path=0xa000000 "@", base_name=0xab40550 "libm.la", func=0x281249e0 <find_file_callback>, data1=0xbfbfcf50, data2=0xbfbfcef0) at raw-ltdl.c:2702
#6 0x28124b63 in find_file (search_path=0x9002270 "", base_name=0x9002270 "", pdir=0x9002270) at raw-ltdl.c:2749
#7 0x2812564e in try_dlopen (phandle=0xbfbfcf88, filename=0xab40ae0 "libm.la")at raw-ltdl.c:3172
#8 0x28125eef in lt_dlopenext (filename=0xab40c30 "libm") at raw-ltdl.c:3468
#9 0x2812503e in load_deplibs (handle=0xab401e0, deplibs=0xab3dfb0 " -L/usr/local/lib /usr/local/lib/libguile-ltdl.la /usr/local/lib/libqthreads.la -lcrypt -lm") at raw-ltdl.c:2931
#10 0x28125a7d in try_dlopen (phandle=0xbfbfd084, filename=0xab3ff70 "/usr/local/lib/libguile.la") at raw-ltdl.c:3304
#11 0x28125d8f in lt_dlopen (filename=0x9002270 "") at raw-ltdl.c:3406
#12 0x28125e86 in lt_dlopenext (filename=0xab3ff70 "/usr/local/lib/libguile.la") at raw-ltdl.c:3458
#13 0x2812503e in load_deplibs (handle=0xab3fe10, deplibs=0xab407c0 " -L/usr/local/lib /usr/local/lib/libguile.la /usr/local/lib/libguile-ltdl.la /usr/local/lib/libqthreads.la -lcrypt -lm")at raw-ltdl.c:2931
#14 0x28125a7d in try_dlopen (phandle=0xbfbfd1a4, filename=0xab3cef0 "/usr/local/lib/libgwrap-glib.la") at raw-ltdl.c:3304
#15 0x28125d8f in lt_dlopen (filename=0x9002270 "") at raw-ltdl.c:3406
#16 0x28125e86 in lt_dlopenext (filename=0xab3cef0 "/usr/local/lib/libgwrap-glib.la") at raw-ltdl.c:3458
#17 0x2812503e in load_deplibs (handle=0xab39a00, deplibs=0xab3b620 " -L/usr/local/lib /usr/local/lib/libgwrap-wct.la /usr/local/lib/libgwrap-glib.la /usr/local/lib/libguile.la /usr/local/lib/libguile-ltdl.la /usr/local/lib/libqthreads.la -lcrypt /usr/local/lib/libpopt"...) at raw-ltdl.c:2931
#18 0x28125a7d in try_dlopen (phandle=0xbfbfd2c4, filename=0xa986750 "/usr/X11R6/lib/gnucash/libgw-kvp.la")at raw-ltdl.c:3304
#19 0x28125d8f in lt_dlopen (filename=0x9002270 "") at raw-ltdl.c:3406
#20 0x28125e86 in lt_dlopenext (filename=0xa986750 "/usr/X11R6/lib/gnucash/libgw-kvp.la")at raw-ltdl.c:3458
#21 0x2812503e in load_deplibs (handle=0xaa9e580, deplibs=0xab30340 " -L/usr/local/lib -L/usr/X11R6/lib /usr/X11R6/lib/gnucash/libgncmod-app-file.la /usr/X11R6/lib/gnucash/libgncmod-gnome-utils.la /usr/X11R6/lib/gnucash/libgncmod-network-utils.la /usr/local/lib/libghtt"...)at raw-ltdl.c:2931
#22 0x28125a7d in try_dlopen (phandle=0xbfbfd3e4, filename=0xa520ed0 "/usr/X11R6/lib/gnucash/libgncmod-report-gnome.la")at raw-ltdl.c:3304
#23 0x28125d8f in lt_dlopen (filename=0x9002270 "") at raw-ltdl.c:3406
#24 0x28125e86 in lt_dlopenext (filename=0xa520ed0 "/usr/X11R6/lib/gnucash/libgncmod-report-gnome.la")at raw-ltdl.c:3458
#25 0x2812503e in load_deplibs (handle=0xa639680, deplibs=0xaf28610 " -L/usr/local/lib -L/usr/X11R6/lib /usr/X11R6/lib/gnucash/libgncmod-backend-file.la /usr/X11R6/lib/gnucash/libgncmod-report-gnome.la /usr/X11R6/lib/gnucash/libgncmod-app-file.la /usr/X11R6/lib/libgnc-"...)at raw-ltdl.c:2931
#26 0x28125a7d in try_dlopen (phandle=0xbfbfd504, filename=0xaf2b8c0 "/usr/X11R6/lib/libgncgnome.la") at raw-ltdl.c:3304
#27 0x28125d8f in lt_dlopen (filename=0x9002270 "") at raw-ltdl.c:3406
#28 0x28125e86 in lt_dlopenext (filename=0xaf2b8c0 "/usr/X11R6/lib/libgncgnome.la") at raw-ltdl.c:3458
#29 0x2812503e in load_deplibs (handle=0xaf2b750, deplibs=0xaf2aed0 " -L/usr/local/lib /usr/X11R6/lib/libgncgnome.la -L/usr/X11R6/lib /usr/X11R6/lib/gnucash/libgncmod-backend-file.la /usr/X11R6/lib/gnucash/libgncmod-report-gnome.la /usr/X11R6/lib/gnucash/libgncmod-app-"...) at raw-ltdl.c:2931
#30 0x28125a7d in try_dlopen (phandle=0xbfbfd628, filename=0xa030650 "libgw-gnc.la") at raw-ltdl.c:3304
#31 0x28125eef in lt_dlopenext (filename=0xa030590 "libgw-gnc")at raw-ltdl.c:3468
#32 0x28127a61 in scm_lt_dlopenext (filename=0x9002270 "") at guile-ltdl.c:61
--
Peter Jeremy
More information about the freebsd-ports
mailing list