Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Simultaneous changes on different instances cause incorrect merge #333

Open
gp42 opened this issue Jul 6, 2020 · 0 comments
Open

Simultaneous changes on different instances cause incorrect merge #333

gp42 opened this issue Jul 6, 2020 · 0 comments

Comments

@gp42
Copy link

gp42 commented Jul 6, 2020

It looks like there is a problem in merging files if different changes happen to the same file on different instances of gitfs.

Here are the steps to recreate:

  • Create 3 VMs with gitfs mounted to same repo.
  • Simultaneously (i used tmux + synchronize-panes) add a new file with different content on each vm:
    echo $(hostname) > /mnt/zpool/gitfs/current/foosync.file
  • Waited for sync. This generated 6 commits.
  • Initial 3 commits show expected behaviour (racing to merge changes), but the next 3 commits perform merges and corrupt initial data:
    b"b'dev-rackly-zfstest-1\\n'" instead of dev-rackly-zfstest-1 - this looks like python formatting
  • logs show conflict-solving
Gitfs log
...
July-06-2020 07:05:02 Dummy-4: Router: Cache key for /current: /current
July-06-2020 07:05:02 Dummy-4: Router: Serving /current from cache
July-06-2020 07:05:02 Dummy-4: Call getattr CurrentView with ('/', None)
July-06-2020 07:05:02 Dummy-4: CurrentView: Get attributes {'st_atime': 1594018097.080711, 'st_ctime': 1594018096.2087092, 'st_gid': 0, 'st_mode': 16832, 'st_mtime': 1594018096.2087092, 'st_nlink': 5, 'st_size': 4096, 'st_uid': 0} for /
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call getattr CurrentView with ('/foosync.file', None)
July-06-2020 07:05:02 Dummy-4: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-4: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-4: Call create CurrentView with ('/foosync.file', 33188)
July-06-2020 07:05:02 Dummy-4: CurrentView: Open /foosync.file for read
July-06-2020 07:05:02 Dummy-4: CurrentView: Open /foosync.file for write
July-06-2020 07:05:02 Dummy-4: CurrentView: Created /foosync.file
July-06-2020 07:05:02 Dummy-4: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-4: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-4: Call getattr CurrentView with ('/foosync.file', 6)
July-06-2020 07:05:02 Dummy-4: CurrentView: Get attributes {'st_atime': 1594019102.8608754, 'st_ctime': 1594019102.8608754, 'st_gid': 0, 'st_mode': 33188, 'st_mtime': 1594019102.8608754, 'st_nlink': 1, 'st_size': 0, 'st_uid': 0} for /foosync.file
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call flush CurrentView with ('/foosync.file', 6)
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call lock CurrentView with ('/foosync.file', 6, 6, 140202101849024)
July-06-2020 07:05:02 Dummy-4: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-4: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-4: Call getxattr CurrentView with ('/foosync.file', 'security.capability')
July-06-2020 07:05:02 Dummy-4: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-4: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-4: Call write CurrentView with ('/foosync.file', b'dev-rackly-zfstest-0\n', 0, 6)
July-06-2020 07:05:02 Dummy-4: CurrentView: Wrote 21 to /foosync.file
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call flush CurrentView with ('/foosync.file', 6)
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call lock CurrentView with ('/foosync.file', 6, 6, 140202101849024)
July-06-2020 07:05:02 Dummy-3: Router: Cache key for /current/foosync.file: /current
July-06-2020 07:05:02 Dummy-3: Router: Serving /current/foosync.file from cache
July-06-2020 07:05:02 Dummy-3: Call release CurrentView with ('/foosync.file', 6)
July-06-2020 07:05:02 Dummy-3: CurrentView: Staged /foosync.file for commit
July-06-2020 07:05:02 Dummy-3: Got a new commit job on queue
July-06-2020 07:05:02 SyncWorker: Got a commit job
July-06-2020 07:05:02 Dummy-3: CurrentView: Release /foosync.file
July-06-2020 07:05:07 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:07 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:07 SyncWorker: Get some commits
July-06-2020 07:05:07 SyncWorker: Commit Update /foosync.file with ('dev-rackly-zfstest-0', 'root@dev-rackly-zfstest-0') as author and ('dev-rackly-zfstest-0', 'root@dev-rackly-zfstest-0') as commiter
July-06-2020 07:05:07 SyncWorker: Update commits cache
July-06-2020 07:05:07 SyncWorker: Checkout to HEAD
July-06-2020 07:05:07 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:07 SyncWorker: Check if I'm ahead
July-06-2020 07:05:07 SyncWorker: Start pushing
July-06-2020 07:05:10 SyncWorker: Push done
July-06-2020 07:05:10 SyncWorker: Clear syncing
July-06-2020 07:05:10 SyncWorker: Set sync_done
July-06-2020 07:05:10 SyncWorker: Set push_successful
July-06-2020 07:05:15 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:15 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:15 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:15 SyncWorker: Check if I'm ahead
July-06-2020 07:05:15 SyncWorker: Start pushing
July-06-2020 07:05:16 SyncWorker: Push failed because of cannot push because a reference that you are trying to update on the remote contains commits that are not present locally.
July-06-2020 07:05:16 FetchWorker: Lock fetching operation
July-06-2020 07:05:16 FetchWorker: Start fetching
July-06-2020 07:05:16 SyncWorker: Failed to sync. Going to sleep for 1 seconds
July-06-2020 07:05:16 FetchWorker: Fetch done
July-06-2020 07:05:16 FetchWorker: Wait for 30
July-06-2020 07:05:17 SyncWorker: Retry-ing to sync with remote. Attempt #1
July-06-2020 07:05:17 SyncWorker: Check if I'm ahead
July-06-2020 07:05:17 SyncWorker: I'm behind so I start merging
July-06-2020 07:05:17 SyncWorker: Start fetching
July-06-2020 07:05:17 SyncWorker: Done fetching
July-06-2020 07:05:17 SyncWorker: Start merging
July-06-2020 07:05:17 SyncWorker: Start merging
July-06-2020 07:05:17 SyncWorker: AcceptMine: Copy local branch to merging_local
July-06-2020 07:05:17 SyncWorker: AcceptMine: Copy remote branch to merging_remote
July-06-2020 07:05:17 SyncWorker: AcceptMine: Find diverge commis
July-06-2020 07:05:17 SyncWorker: AcceptMine: Checkout to refs/heads/merging_remote
July-06-2020 07:05:17 SyncWorker: AcceptMine: Merging 66dd9e4c66747dc8f4e985df0a74465bcd298a54
July-06-2020 07:05:17 SyncWorker: AcceptMine: Solving conflicts
July-06-2020 07:05:17 SyncWorker: AcceptMine: overwrite all file with our content
July-06-2020 07:05:17 SyncWorker: AcceptMine: Commiting changes
July-06-2020 07:05:17 SyncWorker: AcceptMine: We have a non-empty commit
July-06-2020 07:05:17 SyncWorker: AcceptMine: Checkout to refs/heads/merging_remote
July-06-2020 07:05:17 SyncWorker: AcceptMine: Clean the state
July-06-2020 07:05:17 SyncWorker: AcceptMine: Checkout to master
July-06-2020 07:05:17 SyncWorker: AcceptMine: Checkout force to branch master
July-06-2020 07:05:17 SyncWorker: AcceptMine: Delete merging_local
July-06-2020 07:05:17 SyncWorker: AcceptMine: Delete merging_remote
July-06-2020 07:05:17 SyncWorker: Update commits cache
July-06-2020 07:05:17 SyncWorker: Update ignore list
July-06-2020 07:05:17 SyncWorker: Merge done with success, ready to push
July-06-2020 07:05:17 SyncWorker: Start pushing
July-06-2020 07:05:20 SyncWorker: Push done
July-06-2020 07:05:20 SyncWorker: Clear syncing
July-06-2020 07:05:20 SyncWorker: Set sync_done
July-06-2020 07:05:20 SyncWorker: Set push_successful
July-06-2020 07:05:25 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:25 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:25 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:25 SyncWorker: Check if I'm ahead
July-06-2020 07:05:25 SyncWorker: Sync done, clearing
July-06-2020 07:05:30 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:30 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:30 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:31 SyncWorker: Check if I'm ahead
July-06-2020 07:05:31 SyncWorker: Sync done, clearing
July-06-2020 07:05:36 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:36 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:36 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:36 SyncWorker: Check if I'm ahead
July-06-2020 07:05:36 SyncWorker: Sync done, clearing
July-06-2020 07:05:41 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:41 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:41 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:41 SyncWorker: Check if I'm ahead
July-06-2020 07:05:41 SyncWorker: Sync done, clearing
July-06-2020 07:05:46 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:46 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:46 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:46 SyncWorker: Check if I'm ahead
July-06-2020 07:05:46 SyncWorker: Sync done, clearing
July-06-2020 07:05:46 FetchWorker: Lock fetching operation
July-06-2020 07:05:46 FetchWorker: Start fetching
July-06-2020 07:05:47 FetchWorker: Fetch done
July-06-2020 07:05:47 FetchWorker: Wait for 30
July-06-2020 07:05:51 SyncWorker: Nothing to do right now, going idle
July-06-2020 07:05:51 SyncWorker: Set syncing event (0 pending writes)
July-06-2020 07:05:51 SyncWorker: Start syncing, first attempt.
July-06-2020 07:05:51 SyncWorker: Check if I'm ahead
July-06-2020 07:05:51 SyncWorker: I'm behind so I start merging
July-06-2020 07:05:51 SyncWorker: Start fetching
July-06-2020 07:05:51 SyncWorker: Done fetching
July-06-2020 07:05:51 SyncWorker: Start merging
July-06-2020 07:05:51 SyncWorker: Start merging
July-06-2020 07:05:51 SyncWorker: AcceptMine: Copy local branch to merging_local
July-06-2020 07:05:51 SyncWorker: AcceptMine: Copy remote branch to merging_remote
July-06-2020 07:05:51 SyncWorker: AcceptMine: Find diverge commis
July-06-2020 07:05:51 SyncWorker: AcceptMine: Checkout to refs/heads/merging_remote
July-06-2020 07:05:51 SyncWorker: AcceptMine: Checkout to master
July-06-2020 07:05:51 SyncWorker: AcceptMine: Checkout force to branch master
July-06-2020 07:05:51 SyncWorker: AcceptMine: Delete merging_local
July-06-2020 07:05:51 SyncWorker: AcceptMine: Delete merging_remote
July-06-2020 07:05:51 SyncWorker: Update commits cache
July-06-2020 07:05:51 SyncWorker: Update ignore list
July-06-2020 07:05:51 SyncWorker: Merge done with success, ready to push
July-06-2020 07:05:51 SyncWorker: Start pushing
July-06-2020 07:05:54 SyncWorker: Push done
July-06-2020 07:05:54 SyncWorker: Clear syncing
July-06-2020 07:05:54 SyncWorker: Set sync_done
July-06-2020 07:05:54 SyncWorker: Set push_successful
...
Last 3 git commits in sequential order (last one below)
commit 301c4d1d09fd87cbfb7a039400dc0d5b698d0042
Merge: 1ae8492 66dd9e4
Author: dev-rackly-zfstest-0 <root@dev-rackly-zfstest-0>
Date:   Mon Jul 6 07:05:17 2020 +0000

    merging: Update /foosync.file

