#!/usr/bin/env python # # Copyright (C) 2022 The Android Open Source Project # # Licensed under the Apache License, Version 2.0 (the "License"); # you may not use this file except in compliance with the License. # You may obtain a copy of the License at # # http://www.apache.org/licenses/LICENSE-2.0 # # Unless required by applicable law or agreed to in writing, software # distributed under the License is distributed on an "AS IS" BASIS, # WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. # See the License for the specific language governing permissions and # limitations under the License. # """Reports disk I/O usage by UID/Package, process, and file level breakdowns.""" from datetime import datetime from collections import namedtuple import androidFsParser import argparse import collections import os import psutil import re import signal import subprocess import sys import threading import time import uidProcessMapper # ex) lrwxrwxrwx 1 root root 16 1970-01-06 13:22 userdata -> /dev/block/sda14 RE_LS_BLOCK_DEVICE = r"\S+\s[0-9]+\s\S+\s\S+\s+[0-9]+\s[0-9\-]+\s[0-9]+\:[0-9]+\suserdata\s\-\>\s\/dev\/block\/(\S+)" # ex) 1002 246373245 418936352 1818624 0 0 0 0 0 0 0 RE_UID_IO_STATS_LINE = r"([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)" # ex) 253 5 dm-5 3117 0 354656 3324 0 0 0 0 0 2696 3324 0 0 0 0 RE_DISK_STATS_LINE = r"\s+([0-9]+)\s+([0-9]+)\s([a-z\-0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)\s([0-9]+)" ADB_CMD = "adb" TEMP_TRACE_FILE = "temp_trace_file.txt" CARWATCHDOG_DUMP = "carwatchdog_dump.txt" OUTPUT_FILE = "ioblame_out.txt" WATCHDOG_BUFFER_SECS = 600 DID_RECEIVE_SIGINT = False def signal_handler(sig, frame): global DID_RECEIVE_SIGINT DID_RECEIVE_SIGINT = True print("Received signal interrupt") def init_arguments(): parser = argparse.ArgumentParser( description="Collect and process f2fs traces") parser.add_argument( "-s", "--serial", dest="serial", action="store", help="Android device serial number") parser.add_argument( "-r", "--trace_reads", default=False, action="store_true", dest="traceReads", help="Trace f2fs_dataread_start") parser.add_argument( "-w", "--trace_writes", default=False, action="store_true", dest="traceWrites", help="Trace f2fs_datawrite_start") parser.add_argument( "-d", "--trace_duration", type=int, default=3600, dest="traceDuration", help="Total trace duration in seconds") parser.add_argument( "-i", "--sampling_interval", type=int, default=300, dest="samplingInterval", help="Sampling interval in seconds for CarWatchdog collection (applicable only on" " automotive form-factor") parser.add_argument( "-o", "--output_directory", type=dir_path, default=os.getcwd(), dest="outputDir", help="Output directory") return parser.parse_args() def verify_arguments(args): if args.serial is not None: global ADB_CMD ADB_CMD = "%s %s" % ("adb -s", args.serial) if not args.traceReads and not args.traceWrites: raise argparse.ArgumentTypeError( "Must provide at least one of the --trace_reads or --trace_writes options" ) def dir_path(path): if os.path.isdir(path): return path else: raise argparse.ArgumentTypeError( "{} is not a valid directory path".format(path)) def run_adb_cmd(cmd): r = subprocess.check_output(ADB_CMD + " " + cmd, shell=True) return r.decode("utf-8") def run_adb_shell_cmd(cmd): return run_adb_cmd("shell " + cmd) def run_adb_shell_cmd_strip_output(cmd): return run_adb_cmd("shell " + cmd).strip() def run_adb_shell_cmd_ignore_err(cmd): try: r = subprocess.run( ADB_CMD + " shell " + cmd, shell=True, capture_output=True) return r.stdout.decode("utf-8") except Exception: return "" def run_shell_cmd(cmd): return subprocess.check_output(cmd, shell=True) def run_bg_adb_shell_cmd(cmd): return subprocess.Popen(ADB_CMD + " shell " + cmd, shell=True) def run_bg_shell_cmd(cmd): return subprocess.Popen(cmd, shell=True) def get_block_dev(): model = run_adb_shell_cmd_strip_output( "'getprop ro.product.name' | sed \'s/[ \\t\\r\\n]*$//\'") print("Found %s Device" % model) if "emu" in model: return "vda" result = run_adb_shell_cmd_strip_output( "'ls -la /dev/block/bootdevice/by-name | grep userdata'") match = re.compile(RE_LS_BLOCK_DEVICE).match(result) if not match: print("Unknown Device {} -- trying Pixel config".format(model)) return "sda" return match.group(1) def prep_to_do_something(): run_adb_shell_cmd("'echo 3 > /proc/sys/vm/drop_caches'") time.sleep(1) def setup_tracepoints(shouldTraceReads, shouldTraceWrites): # This is a good point to check if the Android FS tracepoints are enabled in the # kernel or not isTraceEnabled = run_adb_shell_cmd( "'if [ -d /sys/kernel/tracing/events/f2fs ]; then echo 0; else echo 1; fi'" ) if isTraceEnabled == 0: raise RuntimeError("Android FS tracing is not enabled") run_adb_shell_cmd("'echo 0 > /sys/kernel/tracing/tracing_on;\ echo 0 > /sys/kernel/tracing/trace;\ echo 0 > /sys/kernel/tracing/events/ext4/enable;\ echo 0 > /sys/kernel/tracing/events/block/enable'") if shouldTraceReads: run_adb_shell_cmd( "'echo 1 > /sys/kernel/tracing/events/f2fs/f2fs_dataread_start/enable'" ) if shouldTraceWrites: run_adb_shell_cmd( "'echo 1 > /sys/kernel/tracing/events/f2fs/f2fs_datawrite_start/enable'" ) run_adb_shell_cmd("'echo 1 > /sys/kernel/tracing/tracing_on'") def clear_tracing(shouldTraceReads, shouldTraceWrites): if shouldTraceReads: run_adb_shell_cmd( "'echo 0 > /sys/kernel/tracing/events/f2fs/f2fs_dataread_start/enable'" ) if shouldTraceWrites: run_adb_shell_cmd( "'echo 0 > /sys/kernel/tracing/events/f2fs/f2fs_datawrite_start/enable'" ) run_adb_shell_cmd("'echo 0 > /sys/kernel/tracing/tracing_on'") def start_streaming_trace(traceFile): return run_bg_adb_shell_cmd( "'cat /sys/kernel/tracing/trace_pipe | grep -e f2fs_data -e f2fs_writepages'\ > {}".format(traceFile)) def stop_streaming_trace(sub_proc): process = psutil.Process(sub_proc.pid) for child_proc in process.children(recursive=True): child_proc.kill() process.kill() class carwatchdog_collection(threading.Thread): def __init__(self, traceDuration, samplingInterval): threading.Thread.__init__(self) self.traceDuration = traceDuration self.samplingInterval = samplingInterval def run(self): isBootCompleted = 0 while isBootCompleted == 0: isBootCompleted = run_adb_shell_cmd_strip_output( "'getprop sys.boot_completed'") time.sleep(1) # Clean up previous state. run_adb_shell_cmd( "'dumpsys android.automotive.watchdog.ICarWatchdog/default\ --stop_perf &>/dev/null'") run_adb_shell_cmd( "'dumpsys android.automotive.watchdog.ICarWatchdog/default \ --start_perf --max_duration {} --interval {}'".format( self.traceDuration + WATCHDOG_BUFFER_SECS, self.samplingInterval)) def stop_carwatchdog_collection(outputDir): run_adb_shell_cmd("'dumpsys android.automotive.watchdog.ICarWatchdog/default" " --stop_perf' > {}/{}".format(outputDir, CARWATCHDOG_DUMP)) def do_something(outpuDir, traceDuration, samplingInterval, uidProcessMapperObj): buildChars = run_adb_shell_cmd_strip_output( "'getprop ro.build.characteristics'") carwatchdog_collection_thread = None if "automotive" in buildChars: carwatchdog_collection_thread = carwatchdog_collection( traceDuration, samplingInterval) carwatchdog_collection_thread.start() for i in range(1, traceDuration): if DID_RECEIVE_SIGINT: break now = time.process_time() read_uid_process_mapping(uidProcessMapperObj) taken = time.process_time() - now if (taken < 1): time.sleep(1 - taken) read_uid_package_mapping(uidProcessMapperObj) if "automotive" in buildChars: carwatchdog_collection_thread.join() stop_carwatchdog_collection(outpuDir) def read_uid_process_mapping(uidProcessMapperObj): procStatusDump = run_adb_shell_cmd_ignore_err( "'cat /proc/*/status /proc/*/task/*/status 2> /dev/null'") uidProcessMapperObj.parse_proc_status_dump(procStatusDump) def read_uid_package_mapping(uidProcessMapperObj): packageMappingDump = run_adb_shell_cmd_ignore_err( "'pm list packages -a -U | sort | uniq'") uidProcessMapperObj.parse_uid_package_dump(packageMappingDump) # Parser for "/proc/diskstats". class DiskStats: def __init__(self, readIos, readSectors, writeIos, writeSectors): self.readIos = readIos self.readSectors = readSectors self.writeIos = writeIos self.writeSectors = writeSectors def delta(self, other): return DiskStats(self.readIos - other.readIos, self.readSectors - other.readSectors, self.writeIos - other.writeIos, self.writeSectors - other.writeSectors) def dump(self, shouldDumpReads, shouldDumpWrites, outputFile): if self.readIos is None or self.readIos is None or self.readIos is None\ or self.readIos is None: outputFile.write("Missing disk stats") return if (shouldDumpReads): outputFile.write("Total dev block reads: {} KB, IOs: {}\n".format( self.readSectors / 2, self.readIos)) if (shouldDumpWrites): outputFile.write("Total dev block writes: {} KB, IOs: {}\n".format( self.writeSectors / 2, self.writeIos)) def get_disk_stats(blockDev): line = run_adb_shell_cmd( "'cat /proc/diskstats' | fgrep -w {}".format(blockDev)) matcher = re.compile(RE_DISK_STATS_LINE) match = matcher.match(line) if not match: return None readIos = int(match.group(4)) readSectors = int(match.group(6)) writeIos = int(match.group(8)) writeSectors = int(match.group(10)) return DiskStats(readIos, readSectors, writeIos, writeSectors) IoBytes = namedtuple("IoBytes", "rdBytes wrBytes") # Parser for "/proc/uid_io/stats". class UidIoStats: def __init__(self): self.uidIoStatsReMatcher = re.compile(RE_UID_IO_STATS_LINE) self.ioBytesByUid = {} # Key: UID, Value: IoBytes self.totalIoBytes = IoBytes(rdBytes=0, wrBytes=0) def parse(self, dump): totalRdBytes = 0 totalWrBytes = 0 for line in dump.split("\n"): (uid, ioBytes) = self.parse_uid_io_bytes(line) self.ioBytesByUid[uid] = ioBytes totalRdBytes += ioBytes.rdBytes totalWrBytes += ioBytes.wrBytes self.totalIoBytes = IoBytes(rdBytes=totalRdBytes, wrBytes=totalWrBytes) def parse_uid_io_bytes(self, line): match = self.uidIoStatsReMatcher.match(line) if not match: return None return (int(match.group(1)), IoBytes( rdBytes=(int(match.group(4)) + int(match.group(8))), wrBytes=(int(match.group(5)) + int(match.group(9))))) def delta(self, other): deltaStats = UidIoStats() deltaStats.totalIoBytes = IoBytes( rdBytes=self.totalIoBytes.rdBytes - other.totalIoBytes.rdBytes, wrBytes=self.totalIoBytes.wrBytes - other.totalIoBytes.wrBytes) for uid, ioBytes in self.ioBytesByUid.items(): if uid not in other.ioBytesByUid: deltaStats.ioBytesByUid[uid] = ioBytes continue otherIoBytes = other.ioBytesByUid[uid] rdBytes = ioBytes.rdBytes - otherIoBytes.rdBytes if ioBytes.rdBytes > otherIoBytes.rdBytes\ else 0 wrBytes = ioBytes.wrBytes - otherIoBytes.wrBytes if ioBytes.wrBytes > otherIoBytes.wrBytes\ else 0 deltaStats.ioBytesByUid[uid] = IoBytes(rdBytes=rdBytes, wrBytes=wrBytes) return deltaStats def dumpTotal(self, mode, outputFile): totalBytes = self.totalIoBytes.wrBytes if mode == "write" else self.totalIoBytes.rdBytes outputFile.write("Total system-wide {} KB: {}\n".format( mode, to_kib(totalBytes))) def dump(self, uidProcessMapperObj, mode, func, outputFile): sortedEntries = collections.OrderedDict( sorted( self.ioBytesByUid.items(), key=lambda item: item[1].wrBytes if mode == "write" else item[1].rdBytes, reverse=True)) totalEntries = len(sortedEntries) for i in range(totalEntries): uid, ioBytes = sortedEntries.popitem(last=False) totalBytes = ioBytes.wrBytes if mode == "write" else ioBytes.rdBytes if totalBytes < androidFsParser.MIN_PID_BYTES: continue uidInfo = uidProcessMapperObj.get_uid_info(uid) outputFile.write("{}, Total {} KB: {}\n".format(uidInfo.to_string(), mode, to_kib(totalBytes))) func(uid) outputFile.write("\n" + ("=" * 100) + "\n") if i < totalEntries - 1: outputFile.write("\n") def get_uid_io_stats(): uidIoStatsDump = run_adb_shell_cmd_strip_output("'cat /proc/uid_io/stats'") uidIoStats = UidIoStats() uidIoStats.parse(uidIoStatsDump) return uidIoStats def to_kib(bytes): return bytes / 1024 def main(argv): signal.signal(signal.SIGINT, signal_handler) args = init_arguments() verify_arguments(args) run_adb_cmd("root") buildDesc = run_adb_shell_cmd_strip_output("'getprop ro.build.description'") blockDev = get_block_dev() prep_to_do_something() setup_tracepoints(args.traceReads, args.traceWrites) diskStatsBefore = get_disk_stats(blockDev) uidIoStatsBefore = get_uid_io_stats() traceFile = "{}/{}".format(args.outputDir, TEMP_TRACE_FILE) startDateTime = datetime.now() proc = start_streaming_trace(traceFile) print("Started trace streaming") uidProcessMapperObj = uidProcessMapper.UidProcessMapper() do_something(args.outputDir, args.traceDuration, args.samplingInterval, uidProcessMapperObj) stop_streaming_trace(proc) endDateTime = datetime.now() print("Stopped trace streaming") clear_tracing(args.traceReads, args.traceWrites) diskStatsAfter = get_disk_stats(blockDev) uidIoStatsAfter = get_uid_io_stats() diskStatsDelta = diskStatsAfter.delta(diskStatsBefore) uidIoStatsDelta = uidIoStatsAfter.delta(uidIoStatsBefore) print("Completed device side collection") writeParser = androidFsParser.AndroidFsParser(androidFsParser.RE_WRITE_START, uidProcessMapperObj) readParser = androidFsParser.AndroidFsParser(androidFsParser.RE_READ_START, uidProcessMapperObj) with open(traceFile) as file: for line in file: if args.traceWrites and writeParser.parse(line): continue if args.traceReads: readParser.parse(line) outputFile = open("{}/{}".format(args.outputDir, OUTPUT_FILE), "w") outputFile.write("Collection datetime: {}, Total duration: {}\n".format( endDateTime, endDateTime - startDateTime)) outputFile.write("Build description: {}\n".format(buildDesc)) outputFile.write( "Minimum KB per process or UID: {}, Small file KB: {}\n\n".format( to_kib(androidFsParser.MIN_PID_BYTES), to_kib(androidFsParser.SMALL_FILE_BYTES))) diskStatsDelta.dump(args.traceReads, args.traceWrites, outputFile) if args.traceWrites: uidIoStatsDelta.dumpTotal("write", outputFile) writeParser.dumpTotal(outputFile) uidIoStatsDelta.dump(uidProcessMapperObj, "write", lambda uid: writeParser.dump(uid, outputFile), outputFile) if args.traceWrites and args.traceReads: outputFile.write("\n\n\n") if args.traceReads: uidIoStatsDelta.dumpTotal("read", outputFile) readParser.dumpTotal(outputFile) uidIoStatsDelta.dump(uidProcessMapperObj, "read", lambda uid: readParser.dump(uid, outputFile), outputFile) outputFile.close() run_shell_cmd("rm {}/{}".format(args.outputDir, TEMP_TRACE_FILE)) if __name__ == "__main__": main(sys.argv)