You are viewing a plain text version of this content. The canonical link for it is here.
Posted to users@subversion.apache.org by asdf <fi...@yahoo.com> on 2006/08/02 15:57:08 UTC

svn info takes a (relatively) long time to complete

When I first ran the "svn info" command on the root URL of a
repository,
it appeared to hang esp. since it wouldn't respond to a Ctrl+C and the
only way to stop it was to stop the process by Ctrl+Z and then send it
the KILL signal. That's when I noticed that it just takes a (long) time
to run to completion.

I am running two svnserve'd repositories on a Linux host:
    repo1 (20 revisions, on disk size = 221 Mb)
    repo2 (22 revisions, on disk size = 123 Mb)

Running "svn info" on the repository root URL takes a long time (longer
than I expected):

(from the same Linux host where the repositories are hosted)
svn info svn://hostname/repo1
    real    2m7.570s
svn info svn://hostname/repo2
    real    0m49.197s

(from a Windows 2000 system using the official 1.3.2 windows binaries
running under the Cygwin bash shell)
svn info svn://hostname/repo1
    real    3m24.047s
svn info svn://hostname/repo2
    real    3m8.643s

(from a Sun Solaris 9 system running 1.3.2 binaries built from source)
svn info svn://hostname/repo1
    real    8m7.362s
svn info svn://hostname/repo2
    real    8m55.268s

(from a Debian Linux system using prepackaged 1.3.2 binaries)
svn info svn://hostname/repo1
    real    6m29.555s
svn info svn://hostname/repo2
    real    7m7.509s


I am curious as to:
   (a) what happens on the client and server ends when this command
       is run that causes the command to complete in so much time?
   (b) whether this time taken is normal considering that
       "svn -v -R ls" and "svn -v log" don't take too much more time to
       run to completion?
   (c) whether this is a known/documented issue or even an issue at
all?

The repositories are hosted on a Debian Linux system using subversion
1.3.2 built from source, and are being served using svnserve (launched
from inetd via "-i -r /svn"), with authz access control enabled.

Thanks!

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org

Re: svn info takes a (relatively) long time to complete

Posted by asdf <fi...@yahoo.com>.
--- Garrett Rooney <ro...@electricjellyfish.net> wrote:

> 
> Ok, that tells us that it's doing cram-md5 authentication at the
> time.
>  I'd say the problem is likely that either the server or the client
> is
> having trouble generating the appropriate amount of entropy to
> generate random numbers for the auth protocol.  On the server you
> could try rebuilding APR to use /dev/urandom for the random device
> instead of /dev/random, see the --with-devrandom option for APR's
> configure.
> 

Recompiling the server with "--with-devrandom=/dev/urandom" appears to
have fixed this problem.

Thanks!

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org

Re: svn info takes a (relatively) long time to complete

