From bd01440e9d8c6e8ebe3f5fb3645905cb9d835526 Mon Sep 17 00:00:00 2001 From: oliver Date: Sat, 5 Sep 2026 03:30:59 +0800 Subject: [PATCH] Fix empty Cisco IOSv CLI output and harden Windows stop/start. Drain leftover prompts before Netmiko send_command, and make stop/start tolerate orphan workers and locked log files. Co-authored-by: Cursor --- netx_api/ne_collect_runner.py | 8 ++++ netx_api/ne_netmiko.py | 78 +++++++++++++++++++++++++++++++---- scripts/start_netx.ps1 | 25 ++++++++--- scripts/stop_netx.ps1 | 76 +++++++++++++++++++--------------- tests/test_ne_netmiko_show.py | 49 ++++++++++++++++++++++ 5 files changed, 187 insertions(+), 49 deletions(-) create mode 100644 tests/test_ne_netmiko_show.py diff --git a/netx_api/ne_collect_runner.py b/netx_api/ne_collect_runner.py index 870fb0a..bca7e06 100644 --- a/netx_api/ne_collect_runner.py +++ b/netx_api/ne_collect_runner.py @@ -97,6 +97,14 @@ def _collect_on_device( except Exception: _log.debug("collection paging disable failed", exc_info=True) prompt = str(conn.find_prompt() or "") + # find_prompt / paging-off often leave an extra prompt in the channel; + # drain before the first show or Netmiko returns empty (IOSv). + try: + from .ne_netmiko import drain_read_channel + + drain_read_channel(conn) + except Exception: + _log.debug("collection channel drain failed", exc_info=True) for command in commands: if conn_holder is not None and conn_holder.get("timed_out"): raise TimeoutError("collection_aborted") diff --git a/netx_api/ne_netmiko.py b/netx_api/ne_netmiko.py index f1acdd0..b722bfd 100644 --- a/netx_api/ne_netmiko.py +++ b/netx_api/ne_netmiko.py @@ -95,18 +95,45 @@ def disable_target_paging( return "".join(chunks) -def send_show_command(conn: Any, command: str, *, read_timeout: int = 120) -> str: - """Send a show/display command via ``send_command`` (wait for device prompt). +def drain_read_channel( + conn: Any, + *, + idle_reads: int = 4, + pause_sec: float = 0.05, +) -> str: + """Read until the SSH/Telnet channel is quiet. - Do not use ``send_command_timing`` for Cisco config collection: long idle during - ``Building configuration...`` is treated as end-of-output and truncates the config. - - ``cmd_verify=False``: Netmiko's default echo check often raises - ``Pattern not detected: 'show\\ lldp\\ ...'`` on IOSv / hop / slow echo paths. + Cisco IOSv (and similar) often leave an extra ``R2#`` in the buffer after + ``find_prompt`` / ``terminal length 0``. Netmiko ``send_command`` then matches + that leftover prompt immediately and returns empty after strip — while a + human terminal still echoes show output normally. """ - cmd = str(command or "").strip() - if not cmd: + chunks: list[str] = [] + idle = 0 + read = getattr(conn, "read_channel", None) + if not callable(read): + clear = getattr(conn, "clear_buffer", None) + if callable(clear): + try: + clear() + except Exception: + pass return "" + while idle < max(1, int(idle_reads)): + try: + part = read() + except Exception: + break + if part: + chunks.append(str(part)) + idle = 0 + continue + idle += 1 + time.sleep(max(0.0, float(pause_sec))) + return "".join(chunks) + + +def _send_command_expect_prompt(conn: Any, cmd: str, *, read_timeout: int) -> str: try: return str( conn.send_command( @@ -119,3 +146,36 @@ def send_show_command(conn: Any, command: str, *, read_timeout: int = 120) -> st except TypeError: # Older Netmiko without cmd_verify kwarg. return str(conn.send_command(command_string=cmd, read_timeout=read_timeout) or "") + + +def send_show_command(conn: Any, command: str, *, read_timeout: int = 120) -> str: + """Send a show/display command via ``send_command`` (wait for device prompt). + + Do not use ``send_command_timing`` as the primary path for Cisco config + collection: long idle during ``Building configuration...`` is treated as + end-of-output and truncates the config. Timing is only a fallback when + expect-prompt returns empty after a channel drain (IOSv leftover-prompt bug). + + ``cmd_verify=False``: Netmiko's default echo check often raises + ``Pattern not detected: 'show\\ lldp\\ ...'`` on IOSv / hop / slow echo paths. + """ + cmd = str(command or "").strip() + if not cmd: + return "" + + drain_read_channel(conn) + out = _send_command_expect_prompt(conn, cmd, read_timeout=read_timeout) + if out.strip(): + return out + + # Leftover prompt matched before command echo — drain again and retry once. + drain_read_channel(conn) + out = _send_command_expect_prompt(conn, cmd, read_timeout=read_timeout) + if out.strip(): + return out + + drain_read_channel(conn) + try: + return str(conn.send_command_timing(cmd, read_timeout=read_timeout) or "") + except Exception: + return "" diff --git a/scripts/start_netx.ps1 b/scripts/start_netx.ps1 index ab6852d..9da9eed 100644 --- a/scripts/start_netx.ps1 +++ b/scripts/start_netx.ps1 @@ -131,25 +131,38 @@ function Test-NetxApiListening { return $false } +function Reset-LogFile { + param([string]$Path) + try { + Set-Content -Path $Path -Value "" -Encoding utf8 -ErrorAction Stop + return $Path + } catch { + $alt = "$Path.$(Get-Date -Format 'yyyyMMdd_HHmmss')" + Write-Host "[WARN] cannot truncate $Path ($($_.Exception.Message))" -ForegroundColor Yellow + Write-Host " using $alt (old worker may still hold the previous file; run stop_netx.ps1 elevated)" -ForegroundColor Yellow + return $alt + } +} + function Start-NetxWorker { if ($InlineSchedulers) { return } - Set-Content -Path $workerLogFile -Value "" -Encoding utf8 - Set-Content -Path $workerErrFile -Value "" -Encoding utf8 + $outLog = Reset-LogFile -Path $workerLogFile + $errLog = Reset-LogFile -Path $workerErrFile Write-Host "==> Starting netx worker (config_sync / lldp / port_traffic)" $workerProc = Start-Process -FilePath $pythonExe ` -ArgumentList @("-m", "netx_api.worker") ` -WorkingDirectory $projectRoot ` -WindowStyle Hidden ` - -RedirectStandardOutput $workerLogFile ` - -RedirectStandardError $workerErrFile ` + -RedirectStandardOutput $outLog ` + -RedirectStandardError $errLog ` -PassThru Set-Content -Path $workerPidFile -Value "$($workerProc.Id)" Write-Host "worker.pid = $workerPidFile" Write-Host "PID = $($workerProc.Id)" - Write-Host "Log = $workerLogFile" - Write-Host "Err = $workerErrFile" + Write-Host "Log = $outLog" + Write-Host "Err = $errLog" Start-Sleep -Seconds 1 $alive = $false try { diff --git a/scripts/stop_netx.ps1 b/scripts/stop_netx.ps1 index 8b4fbaa..270bb2e 100644 --- a/scripts/stop_netx.ps1 +++ b/scripts/stop_netx.ps1 @@ -1,16 +1,35 @@ param( [int]$Port = 8890, [int]$WebPort = 5173, - [switch]$Force = $false + # Windows often ignores graceful Stop-Process on python; default hard-kill. + [switch]$Force = $true, + [switch]$NoForce = $false ) $ErrorActionPreference = "Continue" +$useForce = if ($NoForce) { $false } else { [bool]$Force } $runDir = Join-Path $PSScriptRoot ".run" $pidFile = Join-Path $runDir "netx.pid" $workerPidFile = Join-Path $runDir "worker.pid" $webPidFile = Join-Path $runDir "web.pid" +function Stop-OnePid { + param([int]$ProcId, [string]$Label) + if ($ProcId -le 4) { return } + if ($ProcId -eq $PID) { return } + try { + Stop-Process -Id $ProcId -Force:$useForce -ErrorAction Stop + Write-Host "Stopped $Label PID=$ProcId" + } catch { + $msg = $_.Exception.Message + Write-Host "[WARN] Failed to stop $Label PID=$ProcId : $msg" + if ($msg -match 'Access|Denied|拒绝|拒绝访问') { + Write-Host " Run elevated PowerShell, then: taskkill /F /PID $ProcId" -ForegroundColor Yellow + } + } +} + function Get-ListenPids { param([int]$LocalPort) $ids = [System.Collections.Generic.HashSet[int]]::new() @@ -40,19 +59,28 @@ function Get-ListenPids { @($ids) } -Write-Host "==> Stopping netx" +function Stop-NetxByCommandLine { + # Orphan workers often have no worker.pid but still hold worker.out.log. + $hits = @(Get-CimInstance Win32_Process -ErrorAction SilentlyContinue | + Where-Object { $_.CommandLine -match 'netx_api\.(main|worker)' }) + if ($hits.Count -eq 0) { + Write-Host "[INFO] No netx_api.main/worker process by command line" + return + } + foreach ($p in $hits) { + $kind = if ($p.CommandLine -match 'netx_api\.worker') { "worker(cmd)" } else { "api(cmd)" } + Stop-OnePid -ProcId ([int]$p.ProcessId) -Label $kind + } +} + +Write-Host "==> Stopping netx (Force=$useForce)" if (Test-Path $pidFile) { $pidText = (Get-Content -Path $pidFile -ErrorAction SilentlyContinue | Select-Object -First 1) $procId = 0 [void][int]::TryParse("$pidText", [ref]$procId) if ($procId -gt 0) { - try { - Stop-Process -Id $procId -Force:$Force -ErrorAction Stop - Write-Host "Stopped API PID=$procId" - } catch { - Write-Host "[WARN] PID file process not running: $procId" - } + Stop-OnePid -ProcId $procId -Label "API" } Remove-Item -Path $pidFile -Force -ErrorAction SilentlyContinue } else { @@ -64,12 +92,7 @@ if (Test-Path $workerPidFile) { $workerProcId = 0 [void][int]::TryParse("$workerPidText", [ref]$workerProcId) if ($workerProcId -gt 0) { - try { - Stop-Process -Id $workerProcId -Force:$Force -ErrorAction Stop - Write-Host "Stopped worker PID=$workerProcId" - } catch { - Write-Host "[WARN] worker PID file process not running: $workerProcId" - } + Stop-OnePid -ProcId $workerProcId -Label "worker" } Remove-Item -Path $workerPidFile -Force -ErrorAction SilentlyContinue } else { @@ -81,26 +104,17 @@ if (Test-Path $webPidFile) { $webProcId = 0 [void][int]::TryParse("$webPidText", [ref]$webProcId) if ($webProcId -gt 0) { - try { - Stop-Process -Id $webProcId -Force:$Force -ErrorAction Stop - Write-Host "Stopped web PID=$webProcId" - } catch { - Write-Host "[WARN] web PID file process not running: $webProcId" - } + Stop-OnePid -ProcId $webProcId -Label "web" } Remove-Item -Path $webPidFile -Force -ErrorAction SilentlyContinue } +Stop-NetxByCommandLine + $owningApi = @(Get-ListenPids -LocalPort $Port) if ($owningApi.Count -gt 0) { foreach ($procId in $owningApi) { - if ($procId -eq $PID) { continue } - try { - Stop-Process -Id $procId -Force:$Force -ErrorAction Stop - Write-Host "Stopped by port PID=$procId" - } catch { - Write-Host "[WARN] Failed to stop PID=$procId by port" - } + Stop-OnePid -ProcId $procId -Label "port:$Port" } } else { Write-Host "[INFO] No listener found on port $Port" @@ -109,13 +123,7 @@ if ($owningApi.Count -gt 0) { $owningWeb = @(Get-ListenPids -LocalPort $WebPort) if ($owningWeb.Count -gt 0) { foreach ($procId in $owningWeb) { - if ($procId -eq $PID) { continue } - try { - Stop-Process -Id $procId -Force:$Force -ErrorAction Stop - Write-Host "Stopped web by port PID=$procId" - } catch { - Write-Host "[WARN] Failed to stop web PID=$procId by port" - } + Stop-OnePid -ProcId $procId -Label "port:$WebPort" } } else { Write-Host "[INFO] No listener found on web port $WebPort" diff --git a/tests/test_ne_netmiko_show.py b/tests/test_ne_netmiko_show.py new file mode 100644 index 0000000..dd1b285 --- /dev/null +++ b/tests/test_ne_netmiko_show.py @@ -0,0 +1,49 @@ +"""Tests for Netmiko show helpers (IOSv leftover-prompt drain / retry).""" + +from __future__ import annotations + +import unittest +from unittest.mock import MagicMock, call, patch + +from netx_api.ne_netmiko import drain_read_channel, send_show_command + + +class DrainReadChannelTests(unittest.TestCase): + def test_drains_until_idle(self) -> None: + conn = MagicMock() + conn.read_channel.side_effect = ["R2#\n", "", "", "", ""] + out = drain_read_channel(conn, idle_reads=3, pause_sec=0.0) + self.assertEqual(out, "R2#\n") + self.assertGreaterEqual(conn.read_channel.call_count, 4) + + def test_clear_buffer_when_no_read_channel(self) -> None: + conn = MagicMock(spec=["clear_buffer"]) + self.assertEqual(drain_read_channel(conn), "") + conn.clear_buffer.assert_called_once() + + +class SendShowCommandTests(unittest.TestCase): + @patch("netx_api.ne_netmiko.drain_read_channel") + def test_returns_first_nonempty_send_command(self, drain: MagicMock) -> None: + conn = MagicMock() + conn.send_command.return_value = "*12:00:00 UTC" + out = send_show_command(conn, "show clock", read_timeout=30) + self.assertEqual(out, "*12:00:00 UTC") + conn.send_command.assert_called_once() + conn.send_command_timing.assert_not_called() + drain.assert_called() + + @patch("netx_api.ne_netmiko.drain_read_channel") + def test_retries_then_falls_back_to_timing_when_empty(self, drain: MagicMock) -> None: + conn = MagicMock() + conn.send_command.return_value = "" + conn.send_command_timing.return_value = "Cisco IOS Software" + out = send_show_command(conn, "show version", read_timeout=30) + self.assertEqual(out, "Cisco IOS Software") + self.assertEqual(conn.send_command.call_count, 2) + conn.send_command_timing.assert_called_once_with("show version", read_timeout=30) + self.assertGreaterEqual(drain.call_count, 2) + + +if __name__ == "__main__": + unittest.main()