Added a multithreaded hydration functional test by sanoursa · Pull Request #212 · microsoft/VFSForGit

sanoursa · 2018-08-23T22:17:37Z

There was a previously existing functional test, but it would hydrate a file on a single thread, and then attempt to repeatedly read from it from 4 parallel threads. That test was ensuring that it's possible to read from a hydrated placeholder, but it did not cover the races that we are currently investigating on Mac.

I added a new test that uses 32 threads to concurrently read from a path that was previously completely virtual, all the way to the root of the repo. On my MacBook Pro, this test has failed every single time with 32 threads (and about 80% with 16 threads, 50% with 4 threads). I'm posting the test now to ensure that it is failing on our build servers, and anyone else's machines if you have time to test it out.

Before completing this PR, I will need to either mark the test as Windows-only, or else fix the races on Mac, though I suspect that will take longer.

…attempting to concurrently read a previously unhydrated file from several threads

sanoursa · 2018-08-23T22:19:54Z

@nickgra @wilbaker It would be really helpful if you two have time to run this new test a few times and confirm that it fails reliably for you. I'd like to make sure the failure is reliable, so we then have confidence in the fix(es) as well.

wilbaker · 2018-08-24T00:14:02Z

On my first run I hit the failure:

1) Failed : GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel()
  At least one of the reads failed
  Expected: null
  But was:  <System.IO.FileNotFoundException: Could not find file '/GVFS.FT/test/abccb9029e3642258ab2/src/GVFS/GVFS.FunctionalTests/Tests/LongRunningEnlistment/GitMoveRenameTests.cs'.
File name: '/GVFS.FT/test/abccb9029e3642258ab2/src/GVFS/GVFS.FunctionalTests/Tests/LongRunningEnlistment/GitMoveRenameTests.cs'
   at Interop.ThrowExceptionForIoErrno(ErrorInfo errorInfo, String path, Boolean isDirectory, Func`2 errorRewriter)
   at Microsoft.Win32.SafeHandles.SafeFileHandle.Open(String path, OpenFlags flags, Int32 mode)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
   at System.IO.StreamReader..ctor(String path, Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize)
   at System.IO.File.InternalReadAllText(String path, Encoding encoding)
   at System.IO.File.ReadAllText(String path)
   at GVFS.FunctionalTests.FileSystemRunners.SystemIORunner.ReadAllText(String path) in /Users/wilbaker/Repos/VFSForGit/src/GVFS/GVFS.FunctionalTests/FileSystemRunners/SystemIORunner.cs:line 68
   at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.<>c__DisplayClass0_0.<CanReadVirtualFileInParallel>b__0() in /Users/wilbaker/Repos/VFSForGit/src/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 38>
   at GVFS.Tests.Should.ValueShouldExtensions.ShouldBeNull[T](T obj, String message) in /Users/wilbaker/Repos/VFSForGit/src/GVFS/GVFS.Tests/Should/ValueShouldExtensions.cs:line 76
   at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel() in /Users/wilbaker/Repos/VFSForGit/src/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 54

I'll run some more iterations tomorrow.

nickgra · 2018-08-24T00:51:10Z

On my tiny Mac Mini, I have reproed the failure 5 times in a row.

1) Failed : GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel()
  At least one of the reads failed
  Expected: null
  But was:  <System.IO.DirectoryNotFoundException: Could not find a part of the path '/GVFS.FT/test/a1b2d1730a1d43eab942/src/GVFS/GVFS.FunctionalTests/Tests/LongRunningEnlistment/GitMoveRenameTests.cs'.
   at Interop.ThrowExceptionForIoErrno(ErrorInfo errorInfo, String path, Boolean isDirectory, Func`2 errorRewriter)
   at Microsoft.Win32.SafeHandles.SafeFileHandle.Open(String path, OpenFlags flags, Int32 mode)
   at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
   at System.IO.StreamReader..ctor(String path, Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize)
   at System.IO.File.InternalReadAllText(String path, Encoding encoding)
   at System.IO.File.ReadAllText(String path)
   at GVFS.FunctionalTests.FileSystemRunners.SystemIORunner.ReadAllText(String path) in /Users/nickgra/VFSForGit/GVFS/GVFS.FunctionalTests/FileSystemRunners/SystemIORunner.cs:line 68
   at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.<>c__DisplayClass0_0.<CanReadVirtualFileInParallel>b__0() in /Users/nickgra/VFSForGit/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 38>
   at GVFS.Tests.Should.ValueShouldExtensions.ShouldBeNull[T](T obj, String message) in /Users/nickgra/VFSForGit/GVFS/GVFS.Tests/Should/ValueShouldExtensions.cs:line 76
   at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel() in /Users/nickgra/VFSForGit/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 54

