Seperating Red Herrings in Error Logs

One day, a message was dropped into my box, mentioning that CI was failing for one of the C# projects in build checks after adding a new dependency. The suspected culprit was permissions. As I was the one who set up our CI system and no one knew how to debug it, I started to roll up my sleeves.

The first thing to do was to look at the CI logs.

Building csharp/project/subproject.csproj
MSBuild version 17.6.8+c70978d4d for .NET
  Determining projects to restore...
  Restored /__w/monorepo/monorepo/csharp/project/subproject.csproj (in 11.78 sec).
  INFO [07/13/23 7:13:10:97] Applicable build agent found: 'GitHubActions'.
  INFO [07/13/23 7:13:11:04] Working directory: /__w/monorepo/monorepo/csharp/subproject
  INFO [07/13/23 7:13:11:07] Project root is: /__w/monorepo/monorepo/
  INFO [07/13/23 7:13:11:07] DotGit directory is: /__w/monorepo/monorepo/.git
  INFO [07/13/23 7:13:11:07] Branch from build environment: refs/pull/1337/merge
  INFO [07/13/23 7:13:11:07] Begin: Normalizing git directory for branch 'refs/pull/1337/merge'
    INFO [07/13/23 7:13:11:11] One remote found (origin -> 'monorepo-path').
    INFO [07/13/23 7:13:11:11] Skipping fetching, if GitVersion does not calculate your version as expected you might need to allow fetching or use dynamic repositories
    INFO [07/13/23 7:13:11:12] Creating local branch pull/1337/merge pointing at short-sha
    INFO [07/13/23 7:13:11:36] HEAD points at branch 'refs/heads/pull/1337/merge'.
    INFO [07/13/23 7:13:11:36] End: Normalizing git directory for branch 'refs/pull/1337/merge' (Took: 294.73ms)
    INFO [07/13/23 7:13:11:38] Begin: Loading version variables from disk cache
      INFO [07/13/23 7:13:11:38] Cache file /__w/monorepo/monorepo/.git/gitversion_cache/FFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFFF.yml not found.
    INFO [07/13/23 7:13:11:38] End: Loading version variables from disk cache (Took: 0.70ms)
    INFO [07/13/23 7:13:11:38] Using latest commit on specified branch
    INFO [07/13/23 7:13:11:59] Running against branch: pull/1337/merge (short-sha Merge random-sha into another-random-sha)
    INFO [07/13/23 7:13:11:59] Begin: Calculating base versions
      INFO [07/13/23 7:13:11:60] Begin: Attempting to inherit branch configuration from parent branch
      INFO [07/13/23 7:13:11:61] End: Attempting to inherit branch configuration from parent branch (Took: 6.38ms)
    INFO [07/13/23 7:13:11:61] End: Calculating base versions (Took: 21.50ms)
    ERROR [07/13/23 7:13:11:64] An unexpected error occurred:
  System.NullReferenceException: Object reference not set to an instance of an object.
     at LibGit2Sharp.Core.Handles.ObjectHandle.op_Implicit(ObjectHandle handle) in /_/LibGit2Sharp/Core/Handles/Objects.cs:line 509
     at LibGit2Sharp.Core.Proxy.git_commit_author(ObjectHandle obj) in /_/LibGit2Sharp/Core/Proxy.cs:line 289
     at LibGit2Sharp.Core.LazyGroup`1.Dependent`2.LibGit2Sharp.Core.LazyGroup<T>.IEvaluator<TInput>.Evaluate(TInput input) in /_/LibGit2Sharp/Core/LazyGroup.cs:line 88
     at LibGit2Sharp.Core.LazyGroup`1.<Evaluate>b__6_0(T input) in /_/LibGit2Sharp/Core/LazyGroup.cs:line 36
     at LibGit2Sharp.Core.GitObjectLazyGroup.EvaluateInternal(Action`1 evaluator) in /_/LibGit2Sharp/Core/GitObjectLazyGroup.cs:line 20
     at LibGit2Sharp.Core.LazyGroup`1.Evaluate() in /_/LibGit2Sharp/Core/LazyGroup.cs:line 34
     at LibGit2Sharp.Core.LazyGroup`1.Dependent`2.Evaluate() in /_/LibGit2Sharp/Core/LazyGroup.cs:line 80
     at LibGit2Sharp.Core.LazyGroup`1.Dependent`2.get_Value() in /_/LibGit2Sharp/Core/LazyGroup.cs:line 73
     at LibGit2Sharp.Commit.get_Committer() in /_/LibGit2Sharp/Commit.cs:line 87
     at GitVersion.Commit..ctor(Commit innerCommit) in D:\a\GitVersion\GitVersion\src\GitVersion.LibGit2Sharp\Git\Commit.cs:line 17
     at GitVersion.Commit.<>c.<.ctor>b__3_0(Commit parent) in D:\a\GitVersion\GitVersion\src\GitVersion.LibGit2Sharp\Git\Commit.cs:line 16
     at System.Linq.Enumerable.SelectEnumerableIterator`2.MoveNext()
     at System.Linq.Enumerable.Count[TSource](IEnumerable`1 source)
     at GitVersion.Configuration.BranchConfigurationCalculator.InheritBranchConfiguration(Int32 recursions, IBranch targetBranch, BranchConfig branchConfiguration, ICommit currentCommit, Config configuration, IList`1 excludedInheritBranches) in D:\a\GitVersion\GitVersion\src\GitVersion.Core\Configuration\BranchConfigurationCalculator.cs:line 77
     at GitVersion.Configuration.BranchConfigurationCalculator.GetBranchConfigurationInternal(Int32 recursions, IBranch targetBranch, ICommit currentCommit, Config configuration, IList`1 excludedInheritBranches) in D:\a\GitVersion\GitVersion\src\GitVersion.Core\Configuration\BranchConfigurationCalculator.cs:line 54
     at GitVersion.Configuration.BranchConfigurationCalculator.GetBranchConfiguration(IBranch targetBranch, ICommit currentCommit, Config configuration, IList`1 excludedInheritBranches) in D:\a\GitVersion\GitVersion\src\GitVersion.Core\Configuration\BranchConfigurationCalculator.cs:line 28
     at GitVersion.VersionCalculation.BaseVersionCalculator.GetBaseVersion() in D:\a\GitVersion\GitVersion\src\GitVersion.Core\VersionCalculation\BaseVersionCalculator.cs:line 37
     at GitVersion.VersionCalculation.NextVersionCalculator.FindVersion() in D:\a\GitVersion\GitVersion\src\GitVersion.Core\VersionCalculation\NextVersionCalculator.cs:line 56
     at GitVersion.GitVersionCalculateTool.CalculateVersionVariables() in D:\a\GitVersion\GitVersion\src\GitVersion.Core\Core\GitVersionCalculateTool.cs:line 52
     at GitVersion.GitVersionExecutor.RunGitVersionTool(GitVersionOptions gitVersionOptions) in D:\a\GitVersion\GitVersion\src\GitVersion.App\GitVersionExecutor.cs:line 66
    INFO [07/13/23 7:13:11:64] Attempting to show the current git graph (please include in issue): 
    INFO [07/13/23 7:13:11:64] Showing max of 100 commits
    INFO [07/13/23 7:13:11:70] ERROR: fatal: detected dubious ownership in repository at '/__w/monorepo/monorepo'
