|
| 1 | +# Live clinic debugging |
| 2 | + |
| 3 | +> **When to use**: On-the-day support for a live clinic — checking worklist delivery, |
| 4 | +> image receipt and upload from the gateway VM, and tracing problems through the |
| 5 | +> Azure logs for both the gateway and Manage. |
| 6 | +
|
| 7 | +Two vantage points: |
| 8 | + |
| 9 | +- **The gateway VM** (RDP) — direct access to the MWL/PACS SQLite databases, DICOM |
| 10 | + storage and service logs. Use [`scripts/powershell/debug_toolkit.ps1`](../../../scripts/powershell/debug_toolkit.ps1). |
| 11 | +- **Your laptop** (Azure CLI / portal) — Application Insights for the gateway |
| 12 | + services, container app logs for Manage, and Azure Relay connection health. |
| 13 | + |
| 14 | +## The pipeline at a glance |
| 15 | + |
| 16 | +``` |
| 17 | +Manage (container app) |
| 18 | + │ worklist item ─── Azure Relay (relay-manbrs-prod / hc-<machine>) ──► Gateway-Relay |
| 19 | + │ │ |
| 20 | + │ writes data\worklist.db |
| 21 | + │ │ |
| 22 | +Modality ── C-FIND (port 104) ──► Gateway-MWL ◄── reads worklist.db ──────────┘ |
| 23 | +Modality ── C-STORE (port 11112) ──► Gateway-PACS ──► data\storage + data\pacs.db |
| 24 | + │ |
| 25 | +Manage /api/v1/dicom ◄── HTTPS upload (managed identity) ── Gateway-Upload |
| 26 | +``` |
| 27 | + |
| 28 | +A failure at any hop has a distinct signature — the sections below work through them |
| 29 | +in pipeline order. |
| 30 | + |
| 31 | +## On the gateway VM |
| 32 | + |
| 33 | +Copy `debug_toolkit.ps1` to the VM (or paste it into an editor there), then: |
| 34 | + |
| 35 | +```powershell |
| 36 | +. .\debug_toolkit.ps1 |
| 37 | +Get-GwHealth # start here: services, ports, relay connection, disk |
| 38 | +``` |
| 39 | + |
| 40 | +Reference points: |
| 41 | + |
| 42 | +| Thing | Where | |
| 43 | +|---|---| |
| 44 | +| Install root | `C:\Program Files\NHS\ManageBreastScreeningGateway` | |
| 45 | +| Services (NSSM) | `Gateway-Relay`, `Gateway-MWL`, `Gateway-PACS`, `Gateway-Upload` | |
| 46 | +| Worklist DB (SQLite) | `data\worklist.db` — table `worklist_items` | |
| 47 | +| PACS DB (SQLite) | `data\pacs.db` — table `stored_instances` | |
| 48 | +| DICOM files | `data\storage\` (hash-based directory layout; use `Get-GwDicomFiles`) | |
| 49 | +| Service logs | `logs\Gateway-<Service>.log` (NSSM stdout+stderr) | |
| 50 | +| Deployment logs | `logs\deployments\deploy-*` | |
| 51 | +| Config | `.env` in the install root | |
| 52 | +| MWL | AET `RUBIE_MWL_PROD`, port 104 | |
| 53 | +| PACS | AET `RUBIE_PACS_PROD`, port 11112 | |
| 54 | + |
| 55 | +### Symptom → first command |
| 56 | + |
| 57 | +| Symptom | Check | |
| 58 | +|---|---| |
| 59 | +| Appointment checked in on Manage but not on the modality worklist | `Get-GwWorklist` — is the item in the DB? If **no**: relay hop failed → `Watch-GwLog Relay`, then the Azure Relay + Manage sections below. If **yes**: modality⇄MWL hop → `Watch-GwLog MWL` while the modality refreshes; confirm port 104 listening; scheduled_date is stored in **UTC** `YYYYMMDD` | |
| 60 | +| Exposure taken but images not on the VM | `Watch-GwLog PACS` while the modality sends; `Get-GwImages`; confirm port 11112 and that the modality is configured with AE title `RUBIE_PACS_PROD`, correct IP and port | |
| 61 | +| Images on VM but not appearing in Manage | `Get-GwUploadFailures` — look at `upload_error` and `upload_attempt_count`; `Watch-GwLog Upload`. Auth errors here usually mean the Arc managed identity / `Gateway.Access` app role or `Gateway.oid` in Manage is wrong | |
| 62 | +| Item status stuck at SCHEDULED after procedure started | `Get-GwWorklistItem <ACC>` — MPPS updates set `status` / `mpps_instance_uid`; check `Watch-GwLog MWL` for MPPS N-CREATE/N-SET messages | |
| 63 | +| Anything crashing / restart loops | `Search-GwLogs`; `Get-Service Gateway-*` (NSSM restarts failed services automatically — repeated banner lines in the log mean crash-looping) | |
| 64 | + |
| 65 | +## From your laptop — Azure |
| 66 | + |
| 67 | +```bash |
| 68 | +az account set --subscription "Breast Screening - Manage Breast Screening - Prod" |
| 69 | +``` |
| 70 | + |
| 71 | +### Gateway service telemetry (Application Insights) |
| 72 | + |
| 73 | +All four VM services send OpenTelemetry to `ai-mbsgw-prod-arc-uks` |
| 74 | +(resource group `rg-mbsgw-prod-uks-arc-enabled-servers`). `cloud_RoleName` values: |
| 75 | +`relay-listener`, `mwl-server`, `pacs-server`, `upload-listener`. |
| 76 | + |
| 77 | +```bash |
| 78 | +# Errors and warnings in the last hour, all services |
| 79 | +az monitor app-insights query \ |
| 80 | + --app ai-mbsgw-prod-arc-uks -g rg-mbsgw-prod-uks-arc-enabled-servers \ |
| 81 | + --analytics-query "traces |
| 82 | + | where timestamp > ago(1h) and severityLevel >= 2 |
| 83 | + | project timestamp, cloud_RoleName, message |
| 84 | + | order by timestamp desc" -o table |
| 85 | + |
| 86 | +# Exceptions with stack traces |
| 87 | +az monitor app-insights query \ |
| 88 | + --app ai-mbsgw-prod-arc-uks -g rg-mbsgw-prod-uks-arc-enabled-servers \ |
| 89 | + --analytics-query "exceptions |
| 90 | + | where timestamp > ago(4h) |
| 91 | + | project timestamp, cloud_RoleName, type, outerMessage |
| 92 | + | order by timestamp desc" -o table |
| 93 | + |
| 94 | +# Everything one service said in a window (e.g. relay listener around a failure) |
| 95 | +az monitor app-insights query \ |
| 96 | + --app ai-mbsgw-prod-arc-uks -g rg-mbsgw-prod-uks-arc-enabled-servers \ |
| 97 | + --analytics-query "traces |
| 98 | + | where timestamp > ago(1h) and cloud_RoleName == 'relay-listener' |
| 99 | + | project timestamp, message | order by timestamp desc" -o table |
| 100 | +``` |
| 101 | + |
| 102 | +Portal equivalent: the App Insights resource → **Logs**, or **Live Metrics** for |
| 103 | +real-time output during the clinic. |
| 104 | + |
| 105 | +> Telemetry is a no-op if `APPLICATIONINSIGHTS_CONNECTION_STRING` wasn't set at |
| 106 | +> deploy time — if queries return nothing at all, fall back to the VM logs and |
| 107 | +> check the deploy log for the "Application Insights resource not found" warning. |
| 108 | +
|
| 109 | +### Azure Relay connection health |
| 110 | + |
| 111 | +The namespace is `relay-manbrs-prod` in `rg-manbrs-prod-uks`; the Hull hybrid |
| 112 | +connection is `hc-<arc-machine-name>`. |
| 113 | + |
| 114 | +```bash |
| 115 | +# Does the HC exist / listener count (listenerCount > 0 means the VM is connected) |
| 116 | +az relay hyco show --namespace-name relay-manbrs-prod -g rg-manbrs-prod-uks \ |
| 117 | + -n hc-gw-hull-university-teaching-hospitals-nhs-trust-rwa-01 \ |
| 118 | + --query "{name:name, listenerCount:listenerCount}" |
| 119 | + |
| 120 | +# Namespace metrics: listeners and sender connections over the morning |
| 121 | +az monitor metrics list \ |
| 122 | + --resource "$(az relay namespace show -g rg-manbrs-prod-uks -n relay-manbrs-prod --query id -o tsv)" \ |
| 123 | + --metric "ListenerConnections-Success" "SenderConnections-Success" "ListenerConnections-ClientError" \ |
| 124 | + --interval PT5M --offset 4h -o table |
| 125 | +``` |
| 126 | + |
| 127 | +`listenerCount: 0` means `Gateway-Relay` on the VM is not connected — check the |
| 128 | +service on the VM (`Watch-GwLog Relay`; look for "Connected - waiting for worklist |
| 129 | +actions"). Sender client errors while listeners are healthy point at the Manage side |
| 130 | +(its managed identity / `AZURE_RELAY_CLIENT_ID`). |
| 131 | + |
| 132 | +> **Beware the zombie listener**: `listenerCount: 1` does not prove the listener is |
| 133 | +> *functional* — a connection that died without a clean close can stay registered |
| 134 | +> while rendezvous dispatches go nowhere. The echo probe below is the truth test. |
| 135 | +
|
| 136 | +### The echo probe — test the relay → gateway path without Manage |
| 137 | + |
| 138 | +[`scripts/diagnostics/relay_echo_probe.py`](../../../scripts/diagnostics/relay_echo_probe.py) |
| 139 | +connects to the hybrid connection **as a sender** (exactly like Manage does), sends an |
| 140 | +`echo` action — which the relay listener answers without touching its database — and |
| 141 | +waits for the reply. It needs only Python, `pip install websockets`, and a credential; |
| 142 | +no Azure login, runnable from any laptop. |
| 143 | + |
| 144 | +```bash |
| 145 | +python scripts/diagnostics/relay_echo_probe.py \ |
| 146 | + --namespace relay-manbrs-prod.servicebus.windows.net \ |
| 147 | + --hc hc-gw-hull-university-teaching-hospitals-nhs-trust-rwa-01 \ |
| 148 | + --key '<RootManageSharedAccessKey value>' # namespace-level key, NOT the HC's listen-only key |
| 149 | +``` |
| 150 | + |
| 151 | +| Result | Meaning | |
| 152 | +|---|---| |
| 153 | +| `RESPONSE` in <1s | Relay and gateway listener fully healthy → the fault is on Manage's side | |
| 154 | +| `TIMEOUT` waiting for reply | Sender accepted but listener never answered → zombie listener or gateway-side fault; restart `Gateway-Relay` and retry | |
| 155 | +| `CONNECT FAILED: HTTP 401` | Bad key — the per-HC `listen` policy key cannot send; use the namespace root key | |
| 156 | +| `CONNECT FAILED: HTTP 404` | Wrong HC name, or no listener registered at all | |
| 157 | + |
| 158 | +There is also `--bearer-token` mode (see the script's docstring) to test the AAD |
| 159 | +bearer path Manage uses in production. To run the probe from *inside* the Manage |
| 160 | +container (testing Manage's actual network/DNS/identity), see the container-side |
| 161 | +snippet in the script's docstring — during the July 2026 incident that variant is |
| 162 | +what exposed the relay hostname resolving to a private endpoint IP inside the VNet. |
| 163 | + |
| 164 | +Rotate the namespace key after a debugging session — nothing in a deployed |
| 165 | +environment uses SAS, so rotation is free. |
| 166 | + |
| 167 | +### Manage application logs |
| 168 | + |
| 169 | +Discover the names once (they come from the shared naming module, so don't guess): |
| 170 | + |
| 171 | +```bash |
| 172 | +az containerapp list -g rg-manbrs-prod-uks --query "[].name" -o tsv |
| 173 | +az monitor log-analytics workspace list -g rg-manbrs-prod-uks --query "[].{name:name, id:customerId}" -o table |
| 174 | +``` |
| 175 | + |
| 176 | +Then either live-stream: |
| 177 | + |
| 178 | +```bash |
| 179 | +az containerapp logs show -n <app-name> -g rg-manbrs-prod-uks --type console --follow --tail 50 |
| 180 | +``` |
| 181 | + |
| 182 | +or query Log Analytics (better for searching): |
| 183 | + |
| 184 | +```bash |
| 185 | +# Worklist-send activity and errors from the gateway app code |
| 186 | +az monitor log-analytics query --workspace <workspace-customer-id> \ |
| 187 | + --analytics-query "ContainerAppConsoleLogs_CL |
| 188 | + | where TimeGenerated > ago(2h) |
| 189 | + | where Log_s has_any ('relay', 'GatewayAction', 'worklist', 'ERROR', 'Traceback') |
| 190 | + | project TimeGenerated, Log_s | order by TimeGenerated desc" -o table |
| 191 | + |
| 192 | +# Incoming DICOM uploads from the gateway (the /api/v1/dicom endpoint) |
| 193 | +az monitor log-analytics query --workspace <workspace-customer-id> \ |
| 194 | + --analytics-query "ContainerAppConsoleLogs_CL |
| 195 | + | where TimeGenerated > ago(2h) |
| 196 | + | where Log_s has 'dicom' |
| 197 | + | project TimeGenerated, Log_s | order by TimeGenerated desc" -o table |
| 198 | +``` |
| 199 | + |
| 200 | +Manage-side data checks (worklist item actually created and sent?) are quickest in |
| 201 | +the Django admin: **Gateway actions** — a healthy send is `status: confirmed`; |
| 202 | +`failed` rows carry `last_error` and the retry schedule. |
| 203 | + |
| 204 | +## Pre-flight checklist (run before the clinic starts) |
| 205 | + |
| 206 | +On the VM: |
| 207 | + |
| 208 | +1. `Get-GwHealth` — all four services **Running**, ports 104 and 11112 listening, |
| 209 | + relay log shows "Connected - waiting for worklist actions", disk has headroom. |
| 210 | +2. `Get-GwWorklist` — after the first participant is checked in on Manage, the item |
| 211 | + appears here within seconds. That one check proves Manage → Relay → VM end to end. |
| 212 | +3. On the modality: query the worklist and confirm the participant is listed. |
| 213 | + |
| 214 | +From the laptop: |
| 215 | + |
| 216 | +4. `az relay hyco show ... --query listenerCount` returns ≥ 1. |
| 217 | +5. App Insights errors query over `ago(12h)` is quiet (no crash loops overnight). |
| 218 | + |
| 219 | +## During the clinic — a useful passive setup |
| 220 | + |
| 221 | +On the VM, keep two windows open: |
| 222 | + |
| 223 | +```powershell |
| 224 | +Watch-GwLog PACS # window 1 — see each C-STORE arrive |
| 225 | +Watch-GwLog Upload # window 2 — see each upload to Manage |
| 226 | +``` |
| 227 | + |
| 228 | +After each participant: `Get-GwImages` should show the expected image count with |
| 229 | +`uploaded` equal to `images` within a minute or two. |
0 commit comments