[svn.haxx.se] · SVN Dev · SVN Users · SVN Org · TSVN Dev · TSVN Users · Subclipse Dev · Subclipse Users · this month's index

BUG: svn enters unkillable state, tracked down to UTF conv in locale!=C

From: Denis Vlasenko <vda.linux_at_googlemail.com>
Date: 2006-07-03 17:28:20 CEST

Hello subversion people,

The below command failed for me:

svn co svn://busybox.net/trunk/busybox

in a rather strange way: it started to eat 100% CPU
doing nothing, ctrl-C doesn't work, kill doesn't kill it too,
only kill -9. Repeatable.

After much of fprintf() insertions I found out that
it enters infinite loop here:

/* Convert SRC_LENGTH bytes of SRC_DATA in CONVSET, store the result
 in *DEST, which is allocated in POOL. */
static svn_error_t *
convert_to_stringbuf (apr_xlate_t *convset,
           const char *src_data,
           apr_size_t src_length,
           svn_stringbuf_t **dest,
           apr_pool_t *pool)
{
 apr_size_t buflen = src_length;
 apr_status_t apr_err;
 apr_size_t srclen = src_length;
 apr_size_t destlen = 0;
 char *destbuf;

 /* Initialize *DEST to an empty stringbuf. */
fprintf(stderr, "%s:%s():%d src_data='%s'\n", __FILE__, __FUNCTION__, __LINE__, src_data); //vda
 *dest = svn_stringbuf_create ("", pool);
fprintf(stderr, "%s:%s():%d\n", __FILE__, __FUNCTION__, __LINE__); //vda
 destbuf = (*dest)->data;

 /* Not only does it not make sense to convert an empty string, but
  apr-iconv is quite unreasonable about not allowing that. */
 if (src_length == 0)
  return SVN_NO_ERROR;

 do
  {
   /* A 1:2 ratio of input characters to output characters should
    be enough for most translations, and conveniently enough, if
    it isn't, we'll grow the buffer size by 2 again. */
   if (destlen == 0)
    buflen *= 2;

   /* Ensure that *DEST has sufficient storage for the translated
    result. */
fprintf(stderr, "%s:%s():%d\n", __FILE__, __FUNCTION__, __LINE__); //vda
   svn_stringbuf_ensure (*dest, buflen + 1);
fprintf(stderr, "%s:%s():%d\n", __FILE__, __FUNCTION__, __LINE__); //vda

   /* Update the destination buffer pointer to the first character
    after already-converted output. */
   destbuf = (*dest)->data + (*dest)->len;

   /* Set up state variables for xlate. */
   destlen = buflen - (*dest)->len;

   /* Attempt the conversion. */
fprintf(stderr, "%s:%s():%d src_length=%d srclen=%d destlen=%d\n", __FILE__, __FUNCTION__, __LINE__, src_length, srclen, destlen); //vda
   apr_err = apr_xlate_conv_buffer (convset,
                   src_data + (src_length - srclen),
                   &srclen,
                   destbuf,
                   &destlen);
fprintf(stderr, "%s:%s():%d: apr_err=%d srclen=%d destlen=%d\n", __FILE__, __FUNCTION__, __LINE__, apr_err, srclen, destlen); //vda

   /* Now, update the *DEST->len to track the amount of output data
    churned out so far from this loop. */
   (*dest)->len += ((buflen - (*dest)->len) - destlen);

  } while (! apr_err && srclen);

 /* If we exited the loop with an error, return the error. */
 if (apr_err)
  /* Can't use svn_error_wrap_apr here because it calls functions in
   this file, leading to infinite recursion. */
{fprintf(stderr, "%s:%s():%d\n", __FILE__, __FUNCTION__, __LINE__); //vda
  return svn_error_create (apr_err, NULL, "Can't recode string");
fprintf(stderr, "%s:%s():%d\n", __FILE__, __FUNCTION__, __LINE__); //vda
}
 /* Else, exited due to success. Trim the result buffer down to the
  right length. */
 (*dest)->data[(*dest)->len] = '\0';

 return SVN_NO_ERROR;
}

