Date: Fri, 10 Mar 2006 20:45:14 +1100 From: Peter Jeremy <peterjeremy@optushome.com.au> To: freebsd-ports@freebsd.org Cc: ade@freebsd.org Subject: Excessive startup times following libtool upgrade Message-ID: <20060310094514.GA688@turion.vk2pj.dyndns.org>
next in thread | raw e-mail | index | archive | help
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
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?20060310094514.GA688>