【bat】バッチファイルで実行時刻・経過時間をログに記録する完全ガイド｜タイムスタンプ書式・ステップ計測・性能監視まで

@echo off
setlocal

set LOGFILE=C:\logs\batch.log

REM ログフォルダがなければ作成
if not exist "C:\logs" mkdir "C:\logs"

REM 実行時刻を追記
echo ===== 実行開始: %DATE% %TIME% ===== >> "%LOGFILE%"

REM ここに実際の処理を記述
echo 処理1: データ取得 >> "%LOGFILE%"
echo 処理2: 変換 >> "%LOGFILE%"

echo ===== 実行終了: %DATE% %TIME% ===== >> "%LOGFILE%"
endlocal

@echo off
setlocal

set LOGFILE=C:\logs\batch.log

REM %TIME% を HH:MM:SS に整形（先頭スペースを 0 に変換）
set T=%TIME: =0%
set HH=%T:~0,2%
set MM=%T:~3,2%
set SS=%T:~6,2%
set TIMESTAMP=%HH%:%MM%:%SS%

echo [%TIMESTAMP%] バッチ処理開始 >> "%LOGFILE%"
echo [%TIMESTAMP%] 対象: C:\data\input >> "%LOGFILE%"

REM 処理後の時刻を再取得
set T=%TIME: =0%
set HH=%T:~0,2%
set MM=%T:~3,2%
set SS=%T:~6,2%
set TIMESTAMP=%HH%:%MM%:%SS%

echo [%TIMESTAMP%] 処理完了 >> "%LOGFILE%"
endlocal

@echo off
setlocal

set LOGFILE=C:\logs\batch.log
if not exist "C:\logs" mkdir "C:\logs"

REM サブルーチンを呼び出すだけでタイムスタンプ付きログ出力
call :log_time "処理開始"

REM ここに処理を記述
call :log_time "ステップ1: ファイル取得完了"
timeout /t 2 >nul
call :log_time "ステップ2: データ変換完了"
timeout /t 1 >nul
call :log_time "処理終了"

goto :eof

:log_time
set T=%TIME: =0%
set _TS=%T:~0,2%:%T:~3,2%:%T:~6,2%
echo [%_TS%] %~1 >> "%LOGFILE%"
echo [%_TS%] %~1
goto :eof

[09:15:00] 処理開始
[09:15:00] ステップ1: ファイル取得完了
[09:15:02] ステップ2: データ変換完了
[09:15:03] 処理終了

@echo off
setlocal enabledelayedexpansion

set LOGFILE=C:\logs\perf.log
if not exist "C:\logs" mkdir "C:\logs"

REM === 処理開始 ===
set START_TIME=%TIME%
call :log_time "処理開始"

REM ---- 実際の処理（例）----
timeout /t 3 >nul
call :log_time "ステップ1完了"

timeout /t 2 >nul
call :log_time "ステップ2完了"

REM === 経過時間を計算して記録 ===
set END_TIME=%TIME%
call :calc_elapsed "%START_TIME%" "%END_TIME%"
call :log_time "処理終了 （経過時間: !ELAPSED_S!.!ELAPSED_CS! 秒）"

goto :eof

:log_time
set T=%TIME: =0%
set _TS=%T:~0,2%:%T:~3,2%:%T:~6,2%
echo [%_TS%] %~1 >> "%LOGFILE%"
echo [%_TS%] %~1
goto :eof

:calc_elapsed
REM 引数: %1=開始時刻(%TIME%)  %2=終了時刻(%TIME%)
REM 結果: ELAPSED_S（秒）, ELAPSED_CS（センチ秒の端数）をセット
setlocal
set T1=%~1
set T2=%~2
REM 先頭スペースを 0 に変換してから分解
set T1=%T1: =0%
set T2=%T2: =0%
for /f "tokens=1-4 delims=:." %%a in ("%T1%") do (
    set /a "s_h=%%a, s_m=%%b, s_s=%%c, s_cs=%%d"
)
for /f "tokens=1-4 delims=:." %%a in ("%T2%") do (
    set /a "e_h=%%a, e_m=%%b, e_s=%%c, e_cs=%%d"
)
set /a start_cs = s_h*360000 + s_m*6000 + s_s*100 + s_cs
set /a end_cs   = e_h*360000 + e_m*6000 + e_s*100 + e_cs
set /a total_cs = end_cs - start_cs
if %total_cs% lss 0 set /a total_cs += 8640000
set /a _elapsed_s  = total_cs / 100
set /a _elapsed_cs = total_cs %% 100
endlocal & set ELAPSED_S=%_elapsed_s% & set ELAPSED_CS=%_elapsed_cs%
goto :eof