The output is:

../subversion/libsvn_subr/error.c:svn_error_wrap_apr():162
../subversion/libsvn_subr/error.c:svn_error_wrap_apr():164
../subversion/libsvn_subr/error.c:svn_error_wrap_apr():169
/.share/usr/src/subversion-1.1.3/apr/misc/unix/errorcodes.c:apr_strerror():390
../subversion/libsvn_subr/error.c:svn_error_wrap_apr():171 errbuf='.'
../subversion/libsvn_subr/utf.c:svn_utf_cstring_to_utf8():588 src='.'
../subversion/libsvn_subr/utf.c:convert_cstring():559 src='.'
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():319 src_data='.'
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():321
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():351 src_length=1 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():357: apr_err=0 srclen=1 destlen=2
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():339
../subversion/libsvn_subr/utf.c:convert_to_stringbuf():341
...<forever>...

I suspected that it has something to do with my locale which
is not C, and indeed, when I unset LC_xxx vars, it worked!

Environment in which it fails:

LC_ALL=ru_RU.koi8r
LC_MESSAGES=ru_RU.koi8r
LANG=ru_RU.koi8r

# locale -a
C
en_US.utf8
POSIX
ru_RU.koi8r
ru_RU.utf8

My system has glibc-2.4 installed if it is important.

In order to get some more data points, I removed all debugging
and then added just this single one in xlate.c:

        translated = iconv(convset->ich, (ICONV_INBUF_TYPE)&inbufptr,
                           inbytes_left, &outbufptr, outbytes_left);
fprintf(stderr, "%s:%s():%d iconv() inbytes_left=%d outbytes_left=%d translated=%d errno=%d inbuf='%s'\n",
__FILE__, __FUNCTION__, __LINE__, *inbytes_left, *outbytes_left, translated, errno, inbuf); //vda

I am getting output like this:
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=5 translated=0 errno=7 inbuf='/root'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=84 inbuf='/root/.subversion'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=22 translated=0 errno=84 inbuf='/root/.subversion/auth'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=33 translated=0 errno=84 inbuf='/root/.subversion/auth/svn.simple'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=35 translated=0 errno=84 inbuf='/root/.subversion/auth/svn.username'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=37 translated=0 errno=84 inbuf='/root/.subversion/auth/svn.ssl.server'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=5 translated=0 errno=84 inbuf='/root'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=84 inbuf='/etc/subversion/servers'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=25 translated=0 errno=2 inbuf='/root/.subversion/servers'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=5 translated=0 errno=2 inbuf='/root'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=22 translated=0 errno=2 inbuf='/etc/subversion/config'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=24 translated=0 errno=2 inbuf='/root/.subversion/config'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=31 translated=0 errno=2 inbuf='svn://busybox.net/trunk/busybox'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=7 translated=0 errno=0 inbuf='busybox'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=7 translated=0 errno=2 inbuf='busybox'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=12 translated=0 errno=2 inbuf='busybox/.svn'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=12 translated=0 errno=2 inbuf='busybox/.svn'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=22 translated=0 errno=2 inbuf='busybox/.svn/text-base'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=22 translated=0 errno=2 inbuf='busybox/.svn/prop-base'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=18 translated=0 errno=2 inbuf='busybox/.svn/props'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=20 translated=0 errno=2 inbuf='busybox/.svn/wcprops'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=16 translated=0 errno=2 inbuf='busybox/.svn/tmp'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=26 translated=0 errno=2 inbuf='busybox/.svn/tmp/text-base'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=26 translated=0 errno=2 inbuf='busybox/.svn/tmp/prop-base'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=22 translated=0 errno=2 inbuf='busybox/.svn/tmp/props'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=24 translated=0 errno=2 inbuf='busybox/.svn/tmp/wcprops'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=24 translated=0 errno=2 inbuf='busybox/.svn/tmp/entries'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=24 translated=0 errno=2 inbuf='busybox/.svn/tmp/entries'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=20 translated=0 errno=2 inbuf='busybox/.svn/entries'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=20 translated=0 errno=2 inbuf='busybox/.svn/entries'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=2 inbuf='busybox/.svn/empty-file'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=27 translated=0 errno=2 inbuf='busybox/.svn/tmp/README.txt'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=27 translated=0 errno=2 inbuf='busybox/.svn/tmp/README.txt'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=2 inbuf='busybox/.svn/README.txt'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=2 inbuf='busybox/.svn/README.txt'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=2 inbuf='busybox/.svn/format.tmp'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=23 translated=0 errno=2 inbuf='busybox/.svn/format.tmp'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=19 translated=0 errno=2 inbuf='busybox/.svn/format'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=19 translated=0 errno=2 inbuf='busybox/.svn/format'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=11 translated=0 errno=2 inbuf='.svn/format'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='5.(䧼J .^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=2 outbytes_left=2 translated=-1 errno=7 inbuf='^M'
....forever...

