3

I know that when windows processes open files for reading, they lock them. How does Windows indexer do that? Can it prevent the file from being deleted in addition to slowing everything down? Can my script disable the indexing in the working folder?

I wonder because we use files for interprocess communication. I monitor when to.ugp file is deleted. This works very well only on the machine where search indexer is disabled. I have traiced the logs with filemonitor:


"Time of Day","Process Name","PID","Operation","Path","Result","Detail"
"2:56,0481127","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0529609","java.exe","5812","ReadFile","C:\to.ugp","SUCCESS","Offset: 0, Length: 124, Priority: Normal"
"2:56,0532777","java.exe","5812","ReadFile","C:\to.ugp","END OF FILE","Offset: 124, Length: 8 192, Priority: Normal"
"2:56,0533272","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,1397217","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,2482956","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,3578338","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,4672443","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,5773732","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,6858176","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,7515643","java.exe","3672","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Write Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7546558","java.exe","3672","SetBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 1.01.1601 2:00:00, LastAccessTime: 1.01.1601 2:00:00, LastWriteTime: 1.01.1601 2:00:00, ChangeTime: 1.01.1601 2:00:00, FileAttributes: N"
"2:56,7547107","java.exe","3672","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7548412","java.exe","3672","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7548586","java.exe","3672","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: N"
"2:56,7548660","java.exe","3672","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7549417","java.exe","3672","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7557996","java.exe","3672","QueryAttributeTagFile","C:\to.ugp","SUCCESS","Attributes: N, ReparseTag: 0x0"
"2:56,7558105","java.exe","3672","SetDispositionInformationFile","C:\to.ugp","CANNOT DELETE","Delete: True"
"2:56,7559298","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Open Reparse Point, Open Requiring Oplock, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7569872","java.exe","3672","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7574543","SearchProtocolHost.exe","2556","FileSystemControl","C:\to.ugp","SUCCESS","Control: FSCTL_REQUEST_FILTER_OPLOCK"
"2:56,7574678","SearchProtocolHost.exe","2556","QueryStandardInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 128, EndOfFile: 124, NumberOfLinks: 1, DeletePending: False, Directory: False"
"2:56,7574770","SearchProtocolHost.exe","2556","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: N"
"2:56,7574851","SearchProtocolHost.exe","2556","QueryFileInternalInformationFile","C:\to.ugp","SUCCESS","IndexNumber: 0x19000000017817"
"2:56,7574986","SearchProtocolHost.exe","2556","FileSystemControl","C:\to.ugp","NOT REPARSE POINT","Control: FSCTL_GET_REPARSE_POINT"
"2:56,7575205","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","BUFFER OVERFLOW","Information: Owner, Group, DACL"
"2:56,7575449","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","SUCCESS","Information: Owner, Group, DACL"
"2:56,7575598","SearchProtocolHost.exe","2556","QueryNameInformationFile","C:\to.ugp","SUCCESS","Name: \to.ugp"
"2:56,7577304","SearchProtocolHost.exe","2556","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: N"
"2:56,7578549","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Disallow Exclusive, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7640826","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Read Control, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,7642734","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","BUFFER OVERFLOW","Information: Owner"
"2:56,7642868","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","SUCCESS","Information: Owner"
"2:56,7642992","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7654345","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7654858","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,7944973","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:56,9036038","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,0130876","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,0435401","MsMpEng.exe","168","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Non-Directory File, Open For Backup, Open Requiring Oplock, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:57,0436088","MsMpEng.exe","168","FileSystemControl","C:\to.ugp","OPLOCK HANDLE CLOSED","Control: FSCTL_REQUEST_OPLOCK"
"2:57,0436382","MsMpEng.exe","168","FileSystemControl","C:\to.ugp","SUCCESS","Control: 0x902eb (Device:0x9 Function:186 Method: 3)"
"2:57,0436661","MsMpEng.exe","168","CloseFile","C:\to.ugp","SUCCESS",""
"2:57,1223547","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,2315334","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,3407068","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,4499606","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,5588147","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,6683427","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:57,7771626","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"

