【PowerShell】処理実行時のログファイルへの標準出力

はじまり
DOSとかPowerShellのログを取ります
ログファイルの文字コード指定
1. MS-DOSの文字コード指定
2. PowerShellの文字コード指定
ログファイルの名前
1. MS-DOSにおける年月日取得
2. PowerShellにおける年月日取得
標準出力と標準エラー出力を一つのファイルに出力する
Move-Itemの結果を-PassThruオプションで表示
まとめ
おしまい

はじまり

リサちゃん

今回はログを出していくのか

135ml

処理をまとめるから、

途中どこで処理がミスったかを見れるようにしよう。

DOSとかPowerShellのログを取ります

クラウドを使っていると、ログの取り方がスゴイ簡単なので、こういう作業って困らなかったんですけど・・・。

ローカルでコマンドプロンプトやらPowerShellやらを使って行う作業の場合はログを取るのが面倒で、全くログを取る機能を作っていなかったんですよね。そこで、作業をする時はコマンドを小分けにして今まで実行していました。そうして作業していると、途中でエラーとか発生した時にデバッグしやすかったし。

しかし、そのツールで最近バグが起こらなくなって、その小分けにしたコマンドやらスクリプトやらをチマチマ実行していくことの方が面倒くさくなってきました。なので、そのプロセスをまとめて、途中の実行ログをテキストに出力していくようにしていきたいと思います。

今回はこの記事で扱ったスクリプトをまとめていこうと思います。ローカルに置いてある画像ファイルのExifを編集したり拡張子をWebpに変換するツールです。

ログファイルの文字コード指定

まずは、文字コードを考えていきます。自分が欲しくない文字コードを取ってしまうと、ログファイルの中身がなんやら意味の分からない文字だらけのゴミになってしまいますね。

MS-DOSと、PowerShellで文字コードの指定の仕方を見ていきます。

MS-DOSの文字コード指定

MS-DOS（Version 10.0.22631.4317）では、文字コードがデフォルトでANSIになります。Microsoft様が作った、Shift-JISに似たような文字コードですね。

MS-DOSのバージョンを確認するためには、コマンドプロンプトを起動して、verを実行して確認できます。

しかし今回は、UTF-8で統一していきたいと思います。こっちの方が化けにくいので。

そこで、DOSでリダイレクトする前にLANGという環境変数を設定していきます。こんな感じです。

setlocal

:: Set UTF-8
chcp 65001
set logtxt=log_%date:~,4%%date:~5,2%%date:~8,2%.txt

echo; >> %logtxt%
echo ---------------------------------------------------------- >> %logtxt%
echo "Started: Z0-00_ready_folders.bat" >> %logtxt%
echo; >> %logtxt%

mkdir 1-1_movie_escaping >> %logtxt% 2>&1
mkdir 1-2_create_date_setting >> %logtxt% 2>&1
mkdir 5_original_files >> %logtxt% 2>&1

copy /Y exiftool.exe .\1-1_movie_escaping >> %logtxt% 2>&1
copy /Y exiftool.exe .\1-2_create_date_setting >> %logtxt% 2>&1

echo; >> %logtxt%
echo "Finished: Z0-00_ready_folders.bat" >> %logtxt%
echo ---------------------------------------------------------- >> %logtxt%
echo; >> %logtxt%

endlocal

chcp 65001というコマンドで、UTF-8で出力できるようにしたので、以下のような感じにテキストファイルに出力されました。65001はUTF-8、932がANSIになります。

ちなみにecho;を実行すると改行文字のみの行が入力されます。

---------------------------------------------------------- 
"Started: Z0-00_ready_folders.bat" 
 
A subdirectory or file 1-1_movie_escaping already exists.
A subdirectory or file 1-2_create_date_setting already exists.
A subdirectory or file 5_original_files already exists.
        1 file(s) copied.
        1 file(s) copied.
 
"Finished: Z0-00_ready_folders.bat" 
----------------------------------------------------------

PowerShellの文字コード指定

PowerShell（ver. 5.1.22621.4249）では、デフォルトでUTF-16 LEになります。

