クラシックASPのコーディング考慮点 その3
ASPでのログ出力方法について
VBScriptでのログ出力 (Scripting.FileSystemObject)
ファイル出力自体は、Scripting.FileSystemObject があるのでこれを利用するが、 マルチスレッド下での動作となるので同期処理(排他)が必要。
VBScriptでは、プロセス間も含めてスレッド間の同期方法がない。
SleepしてWaitすることも難しい。 WScript.Shell経由でSleepするコマンドを実行する手段がないこともないが、ログ出力時のWaitには合わないし重い。 そもそもSleepしてリトライはさせたくない。
ということで、VBScript単体で実装する場合は、出力対象のログファイルが使用中なら予備のログファイルに出力する方法くらいか。
ログ出力 VBScript版
Set fs_ = Server.CreateObject("Scripting.FileSystemObject") Const ForAppending = 8 ' 追記モード Sub WriteLog(fileNm, msg) Dim s Dim writer Dim i, wkFileNm, sExt, iPos s = GetTimestamp() & " " & msg On Error Resume Next Set writer = fs_.OpenTextFile(fileNm, ForAppending, True) If Err.Number <> 0 Then iPos = InStrRev(fileNm, ".") If iPos = 0 Then wkFileNm = fileNm Else wkFileNm = Mid(fileNm, 1, iPos - 1) sExt = Mid(fileNm, iPos) End If 'エラーの場合、予備のログファイルへの出力 For i = 0 To 20 - 1 Err.Clear Set writer = fs_.OpenTextFile(wkFileNm & "-" & i & sExt, ForAppending, True) If Err.Number = 0 Then Exit For End If Next End If If Not writer Is Nothing Then writer.WriteLine s writer.Close Set writer = Nothing End If End Sub Function GetTimestamp() Dim ts, tmr Dim h,m,s,ms, wk ts = Now tmr = Timer wk = Fix(tmr) ms = Right("00" & Fix((tmr - wk)*1000), 3) s = wk Mod 60 wk = (wk - s) \ 60 m = wk Mod 60 wk = (wk - m) \ 60 h = wk Mod 60 If m = 0 Then If h = 0 Then If Hour(ts) = 23 Then ts = DateAdd("d", 1, ts) End If End If End If GetTimestamp = Year(ts) & "/" & Right("0" & Month(ts), 2) & "/" & Right("0" & Day(ts), 2) _ & " " & Right("0" & h, 2) & ":" & Right("0" & m, 2) & ":" & Right("0" & s, 2) & "." & ms End Function
上記ではファイルオープン時にエラーが発生した場合、ファイル名を変えてオープンを試みている。20回も回しているが、ここまで切り替えが発生することはないだろう。
このログ出力関数を使う場合は、1サイトにつき1つのログファイルに出力するのでなく、ASPページ毎のログファイルに出力するなどの細かい単位で出力したほうがよい。
一応、実際のASPファイルに組み込んで、JMeterを使って負荷をかけたが問題なさそうではあった。 ノートPC上の仮想環境でテストしたのでどこまで信用できるか怪しいが。
GetTimestamp関数について補足。
1秒よりも細かい精度の時刻が欲しかったので、VBScriptのTimer関数を利用してミリ秒の出力を行っている。 ただ、精度としては10ミリ秒程度とのことらしい。
.NetFramework(C#)のCOM相互運用機能を使ってログ出力
COMと言えば.NetでないVBで実装していたが、現在ではもう使えないので.Netを使う。
.Netであれば、スレッド間の同期が可能なのでログ出力するのに悩まずにすむ。
.NetでCOMを実装するポイントは以下のとおり。
クラスライブラリでプロジェクト作成。
プロジェクトのプロパティ→ビルドタブ→「COM相互運用機能の登録」にチェック。
プロジェクトのプロパティ→ビルドタブ→プラットフォームターゲットをx86に変更。
インタフェースを用意して、インタフェース用のGUIDを割り当てる。
クラスにはProgIdを設定する。クラス用のGUIDを割り当てる。インタフェースをデフォルトインタフェースにするため、ClassInterface(ClassInterfaceType.None)を指定する。
COMを登録する場合は、「regasm 作成したdll /tlb /codebase」。「/codebase」はGACに登録しない場合は必須。
COMを登録解除する場合は、「regasm 作成したdll /unregister」。
ログ出力 C# COM相互運用機能利用版
using System; using System.Collections.Generic; using System.IO; using System.Runtime.InteropServices; namespace MyScriptUtil { [Guid("00EE6642-ED0E-49a2-B0F0-XXXXXXXXXXXX")] //←インタフェース用のGUID public interface ILogger { bool IsErrorEnabled { get; } bool IsWarnEnabled { get; } bool IsInfoEnabled { get; } bool IsTraceEnabled { get; } bool IsDebugEnabled { get; } void Error(string msg); void Warn(string msg); void Info(string msg); void Trace(string msg); void Debug(string msg); string LogFileName { get; set; } string SourceName { get; set; } void SetLevel(string level); } [ComVisible(true)] [ClassInterface(ClassInterfaceType.None)] [ProgId("MyScriptUtil.Logger")] [Guid("4AD76CEA-4361-4a6b-8BDC-XXXXXXXXXXXX")] //←クラス用のGUID public class Logger : ILogger { private string _logFileName = string.Empty; private string _sourceName = string.Empty; private bool _isErrorEnabled = false; private bool _isWarnEnabled = false; private bool _isInfoEnabled = false; private bool _isTraceEnabled = false; private bool _isDebugEnabled = false; private readonly static object _lock = new object(); private readonly static Dictionary<string, object> _filelock = new Dictionary<string, object>(); private readonly static Dictionary<string, TextWriter> _writer = new Dictionary<string, TextWriter>(); private readonly static Dictionary<string, DateTime> _lastWrote = new Dictionary<string, DateTime>(); private static System.Threading.Thread _closer = null; private readonly static ILogFormatter _defaultFormatter = new DefaultFormatter(); private ILogFormatter _formatter = _defaultFormatter; public void SetFormatter(ILogFormatter formatter) { _formatter = formatter; } private void PutLog(string level, string msg) { DateTime ts = DateTime.Now; if (!_filelock.ContainsKey(_logFileName)) { if (string.IsNullOrEmpty(_logFileName)) { return; } lock (_lock) { if (!_filelock.ContainsKey(_logFileName)) { _filelock.Add(_logFileName, new object()); _writer.Add(_logFileName, File.AppendText(_logFileName)); _lastWrote.Add(_logFileName, DateTime.MinValue); } if (_closer == null) { _closer = new System.Threading.Thread(new System.Threading.ThreadStart(FileCloser)); _closer.Start(); } } } lock (_filelock[_logFileName]) { try { //using (TextWriter writer = File.AppendText(_logFileName)) //{ // _formatter.PutLog(writer, level, _sourceName, ts.ToString("yyyy/MM/dd HH:mm:ss.fff"), msg); //} TextWriter writer; if (_writer[_logFileName] == null) { _writer[_logFileName] = File.AppendText(_logFileName); writer = _writer[_logFileName]; } else { writer = _writer[_logFileName]; } _formatter.PutLog(writer, level, _sourceName, ts.ToString("yyyy/MM/dd HH:mm:ss.fff"), msg); writer.Flush(); _lastWrote[_logFileName] = DateTime.Now; } catch (Exception e) { e.ToString(); try { if (_writer[_logFileName] != null) { _writer[_logFileName].Close(); _writer[_logFileName] = null; } } catch { } } } } private static void FileCloser() { while (true) { System.Threading.Thread.Sleep(1000); foreach (string key in _filelock.Keys) { lock (_filelock[key]) { if (DateTime.Now.Subtract(_lastWrote[key]).TotalSeconds > 10.0) { if (_writer[key] != null) { _writer[key].Close(); } _writer[key] = null; } } } } } #region ILogger メンバ public void Debug(string msg) { if (_isDebugEnabled) { PutLog("DEBUG", msg); } } // 省略 #endregion } [ComVisible(false)] public interface ILogFormatter { void PutLog(TextWriter writer, string level, string sourceName, string timestampStr, string msg); } [ComVisible(false)] [ClassInterface(ClassInterfaceType.None)] public class DefaultFormatter : ILogFormatter { public void PutLog(TextWriter writer, string level, string sourceName, string timestampStr, string msg) { writer.Write(timestampStr); writer.Write(","); writer.Write(level); writer.Write(","); writer.Write(sourceName); writer.Write(","); writer.Write(System.Threading.Thread.CurrentThread.ManagedThreadId); writer.Write(" "); writer.WriteLine(msg); } } }
補足
ログファイルは別スレッドにて10秒間書き込みがなければCloseするようにした。 しかし、IISでこのように勝手にスレッドを作るのは作法的によくないかもしれない。
ストリームをOpenしっぱなしにするか、書き込みごとにOpen、Closeするのが無難だろう。
ファイル出力の同期については、ファイルごとにstaticオブジェクトを割り当てそれをlockステートメントで排他制御を行っている。 ストリームをOpenしたままにするのであれば、TextWriter.Synchronizedが利用できるらしい。その場合はTextWriterをstaticにする必要がある。
参考サイト
http://kwski.net/architecture/539/
http://hp.vector.co.jp/authors/VA007219/rtc_pic.html
http://internetcom.jp/developer/20060627/25.html
http://needtec.exblog.jp/21522702/
https://msdn.microsoft.com/ja-jp/library/aa288456%28v=vs.71%29.aspx