You see that java.exe:2484 is a producer process and it polls the to.ugp file until it exists with the intent to create a new one when file is deleted by consumer. java.exe:5812 is the consumer. It reads the file in the beginning of the trace and ceases to exist. Then java.exe:2484 polls - file still exists. Then, new consumer is created. It must remove the previously consumed file. But SetDispositionInformationFile results with "CANNOT DELETE" error. Why? I see that SeachHost opens the file before new consumer closes it. The file will never be deleted and java.exe:2484 will poll in the end alone.

I also traced the preceding accesses to the file (may be it will help you to say what caused the error?):


"2:54,8446903","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:54,9535548","java.exe","2484","QueryDirectory","C:\to.ugp","SUCCESS","Filter: to.ugp, 1: to.ugp"
"2:54,9757732","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Write Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:54,9760764","java.exe","5812","SetBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 1.01.1601 2:00:00, LastAccessTime: 1.01.1601 2:00:00, LastWriteTime: 1.01.1601 2:00:00, ChangeTime: 1.01.1601 2:00:00, FileAttributes: N"
"2:54,9761405","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:54,9763673","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:54,9763960","java.exe","5812","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:54, LastWriteTime: 11.11.2013 2:54, ChangeTime: 11.11.2013 2:54, FileAttributes: N"
"2:54,9764080","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:54,9765206","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:54,9766858","java.exe","5812","QueryAttributeTagFile","C:\to.ugp","SUCCESS","Attributes: N, ReparseTag: 0x0"
"2:54,9766972","java.exe","5812","SetDispositionInformationFile","C:\to.ugp","SUCCESS","Delete: True"
"2:54,9767347","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","NAME NOT FOUND","Desired Access: Generic Read, Disposition: Open, Options: Open Reparse Point, Open Requiring Oplock, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"2:54,9767870","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:55,0636366","java.exe","2484","QueryDirectory","C:\to.ugp","NO SUCH FILE","Filter: to.ugp"
"2:55,3118545","MsMpEng.exe","168","CreateFile","C:\to.ugp","NAME NOT FOUND","Desired Access: Read Attributes, Disposition: Open, Options: Non-Directory File, Open For Backup, Open Requiring Oplock, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a"
"2:56,0325778","java.exe","2484","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read/Write, Disposition: OpenIf, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 0, OpenResult: Created"
"2:56,0332831","java.exe","2484","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A"
"2:56,0333387","java.exe","2484","QueryStandardInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 0, EndOfFile: 0, NumberOfLinks: 1, DeletePending: False, Directory: False"
"2:56,0333560","java.exe","2484","SetEndOfFileInformationFile","C:\to.ugp","SUCCESS","EndOfFile: 0"
"2:56,0333840","java.exe","2484","SetAllocationInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 0"
"2:56,0334979","java.exe","2484","WriteFile","C:\to.ugp","SUCCESS","Offset: 0, Length: 124, Priority: Normal"
"2:56,0335560","java.exe","2484","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0337311","MsMpEng.exe","168","CreateFileMapping","C:\to.ugp","FILE LOCKED WITH WRITERS","SyncType: SyncTypeCreateSection, PageProtection: "
"2:56,0337485","MsMpEng.exe","168","QueryStandardInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 128, EndOfFile: 124, NumberOfLinks: 1, DeletePending: False, Directory: False"
"2:56,0354539","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Open Reparse Point, Open Requiring Oplock, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0360802","SearchProtocolHost.exe","2556","FileSystemControl","C:\to.ugp","SUCCESS","Control: FSCTL_REQUEST_FILTER_OPLOCK"
"2:56,0360990","SearchProtocolHost.exe","2556","QueryStandardInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 128, EndOfFile: 124, NumberOfLinks: 1, DeletePending: False, Directory: False"
"2:56,0361142","SearchProtocolHost.exe","2556","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A"
"2:56,0361262","SearchProtocolHost.exe","2556","QueryFileInternalInformationFile","C:\to.ugp","SUCCESS","IndexNumber: 0x19000000017817"
"2:56,0361457","SearchProtocolHost.exe","2556","FileSystemControl","C:\to.ugp","NOT REPARSE POINT","Control: FSCTL_GET_REPARSE_POINT"
"2:56,0361687","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","BUFFER OVERFLOW","Information: Owner, Group, DACL"
"2:56,0361793","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","SUCCESS","Information: Owner, Group, DACL"
"2:56,0361928","SearchProtocolHost.exe","2556","QueryNameInformationFile","C:\to.ugp","SUCCESS","Name: \to.ugp"
"2:56,0363623","SearchProtocolHost.exe","2556","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A"
"2:56,0366114","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Disallow Exclusive, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0375913","SearchProtocolHost.exe","2556","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Read Control, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0377580","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","BUFFER OVERFLOW","Information: Owner"
"2:56,0377764","SearchProtocolHost.exe","2556","QuerySecurityFile","C:\to.ugp","SUCCESS","Information: Owner"
"2:56,0377941","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0383196","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0383494","java.exe","5812","QueryNetworkOpenInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, AllocationSize: 1.01.1601 2:00:00, EndOfFile: 1.01.1601 2:00:00, FileAttributes: A"
"2:56,0383628","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0384852","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0385482","SearchProtocolHost.exe","2556","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0401676","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0402242","java.exe","5812","QueryInformationVolume","C:\to.ugp","SUCCESS","VolumeCreationTime: 3.09.2013 8:22:20, VolumeSerialNumber: C2F2-255E, SupportsObjects: True, VolumeLabel: "
"2:56,0402387","java.exe","5812","QueryAllInformationFile","C:\to.ugp","BUFFER OVERFLOW","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A, AllocationSize: 128, EndOfFile: 124, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x19000000017817, EaSize: 0, Access: Read Attributes, Synchronize, Position: 0, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word"
"2:56,0406567","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0409493","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Sequential Access, Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0411136","java.exe","5812","QueryAttributeTagFile","C:\to.ugp","SUCCESS","Attributes: A, ReparseTag: 0x0"
"2:56,0411295","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0412625","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0414413","java.exe","5812","QueryStandardInformationFile","C:\to.ugp","SUCCESS","AllocationSize: 128, EndOfFile: 124, NumberOfLinks: 1, DeletePending: False, Directory: False"
"2:56,0414501","java.exe","5812","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A"
"2:56,0414660","java.exe","5812","QueryStreamInformationFile","C:\to.ugp","SUCCESS","0: ::$DATA"
"2:56,0414791","java.exe","5812","QueryBasicInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, FileAttributes: A"
"2:56,0414869","java.exe","5812","QueryEaInformationFile","C:\to.ugp","SUCCESS","EaSize: 0"
"2:56,0430376","java.exe","5812","QueryAttributeInformationVolume","C:\to.ugp","SUCCESS","FileSystemAttributes: Case Preserved, Case Sensitive, Unicode, ACLs, Compression, Named Streams, EFS, Object IDs, Reparse Points, Sparse Files, Quotas, Transactions, 0x3c00000, MaximumComponentNameLength: 255, FileSystemName: NTFS"
"2:56,0432018","java.exe","5812","ReadFile","C:\to.ugp","SUCCESS","Offset: 0, Length: 124, Priority: Normal"
"2:56,0433752","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""
"2:56,0457130","java.exe","5812","CreateFile","C:\to.ugp","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"2:56,0457516","java.exe","5812","QueryNetworkOpenInformationFile","C:\to.ugp","SUCCESS","CreationTime: 11.11.2013 18:10:11, LastAccessTime: 11.11.2013 2:56, LastWriteTime: 11.11.2013 2:56, ChangeTime: 11.11.2013 2:56, AllocationSize: 1.01.1601 2:00:00, EndOfFile: 1.01.1601 2:00:00, FileAttributes: A"
"2:56,0457647","java.exe","5812","CloseFile","C:\to.ugp","SUCCESS",""