PowerShellのバージョンを確認するためには、PowerShellコンソールを起動して、$PSVersionTableを実行すると「PSVersion」というフィールドで確認できます。

PowerShellでも出力する文字コードをUTF-8に指定します。ここで、リダイレクト出力（>や>>）だと文字コードがデフォルトのものから変更できないので、以下のコマンドを使います。

手段1：Out-File系コマンドレット（Out-Fileで新規、Out-File -Appendで追記。）
手段2：Content系コマンドレット（Set-Contentで新規、Add-Contentで追記。）

これらのコマンドレットの挙動の違いについては以下の記事に詳しくまとめられていますので、興味があれば参照下さい。ざっと俯瞰した表を、その記事にあったものから拝借させていただきます。

どちらのコマンドレットでもUTF-8を指定してファイルに出力することが出来ます。今回はContent系コマンドレットで作っていこうと思います。

機能	Content	Out-File
上書き	Set-Content	Out-File
追記	Add-Content	Out-File -Append
NoClobberスイッチ	X	O
Write Lock	O	O
Read Lock	O	X
PowerShell 5.1 デフォルトEncoding	ASCII	UCS-2 Little Endian
PowerShell 6以降デフォルトEncoding	utf-8	utf-8
Encoding指定	O	O
InputObjectが空の場合のファイル作成	X	O
PassThruスイッチ	O	X
Credentialスイッチ	△	X
Includeスイッチ	O	X
Excludeスイッチ	O	X
Filterスイッチ	O	X
Transactionスイッチ	△	X

ログファイルの名前

次に、ログを溜めるファイルの名前を決めます。

日にちが入っていると良いですね。それでは実行した時の年月日がファイル名に入るようにしましょう。

MS-DOSにおける年月日取得

MS-DOSでは、%date%で現在の年月日を取得できる環境変数を参照することが可能です。2024年10月29日であれば「2024/10/29」が取得できます。

そして、その数字だけが欲しいので、以下のようにDOS上でフォーマットして、ファイル名としてローカル変数に格納します。

set logtxt=log_%date:~,4%%date:~5,2%%date:~8,2%.txt

PowerShellにおける年月日取得

PowerShellでは、Get-Dateコマンドレットで現在の日時を取得できる環境変数を参照することが可能です。2024年10月29日であれば「Tuesday, October 29, 2024 14:53:32」みたいに取得できます。

そして、その年月日の数字だけが欲しいので、以下のようにPowerShell上でフォーマットして、ファイル名としてローカル変数に格納します。

$logtxt = "log_{0}.txt" -f (Get-Date).ToString("yyyyMMdd");

標準出力と標準エラー出力を一つのファイルに出力する

コマンド実行時に出てくる標準出力と標準エラー出力を、一つのファイルにまとめて出力したいと思います。

そのために、ファイルに追記する処理を作っていきたいと思います。そこで厄介なことになってきます。

MS-DOS

MS-DOSは特に厄介なことは起こりません。標準出力および標準エラー出力をまとめて出力するコマンドは1行で事足ります。

mkdir 5_original_files >> %logtxt% 2>&1

mkdir 5_original_filesを実行した時に、既にディレクトリが存在しているとエラーというか警告文的なものがコンソールに表示されます。このように書くと、その内容も含めてファイルに出力してくれるようになります。

PowerShell（Sart-Processを使おうとしたが・・・）

PowerShellの場合は厄介です。

結局のところは、この記事で紹介されている方法を拝受させていただきました。

powershell で外部プロセスを起動して標準出力・標準エラー出力を得る - Qiita

概要PowerShell で外部コマンドを実行して、エラーになったりするので、標準出力・標準エラー出力を取得できるようにします。前提PowerShell: 5.1補足)$PSVersio…

当初は、Start-Processコマンドレットの-RedirectStandardOutputと-RedirectStandardErrorのオプションで標準出力と標準エラーを出力しようと思ったのですが、このコマンドレットではファイルへの追記を行うことが出来ないので、今回は使いませんでした。

