Re: segfault when updating with RC9

On Mon, Jun 16, 2008 at 09:09:05PM +0200, Stefan Küng wrote:
> Hi,
>
> Crash report sent for TSVN indicates a problem when updating:
>
> In file subversion\libsvn_wc\update_editor.c, function merge_file(),
> line 2505 the statement:
> oldrev_str = apr_psprintf(pool, ".r%ld%s%s",
> entry->revision,
> *path_ext ? "." : "",
> *path_ext ? path_ext : "");
> can access a NULL entry object.
> From what I can see in the code, entry can be well NULL (there are
> checks for that before), but there can be situations where such a NULL
> entry don't cause the function returning an error but continue to that line.
>
> I don't know exactly what situation causes this though, the crash dump
> doesn't tell that.

That function has more flags controlling the code path than my
brain can comfortably handle. It took me a while to follow the
code, so I'm writing my results up here in detail in order to
save others the time. If you just want to know the end result,
skip past the gory details, to the very end of this mail.

-----------------
The gory details:
-----------------

It certainly seems to be the case that entry is NULL in merge_file
for files that are being added and then modified by the update.

What's exciting is the code path this crash is taking.
Starting from libsvn_wc/update_editor.c, line 2441:

 if (fb->new_text_base_path)

We go in here, cause that is where we're crashing.
It makes sense, because for an added file, there should be
a new text base.

 if (! is_locally_modified && ! is_replaced)
   {
   ...
   }
  else /* working file or obstruction is locally modified... */

We go into the else branch here, even though the file isn't
locally modified cause it's being added. So it's probably
replacing something? But it cannot be replacing anything,
cause is_replaced depends on an entry being present.
Earlier, that function does this:

  if (entry && entry->schedule == svn_wc_schedule_replace)
    is_replaced = TRUE;

We already know there isn't any entry, because that's why we're
crashing. So is_replaced must be FALSE.

So is_locally_modified must be TRUE, since we're taking the else
branch above. How can this be?

The flag is set in 3 different cases. The first one is:

  if (fb->copied_working_text)
    is_locally_modified = TRUE;

It does not apply to us, we're not adding with history.
We know that the file isn't added with history because
the call that's crashing is in the else branch of this
if statement in line 2505: if (fb->added_with_history)

So, these two conditions remain as candidates for toggling
is_locally_modified (which is initially FALSE):

  else if (! fb->existed)
    SVN_ERR(svn_wc__text_modified_internal_p(&is_locally_modified, fb->path,
                                             FALSE, adm_access, FALSE, pool));
  else if (fb->new_text_base_path)
    SVN_ERR(svn_wc__versioned_file_modcheck(&is_locally_modified, fb->path,
                                             adm_access,
                                             fb->new_text_base_path,
                                             FALSE, pool));

If fb->existed is FALSE, we had no obstruction.

Turns out it must be FALSE in order for us to enter this else-if
branch in line 2472, inside which the crash occurs:

          else if (! fb->existed)
            /* Working file exists and has local mods
               or is scheduled for addition but is not an obstruction. */

Right, so entering svn_wc__text_modified_internal_p is the only
possible code path towards the crash.

This is the function's signature:
svn_wc__text_modified_internal_p(svn_boolean_t *modified_p,
                                 const char *filename,
                                 svn_boolean_t force_comparison,
                                 svn_wc_adm_access_t *adm_access,
                                 svn_boolean_t compare_textbases,
                                 apr_pool_t *pool)

First, it does a check to see whether the file exists (on disk):

  /* No matter which way you look at it, the file needs to exist. */
  err = svn_io_stat(&finfo, filename,
                    APR_FINFO_SIZE | APR_FINFO_MTIME | APR_FINFO_TYPE
                    | APR_FINFO_LINK, pool);

If this returns an error, it sets *modified_p to FALSE.
Since we want to find the case where *modified_p ends up
being TRUE, this is not what we're looking for.
For some reason, this function is seeing a file!

So we *do* have an obstruction.
This is where I start wondering why we're still here.
If the file is obstructed, why does add_file(), which must be called
before merge_file() is used to apply further text deltas, succeed?
 
Next, it does this check:

 if (! force_comparison)

We enter here, as we passed FALSE for this flag.

It tries to get the entry in order to do checksum/timestamp
comparison:

      /* Get the entry */
      err = svn_wc_entry(&entry, filename, adm_access, FALSE, pool);