The file monitor does not report the cause of error. It reports that SearchProtocolHost has opened the file after the failed attempt to delete it. But, might be filemonitor just reports the file events out-of-order? Could SearchProtocolHost have opened the file just second before and prevent the deletion, despite of the file monitor report?

I have disabled the indexing in my folder but I am still getting


"Time of Day","Process Name","PID","Operation","Path","Result","Detail"
"3:04,2768992","SearchProtocolHost.exe","4912","CloseFile","C:\test.bin","SUCCESS",""
"3:04,2900787","java.exe","4332","CreateFile","C:\test.bin","SUCCESS","Desired Access: Write Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"3:04,2903130","java.exe","4332","SetBasicInformationFile","C:\test.bin","SUCCESS","CreationTime: 1.01.1601 2:00:00, LastAccessTime: 1.01.1601 2:00:00, LastWriteTime: 1.01.1601 2:00:00, ChangeTime: 1.01.1601 2:00:00, FileAttributes: N"
"3:04,2903760","java.exe","4332","CloseFile","C:\test.bin","SUCCESS",""
"3:04,2906127","java.exe","4332","CreateFile","C:\test.bin","SUCCESS","Desired Access: Read Attributes, Disposition: Open, Options: Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"3:04,2906456","java.exe","4332","QueryBasicInformationFile","C:\test.bin","SUCCESS","CreationTime: 11.11.2013 20:08:50, LastAccessTime: 11.11.2013 3:04, LastWriteTime: 11.11.2013 3:04, ChangeTime: 11.11.2013 3:04, FileAttributes: N"
"3:04,2906591","java.exe","4332","CloseFile","C:\test.bin","SUCCESS",""
"3:04,2907872","java.exe","4332","CreateFile","C:\test.bin","SUCCESS","Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"3:04,2910002","java.exe","4332","QueryAttributeTagFile","C:\test.bin","SUCCESS","Attributes: N, ReparseTag: 0x0"
"3:04,2911567","java.exe","4332","SetDispositionInformationFile","C:\test.bin","CANNOT DELETE","Delete: True"
"3:04,2911712","SearchProtocolHost.exe","4912","CreateFile","C:\test.bin","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Open Reparse Point, Open Requiring Oplock, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
"3:04,2919504","java.exe","4332","CloseFile","C:\test.bin","SUCCESS",""
"3:04,2923298","java.exe","4332","QueryDirectory","C:\test.bin","SUCCESS","Filter: test.bin, 1: test.bin"

