parse_log.py 内容:
#!/usr/bin/env python3
# -*- coding: utf-8 -*-
"""
Log Parser Application
Parses log files to analyze screen wake-up time records
"""
import sys
import re
import datetime
import os
import inspect
from tkinter import Tk, Button, Label
from tkinter.filedialog import askopenfilename
LOG_LEVELS = {"DEBUG": 0, "INFO": 1, "WARN": 2, "ERROR": 3, "CRITICAL": 4}
CURRENT_LOG_LEVEL = LOG_LEVELS["DEBUG"]
# CURRENT_LOG_LEVEL = LOG_LEVELS["INFO"]
# Module-level constants
ANDROID_KEYWORDS = [
"Waking up from Asleep",
"setPowerMode to 2",
"Finished setting power mode 2",
"SurfaceControl: setDisplayBrightness"
]
KERNEL_KEYWORDS = [
"useless context for logic",
"lcm_prepare: enter",
"lcm_prepare: exit",
"lcm_setbacklight_cmdq: bl level"
]
TABLE_FORMAT = "{:^3}{:^25}{:^19}{:^19}{:^19}{:^19}{:^8}{:^8}"
def print_log(level, *args):
"""Print log message with caller information"""
if level == "CRITICAL":
print(*args)
elif LOG_LEVELS[level] >= CURRENT_LOG_LEVEL:
caller_frame = inspect.currentframe().f_back
caller_func = caller_frame.f_code.co_name
caller_line = caller_frame.f_lineno
print(f"{caller_func}:{caller_line}", *args)
class LogRecord:
"""Data class for single log record"""
def __init__(self):
self.reason = ""
self.log_0 = ""
self.log_1 = ""
self.log_2 = ""
self.log_3 = ""
self.time_0 = ""
self.time_1 = ""
self.time_2 = ""
self.time_3 = ""
self.delta_t12 = 0
self.delta_t13 = 0
class LogParser:
"""Log parser class"""
def __init__(self, log_keywords):
"""Initialize parser"""
self.log_keywords = log_keywords
self.records = []
self.current_record = LogRecord()
def parse_log(self, file_path):
"""Parse log file"""
print_log("INFO", f"Start parsing file: {file_path}")
# Reset state
self.records = []
self.current_record = LogRecord()
try:
with open(file_path, 'r', encoding='ISO-8859-1') as file:
lines = file.readlines()
except FileNotFoundError:
print_log("ERROR", f"File not found: {file_path}")
return
except Exception as e:
print_log("ERROR", f"Error reading file: {e}")
return
# Process each line
for line in lines:
# Check if need to save current record (start new record)
if (self.log_keywords[0] in line or self.log_keywords[1] in line):
self._save_current_record()
if self.log_keywords[0] in line:
ret = re.search(r"reason=\S+", line)
if ret:
self.current_record.reason = (ret.group())[7:-1]
print_log(
"DEBUG",
f"ret = {ret} ret.group() = {ret.group()} "
f"reason = {self.current_record.reason} line = {line}"
)
self.current_record.log_0 = line
time_match = re.search(r"\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}", line)
if time_match:
self.current_record.time_0 = time_match.group()
print_log(
"DEBUG",
f"{len(self.records)} {self.current_record.log_0} "
f"_{self.current_record.time_0}_"
)
elif self.log_keywords[1] in line:
self.current_record.log_1 = line
time_match = re.search(r"\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}", line)
if time_match:
self.current_record.time_1 = time_match.group()
print_log(
"DEBUG",
f"{len(self.records)} {self.current_record.log_1} "
f"_{self.current_record.time_1}_"
)
elif (self.log_keywords[2] in line and self.current_record.log_1 != ""):
self.current_record.log_2 = line
time_match = re.search(r"\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}", line)
if time_match:
self.current_record.time_2 = time_match.group()
print_log(
"DEBUG",
f"{len(self.records)} {self.current_record.log_2} "
f"{self.current_record.time_2}"
)
elif (self.log_keywords[3] in line and
self.current_record.log_2 != "" and
self.current_record.log_3 == ""):
self.current_record.log_3 = line
time_match = re.search(r"\d{2}-\d{2} \d{2}:\d{2}:\d{2}.\d{3}", line)
if time_match:
self.current_record.time_3 = time_match.group()
print_log(
"DEBUG",
f"{len(self.records)} {self.current_record.log_3} "
f"{self.current_record.time_3}"
)
# Save the last record
self._save_current_record()
print_log("INFO", f"Parsing completed, found {len(self.records)} records")
# Debug output
self._debug_print_records()
# Display results
self.show_results()
def _save_current_record(self):
"""Save current record to records list"""
# Check if record is complete (has log1 and log2)
if self.current_record.log_1 != "" and self.current_record.log_2 != "":
data_is_valid = True
try:
time_format = "%Y-%m-%d %H:%M:%S.%f"
t1 = datetime.datetime.strptime(
f"2025-{self.current_record.time_1}", time_format
)
t2 = datetime.datetime.strptime(
f"2025-{self.current_record.time_2}", time_format
)
self.current_record.delta_t12 = round(
datetime.datetime.timestamp(t2) -
datetime.datetime.timestamp(t1), 3
)
if self.current_record.delta_t12 < 0:
data_is_valid = False
print_log("DEBUG", f"{t1} {t2} {self.current_record.delta_t12}")
if self.current_record.log_3 != "":
t3 = datetime.datetime.strptime(
f"2025-{self.current_record.time_3}", time_format
)
self.current_record.delta_t13 = round(
datetime.datetime.timestamp(t3) -
datetime.datetime.timestamp(t1), 3
)
if self.current_record.delta_t13 < 0:
data_is_valid = False
print_log("DEBUG", f"{t1} {t3} {self.current_record.delta_t13}")
except ValueError as e:
print_log("ERROR", f"Time parse error: {e}")
data_is_valid = False
if data_is_valid:
print_log("DEBUG", f"current_record = {self.current_record.__dict__}")
self.records.append(self.current_record)
self.current_record = LogRecord()
def _debug_print_records(self):
"""Debug print all records"""
print_log("DEBUG", f"len(records) = {len(self.records)}")
for i, record in enumerate(self.records):
print_log(
"DEBUG",
f"i = {i}\n"
f"record.log_0 = {record.log_0[:-1]}\n"
f"record.log_1 = {record.log_1[:-1]}\n"
f"record.log_2 = {record.log_2[:-1]}\n"
f"record.log_3 = {record.log_3[:-1]}\n"
f"record.time_0 = {record.time_0}\n"
f"record.time_1 = {record.time_1}\n"
f"record.time_2 = {record.time_2}\n"
f"record.time_3 = {record.time_3}\n"
f"record.delta_t12 = {record.delta_t12}\n"
f"record.delta_t13 = {record.delta_t13}\n"
)
def show_results(self):
"""Display all parsing results"""
# Display by reason groups
unique_reasons = set(record.reason for record in self.records)
for reason in unique_reasons:
self.show_by_reason(reason)
# Display summary table
self.show_summary()
def show_by_reason(self, reason):
"""Show records filtered by reason"""
total_t12 = 0
counter = 0
for record in self.records:
if record.reason == reason:
total_t12 += record.delta_t12
counter += 1
if counter == 0:
return
aver_t12 = int(total_t12 / counter * 1000)
print_log(
"CRITICAL",
f"Table for reason = {reason}, average_t12 = {aver_t12} ms"
)
print_log("CRITICAL", f"{'-' * 120}")
print_log(
"CRITICAL",
TABLE_FORMAT.format(
"num", "reason", "t0", "t1", "t2", "t3", "t12(ms)", "t13(ms)"
)
)
print_log(
"CRITICAL",
TABLE_FORMAT.format(
"", "",
f"({self.log_keywords[0][:16]})",
f"({self.log_keywords[1][:16]})",
f"({self.log_keywords[2][:16]})",
f"({self.log_keywords[3][:16]})", "", ""
)
)
for i, record in enumerate(self.records):
if record.reason == reason:
t13_ms = int(record.delta_t13 * 1000) if record.delta_t13 != 0 else ""
t12_ms = int(record.delta_t12 * 1000)
print_log(
"CRITICAL",
TABLE_FORMAT.format(
i, record.reason, record.time_0, record.time_1,
record.time_2, record.time_3, t12_ms, t13_ms
)
)
print_log("CRITICAL", f"{'-' * 120}\n\n")
def show_summary(self):
"""Show summary table"""
if not self.records:
print_log("CRITICAL", "No records found")
return
total_t12 = sum(record.delta_t12 for record in self.records)
aver_t12 = int(total_t12 / len(self.records) * 1000)
print_log(
"CRITICAL",
f"Summary table - records: {len(self.records)}, "
f"average_t12: {aver_t12} ms"
)
print_log("CRITICAL", '-' * 120)
print_log(
"CRITICAL",
TABLE_FORMAT.format(
"num", "reason", "t0", "t1", "t2", "t3", "t12(ms)", "t13(ms)"
)
)
print_log(
"CRITICAL",
TABLE_FORMAT.format(
"", "",
f"({self.log_keywords[0][:16]})",
f"({self.log_keywords[1][:16]})",
f"({self.log_keywords[2][:16]})",
f"({self.log_keywords[3][:16]})", "", ""
)
)
for i, record in enumerate(self.records):
t13_ms = int(record.delta_t13 * 1000) if record.delta_t13 != 0 else ""
t12_ms = int(record.delta_t12 * 1000)
print_log(
"CRITICAL",
TABLE_FORMAT.format(
i, record.reason, record.time_0, record.time_1,
record.time_2, record.time_3, t12_ms, t13_ms
)
)
print_log("CRITICAL", f"{'-' * 120}\n\n")
class LogAnalyzerApp:
"""GUI application class"""
def __init__(self):
self.root = Tk()
self.setup_ui()
def setup_ui(self):
"""Setup user interface"""
self.root.geometry("500x300+0+0")
self.root.title("Log Parser v1.0")
Button(
self.root,
text="Click to select android log", width=50,
command=lambda: self.select_log(ANDROID_KEYWORDS)
).grid(row=0, column=0, padx=50, pady=10)
Button(
self.root,
text="Click to select kernel log", width=50,
command=lambda: self.select_log(KERNEL_KEYWORDS)
).grid(row=1, column=0, padx=50, pady=10)
self.file_label = Label(
self.root, width=50, height=10, bg="white",
wraplength=300, justify="left"
)
self.file_label.grid(row=2, column=0, padx=50, pady=10)
def select_log(self, keywords):
"""Select log file"""
log_file = askopenfilename(
title="Please select log file",
initialdir="D:/dir/python/parse_log",
filetypes=[("All files", "*.*"), ("Log", "*.log"), ("Text", "*.txt")]
)
self.file_label["text"] = f"Log file: {log_file}"
print_log("INFO", f"Selected log file: {log_file}")
if log_file:
parser = LogParser(keywords)
parser.parse_log(log_file)
def run(self):
"""Run application"""
self.root.mainloop()
def main():
"""Main function"""
app = LogAnalyzerApp()
app.run()
if __name__ == "__main__":
main()
测试用例，android.log内容:
11-01 12:34:56.123 1386 2091 I PowerManagerService: Waking up from Asleep (uid=1000, reason=WAKE_REASON_POWER_BUTTON, details=android.policy:POWER)...
2025-11-01 12:34:57.123 895 982 I SurfaceFlinger: setPowerMode to 2 from pid=1386, uid=1000
11-01 12:34:58.124 895 895 I SurfaceFlinger: Finished setting power mode 2 on display 4627039422300187648
11-01 12:34:59.125 1386 2303 I SurfaceControl: setDisplayBrightness. {0.1313524, 68.101685, 0.1313524, 68.101685, 0.13545427, 68.101685}
11-01 12:34:59.456 1386 2303 I SurfaceControl: setDisplayBrightness. {0.1313524, 68.101685, 0.1313524, 68.101685, 0.13545427, 68.101685}
11-01 13:34:57.123 895 982 I SurfaceFlinger: setPowerMode to 2 from pid=1386, uid=1000
11-01 13:34:58.123 895 895 I SurfaceFlinger: Finished setting power mode 2 on display 4627039422300187648
11-01 13:34:59.123 1386 2303 I SurfaceControl: setDisplayBrightness. {0.1313524, 68.101685, 0.1313524, 68.101685, 0.13545427, 68.101685}
11-01 14:34:57.123 895 982 I SurfaceFlinger: setPowerMode to 2 from pid=1386, uid=1000
11-01 14:34:58.123 895 895 I SurfaceFlinger: Finished setting power mode 2 on display 4627039422300187648
模拟其它无关log 11-01 14:34:59.123 Parse LCD screen-on records and time, click to select log file
行 4266: 10-25 10:26:30.125 1386 2091 I PowerManagerService: Waking up from Asleep (uid=1000, reason=WAKE_REASON_TAP, details=android.policy:POWER)...
行 4602: 10-25 10:26:30.176 895 982 I SurfaceFlinger: setPowerMode to 2 from pid=1386, uid=1000
行 6002: 10-25 10:26:30.333 895 895 I SurfaceFlinger: Finished setting power mode 2 on display 4627039422300187648
行 6094: 10-25 10:26:30.339 1386 2303 I SurfaceControl: setDisplayBrightness. {0.1313524, 68.101685, 0.1313524, 68.101685, 0.13545427, 68.101685}
测试用例，kernel.log 内容：
2025-11-01 12:34:57.123 <3>[ 180.082243][ T791] [2025:11:28 02:43:56](0)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: enter
11-01 12:34:58.124 <3>[ 180.211307][ T791] [2025:11:28 02:43:56](3)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: exit
11-01 12:34:59.125 <3>[ 180.262656][ T1362] [2025:11:28 02:43:56](3)[1362:AALMain][LCD_KIT/I]lcm_setbacklight_cmdq: bl level:863
11-01 12:34:59.456 <3>[ 180.262656][ T1362] [2025:11:28 02:43:56](3)[1362:AALMain][LCD_KIT/I]lcm_setbacklight_cmdq: bl level:863
11-01 13:34:57.123 <3>[ 180.082243][ T791] [2025:11:28 02:43:56](0)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: enter
11-01 13:34:58.123 <3>[ 180.211307][ T791] [2025:11:28 02:43:56](3)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: exit
11-01 13:34:59.123 <3>[ 180.262656][ T1362] [2025:11:28 02:43:56](3)[1362:AALMain][LCD_KIT/I]lcm_setbacklight_cmdq: bl level:863
11-01 14:34:57.123 <3>[ 180.082243][ T791] [2025:11:28 02:43:56](0)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: enter
11-01 14:34:58.123 <3>[ 180.211307][ T791] [2025:11:28 02:43:56](3)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: exit
模拟其它无关log 11-01 14:34:59.123 Parse LCD screen-on records and time, click to select log file
行 140: 11-28 02:43:57.268 <3>[ 180.082243][ T791] [2025:11:28 02:43:56](0)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: enter
行 320: 11-28 02:43:57.396 <3>[ 180.211307][ T791] [2025:11:28 02:43:56](3)[791:composer@3.1-se][LCD_KIT/I]lcm_prepare: exit
行 456: 11-28 02:43:57.451 <3>[ 180.262656][ T1362] [2025:11:28 02:43:56](3)[1362:AALMain][LCD_KIT/I]lcm_setbacklight_cmdq: bl level:863
成品效果：
