Discrepancy in events raised by RepositoryWatcher

[StanleyGoldman]

On some workstations the action of git commit is producing a different output in the RepositoryWatcher.
Executing the integration test ShouldAddAndCommitAllFiles from #418 demonstrates the issue more closely.

Workstations seem consistent in their ability to reproduce the issue or not.
I have one workstation where this works and one where it does not.

This log shows what we expect:

17:52:20.600 PM TRACE [ 9] <GitClient> Add all files
17:52:20.609 PM TRACE [ 9] <GitClient> Commit
17:52:20.625 PM TRACE [15] <RepositoryManager> IsBusyChanged Value:True
17:52:20.633 PM TRACE [15] <IRepositoryManagerListener> OnIsBusyChanged: True
17:52:20.777 PM TRACE [15] <RepositoryManager> IsBusyChanged Value:False
17:52:20.783 PM TRACE [15] <IRepositoryManagerListener> OnIsBusyChanged: False
17:52:20.789 PM TRACE [15] <RepositoryWatcher> Handling 57 Events
17:52:20.800 PM TRACE [15] <RepositoryWatcher> IndexChanged
17:52:20.806 PM TRACE [15] <RepositoryWatcher> LocalBranchChanged: master
17:52:20.812 PM TRACE [15] <IRepositoryManagerListener> OnLocalBranchUpdated Name:master
17:52:20.817 PM TRACE [15] <RepositoryWatcher> Processed 2 Events
17:52:20.831 PM TRACE [ 4] <RepositoryManager> Stop
17:52:20.839 PM TRACE [ 4] <RepositoryWatcher> Stopping watcher
17:52:20.845 PM TRACE [ 4] <RepositoryManager> Stop
17:52:20.852 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped
17:52:20.859 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped

In error scenarios this is what we receive:

18:34:55.346 PM TRACE [ 9] <GitClient> Add all files
18:34:55.355 PM TRACE [ 9] <GitClient> Commit
18:34:55.368 PM TRACE [15] <RepositoryManager> IsBusyChanged Value:True
18:34:55.377 PM TRACE [15] <IRepositoryManagerListener> OnIsBusyChanged: True
18:34:55.576 PM TRACE [15] <RepositoryManager> IsBusyChanged Value:False
18:34:55.580 PM TRACE [15] <IRepositoryManagerListener> OnIsBusyChanged: False
18:34:55.586 PM TRACE [15] <RepositoryWatcher> Handling 62 Events
18:34:55.594 PM TRACE [15] <RepositoryWatcher> IndexChanged
18:34:55.598 PM TRACE [15] <RepositoryWatcher> LocalBranchCreated: master
18:34:55.604 PM TRACE [15] <IRepositoryManagerListener> OnLocalBranchAdded Name:master
18:34:55.608 PM TRACE [15] <RepositoryWatcher> LocalBranchDeleted: master
18:34:55.613 PM TRACE [15] <IRepositoryManagerListener> OnLocalBranchRemoved Name:master
18:34:55.617 PM TRACE [15] <RepositoryWatcher> Processed 3 Events
18:34:55.658 PM TRACE [ 4] <RepositoryManager> Stop
18:34:55.664 PM TRACE [ 4] <RepositoryWatcher> Stopping watcher
18:34:55.674 PM TRACE [ 4] <RepositoryManager> Stop
18:34:55.683 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped
18:34:55.689 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped

This issue existed before the batching changes made to the FileWatcher.

https://ci.appveyor.com/project/github-windows/unity/build/1912.releases/0.21/artifacts

170921-16:51:09 TRACE [ 7] <GitClient>                         Add all files
170921-16:51:09 TRACE [ 7] <GitClient>                         Commit
170921-16:51:09 TRACE [15] <RepositoryManager>                 IsBusyChanged Value:True
170921-16:51:09 TRACE [15] <IRepositoryManagerListener>        OnIsBusyChanged: True
170921-16:51:09 TRACE [15] <RepositoryManager>                 IsBusyChanged Value:False
170921-16:51:09 TRACE [15] <IRepositoryManagerListener>        OnIsBusyChanged: False
170921-16:51:09 TRACE [15] <RepositoryWatcher>                 Handling 55 Events
170921-16:51:09 TRACE [15] <RepositoryWatcher>                 LocalBranchChanged: master
170921-16:51:09 TRACE [15] <RepositoryManager>                 Updating Git Status
170921-16:51:09 TRACE [15] <GitClient>                         Status
170921-16:51:09 TRACE [15] <RepositoryWatcher>                 IndexChanged
170921-16:51:09 TRACE [15] <RepositoryWatcher>                 Processed 2 Events
170921-16:51:09 TRACE [ 7] <RepositoryManager>                 Stop
170921-16:51:09 TRACE [ 7] <RepositoryWatcher>                 Stopping watcher
170921-16:51:09 TRACE [ 7] <RepositoryManager>                 Stop
170921-16:51:09  WARN [ 7] <RepositoryWatcher>                 Watcher already stopped
170921-16:51:09  WARN [ 7] <RepositoryWatcher>                 Watcher already stopped

Running the same integration test from 0.21 locally results in the following