一応、ファイルの新規作成は可能なので、一時ファイルを作ってその内容を別のコマンドレットに渡してファイル出力するという方法は可能なのですが、この方法だとIOが発生して微かながらディスクを削ることになります。

-RedirectStandardOutputと-RedirectStandardErrorオプションに対して同じ文字列を入力するとシステムエラーになります。なので一時ファイルは2種類作る必要があります。（今回作るツールを100回実行すれば200回余計に削ることになります・・・。）

そこで、もう少し良い方法があるので、このStart-Processコマンドレットはスルーで。

Start-Process (Microsoft.PowerShell.Management) - PowerShell

Start-Process コマンドレットは、ローカルコンピューターで 1 つ以上のプロセスを開始します。既定では、 Start-Process は、現在のプロセスで定義されているすべての環境変数を継承する新しいプロセスを作成します。 ...

PowerShell（Register-ObjectEventを使う）

その代わりに、先ほどの記事で別の方法が紹介されています。Register-ObjectEventコマンドレットで行うプロセスに関する情報を持ったオブジェクトをエンキューして、

変数に出力を格納して、Write-Hostコマンドレットで別のコマンドレットに渡せるようにして下さっています。これでドライブではなくメモリを使うようになりました。ドライブが削られなくなって、処理も速くなることでしょう。

ありがたく使わせていただきます。

function Invoke-ExternalCommand([string]$commandPath, [string]$arguments) {
  try {
    # Creating process object.
    $pinfo = New-Object System.Diagnostics.Process
    # Setting process invocation parameters.
    $pinfo.StartInfo.FileName = $commandPath
    $pinfo.StartInfo.Arguments = $arguments
    $pinfo.StartInfo.UseShellExecute = $false
    $pinfo.StartInfo.CreateNoWindow = $true
    $pinfo.StartInfo.UseShellExecute = $false
    $pinfo.StartInfo.RedirectStandardOutput = $true
    $pinfo.StartInfo.RedirectStandardError = $true

    # ↓↓↓ (3) 非同期書き込み
    # Creating string builders to store stdout and stderr.
    $oStdOutBuilder = New-Object -TypeName System.Text.StringBuilder
    $oStdErrBuilder = New-Object -TypeName System.Text.StringBuilder

    # Adding event handers for stdout and stderr.
    $sScripBlock = {
      if (! [String]::IsNullOrEmpty($EventArgs.Data)) {
        $Event.MessageData.AppendLine($EventArgs.Data)
      }
    }
    $oStdOutEvent = Register-ObjectEvent -InputObject $pinfo `
      -Action $sScripBlock -EventName 'OutputDataReceived' `
      -MessageData $oStdOutBuilder
    $oStdErrEvent = Register-ObjectEvent -InputObject $pinfo `
      -Action $sScripBlock -EventName 'ErrorDataReceived' `
      -MessageData $oStdErrBuilder

    # Starting process.
    [Void]$pinfo.Start()
    $pinfo.BeginOutputReadLine()
    $pinfo.BeginErrorReadLine()
    [Void]$pinfo.WaitForExit()
    # ↑↑↑

    # Unregistering events to retrieve process output.
    Unregister-Event -SourceIdentifier $oStdOutEvent.Name
    Unregister-Event -SourceIdentifier $oStdErrEvent.Name

    $oResult = New-Object -TypeName PSObject -Property ([Ordered]@{
        "ExitCode" = $pinfo.ExitCode;
        "stdout"   = $oStdOutBuilder.ToString().Trim();
        "stderr"   = $oStdErrBuilder.ToString().Trim();
      })
    return $oResult
  }
  finally {
    $pinfo.Dispose()
  }
}

しかし、ここで一つ解せなかったのが、System.Diagnostics.Process.Argumentsの部分です。

このオブジェクトのそのプロパティでは文字列を格納することが出来るのですが、同じく引数を格納することが出来るプロパティ「System.Diagnostics.Process.ArgumentList」があるのでそちらを使いたかったのですが、なぜか「このオブジェクトにプロパティ’ArgumentList’が存在しません」と表示されてエラーになります。

