Crashes in t/t4058-diff-duplicates.sh

Crashes in t/t4058-diff-duplicates.sh

[Alex Riesen]

Hi,

the test t4058-diff-duplicates reliably dumps core here:

CORE-OF: /home/xxx/yyyyyyy/git/git

DUMPCORE_ARGS:
 9975
 9975
 11
 !home!xxx!yyyyyyy!git!git
DUMPCORE_ARGS_END

PROC-9975:
 root -> /
 cwd -> /home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates
 fd/0 -> /dev/null
 fd/1 -> /dev/pts/7
 fd/2 -> /dev/pts/7
 fd/3 -> /dev/pts/7
 fd/4 -> /dev/pts/7
 fd/5 -> /dev/pts/7
 fd/6 -> /dev/pts/7
 fd/7 -> /dev/pts/7
 fd/8 -> /home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates/.git/index.lock
PROC-9975_END

ENVIRONMENT:
GIT_COMMITTER_NAME=C O Mitter
USER=xxx
GIT_AUTHOR_EMAIL=author@example.com
GIT_TEMPLATE_DIR=/home/xxx/yyyyyyy/git/templates/blt
XDG_SEAT=seat0
TAR_OPTIONS=--atime-preserve
GIT_TEST_DISALLOW_ABBREVIATED_OPTIONS=true
_x05=[0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f]
GIT_EXEC_PATH=/home/xxx/yyyyyyy/git
SSH_AGENT_PID=3796
XDG_SESSION_TYPE=x11
GIT_CEILING_DIRECTORIES=/home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates/..
USER_HOME=/home/xxx
SHLVL=1
LESS=RSX
HOME=/home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates
OLDPWD=/home/xxx/yyyyyyy/git/t
GIT_AUTHOR_DATE=1112354055 +0200
_x35=[0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f]
DESKTOP_SESSION=lightdm-xsession
ZERO_OID=0000000000000000000000000000000000000000
OID_REGEX=[0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f][0-9a-f]
XDG_SEAT_PATH=/org/freedesktop/DisplayManager/Seat0
PAGER=cat
GIT_AUTHOR_NAME=A U Thor
DBUS_SESSION_BUS_ADDRESS=unix:abstract=/tmp/dbus-qjoVRmyD3o,guid=8cdc53ee0598990a001ad838627364a4
u200c=‌
COLORTERM=rxvt-xpm
test_prereq=
GNOME_KEYRING_CONTROL=/run/user/1000/keyring
GIT_TEST_MERGE_ALGORITHM=ort
EMPTY_BLOB=e69de29bb2d1d6434b8b29ae775ad8c2e48c5391
GITPERLLIB=/home/xxx/yyyyyyy/git/perl/build/lib:/home/xxx/yyyyyyy/git/perl/build/lib
LOGNAME=xxx
GIT_ATTR_NOSYSTEM=1
WINDOWID=56623113
_=./t4058-diff-duplicates.sh
GIT_TEST_CHECK_CACHE_TREE=false
XDG_SESSION_CLASS=user
COLORFGBG=15;default
GIT_TEST_DEFAULT_INITIAL_BRANCH_NAME=master
TERM=dumb
XDG_SESSION_ID=2
COLUMNS=80
GIT_TRACE_BARE=1
USER_TERM=rxvt-unicode-256color
GIT_MERGE_VERBOSITY=5
PATH=/home/xxx/yyyyyyy/git/bin-wrappers:/home/xxx/yyyyyyy/git/bin-wrappers:/home/xxx/bin:/usr/local/bin:/usr/bin:/bin:/usr/local/sbin:/usr/sbin:/sbin:/usr/local/bin:/usr/bin:/bin:/usr/local/games:/usr/games
LESSCHARSET=latin1
GDM_LANG=en_US.utf8
GIT_CONFIG_NOSYSTEM=1
XDG_SESSION_PATH=/org/freedesktop/DisplayManager/Session0
XDG_RUNTIME_DIR=/run/user/1000
DISPLAY=:0
GIT_DEFAULT_HASH=sha1
LANG=C
LSAN_OPTIONS=fast_unwind_on_malloc=0:strip_path_prefix=/home/xxx/yyyyyyy/git/:abort_on_error=1
GIT_TRACE2_EVENT_NESTING=100
GNUPGHOME=/home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates/gnupg-home-not-used
SHELL=/bin/bash
MALLOC_CHECK_=3
GIT_TEXTDOMAINDIR=/home/xxx/yyyyyyy/git/po/build/locale
EMPTY_TREE=4b825dc642cb6eb9a060e54bf8d69288fbee4904
MALLOC_PERTURB_=165
OSTYPE=linux-gnu
ASAN_OPTIONS=detect_leaks=0:strip_path_prefix=/home/xxx/yyyyyyy/git/:abort_on_error=1
GIT_COMMITTER_EMAIL=committer@example.com
PWD=/home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates
SHELL_PATH=/bin/sh
PERL_PATH=/usr/bin/perl
LC_ALL=C
GIT_MERGE_AUTOEDIT=no
LC_NUMERIC=C
TZ=UTC
GIT_COMMITTER_DATE=1112354055 +0200
LF=\n
MANPATH=:/home/xxx/share/man
EDITOR=:
GIT_TEST_FSYNC=0
ENVIRONMENT_END

