This is an odd one. I’m currently working on Cloud Firestore support for C#, and I’ve introduced a GeoPoint struct to represent a latitude/longitude pair, each being represented by a double. It implements IEquatable and overloads == and != in the obvious way. So far, so good, and I have working tests which have passed on CI.

I’ve added some more types that implement equality, so I thought I’d extract out common code into an EqualityTester class that can handle both the Equals methods and the operators (the latter via reflection).

All went well on my local machine, but on CI one environment failed. We use both AppVeyor and Travis in CI, and only Travis was failing. There were two failures – one testing the equality operators, and one as part of a broader serialization/deserialization test. Odd. Time to go through the normal diagnostic process…

Step 1: Check there’s really a problem

The nature of the failing tests don’t feel like an intermittent problem, but it’s always good to get more of an idea. I forced Travis to rebuild the pull request on Travis a couple of times: yes, it failed the same two tests each time.

Step 2: Reproduce locally

Tests that only fail in CI are really annoying. I’ve had this a couple of times, and it’s always taken hours to sort out, because the “try something, get results, think about what they mean” cycle is so slow.

Fortunately, I have a Linux box at home – so I fetched the pull request and ran the tests there – and they failed. Hooray! It’s not quite as nice as being able to reproduce it on my Windows laptop, but it’s much better than being isolated to CI.

Step 3: Remove irrelevant test code

There are two parts to the code that’s failing: the unit tests, and the production code. Ideally, I’d like to get rid of both, to create a truly minimal example. I usually try to take out one project at a time, and I could have gone either way – but this time I decided to remove the testing first.

So in the same repo, I created a new netcoreapp1.0 console application, with a project reference to the production code. I moved the operator part of my equality tester code into Program.cs, simplified it slightly, introduced by own Assert class with True and False methods that printed out the result, and I was ready to run:

using System;
using System.Reflection;
using Google.Cloud.Firestore.Data;

class Program
{
   static void Main(string[] args)
   {
       var gp1 = new GeoPoint(1.5, 2.5);
       var gp2 = new GeoPoint(1.5, 2.5);
       AssertEqualityOperators(gp1, gp2);
   }

   internal static void AssertEqualityOperators<T>(T control, T equal)
   {
       var typeInfo = typeof(T).GetTypeInfo();
       var equalityMethodInfo = typeInfo.GetMethod(
           "op_Equality", new[] { typeof(T), typeof(T) });
       Func<T, T, bool> equality = 
           (lhs, rhs) => (bool) equalityMethodInfo.Invoke(null, new object[] { lhs, rhs });

       Assert.True(equality(control, equal));
   }
}

class Assert
{
   public static void True(bool actual)
       => Console.WriteLine($"Expected True; was {actual}");

   public static void False(bool actual)
       => Console.WriteLine($"Expected False; was {actual}");
}

Sure enough, the output shows the problem:

Expected True; was False

Great. Now let’s remove the other dependency…

Step 4: Remove production code dependency

Rather than copy the whole of GeoPoint into my test project, I just created a small Test struct which had similar equality code.

Dead-end: a single double value

I made a mistake here – I changed too much in one go. I reduced my Test struct to just one double field:

using System;
using System.Reflection;

class Program
{
   static void Main(string[] args)
   {
       Test t1 = new Test(1.5);
       Test t2 = new Test(1.5);

       var equalityMethodInfo = typeof(Test)
           .GetMethod("op_Equality", new[] { typeof(Test), typeof(Test) });
       Func<Test, Test, bool> equality =
           (lhs, rhs) => (bool) equalityMethodInfo.Invoke(null, new object[] { lhs, rhs });
       Console.WriteLine(t1 == t2);
       Console.WriteLine(equality(t1, t2));
       Console.WriteLine(equalityMethodInfo.Invoke(null, new object[] { t1, t2 }));
   }
}

struct Test : IEquatable<Test>
{
    private readonly double value;

    public Test(double value)
    {
        this.value = value;
    }