Posted by Garrett Rooney <ro...@electricjellyfish.net>.
On 8/2/06, asdf <fi...@yahoo.com> wrote:
> --- Garrett Rooney <ro...@electricjellyfish.net> wrote:
>
> >
> > That's odd.  It shouldn't be taking so long...  Any chance you could
> > run the client in gdb and see where it's taking so much time?  Just
> > get the command started, then hit control-c part way through and see
> > where it is.
> >
>
> Hi Garrett,
>
> Here is the info from gdb when I ctrl-c interrupt the client (sorry
> about the wrapped lines, Yahoo is pretty annoying this way):
>
> (on Sun Solaris 9)
> GNU gdb 6.0
> Copyright 2003 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and
> you are
> welcome to change it and/or distribute copies of it under certain
> conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB.  Type "show warranty" for
> details.
> This GDB was configured as "sparc-sun-solaris2.9"...
> (gdb) run --username tester --password tester info svn://dev/test
> Starting program: /usr/local/bin/svn --username tester --password
> tester info svn://dev/test
> ^C
> Program received signal SIGINT, Interrupt.
> 0xfe99ec34 in _read () from /usr/lib/libc.so.1
> (gdb) bt
> #0  0xfe99ec34 in _read () from /usr/lib/libc.so.1
> #1  0xfe86d7bc in read () from /usr/lib/libthread.so.1
> #2  0xfeed12c8 in apr_socket_recv (sock=0x56ba0, buf=0x5acf0 "( success
> ( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
>     len=0xffbff094) at sendrecv.c:81
> #3  0xff1cbfe8 in readbuf_input (conn=0x56ba0, data=0x5acf0 "( success
> ( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
>     len=0xffbff094) at subversion/libsvn_ra_svn/marshal.c:247
> (gdb) where
> #0  0xfe99ec34 in _read () from /usr/lib/libc.so.1
> #1  0xfe86d7bc in read () from /usr/lib/libthread.so.1
> #2  0xfeed12c8 in apr_socket_recv (sock=0x56ba0, buf=0x5acf0 "( success
> ( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
>     len=0xffbff094) at sendrecv.c:81
> #3  0xff1cbfe8 in readbuf_input (conn=0x56ba0, data=0x5acf0 "( success
> ( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
>     len=0xffbff094) at subversion/libsvn_ra_svn/marshal.c:247
> (gdb)
> --------------END OUTPUT FROM SUN SOLARIS 9-----------
>
> and here is the output from the Debian Linux system:
> @variable:[~]$ gdb `which svn`
> GNU gdb 6.4.90-debian
> Copyright (C) 2006 Free Software Foundation, Inc.
> GDB is free software, covered by the GNU General Public License, and
> you are
> welcome to change it and/or distribute copies of it under certain
> conditions.
> Type "show copying" to see the conditions.
> There is absolutely no warranty for GDB.  Type "show warranty" for
> details.
> This GDB was configured as "i486-linux-gnu"...(no debugging symbols
> found)
> Using host libthread_db library "/lib/tls/libthread_db.so.1".
>
> (gdb) run --username tester --password tester info svn://dev/test
> Starting program: /usr/bin/svn --username tester --password tester info
> svn://dev/test
> (no debugging symbols found)
> [Thread debugging using libthread_db enabled]
> [New Thread -1484564256 (LWP 3793)]
> (no debugging symbols found)
> Program received signal SIGINT, Interrupt.
> [Switching to Thread -1484564256 (LWP 3793)]
> 0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
> (gdb) where
> #0  0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
> #1  0xa7f5114e in apr_socket_recv () from /usr/lib/libapr-0.so.0
> #2  0xa7db0536 in svn_ra_svn__handle_failure_status () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #3  0xa7db097f in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #4  0xa7db0a15 in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #5  0xa7db0a4b in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #6  0xa7db11b0 in svn_ra_svn_read_item () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #7  0xa7db1210 in svn_ra_svn_read_tuple () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #8  0xa7daba40 in svn_ra_svn__cram_client () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #9  0xa7da77cd in ?? () from /usr/lib/libsvn_ra_svn-1.so.0
> #10 0x08083dd8 in ?? ()
> #11 0x0807f298 in ?? ()
> #12 0x0806b2d0 in ?? ()
> #13 0x0806b2f8 in ?? ()
> #14 0xaff5fdf8 in ?? ()
> #15 0x0807f298 in ?? ()
> #16 0x08086110 in ?? ()
> #17 0xaff5fdf0 in ?? ()
> #18 0x08083dd8 in ?? ()
> #19 0x08086230 in ?? ()
> #20 0x00000000 in ?? ()
> (gdb) bt
> #0  0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
> #1  0xa7f5114e in apr_socket_recv () from /usr/lib/libapr-0.so.0
> #2  0xa7db0536 in svn_ra_svn__handle_failure_status () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #3  0xa7db097f in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #4  0xa7db0a15 in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #5  0xa7db0a4b in svn_ra_svn_flush () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #6  0xa7db11b0 in svn_ra_svn_read_item () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #7  0xa7db1210 in svn_ra_svn_read_tuple () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #8  0xa7daba40 in svn_ra_svn__cram_client () from
> /usr/lib/libsvn_ra_svn-1.so.0
> #9  0xa7da77cd in ?? () from /usr/lib/libsvn_ra_svn-1.so.0
> #10 0x08083dd8 in ?? ()
> #11 0x0807f298 in ?? ()
> #12 0x0806b2d0 in ?? ()
> #13 0x0806b2f8 in ?? ()
> #14 0xaff5fdf8 in ?? ()
> #15 0x0807f298 in ?? ()
> #16 0x08086110 in ?? ()
> #17 0xaff5fdf0 in ?? ()
> #18 0x08083dd8 in ?? ()
> #19 0x08086230 in ?? ()
> #20 0x00000000 in ?? ()
> (gdb) The program is running.  Exit anyway? (y or n) y
> ------------END OUTPUT FROM DEBIAN LINUX---------------------
>
>
> Let me know if you require additional information.
> Thanks!

Ok, that tells us that it's doing cram-md5 authentication at the time.
 I'd say the problem is likely that either the server or the client is
