■概要
ログファイルに記載されている、処理時間、モジュール名、関数名をインプットに、そのモジュールまたは関数ごとの処理時間を算出して、Json形式で出力する。
▼ログファイルのフォーマットと内容
ログファイルのフォーマットは以下の通り。
日付(yyyy-mm-dd hh:mi:ss,ffff)|ログレベル(INFO)|モジュール名|関数名|ログメッセージ
今回使用するログファイルは、以下の通り。
・test_sample.log
2025-05-04 12:39:20,670|INFO|test|test_main|start: test_main
2025-05-04 12:39:20,671|INFO|test|test_sub|ENV: WIN
2025-05-04 12:39:50,763|INFO|test|test_sub|ENV: Linux
2025-05-04 12:40:30,763|INFO|test|test_sub|ENV: MAC
2025-05-04 12:43:27,737|INFO|test|test_main|end: test_main
2025-05-04 12:46:48,222|INFO|test2|test_main2-1|start: test_main2
2025-05-04 12:49:34,740|INFO|test2|test_main2-1|end: test_main2
2025-05-04 12:47:07,638|INFO|test2|test_main2-2|ENV: WIN
2025-05-04 12:48:11,763|INFO|test2|test_main2-2|ENV: Linux
2025-05-04 12:59:32,111|INFO|test2|test_main2-2|ENV: MAC
2025-05-04 12:59:56,293|INFO|test3|test_main3|Only start
▼Jsonの出力フォーマット
Jsonの出力フォーマットは以下の通り。
{
"モジュール名/関数名": {
"start": "開始日時",
"end": "終了日時",
"duration_seconds": "処理時間"
},
"モジュール名/関数名": {
"start": "開始日時",
"end": "終了日時",
"duration_seconds": "処理時間"
},
:
:
}
■フローチャート
本処理のフローチャートを以下に示す。
■サンプルコード
本処理のサンプルコードを以下に示す。
import json
from collections import defaultdict
from datetime import datetime
LOG_FILE_NAME = './logs/test_sample.log'
def cal_processing_time_main():
"""
ログファイルから処理名および関数名
:return: None
"""
# 開始・終了時間Dict 初期値:{"start": None, "end": None}
result_dict = defaultdict(lambda: {"start": None, "end": None})
# ログファイルを読み込み
with open(LOG_FILE_NAME, "r") as f:
# 行を読み込み
lines = f.readlines()
# 1行ずつ繰り返し
for line in lines:
# 改行削除
remove_lf_line = line.rstrip("\n")
# 区切りで配列化
line_list = remove_lf_line.split("|")
# 時刻を取得
timestamp = datetime.strptime(line_list[0], "%Y-%m-%d %H:%M:%S,%f")
# 処理名取得
process_name = line_list[2]
# 関数名取得
function_name = line_list[3]
# 処理名の開始あり
if result_dict[process_name]["start"] is None:
result_dict[process_name]["start"] = timestamp
else:
result_dict[process_name]["end"] = timestamp
# 関数名の開始あり
if result_dict[function_name]["start"] is None:
result_dict[function_name]["start"] = timestamp
else:
result_dict[function_name]["end"] = timestamp
# 出力用Dict
output = {}
# 開始・終了時間Dictの要素数分繰り返し
for key, value in result_dict.items():
# 開始・終了時間取得
start = value["start"]
end = value["end"]
# 差分時間の初期値
duration = None
# 開始・終了時間あり
if start and end:
duration = (end - start).total_seconds()
# 出力用Dict作成
output[key] = {
"start": start.isoformat() if start is not None else None,
"end": end.isoformat() if end is not None else None,
"duration_seconds": duration if duration is not None else None
}
# json形式に変換
json_output = json.dumps(output, indent=2)
# 結果出力
print(json_output)
# メイン処理
if __name__ == '__main__':
cal_processing_time_main()
■実行結果
本処理の実行結果を以下に示す。
{
"test": {
"start": "2025-05-04T12:39:20.670000",
"end": "2025-05-04T12:43:27.737000",
"duration_seconds": 247.067
},
"test_main": {
"start": "2025-05-04T12:39:20.670000",
"end": "2025-05-04T12:43:27.737000",
"duration_seconds": 247.067
},
"test_sub": {
"start": "2025-05-04T12:39:20.671000",
"end": "2025-05-04T12:40:30.763000",
"duration_seconds": 70.092
},
"test2": {
"start": "2025-05-04T12:46:48.222000",
"end": "2025-05-04T12:59:32.111000",
"duration_seconds": 763.889
},
"test_main2-1": {
"start": "2025-05-04T12:46:48.222000",
"end": "2025-05-04T12:49:34.740000",
"duration_seconds": 166.518
},
"test_main2-2": {
"start": "2025-05-04T12:47:07.638000",
"end": "2025-05-04T12:59:32.111000",
"duration_seconds": 744.473
},
"test3": {
"start": "2025-05-04T12:59:56.293000",
"end": null,
"duration_seconds": null
},
"test_main3": {
"start": "2025-05-04T12:59:56.293000",
"end": null,
"duration_seconds": null
}
}
コメント