    public static bool operator==(Test lhs, Test rhs) =>
        lhs.value == rhs.value;

    public static bool operator!=(Test lhs, Test rhs) => !(lhs == rhs);

    public override bool Equals(object obj) =>
        obj is Test t && Equals(t);

    public bool Equals(Test other) => this == other;

    public override int GetHashCode() => value.GetHashCode();
}

That prints “True” three times – which is what we’d like it to do eventually, but it means it’s not reproducing the problem we want it do.

Back to reproducing it: two double values

Taking one step back towards the previous code, I went back to two double values instead of just one, expanding the Test struct like this:

struct Test : IEquatable<Test>
{
    private readonly double x;
    private readonly double y;

    public Test(double x, double y)
    {
        this.x = x;
        this.y = y;
    }

    public static bool operator==(Test lhs, Test rhs) =>
        lhs.x == rhs.x && lhs.y == rhs.y;

    public static bool operator!=(Test lhs, Test rhs) => !(lhs == rhs);

    public override bool Equals(object obj) =>
        obj is Test t && Equals(t);

    public bool Equals(Test other) => this == other;

    public override int GetHashCode() => x.GetHashCode() + y.GetHashCode();
}

Change both constructor calls to Test(1.5, 2.5) and bingo: it prints True, False, False.

Step 5: Explore the scope of the problem

I tried the exact same code on Windows, and (unsurprisingly, given that my earlier unit tests passed) it didn’t reproduce the problem. But sticking with Linux, we can still try multiple frameworks and multiple build configurations.

I wouldn’t like to say what prompted me to try different frameworks – intuition can be hard to explain, unfortunately. But let’s change the project file a bit:

<Project Sdk="Microsoft.NET.Sdk">
  <PropertyGroup>
    <OutputType>Exe</OutputType>
    <TargetFrameworks>netcoreapp1.0;netcoreapp1.1;netcoreapp2.0</TargetFrameworks>
  </PropertyGroup>
</Project>

And then run it in several different configurations (remember that three “True” lines means “everything is working”, and “True”, “False”, “False” means “this is the problem we’re investigating”):

$ dotnet run -c Debug -f netcoreapp1.0
True
False
False
$ dotnet run -c Release -f netcoreapp1.0
True
False
False
$ dotnet run -c Debug -f netcoreapp1.1
True
True
True
$ dotnet run -c Release -f netcoreapp1.1
True
True
True
$ dotnet run -c Debug -f netcoreapp2.0
True
True
True
$ dotnet run -c Release -f netcoreapp2.0
True
True
True

So, it fails under .NET Core 1.0, but works under .NET Core 1.1 and .NET Core 2.0. That certainly makes it sound like a .NET Core 1.0 bug, but that doesn’t mean I want to give up at this point. It’s entirely possible that I have users who are using .NET Core 1.0, so I want my code to work under it.

Now, I’ve only given major/minor version numbers – and that’s partly because I don’t have a very good handle on the different parts of .NET Core on Linux and how to find the version numbers. The 1.0 packages I’ve got installed are listed as:

• dotnet-dev-1.0.4/xenial,now 1.0.4-1 amd64 [installed]
• dotnet-hostfxr-1.0.1/xenial,now 1.0.1-1 amd64 [installed]
• dotnet-sharedframework-microsoft.netcore.app-1.0.5/xenial,now 1.0.5-1 amd64 [installed,automatic]

No dotnet-runtime package, which I believe is part of 2.0 instead.

Step 6: Look into the failed comparison

This part is really simple – just add more diagnostics to the == method:

public static bool operator==(Test lhs, Test rhs)
{
    Console.WriteLine($"lhs=({lhs.x}, {lhs.y}); rhs=({rhs.x}, {rhs.y})");
    Console.WriteLine($"{lhs.x == rhs.x}, {lhs.y == rhs.y}");
    return lhs.x == rhs.x && lhs.y == rhs.y;
}

Now things get really interesting in the output:

