gsadmin/pulse
1
0
Fork 0
mirror of https://github.com/rcourtman/Pulse.git synced 2026-10-26 05:29:45 +00:00
Code Issues Packages Projects Releases Wiki Activity

Integrate reviewed fail-closed diagnostic log recipes

Browse Source 
Combine exact reviewed Delivery 203d1a8fb5 and Product intelligence e95e53cf9e. Disjoint CI helper and documentation/test changes retain their complete exact-source proof; no resolution or source correction is needed.

Contract-Neutral: Integration of existing CI error handling and read-only troubleshooting recipes; no runtime, API, permissions, settings or navigation contract changes.
Change-source: pulse-maintainer
This commit is contained in:
pulse-triage[bot]
2026-10-07 04:17:59 +01:00
parent 203d1a8fb5 e95e53cf9e
commit 3335fc29fc
4 changed files with 277 additions and 90 deletions
Download Patch File Download Diff File Expand all files Collapse all files
docs/TROUBLESHOOTING.md
+80 -12
View File
@@ -837,18 +837,54 @@ inside the Pulse container, not on the Proxmox host. Adjust the time window to
the original incident and substitute your actual service or container name
(`pulse-backend` on some older systemd installs). These examples read at most
200 records from the last 15 minutes; they do not follow the log or send a test.
Each requires **GNU `timeout`** and gives the reader eight seconds plus a
one-second termination grace. If it is unavailable, stop rather than running
an unbounded substitute. These are Bash examples; the enclosing subshell keeps
an unavailable read from exiting your interactive shell.
```bash
# systemd / Proxmox LXC
journalctl -u pulse --since '15 minutes ago' --lines 200 --no-pager
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s journalctl -u pulse --since '15 minutes ago' --lines 200 --no-pager 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs"
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
```bash
# Docker
docker logs --since 15m --tail 200 pulse
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s docker logs --since 15m --tail 200 pulse 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs"
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
Docker can write application logs to either stdout or stderr; inspect both.
Application logs can be written to stdout or stderr; these commands collect
both into one local excerpt, without preserving stdout/stderr attribution,
and display it **only after the reader completes successfully**.
A failed or timed-out read displays only an unavailable message and its exit
code, not a partial excerpt that could be mistaken for complete evidence.
Do not pipe the reader into `grep email`: it can miss SMTP or webhook errors
and hide a failed read behind a matching partial line. A nonzero reader exit,
access error or missing service/container is a failed read, not “no delivery
@@ -876,29 +912,61 @@ Replace `abc123` below with the response's ID. Run only the command for your
deployment, on the Pulse host using an account authorised to read its logs.
These examples limit collection to the last 15 minutes and 1,000 lines; adjust
the time window to the original incident rather than repeating the failed action.
Like the notification-log examples above, these require **GNU `timeout`**,
allow eight seconds plus a one-second termination grace, and search **only a
successfully completed read**. A deadline or failure shows no partial match;
missing `timeout` does not fall back to an unbounded reader.
```bash
# systemd / Proxmox LXC
set -o pipefail
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
REQUEST_ID='abc123'
journalctl -u pulse --since '15 minutes ago' --lines 1000 --no-pager |
grep -F -- "$REQUEST_ID"
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s journalctl -u pulse --since '15 minutes ago' --lines 1000 --no-pager 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
else
exit 1
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
```bash
# Docker
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
REQUEST_ID='abc123'
if pulse_logs=$(docker logs --since 15m --tail 1000 pulse 2>&1); then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s docker logs --since 15m --tail 1000 pulse 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
else
exit 1
fi
else
printf '%s\n' "$pulse_logs" >&2
false
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
A log-reader failure is not an empty search result: resolve any access or
container/service error locally first. Even a successful read with no match
does not prove the request succeeded. At the default log level, this middleware
container/service error locally first. Exit **124** means the reader exceeded
the deadline; **137** can mean the termination grace also elapsed. Neither
establishes that Pulse itself is hung. Do not restart Pulse or Docker, enable
Debug, widen collection or repeat the failed action merely to obtain logs.
Even a successful read with no match does not prove the request succeeded. At the default log level, this middleware
logs HTTP 5xx failures but not successful requests; HTTP 4xx failures are logged
at debug level. The selected window, retained logs or deployment may also differ.
Keep the original response status, time and ID even when there is no matching log;
frontend-modern/public/docs/TROUBLESHOOTING.md
+80 -12
View File
@@ -837,18 +837,54 @@ inside the Pulse container, not on the Proxmox host. Adjust the time window to
the original incident and substitute your actual service or container name
(`pulse-backend` on some older systemd installs). These examples read at most
200 records from the last 15 minutes; they do not follow the log or send a test.
Each requires **GNU `timeout`** and gives the reader eight seconds plus a
one-second termination grace. If it is unavailable, stop rather than running
an unbounded substitute. These are Bash examples; the enclosing subshell keeps
an unavailable read from exiting your interactive shell.
```bash
# systemd / Proxmox LXC
journalctl -u pulse --since '15 minutes ago' --lines 200 --no-pager
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s journalctl -u pulse --since '15 minutes ago' --lines 200 --no-pager 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs"
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
```bash
# Docker
docker logs --since 15m --tail 200 pulse
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s docker logs --since 15m --tail 200 pulse 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs"
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
Docker can write application logs to either stdout or stderr; inspect both.
Application logs can be written to stdout or stderr; these commands collect
both into one local excerpt, without preserving stdout/stderr attribution,
and display it **only after the reader completes successfully**.
A failed or timed-out read displays only an unavailable message and its exit
code, not a partial excerpt that could be mistaken for complete evidence.
Do not pipe the reader into `grep email`: it can miss SMTP or webhook errors
and hide a failed read behind a matching partial line. A nonzero reader exit,
access error or missing service/container is a failed read, not “no delivery
@@ -876,29 +912,61 @@ Replace `abc123` below with the response's ID. Run only the command for your
deployment, on the Pulse host using an account authorised to read its logs.
These examples limit collection to the last 15 minutes and 1,000 lines; adjust
the time window to the original incident rather than repeating the failed action.
Like the notification-log examples above, these require **GNU `timeout`**,
allow eight seconds plus a one-second termination grace, and search **only a
successfully completed read**. A deadline or failure shows no partial match;
missing `timeout` does not fall back to an unbounded reader.
```bash
# systemd / Proxmox LXC
set -o pipefail
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
REQUEST_ID='abc123'
journalctl -u pulse --since '15 minutes ago' --lines 1000 --no-pager |
grep -F -- "$REQUEST_ID"
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s journalctl -u pulse --since '15 minutes ago' --lines 1000 --no-pager 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
else
exit 1
fi
else
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
```bash
# Docker
(
command -v timeout >/dev/null 2>&1 || {
printf 'Log read unavailable: GNU timeout is required; no unbounded fallback.\n' >&2
exit 1
}
REQUEST_ID='abc123'
if pulse_logs=$(docker logs --since 15m --tail 1000 pulse 2>&1); then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
if pulse_logs=$(timeout --signal=TERM --kill-after=1s 8s docker logs --since 15m --tail 1000 pulse 2>&1); then
if [ -n "$pulse_logs" ]; then
printf '%s\n' "$pulse_logs" | grep -F -- "$REQUEST_ID"
else
exit 1
fi
else
printf '%s\n' "$pulse_logs" >&2
false
pulse_log_status=$?
printf 'Log read unavailable (exit %s); no partial excerpt shown.\n' "$pulse_log_status" >&2
exit "$pulse_log_status"
fi
)
```
A log-reader failure is not an empty search result: resolve any access or
container/service error locally first. Even a successful read with no match
does not prove the request succeeded. At the default log level, this middleware
container/service error locally first. Exit **124** means the reader exceeded
the deadline; **137** can mean the termination grace also elapsed. Neither
establishes that Pulse itself is hung. Do not restart Pulse or Docker, enable
Debug, widen collection or repeat the failed action merely to obtain logs.
Even a successful read with no match does not prove the request succeeded. At the default log level, this middleware
logs HTTP 5xx failures but not successful requests; HTTP 4xx failures are logged
at debug level. The selected window, retained logs or deployment may also differ.
Keep the original response status, time and ID even when there is no matching log;
scripts/tests/test_notification_troubleshooting_docs.py
+42 -34
View File
@@ -7,14 +7,12 @@ not prove native installation, notification delivery or automatic redaction.
from __future__ import annotations
import json
import os
from pathlib import Path
import re
import subprocess
import tempfile
import unittest
from test_troubleshooting_logs import exercise_log_recipe
ROOT = Path(__file__).resolve().parents[2]
DOC = ROOT / "docs/TROUBLESHOOTING.md"
@@ -41,32 +39,14 @@ def recipes() -> dict[str, str]:
return {"docker" if "# Docker" in block else "journalctl": block for block in blocks}
READER = '''#!/usr/bin/env python3
import json, os, pathlib, sys
pathlib.Path(os.environ['READER_ARGV']).write_text(json.dumps(sys.argv[1:]))
sys.stdout.write(os.environ.get('LOG_STDOUT', ''))
sys.stderr.write(os.environ.get('LOG_STDERR', ''))
sys.exit(int(os.environ.get('READER_EXIT', '0')))
'''
class NotificationTroubleshootingDocsTest(unittest.TestCase):
def exercise(self, reader: str, *, stdout: str = "", stderr: str = "",
exit_code: int = 0, recipe: str | None = None):
with tempfile.TemporaryDirectory() as temporary:
directory = Path(temporary)
command = directory / reader
command.write_text(READER, encoding="utf-8")
command.chmod(0o700)
argv = directory / "argv.json"
env = dict(os.environ, PATH=f"{directory}:{os.environ['PATH']}",
READER_ARGV=str(argv), LOG_STDOUT=stdout, LOG_STDERR=stderr,
READER_EXIT=str(exit_code))
copied = recipe if recipe is not None else recipes()[reader]
result = subprocess.run(["bash", "-c", copied], env=env,
capture_output=True, text=True, timeout=5)
self.assertTrue(argv.exists(), "copied command did not invoke its log reader")
return result, json.loads(argv.read_text())
exit_code: int = 0, recipe: str | None = None, **settings):
copied = recipe if recipe is not None else recipes()[reader]
result, argv = exercise_log_recipe(reader, copied, stdout=stdout, stderr=stderr,
exit_code=exit_code, **settings)
self.assertEqual(argv is None, bool(settings.get("missing_timeout")))
return result, argv
def test_shipped_document_matches_the_tested_source(self):
self.assertEqual(DOC.read_bytes(),
@@ -84,13 +64,17 @@ class NotificationTroubleshootingDocsTest(unittest.TestCase):
self.assertEqual(result.returncode, 0, result.stderr)
self.assertEqual(argv, expected[reader])
self.assertEqual(result.stdout, SMTP_ERROR + WEBHOOK_ERROR)
self.assertNotRegex(copied, r"[|<>]|\b(?:grep|curl|inspect|restart|printenv)\b|--follow|--token")
self.assertNotRegex(copied, r"\b(?:grep|curl|inspect|restart|printenv)\b|--follow|--token")
self.assertIn("--signal=TERM --kill-after=1s 8s", copied)
def test_docker_application_logs_on_both_streams_remain_visible(self):
result, _ = self.exercise("docker", stdout=WEBHOOK_ERROR, stderr=SMTP_ERROR)
self.assertEqual(result.returncode, 0, result.stderr)
self.assertEqual(result.stdout, WEBHOOK_ERROR)
self.assertEqual(result.stderr, SMTP_ERROR)
# Independently buffered streams have no total ordering. Both records
# must survive, without inventing chronological order across streams.
self.assertCountEqual(result.stdout.splitlines(),
(WEBHOOK_ERROR + SMTP_ERROR).splitlines())
self.assertEqual(result.stderr, "")
def test_reader_failure_keeps_its_exit_even_after_a_partial_email_log(self):
for reader in recipes():
@@ -99,8 +83,32 @@ class NotificationTroubleshootingDocsTest(unittest.TestCase):
result, _ = self.exercise(reader, stdout=output,
stderr="synthetic reader access failure\n", exit_code=2)
self.assertEqual(result.returncode, 2)
self.assertEqual(result.stdout, output)
self.assertEqual(result.stderr, "synthetic reader access failure\n")
self.assertEqual(result.stdout, "")
self.assertIn("Log read unavailable (exit 2)", result.stderr)
self.assertNotIn("synthetic reader access failure", result.stderr)
def test_hung_readers_withhold_partial_excerpts_and_stop_by_deadline(self):
for reader in recipes():
with self.subTest(reader=reader):
result, _ = self.exercise(reader, stdout=PARTIAL_EMAIL_LOG, hang="term")
self.assertEqual(result.returncode, 124, result.stderr)
self.assertEqual(result.stdout, "")
self.assertIn("Log read unavailable", result.stderr)
def test_reader_ignoring_term_is_killed_after_one_second_grace(self):
result, _ = self.exercise("docker", stdout=PARTIAL_EMAIL_LOG, hang="ignore-term")
self.assertEqual(result.returncode, 137, result.stderr)
self.assertEqual(result.stdout, "")
self.assertIn("Log read unavailable (exit 137)", result.stderr)
def test_missing_timeout_does_not_run_a_reader_or_unbounded_fallback(self):
for reader in recipes():
with self.subTest(reader=reader):
result, argv = self.exercise(reader, missing_timeout=True)
self.assertIsNone(argv)
self.assertEqual(result.returncode, 1)
self.assertEqual(result.stdout, "")
self.assertIn("no unbounded fallback", result.stderr)
def test_successful_empty_read_is_not_documented_as_healthy_delivery(self):
for reader in recipes():
@@ -114,7 +122,7 @@ class NotificationTroubleshootingDocsTest(unittest.TestCase):
# disclosure boundary must survive edits to the copied recipe.
for reader in recipes():
result, _ = self.exercise(reader, stderr=SYNTHETIC_SECRET + "\n")
self.assertIn(SYNTHETIC_SECRET, result.stderr)
self.assertIn(SYNTHETIC_SECRET, result.stdout)
text = " ".join(section("Inspect Notification Logs").split())
for boundary in ("not sanitised", "Do not post them wholesale", "manually redacted",
"anything echoed by the provider", "Never upload full environments",
scripts/tests/test_troubleshooting_logs.py
+75 -32
View File
@@ -10,7 +10,10 @@ import json
import os
from pathlib import Path
import re
import shutil
import signal
import subprocess
import sys
import tempfile
import unittest
@@ -38,41 +41,61 @@ def recipes() -> dict[str, str]:
for block in blocks}
READER = '''#!/usr/bin/env python3
import json, os, pathlib, sys
name = pathlib.Path(sys.argv[0]).name
expected = (['-u', 'pulse', '--since', '15 minutes ago', '--lines', '1000', '--no-pager']
if name == 'journalctl' else ['logs', '--since', '15m', '--tail', '1000', 'pulse'])
READER = f'''#!{sys.executable}
import json, os, pathlib, signal, sys, time
pathlib.Path(os.environ['READER_ARGV']).write_text(json.dumps(sys.argv[1:]))
if sys.argv[1:] != expected:
print('unexpected log-reader arguments', file=sys.stderr)
sys.exit(64)
sys.stdout.write(os.environ.get('LOG_STDOUT', ''))
sys.stderr.write(os.environ.get('LOG_STDERR', ''))
sys.stdout.flush()
sys.stderr.flush()
if os.environ.get('READER_HANG'):
if os.environ['READER_HANG'] == 'ignore-term':
signal.signal(signal.SIGTERM, signal.SIG_IGN)
time.sleep(30)
sys.exit(int(os.environ.get('READER_EXIT', '0')))
'''
def exercise_log_recipe(reader: str, copied: str, *, stdout: str = "", stderr: str = "",
exit_code: int = 0, hang: str = "", missing_timeout: bool = False):
"""Own and clean up only this synthetic shell's process group on failure."""
with tempfile.TemporaryDirectory() as temporary:
directory = Path(temporary)
command = directory / reader
command.write_text(READER, encoding="utf-8")
command.chmod(0o700)
argv = directory / "argv.json"
path = str(directory) if missing_timeout else f"{directory}:{os.environ['PATH']}"
env = dict(os.environ, PATH=path, READER_ARGV=str(argv), LOG_STDOUT=stdout,
LOG_STDERR=stderr, READER_EXIT=str(exit_code), READER_HANG=hang)
with subprocess.Popen([shutil.which("bash"), "-c", copied], env=env,
stdout=subprocess.PIPE, stderr=subprocess.PIPE,
text=True, start_new_session=True) as process:
try:
output, errors = process.communicate(timeout=10)
except subprocess.TimeoutExpired:
try:
os.killpg(process.pid, signal.SIGKILL)
except ProcessLookupError:
pass
process.communicate(timeout=5)
raise
result = subprocess.CompletedProcess(process.args, process.returncode, output, errors)
return result, json.loads(argv.read_text()) if argv.exists() else None
class TroubleshootingLogRecipesTest(unittest.TestCase):
def exercise(self, reader: str, *, stdout: str = "", stderr: str = "",
exit_code: int = 0, recipe: str | None = None):
with tempfile.TemporaryDirectory() as temporary:
directory = Path(temporary)
command = directory / reader
command.write_text(READER, encoding="utf-8")
command.chmod(0o700)
argv = directory / "argv.json"
env = dict(os.environ, PATH=f"{directory}:{os.environ['PATH']}",
READER_ARGV=str(argv), LOG_STDOUT=stdout, LOG_STDERR=stderr,
READER_EXIT=str(exit_code))
copied = (recipe if recipe is not None else recipes()[reader]).replace(
"REQUEST_ID='abc123'", f"REQUEST_ID='{REQUEST_ID}'"
)
result = subprocess.run(["bash", "-c", copied], env=env,
capture_output=True, text=True, timeout=10)
self.assertTrue(argv.exists(), "copied recipe did not invoke its log reader")
self.assertNotEqual(result.returncode, 64, result.stderr)
return result
exit_code: int = 0, recipe: str | None = None, **settings):
copied = (recipe if recipe is not None else recipes()[reader]).replace(
"REQUEST_ID='abc123'", f"REQUEST_ID='{REQUEST_ID}'"
)
result, argv = exercise_log_recipe(reader, copied, stdout=stdout, stderr=stderr,
exit_code=exit_code, **settings)
expected = (["-u", "pulse", "--since", "15 minutes ago", "--lines", "1000", "--no-pager"]
if reader == "journalctl" else ["logs", "--since", "15m", "--tail", "1000", "pulse"])
self.assertEqual(argv, None if settings.get("missing_timeout") else expected)
return result
def test_shipped_document_is_the_same_guide(self):
self.assertEqual(DOC.read_bytes(),
@@ -88,10 +111,12 @@ class TroubleshootingLogRecipesTest(unittest.TestCase):
self.assertEqual(result.stdout, log)
self.assertEqual(result.stderr, "")
def test_docker_logs_written_to_stderr_are_searchable(self):
result = self.exercise("docker", stdout=DECOY_LOG, stderr=JSON_LOG)
self.assertEqual(result.returncode, 0, result.stderr)
self.assertEqual(result.stdout, JSON_LOG)
def test_logs_written_to_stderr_are_searchable_for_both_readers(self):
for reader in recipes():
with self.subTest(reader=reader):
result = self.exercise(reader, stdout=DECOY_LOG, stderr=JSON_LOG)
self.assertEqual(result.returncode, 0, result.stderr)
self.assertEqual(result.stdout, JSON_LOG)
def test_no_match_is_nonzero_and_does_not_print_unrelated_logs(self):
for reader in recipes():
@@ -106,8 +131,26 @@ class TroubleshootingLogRecipesTest(unittest.TestCase):
for reader in recipes():
with self.subTest(reader=reader):
result = self.exercise(reader, stdout=JSON_LOG, stderr=error, exit_code=2)
self.assertNotEqual(result.returncode, 0)
self.assertIn(error, result.stderr)
self.assertEqual(result.returncode, 2)
self.assertEqual(result.stdout, "")
self.assertNotIn(error, result.stderr)
self.assertIn("Log read unavailable (exit 2)", result.stderr)
def test_hung_readers_withhold_partial_matches_and_stop_by_deadline(self):
for reader in recipes():
with self.subTest(reader=reader):
result = self.exercise(reader, stdout=JSON_LOG, hang="term")
self.assertEqual(result.returncode, 124, result.stderr)
self.assertEqual(result.stdout, "")
self.assertIn("Log read unavailable", result.stderr)
def test_missing_timeout_stops_before_either_reader(self):
for reader in recipes():
with self.subTest(reader=reader):
result = self.exercise(reader, missing_timeout=True)
self.assertEqual(result.returncode, 1)
self.assertEqual(result.stdout, "")
self.assertIn("no unbounded fallback", result.stderr)
def test_console_only_selector_is_a_negative_control_for_json(self):
copied = recipes()["journalctl"].replace(