Understanding a sharing violation using procmon
I have a procmon trace for a build of an application (using multiple different processes) that at some point fails to write a file because it is being used by another process. The first thing I see is that the file gets deleted at the start of the build:
3:49:32.9928378 PM foo.exe 11460 QueryOpen SUCCESS CreationTime: 8/26/2016 12:49:00 PM, LastAccessTime: 8/26/2016 12:49:00 PM, LastWriteTime: 8/26/2016 12:49:05 PM, ChangeTime: 8/26/2016 12:49:06 PM, AllocationSize: 57,344, EndOfFile: 56,624, FileAttributes: N
3:49:32.9929337 PM foo.exe 11460 CreateFile 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:49:32.9929791 PM foo.exe 11460 QuerySecurityFile SUCCESS Information: 0x20
3:49:32.9930238 PM foo.exe 11460 QueryAttributeTagFile SUCCESS Attributes: N, ReparseTag: 0x0
3:49:32.9930526 PM foo.exe 11460 SetDispositionInformationFile SUCCESS Delete: True
3:49:32.9930955 PM foo.exe 11460 CloseFile SUCCESS
3:49:32.9940971 PM foo.exe 11460 CloseFile SUCCESS
3:49:32.9942480 PM foo.exe 11460 CreateFile 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:49:32.9943085 PM foo.exe 11460 QuerySecurityFile SUCCESS Information: 0x20
3:49:32.9944066 PM foo.exe 11460 SetBasicInformationFile SUCCESS CreationTime: 0, LastAccessTime: 0, LastWriteTime: 0, ChangeTime: 0, FileAttributes: N
3:49:32.9944770 PM foo.exe 11460 CloseFile SUCCESS
3:49:32.9946268 PM foo.exe 11460 QueryOpen SUCCESS CreationTime: 8/26/2016 3:49:27 PM, LastAccessTime: 8/26/2016 3:49:27 PM, LastWriteTime: 8/26/2016 3:49:32 PM, ChangeTime: 8/26/2016 3:49:33 PM, AllocationSize: 57,344, EndOfFile: 56,624, FileAttributes: N
3:49:32.9947224 PM foo.exe 11460 CreateFile SUCCESS Desired Access: Read Attributes, Synchronize, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened
3:49:32.9947681 PM foo.exe 11460 QuerySecurityFile SUCCESS Information: 0x20
3:49:32.9948253 PM foo.exe 11460 QueryInformationVolume BUFFER OVERFLOW VolumeCreationTime: 4/19/2016 10:43:10 PM, VolumeSerialNumber: 4299-1E8C, SupportsObjects: True, VolumeLabel: Dat堜
3:49:32.9948475 PM foo.exe 11460 QueryAllInformationFile BUFFER OVERFLOW CreationTime: 8/26/2016 3:49:27 PM, LastAccessTime: 8/26/2016 3:49:27 PM, LastWriteTime: 8/26/2016 3:49:32 PM, ChangeTime: 8/26/2016 3:49:33 PM, FileAttributes: N, AllocationSize: 57,344, EndOfFile: 56,624, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0xe00000021d3d3, EaSize: 0, Access: Read Attributes, Synchronize, Position: 0, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word
3:49:32.9948678 PM foo.exe 11460 CloseFile SUCCESS
That appears to be successful. The next thing I notice is that there are two "CreateFileMapping" calls that return "File Locked With Only readers". However, as near as I can tell that is nothing to worry about, as both times closefile appears to be called. The interesting thing is that QueryAllInformationFile called after the delete returns a time before the delete for creation time. Does that mean the file didn't get deleted properly?
3:49:41.3811537 PM bar.exe 11724 CreateFile SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, AllocationSize: n/a, OpenResult: Opened
3:49:41.3812155 PM bar.exe 11724 QuerySecurityFile SUCCESS Information: 0x20
3:49:41.3827524 PM bar.exe 11724 QueryNameInformationFile SUCCESS Name: \a\path\to\a\file\thedllinquestion.dll
3:49:41.3827711 PM bar.exe 11724 QueryNameInformationFile SUCCESS Name: \a\path\to\a\file\thedllinquestion.dll
3:49:41.3828506 PM bar.exe 11724 QueryNormalizedNameInformationFile SUCCESS
3:49:41.3829159 PM bar.exe 11724 QueryInformationVolume BUFFER OVERFLOW VolumeCreationTime: 4/19/2016 10:43:10 PM, VolumeSerialNumber: 4299-1E8C, SupportsObjects: True, VolumeLabel: Dat妕
3:49:41.3829281 PM bar.exe 11724 QueryAllInformationFile BUFFER OVERFLOW CreationTime: 8/26/2016 3:49:27 PM, LastAccessTime: 8/26/2016 3:49:27 PM, LastWriteTime: 8/26/2016 3:49:32 PM, ChangeTime: 8/26/2016 3:49:33 PM, FileAttributes: N, AllocationSize: 57,344, EndOfFile: 56,624, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0xe00000021d3d3, EaSize: 0, Access: Generic Read, Position: 0, Mode: Synchronous IO Non-Alert, AlignmentRequirement: Word
3:49:41.3829444 PM bar.exe 11724 CreateFileMapping FILE LOCKED WITH ONLY READERS SyncType: SyncTypeCreateSection, PageProtection:
3:49:41.3829538 PM bar.exe 11724 QueryStandardInformationFile SUCCESS AllocationSize: 57,344, EndOfFile: 56,624, NumberOfLinks: 1, DeletePending: False, Directory: False
3:49:41.3830038 PM bar.exe 11724 CreateFileMapping SUCCESS SyncType: SyncTypeOther
3:49:41.4143299 PM bar.exe 11724 CloseFile SUCCESS
Finally the sharing violation is below. The interesting thing is that the same process opens the file for read without closing before read/write. Theoretically you should be able to do that though right?
3:49:41.8544568 PM foo.exe 11460 CreateFile SUCCESS Desired Access: Generic Read, Disposition: Open, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: n/a, ShareMode: Read, Delete, AllocationSize: n/a, OpenResult: Opened
3:49:41.8545112 PM foo.exe 11460 QuerySecurityFile SUCCESS Information: 0x20
3:49:41.8545970 PM foo.exe 11460 QueryStandardInformationFile SUCCESS AllocationSize: 57,344, EndOfFile: 56,624, NumberOfLinks: 1, DeletePending: False, Directory: False
3:49:41.8546087 PM foo.exe 11460 QueryBasicInformationFile SUCCESS CreationTime: 8/26/2016 3:49:27 PM, LastAccessTime: 8/26/2016 3:49:27 PM, LastWriteTime: 8/26/2016 3:49:32 PM, ChangeTime: 8/26/2016 3:49:33 PM, FileAttributes: N
3:49:41.8546441 PM foo.exe 11460 QueryStreamInformationFile SUCCESS 0: ::$DATA
3:49:41.8546914 PM foo.exe 11460 QueryBasicInformationFile SUCCESS CreationTime: 8/26/2016 3:49:27 PM, LastAccessTime: 8/26/2016 3:49:27 PM, LastWriteTime: 8/26/2016 3:49:32 PM, ChangeTime: 8/26/2016 3:49:33 PM, FileAttributes: N
3:49:41.8547366 PM foo.exe 11460 QueryEaInformationFile SUCCESS EaSize: 0
3:49:41.8550146 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Read/Write, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: 56,624
3:49:41.8552552 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Data/List Directory, Read Attributes, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: 56,624
3:49:41.8554742 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Attributes, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: 56,624
3:49:41.8556783 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Data/List Directory, Read Attributes, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
3:49:41.8558759 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Data/List Directory, Read Attributes, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
3:49:41.8560577 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Attributes, Delete, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
3:49:41.8562656 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Data/List Directory, Read Attributes, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
3:49:41.8564750 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Data/List Directory, Read Attributes, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
3:49:41.8566442 PM foo.exe 11460 CreateFile SHARING VIOLATION Desired Access: Generic Write, Read Attributes, Write DAC, Disposition: OverwriteIf, Options: Sequential Access, Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: 56,624
I can't see anywhere where a file is not being closed after it is open, and it should be deleting the file to start off with, and I verified before the build started that there were no handles to the file (using the "handle" tool).
Any pointers you can provide would be helpful, thanks.