From: code@khaugsbakk.name
We did `git rebase --rebase-merges` on a branch with merge commits. Including
back merges. The reflog after that showed some weird symbols for
certain merge commits (only merges):
e9c962f2ea0 HEAD@{8}: <binary>�: Merged in <branch> (pull request #4441)
Some merge commits were normal.
No backmerges were affected.
We have a main branch. This other branch was created from the main
branch. It had been kept up to date with backmerges. Then someone did
a rebase on it once it was supposed to go into the main branch soonish.
It looks like the string is uninit. The values are different each time.
§ Bisection
Bisects to d188a60d722 (sequencer: stop exporting GIT_REFLOG_ACTION,
2022-11-09).
§ Reproduction on latest code
Reproduced on `master`, on f65182a99e5 (The ninth batch, 2025-04-24).
§ Gdb
This is the backtrace when I get the apparently uninit. string:
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158#1 0x00005555558740d9 in do_merge (r=0x555555a67020 <the_repo>, commit=0x555555b75cb0,arg=0x555555b2164d"<branch stuff> # Merged in <branch> { (pull request #4464)\nlabel branch-point-9\npick 4026b5ced849724bd3857283b6ad50c8609b6d33 only sh"...,arg_len=125,flags=0,check_todo=0x7fffffffb1e0,opts=0x7fffffffc070)atsequencer.c:4380#2 0x0000555555876629 in pick_commits (r=0x555555a67020 <the_repo>, todo_list=0x7fffffffbf50, opts=0x7fffffffc070) at sequencer.c:5048#3 0x0000555555877eeb in sequencer_continue (r=0x555555a67020 <the_repo>, opts=0x7fffffffc070) at sequencer.c:5480#4 0x000055555563a491 in run_sequencer_rebase (opts=0x7fffffffc330) at builtin/rebase.c:369#5 0x000055555563bc74 in run_specific_rebase (opts=0x7fffffffc330) at builtin/rebase.c:746#6 0x000055555563fe2a in cmd_rebase (argc=0, argv=0x555555a73890, prefix=0x0, repo=0x555555a67020 <the_repo>) at builtin/rebase.c:1878#7 0x0000555555574c0d in run_builtin (p=0x555555a34908 <commands+2280>, argc=2, argv=0x555555a73890, repo=0x555555a67020 <the_repo>) at git.c:480#8 0x00005555555750ca in handle_builtin (args=0x7fffffffd8a0) at git.c:743#9 0x000055555557538c in run_argv (args=0x7fffffffd8a0) at git.c:810#10 0x00005555555759e2 in cmd_main (argc=2, argv=0x7fffffffda30) at git.c:950#11 0x000055555569b0c3 in main (argc=5, argv=0x7fffffffda18) at common-main.c:9
§ No reproduction script
I was unable to reproduce with a simple repo. setup. I tried:
1. Creating a side branch which had a merge
2. The side branch conflicted with the other branch
3. Rebased with `--rebase-merges`
-----
Normal bugreport questionaire follows.
-----
Thank you for filling out a Git bug report!
Please answer the following questions to help us understand your issue.
What did you do before the bug happened? (Steps to reproduce your issue)
`git rebase --rebase-merges` on a branch with merge commits. Including
back merges.
What did you expect to happen? (Expected behavior)
Normal “action” string for the reflog like for example `continue`:
3f90f6ab14d (HEAD -> <branch>) HEAD@{1}: rebase (continue): Merged in <branch> (pull request #4507)
What happened instead? (Actual behavior)
The “action” (or whatever it is) string is arbitrary bytes. Like some
uninit. memory.
What's different between what you expected and what actually happened?
Apparently uninit. string.
Anything else you want to add:
Please review the rest of the bug report below.
You can delete any lines you don't wish to share.
[System Info]
git version:
git version 2.49.0.459.gf65182a99e5
cpu: x86_64
built from commit: f65182a99e545d2f2bc22e6c1c2da192133b16a3
sizeof-long: 8
sizeof-size_t: 8
shell-path: /bin/sh
libcurl: 7.81.0
OpenSSL: OpenSSL 3.0.2 15 Mar 2022
zlib: 1.2.11
SHA-1: SHA1_DC
SHA-256: SHA256_BLK
uname: Linux 6.8.0-58-generic #60~22.04.1-Ubuntu SMP PREEMPT_DYNAMIC Fri Mar 28 16:09:21 UTC 2 x86_64
compiler info: gnuc: 11.4
libc info: glibc: 2.35
$SHELL (typically, interactive shell): /bin/bash
[Enabled Hooks]
Hi Kristoffer
On 28/04/2025 20:40, Kristoffer Haugsbakk wrote:
From: code@khaugsbakk.name
We did `git rebase --rebase-merges` on a branch with merge commits. Including
back merges. The reflog after that showed some weird symbols for
certain merge commits (only merges):
e9c962f2ea0 HEAD@{8}: <binary>�: Merged in <branch> (pull request #4441)
Thanks for reporting this. I'm afraid I'm rather confused. In run_git_commit() we set GIT_REFLOG_ACTION with
strvec_pushf(&cmd.env, GIT_REFLOG_ACTION "=%s", ctx->reflog_message);
ctx is allocated with calloc() so ctx->reflog_message is initially NULL. At the start of pick_commits() we store the result of sequencer_reflog_action() in ctx->reflog_message. That function returns a heap allocation that is not freed until we call replay_opts_release() at the end of the rebase. If we're doing a normal pick rather than a merge we store the result of reflog_message() in ctx->reflog_message. That function returns a string stored in a static strbuf. So when we call do_merge() from pick_commits() ctx->reflog_message should point to a valid string though that string will not hold the correct reflog message for the merge because do_merge() does not call reflog_message().
This is the backtrace when I get the apparently uninit. string:
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158
Thanks for the backtrace. It would be useful to know what's stored in opts->ctx->reflog_message at this point if it's not too much trouble please can you run "print *opts" and "print *opts->ctx" here.
Thanks
Phillip
#1 0x00005555558740d9 in do_merge (r=0x555555a67020 <the_repo>, commit=0x555555b75cb0,
arg=0x555555b2164d "<branch stuff> # Merged in <branch> { (pull request #4464)\nlabel branch-point-9\npick 4026b5ced849724bd3857283b6ad50c8609b6d33 only sh"..., arg_len=125, flags=0, check_todo=0x7fffffffb1e0, opts=0x7fffffffc070) at sequencer.c:4380
#2 0x0000555555876629 in pick_commits (r=0x555555a67020 <the_repo>, todo_list=0x7fffffffbf50, opts=0x7fffffffc070) at sequencer.c:5048
#3 0x0000555555877eeb in sequencer_continue (r=0x555555a67020 <the_repo>, opts=0x7fffffffc070) at sequencer.c:5480
#4 0x000055555563a491 in run_sequencer_rebase (opts=0x7fffffffc330) at builtin/rebase.c:369
#5 0x000055555563bc74 in run_specific_rebase (opts=0x7fffffffc330) at builtin/rebase.c:746
#6 0x000055555563fe2a in cmd_rebase (argc=0, argv=0x555555a73890, prefix=0x0, repo=0x555555a67020 <the_repo>) at builtin/rebase.c:1878
#7 0x0000555555574c0d in run_builtin (p=0x555555a34908 <commands+2280>, argc=2, argv=0x555555a73890, repo=0x555555a67020 <the_repo>) at git.c:480
#8 0x00005555555750ca in handle_builtin (args=0x7fffffffd8a0) at git.c:743
#9 0x000055555557538c in run_argv (args=0x7fffffffd8a0) at git.c:810
#10 0x00005555555759e2 in cmd_main (argc=2, argv=0x7fffffffda30) at git.c:950
#11 0x000055555569b0c3 in main (argc=5, argv=0x7fffffffda18) at common-main.c:9
Hi Phillip
On Tue, Apr 29, 2025, at 11:22, Phillip Wood wrote:
quoted
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158
Thanks for the backtrace. It would be useful to know what's stored in
opts->ctx->reflog_message at this point if it's not too much trouble
please can you run "print *opts" and "print *opts->ctx" here.
Today I ran on f65182a99e5 (The ninth batch, 2025-04-24) at
sequencer.c:1148. I was never able to reproduce this
`opts->ctx->reflog_message` having a weird value with GDB today. The
reflog was also fine.
Then I ran without GDB and I got the weird reflog that I expected.
So I don’t know what `*opts` or `*opts->ctx` looks like here. But I did
find just two minutes ago some old notes about `ctx->reflog_message`:
From: Jeff King <hidden> Date: 2025-04-29 21:58:39
On Tue, Apr 29, 2025 at 09:40:13PM +0200, Kristoffer Haugsbakk wrote:
On Tue, Apr 29, 2025, at 11:22, Phillip Wood wrote:
quoted
quoted
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158
Thanks for the backtrace. It would be useful to know what's stored in
opts->ctx->reflog_message at this point if it's not too much trouble
please can you run "print *opts" and "print *opts->ctx" here.
Today I ran on f65182a99e5 (The ninth batch, 2025-04-24) at
sequencer.c:1148. I was never able to reproduce this
`opts->ctx->reflog_message` having a weird value with GDB today. The
reflog was also fine.
Then I ran without GDB and I got the weird reflog that I expected.
Have you tried building with "make SANITIZE=address,undefined"?
This is a wild guess, but since ctx->reflog_message is pointing to a
static strbuf, it could be a use after free if the strbuf is reallocated
due to another call to reflog_message(), but we are still holding the
old pointer via ctx->reflog_message.
-Peff
On Tue, Apr 29, 2025 at 09:40:13PM +0200, Kristoffer Haugsbakk wrote:
quoted
On Tue, Apr 29, 2025, at 11:22, Phillip Wood wrote:
quoted
quoted
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158
Thanks for the backtrace. It would be useful to know what's stored in
opts->ctx->reflog_message at this point if it's not too much trouble
please can you run "print *opts" and "print *opts->ctx" here.
Today I ran on f65182a99e5 (The ninth batch, 2025-04-24) at
sequencer.c:1148. I was never able to reproduce this
`opts->ctx->reflog_message` having a weird value with GDB today. The
reflog was also fine.
Then I ran without GDB and I got the weird reflog that I expected.
Have you tried building with "make SANITIZE=address,undefined"?
No I haven’t. Thank you. The following is with that `make`.
Still on f65182a99e5 (The ninth batch, 2025-04-24). I eventually[1]
got this:
[1] I run through 19 merge conflicts which I `--continue` (using rerere)
until the rebase is done
detachedHEAD5d96584c836]Mergebranch'<branch>'into<somethingelse>Author:[author]===================================================================87324==ERROR:AddressSanitizer:heap-use-after-freeonaddress0x60300001daa0atpc0x79371ca5df89bp0x7fff8e215a50sp0x7fff8e2151c8READofsize2at0x60300001daa0threadT0#0 0x79371ca5df88 in printf_common ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors_format.inc:553#1 0x79371ca5fbd5 in __interceptor_vsnprintf ../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors.inc:1668#2 0x5702aa6bd851 in strbuf_vaddf /home/kristoffer/programming/git/strbuf.c:415#3 0x5702aa6d2384 in strvec_pushf /home/kristoffer/programming/git/strvec.c:35#4 0x5702aa629087 in run_git_commit /home/kristoffer/programming/git/sequencer.c:1148#5 0x5702aa64c652 in do_merge /home/kristoffer/programming/git/sequencer.c:4363#6 0x5702aa655714 in pick_commits /home/kristoffer/programming/git/sequencer.c:5029#7 0x5702aa659a68 in sequencer_continue /home/kristoffer/programming/git/sequencer.c:5461#8 0x5702a9d0f5ce in run_sequencer_rebase builtin/rebase.c:370#9 0x5702a9d14cd9 in run_specific_rebase builtin/rebase.c:747#10 0x5702a9d23798 in cmd_rebase builtin/rebase.c:1887#11 0x5702a9a3c26c in run_builtin /home/kristoffer/programming/git/git.c:480#12 0x5702a9a3d3d5 in handle_builtin /home/kristoffer/programming/git/git.c:744#13 0x5702a9a3dc2c in run_argv /home/kristoffer/programming/git/git.c:811#14 0x5702a9a3f17c in cmd_main /home/kristoffer/programming/git/git.c:951#15 0x5702a9e77aa3 in main /home/kristoffer/programming/git/common-main.c:9#16 0x79371be29d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58#17 0x79371be29e3f in __libc_start_main_impl ../csu/libc-start.c:392#18 0x5702a9a35384 in _start (/home/kristoffer/programming/git/git+0x12a0384)0x60300001daa0islocated0bytesinsideof24-byteregion[0x60300001daa0,0x60300001dab8)freedbythreadT0here:#0 0x79371cab4c38 in __interceptor_realloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:164#1 0x5702aa7ecdca in xrealloc /home/kristoffer/programming/git/wrapper.c:140#2 0x5702aa6b83b7 in strbuf_grow /home/kristoffer/programming/git/strbuf.c:114#3 0x5702aa6bd8ca in strbuf_vaddf /home/kristoffer/programming/git/strbuf.c:420#4 0x5702aa6476dc in reflog_message /home/kristoffer/programming/git/sequencer.c:3948#5 0x5702aa648e42 in do_reset /home/kristoffer/programming/git/sequencer.c:4059#6 0x5702aa65545e in pick_commits /home/kristoffer/programming/git/sequencer.c:5026#7 0x5702aa659a68 in sequencer_continue /home/kristoffer/programming/git/sequencer.c:5461#8 0x5702a9d0f5ce in run_sequencer_rebase builtin/rebase.c:370#9 0x5702a9d14cd9 in run_specific_rebase builtin/rebase.c:747#10 0x5702a9d23798 in cmd_rebase builtin/rebase.c:1887#11 0x5702a9a3c26c in run_builtin /home/kristoffer/programming/git/git.c:480#12 0x5702a9a3d3d5 in handle_builtin /home/kristoffer/programming/git/git.c:744#13 0x5702a9a3dc2c in run_argv /home/kristoffer/programming/git/git.c:811#14 0x5702a9a3f17c in cmd_main /home/kristoffer/programming/git/git.c:951#15 0x5702a9e77aa3 in main /home/kristoffer/programming/git/common-main.c:9#16 0x79371be29d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58previouslyallocatedbythreadT0here:#0 0x79371cab4c38 in __interceptor_realloc ../../../../src/libsanitizer/asan/asan_malloc_linux.cpp:164#1 0x5702aa7ecdca in xrealloc /home/kristoffer/programming/git/wrapper.c:140#2 0x5702aa6b83b7 in strbuf_grow /home/kristoffer/programming/git/strbuf.c:114#3 0x5702aa6bbeae in strbuf_add /home/kristoffer/programming/git/strbuf.c:313#4 0x5702aa61da33 in strbuf_addstr /home/kristoffer/programming/git/strbuf.h:310#5 0x5702aa64766a in reflog_message /home/kristoffer/programming/git/sequencer.c:3943#6 0x5702aa659637 in sequencer_continue /home/kristoffer/programming/git/sequencer.c:5426#7 0x5702a9d0f5ce in run_sequencer_rebase builtin/rebase.c:370#8 0x5702a9d14cd9 in run_specific_rebase builtin/rebase.c:747#9 0x5702a9d23798 in cmd_rebase builtin/rebase.c:1887#10 0x5702a9a3c26c in run_builtin /home/kristoffer/programming/git/git.c:480#11 0x5702a9a3d3d5 in handle_builtin /home/kristoffer/programming/git/git.c:744#12 0x5702a9a3dc2c in run_argv /home/kristoffer/programming/git/git.c:811#13 0x5702a9a3f17c in cmd_main /home/kristoffer/programming/git/git.c:951#14 0x5702a9e77aa3 in main /home/kristoffer/programming/git/common-main.c:9#15 0x79371be29d8f in __libc_start_call_main ../sysdeps/nptl/libc_start_call_main.h:58SUMMARY:AddressSanitizer:heap-use-after-free../../../../src/libsanitizer/sanitizer_common/sanitizer_common_interceptors_format.inc:553inprintf_commonShadowbytesaroundthebuggyaddress:0x0c067fffbb00:fdfdfdfdfafafdfdfdfdfafafdfdfdfa0x0c067fffbb10:fafafdfdfdfdfafafdfdfdfafafafdfd0x0c067fffbb20:fdfdfafafdfdfdfdfafafdfdfdfdfafa0x0c067fffbb30:fdfdfdfdfafafdfdfdfdfafafdfdfdfd0x0c067fffbb40:fafafdfdfdfdfafafdfdfdfdfafafdfd=>0x0c067fffbb50:fdfafafa[fd]fdfdfafafafdfdfdfafafa0x0c067fffbb60:fdfdfdfafafafdfdfdfafafafdfdfdfa0x0c067fffbb70:fafafdfdfdfafafafdfdfdfafafafdfd0x0c067fffbb80:fdfafafafdfdfdfafafafdfdfdfafafa0x0c067fffbb90:fdfdfdfdfafafdfdfdfafafafdfdfdfd0x0c067fffbba0:fafafdfdfdfafafafdfdfdfdfafafdfdShadowbytelegend(oneshadowbyterepresents8applicationbytes):Addressable:00Partiallyaddressable:01020304050607Heapleftredzone:faFreedheapregion:fdStackleftredzone:f1Stackmidredzone:f2Stackrightredzone:f3Stackafterreturn:f5Stackuseafterscope:f8Globalredzone:f9Globalinitorder:f6Poisonedbyuser:f7Containeroverflow:fcArraycookie:acIntraobjectredzone:bbASaninternal:feLeftallocaredzone:caRightallocaredzone:cbShadowgap:cc==87324==ABORTING
This is a wild guess, but since ctx->reflog_message is pointing to a
static strbuf, it could be a use after free if the strbuf is reallocated
due to another call to reflog_message(), but we are still holding the
old pointer via ctx->reflog_message.
From: Jeff King <hidden> Date: 2025-05-01 13:17:58
On Wed, Apr 30, 2025 at 05:17:38PM +0200, Kristoffer Haugsbakk wrote:
quoted
Have you tried building with "make SANITIZE=address,undefined"?
No I haven’t. Thank you. The following is with that `make`.
Still on f65182a99e5 (The ninth batch, 2025-04-24). I eventually[1]
got this:
[1] I run through 19 merge conflicts which I `--continue` (using rerere)
until the rebase is done
Makes sense. Presumably it triggers in your case but not others because
something about your particular reflog messages causes the strbuf to
reallocate (I guess one of them is a lot longer than the others).
But we should be able to trigger it reliably with this:
And indeed, building with that patch and SANITIZE=address seems to show
the problem reliably with the existing tests in t3430 (it might also
show up without ASan, but probably not as reliably).
Probably the smallest solution is for ctx->reflog_message to copy the
result and always own the memory (and then remember to free it, both at
cleanup and if it is ever overwritten).
But I think the way reflog_message() returns the "buf" member of a
static strbuf is kind of an anti-pattern, exactly because you can get
this kind of subtle re-use. It probably should just return a non-const
pointer, handing over memory ownership to the caller. That would require
adjusting its other callers, too.
So the "smallest" version is perhaps something like this, totally
untested except for confirming that t3430 no longer complains:
On Tue, Apr 29, 2025 at 09:40:13PM +0200, Kristoffer Haugsbakk wrote:
quoted
On Tue, Apr 29, 2025, at 11:22, Phillip Wood wrote:
quoted
quoted
#0 run_git_commit (defmsg=0x555555babe70 "<repo path>/MERGE_MSG", opts=0x7fffffffc070, flags=0) at sequencer.c:1158
Thanks for the backtrace. It would be useful to know what's stored in
opts->ctx->reflog_message at this point if it's not too much trouble
please can you run "print *opts" and "print *opts->ctx" here.
Today I ran on f65182a99e5 (The ninth batch, 2025-04-24) at
sequencer.c:1148. I was never able to reproduce this
`opts->ctx->reflog_message` having a weird value with GDB today. The
reflog was also fine.
Then I ran without GDB and I got the weird reflog that I expected.
Have you tried building with "make SANITIZE=address,undefined"?
This is a wild guess, but since ctx->reflog_message is pointing to a
static strbuf, it could be a use after free if the strbuf is reallocated
due to another call to reflog_message(), but we are still holding the
old pointer via ctx->reflog_message.
Oh, nice insight. I'd forgotten we had callers of reflog_message() that didn't store the result in ctx->reflog_message. One of those callers is in do_reset() which due to the way the todo list gets constructed is likely to be called just before do_merge().
Thanks
Phillip
Hi Peff and Kristoffer
On 01/05/2025 14:17, Jeff King wrote:
On Wed, Apr 30, 2025 at 05:17:38PM +0200, Kristoffer Haugsbakk wrote:
Probably the smallest solution is for ctx->reflog_message to copy the
result and always own the memory (and then remember to free it, both at
cleanup and if it is ever overwritten).
But I think the way reflog_message() returns the "buf" member of a
static strbuf is kind of an anti-pattern, exactly because you can get
this kind of subtle re-use. It probably should just return a non-const
pointer, handing over memory ownership to the caller. That would require
adjusting its other callers, too.
Getting rid of the static buffer would certainly protect us from the use-after-free. The bug here is that we're not calling reflog_message() and storing the result in ctx->reflog_message() to create the correct message in do_merge(). Looking at your patch, having to remember to copy the string returned from reflog_message() is a bit of a pain. I wonder if we could change ctx->reflog_message to be an strbuf and update reflog_message() like so
All of the other callers should can then use use ctx->reflog_message.buf where they were using the return value of reflog_message() before. That would protect us from the use-after-free.
I'll try and put a proper patch together next week that removes the static buffer and starts calling reflog_message() when we're merging.
Best Wishes
Phillip
quoted hunk
So the "smallest" version is perhaps something like this, totally
untested except for confirming that t3430 no longer complains:
From: Jeff King <hidden> Date: 2025-05-01 15:36:39
On Thu, May 01, 2025 at 03:36:13PM +0100, phillip.wood123@gmail.com wrote:
quoted
But I think the way reflog_message() returns the "buf" member of a
static strbuf is kind of an anti-pattern, exactly because you can get
this kind of subtle re-use. It probably should just return a non-const
pointer, handing over memory ownership to the caller. That would require
adjusting its other callers, too.
Getting rid of the static buffer would certainly protect us from the
use-after-free. The bug here is that we're not calling reflog_message() and
storing the result in ctx->reflog_message() to create the correct message in
do_merge(). Looking at your patch, having to remember to copy the string
returned from reflog_message() is a bit of a pain. I wonder if we could
change ctx->reflog_message to be an strbuf and update reflog_message() like
so
Yeah, I agree that would solve the use-after-free. I just wasn't sure if
there would still be a logic bug, though. If we have a sequence like:
/* somebody sets the variable */
ctx->reflog_message = reflog_message(...);
...
/* some caller, possibly far away, uses the function again */
foo(reflog_message(...));
...
/* now the original caller wants to use what it stored */
printf("%s", ctx->reflog_message);
Right now that is a potential use-after-free because of reallocating the
static storage inside reflog_message(). If we teach reflog_message
to store things in ctx->reflog_message always, that use-after-free goes
away, but will the printf() above print the wrong thing?
I wasn't clear on who is setting the value or why. It could be that
doing so is actually _fixing_ a bug (because it should be printing what
comes from the invocation in the foo() call).
I'll try and put a proper patch together next week that removes the static
buffer and starts calling reflog_message() when we're merging.