18:50:28.474 PM TRACE [ 4] <GitClient> Add all files
18:50:28.483 PM TRACE [ 4] <GitClient> Commit
18:50:28.492 PM TRACE [11] <RepositoryManager> IsBusyChanged Value:True
18:50:28.497 PM TRACE [11] <IRepositoryManagerListener> OnIsBusyChanged: True
18:50:28.767 PM TRACE [11] <RepositoryManager> IsBusyChanged Value:False
18:50:28.772 PM TRACE [11] <IRepositoryManagerListener> OnIsBusyChanged: False
18:50:28.782 PM TRACE [11] <RepositoryWatcher> Handling 62 Events
18:50:28.789 PM TRACE [11] <RepositoryWatcher> LocalBranchDeleted: master
18:50:28.796 PM TRACE [11] <IRepositoryManagerListener> OnLocalBranchListChanged
18:50:28.803 PM TRACE [11] <RepositoryWatcher> LocalBranchCreated: master
18:50:28.822 PM TRACE [11] <IRepositoryManagerListener> OnLocalBranchListChanged
18:50:28.828 PM TRACE [11] <RepositoryWatcher> IndexChanged
18:50:28.834 PM TRACE [11] <RepositoryWatcher> Processed 3 Events
18:50:28.871 PM TRACE [ 4] <RepositoryManager> Stop
18:50:28.877 PM TRACE [ 4] <RepositoryWatcher> Stopping watcher
18:50:28.884 PM TRACE [ 4] <RepositoryManager> Stop
18:50:28.890 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped
18:50:28.895 PM WARN [ 4] <RepositoryWatcher> Watcher already stopped

Due to the chain of events that follow the ChangesView does not refresh after a git commit and the branch master disappears.

[StanleyGoldman]

This is probably the cause of #382

[StanleyGoldman]

This gist should help with implementation https://gist.github.com/StanleyGoldman/09e648cd521166ea4ad43e154782d4a8

[StanleyGoldman]

After documentation, some bugs found in SFW and further analysis we figure it's best to not act upon single branch added/deleted events. Instead if we detect changes in the folder heads or the folder remotes we should reload the entire local or remote branch list respectively.

[StanleyGoldman]

Also in order to detect that we need to run git status we can watch the index file for changes.
We can make use of COMMIT_EDITMSG to know that we have committed and should update the log.

[shana]

Changes view: git status
History view: git log
Pull/Push: git rev-list (#385)
Branches view: git branch -land git branch -r (we're actually reading directly from the filesystem which is fine, it's just conceptually the equivalent of these two git operations)
Settings view: git lfs locks

Changes to files inside .git and what they mean

• index: git add or git commit have happened. git status needs to run
• HEAD: git checkout or equivalent branch switch action has happened. run git log to update history. run git rev-list to update ahead counters
• COMMIT_EDITMSG: a commit has happened. run git log to update history. run git rev-list to update ahead counters. note: we don't need to run git status here because the index file is always changed when committing, which will trigger git status
• refs/heads: a local branch has been changed (could be because a branch has been created/deleted or a commit has happened or some other fetch action that has updated a local branch). run git branch -l or equivalent logic
• refs/remotes: a remote has been added/deleted or a remote branch has been changed (fetch might have run, etc). run git branch -r or equivalent logic. run git rev-list to update behind counters

Git Commands and how they trigger

git status - Feeds information to changes view and project view icons

• Triggers on changes to the .git/index file
• Triggers on changes outside the .git directory on files that are not ignored (I think that's what we're doing right now already)

git log - Feeds information to history view

• Triggers on changes to the .git/COMMIT_EDITMSG (a commit has been made, update the history)
• Triggers on changes to the .git/HEAD file (we have switched branches, update the history)

git branch -l or equivalent - Feeds information to branches view (local)

• Triggers on changes to the .git/refs/heads directory

git branch -r or equivalent - Feeds information to branches view (remote)

• Triggers on changes to the .git/refs/remotes directory

git rev-list - Feeds information to ahead/behind counters in push/pull buttons

• Triggers on changes to .git/COMMIT_EDITMSG (new commit needs to be pushed, ahead counter needs updating) or to .git/refs/remotes (fetch has happened, behind counter needs updating) or to HEAD (branch switched, ahead/behind counters need updating)

git lfs locks - Feeds information on locked files in settings view (and other UI bits)

• Triggers on...?

[shana]

RepositoryWatcher listens to the filesystem and raises events that match actions we need to do, like IndexChanged (.git/index file has changed)

RepositoryManager listens to the watcher and runs git commands that match the watcher events, like git status when the IndexChanged event comes in

RepositoryManager raises events with the data from the git command(s) that have run, like OnStatus or OnStatusUpdated

Repository listens to data events from the manager, shuffles the data to a UI thread and saves it in the cache

Repository raises property changed events corresponding to the properties that have had data changed in them on the UI thread

Views listen to events from the repository and update UI accordingly

[shana]

If a view requests a manual refresh of data - like calling Repository.Log(), the Repository calls the equivalent method in RepositoryManager. RepositoryManager runs the command and raises the appropriate event, which Repository is listening to (as described above) and updates the data accordingly.

All our refresh actions are fire and forget at the moment, so this shouldn't have an impact on current views.

Other actions (like Revert) should cause the watcher to trigger the appropriate events back so that the required git commands are run (revert will need to trigger a git log, but revert is a commit, so that should happen naturally).