そもそもの問題：桁位置がガタガタ

現在使用してるのは、log4cppでして、設定自体はどこにでもあるようなものでした。

設定ファイルに関しては、本当に「詳しくはWebでっ」というやつでして、他の方が詳しく説明してくれているのでググってみてください。

ちなみにですが、最近以下の問題（こちらの使い方の問題）に出くわしてしまって往生しました。

config設定中にinfo()で出力しようとすると、VCランタイムDLLエラーに飛んで、プロセスもろとも撃沈。
カテゴリあり出力とカテゴリなし出力がどちらも同じファイルに出力（カテゴリありはコンソールにも出力するようにしていた）する設定の場合、スレッドによる同時呼び出しを行うと、これまたVCランタイムDLLエラーに飛んで、プロセスもろとも撃沈。

まず、「config設定中にinfo()で出力」のくだりがおかしいですが、IISのリクエスト処理中に別のリクエストが到着してしまった場合、を想像してください。作りが悪いと、この現象にぶち当たります。これはロジックで対処しましたが、「C++でIISにリクエスト送るのって結構大変なのね。」がわかりました。いつか汎用的なコードとして自分に取り込みたいです。

次の、カテゴリあり・なし同時出力ですが、log4cppではカテゴリを作って出力方法を切り替える方法があります。本来であれば「Appender」ですので、Rootにファイル出力、カテゴリを追加して、そこでコンソール出力（親にも伝わるのでそこでファイル出力）とすればよかったのに、Addivirityをfalseにして、Rootとは別物として扱っていたのに、出力ファイルは同じものだったのでバッティング（たぶん排他エラー）で落ちてしまいました。こちらは設定ファイルの修正で対応です。ふぅっ。

しかし、%t（スレッド名）に関しては使っているサンプル自体に出会わないです。一番詳しい説明は、以下の表現ではないかと。

%t ログ要求をしているスレッドの識別子出典元

私のところの問題は、この%tがスレッドIDであれ、スレッド識別子であれ、３～５桁であることを考慮せず、「%t」で作ってしまったことにあります。こんな些細な修正も簡単に進められないのは、業界の常かと（思いたい）。

しかし、同じメッセージが並んでしたとしても、出力しているスレッドが違うことが、ログからわかることで何度も救われていますので、ここはスクリプトで対応するしかありません。

昔は、桁位置の違いを探りながら進めていました。

そのロジックを闇に葬る前に、反省と成長の証としてここに展開します。

%tがスレッド識別子として３～５桁の可変であるための調整作業。次がカテゴリの長さも、{ERROR, WARN, INFO}で可変だったのでこれまた調整作業。このような調整も、一度プログラムを書いて安定稼働してしまえばいじりなおすこともないだろうと思っていました。

    # Fixed Column
    $date = $row.Substring(0, 10)
    $time = $row.Substring(11, 8)
    $millisec = $row.Substring(20, 3)

    $currentPos = 24

    $processID = ""
    if ($row[$currentPos + 3] -eq " ") {
        $processID = $row.Substring($currentPos, 3)
        $currentPos += 3
    } elseif ($row[$currentPos + 4] -eq " ") {
        $processID = $row.Substring($currentPos, 4)
        $currentPos += 4
    } else {
        $processID = $row.Substring($currentPos, 5)
        $currentPos += 5
    }

    $currentPos += 1

    $category = ""
    $nextOffset = 0
    if ($row[$currentPos + 3] -eq " ") {
        $nextOffset = 3
        $category = $row.Substring($currentPos, $nextOffset)
        $currentPos += $nextOffset
        $nextOffset = 6
    } elseif ($row[$currentPos + 4] -eq " ") {
        $nextOffset = 4
        $category = $row.Substring($currentPos, $nextOffset)
        $currentPos += $nextOffset
        $nextOffset = 5
    } else {
        $nextOffset = 5
        $category = $row.Substring($currentPos, $nextOffset)
        $currentPos += $nextOffset
        $nextOffset = 4
    }

    $currentPos += $nextOffset
    $statement = $row.Substring($currentPos)

