Merge pull request #9 from GoWithitRoger/feat/bufferbloat-add

feat(bufferbloat): parse, log, and highlight under-load latency + pac…

Author: GoWithitRoger

config.py

@@ -45,6 +45,12 @@
 PING_RTT_THRESHOLD: float = 30.0
 # Any jitter measurement strictly greater than this value (in ms) is an anomaly.
 JITTER_THRESHOLD: float = 5.0
+# A latency increase (in ms) greater than this is an anomaly (bufferbloat delta).
+BUFFERBLOAT_DELTA_THRESHOLD: float = 75.0
+# Latency (in ms) during download/upload that is an anomaly.
+LATENCY_UNDER_LOAD_THRESHOLD: float = 100.0
+# Packet loss percentage from the speedtest that is an anomaly.
+SPEEDTEST_PACKET_LOSS_THRESHOLD: float = 0.5
 
 # --- Speed Test Thresholds (in Mbps) ---
 # Set separate thresholds for speed tests. Anomalies are values strictly LESS than these.

main.py

@@ -121,6 +121,8 @@ def managed_webdriver_session(chrome_options: Options, debug_logger: DebugLogger
             debug_logger.log("WebDriver quit: START")
             try:
                 driver.quit()
+            except Exception as e:
+                debug_logger.log(f"Ignoring error during driver.quit(): {e}")
             finally:
                 debug_logger.log("WebDriver quit: END")
         if service and getattr(service, "process", None):
@@ -167,6 +169,10 @@ class SpeedResults(TypedDict, total=False):
     local_downstream_speed: float
     local_upstream_speed: float
     local_speedtest_jitter: float
+    # Bufferbloat / under-load metrics from local Ookla CLI JSON
+    local_latency_down_load_ms: float
+    local_latency_up_load_ms: float
+    local_packet_loss_pct: float
 
 
 class WifiDiagnostics(TypedDict, total=False):
@@ -266,6 +272,13 @@ def log_results(all_data: Mapping[str, str | float | int | None]) -> None:
         "Local_Downstream_Mbps": all_data.get("local_downstream_speed"),
         "Local_Upstream_Mbps": all_data.get("local_upstream_speed"),
         "Local_Speedtest_Jitter_ms": all_data.get("local_speedtest_jitter"),
+        # Calculated bufferbloat deltas
+        "Download_Bufferbloat_ms": all_data.get("download_bufferbloat_ms"),
+        "Upload_Bufferbloat_ms": all_data.get("upload_bufferbloat_ms"),
+        # New bufferbloat metrics
+        "Local_Load_Down_ms": all_data.get("local_latency_down_load_ms"),
+        "Local_Load_Up_ms": all_data.get("local_latency_up_load_ms"),
+        "Local_Pkt_Loss_Pct": all_data.get("local_packet_loss_pct"),
         "WiFi_BSSID": all_data.get("wifi_bssid", "N/A"),
         "WiFi_Channel": all_data.get("wifi_channel", "N/A"),
         "WiFi_RSSI": all_data.get("wifi_rssi", "N/A"),
@@ -275,7 +288,7 @@ def log_results(all_data: Mapping[str, str | float | int | None]) -> None:
 
     # --- CSV Logging ---
     csv_values = [
-        f"{v:.3f}" if isinstance(v, float) else ("N/A" if v is None else v)
+        f"{v:.3f}" if isinstance(v, float) else "N/A" if v is None else str(v)
         for v in data_points.values()
     ]
     header = "Timestamp," + ",".join(data_points.keys()) + "\n"
@@ -402,6 +415,39 @@ def format_value(
     )
     print(f"  Speedtest Jitter:           {speed_jitter}")
 
+    # Bufferbloat deltas (idle -> under-load)
+    down_bloat = format_value(
+        data_points["Download_Bufferbloat_ms"],
+        "ms",
+        config.BUFFERBLOAT_DELTA_THRESHOLD,
+        precision=2,
+    )
+    print(f"  Download Bufferbloat:       {down_bloat}")
+
+    up_bloat = format_value(
+        data_points["Upload_Bufferbloat_ms"],
+        "ms",
+        config.BUFFERBLOAT_DELTA_THRESHOLD,
+        precision=2,
+    )
+    print(f"  Upload Bufferbloat:         {up_bloat}")
+
+    # New bufferbloat metrics
+    down_load_latency = format_value(
+        data_points["Local_Load_Down_ms"], "ms", config.LATENCY_UNDER_LOAD_THRESHOLD
+    )
+    print(f"  Latency (Download Load):    {down_load_latency}")
+
+    up_load_latency = format_value(
+        data_points["Local_Load_Up_ms"], "ms", config.LATENCY_UNDER_LOAD_THRESHOLD
+    )
+    print(f"  Latency (Upload Load):      {up_load_latency}")
+
+    packet_loss_val = format_value(
+        data_points["Local_Pkt_Loss_Pct"], "%", config.SPEEDTEST_PACKET_LOSS_THRESHOLD
+    )
+    print(f"  Speedtest Packet Loss:      {packet_loss_val}")
+
     print("\n--- Wi-Fi Diagnostics ---")
     print(f"  Connected AP (BSSID):       {data_points['WiFi_BSSID']}")
     print(f"  Signal Strength (RSSI):     {data_points['WiFi_RSSI']}")
@@ -426,7 +472,12 @@ def run_ping_test_task(driver: WebDriver) -> Optional[GatewayPingResults]:
         driver.execute_script("arguments[0].click();", ping_button)
         print(f"Gateway ping test started for {config.PING_TARGET}.")
         print("Waiting for gateway ping results...")
-        time.sleep(15)
+        wait = WebDriverWait(driver, 30)
+        wait.until(
+            lambda d: "ping statistics" in d.find_element(By.ID, "progress").get_attribute("value")
+        )
+
+        # Re-find the element after the wait to avoid stale references
         results_element = driver.find_element(By.ID, "progress")
         results_text = (results_element.get_attribute("value") or "").strip()
         if results_text:
@@ -466,13 +517,14 @@ def run_speed_test_task(driver: WebDriver, access_code: str) -> Optional[SpeedRe
         run_button = WebDriverWait(driver, 15).until(EC.element_to_be_clickable((By.NAME, "run")))
         run_button.click()
         print("Gateway speed test initiated. This will take up to 90 seconds...")
-        WebDriverWait(driver, 90).until(EC.element_to_be_clickable((By.NAME, "run")))
+        # Wait directly for the results table to appear
+        # instead of relying on the run button's state
+        print("Waiting for gateway results table...")
+        table_selector = (By.CSS_SELECTOR, "table.grid.table100")
+        table = WebDriverWait(driver, 90).until(EC.visibility_of_element_located(table_selector))
         print("Gateway speed test complete. Parsing results...")
 
         results: SpeedResults = {}
-        table = WebDriverWait(driver, 10).until(
-            EC.visibility_of_element_located((By.CSS_SELECTOR, "table.grid.table100"))
-        )
         rows = table.find_elements(By.TAG_NAME, "tr")
         for row in rows:
             cols = row.find_elements(By.TAG_NAME, "td")
@@ -570,11 +622,19 @@ def run_local_speed_test_task() -> Optional[SpeedResults]:
             upload_speed = (results.get("upload", {}).get("bandwidth", 0) * 8) / 1_000_000
             jitter = results.get("ping", {}).get("jitter", 0.0)
 
+            # New parsing logic for bufferbloat
+            latency_down = results.get("download", {}).get("latency", {}).get("iqm", 0.0)
+            latency_up = results.get("upload", {}).get("latency", {}).get("iqm", 0.0)
+            packet_loss = results.get("packetLoss", 0.0)
+
             print("Local speed test complete.")
             return {
                 "local_downstream_speed": download_speed,
                 "local_upstream_speed": upload_speed,
                 "local_speedtest_jitter": jitter,
+                "local_latency_down_load_ms": latency_down,
+                "local_latency_up_load_ms": latency_up,
+                "local_packet_loss_pct": packet_loss,
             }
 
         except subprocess.CalledProcessError as e:
@@ -765,6 +825,22 @@ def perform_checks() -> None:
             # This 'else' block will run if the context manager yields None
             print("Skipping gateway tests because WebDriver session failed to start.")
 
+    # --- Bufferbloat calculation (download/upload deltas relative to idle WAN RTT) ---
+    idle_latency = master_results.get("local_wan_rtt_avg_ms")
+    down_latency = master_results.get("local_latency_down_load_ms")
+    up_latency = master_results.get("local_latency_up_load_ms")
+
+    master_results["download_bufferbloat_ms"] = (
+        (down_latency - idle_latency)
+        if (idle_latency is not None and down_latency is not None)
+        else None
+    )
+    master_results["upload_bufferbloat_ms"] = (
+        (up_latency - idle_latency)
+        if (idle_latency is not None and up_latency is not None)
+        else None
+    )
+
     debug_log.log("perform_checks: END")
     log_results(master_results)
     print("\n" + "=" * 60 + "\n")

tests/test_bufferbloat.py

@@ -0,0 +1,125 @@
+import os
+import sys
+from unittest.mock import mock_open, patch
+
+import pytest
+
+# Ensure the main module can be imported
+sys.path.insert(0, os.path.abspath(os.path.join(os.path.dirname(__file__), "..")))
+
+import config
+from main import Colors, log_results, perform_checks
+
+
+@patch("builtins.open", new_callable=mock_open)
+@patch("main.os.path.exists", return_value=False)
+@patch("builtins.print")
+def test_log_results_includes_bufferbloat_fields_and_highlighting(
+    mock_print, mock_exists, mock_open_file
+) -> None:
+    # Configure threshold so our values trigger highlighting
+    config.ENABLE_ANOMALY_HIGHLIGHTING = True
+    config.BUFFERBLOAT_DELTA_THRESHOLD = 10.0
+
+    row = {
+        # Minimal fields used by log_results
+        "gateway_loss_percentage": 0.0,
+        "gateway_rtt_avg_ms": 10.0,
+        "downstream_speed": None,
+        "upstream_speed": None,
+        "local_wan_loss_percentage": 0.0,
+        "local_wan_rtt_avg_ms": 15.0,
+        "local_wan_ping_stddev": 1.0,
+        "local_gw_loss_percentage": 0.0,
+        "local_gw_rtt_avg_ms": 5.0,
+        "local_gw_ping_stddev": 0.5,
+        "local_downstream_speed": 100.0,
+        "local_upstream_speed": 10.0,
+        "local_speedtest_jitter": 1.0,
+        # Bufferbloat deltas already computed upstream
+        "download_bufferbloat_ms": 15.5,  # > 10.0 threshold
+        "upload_bufferbloat_ms": 11.0,  # > 10.0 threshold
+        # Under-load raw metrics
+        "local_latency_down_load_ms": 30.5,
+        "local_latency_up_load_ms": 20.0,
+        "local_packet_loss_pct": 0.0,
+        "wifi_bssid": "aa:bb:cc:dd:ee:ff",
+        "wifi_channel": "1,20",
+        "wifi_rssi": "-50",
+        "wifi_noise": "-90",
+        "wifi_tx_rate": "300",
+    }
+
+    log_results(row)
+
+    # CSV header contains the new fields
+    handle = mock_open_file()
+    header = handle.mock_calls[1][1][0]
+    assert "Download_Bufferbloat_ms" in header
+    assert "Upload_Bufferbloat_ms" in header
+
+    # Console output contains highlighted bufferbloat lines
+    all_output = " ".join([str(call.args[0]) for call in mock_print.call_args_list if call.args])
+    assert "Download Bufferbloat:" in all_output
+    assert "Upload Bufferbloat:" in all_output
+    assert f"{Colors.RED}15.50{Colors.RESET}" in all_output
+    assert f"{Colors.RED}11.00{Colors.RESET}" in all_output
+
+
+@patch("main.run_wifi_diagnostics_task", return_value={})
+@patch("main.run_local_ping_task")
+@patch("main.run_local_speed_test_task")
+@patch("main.run_ping_test_task", return_value={})
+@patch("main.run_speed_test_task", return_value={})
+@patch("main.subprocess.run")
+@patch("main.log_results")
+@patch("main.webdriver.Chrome")
+@patch("main.get_access_code", return_value="code")
+@patch("main.ChromeService")
+@patch("main.time.sleep")
+def test_perform_checks_computes_bufferbloat(
+    _sleep,
+    _service,
+    _access,
+    _chrome,
+    mock_log_results,
+    _subproc,
+    _gw_speed,
+    _gw_ping,
+    mock_local_speed,
+    mock_local_ping,
+    _wifi,
+    monkeypatch,
+):
+    # Arrange config to run local ping and local speed, skip gateway interval
+    import main as main_module
+
+    monkeypatch.setattr(config, "RUN_LOCAL_PING_TEST", True)
+    monkeypatch.setattr(config, "RUN_LOCAL_GATEWAY_PING_TEST", False)
+    monkeypatch.setattr(config, "RUN_LOCAL_SPEED_TEST", True)
+    monkeypatch.setattr(config, "RUN_GATEWAY_SPEED_TEST_INTERVAL", 0)
+
+    # Idle RTT and under-load latencies
+    mock_local_ping.return_value = {
+        "loss_percentage": 0.0,
+        "rtt_avg_ms": 20.0,
+        "ping_stddev": 1.0,
+    }
+    mock_local_speed.return_value = {
+        "local_latency_down_load_ms": 55.0,
+        "local_latency_up_load_ms": 41.0,
+        # other fields optional for this test
+    }
+
+    # Reset run counter for deterministic behavior
+    main_module.run_counter = 0
+
+    # Act
+    perform_checks()
+
+    # Assert: log_results called with computed deltas
+    assert mock_log_results.call_count == 1
+    args, _ = mock_log_results.call_args
+    passed = args[0]
+    assert passed.get("download_bufferbloat_ms") == pytest.approx(35.0)
+    assert passed.get("upload_bufferbloat_ms") == pytest.approx(21.0)

tests/test_core.py

@@ -57,10 +57,21 @@
 SPEEDTEST_JSON_OUTPUT = (
     '{"type": "result", "timestamp": "2025-08-06T22:00:00Z", '
     '"ping": {"jitter": 2.789, "latency": 10.123}, '
-    '"download": {"bandwidth": 37500000, "bytes": 300000000, "elapsed": 8000}, '
-    '"upload": {"bandwidth": 2500000, "bytes": 20000000, "elapsed": 8000}}'
+    '"download": {"bandwidth": 37500000, "bytes": 300000000, "elapsed": 8000, '
+    '              "latency": {"iqm": 75.5}}, '
+    '"upload": {"bandwidth": 2500000, "bytes": 20000000, "elapsed": 8000, '
+    '            "latency": {"iqm": 42.0}}, '
+    '"packetLoss": 0.25}'
 )  # 300 Mbps down, 20 Mbps up
 
+# Mock JSON missing bufferbloat fields
+SPEEDTEST_JSON_OUTPUT_MISSING = (
+    '{"type": "result", "timestamp": "2025-08-06T22:00:00Z", '
+    '"ping": {"jitter": 1.234, "latency": 9.876}, '
+    '"download": {"bandwidth": 10000000, "bytes": 80000000, "elapsed": 8000}, '
+    '"upload": {"bandwidth": 2000000, "bytes": 16000000, "elapsed": 8000}}'
+)  # Missing download/upload latency and packetLoss
+
 # Mock data for Wi-Fi diagnostics
 WIFI_DIAG_OUTPUT = "RSSI: -55\nNoise: -90\nTxRate: 866\nChannel: 149,80"
 ARP_OUTPUT = "? (192.168.1.1) at a1:b2:c3:d4:e5:f6 on en0 ifscope [ethernet]"
@@ -142,6 +153,29 @@ def test_local_speed_test_parsing(mock_run, mock_exists):
     assert results.get("local_downstream_speed") == 300.0
     assert results.get("local_upstream_speed") == 20.0
     assert results.get("local_speedtest_jitter") == 2.789
+    assert results.get("local_latency_down_load_ms") == 75.5
+    assert results.get("local_latency_up_load_ms") == 42.0
+    assert results.get("local_packet_loss_pct") == 0.25
+
+
+@patch("main.os.path.exists", return_value=True)
+@patch("main.subprocess.run")
+def test_local_speed_test_parsing_missing_keys(mock_run, mock_exists):
+    """Ookla JSON may omit latency/packetLoss; defaults should be 0.0 without errors."""
+    mock_run.return_value = MagicMock(
+        stdout=SPEEDTEST_JSON_OUTPUT_MISSING, returncode=0, stderr=""
+    )
+    results = run_local_speed_test_task()
+    assert results is not None
+    # Speeds should parse
+    assert results.get("local_downstream_speed") == 80.0  # 10,000,000 * 8 / 1e6
+    assert results.get("local_upstream_speed") == 16.0  # 2,000,000 * 8 / 1e6
+    # Jitter present from ping
+    assert results.get("local_speedtest_jitter") == 1.234
+    # Missing fields default to 0.0
+    assert results.get("local_latency_down_load_ms") == 0.0
+    assert results.get("local_latency_up_load_ms") == 0.0
+    assert results.get("local_packet_loss_pct") == 0.0
 
 
 @patch("main.subprocess.run")