@echo off
setlocal enabledelayedexpansion

set LOGFILE=C:\logs\steps.log
if not exist "C:\logs" mkdir "C:\logs"

set TOTAL_START=%TIME%
call :log_step "=== バッチ開始 ==="

REM --- ステップ1 ---
set STEP_START=%TIME%
timeout /t 2 >nul
set STEP_END=%TIME%
call :calc_elapsed "%STEP_START%" "%STEP_END%"
call :log_step "ステップ1: データ取得 完了 (%ELAPSED_S%.%ELAPSED_CS%秒)"

REM --- ステップ2 ---
set STEP_START=%TIME%
timeout /t 4 >nul
set STEP_END=%TIME%
call :calc_elapsed "%STEP_START%" "%STEP_END%"
call :log_step "ステップ2: 変換処理 完了 (%ELAPSED_S%.%ELAPSED_CS%秒)"

REM --- ステップ3 ---
set STEP_START=%TIME%
timeout /t 1 >nul
set STEP_END=%TIME%
call :calc_elapsed "%STEP_START%" "%STEP_END%"
call :log_step "ステップ3: ファイル出力 完了 (%ELAPSED_S%.%ELAPSED_CS%秒)"

REM --- 合計経過時間 ---
call :calc_elapsed "%TOTAL_START%" "%TIME%"
call :log_step "=== バッチ終了 合計: %ELAPSED_S%.%ELAPSED_CS%秒 ==="

goto :eof

:log_step
set T=%TIME: =0%
set _TS=%T:~0,2%:%T:~3,2%:%T:~6,2%
echo [%_TS%] %~1 >> "%LOGFILE%"
echo [%_TS%] %~1
goto :eof

:calc_elapsed
setlocal
set T1=%~1
set T2=%~2
set T1=%T1: =0%
set T2=%T2: =0%
for /f "tokens=1-4 delims=:." %%a in ("%T1%") do set /a "s_h=%%a, s_m=%%b, s_s=%%c, s_cs=%%d"
for /f "tokens=1-4 delims=:." %%a in ("%T2%") do set /a "e_h=%%a, e_m=%%b, e_s=%%c, e_cs=%%d"
set /a start_cs = s_h*360000 + s_m*6000 + s_s*100 + s_cs
set /a end_cs   = e_h*360000 + e_m*6000 + e_s*100 + e_cs
set /a total_cs = end_cs - start_cs
if %total_cs% lss 0 set /a total_cs += 8640000
set /a _s = total_cs / 100
set /a _cs = total_cs %% 100
endlocal & set ELAPSED_S=%_s% & set ELAPSED_CS=%_cs%
goto :eof

@echo off
setlocal

set LOGFILE=C:\logs\strict.log
if not exist "C:\logs" mkdir "C:\logs"

REM wmic で ISO 形式の日時を取得 (YYYYMMDDHHmmss)
for /f "tokens=2 delims==" %%A in ('wmic os get LocalDateTime /value') do set DT=%%A

REM 年月日・時分秒を取り出す
set YYYY=%DT:~0,4%
set MM=%DT:~4,2%
set DD=%DT:~6,2%
set HH=%DT:~8,2%
set MI=%DT:~10,2%
set SS=%DT:~12,2%

set TIMESTAMP=%YYYY%-%MM%-%DD% %HH%:%MI%:%SS%

echo [%TIMESTAMP%] バッチ実行 >> "%LOGFILE%"
echo タイムスタンプ: %TIMESTAMP%
endlocal

@echo off
setlocal

set LOGFILE=C:\logs\result.log
if not exist "C:\logs" mkdir "C:\logs"

call :log_time "=== 実行開始 ==="

REM 外部コマンドを実行
xcopy /e /y "C:\src" "C:\dst" >nul 2>&1
set XCOPY_RC=%ERRORLEVEL%

if %XCOPY_RC% equ 0 (
    call :log_time "[OK] xcopy 成功"
) else (
    call :log_time "[NG] xcopy 失敗 ERRORLEVEL=%XCOPY_RC%"
)

call :log_time "=== 実行終了 ==="
goto :eof

:log_time
set T=%TIME: =0%
set _TS=%T:~0,2%:%T:~3,2%:%T:~6,2%
echo [%_TS%] %~1 >> "%LOGFILE%"
echo [%_TS%] %~1
goto :eof