9/28 spike capture
This commit is contained in:
+77
-58
@@ -1,4 +1,4 @@
|
||||
"""Windows ping spike monitor. Python 3.8+, standard library only."""
|
||||
"""Windows and Linux continuous route spike monitor. Python 3.8+, standard library only."""
|
||||
from __future__ import annotations
|
||||
|
||||
import argparse
|
||||
@@ -7,9 +7,11 @@ from concurrent.futures import ThreadPoolExecutor
|
||||
from datetime import datetime
|
||||
import ipaddress
|
||||
import json
|
||||
import os
|
||||
from pathlib import Path
|
||||
import re
|
||||
import socket
|
||||
import shutil
|
||||
import statistics
|
||||
import subprocess
|
||||
import sys
|
||||
@@ -19,6 +21,7 @@ import time
|
||||
|
||||
RTT = re.compile(r"([<=]?)\s*(\d+(?:[.,]\d+)?)\s*ms\b", re.I)
|
||||
IP = re.compile(r"\b(?:\d{1,3}\.){3}\d{1,3}\b")
|
||||
LINUX_ADDRESS = re.compile(r"([^\s()]+)\s+\(((?:\d{1,3}\.){3}\d{1,3})\)")
|
||||
|
||||
|
||||
def timestamp():
|
||||
@@ -27,12 +30,13 @@ def timestamp():
|
||||
|
||||
def run_command(command, timeout, stop, capture_path=None):
|
||||
"""Capture output without blocking shutdown or filling a pipe."""
|
||||
env = None if sys.platform == "win32" else dict(os.environ, LC_ALL="C")
|
||||
if capture_path is not None:
|
||||
# Send stdout/stderr straight to disk, preserving the complete original
|
||||
# output even if this monitor is interrupted before tracing finishes.
|
||||
with capture_path.open("wb", buffering=0) as capture:
|
||||
with subprocess.Popen(command, stdout=capture, stderr=subprocess.STDOUT,
|
||||
creationflags=getattr(subprocess, "CREATE_NO_WINDOW", 0)) as process:
|
||||
env=env, creationflags=getattr(subprocess, "CREATE_NO_WINDOW", 0)) as process:
|
||||
deadline = time.monotonic() + timeout
|
||||
try:
|
||||
while process.poll() is None:
|
||||
@@ -46,7 +50,7 @@ def run_command(command, timeout, stop, capture_path=None):
|
||||
raise
|
||||
return process.returncode, capture_path.read_bytes().decode(errors="replace")
|
||||
with subprocess.Popen(command, stdout=subprocess.PIPE, stderr=subprocess.STDOUT,
|
||||
creationflags=getattr(subprocess, "CREATE_NO_WINDOW", 0)) as process:
|
||||
env=env, creationflags=getattr(subprocess, "CREATE_NO_WINDOW", 0)) as process:
|
||||
deadline = time.monotonic() + timeout
|
||||
while True:
|
||||
try:
|
||||
@@ -59,6 +63,21 @@ def run_command(command, timeout, stop, capture_path=None):
|
||||
return -1, output.decode(errors="replace") + "\n[Cancelled or command timed out]\n"
|
||||
|
||||
|
||||
def ping_command(target, timeout_ms):
|
||||
if sys.platform == "win32":
|
||||
return ["ping", "-4", "-n", "1", "-w", str(timeout_ms), target]
|
||||
return ["ping", "-4", "-n", "-c", "1", "-W", str(timeout_ms / 1000), target]
|
||||
|
||||
|
||||
def trace_command(target, args):
|
||||
if sys.platform == "win32":
|
||||
return ["tracert", "-4", "-h", str(args.max_hops), "-w", str(args.trace_timeout), target]
|
||||
# UDP tracing works without root. Serial probes preserve per-hop timing;
|
||||
# reverse DNS remains enabled, as on Windows.
|
||||
return ["traceroute", "-4", "-N", "1", "-q", "3", "-m", str(args.max_hops),
|
||||
"-w", str(args.trace_timeout / 1000), target]
|
||||
|
||||
|
||||
def parse_ping(output):
|
||||
# TTL identifies an echo reply, excluding summaries and unreachable messages.
|
||||
for line in output.splitlines():
|
||||
@@ -123,17 +142,35 @@ def parse_trace(output):
|
||||
times = [0.5 if m[1] == "<" else float(m[2].replace(",", ".")) for m in matches]
|
||||
addresses = IP.findall(remainder)
|
||||
hostname_match = re.search(r"([^\s\[\]]+)\s+\[(?:\d{1,3}\.){3}\d{1,3}\]", remainder)
|
||||
hops.append({"hop": int(number[1]), "ip": addresses[-1] if addresses else None,
|
||||
"hostname": hostname_match[1] if hostname_match else None,
|
||||
hostname = hostname_match[1] if hostname_match else None
|
||||
address = addresses[-1] if addresses else None
|
||||
probes = []
|
||||
linux_addresses = list(LINUX_ADDRESS.finditer(remainder))
|
||||
if linux_addresses:
|
||||
# Linux may print a different router before each timed probe.
|
||||
for match, rtt in zip(matches, times):
|
||||
preceding = [item for item in linux_addresses if item.end() <= match.start()]
|
||||
router = preceding[-1] if preceding else None
|
||||
probes.append({"ip": router[2] if router else None,
|
||||
"hostname": router[1] if router and router[1] != router[2] else None,
|
||||
"rtt_ms": rtt})
|
||||
routers = {item[2] for item in linux_addresses}
|
||||
address = linux_addresses[0][2] if len(routers) == 1 else None
|
||||
hostname = linux_addresses[0][1] if len(routers) == 1 else None
|
||||
if hostname == address:
|
||||
hostname = None
|
||||
else:
|
||||
probes = [{"ip": address, "hostname": hostname, "rtt_ms": rtt} for rtt in times]
|
||||
hops.append({"hop": int(number[1]), "ip": address, "hostname": hostname,
|
||||
"rtt_ms": times, "median_ms": statistics.median(times) if times else None,
|
||||
"timeouts": remainder.count("*")})
|
||||
"timeouts": remainder.count("*"), "probes": probes})
|
||||
return hops
|
||||
|
||||
|
||||
def sustained_jump(hops, destination, jump_ms):
|
||||
"""Return structured evidence only when a jump persists to the destination."""
|
||||
responding = [h for h in hops if h["median_ms"] is not None]
|
||||
if not responding or responding[-1]["ip"] != destination:
|
||||
if not responding or any(h["ip"] is None for h in responding) or responding[-1]["ip"] != destination:
|
||||
return None
|
||||
for index, hop in enumerate(responding):
|
||||
previous = responding[index - 1] if index else None
|
||||
@@ -152,6 +189,8 @@ def analyze_trace(hops, destination, jump_ms):
|
||||
return "Inconclusive: no hops returned timed replies."
|
||||
if responding[-1]["ip"] != destination:
|
||||
return "Inconclusive: destination did not return timed replies; cannot locate the end-to-end delay."
|
||||
if any(h["ip"] is None for h in responding):
|
||||
return "Inconclusive: a hop has replies from multiple routers; cannot assign its combined timings to one router."
|
||||
evidence = sustained_jump(hops, destination, jump_ms)
|
||||
if evidence:
|
||||
previous, hop, floor = evidence["previous"], evidence["hop"], evidence["floor_ms"]
|
||||
@@ -193,9 +232,9 @@ class Log:
|
||||
|
||||
def trace(target, args, log, stop, baseline=None, incident_id=None, attempt=1):
|
||||
name = datetime.now().strftime("trace_%Y%m%d_%H%M%S_%f")
|
||||
command = ["tracert", "-4", "-h", str(args.max_hops), "-w", str(args.trace_timeout), target]
|
||||
command = trace_command(target, args)
|
||||
raw_path = log.directory / (name + ".pending.txt")
|
||||
log.write("trace_start", f"Running tracert to {target} (attempt {attempt}); keeping output only if a spike is captured.",
|
||||
log.write("trace_start", f"Running {command[0]} to {target} (attempt {attempt}); keeping output only if a spike is captured.",
|
||||
command=command, incident_id=incident_id, attempt=attempt)
|
||||
try:
|
||||
code, output = run_command(command, args.max_hops * 3 * args.trace_timeout / 1000 + 30,
|
||||
@@ -211,9 +250,8 @@ def trace(target, args, log, stop, baseline=None, incident_id=None, attempt=1):
|
||||
spike_limit = min(spike_limit, max(baseline * args.multiplier, baseline + args.increase))
|
||||
# Preserve transient samples even when medians hide them or later hops recover.
|
||||
# Capturing a slow diagnostic reply is separate from locating a forwarding fault.
|
||||
spike_probes = [{"hop": hop["hop"], "ip": hop["ip"], "hostname": hop["hostname"],
|
||||
"rtt_ms": rtt}
|
||||
for hop in hops for rtt in hop["rtt_ms"] if rtt >= spike_limit]
|
||||
spike_probes = [{"hop": hop["hop"], **probe}
|
||||
for hop in hops for probe in hop["probes"] if probe["rtt_ms"] >= spike_limit]
|
||||
captured = bool(spike_probes)
|
||||
peak_ms = max((rtt for hop in hops for rtt in hop["rtt_ms"]), default=None)
|
||||
if captured and not evidence:
|
||||
@@ -241,28 +279,6 @@ def trace(target, args, log, stop, baseline=None, incident_id=None, attempt=1):
|
||||
return report
|
||||
|
||||
|
||||
def trace_incident(target, args, log, stop, baseline):
|
||||
incident_id = datetime.now().strftime("incident_%Y%m%d_%H%M%S_%f")
|
||||
attempt = 0
|
||||
log.write("incident_start", "Incident detected: repeating tracert until a spike is captured.",
|
||||
incident_id=incident_id, baseline_ms=baseline)
|
||||
while not stop.is_set():
|
||||
attempt += 1
|
||||
report = trace(target, args, log, stop, baseline, incident_id, attempt)
|
||||
if report["spike_captured"]:
|
||||
log.write("incident_captured", f"Spike captured on trace {attempt}. Returning to ping monitoring.",
|
||||
incident_id=incident_id, attempts=attempt, raw_file=report["raw_file"])
|
||||
return
|
||||
if stop.is_set():
|
||||
break
|
||||
log.write("trace_retry", f"No trace probe crossed the spike threshold; next trace in {args.trace_retry:g}s.",
|
||||
incident_id=incident_id, attempt=attempt)
|
||||
if stop.wait(args.trace_retry):
|
||||
break
|
||||
log.write("incident_cancelled", "Trace capture stopped before a spike was captured.",
|
||||
incident_id=incident_id, attempts=attempt)
|
||||
|
||||
|
||||
def positive_float(value):
|
||||
result = float(value)
|
||||
if not 0 < result < float("inf"):
|
||||
@@ -284,19 +300,19 @@ def arguments():
|
||||
parser.add_argument("--threshold", type=positive_float, default=100, help="absolute spike threshold in ms")
|
||||
parser.add_argument("--multiplier", type=positive_float, default=3, help="relative baseline multiplier")
|
||||
parser.add_argument("--increase", type=positive_float, default=40, help="minimum relative increase in ms")
|
||||
parser.add_argument("--required", type=positive_int, default=3, help="bad probes needed per period (default: 3)")
|
||||
parser.add_argument("--required", type=positive_int, default=3, help="bad probes per qualifying ping summary period (default: 3)")
|
||||
parser.add_argument("--period", type=positive_float, default=60, help="period duration in seconds (default: 60)")
|
||||
parser.add_argument("--consecutive", type=positive_int, default=2, help="consecutive bad periods needed (default: 2)")
|
||||
parser.add_argument("--consecutive", type=positive_int, default=2, help="consecutive qualifying ping summary periods (default: 2)")
|
||||
parser.add_argument("--baseline-window", type=positive_int, default=60)
|
||||
parser.add_argument("--cooldown", type=positive_float, default=120, help="seconds after capture before another incident can start")
|
||||
parser.add_argument("--trace-retry", type=positive_float, default=2, help="seconds between incident trace attempts (default: 2)")
|
||||
parser.add_argument("--cooldown", type=positive_float, default=120, help="legacy option; ignored (tracing is continuous)")
|
||||
parser.add_argument("--trace-retry", type=positive_float, default=2, help="seconds between route traces, including after capture (default: 2)")
|
||||
parser.add_argument("--ping-timeout", type=positive_int, default=1000, help="ping timeout in ms")
|
||||
parser.add_argument("--trace-timeout", type=positive_int, default=500, help="per-hop probe timeout in ms")
|
||||
parser.add_argument("--max-hops", type=positive_int, default=30)
|
||||
parser.add_argument("--hop-jump", type=positive_float, default=30, help="sustained hop RTT increase in ms")
|
||||
parser.add_argument("--log-dir", type=Path, default=Path(__file__).resolve().parent / "logs")
|
||||
parser.add_argument("--count", type=positive_int, help="stop after this many probes (default: continuous)")
|
||||
parser.add_argument("--trace-now", action="store_true", help="also run a diagnostic immediately")
|
||||
parser.add_argument("--trace-now", action="store_true", help="legacy option; tracing always starts immediately")
|
||||
args = parser.parse_args()
|
||||
if args.max_hops > 255:
|
||||
parser.error("--max-hops cannot exceed 255")
|
||||
@@ -307,8 +323,15 @@ def arguments():
|
||||
|
||||
def main():
|
||||
args = arguments()
|
||||
if sys.platform != "win32":
|
||||
print("This program requires Windows (ping.exe and tracert.exe).", file=sys.stderr)
|
||||
if sys.platform != "win32" and not sys.platform.startswith("linux"):
|
||||
print("This program supports Windows and Linux.", file=sys.stderr)
|
||||
return 1
|
||||
required = ("ping", "tracert" if sys.platform == "win32" else "traceroute")
|
||||
missing = [command for command in required if shutil.which(command) is None]
|
||||
if missing:
|
||||
print("Missing required command(s): " + ", ".join(missing), file=sys.stderr)
|
||||
if sys.platform.startswith("linux"):
|
||||
print("On Linux Mint/Ubuntu: sudo apt install iputils-ping traceroute", file=sys.stderr)
|
||||
return 1
|
||||
try:
|
||||
target = socket.gethostbyname(args.target)
|
||||
@@ -322,26 +345,27 @@ def main():
|
||||
args.baseline_window, args.required, args.period, args.consecutive)
|
||||
executor = ThreadPoolExecutor(max_workers=1)
|
||||
pending = None
|
||||
next_incident = float("-inf")
|
||||
pending_incident = False
|
||||
next_trace = float("-inf")
|
||||
samples = 0
|
||||
failed = False
|
||||
try:
|
||||
log.write("start", f"Monitoring {args.target} ({target}). Ctrl+C stops. Logs: {log.directory}",
|
||||
target=target, settings={k: str(v) if isinstance(v, Path) else v for k, v in vars(args).items()})
|
||||
log.write("trigger_rule", f"Trace after {args.required}+ spikes/losses per {args.period:g}s "
|
||||
f"period for {args.consecutive} consecutive periods.")
|
||||
if args.trace_now:
|
||||
pending = executor.submit(trace, target, args, log, stop)
|
||||
log.write("trace_mode", f"Tracing continuously, with {args.trace_retry:g}s between traces."
|
||||
" Captured spikes do not stop tracing.")
|
||||
attempt = 1
|
||||
pending = executor.submit(trace, target, args, log, stop, None, None, attempt)
|
||||
while not stop.is_set() and (args.count is None or samples < args.count):
|
||||
started = time.monotonic()
|
||||
if pending is not None and pending.done():
|
||||
pending.result()
|
||||
pending = None
|
||||
if pending_incident:
|
||||
next_incident = time.monotonic() + args.cooldown
|
||||
pending_incident = False
|
||||
code, output = run_command(["ping", "-4", "-n", "1", "-w", str(args.ping_timeout), target],
|
||||
next_trace = time.monotonic() + args.trace_retry
|
||||
if pending is None and time.monotonic() >= next_trace:
|
||||
baseline = statistics.median(detector.baseline) if len(detector.baseline) >= 10 else None
|
||||
attempt += 1
|
||||
pending = executor.submit(trace, target, args, log, stop, baseline, None, attempt)
|
||||
code, output = run_command(ping_command(target, args.ping_timeout),
|
||||
args.ping_timeout / 1000 + 5, stop)
|
||||
if stop.is_set():
|
||||
break
|
||||
@@ -356,16 +380,11 @@ def main():
|
||||
streak=state["consecutive_bad_periods"])
|
||||
samples += 1
|
||||
log.ping(target, latency, state)
|
||||
if state["trigger"] and pending is None and time.monotonic() >= next_incident:
|
||||
baseline = state["baseline_ms"] if len(detector.baseline) >= 10 else None
|
||||
pending_incident = True
|
||||
pending = executor.submit(trace_incident, target, args, log, stop, baseline)
|
||||
if args.count is None or samples < args.count:
|
||||
stop.wait(max(0, args.interval - (time.monotonic() - started)))
|
||||
if pending:
|
||||
if pending_incident:
|
||||
stop.set() # --count remains a bounded monitoring run.
|
||||
log.write("waiting", "Finishing diagnostic; Ctrl+C cancels.")
|
||||
stop.set() # --count also cancels the active trace.
|
||||
log.write("waiting", "Stopping active trace.")
|
||||
while not pending.done():
|
||||
time.sleep(0.2)
|
||||
pending.result()
|
||||
|
||||
Reference in New Issue
Block a user