having trouble generating the appropriate amount of entropy to
generate random numbers for the auth protocol.  On the server you
could try rebuilding APR to use /dev/urandom for the random device
instead of /dev/random, see the --with-devrandom option for APR's
configure.

-garrett

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org

Re: svn info takes a (relatively) long time to complete

Posted by asdf <fi...@yahoo.com>.
--- Garrett Rooney <ro...@electricjellyfish.net> wrote:

> 
> That's odd.  It shouldn't be taking so long...  Any chance you could
> run the client in gdb and see where it's taking so much time?  Just
> get the command started, then hit control-c part way through and see
> where it is.
> 

Hi Garrett,

Here is the info from gdb when I ctrl-c interrupt the client (sorry
about the wrapped lines, Yahoo is pretty annoying this way):

(on Sun Solaris 9)
GNU gdb 6.0
Copyright 2003 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and
you are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for
details.
This GDB was configured as "sparc-sun-solaris2.9"...
(gdb) run --username tester --password tester info svn://dev/test
Starting program: /usr/local/bin/svn --username tester --password
tester info svn://dev/test
^C
Program received signal SIGINT, Interrupt.
0xfe99ec34 in _read () from /usr/lib/libc.so.1
(gdb) bt
#0  0xfe99ec34 in _read () from /usr/lib/libc.so.1
#1  0xfe86d7bc in read () from /usr/lib/libthread.so.1
#2  0xfeed12c8 in apr_socket_recv (sock=0x56ba0, buf=0x5acf0 "( success
( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
    len=0xffbff094) at sendrecv.c:81
#3  0xff1cbfe8 in readbuf_input (conn=0x56ba0, data=0x5acf0 "( success
( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
    len=0xffbff094) at subversion/libsvn_ra_svn/marshal.c:247
(gdb) where
#0  0xfe99ec34 in _read () from /usr/lib/libc.so.1
#1  0xfe86d7bc in read () from /usr/lib/libthread.so.1
#2  0xfeed12c8 in apr_socket_recv (sock=0x56ba0, buf=0x5acf0 "( success
( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
    len=0xffbff094) at sendrecv.c:81
#3  0xff1cbfe8 in readbuf_input (conn=0x56ba0, data=0x5acf0 "( success
( ( CRAM-MD5 ) 32:Test projects repository ) ) ",
    len=0xffbff094) at subversion/libsvn_ra_svn/marshal.c:247
(gdb)
--------------END OUTPUT FROM SUN SOLARIS 9-----------

and here is the output from the Debian Linux system:
@variable:[~]$ gdb `which svn`
GNU gdb 6.4.90-debian
Copyright (C) 2006 Free Software Foundation, Inc.
GDB is free software, covered by the GNU General Public License, and
you are
welcome to change it and/or distribute copies of it under certain
conditions.
Type "show copying" to see the conditions.
There is absolutely no warranty for GDB.  Type "show warranty" for
details.
This GDB was configured as "i486-linux-gnu"...(no debugging symbols
found)
Using host libthread_db library "/lib/tls/libthread_db.so.1".