PID_TRACE:
9975 (git) S /home/xxx/yyyyyyy/git/git merge update 
 cwd: /home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates
9653 (t4058-diff-dupl) S /bin/sh ./t4058-diff-duplicates.sh -d -v -i 
 cwd: /home/xxx/yyyyyyy/git/t/trash directory.t4058-diff-duplicates
4932 (bash) S bash 
 cwd: /home/xxx/yyyyyyy/git/t
4924 (urxvt) S urxvt 
 cwd: /home/xxx
1 (init) S init [2]   
 cwd: /
PID_TRACE_END

GDB:
Reading symbols from /home/xxx/yyyyyyy/git/git...
[New LWP 9975]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib/x86_64-linux-gnu/libthread_db.so.1".
Core was generated by `/home/xxx/yyyyyyy/git/git merge update'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x00005629e52f4a00 in traverse_by_cache_tree (info=0x7fff27e7dba8, 
    info=0x7fff27e7dba8, nr_names=2, nr_entries=4, pos=0)
    at unpack-trees.c:807
807			len = ce_namelen(src[0]);
Threads:
  Id   Target Id                        Frame 
* 1    Thread 0x7f408feb8740 (LWP 9975) 0x00005629e52f4a00 in traverse_by_cache_tree (info=0x7fff27e7dba8, info=0x7fff27e7dba8, nr_names=2, nr_entries=4, pos=0) at unpack-trees.c:807
Stack:
new_ce_len = <optimized out>
len = <optimized out>
rc = <optimized out>
o = 0x7fff27e7e930
tree_ce = 0x5629e596e7d0
ce_len = 240
i = 1
src = {0x5629e594a518, 0x5629e596e7d0, 0x5629e596e7d0, 0x0, 0x0, 0x0, 0x0, 0x0, 0x0}
d = <optimized out>
src = {<optimized out>, <optimized out>, <optimized out>, <optimized out>, <optimized out>, <optimized out>, <optimized out>, <optimized out>, <optimized out>}
o = <optimized out>
tree_ce = <optimized out>
ce_len = <optimized out>
i = <optimized out>
d = <optimized out>
new_ce_len = <optimized out>
len = <optimized out>
rc = <optimized out>
#0  0x00005629e52f4a00 in traverse_by_cache_tree (info=0x7fff27e7dba8, info=0x7fff27e7dba8, nr_names=2, nr_entries=4, pos=0) at unpack-trees.c:807
#1  traverse_trees_recursive (n=n@entry=2, dirmask=dirmask@entry=3, df_conflicts=df_conflicts@entry=0, names=names@entry=0x7fff27e7df80, info=info@entry=0x7fff27e7e420) at unpack-trees.c:872
#2  0x00005629e52f5668 in unpack_callback (n=<optimized out>, mask=3, dirmask=3, names=0x7fff27e7df80, info=<optimized out>) at unpack-trees.c:1479
#3  0x00005629e52f3162 in traverse_trees (istate=0x5629e541c980 <the_index>, n=n@entry=2, t=t@entry=0x7fff27e7e6f0, info=info@entry=0x7fff27e7e420) at tree-walk.c:532
#4  0x00005629e52f82fa in unpack_trees (len=len@entry=2, t=t@entry=0x7fff27e7e6f0, o=o@entry=0x7fff27e7e930) at unpack-trees.c:1882
#5  0x00005629e523d2ae in checkout_fast_forward (r=0x5629e541caa0 <the_repo>, head=head@entry=0x5629e594be24, remote=remote@entry=0x5629e594be6c, overwrite_ignore=1) at merge.c:94
#6  0x00005629e5135742 in cmd_merge (argc=<optimized out>, argv=<optimized out>, prefix=<optimized out>) at builtin/merge.c:1578
#7  0x00005629e50c921b in run_builtin (argv=0x7fff27e7f9c0, argc=2, p=0x5629e53ead48 <commands+1608>) at git.c:465
#8  handle_builtin (argc=2, argv=0x7fff27e7f9c0) at git.c:719
#9  0x00005629e50ca53d in run_argv (argv=0x7fff27e7f700, argcp=0x7fff27e7f70c) at git.c:786
#10 cmd_main (argc=<optimized out>, argc@entry=3, argv=<optimized out>, argv@entry=0x7fff27e7f9b8) at git.c:917
#11 0x00005629e50c8f03 in main (argc=3, argv=0x7fff27e7f9b8) at common-main.c:56
GDB_END

end

P.S. dumpcore (the tool which produced this trace) is this: https://github.com/raalkml/dumpcore

Re: Crashes in t/t4058-diff-duplicates.sh

[Alex Riesen]

Taylor Blau, Fri, May 06, 2022 05:31:12 +0200:
> On Thu, May 05, 2022 at 10:53:45AM +0200, Alex Riesen wrote:
> > Hi,
> >
> > the test t4058-diff-duplicates reliably dumps core here:
> 
> It was a little tricky to find out what part of t4058 you were referring
> to, but...

Very sorry! I forgot to include the output of the test itself!

> > Core was generated by `/home/xxx/yyyyyyy/git/git merge update'.
> 
> ...helps us out ;-). The only match for "git merge update" is in
> t4058.16, which blames back to ac14de13b2 (t4058: explore duplicate tree
> entry handling in a bit more detail, 2020-12-11), which helpfully
> explains that this segfault is known (and furthermore they are
> long-lived and likely not even worth fixing, per ac14de13b2).

