Bug 3350 - globusrun-ws hangs for 2 minutes at startup
: globusrun-ws hangs for 2 minutes at startup
Status: RESOLVED FIXED
: Toolkit Internals
globus_common
: development
: PC FreeBSD
: P3 normal
: ---
Assigned To:
:
:
:
:
  Show dependency treegraph
 
Reported: 2005-05-13 17:02 by
Modified: 2006-04-18 10:18 (History)


Attachments
first 500.000 lines of strace log (372.64 KB, application/x-gzip)
2005-05-19 11:42, Kolia Morev
Details


Note

You need to log in before you can comment on or make changes to this bug.


Description From 2005-05-13 17:02:23
globusrun-ws -submit -c /bin/ls

everything runs as expected except that at startup it waits about 2 minutes with
99% cpu utilization.

A small investigation showed that it hangs on the following line in globusrun_ws.c:

globus_i_test_rc("loading ws-addressing handler",
  globus_extension_activate("globus_handler_ws_addressing"));
------- Comment #1 From 2005-05-16 11:28:33 -------
I also found the bug in source-trees/wsrf/c/samples/counter/test/test_counter.c
on similar line:

    result = globus_extension_activate("globus_handler_ws_addressing");

Tracing it with gdb showed that the bug is somehow connected to libltdl. So I
tried to execute it with different versions of libltdl (without recompiling) and
that didn't help.

Also here is the output of 
strace ./test-counter abc 2>&1 |sort |uniq -c |sort -rn

440372 sigprocmask(SIG_BLOCK, ~[ILL TRAP ABRT EMT FPE BUS SEGV SYS], []) = 0
440371 sigprocmask(SIG_SETMASK, [], NULL)      = 0
440340 close(6)                                = 0
226042 fstat(6, {st_mode=0, st_size=0, ...})   = 0
220174 read(6, "", 16384)                      = 0
146478 read(6, "!<arch>\n/               11148891"..., 4096) = 4096
92206 fstat(6, {st_mode=S_IFBLK|S_ISUID|S_ISGID|0141, st_rdev=makedev(46,
791674928), ...}) = 0
73495 read(6, "!<arch>\n/               11148889"..., 4096) = 4096
73304 read(6, "# libcrypto_gcc32dbg.la - a libt"..., 16384) = 905
73304 open("/usr/local/globus-4.0.0/lib/libcrypto_gcc32dbg.la", O_RDONLY) = 6
73304 open("/usr/local/globus-4.0.0/lib/libcrypto_gcc32dbg.a", O_RDONLY) = 6
73304 access("/usr/local/globus-4.0.0/lib/libcrypto_gcc32dbg.a", F_OK) = 0
48998 read(6, "# libltdl_gcc32dbg.la - a libtoo"..., 16384) = 891
48998 open("/usr/local/globus-4.0.0/lib/libltdl_gcc32dbg.la", O_RDONLY) = 6
48998 open("/usr/local/globus-4.0.0/lib/libltdl_gcc32dbg.a", O_RDONLY) = 6
48998 access("/usr/local/globus-4.0.0/lib/libltdl_gcc32dbg.a", F_OK) = 0
36652 read(6, "# libssl_gcc32dbg.la - a libtool"..., 16384) = 934
36652 open("/usr/local/globus-4.0.0/lib/libssl_gcc32dbg.la", O_RDONLY) = 6
36652 open("/usr/local/globus-4.0.0/lib/libssl_gcc32dbg.a", O_RDONLY) = 6
36652 access("/usr/local/globus-4.0.0/lib/libssl_gcc32dbg.a", F_OK) = 0
24499 read(6, "# libglobus_common_gcc32dbg.la -"..., 16384) = 1002
24499 open("/usr/local/globus-4.0.0/lib/libglobus_common_gcc32dbg.la", O_RDONLY) = 6
24498 open("/usr/local/globus-4.0.0/lib/libglobus_common_gcc32dbg.a", O_RDONLY) = 6
24498 access("/usr/local/globus-4.0.0/lib/libglobus_common_gcc32dbg.a", F_OK) = 0
14796 fstat(6, {st_mode=020, st_size=7310575237517855424, ...}) = 0
12690 fstat(6, {st_mode=S_IFSOCK|S_ISUID|S_ISVTX|0500,
st_size=3702912614262796146, ...}) = 0
12217 read(6, "# libglobus_proxy_ssl_gcc32dbg.l"..., 16384) = 1072
12217 read(6, "# libglobus_openssl_error_gcc32d"..., 16384) = 1205
12217 open("/usr/local/globus-4.0.0/lib/libglobus_proxy_ssl_gcc32dbg.la",
O_RDONLY) = 6
12217 open("/usr/local/globus-4.0.0/lib/libglobus_proxy_ssl_gcc32dbg.a",
O_RDONLY) = 6
12217 open("/usr/local/globus-4.0.0/lib/libglobus_openssl_error_gcc32dbg.la",
O_RDONLY) = 6
12217 open("/usr/local/globus-4.0.0/lib/libglobus_openssl_error_gcc32dbg.a",
O_RDONLY) = 6
12217 access("/usr/local/globus-4.0.0/lib/libglobus_proxy_ssl_gcc32dbg.a", F_OK) = 0
12217 access("/usr/local/globus-4.0.0/lib/libglobus_openssl_error_gcc32dbg.a",
F_OK) = 0
11015 fstat(6, {st_mode=040, st_size=577813151740120192, ...}) = 0
8759 fstat(6, {st_mode=0, st_size=27700461086715440, ...}) = 0
8591 fstat(6, {st_mode=057563, st_size=27700461086715440, ...}) = 0
8443 fstat(6, {st_mode=S_IFSOCK|S_ISUID|S_ISVTX|0500, st_size=27700461086703713,
...}) = 0
7898 fstat(6, {st_mode=S_IFSOCK|S_ISUID|S_ISVTX|0300,
st_size=7449626900397515623, ...}) = 0
6247 fstat(6, {st_mode=0, st_size=27700461086703713, ...}) = 0
6109 read(6, "# libglobus_openssl_gcc32dbg.la "..., 16384) = 1287
6109 open("/usr/local/globus-4.0.0/lib/libglobus_openssl_gcc32dbg.la", O_RDONLY) = 6
6108 open("/usr/local/globus-4.0.0/lib/libglobus_openssl_gcc32dbg.a", O_RDONLY) = 6
6108 access("/usr/local/globus-4.0.0/lib/libglobus_openssl_gcc32dbg.a", F_OK) = 0
.... and more

I'm not a big expert in unix internals, but I think that something is not right
when the same files are opened thousands times on startup.
------- Comment #2 From 2005-05-18 10:38:17 -------
This is likely either a globus_extension problem or a libtool issue.
------- Comment #3 From 2005-05-18 11:05:31 -------
Can you gzip and attach the original strace (unsorted) output, and also step 
into the hanging globus_extension_activate call in gdb, and report which non-
globus line is hanging?
------- Comment #4 From 2005-05-19 11:42:22 -------
Created an attachment (id=617) [details]
first 500.000 lines of strace log

First I wanted to post the full 1.5GB log (it is compressed with bzip2 to
3.8MB), but something is wrong with this bug tracker :)
------- Comment #5 From 2005-12-02 00:07:34 -------
Does this bug still exist with the 4.0.1 release?
------- Comment #6 From 2006-04-18 10:18:04 -------
I am closing this bug out as incomplete since we have not heard from the
submitter for over 4 months.  If it is still an issue and you want to respond
to the request about 4.0.1, feel free to re-open the bug.