Delay between CloseHandle function call and SMB Close request

Question

The bit of code below opens a file on an SMB share and closes it immediately. For some reason I'm seeing a delay between the CloseHandle call and the SMB Close request being sent over the wire.

#include <Windows.h>
#include <stdio.h>

typedef NTSTATUS (__stdcall *NtQuerySecurityObjectPtr)(
    _In_  HANDLE               Handle,
    _In_  SECURITY_INFORMATION SecurityInformation,
    _Out_ PSECURITY_DESCRIPTOR SecurityDescriptor,
    _In_  ULONG                Length,
    _Out_ PULONG               LengthNeeded
    );

void printTime() {
    SYSTEMTIME time;
    GetSystemTime(&time);
    int required = GetTimeFormat(LOCALE_INVARIANT, 0, &time, nullptr, nullptr, 0);
    LPTSTR buffer = (LPTSTR)GlobalAlloc(GPTR, required * sizeof(TCHAR));
    GetTimeFormat(LOCALE_INVARIANT, 0, &time, nullptr, buffer, required);
    wprintf(L"%s\n", buffer);
}

int main()
{
    LPCTSTR file = L"\\\\192.168.13.163\\share\\file1";
    HANDLE f = INVALID_HANDLE_VALUE;


    f = CreateFile(
        file,
        GENERIC_WRITE,
        FILE_SHARE_READ | FILE_SHARE_WRITE | FILE_SHARE_DELETE,
        nullptr,
        CREATE_ALWAYS,
        FILE_FLAG_BACKUP_SEMANTICS | FILE_FLAG_SEQUENTIAL_SCAN,
        INVALID_HANDLE_VALUE
        );
    CloseHandle(f);
    printTime();

    return 0;
}

I ran this code with a debugger and put a breakpoint right after the printTime call. In one test run of this printTime outputs 12:18:11. In Wireshark I see the corresponding Close request being sent out at 12:18:20. So there's about 10s delay between the function call and the message being sent out.

I thought this might be due to a handle being leaked somewhere or some other process keeping a handle to the file open, but I don't think that's the case. If I halt the program right before the CloseHandle call, the sysinternals handle tool, executed in a system user shell, shows me that my process has a handle to the file

C:\Users\pepijn\Desktop>Handle.exe file1

Handle v4.0
Copyright (C) 1997-2014 Mark Russinovich
Sysinternals - www.sysinternals.com

SmbClose.exe       pid: 7020   type: File            C8: \Device\Mup\192.168.13.163\DMTest_share\file1

Running the same command right after the CloseHandle call results in no handles being found

C:\Users\pepijn\Desktop>Handle.exe file1

Handle v4.0
Copyright (C) 1997-2014 Mark Russinovich
Sysinternals - www.sysinternals.com

No matching handles found.

Does anyone know what could be the cause of this delay?

The closest related question on this topic I could find is FileStream.Close() is not closing the file handle instantly. The accepted answer there is that some other process might be holding on to the file. As stated above, I don't think that's the case here. I don't have any virus scanners running and I would expect any open handles to show up in the output of Handle since it's running with elevated privileges.

Answer 1

Not exactly an answer (sorry), but I think this might happen with local files as well. I'm working on backup software that runs on Windows and Linux, and has a test suite, during which it opens an old file, reads its contents, writes a new file, closes the old one and then renames over it.

On Unix this is fine because we can rename over an existing file, even an open one. On Windows these tests fail reliably if I don't close the filehandle first. However, even if I do, the tests fail randomly about 10% of the time, like this:

TRACE: Trying to create testfiles/0_0\backup\01234567\refcount.rdb.rfw shared using dwShareMode FILE_SHARE_READ | FILE_SHARE_WRITE [check fix] WARNING: Exception thrown: CommonException(OSFileError) (Failed to rename temporary refcount database file from testfiles/0_0\backup\01234567\refcount.rdb.rfwX to testfiles/0_0\backup\01234567\refcount.rdb.rfw: Access is denied. (5)) at C:\projects\boxbackup\lib\backupstore\BackupStoreRefCountDatabase.cpp:200

I know that I close the file with CloseHandle() before renaming over it. The symptoms would be perfectly explained by CloseHandle() happening asynchronously, but so far my experience and this question are the only evidence I have that this might happening. And this is on a local filesystem, not SMB (I think, because AppVeyor's internals are a bit of a black box to me).

Edit: I found confirmation and explanation in another StackOverflow question and answer:

I believe this is covered in Windows Internals. The short story is that even though you've called CloseHandle on the file handle, the kernel may still have outstanding references that take a few milliseconds to close.

Answer 2

Thanks to the first answer I had a better idea of where to look. As far as I can tell this is intentional behaviour in the Windows SMB redirector. It has a cache of open file handles that are reaped every x seconds. This is done to transparently optimise applications that open/close/reopen files often. There are a number of registry keys that should influence this (see https://support.microsoft.com/en-us/kb/102981, https://msdn.microsoft.com/en-us/library/windows/hardware/dn567661%28v=vs.85%29.aspx, https://social.msdn.microsoft.com/Forums/en-US/832d395b-6e6f-4658-8dbb-120138a4cd7c/smb2-registry-settings?forum=os_fileservices) but none of these seem to result in an immediate SMB close request on CloseHandle. The best result I've been able to get is by setting CacheFileTimeout to 0. That still leaves a delay of somewhere between 3-5 seconds (probably determined by how often the cleanup timer is triggered).

Answer 3

This is apparently due to Batch Oplock (or relative Lease) granted by the server on file open. You can prove this by inspecting Create response with Wireshark.

One of recommended tricks to avoid batch oplocks being granted si opening the same file for reading in another application right before your original CreateFile call.