Please note again

"3:04,2911567","java.exe","4332","SetDispositionInformationFile","C:\test.bin","CANNOT DELETE","Delete: True"
"3:04,2911712","SearchProtocolHost.exe","4912","CreateFile","C:\test.bin","SUCCESS","Desired Access: Generic Read, Disposition: Open, Options: Open Reparse Point, Open Requiring Oplock, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"

happen one after another and my java process fails because it cannot remove the test.bin. I see nobody else besides the SearchProtocolHost who accessed this file. Why nobody reports that SearchProtocolHost locks the files even after indexing was disabled?

Update I have fixed my problem by retrying the delete. Second immediate delete succeeds. For instance, here is a profile of retries (the first column is the seconds)

19012: evaluator\to.ugp
21764: evaluator\to.ugp
22318: evaluator\to.ugp
23422: evaluator\to.ugp

and

03:14:02: failed to remove asm.o
03:19:37: failed to remove test.bin
03:46:11: failed to remove test.lst
04:04:24: failed to remove asm.o
04:44:39: failed to remove test.bin
04:46:30: failed to remove asm.o
04:46:30: failed to remove asm.o
04:46:31: failed to remove asm.o

from the producer process. We see a failure every 30 minutes. My processes are single-threaded. It cannot be that one of my threads releases the lock for the delete to succeed. Yet, if if I remove the computation and leave the bare file I/O, no delete failures are observed and it has never occured to me with other java applications.

Despite I have resolved the issue, I have asked if Windows services (file index, antivirus) can be guilty and still waiting for the answer. Why does delete fail? Why I still can rely on file open and file.exists() without any retries?

update-2

