Concurrency bug with import git refs

[ilyagr]

Description

I see this bug recurrently, about once in a couple of weeks. jj git import sometimes messes up the repo sometimes if it runs concurrently with other operations (which happens because I have an analogue of watch "jj diff -s && jj log --ignore-working-copy" running in a tmux pane continuously). I think the "other operation" was a rebase in almost all cases.

I am using watchman; I'm unsure whether that matters.

Workaround: So far, I've always been able to work around the bug by jj op restore before_conflicting_operations and then repeating the operation that went wrong.

I finally succeeded in recording a reproduction of a reasonable size for it. You can get the repo at https://ilya.gr/share/jj-bug-20240523.tar.gz (~50MB)

The operation log looks as follows. In between d860 and 35ae, I ran a single jj rebase operation. At the same time, a jj diff operation was run by watch. After jj resolved the concurrent operations (operation 35ae), the result was a mess.

The rest of the op log is me recovering from the bug: jj op restore and repeating the rebase.

@  a05414f978fe [email protected] 3 minutes ago, lasted 5
│  milliseconds
│  abandon commit 9dae66458fc522d1a81ab44c02fc3c83ea4b9403
│  and 2 more
│  args: jj abandon 086::
○  5d2aa4186b05 [email protected] 3 minutes ago, lasted 73
│  milliseconds
│  rebase commit 2d43ad3a838bb46add59e22e52cf16e826d76e27
│  and descendants
│  args: jj rebase -s @ -d pr/3617
○  dcc2afa5e6f3 [email protected] 4 minutes ago, lasted 10
│  milliseconds
│  restore to operation
│  d870e8dd678eb95b7766f5f673b392dfe4ea822ed8bab19a20fe6a081d79e0bc1401f1cd471f394ea97d0e060c58556d5be40a9d3ff6585f6b489e07cbc9260f
│  args: jj op restore d870e8dd678e
○    35ae1dcc55fe [email protected] 4 minutes ago, lasted 4
├─╮  milliseconds
│ │  resolve concurrent operations
│ │  args: jj log --ignore-working-copy --no-graph -T  -r
│ │  'none()'
○ │  0493ab9c3be4 [email protected] 4 minutes ago, lasted
│ │  78 milliseconds
│ │  rebase commit 2d43ad3a838bb46add59e22e52cf16e826d76e27
│ │  and descendants
│ │  args: jj rebase -s @ -d pr/3617
│ ○  201621957b98 [email protected] 4 minutes ago, lasted
│ │  10 milliseconds
│ │  import git refs
│ │  args: jj diff --stat '--color=always'
│ ○  ba0f3775b56d [email protected] 4 minutes ago, lasted
├─╯  10 milliseconds
│    import git head
│    args: jj diff --stat '--color=always'
○  d870e8dd678e [email protected] 5 minutes ago, lasted 39
│  milliseconds
│  new empty commit
│  args: jj new --after 9dae664

The transcript is as follows. The "Internal error" is a consequence of the bug, but I've experienced the bug many times without an internal error.

# Start at operation d870
$ jj rebase -s @ -d pr/3617
Rebased 8 commits
Internal error: Failed to check out commit 287ad1d0ea7bb3836dab9c6b031ae8d4fdb0cad4
Caused by: Concurrent checkout

# The bug happened at the above operation.
# We are now at operation 35ae.
# The rest of the transcript is me recovering from the bug.
$ jj op restore d870e8dd678e
Working copy now at: uvyoyr 2d43ad3 (conflict) (empty) (no description set)
Parent commit      : uuwovo?? 9dae664 (conflict) cli: add `jj operation show` and `jj operation diff` commands
Added 1 files, modified 69 files, removed 0 files
Warning: 1 of those updates were skipped because there were conflicting changes in the working copy.
Hint: Inspect the changes compared to the intended target with `jj diff --from 2d43ad3a838b`.
Discard the conflicting changes with `jj restore --from 2d43ad3a838b`.
There are unresolved conflicts at these paths:
CHANGELOG.md                        3-sided conflict
lib/src/default_index/revset_engine.rs 3-sided conflict