Thanks for finding the commit! Makes absolutely sense, but...

I have a little problem with the approach to have it crashing though.
It crashes for every run of the tests: I have a crash core collecting program
on the machine I use to build binaries of the tools I use. While it is not
hard to isolate builds of Git (as a whole) with coredump collecting switched
off I'd prefer to not do it: it's a special case (which gets forgotten) and
with it I'll miss new crashes in Git (which I might have authored).
It is inconvenient to crash regularly.

Is it reasonable to ask to replace the crash in case of this known breakage
with an error()+exit(130)? (`exit(130)` because the test_expect_failure seems
to require an exit code greater than 129, and I failed to find where it is).

Or, since the test-lib already has a notion of "expected failure" provide
the *tests* with a way to reduce collateral effects of that failure?
Like below with the GDB.

Regards,
Alex

diff --git a/t/t4058-diff-duplicates.sh b/t/t4058-diff-duplicates.sh
index 54614b814d..b2f9ab07d1 100755
--- a/t/t4058-diff-duplicates.sh
+++ b/t/t4058-diff-duplicates.sh
@@ -132,22 +132,38 @@ test_expect_success 'create a few commits' '
 	rm commit_id up final
 '
 
+may_crash() {
+	local ret
+	if test -n "$GIT_DEBUGGER"
+	then
+		"$@"
+		ret=$?
+	else
+		GIT_DEBUGGER="gdb --batch --return-child-result --nh -ex run --args"
+		export GIT_DEBUGGER
+		"$@"
+		ret=$?
+		unset GIT_DEBUGGER
+	fi
+	return $ret
+}
+
 test_expect_failure 'git read-tree does not segfault' '
 	test_when_finished rm .git/index.lock &&
-	test_might_fail git read-tree --reset base
+	test_might_fail may_crash git read-tree --reset base
 '
 
 test_expect_failure 'reset --hard does not segfault' '
 	test_when_finished rm .git/index.lock &&
 	git checkout base &&
-	test_might_fail git reset --hard
+	test_might_fail may_crash git reset --hard
 '
 
 test_expect_failure 'git diff HEAD does not segfault' '
 	git checkout base &&
 	GIT_TEST_CHECK_CACHE_TREE=false &&
 	git reset --hard &&