(gdb) run --username tester --password tester info svn://dev/test
Starting program: /usr/bin/svn --username tester --password tester info
svn://dev/test
(no debugging symbols found)
[Thread debugging using libthread_db enabled]
[New Thread -1484564256 (LWP 3793)]
(no debugging symbols found)
Program received signal SIGINT, Interrupt.
[Switching to Thread -1484564256 (LWP 3793)]
0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
(gdb) where
#0  0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
#1  0xa7f5114e in apr_socket_recv () from /usr/lib/libapr-0.so.0
#2  0xa7db0536 in svn_ra_svn__handle_failure_status () from
/usr/lib/libsvn_ra_svn-1.so.0
#3  0xa7db097f in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#4  0xa7db0a15 in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#5  0xa7db0a4b in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#6  0xa7db11b0 in svn_ra_svn_read_item () from
/usr/lib/libsvn_ra_svn-1.so.0
#7  0xa7db1210 in svn_ra_svn_read_tuple () from
/usr/lib/libsvn_ra_svn-1.so.0
#8  0xa7daba40 in svn_ra_svn__cram_client () from
/usr/lib/libsvn_ra_svn-1.so.0
#9  0xa7da77cd in ?? () from /usr/lib/libsvn_ra_svn-1.so.0
#10 0x08083dd8 in ?? ()
#11 0x0807f298 in ?? ()
#12 0x0806b2d0 in ?? ()
#13 0x0806b2f8 in ?? ()
#14 0xaff5fdf8 in ?? ()
#15 0x0807f298 in ?? ()
#16 0x08086110 in ?? ()
#17 0xaff5fdf0 in ?? ()
#18 0x08083dd8 in ?? ()
#19 0x08086230 in ?? ()
#20 0x00000000 in ?? ()
(gdb) bt
#0  0xa7f373de in __read_nocancel () from /lib/tls/libpthread.so.0
#1  0xa7f5114e in apr_socket_recv () from /usr/lib/libapr-0.so.0
#2  0xa7db0536 in svn_ra_svn__handle_failure_status () from
/usr/lib/libsvn_ra_svn-1.so.0
#3  0xa7db097f in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#4  0xa7db0a15 in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#5  0xa7db0a4b in svn_ra_svn_flush () from
/usr/lib/libsvn_ra_svn-1.so.0
#6  0xa7db11b0 in svn_ra_svn_read_item () from
/usr/lib/libsvn_ra_svn-1.so.0
#7  0xa7db1210 in svn_ra_svn_read_tuple () from
/usr/lib/libsvn_ra_svn-1.so.0
#8  0xa7daba40 in svn_ra_svn__cram_client () from
/usr/lib/libsvn_ra_svn-1.so.0
#9  0xa7da77cd in ?? () from /usr/lib/libsvn_ra_svn-1.so.0
#10 0x08083dd8 in ?? ()
#11 0x0807f298 in ?? ()
#12 0x0806b2d0 in ?? ()
#13 0x0806b2f8 in ?? ()
#14 0xaff5fdf8 in ?? ()
#15 0x0807f298 in ?? ()
#16 0x08086110 in ?? ()
#17 0xaff5fdf0 in ?? ()
#18 0x08083dd8 in ?? ()
#19 0x08086230 in ?? ()
#20 0x00000000 in ?? ()
(gdb) The program is running.  Exit anyway? (y or n) y
------------END OUTPUT FROM DEBIAN LINUX---------------------


Let me know if you require additional information.
Thanks!

__________________________________________________
Do You Yahoo!?
Tired of spam?  Yahoo! Mail has the best spam protection around 
http://mail.yahoo.com 

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org

Re: svn info takes a (relatively) long time to complete

Posted by Garrett Rooney <ro...@electricjellyfish.net>.
On 8/2/06, asdf <fi...@yahoo.com> wrote:
> When I first ran the "svn info" command on the root URL of a
> repository,
> it appeared to hang esp. since it wouldn't respond to a Ctrl+C and the
> only way to stop it was to stop the process by Ctrl+Z and then send it
> the KILL signal. That's when I noticed that it just takes a (long) time
> to run to completion.
>
> I am running two svnserve'd repositories on a Linux host:
>     repo1 (20 revisions, on disk size = 221 Mb)
>     repo2 (22 revisions, on disk size = 123 Mb)
>
> Running "svn info" on the repository root URL takes a long time (longer
> than I expected):
>
> (from the same Linux host where the repositories are hosted)
> svn info svn://hostname/repo1
>     real    2m7.570s
> svn info svn://hostname/repo2
>     real    0m49.197s
>
> (from a Windows 2000 system using the official 1.3.2 windows binaries
> running under the Cygwin bash shell)
> svn info svn://hostname/repo1
>     real    3m24.047s
> svn info svn://hostname/repo2
>     real    3m8.643s
>
> (from a Sun Solaris 9 system running 1.3.2 binaries built from source)
> svn info svn://hostname/repo1
>     real    8m7.362s
> svn info svn://hostname/repo2
>     real    8m55.268s
>
> (from a Debian Linux system using prepackaged 1.3.2 binaries)
> svn info svn://hostname/repo1
>     real    6m29.555s
> svn info svn://hostname/repo2
>     real    7m7.509s
>
>
> I am curious as to:
>    (a) what happens on the client and server ends when this command
>        is run that causes the command to complete in so much time?
>    (b) whether this time taken is normal considering that
>        "svn -v -R ls" and "svn -v log" don't take too much more time to
>        run to completion?
>    (c) whether this is a known/documented issue or even an issue at
> all?
>
> The repositories are hosted on a Debian Linux system using subversion
> 1.3.2 built from source, and are being served using svnserve (launched
> from inetd via "-i -r /svn"), with authz access control enabled.

That's odd.  It shouldn't be taking so long...  Any chance you could
run the client in gdb and see where it's taking so much time?  Just
get the command started, then hit control-c part way through and see
where it is.

-garrett

---------------------------------------------------------------------
To unsubscribe, e-mail: users-unsubscribe@subversion.tigris.org
For additional commands, e-mail: users-help@subversion.tigris.org