We already know this won't work, so we follow the goto (yay! this
is getting better by the minute) in this statement:

      if (! entry)
        goto compare_them;

This starts off with a nice comment which seems to be
obsoleted by the one following it, no idea why they
are both still there:

compare_them:
 /* If there's no text-base file, we have to assume the working file
     is modified. For example, a file scheduled for addition but not
     yet committed. */
  /* We used to stat for the working base here, but we just give
     compare_and_verify a try; we'll check for errors afterwards */
  textbase_filename = svn_wc__text_base_path(filename, FALSE, pool);

We end up calling:

    err = compare_and_verify(modified_p,
                             filename,
                             adm_access,
                             textbase_filename,
                             compare_textbases,
                             force_comparison,
                             subpool);

Which does a byte-by-byte comparison of the obstruction and
the file the update wants to add. If they don't match, the
file is considered locally modified.

But how can the file exist in the working copy at this point?
The add_file() should have bailed out if the file was obstructed
before the update has started.

I can reproduce this crash by running this script:

  #!/bin/sh
  
  REPOS=/tmp/repos
  WC1=/tmp/wc
  WC2=/tmp/wc2
  
  set -e
  
  # Clean up from previous run
  rm -rf $REPOS $WC1 $WC2
  
  # Create a repository
  svnadmin create $REPOS
  
  # Checkout two working copies
  svn co file://$REPOS $WC1
  svn co file://$REPOS $WC2
  
  # Add a file in WC1, and commit
  echo alpha > $WC1/alpha
  svn add $WC1/alpha
  svn commit -m "added alpha" $WC1
  
  # Modify the file in WC1, and commit again
  echo "alpha, modified" > $WC1/alpha
  svn commit -m "modified alpha" $WC1
  
  gdb svn

  
... and then faking the file to be present in the working
copy from within the debugger:

(gdb) br merge_file
Breakpoint 1 at 0x80c65cc: file subversion/libsvn_wc/update_editor.c, line 2333.
(gdb) run update /tmp/wc2
Starting program: /home/stsp/elego/prefix/svn-1.5.x-prefix/bin/svn up /tmp/wc2
[New LWP 100155]
[New Thread 0x28801100 (LWP 100155)]
[Switching to Thread 0x28801100 (LWP 100155)]

Breakpoint 1, merge_file (content_state=0xbfbfda64, prop_state=0xbfbfda60,
    lock_state=0xbfbfda5c, fb=0x2889c630, pool=0x2889b018)
    at subversion/libsvn_wc/update_editor.c:2333
2333 struct edit_baton *eb = fb->edit_baton;
(gdb) n

<lots of stepping ommitted>

Here I make the svn_io_stat succeed:

(gdb) s
svn_wc__text_modified_internal_p (modified_p=0xbfbfd984,
    filename=0x2889c698 "/tmp/wc2/alpha", force_comparison=0,
    adm_access=0x288551b0, compare_textbases=0, pool=0x2889b018)
    at subversion/libsvn_wc/questions.c:393
393 err = svn_io_stat(&finfo, filename,
(gdb) p filename
$1 = 0x2889c698 "/tmp/wc2/alpha"
(gdb) shell touch /tmp/wc2/alpha
(gdb) n

Stepping on through, we get the crash:

(gdb)

Program received signal SIGSEGV, Segmentation fault.
0x080c6c29 in merge_file (content_state=0xbfbfda64, prop_state=0xbfbfda60,
    lock_state=0xbfbfda5c, fb=0x2889c630, pool=0x2889b018)
    at subversion/libsvn_wc/update_editor.c:2504
2504 oldrev_str = apr_psprintf(pool, ".r%ld%s%s",

Without making the svn_io_stat call succeed, the update works fine:

(gdb) run update /tmp/wc2
Starting program: /home/stsp/elego/prefix/svn-1.5.x-prefix/bin/svn up /tmp/wc2
[New LWP 100139]
[New Thread 0x28801100 (LWP 100139)]
A /tmp/wc2/alpha
Updated to revision 2.

Program exited normally.
(gdb)

------------
The summary:
------------

It looks like something outside of Subversion was sneaking an
obstruction into the working copy while an update was running.
The update was doing an 'add' (where the file wasn't present
in the working copy yet) followed by applying a text-delta
(where the file suddenly was present in the working copy).

I really wonder how this happened to be triggered just by
using Tortoise :/

If someone else finds another way to trigger this, please
let me know.

Stefan