diff --cc foosync.file
index 5cbab9a,88ab997..de6283d
--- a/foosync.file
+++ b/foosync.file
@@@ -1,1 -1,1 +1,1 @@@
- dev-rackly-zfstest-2
 -dev-rackly-zfstest-0
++b'dev-rackly-zfstest-0\n'
commit 77711a2d34e5ccfcbd4514eeefe7970638ce6f32
Merge: 1ae8492 47dd0d6
Author: dev-rackly-zfstest-1 <root@dev-rackly-zfstest-1>
Date:   Mon Jul 6 07:05:18 2020 +0000

    merging: Update /foosync.file

diff --cc foosync.file
index 5cbab9a,12413e6..6afe446
--- a/foosync.file
+++ b/foosync.file
@@@ -1,1 -1,1 +1,1 @@@
- dev-rackly-zfstest-2
 -dev-rackly-zfstest-1
++b'dev-rackly-zfstest-1\n'
commit 2638ddef97f42c74f009deeb8f277bd394e6d2fb (HEAD -> master, origin/master)
Merge: 301c4d1 77711a2
Author: dev-rackly-zfstest-1 <root@dev-rackly-zfstest-1>
Date:   Mon Jul 6 07:05:29 2020 +0000

    merging: merging: Update /foosync.file

diff --cc foosync.file
index de6283d,6afe446..20b0403
--- a/foosync.file
+++ b/foosync.file
@@@ -1,1 -1,1 +1,1 @@@
- b'dev-rackly-zfstest-0\n'
 -b'dev-rackly-zfstest-1\n'
++b"b'dev-rackly-zfstest-1\\n'"

Please help me to understand, maybe I am just confused and gitfs was not designed to work with multiple mounts simultaniously.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Labels
None yet
Projects
None yet
Development

No branches or pull requests

1 participant