lhs=(1.5, 2.5); rhs=(1.5, 2.5)
True, True
True
lhs=(1.5, 1.85492638478664E-316); rhs=(1.5, 6.95251497332956E-310)
True, False
False
lhs=(1.5, 6.9525149733517E-310); rhs=(1.5, 6.9525149733351E-310)
True, False
False

The first three lines are as expected – and that’s the working comparison. But each of the three-line-segments for the second and third comparisons show the first field (x) being fine, but the second being some tiny double value, and inconsistent at that.

Step 7: Try (and fail) to simplify

Maybe boxing is to blame? How about we try a really simple version of boxing – just override ToString(), box a value and see what comes up. The change in Test is simply:

public override string ToString() => $"{x}, {y}";

And then to test it:

object x = new Test(1.5, 2.5);
Console.WriteLine(x);

This prints 1.5, 2.5 – so it appears to be boxed correctly.

Step 8: Try simplifying a bit less

In our failing program, there are two potential complications at play: we’re boxing the value, and we’re calling a method via reflection. If just boxing isn’t a problem, maybe reflection is?

I decided to try two things at once: an instance method and a static method accepting a Test parameter (like the operator). Now we’re not doing any comparisons, we can get rid of a lot of code. Here’s the new complete code:

using System;
using System.Reflection;

class Program
{
   static void Main(string[] args)
   {
       Test t = new Test(1.5, 2.5);
       var foo = typeof(Test).GetMethod("Foo");
       foo.Invoke(t, null);
       var bar = typeof(Test).GetMethod("Bar");
       bar.Invoke(null, new object[] { t });
   }
}

struct Test
{
    private readonly double x;
    private readonly double y;

    public Test(double x, double y)
    {
        this.x = x;
        this.y = y;
    }

    public void Foo() => Console.WriteLine($"{x}, {y}");
    public static void Bar(Test t) => Console.WriteLine($"{t.x}, {t.y}");
}

And now the results:

1.5, 2.5
1.5, 6.95260190884551E-310

Interesting! At this point, there are lots of things that I could check:

• Does it affect all parameters?
• Does it happen for other field types? Other primitives? References?
• Can I provoke it in any other circumstances other than via
  reflection?

Most of these can probably be answered by finding an existing issue that was fixed in netcore1.1… which is reasonably feasible given the Open Source nature of .NET Core.

That can all wait though (it’s a Sunday evening for me, after all…) – let’s see if we can fix the problem first.

Step 9: Fix it with a stroke of luck

Given that this feels like a memory management issue, let’s try something I’ve basically not used before: explicit struct layout.

A struct containing two double fields should be pretty easy to lay out: just fields at offsets 0 and 8, right? Admittedly it also sounds like it should be easy for the CLR to get right itself… but at least laying it out explicitly is low-risk.

using System.Runtime.InteropServices;

[StructLayout(LayoutKind.Explicit)]
struct Test
{
    [FieldOffset(0)]
    private readonly double x;
    [FieldOffset(8)]
    private readonly double y;

    ...
}

Normally, things don’t get fixed on first attempt, but in this case… it just worked!

Backtracking from the simplification, to the standalone comparison version, to fixing GeoPoint (which involved not using automatically implemented properties any more, as I want to apply the attribute to the field, not the property – boo!) and checking it works locally, to adding a commit to the PR and seeing it pass on Travis. Yay!

Next steps and points to note

My next step is definitely to try to find some history of this issue. It’s a surprisingly big problem to affect the GA .NET Core 1.0 runtime, so I expect there’s some record of it somewhere. I want to understand better what was wrong, whether my fix is appropriate, and whether I need to apply it elsewhere.

Update: this is a still an issue in the 1.0.7 runtime, and apparently even in the 1.0.8-servicing daily builds, so I’ve filed an issue and look forward to seeing what happens there.

Some interesting aspects:

• If you initially see a problem in CI, your top priority is to reproduce it locally.
• As ever, remove as much other code as you can – your production code, your test code, all dependencies.
• It’s handy to have multiple execution environments available. If I hadn’t had a local Linux box, this would have been a nightmare.
• Try different configurations and different runtimes/frameworks.
• Sometimes the bug really is in the runtime or BCL. It’s pretty rare, but it does happen.