-	test_might_fail git diff HEAD
+	test_might_fail may_crash git diff HEAD
 '
 
 test_expect_failure 'can switch to another branch when status is empty' '
@@ -183,7 +199,7 @@ test_expect_success 'switch to base branch and force status to be clean' '
 '
 
 test_expect_failure 'fast-forward from duplicate entries to non-duplicate' '
-	git merge update
+	may_crash git merge update
 '
 
 test_done

Re: Crashes in t/t4058-diff-duplicates.sh

[Junio C Hamano]

Alex Riesen <alexander.riesen@cetitec.com> writes:

> Taylor Blau, Fri, May 06, 2022 05:31:12 +0200:

>> t4058.16, which blames back to ac14de13b2 (t4058: explore duplicate tree

That commit talks about "trees with duplicate entries".  Does it
mean a bad history where a tree object has two or more entries under
the same name?  We should of course be catching these things at fsck
time and rejecting at network transfer time, but I agree it is not a
good excuse for us to segfault.  We should diagnose it as a broken
tree object and actively refuse to proceed by calling die().

Re: Crashes in t/t4058-diff-duplicates.sh

[Elijah Newren]

On Fri, May 6, 2022 at 9:30 AM Junio C Hamano <gitster@pobox.com> wrote:
>
> Alex Riesen <alexander.riesen@cetitec.com> writes:
>
> > Taylor Blau, Fri, May 06, 2022 05:31:12 +0200:
>
> >> t4058.16, which blames back to ac14de13b2 (t4058: explore duplicate tree
>
> That commit talks about "trees with duplicate entries".  Does it
> mean a bad history where a tree object has two or more entries under
> the same name?

Yes.

> We should of course be catching these things at fsck
> time and rejecting at network transfer time, but I agree it is not a
> good excuse for us to segfault.  We should diagnose it as a broken
> tree object and actively refuse to proceed by calling die().

Re: Crashes in t/t4058-diff-duplicates.sh

[Alex Riesen]

Junio C Hamano, Fri, May 06, 2022 18:30:34 +0200:
> Alex Riesen <alexander.riesen@cetitec.com> writes:
> 
> > Taylor Blau, Fri, May 06, 2022 05:31:12 +0200:
> 
> >> t4058.16, which blames back to ac14de13b2 (t4058: explore duplicate tree
> 
> That commit talks about "trees with duplicate entries".  Does it
> mean a bad history where a tree object has two or more entries under
> the same name?  We should of course be catching these things at fsck
> time and rejecting at network transfer time, but I agree it is not a
> good excuse for us to segfault.  We should diagnose it as a broken
> tree object and actively refuse to proceed by calling die().

There seem to be multiple places (according to the the commit above, and these
tests on my machine find two) where something crashes, and while one is easy to
plug with a simple if-NULL check:

Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x000055786ef58a00 in traverse_by_cache_tree (info=0x7fff87d1f400,
    info=0x7fff87d1f400, nr_names=1, nr_entries=4, pos=0)
    at unpack-trees.c:807
807                     len = ce_namelen(src[0]); <--- src[0] is NULL


the other case seems to be more involved:

#0  verify_one (r=r@entry=0x5555e70aeaa0 <the_repo>,
    istate=istate@entry=0x5555e70ae980 <the_index>, it=0x5555e839ab90,
    path=path@entry=0x7ffedea66570) at cache-tree.c:929
929                     if (ce->ce_flags & (CE_STAGEMASK | CE_INTENT_TO_ADD | CE_REMOVE))
(ce cannot be resolved) ----^

Threads:
  Id   Target Id                         Frame
* 1    Thread 0x7f26de550740 (LWP 19565) verify_one (r=r@entry=0x5555e70aeaa0 <the_repo>, istate=istate@entry=0x5555e70ae980 <the_index>, it=0x5555e839ab90, path=path@entry=0x7ffedea66570) at cache-tree.c:929
Stack:
ce = 0x5a5a5a5a5a5a5a5a <--- Poisoned pointer?
sub = 0x0
i = 1
pos = 0
len = 6
tree_buf = {
  alloc = 65,
  len = 33,
  buf = 0x5555e839b530 "100644 inner"
}
new_oid = {
  hash = '\000' <repeats 31 times>,
  algo = 0
}
#0  verify_one (r=r@entry=0x5555e70aeaa0 <the_repo>, istate=istate@entry=0x5555e70ae980 <the_index>, it=0x5555e839ab90, path=path@entry=0x7ffedea66570) at cache-tree.c:929
#1  0x00005555e6e43720 in verify_one (r=r@entry=0x5555e70aeaa0 <the_repo>, istate=istate@entry=0x5555e70ae980 <the_index>, it=0x5555e83777b0, path=path@entry=0x7ffedea66570) at cache-tree.c:888
#2  0x00005555e6e44398 in cache_tree_verify (r=0x5555e70aeaa0 <the_repo>, istate=istate@entry=0x5555e70ae980 <the_index>) at cache-tree.c:968
#3  0x00005555e6f10807 in write_locked_index (istate=0x5555e70ae980 <the_index>, lock=lock@entry=0x7ffedea66740, flags=flags@entry=1) at read-cache.c:3332
#4  0x00005555e6df7456 in cmd_reset (argc=<optimized out>, argv=<optimized out>, prefix=<optimized out>) at builtin/reset.c:551
#5  0x00005555e6d5b21b in run_builtin (argv=0x7ffedea67260, argc=2, p=0x5555e707d0a8 <commands+2472>) at git.c:465
...

Ideas?

Re: Crashes in t/t4058-diff-duplicates.sh

[Taylor Blau]

On Fri, May 06, 2022 at 09:14:07PM -0700, Elijah Newren wrote:
> > That commit talks about "trees with duplicate entries".  Does it
> > mean a bad history where a tree object has two or more entries under
> > the same name?
>
> Yes.
>
> > We should of course be catching these things at fsck
> > time and rejecting at network transfer time, but I agree it is not a
> > good excuse for us to segfault.  We should diagnose it as a broken
> > tree object and actively refuse to proceed by calling die().

Elijah would be able to comment more authoritatively than I could about
whether or not these are easily detect-able. If they are, then I think
it'd be worth doing so and calling die(). But they may be tricker, I
don't know.

Thanks,
Taylor

Re: Crashes in t/t4058-diff-duplicates.sh

[Elijah Newren]

On Mon, May 9, 2022 at 8:23 AM Taylor Blau <me@ttaylorr.com> wrote:
>
> On Fri, May 06, 2022 at 09:14:07PM -0700, Elijah Newren wrote:
> > > That commit talks about "trees with duplicate entries".  Does it
> > > mean a bad history where a tree object has two or more entries under
> > > the same name?
> >
> > Yes.
> >
> > > We should of course be catching these things at fsck
> > > time and rejecting at network transfer time, but I agree it is not a
> > > good excuse for us to segfault.  We should diagnose it as a broken
> > > tree object and actively refuse to proceed by calling die().
>
> Elijah would be able to comment more authoritatively than I could about
> whether or not these are easily detect-able. If they are, then I think
> it'd be worth doing so and calling die(). But they may be tricker, I
> don't know.

It's been a couple years, so I don't remember much.  I think the way I
discovered these issues was that in order to make sure some other code
changes of mine didn't regress on some issues, I was attempting to
recreate problematic cases that had been covered by the code I was
restructuring.  The existing tests related to that code had some
problems, so I was modifying/creating my own testcases, and I
misunderstood the setup of those tests and the checks behind them and
ended up creating trees broken in a *different* way and which was not
covered by the existing code anywhere.  I was already a few tangents
from the focus of my work at the time (the new merge backend), so I
don't think I investigated whether these were easily detectable.  I do
remember being concerned that the necessary checks might be expensive,
and feeling that it'd be unfortunate to add expensive checks for
issues that no one had ever triggered in 15.5 years, and which I only
discovered due to intentionally trying to create a broken tree but
accidentally creating the wrong type of broken tree.

As it was, the new merge backend took a few years of work, and I
probably followed too many tangents along the way.  This particular
issue was a case where it clearly didn't touch code I was modifying
(the merge or diff machinery) and instead triggered in unpack-trees.c
and cache-tree.c.  So, I decided to simply document it in case others
wanted to investigate.

Long story short, I can't comment about the difficulty of detecting
and working around these.  If you've read this email and the commit
message I wrote at the time, then you know everything I remember about
the issue.