delete - Can windows search indexer prevent file from deleting?

06
2014-04
  • Val

    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. But, on the other PC, I see that realplayer does the shit (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) 

    
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,"
    • Answers
  • Rob

    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.


    • Related Question

    .exe files not indexed with Windows Search
  • JcMaco

    I have several standalone applications in my "My Documents" folder such as "procexp.exe", "putty.exe", etc.

    I noticed that Windows Search does not index them even though "exe" is a file type that should be indexed (file properties filter) according to the advanced options of Windows Search.

    The "exe" files show up when I consult the full "Search results" after entering my query and clicking "See more results" in the Start menu.

    How can I make them show up in the start menu search result listing? What can I do to solve my problem?


    • Related Answers
  • William Hilsum

    It should do and whilst I have other problems with indexing on my machine, it does return .exe results.

    Try going in to options and rebuilding your database.

  • harrymc

    If you'll consider using a better search engine, the Everything search engine might be suitable.
    The only requirement is that your disk must be formatted in ntfs. It's quite nice to have your answers display in real time per each character while you're still typing the file name.