I do most of my work in the google-cloud-dotnet github repo (That’s the repo for the Google Cloud Client Libraries for .NET, just to get a quick bit of marketing in there.) We try to keep our build and test dependencies up to date, so I recently updated to the latest versions of Microsoft.NET.Test.Sdk and xUnit.

Leaving aside problems identified by the xUnit analyzer which is now bundled in the xUnit package (some of which were useful, and some of which weren’t), this change caused another problem: while building from the command line worked fine, building some of the many solutions from Visual Studio (15.3.3) generated the following error:

Error MSB4018 The “GenerateBindingRedirects” task failed unexpectedly.
System.IO.PathTooLongException: The specified path, file name, or both are too long. The fully qualified file name must be less than 260 characters, and the directory name must be less than 248 characters.
at System.IO.PathHelper.GetFullPathName()
at System.IO.Path.LegacyNormalizePath(…)
at System.IO.Path.NormalizePath(…)
at System.IO.Path.NormalizePath(…)

(more stack trace here)

The output window shows a file related to the error:

C:\Program Files (x86)\Microsoft Visual Studio\2017\Community\MSBuild\15.0\Bin\Microsoft.Common.CurrentVersion.targets(2099,5)

So, what’s going on, and how do we fix it?

Step 1: Check that this change is responsible

Git makes life really easy here. For peace of mind – particularly for this kind of issue – I tend to close Visual Studio when switching branches, so:

• Find a solution that fails (e.g. Google.Cloud.Diagnostics.AspNetCore)
• Close VS
• git checkout master
• Rebuild solution in VS – looks fine
• Close VS
• git checkout branch with change
• Rebuild in VS – observe error
• git checkout master
• Rebuild solution in VS – looks fine
• Close VS
• git checkout branch with change
• Rebuild in VS – observe error

Yes, I did everything twice, just to make sure it wasn’t an anomaly.

So yes, it’s definitely a problem.

Step 2: Moan on Twitter

This isn’t the most scientific diagnostic tool in the world, but posting on Twitter about the problem did at least reassure me that I wasn’t alone.

Step 3: Narrow down the cause

Even though I observed the problem in Google.Cloud.Diagnostics.AspNetCore, the full error message in VS referred to Google.Cloud.Diagnostics.Common.IntegrationTests. That’s part of the Google.Cloud.Diagnostics.Common solution – the AspNetCore projects depend on the Common projects.

Try step 1 again with Google.Cloud.Diagnostics.Common (just one pass and one failure this time) – yes, it’s still a problem there. That’s useful.

Step 4: Try a workaround

All my source is under c:\Users\Jon\Test\Projects. The “Test” part is a bit of an anomaly, and next time I get a new machine, I’ll probably work without it, but there’s no need to change now. The Projects directory is actually a junction (symlink) to the c:\Users\Jon\Documents\Visual Studio 2015\Projects directory. That’s quite a long path to start with… let’s see if getting rid of the symlink helps.

• Delete symlink
• Move Projects file from under Documents to directly under Test
• Try to build: same failure

Okay, it looks like we’ll have to be a bit more subtle.

Step 5: Play spot the difference

Given that we have code which builds on the command line in both the working and failing situations, we can reasonably easily see any differences in generated files.

• On the command line, go into the Google.Cloud.Diagnostics.Common.IntegrationTests directory
• Delete bin and obj
• git checkout master
• Run dotnet build
• Copy the resulting bin and obj directories to a “working” directory
• git checkout branch with change
• Delete bin and obj
• Run dotnet build
• Copy the resulting bin and obj directories to a “broken” directory
• Run kdiff3 against the working and broken directories

There are lots of differences between the directories, as I’d expect, but given that this is about binding redirects, it’s reaosnable to use experience and start scanning for filenames ending with .config.