$ jj rebase -s @ -d pr/3617
Rebased 8 commits
Working copy now at: uvyoyr cba1061 (empty) (no description set)
Parent commit      : uuwovo?? 33ee8dd pr/3617| cli: add `jj operation show` and `jj operation diff` commands
Added 0 files, modified 69 files, removed 1 files

$ jj abandon 086::
Abandoned the following commits:
  uuwovo?? 9dae664 (conflict) cli: add `jj operation show` and `jj operation diff` commands
  lptunt?? 602fed6 (conflict) repo: add `MutableRepo::merge_index`
  upxwko?? 08624ca (conflict) revset_graph: rename to `graph` and make generic over graph node type
Existing conflicts were resolved or abandoned from these commits:
  uuwovo hidden 9dae664 (conflict) cli: add `jj operation show` and `jj operation diff` commands
  lptunt hidden 602fed6 (conflict) repo: add `MutableRepo::merge_index`
  upxwko hidden 08624ca (conflict) revset_graph: rename to `graph` and make generic over graph node type

Here's a demo of some craziness at the buggy operation 35ae. The conflicts inside the commits are expected, but the branch conflict is a bug.

$ jj branch list --at-op 35ae ilya
ilya (conflicted):
  - toztnq hidden bc20489 (conflict) (empty) Merge of features I use
  - toztnq hidden bc20489 (conflict) (empty) Merge of features I use
  + toztnq?? ed78955 (conflict) (empty) Merge of features I use
  + toztnq?? 287dce9 (conflict) (empty) Merge of features I use
  + toztnq?? ed78955 (conflict) (empty) Merge of features I use
  @git (behind by 4 commits): toztnq?? ed78955 (conflict) (empty) Merge of features I use
  @origin (ahead by 14 commits, behind by 60 commits): toztnq hidden 6782f4f (empty) Merge of features I use

The expected situation would have been:

$ jj branch list --at-op 5d2aa ilya
ilya: toztnq 2fc562d (conflict) (empty) Merge of features I use
  @origin (ahead by 14 commits, behind by 56 commits): toztnq hidden 6782f4f (empty) Merge of features I use

Here's an attempt of showing what the buggy "import git refs" operation did using @bnjmnt4n 's #3617 (thank you!):

# Using https://github.com/martinvonz/jj/pull/3617
$ jj op diff --operation 20162
From operation ba0f3775b56d: import git head
  To operation 201621957b98: import git refs
From operation ba0f3775b56d: import git head
  To operation 201621957b98: import git refs

Changed commits:
○  Modified change luowyrymyomo
│  +luowyr?? 5cd7178 xprotect?? xprotect@git| (conflict)
│  XProtectService
│ ○  Modified change xyzpyrqutwol
│ │  +xyzpyr?? 5564dba brdoc2?? brdoc2@git| (conflict) globs
│ ○  Modified change sklqvkvtynyy
│ │  +sklqvk?? d0d1bb0 (conflict) docs `branches.md`:
│ │  discuss forgetting branch after `jj branch untrack`
│ ○  Modified change mrxkrtssqxlp
│ │  +mrxkrt?? 415a506 (conflict) forget v2
│ ○  Modified change pkszrmpxlokv
│ │  +pkszrm?? e648f2d (conflict) overview of `branch
│ │  delete` and `branch forget`
│ ○  Modified change ulqyqnsxymzk
├─╯  +ulqyqn?? fe0b86f (conflict) push and tracking
From operation ba0f3775b56d: import git head
  To operation 201621957b98: import git refs