EXEC : error : To add an exception for this directory, call: [/__w/monorepo/monorepo/csharp/project/subproject.csproj]
EXEC : error :  [/__w/monorepo/monorepo/csharp/project/subproject.csproj]
EXEC : error : git config --global --add safe.directory /__w/monorepo/monorepo [/__w/monorepo/monorepo/csharp/project/subproject.csproj] 

To provide some context, the new dependency that was added was GitVersion.MsBuild. It adds a new step during building which inspects commits, creates a new version according to those commits, and then embeds that version into the executable. At line 49, you can see why my colleague suspected a permission problem; the dubious ownership error was the most glaring at the end of the logs. However, I was not convinced because, above that, there was another unassuming error at line 25 indicating that something went wrong. It seemed that during the inspection of commits, an issue was encountered.

To better debug the problem, I decided to recreate the issue on my machine. The project was building without a hiccup on my machine and our docker build image. As I wondered whether I should clone the monorepo from zero, I remembered a crucial detail. actions/checkout (as we were using Github Actions) wasn’t using git clone. Instead, it was creating a new repo from scratch, setting the origin manually, then fetching the specified branch or pull request. While I was copying what actions/checkout did, I saw `–depth=1` for the fetch command. Everything made sense, GitVersion.MsBuild was failing because in the repository there was no commit history. After some research, GitVersion’s developer, GitTools, was recommending running the actions/checkout with fetch-depth: 0 argument. With this, it was pulling the whole commit history and build check were passing from CI.

As for the ownership problem, as mentioned before, we were using docker containers for most of our workflows. Thus, I was suspecting that different images might have different users, like some of them use root, while others use a newly created user in the docker build process. However, after checking some resources, it seems to be an actions/checkout issue.

Logs are expansive lakes, demanding meticulous examination. A large catch might seem impressive, but accurate identification is crucial. Misinterpreting a red herring can waste valuable time. Therefore, within this ocean of data, precision and understanding are key. It’s not just about how much you catch, but how well you discern useful information from distractions. Approach your logs like an experienced fisher, cast your net purposefully and analyze your catch meticulously.