The answer is right. MsMpEng is repsonsible. Yet, I wonder how it manages to map the file after CreateFile has failed in my logs above. I have also spotted that realplayer does this (Windows XP, RealPlayer 15.0.1.13, RealNetworks, Inc., Build time: Wed Nov 30 02:07:39 2011 command line: "c:\program files\real\realplayer\\RealPlay.exe" /runevent "C:\program files\real\realplayer\update\upgr3270.dll" AutoUpdateEvent) on another machine.


50,2525433,cscript,8128,WriteFile,fname.txt,SUCCESS,Offset: 15, Length: 2"
50,2527714,cscript,8128,CloseFile,fname.txt,SUCCESS,"
50,2530630,RealPlay,6076,CreateFile,fname.txt,SUCCESS,Desired Access: Read Data/List Directory, Read Attributes, Disposition: Open, Options: Non-Directory File, Attributes: N, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
50,2552132,cscript,8128,QueryOpen,fname.txt,SUCCESS,CreationTime: 2.02.2014 21:04:31, LastAccessTime: 2.02.2014 21:20:50, LastWriteTime: 2.02.2014 21:20:50, ChangeTime: 2.02.2014 21:20:50, AllocationSize: 24, EndOfFile: 17, FileAttributes: A"
50,2553296,cscript,8128,CreateFile,DIRjs_slot0,SUCCESS,Desired Access: Read Data/List Directory, Synchronize, Disposition: Open, Options: Directory, Synchronous IO Non-Alert, Attributes: n/a, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened"
50,2554178,cscript,8128,QueryDirectory,fname.txt,SUCCESS,Filter: filename.txt, 1: filename.txt"
50,2555344,cscript,8128,CreateFile,fname.txt,SUCCESS,Desired Access: Read Attributes, Delete, Disposition: Open, Options: Non-Directory File, Open Reparse Point, Attributes: n/a, ShareMode: Read, Write, Delete, AllocationSize: n/a, OpenResult: Opened"
50,2558546,cscript,8128,QueryAttributeTagFile,fname.txt,SUCCESS,Attributes: A, ReparseTag: 0x0"
50,2559248,cscript,8128,SetDispositionInformationFile,fname.txt,CANNOT DELETE,Delete: True"
50,2560505,RealPlay,6076,CreateFileMapping,fname.txt,SUCCESS,SyncType: SyncTypeCreateSection, PageProtection: PAGE_READWRITE"
50,2560599,RealPlay,6076,QueryStandardInformationFile,fname.txt,SUCCESS,AllocationSize: 24, EndOfFile: 17, NumberOfLinks: 1, DeletePending: False, Directory: False"
50,2560731,RealPlay,6076,CreateFileMapping,fname.txt,SUCCESS,SyncType: SyncTypeOther"
50,2942892,cscript,8128,CloseFile,fname.txt,SUCCESS,"
50,3028039,cscript,8128,CloseFile,DIRjs_slot0,SUCCESS,"
50,4411248,RealPlay,6076,CloseFile,fname.txt,SUCCESS,"

1 Answer 1

2

It's because of MsMpEng.exe, which is Windows malware scanning code. It's locking the file for anything but read. It only locks it for a short period of time - once the scan is done it releases the lock and moves to another file.

3
  • "We're looking for long answers that provide some explanation and context. Don't just give a one-line answer; explain why your answer is right, ideally with citations. Answers that don't include explanations may be removed."
    – gparyani
    Feb 1, 2014 at 1:26
  • @gparyani "You" (are here)[meta.stackexchange.com/questions/160875/]. The answer is absolutely adequate and should not spoil it with "add noise for quality".
    – Val
    Feb 1, 2014 at 18:01
  • @Rob I have the MsMpEng.exe on the machines that demonstrate the failures quite often. But I do not have it on the machine that fails very-very rarely. So, you might be right, MsMpEng is complicit for the most of the failures. Indeed, I see that MsMpEng.exe opens the file at 2:56,0337485 and does not close it anywhere. Thanks, ROB!
    – Val
    Feb 1, 2014 at 18:43

You must log in to answer this question.

Not the answer you're looking for? Browse other questions tagged .