Changed commits:
○  Modified change luowyrymyomo
│  +luowyr?? 5cd7178 xprotect?? xprotect@git| (conflict)
│  XProtectService
│ ○  Modified change xyzpyrqutwol
│ │  +xyzpyr?? 5564dba brdoc2?? brdoc2@git| (conflict) globs
│ ○  Modified change sklqvkvtynyy
│ │  +sklqvk?? d0d1bb0 (conflict) docs `branches.md`:
│ │  discuss forgetting branch after `jj branch untrack`
│ ○  Modified change mrxkrtssqxlp
│ │  +mrxkrt?? 415a506 (conflict) forget v2
│ ○  Modified change pkszrmpxlokv
│ │  +pkszrm?? e648f2d (conflict) overview of `branch
│ │  delete` and `branch forget`
│ ○  Modified change ulqyqnsxymzk
├─╯  +ulqyqn?? fe0b86f (conflict) push and tracking
From operation ba0f3775b56d: import git head
  To operation 201621957b98: import git refs

Changed commits:
○  Modified change luowyrymyomo
│  +luowyr?? 5cd7178 xprotect?? xprotect@git| (conflict)
│  XProtectService
│ ○  Modified change xyzpyrqutwol
│ │  +xyzpyr?? 5564dba brdoc2?? brdoc2@git| (conflict) globs
│ ○  Modified change sklqvkvtynyy
│ │  +sklqvk?? d0d1bb0 (conflict) docs `branches.md`:
│ │  discuss forgetting branch after `jj branch untrack`
│ ○  Modified change mrxkrtssqxlp
│ │  +mrxkrt?? 415a506 (conflict) forget v2
│ ○  Modified change pkszrmpxlokv
│ │  +pkszrm?? e648f2d (conflict) overview of `branch
│ │  delete` and `branch forget`
│ ○  Modified change ulqyqnsxymzk
├─╯  +ulqyqn?? fe0b86f (conflict) push and tracking
○  Modified change toztnqoqlqou
│  +toztnq?? ed78955 ilya?? ilya@git| (conflict) (empty)
│  Merge of features I use
○  Modified change uvyoyrvovtzs
   +uvyoyr 287ad1d (empty) (no description set)

Changed local branches:
brdoc2:
+ (added) xyzpyr?? ed82d76 brdoc2??| (conflict) globs
+ (added) xyzpyr?? 5564dba brdoc2?? brdoc2@git| (conflict) globs
+ (removed) xyzpyr hidden 1dd33df (conflict) globs
- xyzpyr?? ed82d76 brdoc2??| (conflict) globs
ilya:
+ (added) toztnq?? 287dce9 ilya??| (conflict) (empty) Merge
of features I use
+ (added) toztnq?? ed78955 ilya?? ilya@git| (conflict) (empt
y) Merge of features I use
+ (removed) toztnq hidden bc20489 (conflict) (empty) Merge o
f features I use
- toztnq?? 287dce9 ilya??| (conflict) (empty) Merge of featu
res I use
xprotect:
+ (added) luowyr?? a893d32 xprotect??| (conflict) XProtectService
+ (added) luowyr?? 5cd7178 xprotect?? xprotect@git| (conflict) XProtectService
+ (removed) luowyr hidden 56e3f3d (conflict) XProtectService
- luowyr?? a893d32 xprotect??| (conflict) XProtectService

Specifications