Sure enough, in the “broken” directory, under obj\net452, there was a file called Google.Cloud.Diagnostics.Common.IntegrationTests.csproj.Google.Cloud.Diagnostics.Common.IntegrationTests.dll.config. That’s not a copy and paste error – it really is a 115-character-long filename, even leaving out any directory parts.

In the file system, the full path is: c:\users\jon\Test\Projects/google-cloud-dotnet\apis\Google.Cloud.Diagnostics.Common\Google.Cloud.Diagnostics.Common.IntegrationTests\obj\Debug\net452\Google.Cloud.Diagnostics.Common.IntegrationTests.csproj.Google.Cloud.Diagnostics.Common.IntegrationTests.dll.config – that’s 266 characters.

Step 6: Try being slightly cheeky: very temporary workaround

Okay, so moving away from the “Documents\Visual Studio 2015” directory didn’t help much, but given that we’re just on the limit, let’s try just renaming “google-cloud-dotnet” to “short” (very temporarily).

Try opening it in Visual Studio – wahoo, it works :) The .config file is generated by Visual Studio correctly.

Step 7: Work out who to blame

So, where’s the bug?

• It’s a shame that Visual Studio 2017 doesn’t support long filenames, even though the dotnet CLI does
• Surely we don’t need such a long filename anyway
• Do I need the project name to be so long?

Looking back to the very first description, let’s have a look at the msbuild file that’s mentioned: C:\Program Files (x86)\Microsoft Visual Studio\2017\Community\MSBuild\15.0\Bin\Microsoft.Common.CurrentVersion.targets

That has:

<GenerateBindingRedirects
  AppConfigFile="@(AppConfigWithTargetPath)"
  TargetName="$(TargetFileName).config"
  OutputAppConfigFile="$(_GenerateBindingRedirectsIntermediateAppConfig)"
  SuggestedRedirects="@(SuggestedBindingRedirects)"
>

So it looks like the problem is _GenerateBindingRedirectsIntermediateAppConfig, which is defined in a property group elsewhere as:

<_GenerateBindingRedirectsIntermediateAppConfig>$(IntermediateOutputPath)$(MSBuildProjectFile).$(TargetFileName).config</_GenerateBindingRedirectsIntermediateAppConfig>

That certainly looks like it’s responsible for the choice of file.

A quick search for _GenerateBindingRedirectsIntermediateAppConfig shows that I’m not the first person to have run into this – PathTooLongException with _GenerateBindingRedirectsIntermediateAppConfig describes exactly the pain I’ve been going through, and even helpfully references MSBuild should handle paths longer than MAX_PATH.

I’ll add my little bit of feedback to the former issue as soon as I’ve published this post (so I can link to it).

Step 8: Decide what to do

My options appear to be:

1. Change the project name or the directory structure
2. Ask everyone on the team to work from a really short root directory name
3. Downgrade my dependencies again
4. Live with Visual Studio not building a few solutions properly – we can still work in Visual Studio, so long as we don’t need a full build in it.

I went with option 4, and published this blog post.

Step 9: Embrace community feedback

Theose were the only options I considered at the time of original writing, partly as I was somewhat scared of this suggestion, being inexperienced in msbuild. However, combining that with a Directory.Build.targets file (which I didn’t know about before being tipped off by Nick Guerrera), it was very easy to implement a repo-wide workaround.

My friend Kirill Osenkov also pointed me at his MSBuild Log Viewer and pointed out that if it failed in Visual Studio, it would probably fail from msbuild on the command line. He was right, and the log viewer pinpointed what it was trying to write, which would have saved time.

Points to note

• Situations where you have a working case and a broken case are great. They can help you validate your problem (does it go away if I revert to the previous commit?) and find the cause (what’s the difference in output between working and broken?)
• Temporary approaches to double-check the diagnosis (such as me renaming my source directory to “short”) can be useful – don’t forget to undo them though!
• If you’ve run into a problem, someone else probably has too
• The .NET community can be really amazing – I was really impressed by the response here
• Tools are often available – in this case, msbuildlog.com would have saved me quite a bit of time.