dokan-dev / dokan-dotnet

Dokan DotNet Wrapper
http://dokan-dev.github.io
MIT License
462 stars 116 forks source link

Error when cloning git repository into container #261

Closed phobeus closed 4 years ago

phobeus commented 4 years ago

When I'm trying to use "git clone" to clone the repository into a mounted folder, the git command fails at certain positions. At first I thought it had something to do with our driver, but I was able to reproduce this on the master branch on dokan-dotnet, running with stock settings (I mounted the drive to V:) Here's the output of the command:

PS V:\> git clone https://github.com/phobeus/dokan-dotnet.git
Cloning into 'dokan-dotnet'...
remote: Enumerating objects: 75, done.
remote: Counting objects: 100% (75/75), done.
remote: Compressing objects: 100% (56/56), done.
remote: Total 2369 (delta 39), reused 40 (delta 19), pack-reused 2294
Receiving objects: 100% (2369/2369), 2.07 MiB | 431.00 KiB/s, done.
Resolving deltas: 100% (1580/1580), done.
error: unable to append to 'V:/dokan-dotnet/.git/logs/refs/remotes/origin/HEAD': Invalid argument
fatal: update_ref failed for ref 'HEAD': cannot update the ref 'HEAD': unable to append to 'V:/dokan-dotnet/.git/logs/HEAD': Invalid argument
Unlink of file 'dokan-dotnet/.git/objects/pack/pack-726956d72141b339e8fa1feda01e32f0fd7c7330.idx' failed. Should I try again? (y/n) n
Unlink of file 'dokan-dotnet/.git/objects/pack/pack-726956d72141b339e8fa1feda01e32f0fd7c7330.idx' failed. Should I try again? (y/n) n
PS V:\>

If I attach a trace logger, it looks like I'm running into a timing issue:

PS V:\> git clone https://github.com/phobeus/dokan-dotnet.git
Cloning into 'dokan-dotnet'...
error: failed to write new configuration file V:/dokan-dotnet/.git/config.lock
fatal: could not set 'core.filemode' to 'false'

In the trace log, I see the following errors:

