cmarcusreid / git-status-cache

High performance cache for git repository status. Clients can retrieve information via named pipe.
MIT License
16 stars 4 forks source link

On a large repository the cache invalidates when only run `git status` #16

Closed DoCode closed 8 years ago

DoCode commented 8 years ago

Only when running git status the cache invalidates, although nothing is changed. See it here in acton:

http://1drv.ms/1LJhp4p

cmarcusreid commented 8 years ago

If you start GitStatusCache.exe with "--fileLogging -s", it'll write a log file to %temp% with a name like GitStatusCache_{timestamp}.log. There should be a log line reporting what caused the invalidation.

My guess would be that git touched something like /.git/index.lock. I've seen this file get added and removed as part of some git operations, but I'm not sure if it's always safe to ignore in the invalidation logic.

DoCode commented 8 years ago

Thanks, Markus... I'll check it `sofort' ;)

DoCode commented 8 years ago

Nothing logged!? I'm using the latest version and start it manual with GitStatusCache.exe --filelogging -s.

cmarcusreid commented 8 years ago

My mistake! It should be "--fileLogging -s". Looks like it's case sensitive.

(If you're interested, the full set of switches is at https://github.com/cmarcusreid/git-status-cache/blob/master/src/GitStatusCache/src/Main.cpp)

DoCode commented 8 years ago

Hi, yeah! Your guess was right...

2015-10-13 21:46:39.380111  GitStatusCache.exe (0x000028b0) 0x000000a0  Spam    CachePrimer.StartingPrimingThread   Attempting to start background thread for cache priming.
2015-10-13 21:46:39.384110  GitStatusCache.exe (0x000028b0) 0x0000360c  Verbose CachePrimer.WaitForPrimingTimerExpiration.Start Thread for cache priming started.
2015-10-13 21:46:39.384110  GitStatusCache.exe (0x000028b0) 0x000000a0  Spam    NamedPipeServer.StartingBackgroundThread    Attempting to start server thread.
2015-10-13 21:46:39.385136  GitStatusCache.exe (0x000028b0) 0x000039bc  Verbose NamedPipeServer.WaitForClientRequest.Start  Server thread started.
2015-10-13 21:46:39.385136  GitStatusCache.exe (0x000028b0) 0x000039bc  Verbose NamedPipeServer.WaitForClientRequest    Creating named pipe instance and waiting for client.
2015-10-13 21:46:46.832208  GitStatusCache.exe (0x000028b0) 0x000039bc  Spam    NamedPipeInstance.Connect.Success   ConnectNamedPipe succeeded.
2015-10-13 21:46:46.833207  GitStatusCache.exe (0x000028b0) 0x000039bc  Spam    NamedPipeInstance.StartingBackgroundThread  Attempting to start background thread for servicing requests.
2015-10-13 21:46:46.833207  GitStatusCache.exe (0x000028b0) 0x000039bc  Verbose NamedPipeServer.WaitForClientRequest    Creating named pipe instance and waiting for client.
2015-10-13 21:46:46.833207  GitStatusCache.exe (0x000028b0) 0x00003c48  Verbose NamedPipeInstance.OnClientRequest.Start Request servicing thread started.
2015-10-13 21:46:46.834182  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:46.835208  GitStatusCache.exe (0x000028b0) 0x00003c48  Warning Cache.GetStatus.CacheMiss   Failed to find git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:46:51.251600  GitStatusCache.exe (0x000028b0) 0x00003c48  Info    DirectoryMonitor.AddDirectory   Registering directory for change notifications. { "token": 0, "path": "D:/projects/TestRepo/" }
2015-10-13 21:46:51.251600  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    DirectoryMonitor.StartingBackgroundThread   Attempting to start background thread for handling notifications.
2015-10-13 21:46:51.251600  GitStatusCache.exe (0x000028b0) 0x00002e00  Verbose DirectoryMonitor.WaitForNotifications.Start Thread for handling notifications started.
2015-10-13 21:46:51.251600  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }
2015-10-13 21:46:52.763999  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:52.764973  GitStatusCache.exe (0x000028b0) 0x00003c48  Info    Cache.GetStatus.CacheHit    Found git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:46:52.764973  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }
2015-10-13 21:46:53.181242  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:53.181242  GitStatusCache.exe (0x000028b0) 0x00003c48  Info    Cache.GetStatus.CacheHit    Found git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:46:53.182267  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }
2015-10-13 21:46:53.580497  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:53.581498  GitStatusCache.exe (0x000028b0) 0x00003c48  Info    Cache.GetStatus.CacheHit    Found git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:46:53.581498  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }
2015-10-13 21:46:53.957049  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:53.958047  GitStatusCache.exe (0x000028b0) 0x00003c48  Info    Cache.GetStatus.CacheHit    Found git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:46:53.958047  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }
2015-10-13 21:46:56.507487  GitStatusCache.exe (0x000028b0) 0x00002e00  Spam    DirectoryMonitor.Notification.Modified  Modified file. { "token": 0, "path": "D:/projects/TestRepo/.git" }
2015-10-13 21:46:56.507487  GitStatusCache.exe (0x000028b0) 0x00002e00  Info    CacheInvalidator.OnFileChanged.InvalidatedCacheEntry    Invalidated git status in cache for file change. { "token": 0, "repositoryPath": "D:/projects/TestRepo/.git/", "filePath": "D:/projects/TestRepo/.git" }
2015-10-13 21:46:56.544487  GitStatusCache.exe (0x000028b0) 0x00002e00  Spam    DirectoryMonitor.Notification.Add   Added file. { "token": 0, "path": "D:/projects/TestRepo/.git\index.lock" }
2015-10-13 21:46:56.605477  GitStatusCache.exe (0x000028b0) 0x00002e00  Spam    DirectoryMonitor.Notification.Remove    Removed file. { "token": 0, "path": "D:/projects/TestRepo/.git\index.lock" }
2015-10-13 21:46:56.626476  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Request   Received request from client. { "request": "{"Path":"D:\\projects\\TestRepo","Version":1,"Action":"GetStatus"}" }
2015-10-13 21:46:56.627471  GitStatusCache.exe (0x000028b0) 0x00003c48  Warning Cache.GetStatus.CacheMiss   Failed to find git status in cache. { "repositoryPath": "D:/projects/TestRepo/.git/" }
2015-10-13 21:47:01.386896  GitStatusCache.exe (0x000028b0) 0x00003c48  Spam    NamedPipeInstance.OnClientRequest.Response  Sending response to client. { "response": "{"Version":1,"Path":"D:\\projects\\TestRepo","RepoPath":"D:/projects/TestRepo/.git/","WorkingDir":"D:/projects/TestRepo/","State":"","Branch":"master","Upstream":"origin/master","AheadBy":0,"BehindBy":0,"IndexAdded":[],"IndexModified":[],"IndexDeleted":[],"IndexTypeChange":[],"IndexRenamed":[],"WorkingAdded":[],"WorkingModified":[],"WorkingDeleted":[],"WorkingTypeChange":[],"WorkingRenamed":[],"WorkingUnreadable":[],"Ignored":[],"Conflicted":[],"Stashes":[]}" }

