diff --git a/src/freeze-monitor-gui b/src/freeze-monitor-gui
index e28c2ff..e3ae644 100755
--- a/src/freeze-monitor-gui
+++ b/src/freeze-monitor-gui
@@ -11,7 +11,7 @@ import re
import subprocess
import sys
from collections import Counter, deque
-from datetime import datetime
+from datetime import datetime, timedelta
from pathlib import Path
from PySide6.QtCore import Qt, QTimer, QPointF, Signal
@@ -34,13 +34,25 @@ GRAPH_UPDATE_MS = 1000
def read_psi(name):
try:
- line = (Path("/proc/pressure") / name).read_text().splitlines()[0]
- m = re.search(r"avg10=([\d.]+)", line)
+ text = (Path("/proc/pressure") / name).read_text()
+ m = re.search(r"avg10=([\d.]+)", text.splitlines()[0])
return float(m.group(1)) if m else 0.0
except Exception:
return 0.0
+def read_psi_full(name):
+ """Read the 'full' row avg10 instead of 'some'."""
+ try:
+ for line in (Path("/proc/pressure") / name).read_text().splitlines():
+ if line.startswith("full"):
+ m = re.search(r"avg10=([\d.]+)", line)
+ return float(m.group(1)) if m else 0.0
+ except Exception:
+ pass
+ return 0.0
+
+
def read_dstate_count():
try:
out = subprocess.run(
@@ -74,6 +86,50 @@ def service_active():
return r.stdout.strip() == "active"
+def parse_events_log():
+ """Parse events.log and return a list of storm dicts with start/end info."""
+ storms = []
+ current = None
+ try:
+ for line in (LOG_DIR / "events.log").read_text(errors="replace").splitlines():
+ m = re.match(r"^(\S+) STORM STARTED: (\d+) captures in (\d+)s \(trigger: (.+)\)$", line)
+ if m:
+ current = {
+ "type": "storm",
+ "start_str": m.group(1),
+ "count_at_start": int(m.group(2)),
+ "window": int(m.group(3)),
+ "trigger": m.group(4),
+ "end_str": None,
+ "duration": None,
+ "total_captures": None,
+ }
+ try:
+ current["start_ts"] = datetime.fromisoformat(m.group(1)).replace(tzinfo=None)
+ except Exception:
+ current["start_ts"] = None
+ continue
+ m = re.match(r"^(\S+) STORM ENDED: duration=(\d+)s, captures=(\d+)$", line)
+ if m and current:
+ current["end_str"] = m.group(1)
+ current["duration"] = int(m.group(2))
+ current["total_captures"] = int(m.group(3))
+ try:
+ current["end_ts"] = datetime.fromisoformat(m.group(1)).replace(tzinfo=None)
+ except Exception:
+ current["end_ts"] = None
+ storms.append(current)
+ current = None
+ # Storm without an end (still ongoing)
+ if current:
+ current["end_str"] = None
+ current["end_ts"] = None
+ storms.append(current)
+ except Exception:
+ pass
+ return storms
+
+
# ----------------------------------------------------------------- widgets
class MetricLabel(QLabel):
@@ -114,21 +170,26 @@ class LineGraph(QWidget):
self.warn = warn
self.crit = crit
self.values = deque(maxlen=HISTORY_SECONDS)
- self.markers = set() # indices to mark as snapshot events
+ self.markers = set() # indices of regular snapshot captures
+ self.storm_markers = set() # indices of storm-start events
self.setMinimumHeight(110)
self.setSizePolicy(QSizePolicy.Expanding, QSizePolicy.Preferred)
- def push(self, value, marker=False):
+ def push(self, value, marker=False, storm_marker=False):
self.values.append(value)
+ idx = len(self.values) - 1
if marker:
- self.markers.add(len(self.values) - 1)
- # Decay markers as values shift out
- new_markers = set()
- for m in self.markers:
- shifted = m - 1 if len(self.values) == HISTORY_SECONDS else m
- if shifted >= 0:
- new_markers.add(shifted)
- self.markers = new_markers
+ self.markers.add(idx)
+ if storm_marker:
+ self.storm_markers.add(idx)
+ # Decay markers as values shift out of the deque
+ for attr in ("markers", "storm_markers"):
+ new = set()
+ for m in getattr(self, attr):
+ shifted = m - 1 if len(self.values) == HISTORY_SECONDS else m
+ if shifted >= 0:
+ new.add(shifted)
+ setattr(self, attr, new)
self.update()
def paintEvent(self, _):
@@ -136,7 +197,6 @@ class LineGraph(QWidget):
p.setRenderHint(QPainter.Antialiasing)
w, h = self.width(), self.height()
- # Background
p.fillRect(0, 0, w, h, QColor("#1a1a1a"))
if not self.values:
@@ -148,13 +208,11 @@ class LineGraph(QWidget):
min_v = 0
rng = max_v - min_v
- # Title and current value
p.setPen(QColor("#aaa"))
p.setFont(QFont("monospace", 9))
current = self.values[-1]
p.drawText(8, 16, f"{self.label} current={current:.1f} max={max(self.values):.1f}")
- # Threshold lines
plot_top = 24
plot_bot = h - 8
plot_h = plot_bot - plot_top
@@ -165,11 +223,10 @@ class LineGraph(QWidget):
p.setPen(QPen(QColor(col), 1, Qt.DashLine))
p.drawLine(0, int(y), w, int(y))
- # Line
n = len(self.values)
if n < 2:
return
- step = w / (n - 1) if n > 1 else 0
+ step = w / (n - 1)
poly = QPolygonF()
for i, v in enumerate(self.values):
x = i * step
@@ -178,12 +235,18 @@ class LineGraph(QWidget):
p.setPen(QPen(self.color, 1.5))
p.drawPolyline(poly)
- # Markers (snapshot captures)
+ # Regular snapshot markers (red dotted)
p.setPen(QPen(QColor("#ff5555"), 1, Qt.DotLine))
for m in self.markers:
x = m * step
p.drawLine(int(x), plot_top, int(x), plot_bot)
+ # Storm markers (orange solid, thicker)
+ p.setPen(QPen(QColor("#f5a623"), 2, Qt.SolidLine))
+ for m in self.storm_markers:
+ x = m * step
+ p.drawLine(int(x), plot_top, int(x), plot_bot)
+
# ----------------------------------------------------------------- snapshot parsing
@@ -252,6 +315,10 @@ class FreezeMonitor(QMainWindow):
self.status_label = QLabel()
self.status_label.setStyleSheet("padding:6px; font-weight:bold;")
status_row.addWidget(self.status_label)
+ self.storm_label = QLabel()
+ self.storm_label.setStyleSheet("padding:6px; font-weight:bold; color:#f5a623;")
+ self.storm_label.hide()
+ status_row.addWidget(self.storm_label)
status_row.addStretch()
self.btn_capture_now = QPushButton("📸 Capture Now")
self.btn_capture_now.setToolTip("Manually trigger a snapshot capture")
@@ -268,7 +335,7 @@ class FreezeMonitor(QMainWindow):
# Live metrics row
metrics_box = QGroupBox("Live metrics (1s refresh)")
grid = QGridLayout(metrics_box)
- labels = ["PSI IO %", "PSI CPU %", "PSI Mem %", "D-state", "Blocked", "Load (1m)"]
+ labels = ["PSI IO %", "PSI IO full %", "PSI CPU %", "PSI Mem %", "D-state", "Blocked", "Load (1m)"]
self.metrics = {}
for i, name in enumerate(labels):
grid.addWidget(QLabel(name, alignment=Qt.AlignCenter), 0, i)
@@ -286,7 +353,8 @@ class FreezeMonitor(QMainWindow):
self._build_summary_tab()
self._known_events = set()
- self._all_snapshots = [] # cached parses
+ self._all_snapshots = []
+ self._storms = []
# Tray
self.tray = QSystemTrayIcon(self.style().standardIcon(QStyle.SP_ComputerIcon), self)
@@ -306,7 +374,6 @@ class FreezeMonitor(QMainWindow):
self.tray.activated.connect(self._tray_clicked)
self.tray.show()
- # Tick timer
self.timer = QTimer()
self.timer.timeout.connect(self.tick)
self.timer.start(GRAPH_UPDATE_MS)
@@ -318,12 +385,14 @@ class FreezeMonitor(QMainWindow):
def _build_graphs_tab(self):
tab = QWidget()
v = QVBoxLayout(tab)
- v.addWidget(QLabel("Last hour — red dashed lines mark snapshot captures"))
- self.graph_load = LineGraph("Load (1m)", "#5cdb95", warn=8, crit=16)
- self.graph_psi_io = LineGraph("PSI io.some %", "#88ccff", warn=30, crit=60)
- self.graph_psi_cpu = LineGraph("PSI cpu.some %", "#ffcc66", warn=30, crit=60)
- self.graph_dstate = LineGraph("D-state procs", "#ff8888", warn=3, crit=6)
- for g in (self.graph_load, self.graph_psi_io, self.graph_psi_cpu, self.graph_dstate):
+ v.addWidget(QLabel("Last hour — red dashed = snapshot capture, orange = storm start"))
+ self.graph_load = LineGraph("Load (1m)", "#5cdb95", warn=8, crit=16)
+ self.graph_psi_io = LineGraph("PSI io.some %", "#88ccff", warn=30, crit=60)
+ self.graph_psi_iof = LineGraph("PSI io.full %", "#5599ff", warn=15, crit=40)
+ self.graph_psi_cpu = LineGraph("PSI cpu.some %", "#ffcc66", warn=30, crit=60)
+ self.graph_dstate = LineGraph("D-state procs", "#ff8888", warn=3, crit=6)
+ for g in (self.graph_load, self.graph_psi_io, self.graph_psi_iof,
+ self.graph_psi_cpu, self.graph_dstate):
v.addWidget(g)
self.tabs.addTab(tab, "Live graphs")
@@ -334,7 +403,7 @@ class FreezeMonitor(QMainWindow):
filter_row = QHBoxLayout()
filter_row.addWidget(QLabel("Filter:"))
self.filter_edit = QLineEdit()
- self.filter_edit.setPlaceholderText("substring match against reason/diagnosis (e.g. btrfs, dstate, usb)")
+ self.filter_edit.setPlaceholderText("substring match against reason/diagnosis (e.g. btrfs, dstate, usb, storm)")
self.filter_edit.textChanged.connect(self._apply_filter)
filter_row.addWidget(self.filter_edit)
self.btn_refresh = QPushButton("Refresh")
@@ -415,19 +484,21 @@ class FreezeMonitor(QMainWindow):
# ---- tick
def tick(self):
- psi_io = read_psi("io")
- psi_cpu = read_psi("cpu")
- psi_mem = read_psi("memory")
- dstate = read_dstate_count()
- blocked = read_procs_blocked()
- load = read_loadavg()
+ psi_io = read_psi("io")
+ psi_io_f = read_psi_full("io")
+ psi_cpu = read_psi("cpu")
+ psi_mem = read_psi("memory")
+ dstate = read_dstate_count()
+ blocked = read_procs_blocked()
+ load = read_loadavg()
- self.metrics["PSI IO %"].set_value(int(psi_io), 30, 60, "")
- self.metrics["PSI CPU %"].set_value(int(psi_cpu), 30, 60, "")
- self.metrics["PSI Mem %"].set_value(int(psi_mem), 20, 50, "")
- self.metrics["D-state"].set_value(dstate, 3, 6, "")
- self.metrics["Blocked"].set_value(blocked, 3, 6, "")
- self.metrics["Load (1m)"].set_value(int(load), 8, 16, "")
+ self.metrics["PSI IO %"].set_value(int(psi_io), 30, 60)
+ self.metrics["PSI IO full %"].set_value(int(psi_io_f), 15, 40)
+ self.metrics["PSI CPU %"].set_value(int(psi_cpu), 30, 60)
+ self.metrics["PSI Mem %"].set_value(int(psi_mem), 20, 50)
+ self.metrics["D-state"].set_value(dstate, 3, 6)
+ self.metrics["Blocked"].set_value(blocked, 3, 6)
+ self.metrics["Load (1m)"].set_value(int(load), 8, 16)
active = service_active()
if active:
@@ -437,23 +508,43 @@ class FreezeMonitor(QMainWindow):
self.status_label.setText("● Service: STOPPED")
self.status_label.setStyleSheet("padding:6px; font-weight:bold; color:#ff5555;")
+ # Storm indicator
+ storms = parse_events_log()
+ active_storm = next((s for s in reversed(storms) if s.get("end_str") is None), None)
+ if active_storm:
+ start_ts = active_storm.get("start_ts")
+ dur_str = ""
+ if start_ts:
+ dur = int((datetime.now() - start_ts).total_seconds())
+ dur_str = f" — {dur//60}m{dur%60:02d}s"
+ self.storm_label.setText(f"⚡ STORM IN PROGRESS{dur_str} ({active_storm['total_captures'] or active_storm['count_at_start']} captures)")
+ self.storm_label.show()
+ else:
+ self.storm_label.hide()
+
self.tray.setToolTip(
f"Freeze Watcher — {'active' if active else 'stopped'}\n"
- f"PSI io {int(psi_io)}% / cpu {int(psi_cpu)}% — D:{dstate} blk:{blocked} load:{load:.2f}"
+ f"PSI io {int(psi_io)}%/{int(psi_io_f)}%full cpu {int(psi_cpu)}% — D:{dstate} blk:{blocked} load:{load:.2f}"
)
- # Detect new snapshot files for graph markers
current = set(p.name for p in LOG_DIR.glob("snap-*.log")) if LOG_DIR.exists() else set()
new = current - self._known_events
+
+ # Check if any new storm events occurred since last tick
+ new_storm = len(storms) > len(self._storms)
+ self._storms = storms
+
is_marker = bool(new)
- self.graph_load.push(load, marker=is_marker)
- self.graph_psi_io.push(psi_io, marker=is_marker)
- self.graph_psi_cpu.push(psi_cpu, marker=is_marker)
- self.graph_dstate.push(dstate, marker=is_marker)
+ is_storm_marker = new_storm and bool(active_storm)
+ self.graph_load.push(load, marker=is_marker, storm_marker=is_storm_marker)
+ self.graph_psi_io.push(psi_io, marker=is_marker, storm_marker=is_storm_marker)
+ self.graph_psi_iof.push(psi_io_f, marker=is_marker, storm_marker=is_storm_marker)
+ self.graph_psi_cpu.push(psi_cpu, marker=is_marker, storm_marker=is_storm_marker)
+ self.graph_dstate.push(dstate, marker=is_marker, storm_marker=is_storm_marker)
if current != self._known_events:
self._known_events = current
- self._all_snapshots = [] # invalidate cache
+ self._all_snapshots = []
self.load_events()
for n in new:
self.tray.showMessage(
@@ -474,29 +565,89 @@ class FreezeMonitor(QMainWindow):
self._all_snapshots = [parse_snapshot(p) for p in files]
self._all_snapshots = [s for s in self._all_snapshots if s]
self._known_events = set(p.name for p in files)
+ self._storms = parse_events_log()
self._apply_filter()
def _apply_filter(self):
needle = self.filter_edit.text().lower().strip()
self.event_list.clear()
+
+ # Interleave storm events into the snapshot list by time
+ snap_items = []
for info in self._all_snapshots:
+ ts = datetime.fromtimestamp(info["mtime"])
text_blob = (info["reason"] + " " + " ".join(info["diagnoses"])).lower()
- if needle and needle not in text_blob:
+ if needle and needle not in text_blob and "storm" not in needle:
continue
- ts = datetime.fromtimestamp(info["mtime"]).strftime("%Y-%m-%d %H:%M:%S")
- diag_short = info["diagnoses"][0][:80] if info["diagnoses"] else ""
- label = f"{ts}\n reason: {info['reason']}"
- if diag_short:
- label += f"\n → {diag_short}"
- item = QListWidgetItem(label)
- item.setData(Qt.UserRole, info["path"])
- self.event_list.addItem(item)
+ snap_items.append(("snap", ts, info))
+
+ storm_items = []
+ for s in self._storms:
+ ts = s.get("start_ts") or datetime.now()
+ text_blob = f"storm {s['trigger']}".lower()
+ if needle and needle not in text_blob and needle not in "storm":
+ continue
+ storm_items.append(("storm", ts, s))
+
+ # Merge by timestamp descending
+ all_items = sorted(snap_items + storm_items, key=lambda x: x[1], reverse=True)
+
+ for kind, ts, data in all_items:
+ if kind == "storm":
+ s = data
+ dur = f"{s['duration']}s" if s.get("duration") else "ongoing"
+ n = s.get("total_captures") or s.get("count_at_start", "?")
+ label = (f"⚡ STORM {ts.strftime('%Y-%m-%d %H:%M:%S')}\n"
+ f" {n} captures, {dur}, trigger: {s['trigger'][:60]}")
+ item = QListWidgetItem(label)
+ item.setData(Qt.UserRole, None)
+ item.setData(Qt.UserRole + 1, "storm")
+ item.setForeground(QColor("#f5a623"))
+ self.event_list.addItem(item)
+ else:
+ info = data
+ ts_str = ts.strftime("%Y-%m-%d %H:%M:%S")
+ diag_short = info["diagnoses"][0][:80] if info["diagnoses"] else ""
+ label = f"{ts_str}\n reason: {info['reason']}"
+ if diag_short:
+ label += f"\n → {diag_short}"
+ item = QListWidgetItem(label)
+ item.setData(Qt.UserRole, info["path"])
+ item.setData(Qt.UserRole + 1, "snap")
+ self.event_list.addItem(item)
def show_selected(self):
items = self.event_list.selectedItems()
if not items:
return
- path = Path(items[0].data(Qt.UserRole))
+ kind = items[0].data(Qt.UserRole + 1)
+ if kind == "storm":
+ s_data = None
+ # Find this storm from its label
+ label = items[0].text()
+ ts_str = label.split("\n")[0].replace("⚡ STORM ", "").strip()
+ for s in self._storms:
+ if s.get("start_ts") and s["start_ts"].strftime("%Y-%m-%d %H:%M:%S") == ts_str:
+ s_data = s
+ break
+ if s_data:
+ dur = f"{s_data['duration']}s" if s_data.get("duration") else "ongoing"
+ n = s_data.get("total_captures") or s_data.get("count_at_start", "?")
+ text = (
+ f"STORM EVENT\n"
+ f"{'─'*60}\n"
+ f"Started: {s_data['start_str']}\n"
+ f"Ended: {s_data.get('end_str') or '(ongoing)'}\n"
+ f"Duration: {dur}\n"
+ f"Captures: {n}\n"
+ f"Trigger: {s_data['trigger']}\n"
+ )
+ self.detail.setPlainText(text)
+ return
+ path = items[0].data(Qt.UserRole)
+ if not path:
+ return
+ path = Path(path)
try:
text = path.read_text()
html_sidecar = path.with_suffix(".html")
@@ -519,10 +670,12 @@ class FreezeMonitor(QMainWindow):
QMessageBox.information(self, "Select a snapshot",
"Pick a snapshot from the list first.")
return
- path = Path(items[0].data(Qt.UserRole))
+ path = items[0].data(Qt.UserRole)
+ if not path:
+ return
+ path = Path(path)
html = path.with_suffix(".html")
if not html.exists():
- # Try generating on demand
try:
subprocess.run(["freeze-snapshot-convert", "--html", str(path)],
check=True, capture_output=True)
@@ -556,17 +709,45 @@ class FreezeMonitor(QMainWindow):
if not self._all_snapshots:
self.load_events()
snaps = self._all_snapshots
+ storms = self._storms
+
+ out = []
+
+ # Storm summary
+ if storms:
+ completed = [s for s in storms if s.get("duration") is not None]
+ ongoing = [s for s in storms if s.get("duration") is None]
+ out.append("─── Storm history ───────────────────────────────────────")
+ out.append(f" Total storms recorded: {len(storms)}")
+ if completed:
+ durations = [s["duration"] for s in completed]
+ captures = [s["total_captures"] for s in completed if s.get("total_captures")]
+ out.append(f" Completed: {len(completed)} avg duration: {sum(durations)//len(durations)}s "
+ f"max: {max(durations)}s")
+ if captures:
+ out.append(f" Captures per storm: avg {sum(captures)//len(captures)} max {max(captures)}")
+ if ongoing:
+ out.append(f" Currently active: {len(ongoing)} storm(s)")
+ out.append("")
+ out.append(" Recent storms:")
+ for s in storms[-5:]:
+ dur = f"{s['duration']}s" if s.get("duration") else "ongoing"
+ n = s.get("total_captures") or s.get("count_at_start", "?")
+ out.append(f" {s['start_str'][:19]} {n} captures {dur} trigger: {s['trigger'][:50]}")
+ out.append("")
+
if not snaps:
- self.summary_text.setPlainText("No snapshots captured yet.")
+ out.append("No snapshots captured yet.")
+ self.summary_text.setPlainText("\n".join(out))
return
- wchans = Counter()
- procs = Counter()
+ wchans = Counter()
+ procs = Counter()
top_cpu = Counter()
diagnoses = Counter()
- hours = Counter()
- first = None
- last = None
+ hours = Counter()
+ first = None
+ last = None
for s in snaps:
for w in s["wchans"]:
wchans[w] += 1
@@ -575,13 +756,12 @@ class FreezeMonitor(QMainWindow):
if s["top_cpu_proc"]:
top_cpu[s["top_cpu_proc"]] += 1
for d in s["diagnoses"]:
- # First clause only, before " — "
key = d.split("—")[0].strip()[:60]
diagnoses[key] += 1
ts = datetime.fromtimestamp(s["mtime"])
hours[ts.hour] += 1
first = min(first, ts) if first else ts
- last = max(last, ts) if last else ts
+ last = max(last, ts) if last else ts
def topn(ctr, n=10):
total = sum(ctr.values()) or 1
@@ -595,10 +775,9 @@ class FreezeMonitor(QMainWindow):
hour_dist = []
for h in range(24):
count = hours.get(h, 0)
- bar = "▇" * count
+ bar = "▇" * min(count, 40)
hour_dist.append(f" {h:02d}:00 {bar} {count}")
- out = []
out.append(f"Snapshots analyzed: {len(snaps)}")
if first and last:
out.append(f"Time range: {first} → {last}")
diff --git a/src/freeze-watcher.sh b/src/freeze-watcher.sh
index 94b8fbf..1109900 100755
--- a/src/freeze-watcher.sh
+++ b/src/freeze-watcher.sh
@@ -15,6 +15,9 @@ DSTATE_THRESHOLD=5
BLOCKED_THRESHOLD=5
LOAD_THRESHOLD=20
COOLDOWN=30
+STORM_THRESHOLD=8 # captures within STORM_WINDOW before declaring a storm
+STORM_WINDOW=300 # seconds; how far back to count captures for storm detection
+STORM_COOLDOWN=90 # cooldown to use during an active storm (vs COOLDOWN)
SAMPLE_INTERVAL=1
MAX_SNAPSHOTS=200
MAX_SNAPSHOT_AGE_DAYS=30
@@ -23,6 +26,7 @@ NOTIFY_URGENCY=normal
CAPTURE_KERNEL_STACKS=1
CAPTURE_BPFTRACE=0
CAPTURE_CGROUP_PSI=1
+CAPTURE_DEVICE_IO=1 # include hot-device IO digest (device labels, await, nr_requests)
OUTPUT_JSON=0
OUTPUT_HTML=0
@@ -33,6 +37,13 @@ mkdir -p "$LOG_DIR"
last_capture=0
captures_since_prune=0
+# Storm tracking
+in_storm=0
+storm_count=0
+storm_window_start=0
+storm_start_time=0
+last_trigger_time=0
+
notify_users() {
[ -z "$NOTIFY_USERS" ] && return 0
local body="$1"
@@ -110,8 +121,65 @@ capture_bpftrace() {
' 2>/dev/null | tail -40
}
+# Human-readable summary of hot block devices with volume labels, await times,
+# and nr_requests. Makes it immediately clear which volume is under pressure.
+capture_device_io_digest() {
+ echo "## Hot device IO digest (>10% util)"
+
+ # Build label map from lsblk (covers dm and physical devices)
+ declare -A label_map
+ while IFS= read -r line; do
+ local dev lbl
+ dev=${line%% *}
+ lbl=${line#* }
+ lbl=${lbl## }
+ [ -n "$dev" ] && [ -n "$lbl" ] && label_map["$dev"]="$lbl"
+ done < <(lsblk -o NAME,LABEL -rn 2>/dev/null | awk 'NF>=2')
+
+ # nr_requests for sd* (USB bridges typically nr_req=2, SATA gets 64+)
+ declare -A nr_map
+ for f in /sys/block/sd*/queue/nr_requests; do
+ [ -r "$f" ] || continue
+ local dev nr
+ dev=$(echo "$f" | cut -d/ -f4)
+ nr=$(cat "$f" 2>/dev/null)
+ [ -n "$nr" ] && nr_map["$dev"]="$nr"
+ done
+
+ # Parse iostat using column headers so it's robust across versions
+ local raw
+ raw=$(iostat -dx 1 1 2>/dev/null | awk '
+ /^Device/ {
+ for (i=1; i<=NF; i++) col[$i]=i
+ p=1; next
+ }
+ p && NF>5 {
+ u = col["%util"] ? $col["%util"]+0 : 0
+ if (u < 10) next
+ r = col["r_await"] ? $col["r_await"] : 0
+ w = col["w_await"] ? $col["w_await"] : 0
+ a = col["aqu-sz"] ? $col["aqu-sz"] : 0
+ printf "%s\t%.1f\t%s\t%s\t%s\n", $1, u, r, w, a
+ }
+ ' | sort -t$'\t' -k2 -rn)
+
+ if [ -z "$raw" ]; then
+ echo " (no devices above 10% utilization)"
+ return
+ fi
+
+ printf " %-10s %-22s %6s %8s %8s %6s\n" \
+ Device "Volume/Label" "%util" "r_await" "w_await" "nr_req"
+ while IFS=$'\t' read -r dev util r_await w_await aqu; do
+ local lbl="${label_map[$dev]:-}"
+ local nr="${nr_map[$dev]:-}"
+ [ -z "$nr" ] && [[ "$dev" == nvme* ]] && nr="(nvme)"
+ printf " %-10s %-22s %5s%% %7sms %7sms %6s\n" \
+ "$dev" "${lbl:0:22}" "$util" "$r_await" "$w_await" "${nr:-(n/a)}"
+ done <<< "$raw"
+}
+
# Reads a snapshot file and emits one or more diagnosis lines.
-# Pattern-matches D-state wchans and PSI metrics against known freeze types.
classify_snapshot() {
local file="$1"
local diagnoses=()
@@ -130,7 +198,33 @@ classify_snapshot() {
local dcount
dcount=$(echo "$dstate_section" | grep -c "^D ")
- # btrfs lock contention
+ # --- dm-crypt request pool exhaustion ---
+ # Multiple kcryptd workers stuck in crypt_alloc_buffer, often with blk_mq_get_tag
+ # on the dmcrypt_write threads. Root cause: nr_requests=2 on USB-to-SATA bridges
+ # under concurrent IO load exhausts all block MQ slots.
+ if echo "$dstate_section" | grep -q "crypt_alloc_buffer"; then
+ local n_crypt
+ n_crypt=$(echo "$dstate_section" | grep -c "crypt_alloc_buffer")
+ if echo "$dstate_section" | grep -q "blk_mq_get_tag"; then
+ local hot_devs
+ hot_devs=$(awk '/^## Hot device IO digest/{flag=1;next} /^## /{flag=0} flag && /dm-/{print $1}' "$file" 2>/dev/null | head -3 | tr '\n' ' ')
+ local dev_hint=""
+ [ -n "$hot_devs" ] && dev_hint=" (hot: ${hot_devs% })"
+ diagnoses+=("dm-crypt request pool exhausted — ${n_crypt} kcryptd workers blocked${dev_hint}; backing device nr_requests too low for concurrent IO; increase nr_requests or limit parallel readers")
+ else
+ diagnoses+=("dm-crypt encryption pool stall — ${n_crypt} kcryptd workers waiting for memory; encryption CPU/memory bound")
+ fi
+ fi
+
+ # --- block MQ tag starvation (non-crypt) ---
+ if echo "$dstate_section" | grep -q "blk_mq_get_tag" && \
+ ! echo "$dstate_section" | grep -q "crypt_alloc_buffer"; then
+ local n_blkmq
+ n_blkmq=$(echo "$dstate_section" | grep -c "blk_mq_get_tag")
+ diagnoses+=("block MQ request tags exhausted — ${n_blkmq} processes waiting for IO slots; device nr_requests too low for this workload")
+ fi
+
+ # --- btrfs lock contention ---
if echo "$dstate_section" | grep -qE "btrfs_lock_root_node|btrfs_sync_log"; then
if [ "${psi_io_some:-0}" -lt 10 ]; then
diagnoses+=("btrfs metadata lock contention — wchans show btrfs_lock_root_node/sync_log with low PSI io. Typical of qgroups + many snapshots, or heavy fsync churn.")
@@ -139,18 +233,26 @@ classify_snapshot() {
fi
fi
- # btrfs metadata pressure (less severe)
+ # --- btrfs metadata pressure ---
if echo "$dstate_section" | grep -q "btrfs_search_slot" && \
- ! echo "$dstate_section" | grep -q "btrfs_lock_root_node"; then
+ ! echo "$dstate_section" | grep -q "btrfs_lock_root_node" && \
+ ! echo "$dstate_section" | grep -q "crypt_alloc_buffer"; then
diagnoses+=("btrfs metadata pressure — cleaner walking trees, fsyncs queueing")
fi
- # USB stall
+ # --- USB stall ---
if echo "$dstate_section" | grep -qE "usb_sg_wait|scsi_eh|sd_check_events|usb_hcd"; then
- diagnoses+=("USB storage stall — one external drive responding slowly")
+ local n_usb
+ n_usb=$(echo "$dstate_section" | grep -cE "usb_sg_wait|scsi_eh|sd_check_events|usb_hcd")
+ local hot_vol
+ hot_vol=$(awk '/^## Hot device IO digest/{flag=1;next} /^## /{flag=0} flag && /%/{print $2}' "$file" 2>/dev/null \
+ | grep -v "Volume\|---\|^$" | head -2 | tr '\n' ',' | sed 's/,$//')
+ local vol_hint=""
+ [ -n "$hot_vol" ] && vol_hint=" (hot volumes: $hot_vol)"
+ diagnoses+=("USB storage stall — ${n_usb} usb-storage threads unresponsive${vol_hint}; check SMART and USB hub bandwidth sharing")
fi
- # Memory swap thrash
+ # --- memory swap thrash ---
if echo "$dstate_section" | grep -q "folio_wait_bit_common"; then
if [ "${psi_mem_some:-0}" -gt 5 ]; then
diagnoses+=("memory pressure / swap thrash — folio_wait + PSI mem ${psi_mem_some}%")
@@ -159,15 +261,19 @@ classify_snapshot() {
fi
fi
- # CPU oversubscription
- if [ "${psi_cpu_some:-0}" -gt 30 ] && [ "$dcount" -lt 3 ]; then
+ # --- container/Waydroid startup CPU spike ---
+ local lxc_cpu_psi
+ lxc_cpu_psi=$(awk '/^## Top cgroups by PSI cpu/{flag=1;next} /^## /{flag=0} flag && /lxc/{print $1+0; exit}' "$file" 2>/dev/null)
+ if [ "${lxc_cpu_psi:-0}" -gt 20 ] && [ "${psi_cpu_some:-0}" -gt 20 ]; then
+ diagnoses+=("container/Waydroid CPU spike — lxc cgroup at ${lxc_cpu_psi}% CPU PSI; Android container startup or heavy in-container workload")
+ fi
+
+ # --- CPU oversubscription ---
+ if [ "${psi_cpu_some:-0}" -gt 30 ] && [ "$dcount" -lt 3 ] && [ "${lxc_cpu_psi:-0}" -le 20 ]; then
diagnoses+=("CPU oversubscription — PSI cpu ${psi_cpu_some}%, few D-state procs. Heavy compile, transcoding, or runaway process competing for cores.")
fi
- # NIC IRQ saturation — use delta against the running baseline so old
- # cumulative skew doesn't trigger forever.
- # With RPS enabled, per-flow concentration on one CPU is normal up to ~85%.
- # Only flag when no RPS spreading is happening at all, or it's truly extreme.
+ # --- NIC IRQ saturation ---
if [ -r "$LOG_DIR/.softirq-baseline" ] && [ -n "$(echo "$softirq" | grep '^ *NET_RX:')" ]; then
local cur prev
cur=$(echo "$softirq" | grep '^ *NET_RX:' | sed 's/^ *NET_RX://')
@@ -187,13 +293,11 @@ classify_snapshot() {
done
if [ "$total" -gt 100000 ]; then
local pct=$((max * 100 / total))
- # Check if RPS is configured (any non-zero, non-single-bit value)
local rps_active=0
for rps in /sys/class/net/*/queues/rx-0/rps_cpus; do
[ -r "$rps" ] || continue
local v
v=$(cat "$rps" 2>/dev/null | tr -d ',')
- # Strip leading zeros, count hex bits set
[ "$v" != "0" ] && [ "$v" != "00" ] && [ "$v" != "000" ] \
&& [ "$v" != "0000" ] && rps_active=1
done
@@ -206,7 +310,7 @@ classify_snapshot() {
fi
fi
- # Genuine I/O bottleneck
+ # --- genuine I/O bottleneck ---
if [ "${psi_io_full:-0}" -gt 30 ]; then
diagnoses+=("genuine I/O bottleneck — PSI io full ${psi_io_full}%, device truly can't keep up")
fi
@@ -225,8 +329,7 @@ capture_snapshot() {
local body="$LOG_DIR/.snap-body-$$.tmp"
local final="$LOG_DIR/snap-$(date +%Y%m%d-%H%M%S).log"
- # CAPTURE D-STATE FIRST - blocked spikes are often <1s long, so we need
- # to grab process state before reading slower /proc/* files
+ # Capture D-state first — spikes can be <1s, grab before slower /proc reads
local dstate_immediate
dstate_immediate=$(ps -eo state,pid,user,wchan:25,comm,args --no-headers 2>/dev/null | awk '$1=="D"' | head -30)
local dstate_t1
@@ -253,8 +356,6 @@ capture_snapshot() {
echo
fi
echo "## D-state processes (with kernel wchan)"
- # Use the snapshot taken before /proc reads to catch transient blockers.
- # Combine 3 rapid samples (~100ms apart) and dedupe by pid (column 2).
printf '%s\n%s\n%s\n' "$dstate_immediate" "$dstate_t1" "$dstate_t2" \
| awk 'NF >= 4 && $1=="D" && !seen[$2]++' | head -30
echo
@@ -271,9 +372,16 @@ capture_snapshot() {
echo "## /proc/meminfo summary"
grep -E "MemTotal|MemFree|MemAvailable|Dirty|Writeback|Slab|Cached|Buffers" /proc/meminfo
echo
+ if [ "${CAPTURE_DEVICE_IO:-1}" = "1" ]; then
+ capture_device_io_digest
+ echo
+ fi
echo "## iostat (1s snapshot)"
iostat -xt 1 2 2>&1 | tail -50
echo
+ echo "## Block device map"
+ lsblk -o NAME,MAJ:MIN,TYPE,TRAN,SIZE,LABEL 2>/dev/null
+ echo
echo "## interrupts (top by total)"
awk 'NR==1{next} {sum=0; for(i=2;i<=NF-2;i++) sum+=$i; if(sum>1000) print sum, $0}' /proc/interrupts | sort -rn | head -15
echo
@@ -291,21 +399,27 @@ capture_snapshot() {
journalctl --since "60 seconds ago" -p warning --no-pager 2>&1 | tail -40
} > "$body" 2>&1
- # Build final file: header + diagnosis (computed from body) + body
+ # Run classifier once — result goes into both the snapshot header and events.log
+ local diagnosis
+ diagnosis=$(classify_snapshot "$body")
+
{
echo "=== FREEZE EVENT TRIGGERED: $reason ==="
echo "Time: $(date -Iseconds)"
echo
echo "## Diagnosis (auto-classified)"
- classify_snapshot "$body"
+ echo "$diagnosis"
echo
cat "$body"
} > "$final"
rm -f "$body"
- echo "$(date -Iseconds) Captured snapshot to $final (reason: $reason)" >> "$LOG_DIR/events.log"
- # Optional sidecar formats
+ local diag_line
+ diag_line=$(echo "$diagnosis" | head -1 | sed 's/^ • //')
+ echo "$(date -Iseconds) Captured snapshot to $final (reason: $reason) [${diag_line}]" \
+ >> "$LOG_DIR/events.log"
+
local convert_args=""
[ "${OUTPUT_JSON:-0}" = "1" ] && convert_args="$convert_args --json"
[ "${OUTPUT_HTML:-0}" = "1" ] && convert_args="$convert_args --html"
@@ -319,14 +433,13 @@ capture_snapshot() {
echo "$(date -Iseconds) freeze-watcher started (pid $$)" >> "$LOG_DIR/events.log"
prune_snapshots
-# Initial softirq baseline so classifier can compute deltas
cp /proc/softirqs "$LOG_DIR/.softirq-baseline" 2>/dev/null
softirq_baseline_at=$(date +%s)
while true; do
now=$(date +%s)
- # Manual trigger from GUI (file-based, no auth required for users in log group)
+ # Manual trigger from GUI
if [ -f "$TRIGGER_FILE" ]; then
manual_reason="manual"
if [ -s "$TRIGGER_FILE" ]; then
@@ -335,6 +448,7 @@ while true; do
rm -f "$TRIGGER_FILE"
capture_snapshot "$manual_reason" &
last_capture=$now
+ last_trigger_time=$now
sleep "$SAMPLE_INTERVAL"
continue
fi
@@ -346,23 +460,57 @@ while true; do
load1=$(awk '{print int($1+0.5)}' /proc/loadavg)
triggered=""
- [ "${psi_io:-0}" -ge "$PSI_IO_THRESHOLD" ] && triggered="psi_io=$psi_io%"
+ [ "${psi_io:-0}" -ge "$PSI_IO_THRESHOLD" ] && triggered="psi_io=$psi_io%"
[ "${psi_cpu:-0}" -ge "$PSI_CPU_THRESHOLD" ] && triggered="${triggered:+$triggered, }psi_cpu=$psi_cpu%"
- [ "${dstate:-0}" -ge "$DSTATE_THRESHOLD" ] && triggered="${triggered:+$triggered, }dstate=$dstate"
+ [ "${dstate:-0}" -ge "$DSTATE_THRESHOLD" ] && triggered="${triggered:+$triggered, }dstate=$dstate"
[ "${blocked:-0}" -ge "$BLOCKED_THRESHOLD" ] && triggered="${triggered:+$triggered, }blocked=$blocked"
- [ "${load1:-0}" -ge "$LOAD_THRESHOLD" ] && triggered="${triggered:+$triggered, }load1=$load1"
+ [ "${load1:-0}" -ge "$LOAD_THRESHOLD" ] && triggered="${triggered:+$triggered, }load1=$load1"
- if [ -n "$triggered" ] && [ $((now - last_capture)) -ge "$COOLDOWN" ]; then
- capture_snapshot "$triggered" &
- last_capture=$now
- captures_since_prune=$((captures_since_prune+1))
- if [ "$captures_since_prune" -ge 20 ]; then
- prune_snapshots &
- captures_since_prune=0
+ if [ -n "$triggered" ]; then
+ last_trigger_time=$now
+
+ # Slide the storm counting window
+ if [ "$storm_window_start" -eq 0 ] || \
+ [ $((now - storm_window_start)) -gt "$STORM_WINDOW" ]; then
+ storm_count=0
+ storm_window_start=$now
+ fi
+ storm_count=$((storm_count + 1))
+
+ # Transition into storm state
+ if [ "$in_storm" -eq 0 ] && [ "$storm_count" -ge "$STORM_THRESHOLD" ]; then
+ in_storm=1
+ storm_start_time=$now
+ echo "$(date -Iseconds) STORM STARTED: ${storm_count} captures in $((now - storm_window_start))s (trigger: $triggered)" \
+ >> "$LOG_DIR/events.log"
+ fi
+
+ # Use longer cooldown during a storm to reduce log spam
+ effective_cooldown="$COOLDOWN"
+ [ "$in_storm" -eq 1 ] && effective_cooldown="$STORM_COOLDOWN"
+
+ if [ $((now - last_capture)) -ge "$effective_cooldown" ]; then
+ capture_snapshot "$triggered" &
+ last_capture=$now
+ captures_since_prune=$((captures_since_prune+1))
+ if [ "$captures_since_prune" -ge 20 ]; then
+ prune_snapshots &
+ captures_since_prune=0
+ fi
+ fi
+ else
+ # End storm when quiet for 3× the storm cooldown after the last trigger
+ if [ "$in_storm" -eq 1 ] && [ $((now - last_trigger_time)) -gt $((STORM_COOLDOWN * 3)) ]; then
+ duration=$((last_trigger_time - storm_start_time))
+ echo "$(date -Iseconds) STORM ENDED: duration=${duration}s, captures=${storm_count}" \
+ >> "$LOG_DIR/events.log"
+ in_storm=0
+ storm_count=0
+ storm_window_start=0
fi
fi
- # Refresh softirq baseline every 5 minutes so classifier deltas reflect recent activity
+ # Refresh softirq baseline every 5 minutes
if [ $((now - softirq_baseline_at)) -ge 300 ]; then
cp /proc/softirqs "$LOG_DIR/.softirq-baseline" 2>/dev/null
softirq_baseline_at=$now