2

(a similar question has been asked by me before - this question relates to the same application, but a different - but probably related - problem)

I have an application that regularly writes records to a data file. The file is opened, updated, and closed each time. This same instance of the application also reads from the file.

Elsewhere on the network, there are several "slave" instances of the same application running that only read from the same data file across the network.

Occasionally (the occasions are days, sometimes weeks apart), the file access fails with an access denied error on all machines, and at the same instant, except that sometimes it fails on all machines apart from one of the slaves. The file can't be written to or read from. Usually all the PC's apart from one fail in the same fashion - "access denied" error code 5 - but sometimes one of the slaves can still continue to access the file.

Inspection of the system with utilities that tell who has a file open (LockHunter, SysInternal's Handle utility) tells us little - on the PC that writes to the file, they find the System process has the handle, presumably because the application that has the file open opened it via a network share, the Slave that can still write to the file shows the handle as unlocked, and with the other slaves neither utility reports anything.

When we have been troubleshooting the system we have used NotePad to quickly test if the file is unlocked. Notepad always reports that it can't open the file because another application has the file open - except for one of the slave machines, and not always the same one. When we open the file with NotePad on that PC, it opens without complaint, and at the same instant, the file unlocks - all the other PCs can read and write to the file from then on (although things appear to function OK from then on, I'm not convinced that the file system hasn't been damaged in some way).

The following is a log obtained by ProcMon of the slave file system operations over the period that Notepad is used to "unstick" the file. The file APP.ZZZ is read every second, corresponding to each group of 5 accesses from App.exe

... accesses from the remote machine

1:08:59.5706074 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:08:59.7993871 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:08:59.8081861 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:08:59.8083675 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 11:53:21 a.m., ChangeTime: 23/09/2015 11:53:21 a.m., FileAttributes: ANCI"
1:08:59.8083874 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:00.5663175 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:00.7611667 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:00.7669819 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:00.7671534 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 11:53:21 a.m., ChangeTime: 23/09/2015 11:53:21 a.m., FileAttributes: ANCI"
1:09:00.7671720 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:01.5654203 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"

... NOTEPAD starts and opens the file    

1:09:01.7112007 p.m.    NOTEPAD.EXE 4508    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:01.7187932 p.m.    NOTEPAD.EXE 4508    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened"
1:09:01.7233678 p.m.    NOTEPAD.EXE 4508    QueryInformationVolume  \\REMOTE\App\Datafiles\APP.ZZZ  BUFFER OVERFLOW "VolumeCreationTime: 13/02/2014 11:58:47 a.m., VolumeSerialNumber: 6060-4BB9, SupportsObjects: True, VolumeLabel: Win?"
1:09:01.7248358 p.m.    NOTEPAD.EXE 4508    QueryAllInformationFile \\REMOTE\App\Datafiles\APP.ZZZ  BUFFER OVERFLOW "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 11:53:21 a.m., ChangeTime: 23/09/2015 11:53:21 a.m., FileAttributes: ANCI, AllocationSize: 692,224, EndOfFile: 691,600, NumberOfLinks: 1, DeletePending: False, Directory: False, IndexNumber: 0x1000000000bdb5, EaSize: 0, Access: None 0x0, Position: 0, Mode: , AlignmentRequirement: Byte"
1:09:01.7407505 p.m.    NOTEPAD.EXE 4508    CreateFileMapping   \\REMOTE\App\Datafiles\APP.ZZZ  FILE LOCKED WITH WRITERS    "SyncType: SyncTypeCreateSection, PageProtection: "
1:09:01.7407840 p.m.    NOTEPAD.EXE 4508    QueryStandardInformationFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "AllocationSize: 692,224, EndOfFile: 691,600, NumberOfLinks: 1, DeletePending: False, Directory: False"
1:09:01.7408038 p.m.    NOTEPAD.EXE 4508    CreateFileMapping   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS SyncType: SyncTypeOther
1:09:01.7408244 p.m.    NOTEPAD.EXE 4508    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 
1:09:01.7408578 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 0, Length: 32,768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.7459986 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 32,768, Length: 32,768, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.7502571 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 65,536, Length: 65,536, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.7567997 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 131,072, Length: 131,072, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.7759753 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 262,144, Length: 262,144, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.7995374 p.m.    NOTEPAD.EXE 4508    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 524,288, Length: 167,312, I/O Flags: Non-cached, Paging I/O, Synchronous Paging I/O, Priority: Normal"
1:09:01.8194679 p.m.    NOTEPAD.EXE 4508    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"

1:09:01.8228119 p.m.    NOTEPAD.EXE 4508    RegQueryValue   HKLM\SOFTWARE\MICROSOFT\Windows\CurrentVersion\Explorer\KindMap\.ZZZ    NAME NOT FOUND  Length: 144

.... NOTEPAD does a whole bunch of registry stuff

1:09:01.8245487 p.m.    NOTEPAD.EXE 4508    RegCloseKey HKCU\Software\Classes\.ZZZ  SUCCESS 

... accesses from the remote machine again. File is now unstuck. 

1:09:01.9170334 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:01.9249583 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:01.9287995 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 11:53:21 a.m., ChangeTime: 23/09/2015 11:53:21 a.m., FileAttributes: ANCI"
1:09:01.9288154 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:02.5679077 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:02.8324048 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:02.8813660 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:02.8924965 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 1:09:02 p.m., ChangeTime: 23/09/2015 1:09:02 p.m., FileAttributes: ANCI"
1:09:02.8925206 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:03.5661778 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: Read, Write, AllocationSize: n/a, OpenResult: Opened"
1:09:03.5749668 p.m.    App.exe 6276    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 630,252, Length: 61,376, Priority: Normal"
1:09:03.5750069 p.m.    App.exe 6276    ReadFile    \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Offset: 626,688, Length: 64,940, I/O Flags: Non-cached, Paging I/O, Priority: Normal"
1:09:03.5820100 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:03.5862665 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:03.7772397 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:03.7848388 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:03.7880212 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 1:09:02 p.m., ChangeTime: 23/09/2015 1:09:02 p.m., FileAttributes: ANCI"
1:09:03.7880374 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:04.5695737 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:04.7597043 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:04.7653450 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:04.7711026 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 1:09:04 p.m., ChangeTime: 23/09/2015 1:09:04 p.m., FileAttributes: ANCI"
1:09:04.7711189 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

1:09:05.5674975 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:05.7744582 p.m.    App.exe 6276    QueryDirectory  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Filter: APP.ZZZ, 1: APP.ZZZ"
1:09:05.7818819 p.m.    App.exe 6276    CreateFile  \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "Desired Access: Generic Read, Disposition: Open, Options: Synchronous IO Non-Alert, Non-Directory File, Attributes: N, ShareMode: None, AllocationSize: n/a, OpenResult: Opened"
1:09:05.7898488 p.m.    App.exe 6276    QueryBasicInformationFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS "CreationTime: 17/11/2014 5:46:01 p.m., LastAccessTime: 23/09/2015 4:00:01 a.m., LastWriteTime: 23/09/2015 1:09:04 p.m., ChangeTime: 23/09/2015 1:09:04 p.m., FileAttributes: ANCI"
1:09:05.7898647 p.m.    App.exe 6276    CloseFile   \\REMOTE\App\Datafiles\APP.ZZZ  SUCCESS 

I'm trying to determine what is putting the datafile in this state. I remember seeing a reference to problems if an exception occurs when a network file is closed. Could this problem point to something of that nature? I'm hoping that someone may be able to offer some insight as to what might be happening.

The application is written in Delphi 2007 (32-bit).

3

Open "Command Prompt" and type in

openfiles

To see the options

openfiles /?

The other method is

  • Select "Manage Computer" (Open "Computer Management")
  • click "Shared Folders"
  • choose "Open Files"
  • Openfiles appears to require elevated privileges, at least it does on my Windows 7 desktop here. I recommend opening the command prompt via "Run as Administrator" – dgnuff Jun 27 '17 at 2:15

Your Answer

By clicking “Post Your Answer”, you agree to our terms of service, privacy policy and cookie policy

Not the answer you're looking for? Browse other questions tagged or ask your own question.