I'll try on my Mac Pro and the iMac Pro tomorrow.

Code LGTM though.

jrbriggs · 2018-08-24T12:56:50Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

+                    }
+                    catch (Exception e)
+                    {
+                        readException = e;


Does the number of failed reads provide any interesting signal?

I wondered about that too, but I'm not sure that it would. The number needs to be 0, always. And if it's ever non-zero, it signals that there's at least one race, somewhere, but gives no more signal than that. So I think this is a binary test, unless you can think of more we can get out of it?

So I think this is a binary test, unless you can think of more we can get out of it?

@sanoursa, have you checked if the thread(s) that are failing are all failing with the same exception?

Every time I've seen it fail, it has been one of the two failures that you and Nick reported. One of the directories or the file appears missing.

There's no expectation that they will all fail with the same exception. What's happening is that they are all racing on creating the placeholder directories, expanding those directories, then creating the placeholder file, and finally hydrating it. Since we currently have races in our enumeration of directories, one of the directories or the leaf file will sometimes appear to be missing.

That said, I can definitely update it to print out every exception we get, if you think it'll add more diagnostic value.

That said, I can definitely update it to print out every exception we get, if you think it'll add more diagnostic value.

I think we can start with just printing one. I agree the most important\interesting part of this test is simply whether or not it succeeds.

wilbaker · 2018-08-24T15:48:03Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

+                threads[i].Join();
+            }
+
+            readException.ShouldBeNull("At least one of the reads failed");


Can you print the Exception callstack here as well?

It already is - see your test output up above :-)

Should have checked the output first :) You're right I can see the exception, thanks!

wilbaker · 2018-08-24T15:48:37Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