ふとしたことで、この鉄板コードと思っていたところにメスを入れることに。

Pythonの試験勉強を行っている際、正規表現の置換に関しての部分を勉強していた際、ふとここのロジックに手を入れるべきと思いつきました。

正規表現では、カッコ（）でくくられた部分はグループという概念で、再利用ができます。再利用時は本来ならばカッコの登場順に\1, \2 ... となるのですが、PowerShellとしては、以下のように使います。Groupsでもなく、Valueでもないところにあれっ、と思うところはあります。しかも、groupsは１オリジン？そして、メッセージ部分までカッコでグループ化していませんが、なぜか７番目に入っていたので、そのまま使っています。

途中で｛｝が登場していますが、どうやらラムダ式として入れているようです。出典元

$row = [regex]::Replace($row, "(\d{4}-\d{2}-\d{2}) (\d{2}:\d{2}:\d{2}),(\d{3}) (\d{3,5}) (\w+)(\s+-\s+)",
    {
        $date = $args.groups[1].value
        $time = $args.groups[2].value
        $millisec = $args.groups[3].value
        $tid = $args.groups[4].value
        $category = $args.groups[5].value
        $statement = $args.groups[7].value
        "{0}`t{1}`t{2}`t{3}`t{4}`t{5}" -F $date, $time, $millisec, $tid.PadLeft(5, " "), $category, $statement
    })

正規表現万歳！
これで、スレッド識別子やカテゴリ名でガタガタしてしまっていたログに対して、一発できれいなTSV出力ができます。

最終的に使用しているロジックは以下のようになりました。今はこれの出力結果をExcelに読み込ませて、フィルター機能で問題を探したり、網掛けや文字色変更などで問題点の説明などに使っています。あまりでかいログファイルだとExcelが先に悲鳴を上げますが ^^;

$targetLog = ".\hogehoge.log"
$outputLog = ".\hogehoge.txt"

$contents = Get-Content -Path $targetLog -Encoding OEM

$outputString = "{0}`t{1}`t{2}`t{3}`t{4}`t{5}" -F "Date", "Time", "ms", "PID", "Category", "Message"
$outputString | Out-File $outputLog -Encoding OEM

foreach ($row in $contents) {
    if ($row.Length -eq 0) {
        continue
    }
    elseif ($row.Substring(0, 4) -ne "2020") {
        continue
    }

    $row = $row.Replace("`t", " ")

    $row = [regex]::Replace($row, "(\d{4}-\d{2}-\d{2}) (\d{2}:\d{2}:\d{2}),(\d{3}) (\d{3,5}) (\w+)(\s+-\s+)",
        {
            $date = $args.groups[1].value
            $time = $args.groups[2].value
            $millisec = $args.groups[3].value
            $tid = $args.groups[4].value
            $category = $args.groups[5].value
            $statement = $args.groups[7].value

            "{0}`t{1}`t{2}`t{3}`t{4}`t{5}" -F $date, $time, $millisec, $tid.PadLeft(5, " "), $category, $statement
        })


    Write-Output $row
    $row | Out-File -FilePath $outputLog -Append -Encoding OEM
}

しかし、PowerShellの限界なのか、Windowsが悪いのか、この解析ロジックは出力に時間が掛かります。( ´ー｀)y-~~
ま、休憩のきっかけになるからいいのですが、ここでPythonとの一本勝負と行きたいところです。

くまくまの業務日誌

Markdown記法で徒然に書いてみましょう。

ログからキーワードを抽出して、ソートして、同じものを切り捨てる　弐

そもそもの問題：桁位置がガタガタ

昔は、桁位置の違いを探りながら進めていました。

ふとしたことで、この鉄板コードと思っていたところにメスを入れることに。