.NET 4.8程序LogFreeText方法随机抛出文件占用异常求助

环境 #

• .NET 4.8
• VS 2019

问题描述 #

我开发的程序里有个CommandLogger类，用来记录命令活动和自由文本日志。数万客户里只有一位出现问题：LogFreeText方法在随机多次成功写入后，突然抛出“文件被另一个进程占用”异常，导致程序崩溃。我本地无法复现该问题。

相关代码 #

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

异常堆栈跟踪 #

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. 

已做排查 #

• 所有StreamWriter都用using块包裹，确保资源释放
• 写入后显式调用log.Close()
• 确认无其他类或进程操作该日志文件
• 用SyncLock包裹操作，排除多线程冲突可能
• 确认仅单一进程调用该类

可能的原因分析 #

1. 文件系统缓存延迟：虽然using块会自动释放资源，但Windows文件系统可能存在缓存延迟，导致文件句柄未立即回收。在系统负载较高时，这种延迟可能刚好触发写入时的占用冲突。
2. 第三方软件拦截：客户机器上的杀毒软件、备份工具或文件监控程序，可能会临时锁定日志文件进行扫描或备份，刚好和程序的写入操作撞车。仅单个客户出现问题，环境因素的可能性极高。
3. 重命名API的潜在问题：构造函数中使用FileSystem.RenameFile重命名文件后，系统可能未完全同步文件状态，后续对新文件的操作可能隐含旧的锁定状态。建议替换为File.Move，API实现更稳定。
4. 锁对象的外部干扰：LockObject是Public的，不排除外部代码意外对其加锁，导致当前类的锁等待，进而引发文件句柄释放异常。建议将LockObject改为Private，避免外部干扰。
5. 路径拼接的不规范：构造函数中用\"拼接路径，如果sFolder本身以反斜杠结尾，会出现双反斜杠路径，部分系统环境下可能引发文件操作异常。建议用Path.Combine拼接路径，确保格式正确。
6. 文件存在性检查的竞态条件：虽然有SyncLock，但File.Exists是非原子操作，极端情况下文件可能在检查后、写入前被其他因素删除或锁定，不过这种概率极低。

内容的提问来源于stack exchange，提问作者John Tamburo