Collectives™ on Stack Overflow
Find centralized, trusted content and collaborate around the technologies you use most.
Learn more about Collectives
Teams
Q&A for work
Connect and share knowledge within a single location that is structured and easy to search.
Learn more about Teams
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.
Thanks for contributing an answer to Stack Overflow!
- Please be sure to answer the question. Provide details and share your research!
But avoid …
- Asking for help, clarification, or responding to other answers.
- Making statements based on opinion; back them up with references or personal experience.
To learn more, see our tips on writing great answers.