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

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

はじまり#

リサちゃん avatar
リサちゃん
今回はログを出していくのか
135ml avatar
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という環境変数を設定していきます。こんな感じです。

Terminal window
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系コマンドレットで作っていこうと思います。

機能ContentOut-File
上書きSet-ContentOut-File
追記Add-ContentOut-File -Append
NoClobberスイッチXO
Write LockOO
Read LockOX
PowerShell 5.1 デフォルトEncodingASCIIUCS-2 Little Endian
PowerShell 6以降 デフォルトEncodingutf-8utf-8
Encoding指定OO
InputObjectが空の場合のファイル作成XO
PassThruスイッチOX
CredentialスイッチX
IncludeスイッチOX
ExcludeスイッチOX
FilterスイッチOX
TransactionスイッチX

ログファイルの名前#

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

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

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

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

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

Terminal window
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上でフォーマットして、ファイル名としてローカル変数に格納します。

Terminal window
$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の場合は厄介です。

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

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

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

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

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

PowerShell(Register-ObjectEventを使う)#

その代わりに、先ほどの記事で別の方法が紹介されています。

Register-ObjectEventコマンドレットで行うプロセスに関する情報を持ったオブジェクトをエンキューして、変数に出力を格納して、Write-Hostコマンドレットで別のコマンドレットに渡せるようにして下さっています。これでドライブではなくメモリを使うようになりました。ドライブが削られなくなって、処理も速くなることでしょう。

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

Terminal window
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の謎・・・。

PowerShell(Write-HostではなくWrite-Outputを使う)#

Register-ObjectEventでジョブを登録して、実行が終わったジョブをUnregister-Eventで破棄する。 そんな処理をしている先程のInvoke-ExternalCommandを実行する部分をさらにまとめます。Edit-Exifという関数を作って、実行部分とログ出力部分の双方をまとめました。

Terminal window
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オプションを使えないらしいので、今回はこのようにしました。

Terminal window
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

まとめ#

PowerShellおよびMS-DOSで、ファイルに実行ログを残す方法を書いてみました。 以下がまとめです。

  • 文字コード指定chcp 65001や、Out-FileSet-ContentでUTF-8を設定する。
  • ログファイル名%date%や、Get-Dateコマンドレットで実行日時をファイル名に反映する。
  • 出力の一元化2>&1や、Register-ObjectEventWrite-Outputで標準出力・エラー出力をまとめる。
  • ファイル移動ログMove-ItemPassThruでファイル移動を確認する。

外部ファイルからの標準ログと標準エラーログも出すとなると少し面倒になりました。

ログを出力できるようにすれば、より大きな処理も安心して動かすことが出来ますね。

おしまい#

リサちゃん avatar
リサちゃん
色々な仕様があって厄介だったな
135ml avatar
135ml
クラウドのロガーってスゴイ便利だったんだな。

以上になります!

記事を共有

この記事が役に立ったなら、ぜひ他の人と共有してください!

【PowerShell】処理実行時のログファイルへの標準出力
https://endorphinbath.com/posts/powershell-stdout/
著者
kinkinbeer135ml
公開日
2024-10-22
ライセンス
CC BY-NC-SA 4.0
Profile Image of the Author
kinkinbeer135ml
SIerをやめて、プログラミングを勉強しています。※Amazonアソシエイトに参加しています。
お知らせ
私のブログへようこそ!これはサンプルのお知らせです。
音楽
カバー

音楽

再生中なし

0:00 0:00
歌詞なし
カテゴリ
タグ
サイト統計
記事
287
カテゴリー
8
タグ
93
総文字数
486,174
運用日数
0
最終活動
0 日前

目次