^M in inbuf string is a Ctrl-M, not '^' + 'M'. errno==7 is E2BIG.

In the very same run with LC_xxx variables unset, I am getting:
...
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=17 translated=0 errno=2 inbuf='busybox/.svn/lock'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=11 translated=0 errno=2 inbuf='.svn/format'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=16 outbytes_left=33 translated=-1 errno=84 inbuf='5.8\>. .^M'
xlate.c:apr_xlate_conv_buffer():353 iconv() inbytes_left=0 outbytes_left=19 translated=0 errno=84 inbuf='busybox/.svn/format'
...
and svn happily continues. NB: errno is different!

The code handles E2BIG as non-error:

fprintf(stderr, "%s:%s():%d iconv() inbytes_left=%d outbytes_left=%d translated=%d errno=%d inbuf='%s'\n",
__FILE__, __FUNCTION__, __LINE__, *inbytes_left, *outbytes_left, translated, errno, inbuf); //vda

        if (translated == (apr_size_t)-1) {
            int rv = errno;
            switch (rv) {

            case E2BIG: /* out of space on output */
                status = 0; /* change table lookup code below if you
                               make this an error */
                break;

Maybe this is a problem?

P.S. inbuf seems like garbage to me. Is that ok?

P.P.S. the full subroutine stack leading to this place is:

svn_io_file_open():
SVN_ERR(svn_path_cstring_from_utf8(&fname_apr, fname, pool));
apr_file_open(new_file, fname_apr, flag | APR_BINARY, perm, pool);
if (status) return svn_error_wrap_apr(status, _("Can't open file '%s'"), svn_path_local_style (fname, pool));
  svn_error_wrap_apr():
  make_error_internal(status, NULL);
  apr_strerror(status, errbuf, sizeof (errbuf));
  svn_utf_cstring_to_utf8(&msg_apr, errbuf, err->pool);
    svn_utf_cstring_to_utf8():
    SVN_ERR(get_ntou_xlate_handle_node(&node, pool));
    err = convert_cstring (dest, src, node, pool);
      convert_cstring():
      SVN_ERR(convert_to_stringbuf(node, src, strlen (src), &destbuf, pool));
        convert_to_stringbuf()
        ...

And it is executed on every file open error, even on those which are
*expected* to fail:

open("busybox/scripts/.svn/text-base/showasm.svn-base", O_RDONLY) = -1 ENOENT (No such file or directory)

There are a lot of such open() calls in normal svn operation
and svn never uses error string (does not print it).
Why do you bother with generating it in the first place?
Maybe you need a "int svn_io_file_open_silent()" which
does not do all this wasted work, but simply returns relevant
errno?

--
vda
---------------------------------------------------------------------
To unsubscribe, e-mail: dev-unsubscribe@subversion.tigris.org
For additional commands, e-mail: dev-help@subversion.tigris.org
Received on Mon Jul 3 17:29:26 2006

This is an archived mail posted to the Subversion Dev mailing list.

This site is subject to the Apache Privacy Policy and the Apache Public Forum Archive Policy.