Cache broken with GitVersionTask 3.6.0

[tpluscode]

I've just updated the MSBuild task package and apparently the cache is broken. Each target (WriteVersionInfoToBuildLog, WriteVersionInfoToBuildLog and GitVersion) in each built project recalculates the version number from scratch. Every time I see

Cache file C:\TeamCity\buildAgent\work\aaa244402599d927\.git\gitversion_cache\XYZ123.yml not found

And every time (during one build) the XYZ123 part is different. Worked good in version 3.5.4

[Martin-Andersen]

@tpluscode glad I am not alone and not crazy. I am getting the exact same error
[WriteVersionInfoToBuildLog] INFO [07/14/16 13:55:32:72] Cache file C:\TeamCity\buildAgent\work\e21746ec702e5b5d\.git\gitversion_cache\3012A3203E0BBA59F13642534D34033F6E301B69.yml not found.

It takes forever when the cache is not working.

[DanielRose]

I have the same problem here. My build time went from MSBuild (3m:08s) to MSBuild (2h:04m:52s)!

Even while building an assembly, the name of the cache file keeps on changing for every step:
[WriteVersionInfoToBuildLog] INFO [07/13/16 10:42:19:40] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\B979AEEFD2C8836D2DD487256DFC4D03DFE097D1.yml not found.
[UpdateAssemblyInfo] INFO [07/13/16 10:42:51:60] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\4641D2244564FA2AAB7EE360234E2E4AD9544A41.yml not found.
[GetVersion] INFO [07/13/16 10:43:17:57] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\4F5D3967671A88C07685ED01CF8CCF4AC536CD7C.yml not found.

[JakeGinnivan]

Hey, thanks for posting the issue.

Not sure why this is happening, the code to calculate the hash is:

var ticks = fileSystem.GetLastDirectoryWrite(Path.Combine(gitDir, "refs"));
var configPath = Path.Combine(repo.GetRepositoryDirectory(), "GitVersionConfig.yaml");
var configText = fileSystem.Exists(configPath) ? fileSystem.ReadAllText(configPath) : null;
var configHash = configText != null ? GetHash(configText) : null;
return string.Join(":", gitDir, repo.Head.CanonicalName, repo.Head.Tip.Sha, ticks, configHash);

The result is then hashed. As far as I know the only change is including the config file contents in the hash. Thoughts @asbjornu ?

[JakeGinnivan]

Can you try 3.6.1, we received a PR which cleaned up and fixed some issues around cache.

[DanielRose]

Still broken:

[WriteVersionInfoToBuildLog]   INFO [07/18/16 15:04:21:19] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\C29370840A305E08427BF70EDB4606F5D5CEE775.yml not found.
[UpdateAssemblyInfo]   INFO [07/18/16 15:04:53:64] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\5D1DF19B99D8DA89FB856708DB2FC6C5037E0962.yml not found.
[GetVersion]   INFO [07/18/16 15:05:19:65] Cache file C:\TeamCity_BuildAgent_2\work\60f2387b524bacc3\.git\gitversion_cache\863886002D4EC50937D970DD5EE8B93E9ECF5376.yml not found.

[DanielRose]

@JakeGinnivan I made a local build of GitVersion, where I added a bunch of debug info:

[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:24] Applicable build agent found: 'TeamCity'.
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:24] Branch from build environment: refs/heads/master
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:40] IsDynamicGitRepository: False
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:40] Returning Project Root from DotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git - C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:40] Project root is: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:40] DotGit directory is: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:40] Begin: Creating cache key
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:40] dotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:40] fileSystem.Type: GitVersion.Helpers.FileSystem
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:41] lastWriteDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git\refs\heads at 2016-07-20T10:30:33.3694796Z
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] lastGitRefsChangedTicks: 636046074333694796
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] gitSystemHash: F5EE0BFC8A9ED77A73138C9758BBDB94582F334E
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] IsDynamicGitRepository: False
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] Returning Project Root from DotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git - C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] configFileHash: 
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:42] repositorySnapshotHash: 9DC5F0788F5E28502467DE855A9B70A9E678F540
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:43] overrideConfigHash: 
[WriteVersionInfoToBuildLog]   INFO [07/20/16 12:30:33:43] compositeHash: 745008D89B2C3CF1ABDA43F572E94F48830177F8
[WriteVersionInfoToBuildLog] INFO [07/20/16 12:30:33:43] End: Creating cache key (Took: 26.00ms)


[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:59] Applicable build agent found: 'TeamCity'.
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:59] Branch from build environment: refs/heads/master
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:61] IsDynamicGitRepository: False
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:62] Returning Project Root from DotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git - C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:62] Project root is: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:62] DotGit directory is: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:62] Begin: Creating cache key
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] dotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] fileSystem.Type: GitVersion.Helpers.FileSystem
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] lastWriteDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git\refs\heads at 2016-07-20T10:30:33.6024930Z
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] lastGitRefsChangedTicks: 636046074336024930
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] gitSystemHash: 8EDD4CCE752764B9B7FA39DD136356CA4A3A1A36
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] IsDynamicGitRepository: False
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] Returning Project Root from DotGitDirectory: C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65\.git - C:\TeamCity_BuildAgent_1\work\a458f20b6997ff65
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] configFileHash: 
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] repositorySnapshotHash: 9DC5F0788F5E28502467DE855A9B70A9E678F540
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] overrideConfigHash: 
[UpdateAssemblyInfo]   INFO [07/20/16 12:30:33:62] compositeHash: 183C0614646EBAE4F8EB31BE8ADC17B4A74F488D
[UpdateAssemblyInfo] INFO [07/20/16 12:30:33:62] End: Creating cache key (Took: 8.00ms)

The difference is when getting the last directory write. If you look at the timestamps, the write to .git\refs\heads happens somewhere between Branch from build environment: refs/heads/master and IsDynamicGitRepository: False

[DanielRose]

After some more tests: In GitPreparer.Initialise(), it calls GitRepositoryHelper.NormalizeGitDirectory() This method modifies the repository, which causes the cache to fail.

It is a side effect of commit acce06c: the git directory is always normalized in a build server.

[tofutim]

I have the problem too. It just happened that I was finally able to get my big solution into TeamCity right as 3.6.0 was available.

[tofutim]

Seems like the problem persists in 3.6.1 - my builds are taking 20 min instead of a few minutes or less\

[JakeGinnivan]

Awesome investigation @DanielRose

If someone wants to pick this up that would be great.

[tofutim]

@DanielRose what does it mean that the git directory is normalized?

Is it running this? https://github.com/GitTools/GitTools.Core/blob/244cca386321d6f8c90cf31cd3c4734c8932b4da/src/GitTools.Core/GitTools.Core.Shared/Git/Helpers/GitRepositoryHelper.cs