Can you ignore that lock file?

Many THX!

cmarcusreid commented 8 years ago

Unfortunately I'm not confident that we can safely ignore index.lock without getting additional information from another source.

Suppose you have an existing file "t.txt" on disk and you call "git add t.txt". In this case we want an invalidation so that we see "t.txt" get staged in the status response, but "t.txt" won't be modified or changed by this operation. Files in the "/.git/" directory will be changed (including index.lock), which correctly causes the invalidation.

It's possible that we can ignore index.lock changes if git operations that should cause invalidation always touch other files. We'll want to be very careful before making this change though -- if there's ever a case where a git operation that should invalidate the cache doesn't modify another file, we'll return the wrong result.

I think the change is a fairly straightforward tweak to CacheInvalidator::OnFileChanged. Perhaps we make the adjustment in a branch and test it for a few weeks with day-to-day use?

DoCode commented 8 years ago

I agree. I can test the tweak on this repo on every day.

DoCode commented 8 years ago

Maybe you can do an configuration option to specifically exclude files like index.lock.

cmarcusreid commented 8 years ago

I've published a pre-release executable as v1.1.3-alpha with 743dd3b. This will not work for all cases; for example, if the repo contains submodules that are touched as part of "git status", I don't see a way to safely distinguish these touches from real modifications.

I'm very interested in feedback. We want to look out for any cases where this could result in a stale cache entry.

I did some basic testing and didn't find any problems. I'm going to use this in my normal workflow for a while to see if anything pops up.

dahlbyk commented 8 years ago

For future reference, index.lock is only used to ensure atomic use (read/write) of .git/index. It should be 100% safe to ignore.

cmarcusreid commented 8 years ago

Thanks!