在開發程序的過程中,難免少不了寫入錯誤日志這個關鍵功能。實現這個功能,可以選擇使用第三方日志插件,也可以選擇使用數據庫,還可以自己寫個簡單的方法把錯誤信息記錄到日志文件。
選擇最後一種方法實現的時候,若對文件操作與線程同步不熟悉,問題就有可能出現了,因為同一個文件並不允許多個線程同時寫入,否則會提示“文件正在由另一進程使用,因此該進程無法訪問此文件”。
這是文件的並發寫入問題,就需要用到線程同步。而微軟也給線程同步提供了一些相關的類可以達到這樣的目的,本文使用到的 System.Threading.ReaderWriterLockSlim 便是其中之一。
該類用於管理資源訪問的鎖定狀態,可實現多線程讀取或進行獨占式寫入訪問。利用這個類,我們就可以避免在同一時間段內多線程同時寫入一個文件而導致的並發寫入問題。
讀寫鎖是以 ReaderWriterLockSlim 對象作為鎖管理資源的,不同的 ReaderWriterLockSlim 對象中鎖定同一個文件也會被視為不同的鎖進行管理,這種差異可能會再次導致文件的並發寫入問題,所以 ReaderWriterLockSlim 應盡量定義為只讀的靜態對象。
ReaderWriterLockSlim 有幾個關鍵的方法,本文僅討論寫入鎖:
調用 EnterWriteLock 方法 進入寫入狀態,在調用線程進入鎖定狀態之前一直處於阻塞狀態,因此可能永遠都不返回。
調用 TryEnterWriteLock 方法 進入寫入狀態,可指定阻塞的間隔時間,如果調用線程在此間隔期間並未進入寫入模式,將返回false。
調用 ExitWriteLock 方法 退出寫入狀態,應使用 finally 塊執行 ExitWriteLock 方法,從而確保調用方退出寫入模式。
1.多線程同時寫入文件
1 class Program 2 { 3 static int LogCount = 100; 4 static int WritedCount = 0; 5 static int FailedCount = 0; 6 7 static void Main(string[] args) 8 { 9 //迭代運行寫入日志記錄,由於多個線程同時寫入同一個文件將會導致錯誤 10 Parallel.For(0, LogCount, e => 11 { 12 WriteLog(); 13 }); 14 15 Console.WriteLine(string.Format("\r\nLog Count:{0}.\t\tWrited Count:{1}.\tFailed Count:{2}.", LogCount.ToString(), WritedCount.ToString(), FailedCount.ToString())); 16 Console.Read(); 17 } 18 19 static void WriteLog() 20 { 21 try 22 { 23 var logFilePath = "log.txt"; 24 var now = DateTime.Now; 25 var logContent = string.Format("Tid: {0}{1} {2}.{3}\r\n", Thread.CurrentThread.ManagedThreadId.ToString().PadRight(4), now.ToLongDateString(), now.ToLongTimeString(), now.Millisecond.ToString()); 26 File.AppendAllText(logFilePath, logContent); 27 WritedCount++; 28 } 29 catch (Exception ex) 30 { 31 FailedCount++; 32 Console.WriteLine(ex.Message); 33 } 34 } 35 }
運行結果:
不使用讀寫鎖,只有部分日志成功寫入了日志文件。
2.多線程使用讀寫鎖同步寫入文件
1 class Program 2 { 3 static int LogCount = 100; 4 static int WritedCount = 0; 5 static int FailedCount = 0; 6 7 static void Main(string[] args) 8 { 9 //迭代運行寫入日志記錄 10 Parallel.For(0, LogCount, e => 11 { 12 WriteLog(); 13 }); 14 15 Console.WriteLine(string.Format("\r\nLog Count:{0}.\t\tWrited Count:{1}.\tFailed Count:{2}.", LogCount.ToString(), WritedCount.ToString(), FailedCount.ToString())); 16 Console.Read(); 17 } 18 19 //讀寫鎖,當資源處於寫入模式時,其他線程寫入需要等待本次寫入結束之後才能繼續寫入 20 static ReaderWriterLockSlim LogWriteLock = new ReaderWriterLockSlim(); 21 static void WriteLog() 22 { 23 try 24 { 25 //設置讀寫鎖為寫入模式獨占資源,其他寫入請求需要等待本次寫入結束之後才能繼續寫入 26 //注意:長時間持有讀線程鎖或寫線程鎖會使其他線程發生饑餓 (starve)。 為了得到最好的性能,需要考慮重新構造應用程序以將寫訪問的持續時間減少到最小。 27 // 從性能方面考慮,請求進入寫入模式應該緊跟文件操作之前,在此處進入寫入模式僅是為了降低代碼復雜度 28 // 因進入與退出寫入模式應在同一個try finally語句塊內,所以在請求進入寫入模式之前不能觸發異常,否則釋放次數大於請求次數將會觸發異常 29 LogWriteLock.EnterWriteLock(); 30 31 var logFilePath = "log.txt"; 32 var now = DateTime.Now; 33 var logContent = string.Format("Tid: {0}{1} {2}.{3}\r\n", Thread.CurrentThread.ManagedThreadId.ToString().PadRight(4), now.ToLongDateString(), now.ToLongTimeString(), now.Millisecond.ToString()); 34 35 File.AppendAllText(logFilePath, logContent); 36 WritedCount++; 37 } 38 catch (Exception) 39 { 40 FailedCount++; 41 } 42 finally 43 { 44 //退出寫入模式,釋放資源占用 45 //注意:一次請求對應一次釋放 46 // 若釋放次數大於請求次數將會觸發異常[寫入鎖定未經保持即被釋放] 47 // 若請求處理完成後未釋放將會觸發異常[此模式不下允許以遞歸方式獲取寫入鎖定] 48 LogWriteLock.ExitWriteLock(); 49 } 50 } 51 }
運行結果:
使用讀寫鎖,全部日志成功寫入了日志文件。
3.測試復雜多線程環境下使用讀寫鎖同步寫入文件
1 class Program 2 { 3 static int LogCount = 1000; 4 static int SumLogCount = 0; 5 static int WritedCount = 0; 6 static int FailedCount = 0; 7 8 static void Main(string[] args) 9 { 10 //往線程池裡添加一個任務,迭代寫入N個日志 11 SumLogCount += LogCount; 12 ThreadPool.QueueUserWorkItem((obj) => 13 { 14 Parallel.For(0, LogCount, e => 15 { 16 WriteLog(); 17 }); 18 }); 19 20 //在新的線程裡,添加N個寫入日志的任務到線程池 21 SumLogCount += LogCount; 22 var thread1 = new Thread(() => 23 { 24 Parallel.For(0, LogCount, e => 25 { 26 ThreadPool.QueueUserWorkItem((subObj) => 27 { 28 WriteLog(); 29 }); 30 }); 31 }); 32 thread1.IsBackground = false; 33 thread1.Start(); 34 35 //添加N個寫入日志的任務到線程池 36 SumLogCount += LogCount; 37 Parallel.For(0, LogCount, e => 38 { 39 ThreadPool.QueueUserWorkItem((obj) => 40 { 41 WriteLog(); 42 }); 43 }); 44 45 //在新的線程裡,迭代寫入N個日志 46 SumLogCount += LogCount; 47 var thread2 = new Thread(() => 48 { 49 Parallel.For(0, LogCount, e => 50 { 51 WriteLog(); 52 }); 53 }); 54 thread2.IsBackground = false; 55 thread2.Start(); 56 57 //在當前線程裡,迭代寫入N個日志 58 SumLogCount += LogCount; 59 Parallel.For(0, LogCount, e => 60 { 61 WriteLog(); 62 }); 63 64 Console.WriteLine("Main Thread Processed.\r\n"); 65 while (true) 66 { 67 Console.WriteLine(string.Format("Sum Log Count:{0}.\t\tWrited Count:{1}.\tFailed Count:{2}.", SumLogCount.ToString(), WritedCount.ToString(), FailedCount.ToString())); 68 Console.ReadLine(); 69 } 70 } 71 72 //讀寫鎖,當資源處於寫入模式時,其他線程寫入需要等待本次寫入結束之後才能繼續寫入 73 static ReaderWriterLockSlim LogWriteLock = new ReaderWriterLockSlim(); 74 static void WriteLog() 75 { 76 try 77 { 78 //設置讀寫鎖為寫入模式獨占資源,其他寫入請求需要等待本次寫入結束之後才能繼續寫入 79 //注意:長時間持有讀線程鎖或寫線程鎖會使其他線程發生饑餓 (starve)。 為了得到最好的性能,需要考慮重新構造應用程序以將寫訪問的持續時間減少到最小。 80 // 從性能方面考慮,請求進入寫入模式應該緊跟文件操作之前,在此處進入寫入模式僅是為了降低代碼復雜度 81 // 因進入與退出寫入模式應在同一個try finally語句塊內,所以在請求進入寫入模式之前不能觸發異常,否則釋放次數大於請求次數將會觸發異常 82 LogWriteLock.EnterWriteLock(); 83 84 var logFilePath = "log.txt"; 85 var now = DateTime.Now; 86 var logContent = string.Format("Tid: {0}{1} {2}.{3}\r\n", Thread.CurrentThread.ManagedThreadId.ToString().PadRight(4), now.ToLongDateString(), now.ToLongTimeString(), now.Millisecond.ToString()); 87 88 File.AppendAllText(logFilePath, logContent); 89 WritedCount++; 90 } 91 catch (Exception) 92 { 93 FailedCount++; 94 } 95 finally 96 { 97 //退出寫入模式,釋放資源占用 98 //注意:一次請求對應一次釋放 99 // 若釋放次數大於請求次數將會觸發異常[寫入鎖定未經保持即被釋放] 100 // 若請求處理完成後未釋放將會觸發異常[此模式不下允許以遞歸方式獲取寫入鎖定] 101 LogWriteLock.ExitWriteLock(); 102 } 103 } 104 }
運行結果:
部分日志文件內容:
1 ... 2 Tid: 36 2016年12月11日 15:29:22.825 3 Tid: 29 2016年12月11日 15:29:22.830 4 Tid: 6 2016年12月11日 15:29:22.838 5 Tid: 26 2016年12月11日 15:29:22.845 6 Tid: 34 2016年12月11日 15:29:22.854 7 Tid: 24 2016年12月11日 15:29:22.863 8 Tid: 27 2016年12月11日 15:29:22.872 9 Tid: 14 2016年12月11日 15:29:22.877 10 Tid: 23 2016年12月11日 15:29:22.886 11 Tid: 20 2016年12月11日 15:29:22.892 12 Tid: 30 2016年12月11日 15:29:22.898 13 Tid: 9 2016年12月11日 15:29:22.904 14 Tid: 21 2016年12月11日 15:29:22.909 15 Tid: 22 2016年12月11日 15:29:22.915 16 Tid: 7 2016年12月11日 15:29:22.920 17 Tid: 3 2016年12月11日 15:29:22.925 18 Tid: 12 2016年12月11日 15:29:22.931 19 Tid: 5 2016年12月11日 15:29:22.937 20 Tid: 13 2016年12月11日 15:29:22.942 21 Tid: 11 2016年12月11日 15:29:22.947 22 Tid: 19 2016年12月11日 15:29:22.953 23 Tid: 37 2016年12月11日 15:29:22.958 24 Tid: 37 2016年12月11日 15:29:22.964 25 Tid: 40 2016年12月11日 15:29:22.970 26 Tid: 40 2016年12月11日 15:29:22.975 27 Tid: 40 2016年12月11日 15:29:22.980 28 Tid: 40 2016年12月11日 15:29:22.985 29 Tid: 40 2016年12月11日 15:29:22.991 30 Tid: 40 2016年12月11日 15:29:22.997 31 Tid: 31 2016年12月11日 15:29:23.3 32 Tid: 31 2016年12月11日 15:29:23.9 33 Tid: 31 2016年12月11日 15:29:23.14 34 Tid: 31 2016年12月11日 15:29:23.20 35 Tid: 31 2016年12月11日 15:29:23.27 36 Tid: 31 2016年12月11日 15:29:23.33 37 Tid: 31 2016年12月11日 15:29:23.38 38 Tid: 31 2016年12月11日 15:29:23.44 39 Tid: 31 2016年12月11日 15:29:23.49 40 Tid: 31 2016年12月11日 15:29:23.57 41 Tid: 31 2016年12月11日 15:29:23.63 42 Tid: 31 2016年12月11日 15:29:23.68 43 Tid: 31 2016年12月11日 15:29:23.74 44 Tid: 16 2016年12月11日 15:29:23.80 45 Tid: 16 2016年12月11日 15:29:23.86 46 Tid: 16 2016年12月11日 15:29:23.93 47 Tid: 16 2016年12月11日 15:29:23.99 48 Tid: 16 2016年12月11日 15:29:23.105 49 Tid: 16 2016年12月11日 15:29:23.110 50 Tid: 16 2016年12月11日 15:29:23.116 51 Tid: 38 2016年12月11日 15:29:23.122 52 Tid: 38 2016年12月11日 15:29:23.128 53 Tid: 28 2016年12月11日 15:29:23.134 54 Tid: 19 2016年12月11日 15:29:23.139 55 Tid: 25 2016年12月11日 15:29:23.146 56 Tid: 37 2016年12月11日 15:29:23.152 57 Tid: 39 2016年12月11日 15:29:23.158 58 Tid: 32 2016年12月11日 15:29:23.164 59 Tid: 33 2016年12月11日 15:29:23.170 60 Tid: 31 2016年12月11日 15:29:23.176 61 Tid: 35 2016年12月11日 15:29:23.182 62 Tid: 40 2016年12月11日 15:29:23.189 63 Tid: 15 2016年12月11日 15:29:23.194 64 Tid: 18 2016年12月11日 15:29:23.202 65 Tid: 17 2016年12月11日 15:29:23.208 66 Tid: 10 2016年12月11日 15:29:23.215 67 Tid: 16 2016年12月11日 15:29:23.221
復雜多線程環境下使用讀寫鎖,全部日志成功寫入了日志文件,由ThreadId和DateTime可以看出是由不同的線程同步寫入。
本文旨在提供簡單的方式解決文件並發寫入的問題,需要深入了解線程同步及高性能文件讀寫相關知識,請參閱其他相關資料。