+                    }
+                    catch (Exception e)
+                    {
+                        readException = e;


So I think this is a binary test, unless you can think of more we can get out of it?

@sanoursa, have you checked if the thread(s) that are failing are all failing with the same exception?

sanoursa · 2018-08-24T16:09:27Z

Confirmed that the Mac build agent also fails on this test:

2018-08-24T15:52:34.7491020Z => GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel()
2018-08-24T15:52:34.7508480Z Test GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel()
2018-08-24T15:52:34.7525560Z Failed at 3:52:34 PM taking 00:00:00.9360170
2018-08-24T15:52:34.7542200Z   At least one of the reads failed
2018-08-24T15:52:34.7558830Z   Expected: null
2018-08-24T15:52:34.7590470Z   But was:  <System.IO.DirectoryNotFoundException: Could not find a part of the path '/GVFS.FT/test/b0d29b4197074782bb10/src/GVFS/GVFS.FunctionalTests/Tests/LongRunningEnlistment/GitMoveRenameTests.cs'.
2018-08-24T15:52:34.7635860Z    at Interop.ThrowExceptionForIoErrno(ErrorInfo errorInfo, String path, Boolean isDirectory, Func`2 errorRewriter)
2018-08-24T15:52:34.7664860Z    at Microsoft.Win32.SafeHandles.SafeFileHandle.Open(String path, OpenFlags flags, Int32 mode)
2018-08-24T15:52:34.7688230Z    at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options)
2018-08-24T15:52:34.7708560Z    at System.IO.StreamReader..ctor(String path, Encoding encoding, Boolean detectEncodingFromByteOrderMarks, Int32 bufferSize)
2018-08-24T15:52:34.7727550Z    at System.IO.File.InternalReadAllText(String path, Encoding encoding)
2018-08-24T15:52:34.7753650Z    at System.IO.File.ReadAllText(String path)
2018-08-24T15:52:34.7772920Z    at GVFS.FunctionalTests.FileSystemRunners.SystemIORunner.ReadAllText(String path) in /Users/vsts/agent/2.139.0/work/1/s/GVFS/GVFS.FunctionalTests/FileSystemRunners/SystemIORunner.cs:line 68
2018-08-24T15:52:34.7793560Z    at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.<>c__DisplayClass0_0.<CanReadVirtualFileInParallel>b__0() in /Users/vsts/agent/2.139.0/work/1/s/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 38>
2
2018-08-24T15:56:52.9206430Z    at GVFS.Tests.Should.ValueShouldExtensions.ShouldBeNull[T](T obj, String message) in /Users/vsts/agent/2.139.0/work/1/s/GVFS/GVFS.Tests/Should/ValueShouldExtensions.cs:line 76
2018-08-24T15:56:52.9223800Z    at GVFS.FunctionalTests.Tests.EnlistmentPerFixture.MultithreadedReadWriteTests.CanReadVirtualFileInParallel() in /Users/vsts/agent/2.139.0/work/1/s/GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs:line 54

sanoursa · 2018-08-24T17:17:16Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

+            Thread[] threads = new Thread[32];
+            for (int i = 0; i < threads.Length; ++i)
+            {
+                int myIndex = i;


No need for this index, it's not being used anywhere

sanoursa · 2018-08-24T17:17:49Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

+                {
+                    try
+                    {
+                        FileSystemRunner.DefaultRunner.ReadAllText(virtualPath).ShouldBeNonEmpty();


I think there would be value in using all of our runners here, since they may have slightly different timing or system calls that trigger hydration in different ways.

And that implies a need to make this class create an enlistment per test case, since the test is guaranteed to pass the second time around, regardless of races

Interestingly enough, I can't repro the failures with the BashRunner, so I'm not going to add the overhead of a new enlistment per test case for now. It must be that having to spawn a new bash process per request slows things down enough to avoid hitting these races, because the SystemIORunner fails completely reliably and the BashRunner passes completely reliably, on my MacBook Pro.

sanoursa · 2018-08-24T18:18:24Z

GVFS/GVFS.FunctionalTests/Tests/EnlistmentPerFixture/MultithreadedReadWriteTests.cs

-        [TestCase]
-        public void CanReadUnhydratedFileInParallelWithoutTearing()
+        [TestCase, Order(1)]
+        [Category(Categories.Windows)]


Marked as Windows-only for now. I'm rerunning the tests on both platforms now, and will merge in once those pass. I'll then remove this category in my other PR for reproing and prototyping fixes for the races.

Added a multithreaded functional test that currently fails on Mac by …

89d702c

…attempting to concurrently read a previously unhydrated file from several threads

Fix spacing

9790552

jrbriggs reviewed Aug 24, 2018

View reviewed changes

wilbaker reviewed Aug 24, 2018

View reviewed changes

wilbaker approved these changes Aug 24, 2018

View reviewed changes

sanoursa commented Aug 24, 2018

View reviewed changes

Mark the new test as Windows-only

18611be

nickgra approved these changes Aug 24, 2018

View reviewed changes

sanoursa commented Aug 24, 2018

View reviewed changes

sanoursa merged commit 0449ca0 into microsoft:master Aug 24, 2018

sanoursa deleted the hydration-race branch August 24, 2018 19:14

jrbriggs mentioned this pull request Oct 12, 2018

Merge milestones/M142 to releases/shipped #381

Merged

Conversation

sanoursa commented Aug 23, 2018

Uh oh!

sanoursa commented Aug 23, 2018

Uh oh!

wilbaker commented Aug 24, 2018

Uh oh!

nickgra commented Aug 24, 2018

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

sanoursa commented Aug 24, 2018 • edited Loading Uh oh! There was an error while loading. Please reload this page.

Uh oh!

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Choose a reason for hiding this comment

Uh oh!

Reviewers

Assignees

Labels

Projects

Milestone

Development

Uh oh!

4 participants

sanoursa commented Aug 24, 2018 •

edited

Loading