• Platform: Mac OS ARM
• Version: jj 0.17.1+20240516-eb80305f23be32a6, slightly custom binary from a week ago. (But I've been seeing this bug recurrently for ~a couple of months)

[ilyagr]

This bug immediately happened to me again after I did another rebase. See https://ilya.gr/share/jj-bug-20240523-2.tar.gz (another 50MB file), this instance has fewer distracting and irrelevant file conflicts.

This time, there was no internal error, the problematic operation looked like:

$ # We are at operation cbead13cef3d in the op log below
$ jj rebase -s ilya -d all:ilya-~uvy
Rebased 8 commits
Existing conflicts were resolved or abandoned from these commits:
  luowyr hidden 4d76830 (conflict) XProtectService
  xyzpyr hidden 5e42bc2 (conflict) globs
  sklqvk hidden 0a7e957 (conflict) docs `branches.md`: discuss forgetting branch after `jj branch untrack`
  mrxkrt hidden e0e1f3a (conflict) forget v2
  pkszrm hidden 9272272 (conflict) overview of `branch delete` and `branch forget`
  ulqyqn hidden dda0739 (conflict) push and tracking
Working copy now at: vwvmrw 505c3f2 (empty) (no description set)
Parent commit      : toztnq 685d727 ilya*| (empty) Merge of features I use
Added 1 files, modified 11 files, removed 1 files

There was also a transient message in the watch window on a subsequent jj diff -s: "Reset the working copy parent to the new Git HEAD". The relevant part of the op log is:

○  57c1acb47887 [email protected] 18 minutes ago, lasted 2
│  milliseconds
│  snapshot working copy
│  args: jj diff --stat '--color=always'
○  b2a25ada0054 [email protected] 18 minutes ago, lasted 9
│  milliseconds
│  import git head
│  args: jj diff --stat '--color=always'
○    224ec74964f5 [email protected] 18 minutes ago, lasted
├─╮  4 milliseconds
│ │  resolve concurrent operations
│ │  args: jj log --ignore-working-copy --no-graph -T  -r
│ │  'none()'
○ │  b6fbe2c88bf7 [email protected] 18 minutes ago, lasted
│ │  41 milliseconds
│ │  rebase commit 2fc562d9365fe3e9480ef17cf3e988160e4e9891
│ │  and descendants
│ │  args: jj rebase -s ilya -d 'all:ilya-~uvy'
│ ○  2ca763881656 [email protected] 18 minutes ago, lasted
├─╯  12 milliseconds
│    import git refs
│    args: jj diff --stat '--color=always'
○  cbead13cef3d [email protected] 1 hour ago, lasted 10
│  milliseconds
│  new empty commit
│  args: jj new tozt

---

I have one more older example, but it's ~417MB: https://drive.google.com/file/d/15oWQUrVBtGsOFDPMCnkkzq9uvVrgXoZY/view?usp=drive_link

[yuja]

As I said before, git import/export and jj's tx.commit() can't be atomic. So the background jj process might observe exported git refs and/or HEAD before tx.commit(). Normal refs usually converge, but the HEAD handling is a mess.

In the first example,

○    35ae1dcc55fe [email protected] 4 minutes ago, lasted 4
├─╮  milliseconds
│ │  resolve concurrent operations
│ │  args: jj log --ignore-working-copy --no-graph -T  -r
│ │  'none()'
○ │  0493ab9c3be4 [email protected] 4 minutes ago, lasted
│ │  78 milliseconds
│ │  rebase commit 2d43ad3a838bb46add59e22e52cf16e826d76e27
│ │  and descendants
│ │  args: jj rebase -s @ -d pr/3617
│ ○  201621957b98 [email protected] 4 minutes ago, lasted
│ │  10 milliseconds
│ │  import git refs
│ │  args: jj diff --stat '--color=always'
│ ○  ba0f3775b56d [email protected] 4 minutes ago, lasted
├─╯  10 milliseconds
│    import git head
│    args: jj diff --stat '--color=always'
○  d870e8dd678e [email protected] 5 minutes ago, lasted 39

1. At ba0f3775b56d, the background process observed new exported HEAD, so it imported the new HEAD as @, abandoning the old @. The descendants of @ were rebased, creating branches diverged from the base operation d870e8dd678e.
2. Then, at 201621957b98, new refs rebased by 0493ab9c3be4 got imported, creating branch conflicts.

Perhaps, the main problem here is that import_git_head() abandons the old @ even if it had children. jj new/edit wouldn't abandon old wc under that situation.