DokanNetMirror.exe Information: 0 : WriteFileProxy : \dokan-dotnet\.git\config.lock
DokanNetMirror.exe Information: 0 :   NumberOfBytesToWrite  18
DokanNetMirror.exe Information: 0 :   Offset  7
DokanNetMirror.exe Information: 0 :   Context {System.IO.FileStream, False, False, False, False, #36056, True, False}
DokanNetMirror.exe Information: 0 : Buffer size 18 not power of 2 or too large, returning unpooled buffer.
DokanNetMirror.exe Information: 0 : -1 (size 18) outside pool range, discarding buffer.
DokanNetMirror.exe Information: 0 : WriteFileProxy : \dokan-dotnet\.git\config.lock Return : Success NumberOfBytesWritten : 18
DokanNetMirror.exe Information: 0 : ReadFileProxy : \dokan-dotnet\.git\config
DokanNetMirror.exe Information: 0 :   BufferLength  4096
DokanNetMirror.exe Information: 0 :   Offset  0
DokanNetMirror.exe Information: 0 : Exception thrown: 'System.FormatException' in mscorlib.dll
DokanNetMirror.exe Error: 0 : ReadFileProxy : \dokan-dotnet\.git\config Throw : Input string was not in a correct format.

In my own application, I'm getting the following error, but I was never able to reproduce this on mirror unfortunately:

2020-10-22 13:00:58.479 +02:00 [DBG] GetFileInformationProxy : \test\repo\.git\logs\refs\remotes\origin\HEAD
2020-10-22 13:00:58.479 +02:00 [DBG]    Context {<null>, False, False, False, False, #29660, False, False}
2020-10-22 13:00:58.479 +02:00 [DBG]    FileName    HEAD
2020-10-22 13:00:58.479 +02:00 [DBG]    Attributes  "Normal"
2020-10-22 13:00:58.479 +02:00 [DBG]    CreationTime    "2020-10-22T13:00:58.4775505+02:00"
2020-10-22 13:00:58.479 +02:00 [DBG]    LastAccessTime  "2020-10-22T13:00:58.4775505+02:00"
2020-10-22 13:00:58.479 +02:00 [DBG]    LastWriteTime   "2020-10-22T13:00:58.4775505+02:00"
2020-10-22 13:00:58.479 +02:00 [DBG]    Length  0
2020-10-22 13:00:58.479 +02:00 [DBG] GetFileInformationProxy : \test\repo\.git\logs\refs\remotes\origin\HEAD Return : "Success"
2020-10-22 13:00:58.480 +02:00 [DBG] WriteFileProxy : \test\repo\.git\logs\refs\remotes\origin\HEAD
2020-10-22 13:00:58.480 +02:00 [DBG]    NumberOfBytesToWrite    191
2020-10-22 13:00:58.480 +02:00 [DBG]    Offset  -1
2020-10-22 13:00:58.480 +02:00 [DBG]    Context {<null>, False, False, False, False, #29660, True, True}
2020-10-22 13:00:58.480 +02:00 [DBG] Buffer size 191 not power of 2 or too large, returning unpooled buffer.
2020-10-22 13:00:58.504 +02:00 [DBG] -1 (size 191) outside pool range, discarding buffer.
2020-10-22 13:00:58.504 +02:00 [ERR] WriteFileProxy : \test\repo\.git\logs\refs\remotes\origin\HEAD Throw : Specified argument was out of the range of valid values.
Parameter name: from

Which is weird, from what I've gathered on the dokan side, the offset of -1 should be handled as an "ammend" by fuse? I'm not 100% certain though and I'm also not certain that this is the same issue, we just had similar errors when cloning repositories.

Please let me know if I should attach better logging for this or if this is reproduceable enough. The clone runs through if I use mirror.exe though, so I thought posting this here seems like the right spot.

Liryna commented 4 years ago

Hi @phobeus ,

You are right, -1 should be taken as an "APPEND_DATA"! Good catch.I haven't even looked if the C# Mirror is supporting this case 😢

https://docs.microsoft.com/en-us/windows/win32/api/fileapi/nf-fileapi-writefile

To write to the end of file, specify both the Offset and OffsetHigh members of the OVERLAPPED structure as 0xFFFFFFFF. This is functionally equivalent to previously calling the CreateFile function to open hFile using FILE_APPEND_DATA access.

FileStream.Position used will be set to -1 and the doc says nothing of what will happen. I might be better to add a check for -1 offset and seek the end of the file ourself. Would you be able to do the test ?

phobeus commented 4 years ago

Hey @Liryna ,

We were able to reproduce this inside our software in a unit test. Here's the code for the curious:

    public void TestWriteOverlapped() {
      var fileName = GetTemporaryFileName();

      var handle = Win32Api.CreateFile(fileName,
        Win32Api.GENERIC_READ | Win32Api.GENERIC_WRITE,
        Win32Api.FILE_SHARE_NONE,
        IntPtr.Zero,
        Win32Api.CREATE_ALWAYS,
        Win32Api.FILE_FLAG_OVERLAPPED,
        IntPtr.Zero
      );

      var writeBuffer = new byte[] { 65, 66, 68 };
      var result = WriteFileWithOverlappedAppend(handle, writeBuffer, out var bytesWritten);
      Assert.That(bytesWritten, Is.EqualTo(writeBuffer.Length));
      Assert.That(result, Is.True);
    }

    private bool WriteFileWithOverlappedAppend(SafeFileHandle handle, byte[] writeBuffer, out uint bytesWritten)
    {
      var stateChangeEvent = new ManualResetEvent(false);
      var nativeOverlapped = new NativeOverlapped
      {
        OffsetHigh = -1,
        OffsetLow = -1,
        EventHandle = stateChangeEvent.SafeWaitHandle.DangerousGetHandle()
      };

      // See http://www.pinvoke.net/default.aspx/kernel32/GetOverlappedResult.html for more information
      var result = Win32Api.WriteFile(handle.DangerousGetHandle(), writeBuffer, (uint)writeBuffer.Length, out bytesWritten, ref nativeOverlapped);
      var lastError = Marshal.GetLastWin32Error();
      if (!result && (lastError == Win32ErrorCodes.ERROR_IO_PENDING || lastError == Win32ErrorCodes.ERROR_SUCCESS))
      {
        return Win32Api.GetOverlappedResult(handle.DangerousGetHandle(), ref nativeOverlapped, out bytesWritten, true);
      }

      bytesWritten = 0;
      return false;
    }

When running this test on windows, it's fine, but in dokan-dotnet it crashes. I have not had the time to try to fix it yet, just wanted to update for now.

phobeus commented 4 years ago

I created a pull request: #262 with the fix. After the fix, I was able to pull git repositories.

Liryna commented 4 years ago

@phobeus Thank you very much for reporting, investigating and contributing the fix ! That's very much appreciated it really deserves a 🏆 !