.NET 4.8 VS 2019
I have a class in my program that logs text to a file to log command activity and free text messages. The program is crashing for one (1) customer of tens of thousands with a "file is being used by another process" exception in the "LogFreeText" method. However, I cannot seem to figure out the issue.
Here is the class, which is embedded in the command handler class I wrote:
Public Class CommandLogger
Private _sFileName As String = ""
Public LockObject As New Object()
Public ReadOnly Property LogFile As String
Get
Return _sFileName
End Get
End Property
Public Sub New(sFolder As String)
'Clear old Activity Logs
Dim directory As New IO.DirectoryInfo(sFolder)
SyncLock (LockObject)
For Each file As IO.FileInfo In directory.GetFiles
If file.Name.StartsWith(My.Application.Info.ProductName.Trim.ToUpper & "_CMDLOG_") AndAlso file.Name.EndsWith(".TXT") Then
If (Now - file.CreationTime).Days > 7 Then file.Delete()
End If
Next
_sFileName = sFolder & "\" & My.Application.Info.ProductName.Trim.ToUpper & "_CMDLOG_" & Format(Now, "yyyy_MM_dd_H_mm_ss") & ".TXT"
If File.Exists(_sFileName) Then
FileSystem.RenameFile(_sFileName, _sFileName.Replace(".TXT", "_OLD.TXT"))
End If
Using log As StreamWriter = File.CreateText(_sFileName)
log.WriteLine("DateTime|CommandVerb|Page|Key|String|Text")
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|STARTUP||||")
log.Close()
End Using
End SyncLock
End Sub
Public Sub LogCommand(mnc As MBFS_CommonControls.MBFSNavCommand)
SyncLock (LockObject)
If Not File.Exists(_sFileName) Then
Using log As StreamWriter = File.CreateText(_sFileName)
log.WriteLine("DateTime|CommandVerb|Page|Key|String|Text")
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|STARTUP-ORPHAN|||||")
log.Close()
End Using
End If
Using log As StreamWriter = File.AppendText(_sFileName)
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|" & mnc.CommandVerb.Trim & "|" & mnc.CommandPage.ToString.Trim & "|" & mnc.RecordKey.ToString.Trim & "|" & mnc.RecordParentKey.ToString.Trim & "|" & mnc.sStringArgument.Trim & "|" & mnc.Text.Trim)
log.Close()
End Using
End SyncLock
End Sub
Public Sub LogFreeText(sText As String)
SyncLock (LockObject)
If Not File.Exists(_sFileName) Then
Using log As StreamWriter = File.CreateText(_sFileName)
log.WriteLine("DateTime|CommandVerb|Page|Key|String|Text")
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|STARTUP-ORPHAN|||||")
log.Close()
End Using
End If
Using log As StreamWriter = File.AppendText(_sFileName)
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|Freetext: " & sText & "|||||") '<<<<<<< BOOM!
log.Close()
End Using
End SyncLock
End Sub
Public Function Closeout() As Boolean
LogFreeText(Format(Now, "MM/dd/yyyy H:mm:ss") & "|SHUTDOWN||||")
Return True
End Function
End Class
In case it helps, here is the stack trace, with private identifying info redacted...
Message: The process cannot access the file 'C:\ProgramData\MyCompany\MyProgram\MyProgram_CMDLOG_2024_12_15_12_53_35.TXT' because it is being used by another process.
Stack Trace:
at System.IO.__Error.WinIOError(Int32 errorCode, String maybeFullPath)
at System.IO.FileStream.Init(String path, FileMode mode, FileAccess access, Int32 rights, Boolean useRights, FileShare share, Int32 bufferSize, FileOptions options, SECURITY_ATTRIBUTES secAttrs, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
at System.IO.FileStream..ctor(String path, FileMode mode, FileAccess access, FileShare share, Int32 bufferSize, FileOptions options, String msgPath, Boolean bFromProxy, Boolean useLongPath, Boolean checkHost)
at System.IO.StreamWriter.CreateFile(String path, Boolean append, Boolean checkHost)
at System.IO.StreamWriter..ctor(String path, Boolean append, Encoding encoding, Int32 bufferSize, Boolean checkHost)
at System.IO.StreamWriter..ctor(String path, Boolean append)
at System.IO.File.AppendText(String path)
at MyClass.CommonGlobalWinFuncs.CommandLogger.LogFreeText(String sText)
at MyClass.CommonGlobalWinFuncs.DoCommand(MyNavCommand& mncCommand, String& sErr)
at MyClass.CommonGlobalWinFuncs.CommandShuffler(MBFSNavCommand mnc)
at MyClass.ActiveWindow.HandleShowEntityCommand(Object sender, String sCommand, EventArgs e, wwCommandAction& eResponseAction)
at MyClass.A_ModalWorkWithForm.SelectGridRow(Int32 iRow)
at MyClass.A_ModalWorkWithForm.wwGrid_RowEnter(Object sender, DataGridViewCellEventArgs e)
at System.Windows.Forms.DataGridView.OnRowEnter(DataGridViewCellEventArgs e)
at System.Windows.Forms.DataGridView.OnRowEnter(DataGridViewCell& dataGridViewCell, Int32 columnIndex, Int32 rowIndex, Boolean canCreateNewRow, Boolean validationFailureOccurred)
at System.Windows.Forms.DataGridView.SetCurrentCellAddressCore(Int32 columnIndex, Int32 rowIndex, Boolean setAnchorCellAddress, Boolean validateCurrentCell, Boolean throughMouseClick)
at System.Windows.Forms.DataGridView.SetAndSelectCurrentCellAddress(Int32 columnIndex, Int32 rowIndex, Boolean setAnchorCellAddress, Boolean validateCurrentCell, Boolean throughMouseClick, Boolean clearSelection, Boolean forceCurrentCellSelection)
at System.Windows.Forms.DataGridView.MakeFirstDisplayedCellCurrentCell(Boolean includeNewRow)
at System.Windows.Forms.DataGridView.OnHandleCreated(EventArgs e)
at System.Windows.Forms.Control.WmCreate(Message& m)
at System.Windows.Forms.Control.WndProc(Message& m)
at System.Windows.Forms.NativeWindow.Callback(IntPtr hWnd, Int32 msg, IntPtr wparam, IntPtr lparam)
No Inner Exception found.
I wrap all of the streamwriters in using blocks as is my habit.
I close the stream at all points where I write a line. See Code.
No other class exists that tries to write to that file name.
The class is invoked by only one process.
I don't think that there is threading involved, but out of an abundance of caution I wrapped the functions in SyncLock.
This happens for one customer. There is a random number of successful writes and then this happens. I cannot make it happen here.
I am totally confused. Am I missing something?
Thanks
I fixed the issue for this customer by brute force.
I isolated the writes into a single method. I wrapped the method into a try block. I put in a catch which tested for the error message in question. If the error was caught it added the line to the end of a list of strings. If no error, I test for any strings in the list, and write those first, and then the pending new string. This ensures no loss of logging data (assuming no other crash before it writes).
Here's the code:
Private Sub TextWrite(sText As String)
Try
SyncLock (LockObject)
If Not File.Exists(_sFileName) Then
Using log As StreamWriter = File.CreateText(_sFileName)
log.WriteLine("DateTime|CommandVerb|Page|Key|String|Text")
log.WriteLine(Format(Now, "MM/dd/yyyy H:mm:ss") & "|STARTUP-ORPHAN|||||")
log.WriteLine(sText)
log.Close()
End Using
Else
Using log As StreamWriter = File.AppendText(_sFileName)
'' If there are unwritten lines write them.
If lBufferUnwritten.Count > 0 Then
For Each s As String In lBufferUnwritten
log.WriteLine(s)
Next
lBufferUnwritten.Clear()
End If
log.WriteLine(sText)
log.Close()
End Using
End If
End SyncLock
Catch ex As Exception
If ex.Message.ToUpper().Contains("ANOTHER PROCESS") Then
lBufferUnwritten.Add(Format(Now, "MM/dd/yyyy H:mm:ss") & "|BUFFERED - FILE ANOTHER PROCESS|||||")
lBufferUnwritten.Add(sText)
Else
Throw
End If
End Try
End Sub
So there seems to be some sort of anomaly which needs to be coded around, and this is the only code-around I found that works.