間違いなく存在するはずなのに・・・PowerShellの謎・・・。

ProcessStartInfo.ArgumentList プロパティ (System.Diagnostics)

アプリケーションを起動するときに使用するコマンドライン引数のコレクションを取得します。リストに追加する文字列は、前もってエスケープする必要はありません。

PowerShell（Write-HostではなくWrite-Outputを使う）

Register-ObjectEventでジョブを登録して、実行が終わったジョブをUnregister-Eventで破棄する。

そんな処理をしている先程のInvoke-ExternalCommandを実行する部分をさらにまとめます。Edit-Exifという関数を作って、実行部分とログ出力部分の双方をまとめました。

function Edit-Exif([string]$workingPath, [array]$argumentArray) {
  cd $folderDir;
  $arguments = $argumentArray -join " ";
  $strCmd = "${folderDir}\exiftool";
  Write-Output("+ $strCmd $argumentArray") | Add-Content -Path "..\$logtxt" -Encoding utf8;
  $oResult = Invoke-ExternalCommand $strCmd $arguments;
  Write-Output $oResult.stdout | Add-Content -Path "..\$logtxt" -Encoding utf8;
  Write-Host $oResult.stdout;
  Write-Host $oResult.stderr -BackgroundColor DarkRed;
  Write-Output $oResult.stderr | Add-Content -Path "..\$logtxt" -Encoding utf8;
};

このInvoke-ExternalCommandを呼び出す部分で、紹介した記事ではWrite-Hostのみが使用されていましたが、そのコマンドレットですとファイルに出力することが出来ません。

そのため、Write-HostではなくWrite-Outputを使います。（ちなみに、久し振りにPowerShellを触った僕はここで沼りました・・・。）

例えば、このような出力がコンソールで流されている場合・・・、

このようにテキストファイルの中に出力されるようになります。

1-1_movie_escaping ++++++++++++++++++++++++++++++++


Edit-Exif Started ++++++++++++++++

+ .\1-1_movie_escaping\exiftool -CreateDate<FileModifyDate -d %Y:%m:%d:%H:%M:%S .\1-1_movie_escaping
1 directories scanned
    1 image files updated
Warning: [Minor] Extracted only 1000 xmpMM:Pantry items. Ignore minor errors to extract all - ./1-1_movie_escaping/ROG_Content_01_Face_MB.mp4
Warning: [minor] Excessive number of items for xmpMM:Pantry. Processing may be slow - ./1-1_movie_escaping/ROG_Content_01_Face_MB.mp4

Edit-Exif Ended ++++++++++++++++

Move-Itemの結果を-PassThruオプションで表示

そして色々と処理を進めていくと、ファイルを動かすことが出てきます。

その際に、Move-Itemコマンドレットで動かしますが、それで動かされたファイル名を一覧で把握したいです。

そこで、-PassThruオプションを記載して、ファイル書き込み用のAdd-Contentコマンドレットにファイルを渡します。Out-File -Appendのコマンドレットには-PassThruオプションを使えないらしいので、今回はこのようにしました。

Move-Item -Path .\*_original -Destination .\5_original_files -PassThru | Add-Content -Path ".\${logtxt}" -Encoding utf8;
Move-Item -Path .\*.jpg -Destination .\5_original_files -PassThru | Add-Content -Path ".\${logtxt}" -Encoding utf8;
Move-Item -Path .\*.png -Destination .\5_original_files -PassThru | Add-Content -Path ".\${logtxt}" -Encoding utf8;

例えば、以下のようにファイルに出力されます。

これで何かしらの問題が発生したファイルを把握することが可能になります。

C:\Users\*******\Downloads\picture_backup\5_original_files\20241024052618.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024134337.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024134555.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024152547.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024195148.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022144.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022221.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022306.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022442.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027170510.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241028214610.webp_original
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024052618.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024134337.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024134555.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024152547.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241024195148.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022144.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022221.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022306.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027022442.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241027170510.jpg
C:\Users\*******\Downloads\picture_backup\5_original_files\20241028214610.jpg