IQ.Pilot Release Commit @ bec7652
This commit is contained in:
1
iqpilot/tools/iqperf/__init__.py
Executable file
1
iqpilot/tools/iqperf/__init__.py
Executable file
@@ -0,0 +1 @@
|
||||
|
||||
82
iqpilot/tools/iqperf/analyze_msg_size.py
Executable file
82
iqpilot/tools/iqperf/analyze_msg_size.py
Executable file
@@ -0,0 +1,82 @@
|
||||
#!/usr/bin/env python3
|
||||
import argparse
|
||||
from tqdm import tqdm
|
||||
|
||||
from iqpilot.cereal.services import SERVICE_LIST, QueueSize
|
||||
from iqpilot.tools.lib.logreader import LogReader
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
parser = argparse.ArgumentParser(description="Analyze message sizes from a log route")
|
||||
parser.add_argument("route", nargs="?", default="98395b7c5b27882e/000000a8--f87e7cd255",
|
||||
help="Log route to analyze (default: 98395b7c5b27882e/000000a8--f87e7cd255)")
|
||||
args = parser.parse_args()
|
||||
|
||||
lr = LogReader(args.route)
|
||||
|
||||
szs = {}
|
||||
for msg in tqdm(lr):
|
||||
sz = len(msg.as_builder().to_bytes())
|
||||
msg_type = msg.which()
|
||||
if msg_type not in szs:
|
||||
szs[msg_type] = {'min': sz, 'max': sz, 'sum': sz, 'count': 1}
|
||||
else:
|
||||
szs[msg_type]['min'] = min(szs[msg_type]['min'], sz)
|
||||
szs[msg_type]['max'] = max(szs[msg_type]['max'], sz)
|
||||
szs[msg_type]['sum'] += sz
|
||||
szs[msg_type]['count'] += 1
|
||||
|
||||
print()
|
||||
print(f"{'Service':<36} {'Min (KB)':>12} {'Max (KB)':>12} {'Avg (KB)':>12} {'KB/min':>12} {'KB/sec':>12} {'Minutes in 10MB':>18} {'Seconds in Queue':>18}")
|
||||
print("-" * 132)
|
||||
def sort_key(x):
|
||||
k, v = x
|
||||
avg = v['sum'] / v['count']
|
||||
freq = SERVICE_LIST.get(k, None)
|
||||
freq_val = freq.frequency if freq else 0.0
|
||||
kb_per_min = (avg * freq_val * 60) / 1024 if freq_val > 0 else 0.0
|
||||
return kb_per_min
|
||||
total_kb_per_min = 0.0
|
||||
RINGBUFFER_SIZE_KB = 10 * 1024 # 10MB old default
|
||||
for k, v in sorted(szs.items(), key=sort_key, reverse=True):
|
||||
avg = v['sum'] / v['count']
|
||||
service = SERVICE_LIST.get(k, None)
|
||||
freq_val = service.frequency if service else 0.0
|
||||
queue_size_kb = (service.queue_size / 1024) if service else 250 # default to SMALL
|
||||
kb_per_min = (avg * freq_val * 60) / 1024 if freq_val > 0 else 0.0
|
||||
kb_per_sec = kb_per_min / 60
|
||||
minutes_in_buffer = RINGBUFFER_SIZE_KB / kb_per_min if kb_per_min > 0 else float('inf')
|
||||
seconds_in_queue = (queue_size_kb / kb_per_sec) if kb_per_sec > 0 else float('inf')
|
||||
total_kb_per_min += kb_per_min
|
||||
min_str = f"{minutes_in_buffer:.2f}" if minutes_in_buffer != float('inf') else "inf"
|
||||
sec_queue_str = f"{seconds_in_queue:.2f}" if seconds_in_queue != float('inf') else "inf"
|
||||
print(f"{k:<36} {v['min']/1024:>12.2f} {v['max']/1024:>12.2f} {avg/1024:>12.2f} {kb_per_min:>12.2f} {kb_per_sec:>12.2f} {min_str:>18} {sec_queue_str:>18}")
|
||||
|
||||
# Summary section
|
||||
print()
|
||||
print(f"Total usage: {total_kb_per_min / 1024:.2f} MB/min")
|
||||
|
||||
# Calculate memory usage: old (10MB for all) vs new (from services.py)
|
||||
OLD_SIZE = 10 * 1024 * 1024 # 10MB was the old default
|
||||
old_total = len(SERVICE_LIST) * OLD_SIZE
|
||||
|
||||
new_total = sum(s.queue_size for s in SERVICE_LIST.values())
|
||||
|
||||
# Count by queue size
|
||||
size_counts = {QueueSize.BIG: 0, QueueSize.MEDIUM: 0, QueueSize.SMALL: 0}
|
||||
for s in SERVICE_LIST.values():
|
||||
size_counts[s.queue_size] += 1
|
||||
|
||||
savings_pct = (1 - new_total / old_total) * 100
|
||||
|
||||
print()
|
||||
print(f"{'Queue Size Comparison':<40}")
|
||||
print("-" * 60)
|
||||
print(f"{'Old (10MB default):':<30} {old_total / 1024 / 1024:>10.2f} MB")
|
||||
print(f"{'New (from services.py):':<30} {new_total / 1024 / 1024:>10.2f} MB")
|
||||
print(f"{'Savings:':<30} {savings_pct:>10.1f}%")
|
||||
print()
|
||||
print(f"{'Breakdown:':<30}")
|
||||
print(f" BIG (10MB): {size_counts[QueueSize.BIG]:>3} services")
|
||||
print(f" MEDIUM (2MB): {size_counts[QueueSize.MEDIUM]:>3} services")
|
||||
print(f" SMALL (250KB): {size_counts[QueueSize.SMALL]:>3} services")
|
||||
35
iqpilot/tools/iqperf/check_can_parser_performance.py
Executable file
35
iqpilot/tools/iqperf/check_can_parser_performance.py
Executable file
@@ -0,0 +1,35 @@
|
||||
#!/usr/bin/env python3
|
||||
import numpy as np
|
||||
import time
|
||||
from tqdm import tqdm
|
||||
|
||||
from iqpilot.cereal import car
|
||||
from iqdbc.car.tests.routes import CarTestRoute
|
||||
from iqpilot.selfdrive.car.tests.test_models import TestCarModelBase
|
||||
N_RUNS = 10
|
||||
DEMO_ROUTE = "a2a0ccea32023010|2023-07-27--13-01-19"
|
||||
|
||||
|
||||
class CarModelTestCase(TestCarModelBase):
|
||||
test_route = CarTestRoute(DEMO_ROUTE, None)
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
# Get CAN messages and parsers
|
||||
tm = CarModelTestCase()
|
||||
tm.setUpClass()
|
||||
tm.setUp()
|
||||
|
||||
CC = car.CarControl.new_message()
|
||||
ets = []
|
||||
for _ in tqdm(range(N_RUNS)):
|
||||
start_t = time.process_time_ns()
|
||||
for msg in tm.can_msgs:
|
||||
for cp in tm.CI.can_parsers.values():
|
||||
if cp is not None:
|
||||
cp.update_strings(msg)
|
||||
ets.append((time.process_time_ns() - start_t) * 1e-6)
|
||||
|
||||
print(f'{len(tm.can_msgs)} CAN packets, {N_RUNS} runs')
|
||||
print(f'{np.mean(ets):.2f} mean ms, {max(ets):.2f} max ms, {min(ets):.2f} min ms, {np.std(ets):.2f} std ms')
|
||||
print(f'{np.mean(ets) / len(tm.can_msgs):.4f} mean ms / CAN packet')
|
||||
50
iqpilot/tools/iqperf/check_freq.py
Executable file
50
iqpilot/tools/iqperf/check_freq.py
Executable file
@@ -0,0 +1,50 @@
|
||||
#!/usr/bin/env python3
|
||||
import argparse
|
||||
import numpy as np
|
||||
import time
|
||||
from collections import defaultdict, deque
|
||||
from collections.abc import MutableSequence
|
||||
|
||||
import iqpilot.cereal.messaging as messaging
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
context = messaging.Context()
|
||||
poller = messaging.Poller()
|
||||
|
||||
parser = argparse.ArgumentParser()
|
||||
parser.add_argument("socket", type=str, nargs='*', help="socket name")
|
||||
args = parser.parse_args()
|
||||
|
||||
socket_names = args.socket
|
||||
sockets = {}
|
||||
|
||||
rcv_times: defaultdict[str, MutableSequence[float]] = defaultdict(lambda: deque(maxlen=100))
|
||||
valids: defaultdict[str, deque[bool]] = defaultdict(lambda: deque(maxlen=100))
|
||||
|
||||
t = time.monotonic()
|
||||
for name in socket_names:
|
||||
sock = messaging.sub_sock(name, poller=poller)
|
||||
sockets[sock] = name
|
||||
|
||||
prev_print = t
|
||||
while True:
|
||||
for socket in poller.poll(100):
|
||||
msg = messaging.recv_one(socket)
|
||||
if msg is None:
|
||||
continue
|
||||
|
||||
name = msg.which()
|
||||
|
||||
t = time.monotonic()
|
||||
rcv_times[name].append(msg.logMonoTime / 1e9)
|
||||
valids[name].append(msg.valid)
|
||||
|
||||
if t - prev_print > 1:
|
||||
print()
|
||||
for name in socket_names:
|
||||
dts = np.diff(rcv_times[name])
|
||||
mean = np.mean(dts)
|
||||
print(f"{name}: Freq {1.0 / mean:.2f} Hz, Min {np.min(dts) / mean * 100:.2f}%, Max {np.max(dts) / mean * 100:.2f}%, valid ", all(valids[name]))
|
||||
|
||||
prev_print = t
|
||||
27
iqpilot/tools/iqperf/check_lag.py
Executable file
27
iqpilot/tools/iqperf/check_lag.py
Executable file
@@ -0,0 +1,27 @@
|
||||
#!/usr/bin/env python3
|
||||
|
||||
import iqpilot.cereal.messaging as messaging
|
||||
from iqpilot.cereal.services import SERVICE_LIST
|
||||
|
||||
TO_CHECK = ['carState']
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
sm = messaging.SubMaster(TO_CHECK)
|
||||
|
||||
prev_t: dict[str, float] = {}
|
||||
|
||||
while True:
|
||||
sm.update()
|
||||
|
||||
for s in TO_CHECK:
|
||||
if sm.updated[s]:
|
||||
t = sm.logMonoTime[s] / 1e9
|
||||
|
||||
if s in prev_t:
|
||||
expected = 1.0 / (SERVICE_LIST[s].frequency)
|
||||
dt = t - prev_t[s]
|
||||
if dt > 10 * expected:
|
||||
print(t, s, dt)
|
||||
|
||||
prev_t[s] = t
|
||||
36
iqpilot/tools/iqperf/check_timings.py
Executable file
36
iqpilot/tools/iqperf/check_timings.py
Executable file
@@ -0,0 +1,36 @@
|
||||
#!/usr/bin/env python3
|
||||
import sys
|
||||
import time
|
||||
import numpy as np
|
||||
import datetime
|
||||
from collections.abc import MutableSequence
|
||||
from collections import defaultdict
|
||||
|
||||
import iqpilot.cereal.messaging as messaging
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
ts: defaultdict[str, MutableSequence[float]] = defaultdict(list)
|
||||
socks = {s: messaging.sub_sock(s, conflate=False) for s in sys.argv[1:]}
|
||||
try:
|
||||
st = time.monotonic()
|
||||
while True:
|
||||
print()
|
||||
for s, sock in socks.items():
|
||||
msgs = messaging.drain_sock(sock)
|
||||
for m in msgs:
|
||||
ts[s].append(m.logMonoTime / 1e6)
|
||||
|
||||
if len(ts[s]) > 2:
|
||||
d = np.diff(ts[s])[-100:]
|
||||
print(f"{s:25} {np.mean(d):7.2f} {np.std(d):7.2f} {np.max(d):7.2f} {np.min(d):7.2f}")
|
||||
time.sleep(1)
|
||||
except KeyboardInterrupt:
|
||||
print("\n")
|
||||
print("="*5, "timing summary", "="*5)
|
||||
for s, sock in socks.items():
|
||||
msgs = messaging.drain_sock(sock)
|
||||
if len(ts[s]) > 2:
|
||||
d = np.diff(ts[s])
|
||||
print(f"{s:25} {np.mean(d):7.2f} {np.std(d):7.2f} {np.max(d):7.2f} {np.min(d):7.2f}")
|
||||
print("="*5, datetime.timedelta(seconds=time.monotonic()-st), "="*5)
|
||||
120
iqpilot/tools/iqperf/cpu_usage_stat.py
Executable file
120
iqpilot/tools/iqperf/cpu_usage_stat.py
Executable file
@@ -0,0 +1,120 @@
|
||||
#!/usr/bin/env python3
|
||||
'''
|
||||
System tools like top/htop can only show current cpu usage values, so I write this script to do statistics jobs.
|
||||
Features:
|
||||
Use psutil library to sample cpu usage(avergage for all cores) of openpilot processes, at a rate of 5 samples/sec.
|
||||
Do cpu usage statistics periodically, 5 seconds as a cycle.
|
||||
Calculate the average cpu usage within this cycle.
|
||||
Calculate minumium/maximum/accumulated_average cpu usage as long term inspections.
|
||||
Monitor multiple processes simuteneously.
|
||||
Sample usage:
|
||||
root@localhost:/data/openpilot$ python iqpilot/tools/iqperf/cpu_usage_stat.py pandad,ubloxd
|
||||
('Add monitored proc:', './pandad')
|
||||
('Add monitored proc:', 'python locationd/ubloxd.py')
|
||||
pandad: 1.96%, min: 1.96%, max: 1.96%, acc: 1.96%
|
||||
ubloxd.py: 0.39%, min: 0.39%, max: 0.39%, acc: 0.39%
|
||||
'''
|
||||
import psutil
|
||||
import time
|
||||
import os
|
||||
import sys
|
||||
import numpy as np
|
||||
import argparse
|
||||
import re
|
||||
from collections import defaultdict
|
||||
|
||||
from iqpilot.system.manager.process_config import managed_processes
|
||||
|
||||
# Do statistics every 5 seconds
|
||||
PRINT_INTERVAL = 5
|
||||
SLEEP_INTERVAL = 0.2
|
||||
|
||||
monitored_proc_names = [
|
||||
# android procs
|
||||
'SurfaceFlinger', 'sensors.qcom'
|
||||
] + list(managed_processes.keys())
|
||||
|
||||
cpu_time_names = ['user', 'system', 'children_user', 'children_system']
|
||||
|
||||
|
||||
def get_arg_parser():
|
||||
parser = argparse.ArgumentParser(formatter_class=argparse.ArgumentDefaultsHelpFormatter)
|
||||
|
||||
parser.add_argument("proc_names", nargs="?", default='',
|
||||
help="Process names to be monitored, comma separated")
|
||||
parser.add_argument("--list_all", action='store_true',
|
||||
help="Show all running processes' cmdline")
|
||||
parser.add_argument("--detailed_times", action='store_true',
|
||||
help="show cpu time details (split by user, system, child user, child system)")
|
||||
return parser
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
args = get_arg_parser().parse_args(sys.argv[1:])
|
||||
if args.list_all:
|
||||
for p in psutil.process_iter():
|
||||
print('cmdline', p.cmdline(), 'name', p.name())
|
||||
sys.exit(0)
|
||||
|
||||
if len(args.proc_names) > 0:
|
||||
monitored_proc_names = args.proc_names.split(',')
|
||||
monitored_procs = []
|
||||
stats = {}
|
||||
for p in psutil.process_iter():
|
||||
if p == psutil.Process():
|
||||
continue
|
||||
matched = any(l for l in p.cmdline() if any(pn for pn in monitored_proc_names if re.match(fr'.*{pn}.*', l, re.M | re.I)))
|
||||
if matched:
|
||||
k = ' '.join(p.cmdline())
|
||||
print('Add monitored proc:', k)
|
||||
stats[k] = {'cpu_samples': defaultdict(list), 'min': defaultdict(lambda: None), 'max': defaultdict(lambda: None),
|
||||
'avg': defaultdict(float), 'last_cpu_times': None, 'last_sys_time': None}
|
||||
stats[k]['last_sys_time'] = time.monotonic()
|
||||
stats[k]['last_cpu_times'] = p.cpu_times()
|
||||
monitored_procs.append(p)
|
||||
i = 0
|
||||
interval_int = int(PRINT_INTERVAL / SLEEP_INTERVAL)
|
||||
while True:
|
||||
for p in monitored_procs:
|
||||
k = ' '.join(p.cmdline())
|
||||
cur_sys_time = time.monotonic()
|
||||
cur_cpu_times = p.cpu_times()
|
||||
cpu_times = np.subtract(cur_cpu_times, stats[k]['last_cpu_times']) / (cur_sys_time - stats[k]['last_sys_time'])
|
||||
stats[k]['last_sys_time'] = cur_sys_time
|
||||
stats[k]['last_cpu_times'] = cur_cpu_times
|
||||
cpu_percent = 0
|
||||
for num, name in enumerate(cpu_time_names):
|
||||
stats[k]['cpu_samples'][name].append(cpu_times[num])
|
||||
cpu_percent += cpu_times[num]
|
||||
stats[k]['cpu_samples']['total'].append(cpu_percent)
|
||||
time.sleep(SLEEP_INTERVAL)
|
||||
i += 1
|
||||
if i % interval_int == 0:
|
||||
l = []
|
||||
for k, stat in stats.items():
|
||||
if len(stat['cpu_samples']) <= 0:
|
||||
continue
|
||||
for name, samples in stat['cpu_samples'].items():
|
||||
samples = np.array(samples)
|
||||
avg = samples.mean()
|
||||
c = samples.size
|
||||
min_cpu = np.amin(samples)
|
||||
max_cpu = np.amax(samples)
|
||||
if stat['min'][name] is None or min_cpu < stat['min'][name]:
|
||||
stat['min'][name] = min_cpu
|
||||
if stat['max'][name] is None or max_cpu > stat['max'][name]:
|
||||
stat['max'][name] = max_cpu
|
||||
stat['avg'][name] = (stat['avg'][name] * (i - c) + avg * c) / (i)
|
||||
stat['cpu_samples'][name] = []
|
||||
|
||||
msg = f"avg: {stat['avg']['total']:.2%}, min: {stat['min']['total']:.2%}, max: {stat['max']['total']:.2%} {os.path.basename(k)}"
|
||||
if args.detailed_times:
|
||||
for stat_type in ['avg', 'min', 'max']:
|
||||
msg += f"\n {stat_type}: {[(name + ':' + str(round(stat[stat_type][name] * 100, 2))) for name in cpu_time_names]}"
|
||||
l.append((os.path.basename(k), stat['avg']['total'], msg))
|
||||
l.sort(key=lambda x: -x[1])
|
||||
for x in l:
|
||||
print(x[2])
|
||||
print('avg sum: {:.2%} over {} samples {} seconds\n'.format(
|
||||
sum(stat['avg']['total'] for k, stat in stats.items()), i, i * SLEEP_INTERVAL
|
||||
))
|
||||
223
iqpilot/tools/iqperf/io_stall_repro.py
Executable file
223
iqpilot/tools/iqperf/io_stall_repro.py
Executable file
@@ -0,0 +1,223 @@
|
||||
#!/usr/bin/env python3
|
||||
"""
|
||||
io_stall_repro.py — bench reproduction + fix-validation rig for the VW PQ EPS
|
||||
HCA fault (control loop stalling on a /data read under eMMC write saturation).
|
||||
|
||||
The real fault chain (proven from rlog b29ee8c5a0a735d1/000000e4--8a8ba97b54):
|
||||
loggerd buffered writes saturate eMMC -> ext4 jbd2 journal commits ->
|
||||
controlsd's inline Params.get (util::read_file on /data) blocks ~300-630ms ->
|
||||
controlsd stops publishing carControl -> card's all_alive guard withholds
|
||||
HCA_1 -> EPS LH2_Sta_HCA 7->2.
|
||||
|
||||
This reproduces the *proximate* cause WITHOUT driving, WITHOUT the EPS, and
|
||||
WITHOUT touching the real control stack. Two roles:
|
||||
|
||||
--writer : emulate loggerd. Buffered (no-fsync) writes to /data at a target
|
||||
MB/s, with an optional periodic big flush to mimic 60s segment
|
||||
rotation. This is what saturates the eMMC.
|
||||
|
||||
--probe : emulate controlsd's I/O exposure. A 100Hz loop that every
|
||||
--param-period seconds reads a real param (util::read_file on
|
||||
/data). It records per-iteration loop gaps and param-read
|
||||
durations. A 300ms gap here == the stall that drops HCA.
|
||||
--threaded moves the param read to a background thread (the
|
||||
proposed fix, mirroring card.py's params_thread) so you can A/B it.
|
||||
|
||||
USAGE (run parked, ignition on, on the device):
|
||||
# 1) baseline: probe alone -> gaps should be tiny
|
||||
python3 io_stall_repro.py --probe --secs 120
|
||||
|
||||
# 2) reproduce: writer in one shell, probe in another
|
||||
python3 io_stall_repro.py --writer --mbps 25 --rotate 60
|
||||
python3 io_stall_repro.py --probe --secs 180 # expect big gaps
|
||||
|
||||
# 3) validate fix A (params off control thread):
|
||||
python3 io_stall_repro.py --probe --secs 180 --threaded # gaps should vanish
|
||||
|
||||
# 4) validate fix B (smoother writeback) — set before step 2, as root:
|
||||
# echo 5 > /proc/sys/vm/dirty_background_ratio
|
||||
# echo 10 > /proc/sys/vm/dirty_ratio
|
||||
# then re-run step 2 inline probe and compare gap distribution.
|
||||
|
||||
Cleanup: writer deletes its scratch files on exit. Read-only wrt openpilot.
|
||||
"""
|
||||
|
||||
import argparse
|
||||
import os
|
||||
import sys
|
||||
import time
|
||||
import threading
|
||||
import signal
|
||||
|
||||
SCRATCH_DEFAULT = "/data/media/0/io_repro_scratch"
|
||||
|
||||
|
||||
# ----------------------------------------------------------------------------- writer
|
||||
def run_writer(args):
|
||||
os.makedirs(args.scratch, exist_ok=True)
|
||||
chunk = os.urandom(1 << 20) # 1 MiB
|
||||
bytes_per_s = int(args.mbps * (1 << 20))
|
||||
print(f"[writer] buffered no-fsync writes to {args.scratch} at ~{args.mbps} MB/s, rotate every {args.rotate}s (big flush). Ctrl-C to stop.", file=sys.stderr)
|
||||
|
||||
stop = {"v": False}
|
||||
signal.signal(signal.SIGINT, lambda *_: stop.update(v=True))
|
||||
signal.signal(signal.SIGTERM, lambda *_: stop.update(v=True))
|
||||
|
||||
files = []
|
||||
seg = 0
|
||||
try:
|
||||
while not stop["v"]:
|
||||
seg_start = time.monotonic()
|
||||
path = os.path.join(args.scratch, f"seg_{seg}.bin")
|
||||
f = open(path, "wb", buffering=1 << 20)
|
||||
files.append(path)
|
||||
written = 0
|
||||
# write at target rate using buffered fwrite, NO fsync (exactly loggerd)
|
||||
while not stop["v"] and (time.monotonic() - seg_start) < args.rotate:
|
||||
f.write(chunk)
|
||||
written += len(chunk)
|
||||
# pace to target MB/s
|
||||
target_t = written / bytes_per_s
|
||||
elapsed = time.monotonic() - seg_start
|
||||
if target_t > elapsed:
|
||||
time.sleep(min(0.1, target_t - elapsed))
|
||||
# "segment rotation": flush+close a big buffered file at once -> writeback burst
|
||||
f.flush()
|
||||
f.close()
|
||||
seg += 1
|
||||
# keep only a few recent files so we don't fill the disk
|
||||
while len(files) > 3:
|
||||
old = files.pop(0)
|
||||
try:
|
||||
os.remove(old)
|
||||
except OSError:
|
||||
pass
|
||||
finally:
|
||||
for p in files:
|
||||
try:
|
||||
os.remove(p)
|
||||
except OSError:
|
||||
pass
|
||||
print("[writer] stopped, scratch cleaned.", file=sys.stderr)
|
||||
|
||||
|
||||
# ----------------------------------------------------------------------------- probe
|
||||
def _get_param(key):
|
||||
# real /data read, same syscall path as controlsd's get_params_iq
|
||||
try:
|
||||
from iqpilot.common.params import Params
|
||||
|
||||
return Params().get_bool(key)
|
||||
except Exception:
|
||||
# fallback: plain file read of a param file if openpilot import unavailable
|
||||
p = os.path.join(os.getenv("PARAMS_ROOT", "/data/params"), "d", key)
|
||||
try:
|
||||
with open(p, "rb") as fh:
|
||||
return fh.read()
|
||||
except OSError:
|
||||
return None
|
||||
|
||||
|
||||
class ThreadedParam:
|
||||
"""Mirror card.py params_thread: refresh the param on a bg thread, control
|
||||
loop reads the cached value (non-blocking)."""
|
||||
|
||||
def __init__(self, key, period):
|
||||
self.key = key
|
||||
self.period = period
|
||||
self.val = None
|
||||
self.stop = False
|
||||
self.t = threading.Thread(target=self._loop, daemon=True)
|
||||
self.t.start()
|
||||
|
||||
def _loop(self):
|
||||
while not self.stop:
|
||||
self.val = _get_param(self.key)
|
||||
time.sleep(self.period)
|
||||
|
||||
def read(self): # O(1), no I/O on the control thread
|
||||
return self.val
|
||||
|
||||
|
||||
def run_probe(args):
|
||||
# pin like controlsd (core 4) so we share the same iowait domain if possible
|
||||
try:
|
||||
os.sched_setaffinity(0, {args.core})
|
||||
except (OSError, AttributeError):
|
||||
pass
|
||||
|
||||
interval = 0.01 # 100Hz, like the control loop
|
||||
gaps = [] # ms, per-iteration loop overrun beyond 10ms
|
||||
read_ms = [] # ms, time spent in the param read on the control thread
|
||||
worst = 0.0
|
||||
threaded = ThreadedParam(args.param_key, args.param_period) if args.threaded else None
|
||||
|
||||
print(
|
||||
f"[probe] 100Hz loop for {args.secs}s, param '{args.param_key}' every {args.param_period}s, threaded={args.threaded}, core={args.core}", file=sys.stderr
|
||||
)
|
||||
t_end = time.monotonic() + args.secs
|
||||
next_t = time.monotonic()
|
||||
last_param = 0.0
|
||||
while time.monotonic() < t_end:
|
||||
loop_start = time.monotonic()
|
||||
|
||||
# the I/O exposure: read param on the control thread (inline) every period
|
||||
if loop_start - last_param >= args.param_period:
|
||||
r0 = time.monotonic()
|
||||
if threaded is not None:
|
||||
_ = threaded.read() # cached, no I/O on this thread (the FIX)
|
||||
else:
|
||||
_ = _get_param(args.param_key) # inline /data read (current behavior)
|
||||
dr = (time.monotonic() - r0) * 1000
|
||||
read_ms.append(dr)
|
||||
last_param = loop_start
|
||||
|
||||
# measure scheduling/lag: how late did this iteration actually fire?
|
||||
next_t += interval
|
||||
lag = (time.monotonic() - next_t) * 1000 # ms behind schedule
|
||||
if lag > 5:
|
||||
gaps.append(lag)
|
||||
worst = max(worst, lag)
|
||||
sleep = next_t - time.monotonic()
|
||||
if sleep > 0:
|
||||
time.sleep(sleep)
|
||||
else:
|
||||
next_t = time.monotonic() # don't spiral after a big stall
|
||||
|
||||
if threaded:
|
||||
threaded.stop = True
|
||||
|
||||
def pct(xs, p):
|
||||
return sorted(xs)[int(p / 100 * (len(xs) - 1))] if xs else 0.0
|
||||
|
||||
print("\n================ PROBE RESULT ================")
|
||||
print(f"loop-lag events >5ms : {len(gaps)}")
|
||||
print(f"loop-lag p50/p99/max : {pct(gaps, 50):.0f} / {pct(gaps, 99):.0f} / {worst:.0f} ms")
|
||||
print(f"param-read p50/p99/max: {pct(read_ms, 50):.1f} / {pct(read_ms, 99):.1f} / {max(read_ms + [0]):.1f} ms (n={len(read_ms)})")
|
||||
hca_class = max(gaps + [0])
|
||||
verdict = "FAULT-CLASS STALL REPRODUCED (>250ms -> would drop HCA)" if hca_class > 250 else "marginal (100-250ms)" if hca_class > 100 else "clean (<100ms)"
|
||||
print(f"VERDICT: {verdict}")
|
||||
print("=============================================")
|
||||
|
||||
|
||||
# ----------------------------------------------------------------------------- main
|
||||
def main():
|
||||
ap = argparse.ArgumentParser()
|
||||
ap.add_argument("--writer", action="store_true", help="emulate loggerd eMMC saturation")
|
||||
ap.add_argument("--probe", action="store_true", help="emulate controlsd I/O exposure")
|
||||
ap.add_argument("--mbps", type=float, default=25.0, help="writer target MB/s (loggerd ~10-30)")
|
||||
ap.add_argument("--rotate", type=float, default=60.0, help="writer segment/flush period s")
|
||||
ap.add_argument("--scratch", default=SCRATCH_DEFAULT)
|
||||
ap.add_argument("--secs", type=float, default=180.0, help="probe duration s")
|
||||
ap.add_argument("--param-key", default="IsMetric", help="a real param key to read")
|
||||
ap.add_argument("--param-period", type=float, default=3.0, help="controlsd reads every 3s")
|
||||
ap.add_argument("--threaded", action="store_true", help="probe: read param off control thread (the FIX)")
|
||||
ap.add_argument("--core", type=int, default=4, help="probe cpu affinity (control core)")
|
||||
args = ap.parse_args()
|
||||
if args.writer == args.probe:
|
||||
ap.error("pick exactly one of --writer / --probe (run them in separate shells)")
|
||||
run_writer(args) if args.writer else run_probe(args)
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
main()
|
||||
268
iqpilot/tools/iqperf/io_stall_tracer.py
Executable file
268
iqpilot/tools/iqperf/io_stall_tracer.py
Executable file
@@ -0,0 +1,268 @@
|
||||
#!/usr/bin/env python3
|
||||
"""
|
||||
io_stall_tracer.py — continuous low-overhead per-process disk-I/O tracer.
|
||||
|
||||
WHY: the VW PQ EPS HCA faults are caused by a control process (controlsd/card)
|
||||
blocking ~300-630ms in disk I/O (iowait) on /data, which stops HCA_1 TX. The
|
||||
stall is far too short to catch with a manual `iostat`/`iotop` run. This sampler
|
||||
runs for the whole drive at 100ms cadence and records, per process:
|
||||
|
||||
- write_bytes (/proc/<pid>/io) -> identifies the WRITER saturating eMMC
|
||||
- delayacct_blkio (/proc/<pid>/stat) -> per-process cumulative block-I/O wait
|
||||
- state (/proc/<pid>/stat) -> catches 'D' (uninterruptible disk wait)
|
||||
|
||||
plus whole-device /proc/diskstats. After a fault, find the wall-clock time of the
|
||||
LH2_Sta_HCA->2 event (from the rlog) and look at the rows around it: the process
|
||||
whose write_bytes delta spikes is the bully; the control process whose blkio
|
||||
delta jumps / state == 'D' is the victim.
|
||||
|
||||
Deploy: copy to the device, run alongside openpilot during a drive:
|
||||
python3 io_stall_tracer.py --out /data/media/0/io_trace.csv
|
||||
Overhead: reading /proc for ~40 procs every 100ms is well under 1% of one core,
|
||||
and it pins itself to CPU 0 (away from the control cores 4/5) at low priority.
|
||||
|
||||
Read-only. Writes a single CSV. No openpilot deps.
|
||||
"""
|
||||
|
||||
import argparse
|
||||
import os
|
||||
import time
|
||||
import glob
|
||||
import sys
|
||||
|
||||
CLK_TCK = os.sysconf("SC_CLK_TCK") # usually 100 -> blkio ticks are 10ms each
|
||||
|
||||
|
||||
def read_proc_io(pid):
|
||||
# wchar/rchar = bytes moved via read()/write() syscalls (catches BUFFERED writers
|
||||
# like loggerd, which never appear in write_bytes because the kernel flushes their
|
||||
# page-cache dirty pages asynchronously via kworker). write_bytes = bytes actually
|
||||
# sent to the block device. Track both.
|
||||
try:
|
||||
with open(f"/proc/{pid}/io") as f:
|
||||
d = {}
|
||||
for line in f:
|
||||
k, _, v = line.partition(":")
|
||||
d[k] = int(v)
|
||||
return (d.get("wchar", 0), d.get("rchar", 0), d.get("write_bytes", 0), d.get("read_bytes", 0))
|
||||
except (OSError, ValueError):
|
||||
return None
|
||||
|
||||
|
||||
def read_proc_stat(pid):
|
||||
# state is field 3; delayacct_blkio_ticks is field 42 (1-indexed). comm may
|
||||
# contain spaces/parens, so split on the last ')'.
|
||||
try:
|
||||
with open(f"/proc/{pid}/stat") as f:
|
||||
data = f.read()
|
||||
rparen = data.rfind(")")
|
||||
comm = data[data.find("(") + 1 : rparen]
|
||||
rest = data[rparen + 2 :].split()
|
||||
state = rest[0] # field 3
|
||||
blkio_ticks = int(rest[39]) if len(rest) > 39 else 0 # field 42
|
||||
return comm, state, blkio_ticks
|
||||
except (OSError, ValueError, IndexError):
|
||||
return None
|
||||
|
||||
|
||||
def read_diskstats():
|
||||
# returns {dev: (sectors_written, ms_doing_io)} for whole-disk devices
|
||||
out = {}
|
||||
try:
|
||||
with open("/proc/diskstats") as f:
|
||||
for line in f:
|
||||
p = line.split()
|
||||
if len(p) < 14:
|
||||
continue
|
||||
dev = p[2]
|
||||
# field 10 (idx 9) = sectors written; field 13 (idx 12) = ms doing I/O
|
||||
out[dev] = (int(p[9]), int(p[12]))
|
||||
except (OSError, AttributeError):
|
||||
pass
|
||||
return out
|
||||
|
||||
|
||||
# These counters tell us WHICH kernel mechanism caused a stall, which decides
|
||||
# the fix: compact_stall jumping -> memory compaction (texture-pool fix);
|
||||
# allocstall/pgsteal jumping -> direct reclaim; high nr_dirty/nr_writeback ->
|
||||
# loggerd writeback bomb (loggerd sync_file_range fix). meminfo Dirty/Writeback
|
||||
# are absolute kB; vmstat ones are cumulative event counts (we delta them).
|
||||
VMSTAT_KEYS = (
|
||||
"compact_stall",
|
||||
"compact_fail",
|
||||
"allocstall_normal",
|
||||
"allocstall_movable",
|
||||
"pgsteal_direct",
|
||||
"pgscan_direct",
|
||||
"pgmajfault",
|
||||
"nr_dirty",
|
||||
"nr_writeback",
|
||||
)
|
||||
MEMINFO_KEYS = ("MemFree", "MemAvailable", "Dirty", "Writeback")
|
||||
|
||||
|
||||
def read_vmstat():
|
||||
out = {}
|
||||
try:
|
||||
with open("/proc/vmstat") as f:
|
||||
for line in f:
|
||||
k, _, v = line.partition(" ")
|
||||
if k in VMSTAT_KEYS:
|
||||
out[k] = int(v)
|
||||
except OSError:
|
||||
pass
|
||||
return out
|
||||
|
||||
|
||||
def read_meminfo():
|
||||
out = {}
|
||||
try:
|
||||
with open("/proc/meminfo") as f:
|
||||
for line in f:
|
||||
k, _, v = line.partition(":")
|
||||
if k in MEMINFO_KEYS:
|
||||
out[k] = int(v.split()[0]) # kB
|
||||
except (OSError, IndexError):
|
||||
pass
|
||||
return out
|
||||
|
||||
|
||||
def main():
|
||||
ap = argparse.ArgumentParser()
|
||||
ap.add_argument("--out", default="/data/media/0/io_trace.csv")
|
||||
ap.add_argument("--hz", type=float, default=10.0, help="sample rate (default 10Hz/100ms)")
|
||||
ap.add_argument("--disk", default="sda", help="comma-separated disk devices to track (default sda)")
|
||||
ap.add_argument(
|
||||
"--names",
|
||||
default="controlsd,car.c,selfd,ui,loggerd,encoderd,modeld,camerad,locationd,estimatord,navd,mapd",
|
||||
help="substring match of process comm to record (others summed as 'other')",
|
||||
)
|
||||
args = ap.parse_args()
|
||||
|
||||
# be a good citizen: low priority, off the control cores
|
||||
try:
|
||||
os.nice(10)
|
||||
os.sched_setaffinity(0, {0})
|
||||
except OSError:
|
||||
pass
|
||||
|
||||
watch = [n.strip() for n in args.names.split(",") if n.strip()]
|
||||
disks = [d.strip() for d in args.disk.split(",") if d.strip()]
|
||||
interval = 1.0 / args.hz
|
||||
|
||||
prev_io = {} # pid -> (wchar, rchar, write_bytes, read_bytes)
|
||||
prev_blkio = {} # pid -> blkio_ticks
|
||||
prev_disk = read_diskstats()
|
||||
prev_vm = read_vmstat()
|
||||
|
||||
f = open(args.out, "w", buffering=1)
|
||||
# per-proc rows fill the first block; one SYS row per tick fills the trailing
|
||||
# mechanism columns (deltas for the vmstat counts, absolute kB for meminfo).
|
||||
columns = [
|
||||
"wall",
|
||||
"mono",
|
||||
"proc",
|
||||
"pid",
|
||||
"state",
|
||||
"d_wchar_kB",
|
||||
"d_wbytes_kB",
|
||||
"d_blkio_ms",
|
||||
"disk_d_write_kB",
|
||||
"disk_d_busy_ms",
|
||||
"compact_stall",
|
||||
"allocstall",
|
||||
"pgmajfault",
|
||||
"dirty_kB",
|
||||
"writeback_kB",
|
||||
"memfree_kB",
|
||||
"memavail_kB",
|
||||
]
|
||||
f.write(",".join(columns) + "\n")
|
||||
print(f"[io_stall_tracer] writing {args.out} at {args.hz}Hz, tracking {watch}", file=sys.stderr)
|
||||
|
||||
while True:
|
||||
t_wall = time.time()
|
||||
t_mono = time.monotonic()
|
||||
|
||||
# whole-disk delta (write kB + busy ms) for the named disks
|
||||
disk = read_diskstats()
|
||||
disk_dw = disk_db = 0
|
||||
for dev in disks:
|
||||
if dev in disk and dev in prev_disk:
|
||||
disk_dw += (disk[dev][0] - prev_disk[dev][0]) * 512 / 1024.0 # sectors->kB
|
||||
disk_db += disk[dev][1] - prev_disk[dev][1]
|
||||
prev_disk = disk
|
||||
|
||||
seen = set()
|
||||
rows = []
|
||||
for path in glob.glob("/proc/[0-9]*"):
|
||||
pid = path.rsplit("/", 1)[1]
|
||||
st = read_proc_stat(pid)
|
||||
if st is None:
|
||||
continue
|
||||
comm, state, blkio = st
|
||||
label = next((w for w in watch if w in comm), None)
|
||||
if label is None:
|
||||
# still track D-state of anything to catch surprise writers/blockers
|
||||
if state != "D":
|
||||
continue
|
||||
label = comm
|
||||
io = read_proc_io(pid)
|
||||
if io is None:
|
||||
continue
|
||||
wchar, rchar, wbytes, rbytes = io
|
||||
pw = prev_io.get(pid, io)
|
||||
pblk = prev_blkio.get(pid, blkio)
|
||||
d_wchar = (wchar - pw[0]) / 1024.0 # syscall write volume (catches loggerd)
|
||||
d_wbytes = (wbytes - pw[2]) / 1024.0 # bytes hitting the block device
|
||||
d_blk = (blkio - pblk) * (1000.0 / CLK_TCK) # ticks -> ms blocked on block I/O
|
||||
prev_io[pid] = io
|
||||
prev_blkio[pid] = blkio
|
||||
seen.add(pid)
|
||||
# only emit rows that carry signal (writing, blocked, or in D) to keep file small
|
||||
if d_wchar > 4 or d_wbytes > 4 or d_blk > 5 or state == "D":
|
||||
rows.append((label, pid, state, d_wchar, d_wbytes, d_blk))
|
||||
|
||||
# drop dead pids from prev maps occasionally
|
||||
if len(prev_io) > 4000:
|
||||
prev_io = {p: v for p, v in prev_io.items() if p in seen}
|
||||
prev_blkio = {p: v for p, v in prev_blkio.items() if p in seen}
|
||||
|
||||
for label, pid, state, d_wchar, d_wbytes, d_blk in rows:
|
||||
f.write(f"{t_wall:.3f},{t_mono:.3f},{label},{pid},{state},{d_wchar:.0f},{d_wbytes:.0f},{d_blk:.0f},{disk_dw:.0f},{disk_db:.0f},,,,,,,\n")
|
||||
|
||||
# one SYS row per tick: the kernel-mechanism counters (compaction vs reclaim
|
||||
# vs writeback). Compare these against the stall's wall-clock to see which
|
||||
# one spiked.
|
||||
vm = read_vmstat()
|
||||
mi = read_meminfo()
|
||||
d_compact = vm.get("compact_stall", 0) - prev_vm.get("compact_stall", 0)
|
||||
d_alloc = (vm.get("allocstall_normal", 0) + vm.get("allocstall_movable", 0)) - (prev_vm.get("allocstall_normal", 0) + prev_vm.get("allocstall_movable", 0))
|
||||
d_majflt = vm.get("pgmajfault", 0) - prev_vm.get("pgmajfault", 0)
|
||||
prev_vm = vm
|
||||
values = [
|
||||
f"{t_wall:.3f}",
|
||||
f"{t_mono:.3f}",
|
||||
"SYS",
|
||||
"0",
|
||||
"-",
|
||||
"",
|
||||
"",
|
||||
"",
|
||||
"",
|
||||
"",
|
||||
str(d_compact),
|
||||
str(d_alloc),
|
||||
str(d_majflt),
|
||||
str(mi.get("Dirty", 0)),
|
||||
str(mi.get("Writeback", 0)),
|
||||
str(mi.get("MemFree", 0)),
|
||||
str(mi.get("MemAvailable", 0)),
|
||||
]
|
||||
f.write(",".join(values) + "\n")
|
||||
|
||||
time.sleep(max(0.0, interval - (time.monotonic() - t_mono)))
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
main()
|
||||
106
iqpilot/tools/iqperf/live_cpu_and_temp.py
Executable file
106
iqpilot/tools/iqperf/live_cpu_and_temp.py
Executable file
@@ -0,0 +1,106 @@
|
||||
#!/usr/bin/env python3
|
||||
import argparse
|
||||
import numpy as np
|
||||
import capnp
|
||||
from collections import defaultdict
|
||||
|
||||
from iqpilot.cereal.messaging import SubMaster
|
||||
|
||||
def cputime_total(ct):
|
||||
return ct.user + ct.nice + ct.system + ct.idle + ct.iowait + ct.irq + ct.softirq
|
||||
|
||||
|
||||
def cputime_busy(ct):
|
||||
return ct.user + ct.nice + ct.system + ct.irq + ct.softirq
|
||||
|
||||
|
||||
def proc_cputime_total(ct):
|
||||
return ct.cpuUser + ct.cpuSystem + ct.cpuChildrenUser + ct.cpuChildrenSystem
|
||||
|
||||
|
||||
def proc_name(proc):
|
||||
name = proc.name
|
||||
if len(proc.cmdline):
|
||||
name = proc.cmdline[0]
|
||||
if len(proc.exe):
|
||||
name = proc.exe + " - " + name
|
||||
|
||||
return name
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
parser = argparse.ArgumentParser()
|
||||
parser.add_argument('--mem', action='store_true')
|
||||
parser.add_argument('--cpu', action='store_true')
|
||||
args = parser.parse_args()
|
||||
|
||||
sm = SubMaster(['deviceState', 'procLog'])
|
||||
|
||||
last_temp = 0.0
|
||||
last_mem = 0.0
|
||||
total_times = [0.]*8
|
||||
busy_times = [0.]*8
|
||||
|
||||
prev_proclog: capnp._DynamicStructReader | None = None
|
||||
prev_proclog_t: int | None = None
|
||||
|
||||
while True:
|
||||
sm.update()
|
||||
|
||||
if sm.updated['deviceState']:
|
||||
t = sm['deviceState']
|
||||
last_temp = np.mean(t.cpuTempC)
|
||||
last_mem = t.memoryUsagePercent
|
||||
|
||||
if sm.updated['procLog']:
|
||||
m = sm['procLog']
|
||||
|
||||
cores = [0.]*8
|
||||
total_times_new = [0.]*8
|
||||
busy_times_new = [0.]*8
|
||||
|
||||
for c in m.cpuTimes:
|
||||
n = c.cpuNum
|
||||
total_times_new[n] = cputime_total(c)
|
||||
busy_times_new[n] = cputime_busy(c)
|
||||
|
||||
for n in range(8):
|
||||
t_busy = busy_times_new[n] - busy_times[n]
|
||||
t_total = total_times_new[n] - total_times[n]
|
||||
cores[n] = t_busy / t_total
|
||||
|
||||
total_times = total_times_new[:]
|
||||
busy_times = busy_times_new[:]
|
||||
|
||||
print(f"CPU {100.0 * np.mean(cores):.2f}% - RAM: {last_mem:.2f}% - Temp {last_temp:.2f}C")
|
||||
|
||||
if args.cpu and prev_proclog is not None and prev_proclog_t is not None:
|
||||
procs: dict[str, float] = defaultdict(float)
|
||||
dt = (sm.logMonoTime['procLog'] - prev_proclog_t) / 1e9
|
||||
for proc in m.procs:
|
||||
try:
|
||||
name = proc_name(proc)
|
||||
prev_proc = [p for p in prev_proclog.procs if proc.pid == p.pid][0]
|
||||
cpu_time = proc_cputime_total(proc) - proc_cputime_total(prev_proc)
|
||||
cpu_usage = cpu_time / dt * 100.
|
||||
procs[name] += cpu_usage
|
||||
except IndexError:
|
||||
pass
|
||||
|
||||
print("Top CPU usage:")
|
||||
for k, v in sorted(procs.items(), key=lambda item: item[1], reverse=True)[:10]:
|
||||
print(f"{k.rjust(70)} {v:.2f} %")
|
||||
print()
|
||||
|
||||
if args.mem:
|
||||
mems = {}
|
||||
for proc in m.procs:
|
||||
name = proc_name(proc)
|
||||
mems[name] = float(proc.memRss) / 1e6
|
||||
print("Top memory usage:")
|
||||
for k, v in sorted(mems.items(), key=lambda item: item[1], reverse=True)[:10]:
|
||||
print(f"{k.rjust(70)} {v:.2f} MB")
|
||||
print()
|
||||
|
||||
prev_proclog = m
|
||||
prev_proclog_t = sm.logMonoTime['procLog']
|
||||
131
iqpilot/tools/iqperf/max_lat_accel.py
Executable file
131
iqpilot/tools/iqperf/max_lat_accel.py
Executable file
@@ -0,0 +1,131 @@
|
||||
#!/usr/bin/env python3
|
||||
import argparse
|
||||
import numpy as np
|
||||
import matplotlib.pyplot as plt
|
||||
from functools import partial
|
||||
from tqdm import tqdm
|
||||
from typing import NamedTuple
|
||||
from iqpilot.tools.lib.logreader import LogReader
|
||||
from iqpilot.selfdrive.locationd.models.pose_kf import EARTH_G
|
||||
|
||||
RLOG_MIN_LAT_ACTIVE = 50
|
||||
RLOG_MIN_STEERING_UNPRESSED = 50
|
||||
RLOG_MIN_REQUESTING_MAX = 25 # sample many times after reaching max torque
|
||||
|
||||
QLOG_DECIMATION = 10
|
||||
|
||||
|
||||
class Event(NamedTuple):
|
||||
lateral_accel: float
|
||||
speed: float
|
||||
roll: float
|
||||
timestamp: float # relative to start of route (s)
|
||||
|
||||
|
||||
def find_events(lr: LogReader, extrapolate: bool = False, qlog: bool = False) -> list[Event]:
|
||||
min_lat_active = RLOG_MIN_LAT_ACTIVE // QLOG_DECIMATION if qlog else RLOG_MIN_LAT_ACTIVE
|
||||
min_steering_unpressed = RLOG_MIN_STEERING_UNPRESSED // QLOG_DECIMATION if qlog else RLOG_MIN_STEERING_UNPRESSED
|
||||
min_requesting_max = RLOG_MIN_REQUESTING_MAX // QLOG_DECIMATION if qlog else RLOG_MIN_REQUESTING_MAX
|
||||
|
||||
# if we test with driver torque safety, max torque can be slightly noisy
|
||||
steer_threshold = 0.7 if extrapolate else 0.95
|
||||
|
||||
events = []
|
||||
|
||||
# state tracking
|
||||
steering_unpressed = 0 # frames
|
||||
requesting_max = 0 # frames
|
||||
lat_active = 0 # frames
|
||||
|
||||
# current state
|
||||
curvature = 0
|
||||
v_ego = 0
|
||||
roll = 0
|
||||
out_torque = 0
|
||||
|
||||
start_ts = 0
|
||||
for msg in lr:
|
||||
if msg.which() == 'carControl':
|
||||
if start_ts == 0:
|
||||
start_ts = msg.logMonoTime
|
||||
|
||||
lat_active = lat_active + 1 if msg.carControl.latActive else 0
|
||||
|
||||
elif msg.which() == 'carOutput':
|
||||
out_torque = msg.carOutput.actuatorsOutput.torque
|
||||
requesting_max = requesting_max + 1 if abs(out_torque) > steer_threshold else 0
|
||||
|
||||
elif msg.which() == 'carState':
|
||||
steering_unpressed = steering_unpressed + 1 if not msg.carState.steeringPressed else 0
|
||||
v_ego = msg.carState.vEgo
|
||||
|
||||
elif msg.which() == 'controlsState':
|
||||
curvature = msg.controlsState.curvature
|
||||
|
||||
elif msg.which() == 'vehicleParameters':
|
||||
roll = msg.vehicleParameters.roll
|
||||
|
||||
if lat_active > min_lat_active and steering_unpressed > min_steering_unpressed and requesting_max > min_requesting_max:
|
||||
# TODO: record max lat accel at the end of the event, need to use the past lat accel as overriding can happen before we detect it
|
||||
requesting_max = 0
|
||||
|
||||
factor = 1 / abs(out_torque)
|
||||
current_lateral_accel = (curvature * v_ego ** 2 * factor) - roll * EARTH_G
|
||||
events.append(Event(current_lateral_accel, v_ego, roll, round((msg.logMonoTime - start_ts) * 1e-9, 2)))
|
||||
print(events[-1])
|
||||
|
||||
return events
|
||||
|
||||
|
||||
if __name__ == '__main__':
|
||||
parser = argparse.ArgumentParser(description="Find max lateral acceleration events",
|
||||
formatter_class=argparse.ArgumentDefaultsHelpFormatter)
|
||||
|
||||
parser.add_argument("route", nargs='+')
|
||||
parser.add_argument("-e", "--extrapolate", action="store_true", help="Extrapolates max lateral acceleration events linearly. " +
|
||||
"This option can be far less accurate.")
|
||||
args = parser.parse_args()
|
||||
|
||||
events = []
|
||||
for route in tqdm(args.route):
|
||||
try:
|
||||
lr = LogReader(route, sort_by_time=True)
|
||||
except Exception:
|
||||
print(f'Skipping {route}')
|
||||
continue
|
||||
|
||||
qlog = route.endswith('/q')
|
||||
if qlog:
|
||||
print('WARNING: Treating route as qlog!')
|
||||
|
||||
print('Finding events...')
|
||||
events += lr.run_across_segments(8, partial(find_events, extrapolate=args.extrapolate, qlog=qlog), disable_tqdm=True)
|
||||
|
||||
print()
|
||||
print(f'Found {len(events)} events')
|
||||
|
||||
perc_left_accel = -np.percentile([-ev.lateral_accel for ev in events if ev.lateral_accel < 0] or [0], 90)
|
||||
perc_right_accel = np.percentile([ev.lateral_accel for ev in events if ev.lateral_accel > 0] or [0], 90)
|
||||
|
||||
CP = lr.first('carParams')
|
||||
|
||||
plt.ion()
|
||||
plt.clf()
|
||||
plt.suptitle(f'{CP.carFingerprint} - Max lateral acceleration events')
|
||||
plt.title(', '.join(args.route))
|
||||
plt.scatter([ev.speed for ev in events], [ev.lateral_accel for ev in events], label='max lateral accel events')
|
||||
|
||||
plt.plot([0, 35], [3, 3], c='r', label='ISO 11270 - 3 m/s^2')
|
||||
plt.plot([0, 35], [-3, -3], c='r')
|
||||
|
||||
plt.plot([0, 35], [perc_left_accel, perc_left_accel], c='g', linestyle='--', label='90th percentile left lateral accel')
|
||||
plt.plot([0, 35], [perc_right_accel, perc_right_accel], c='#ff7f0e', linestyle='--', label='90th percentile right lateral accel')
|
||||
plt.text(0.4, float(perc_left_accel + 0.4), f'{perc_left_accel:.2f} m/s^2', verticalalignment='center', fontsize=12)
|
||||
plt.text(0.4, float(perc_right_accel - 0.4), f'{perc_right_accel:.2f} m/s^2', verticalalignment='center', fontsize=12)
|
||||
|
||||
plt.xlim(0, 35)
|
||||
plt.ylim(-5, 5)
|
||||
plt.xlabel('speed (m/s)')
|
||||
plt.ylabel('lateral acceleration (m/s^2)')
|
||||
plt.legend()
|
||||
plt.show(block=True)
|
||||
58
iqpilot/tools/iqperf/measure_torque_time_to_max.py
Executable file
58
iqpilot/tools/iqperf/measure_torque_time_to_max.py
Executable file
@@ -0,0 +1,58 @@
|
||||
#!/usr/bin/env python3
|
||||
|
||||
import os
|
||||
import argparse
|
||||
import struct
|
||||
from collections import deque
|
||||
from statistics import mean
|
||||
|
||||
from iqpilot.cereal import log
|
||||
import iqpilot.cereal.messaging as messaging
|
||||
|
||||
if __name__ == "__main__":
|
||||
|
||||
parser = argparse.ArgumentParser(description='Sniff a communication socket')
|
||||
parser.add_argument('--addr', default='127.0.0.1')
|
||||
args = parser.parse_args()
|
||||
|
||||
if args.addr != "127.0.0.1":
|
||||
os.environ["ZMQ"] = "1"
|
||||
messaging.reset_context()
|
||||
|
||||
poller = messaging.Poller()
|
||||
messaging.sub_sock('can', poller, addr=args.addr)
|
||||
|
||||
active = 0
|
||||
start_t = 0
|
||||
start_v = 0
|
||||
max_v = 0
|
||||
max_t = 0
|
||||
window = deque(maxlen=10)
|
||||
avg = 0
|
||||
while 1:
|
||||
polld = poller.poll(1000)
|
||||
for sock in polld:
|
||||
msg = sock.receive()
|
||||
with log.Event.from_bytes(msg) as log_evt:
|
||||
evt = log_evt
|
||||
|
||||
for item in evt.can:
|
||||
if item.address == 0xe4 and item.src == 128:
|
||||
torque_req = struct.unpack('!h', item.dat[0:2])[0]
|
||||
# print(torque_req)
|
||||
active = abs(torque_req) > 0
|
||||
if abs(torque_req) < 100:
|
||||
if max_v > 5:
|
||||
print(f'{start_v} -> {max_v} = {round(max_v - start_v, 2)} over {round(max_t - start_t, 2)}s')
|
||||
start_t = evt.logMonoTime / 1e9
|
||||
start_v = avg
|
||||
max_t = 0
|
||||
max_v = 0
|
||||
if item.address == 0x1ab and item.src == 0:
|
||||
motor_torque = ((item.dat[0] & 0x3) << 8) + item.dat[1]
|
||||
window.append(motor_torque)
|
||||
avg = mean(window)
|
||||
#print(f'{evt.logMonoTime}: {avg}')
|
||||
if active and avg > max_v + 0.5:
|
||||
max_v = avg
|
||||
max_t = evt.logMonoTime / 1e9
|
||||
78
iqpilot/tools/iqperf/qlog_size.py
Executable file
78
iqpilot/tools/iqperf/qlog_size.py
Executable file
@@ -0,0 +1,78 @@
|
||||
#!/usr/bin/env python3
|
||||
import argparse
|
||||
import zstandard as zstd
|
||||
from collections import defaultdict
|
||||
|
||||
import matplotlib.pyplot as plt
|
||||
|
||||
from iqpilot.cereal.services import SERVICE_LIST
|
||||
from iqpilot.common.utils import LOG_COMPRESSION_LEVEL
|
||||
from iqpilot.tools.lib.logreader import LogReader
|
||||
from tqdm import tqdm
|
||||
|
||||
MIN_SIZE = 0.5 # Percent size of total to show as separate entry
|
||||
|
||||
|
||||
def make_pie(msgs, typ):
|
||||
msgs_by_type = defaultdict(list)
|
||||
for m in msgs:
|
||||
msgs_by_type[m.which()].append(m.as_builder().to_bytes())
|
||||
|
||||
total = len(zstd.compress(b"".join([m.as_builder().to_bytes() for m in msgs]), LOG_COMPRESSION_LEVEL))
|
||||
uncompressed_total = len(b"".join([m.as_builder().to_bytes() for m in msgs]))
|
||||
|
||||
length_by_type = {k: len(b"".join(v)) for k, v in msgs_by_type.items()}
|
||||
# calculate compressed size by calculating diff when removed from the segment
|
||||
compressed_length_by_type = {}
|
||||
for k in tqdm(msgs_by_type.keys(), desc="Compressing"):
|
||||
compressed_length_by_type[k] = total - len(zstd.compress(b"".join([m.as_builder().to_bytes() for m in msgs if m.which() != k]), LOG_COMPRESSION_LEVEL))
|
||||
|
||||
sizes = sorted(compressed_length_by_type.items(), key=lambda kv: kv[1])
|
||||
|
||||
print("name - comp. size (uncomp. size)")
|
||||
for (name, sz) in sizes:
|
||||
print(f"{name:<22} - {sz / 1024:.2f} kB ({length_by_type[name] / 1024:.2f} kB)")
|
||||
print()
|
||||
print(f"{typ} - Real total {total / 1024:.2f} kB")
|
||||
print(f"{typ} - Breakdown total {sum(compressed_length_by_type.values()) / 1024:.2f} kB")
|
||||
print(f"{typ} - Uncompressed total {uncompressed_total / 1024 / 1024:.2f} MB")
|
||||
|
||||
sizes_large = [(k, sz) for (k, sz) in sizes if sz >= total * MIN_SIZE / 100]
|
||||
sizes_large += [('other', sum(sz for (_, sz) in sizes if sz < total * MIN_SIZE / 100))]
|
||||
|
||||
labels, sizes = zip(*sizes_large, strict=True)
|
||||
|
||||
plt.figure()
|
||||
plt.title(f"{typ}")
|
||||
plt.pie(sizes, labels=labels, autopct='%1.1f%%')
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
parser = argparse.ArgumentParser(description='View log size breakdown by message type')
|
||||
parser.add_argument('route', help='route to use')
|
||||
parser.add_argument('--as-qlog', action='store_true', help='decimate rlog using latest decimation factors')
|
||||
args = parser.parse_args()
|
||||
|
||||
msgs = list(LogReader(args.route))
|
||||
|
||||
if args.as_qlog:
|
||||
new_msgs = []
|
||||
msg_cnts: dict[str, int] = defaultdict(int)
|
||||
for msg in msgs:
|
||||
msg_which = msg.which()
|
||||
if msg.which() in ("initData", "sentinel"):
|
||||
new_msgs.append(msg)
|
||||
continue
|
||||
|
||||
if msg_which not in SERVICE_LIST:
|
||||
continue
|
||||
|
||||
decimation = SERVICE_LIST[msg_which].decimation
|
||||
if decimation is not None and msg_cnts[msg_which] % decimation == 0:
|
||||
new_msgs.append(msg)
|
||||
msg_cnts[msg_which] += 1
|
||||
|
||||
msgs = new_msgs
|
||||
|
||||
make_pie(msgs, 'qlog')
|
||||
plt.show()
|
||||
78
iqpilot/tools/iqperf/sendcan_gap_audit.py
Executable file
78
iqpilot/tools/iqperf/sendcan_gap_audit.py
Executable file
@@ -0,0 +1,78 @@
|
||||
#!/usr/bin/env python3
|
||||
"""
|
||||
sendcan_gap_audit.py — measure the openpilot->car actuator TX cadence from an rlog.
|
||||
|
||||
WHY: VW PQ random long/lat disengages are caused by control-loop STALLS that
|
||||
freeze the `sendcan` publish for >100ms. The car's ECU runs a counter/checksum
|
||||
watchdog on the actuator messages (ACC_System ADR, HCA_1) and FAULTS when frames
|
||||
arrive late/missing — it does NOT care about the payload value. So the single
|
||||
metric that predicts the fault is the inter-frame GAP in sendcan, not anything
|
||||
about accel/torque. (Reference: route 20e3cd4f0d5f39d1|00000038--0f69286335 had a
|
||||
103ms gap at ~373s -> engine MO2_Sta_GRA->0 -> main switch off -> disengage. A
|
||||
separate 60ms gap did NOT disengage: the ECU timeout sits ~60-100ms.)
|
||||
|
||||
This is the pass/fail metric for the mlockall / loggerd-writeback fix (5324c46)
|
||||
and, later, the decoupled in-card heartbeat TX. Run it on a BASELINE route to see
|
||||
the offending gaps, then on POST-FIX drives to confirm they're gone.
|
||||
|
||||
python3 iqpilot/tools/iqperf/sendcan_gap_audit.py <route_or_segment> [--warn-ms 30] [--fault-ms 100]
|
||||
|
||||
Exit code 0 if no gap >= --fault-ms, else 1 (so it can gate CI / a smoke test).
|
||||
Read-only; pulls rlogs via the normal LogReader (konn3kt for IQ.Pilot routes).
|
||||
"""
|
||||
|
||||
import argparse
|
||||
import sys
|
||||
|
||||
from iqpilot.tools.lib.logreader import LogReader
|
||||
|
||||
|
||||
def audit(route: str, warn_ms: float, fault_ms: float) -> int:
|
||||
lr = LogReader(route, sort_by_time=True)
|
||||
|
||||
last = None
|
||||
gaps = [] # (t_end, dt_ms) for every gap >= warn_ms
|
||||
n = 0
|
||||
worst = 0.0
|
||||
for m in lr:
|
||||
if m.which() != "sendcan":
|
||||
continue
|
||||
t = m.logMonoTime / 1e9
|
||||
n += 1
|
||||
if last is not None:
|
||||
dt = (t - last) * 1000.0
|
||||
worst = max(worst, dt)
|
||||
if dt >= warn_ms:
|
||||
gaps.append((t, dt))
|
||||
last = t
|
||||
|
||||
faults = [(t, dt) for t, dt in gaps if dt >= fault_ms]
|
||||
|
||||
print(f"route : {route}")
|
||||
print(f"sendcan frames : {n}")
|
||||
print(f"worst gap : {worst:.1f} ms")
|
||||
print(f"gaps >= {warn_ms:.0f}ms : {len(gaps)}")
|
||||
print(f"gaps >= {fault_ms:.0f}ms (FAULT-RISK): {len(faults)}")
|
||||
if gaps:
|
||||
print("\n t(s) gap(ms) risk")
|
||||
for t, dt in gaps:
|
||||
print(f" {t:10.3f} {dt:7.1f} {'<-- FAULT RISK' if dt >= fault_ms else ''}")
|
||||
|
||||
if faults:
|
||||
print(f"\nFAIL: {len(faults)} gap(s) >= {fault_ms:.0f}ms can trip the car's actuator counter watchdog (late/missing frames).")
|
||||
return 1
|
||||
print(f"\nPASS: no sendcan gap >= {fault_ms:.0f}ms.")
|
||||
return 0
|
||||
|
||||
|
||||
def main() -> int:
|
||||
p = argparse.ArgumentParser(description=__doc__, formatter_class=argparse.RawDescriptionHelpFormatter)
|
||||
p.add_argument("route", help="route name, segment, or URL (e.g. dongle|time--hash or .../5:8)")
|
||||
p.add_argument("--warn-ms", type=float, default=30.0, help="list gaps >= this (default 30)")
|
||||
p.add_argument("--fault-ms", type=float, default=100.0, help="fail on gaps >= this (default 100)")
|
||||
args = p.parse_args()
|
||||
return audit(args.route, args.warn_ms, args.fault_ms)
|
||||
|
||||
|
||||
if __name__ == "__main__":
|
||||
sys.exit(main())
|
||||
Reference in New Issue
Block a user