fix(notifications): preserve evidenced outcomes in backup and health notices

This commit is contained in:
martino
2026-10-01 08:38:32 +02:00
parent 147c401864
commit 08598d2863
20 changed files with 497 additions and 51 deletions
@@ -142,6 +142,10 @@ class CommandDescriptionsTests(unittest.TestCase):
'observation', source['channels']['email']['severity']['observation'])
local['channels']['email']['status'].setdefault(
'unconfirmed', source['channels']['email']['status']['unconfirmed'])
local['channels']['email']['status'].setdefault(
'completed_with_warnings', source['channels']['email']['status']['completed_with_warnings'])
for key, value in source['healthRecovery'].items():
local.setdefault('healthRecovery', {}).setdefault(key, value)
path.write_text(json.dumps(temporary, ensure_ascii=False))
# Model steady state after the bot fills these intentional new
# messages; keep repository locales and all other leaves intact.
@@ -217,10 +217,10 @@ class CorrectionTests(unittest.TestCase):
self.assertIn('✅ VM web (100)', result['body'])
def test_official_prefixed_warning_is_uncertain_and_retained(self):
def test_official_completed_report_warning_is_distinct_and_retained(self):
warning = '100: 2026-09-29 17:00:00 WARN: unable to add notes - permission denied'
event = receive(REPORT + '\n' + warning)
self.assertEqual(event.data['backup_outcome'], 'unconfirmed')
self.assertEqual(event.data['backup_outcome'], 'completed_with_warnings')
for language in LANGUAGES:
result, markup = email(event.event_type, event.data, event.severity, language)
self.assertIn(warning, result['body'])
@@ -0,0 +1,150 @@
"""Maintainer acceptance at inert actual notification consumers."""
import unittest
from notification_fixture import templates, receive, LANGUAGES, SCRIPTS, extract
from notification_final_fixture import deliver
NATIVE_REPORT = '''Details
=======
VMID Name Status Time Size Filename
100 web ok 1m 1s 1 GiB vm/100/2026-09-29T17:00:00Z
Total running time: 1m 1s
Total size: 1 GiB
Logs
====
vzdump --all 1 --storage PBS --mode snapshot
100: 2026-09-29 17:00:00 INFO: Starting Backup of VM 100 (qemu)
100: 2026-09-29 17:01:01 INFO: Finished Backup of VM 100 (00:01:01)
'''
class MaintainerFollowupTests(unittest.TestCase):
def test_completed_with_warnings_requires_independent_completion(self):
warning = '\n100: 2026-09-29 17:00:01 WARN: file changed during backup'
event = receive(NATIVE_REPORT + warning)
self.assertEqual(event.data['backup_outcome'], 'completed_with_warnings')
self.assertEqual((event.event_type,event.severity), ('backup_complete','INFO'))
for manual in (False,True):
for lang in LANGUAGES:
result = deliver(event.event_type,event.data,event.severity,lang,manual=manual)
label = templates.runtime_message('backup.warningTitle',lang,hostname='node-a')
self.assertIn(label,result['title'])
status = templates.runtime_message('channels.email.status.completed_with_warnings',lang)
self.assertIn(status,result['text'])
self.assertIn('file changed during backup',result['text'])
# Manual sends intentionally skip channel emoji enrichment.
if not manual: self.assertTrue(result['title'].startswith('💾⚠️'))
rich, _ = templates.enrich_with_emojis(event.event_type,result['title'],result['body'],event.data)
self.assertTrue(rich.startswith('💾⚠️'))
self.assertEqual(receive('WARN: file changed during backup').data['backup_outcome'],'unconfirmed')
self.assertEqual(receive(NATIVE_REPORT.split('Total running time:')[0]+warning).data['backup_outcome'],'unconfirmed')
self.assertEqual(receive(NATIVE_REPORT+warning+'\nERROR: cleanup failed').data['backup_outcome'],'failed')
self.assertEqual(receive(NATIVE_REPORT+warning,'warning').data['backup_outcome'],'completed_with_warnings')
self.assertEqual(receive('INFO: Starting Backup of VM 100 (qemu)\nINFO: Finished Backup of VM 100 (00:01:01)'+warning).data['backup_outcome'],'completed_with_warnings')
self.assertEqual(receive(NATIVE_REPORT+warning,kind='').data['backup_outcome'],'unconfirmed')
def test_null_filename_failed_guest_uses_own_start_identity(self):
report = NATIVE_REPORT.replace('100 web ok 1m 1s 1 GiB vm/100/2026-09-29T17:00:00Z',
'100 web err 1m 1s 0 B null')
for kind, prefix in (('qemu','VM'),('lxc','CT')):
own = report.replace('VM 100 (qemu)',f'VM 100 ({kind})')
# Unrelated guest appears first and must never supply the failed type.
message = f'INFO: Starting Backup of VM 999 ({"lxc" if kind == "qemu" else "qemu"})\n' + own
event = receive(message,'error','vzdump backup status (raw-node): backup failed')
parsed = templates._parse_vzdump_message(message)
self.assertEqual(parsed['vms'][0]['type'],kind)
result = deliver(event.event_type,event.data,event.severity)
self.assertIn(f'{prefix} web (100)',result['title'])
self.assertIn(f'❌ {prefix} web (100)',result['body'])
for message in (report.replace('Starting Backup of VM 100','Starting Backup of VM 999'),
report+'\nINFO: Starting Backup of VM 100 (lxc)'):
self.assertEqual(templates._parse_vzdump_message(message)['vms'][0]['type'],'')
def test_original_subject_only_retained_when_no_guest_context(self):
subject = 'vzdump backup status (raw-host): backup failed: multiple problems'
event = receive('ERROR: archive write failed\n'+NATIVE_REPORT,'error',subject)
event.data['hostname']='configured-alias'
for lang in LANGUAGES:
result=deliver(event.event_type,event.data,event.severity,lang)
self.assertNotIn(subject,result['text'])
self.assertEqual(result['text'].count('ERROR: archive write failed'),1)
self.assertIn('configured-alias',result['title'])
setup=receive('Details\n=======\nVMID Name Status Time Size Filename\n\nTotal running time: 0s\nTotal size: 0 B','error',subject.replace('multiple problems','unable to open storage'))
result=deliver(setup.event_type,setup.data,setup.severity)
self.assertEqual(result['text'].count(setup.data['pve_title']),1)
unique=receive(NATIVE_REPORT,'error',subject.replace('multiple problems','job-end hook denied'))
result=deliver(unique.event_type,unique.data,unique.severity)
self.assertIn('job-end hook denied',result['body'])
self.assertNotIn('vzdump backup status',result['body'])
def test_backup_diagnostics_are_bounded_with_principal_cause_and_notice(self):
raw = NATIVE_REPORT + '\n' + '\n'.join(f'WARN: repeated warning {i}' for i in range(80)) + '\nERROR: principal archive write failure'
event=receive(raw)
for lang in LANGUAGES:
result=deliver(event.event_type,event.data,event.severity,lang)
self.assertIn('ERROR: principal archive write failure',result['body'])
self.assertLessEqual(len('\n'.join(line for line in result['body'].splitlines() if line.startswith(('WARN:','ERROR:')))),1024)
self.assertLessEqual(sum(line.startswith(('WARN:','ERROR:')) for line in result['body'].splitlines()),8)
notice=templates.runtime_message('backup.diagnosticsOmitted',lang,count=73)
self.assertIn(notice,result['body'])
self.assertEqual(event.data['pve_message'],raw)
long=receive('ERROR: '+ 'b'*5000,'error','vzdump backup status (node): backup failed')
result=deliver(long.event_type,long.data,long.severity)
self.assertLess(len(result['body']),1400)
self.assertIn('ERROR: '+ 'b'*100,result['body'])
self.assertIn(templates.runtime_message('backup.diagnosticsOmitted','en',count=1),result['body'])
def test_real_quiet_digest_retains_each_backup_outcome_icon(self):
samples=[(NATIVE_REPORT,'confirmed','💾✅'),(NATIVE_REPORT+'\nWARN: changed file','completed_with_warnings','💾⚠️'),(NATIVE_REPORT+'\nERROR: write failed','failed','💾❌'),('INFO: Starting Backup of VM 100 (qemu)','unconfirmed','💾❔')]
for raw,outcome,icon in samples:
event=receive(raw)
self.assertEqual(event.data['backup_outcome'],outcome)
for lang in LANGUAGES:
result=deliver(event.event_type,event.data,event.severity,lang,quiet=True)
self.assertIn(icon,result['body'])
self.assertNotIn('💾❔',result['body']) if outcome!='unconfirmed' else None
import types,datetime
ns={'datetime':datetime.datetime,'runtime_message':templates.runtime_message,'EVENT_EMOJI':templates.EVENT_EMOJI,'CATEGORY_EMOJI':templates.CATEGORY_EMOJI}
compose=extract(SCRIPTS/'notification_manager.py','_compose_digest_body','NotificationManager',ns)
target=types.SimpleNamespace(_notification_language=lambda:'en')
rows=[(i,'backup_complete','backup',1,icon+' node: Backup','') for i,(_,_,icon) in enumerate(samples)]
body=compose(target,rows,use_icons=True)
for _,_,icon in samples:self.assertIn(icon,body)
plain=compose(target,rows,use_icons=False)
for _,_,icon in samples:self.assertNotIn(icon,plain)
should=extract(SCRIPTS/'notification_manager.py','_should_buffer_for_digest','NotificationManager',{})
self.assertFalse(should(types.SimpleNamespace(_DIGEST_EXEMPT_EVENTS={'backup_complete'},_config={'email.digest_enabled':'true'}),'email','INFO','backup_complete'))
def test_quiet_restore_details_are_subordinate_in_text_and_email(self):
from notification_final_fixture import restore_event
event=restore_event('missing module zfs')
for lang in LANGUAGES:
result=deliver(event['event_type'],event['data'],event['severity'],lang,quiet=True)
body_lines=result['buffered'][0][3].splitlines()
for line in body_lines:
if line.strip():
self.assertIn(' '+line.strip(),result['body'])
self.assertIn(' '+__import__('html').escape(line.strip()),result['html'])
self.assertIn('white-space:pre-wrap;',result['html'])
self.assertNotIn(templates.runtime_message('digest.footer',lang),result['body'])
def test_job_level_subject_cause_survives_warning_cap(self):
raw=NATIVE_REPORT+'\n'+'\n'.join('WARN: repeated diagnostic '+str(i) for i in range(80))
event=receive(raw,'error','vzdump backup status (raw-host): backup failed: job-end hook denied')
for lang in LANGUAGES:
result=deliver(event.event_type,event.data,event.severity,lang)
self.assertEqual(result['body'].count('job-end hook denied'),1)
self.assertNotIn('vzdump backup status',result['body'])
self.assertIn(templates.runtime_message('backup.diagnosticsOmitted',lang,count=73),result['body'])
def test_backup_quiet_email_uses_event_scoped_wrapping(self):
event=receive(NATIVE_REPORT+'\nWARN: changed file')
result=deliver(event.event_type,event.data,event.severity,'sv',quiet=True)
self.assertTrue(result['data'].get('_backup_summary'))
self.assertIn('table-layout:fixed;',result['html'])
self.assertIn('overflow-wrap:break-word;',result['html'])
unrelated=deliver('node_reconnect',{'hostname':'node-a'},'OK')
self.assertNotIn('table-layout:fixed;',unrelated['html'])
if __name__ == '__main__': unittest.main()
@@ -134,7 +134,7 @@ class OutcomeWording(unittest.TestCase):
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\n'+header+'\n'+row_ok+'\nTotal running time: 00:01:00\n'+truncated, 'confirmed'),
('vzdump', 'info', header+'\n'+row_ok+'\nTotal running time: 00:01:00\n'+truncated, 'confirmed'),
('vzdump', 'info', header+'\n'+row_err+'\nTotal running time: 00:01:00\n'+truncated, 'failed'),
('vzdump', 'warning', header+'\n'+row_ok+'\nTotal running time: 00:01:00', 'unconfirmed'),
('vzdump', 'warning', header+'\n'+row_ok+'\nTotal running time: 00:01:00', 'completed_with_warnings'),
('vzdump', 'info', header+'\n'+row_ok, 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)\n'+header+'\n'+row_ok, 'unconfirmed'),
('vzdump', 'warning', header+'\n'+row_err+'\nTotal running time: 00:01:00', 'failed'),
@@ -147,11 +147,11 @@ class OutcomeWording(unittest.TestCase):
('vzdump', 'info', header+'\n'+row_ok+'\n'+row_warning+'\nTotal running time: 00:02:00', 'unconfirmed'),
('vzdump', 'info', header+'\n'+row_ok[:30], 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)', 'confirmed'),
('vzdump', 'warning', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)', 'unconfirmed'),
('vzdump', 'warning', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)', 'completed_with_warnings'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)', 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Starting Backup of VM 105 (lxc)\nINFO: Finished Backup of VM 105 (00:01:00)', 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)\nWARNING: skipped file', 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)\nINFO: TASK OK\n104 alpha WARNINGS: 1', 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)\nWARNING: skipped file', 'completed_with_warnings'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 104 (00:01:00)\nINFO: TASK OK\n104 alpha WARNINGS: 1', 'completed_with_warnings'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Finished Backup of VM 105 (00:01:00)', 'unconfirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nINFO: Starting Backup of VM 105 (lxc)\nINFO: Finished Backup of VM 104 (00:01:00)\nINFO: Finished Backup of VM 105 (00:01:00)', 'confirmed'),
('vzdump', 'info', 'INFO: Starting Backup of VM 104 (qemu)\nERROR: backup failed for VM 104', 'failed'),
@@ -128,10 +128,10 @@ class PVE92Tests(unittest.TestCase):
self.assertEqual(event_for(message).data['backup_outcome'], 'confirmed')
for message, severity, expected in (
(PVE92.replace('ok ', 'OK '), 'info', 'confirmed'),
(message, 'warning', 'unconfirmed'),
(message, 'warning', 'completed_with_warnings'),
(message, 'error', 'failed'),
(message + '\nERROR: archive write failed', 'info', 'failed'),
(message + '\nWARNING: skipped file', 'info', 'unconfirmed'),
(message + '\nWARNING: skipped file', 'info', 'completed_with_warnings'),
(PVE92.replace('ok ', 'WARNINGS '), 'info', 'unconfirmed'),
):
with self.subTest(message=message, severity=severity):
@@ -0,0 +1,107 @@
"""Fresh existing-check provenance; extracted consumers, real disposable SQLite."""
import contextlib
import datetime
import json
import os
import sqlite3
import tempfile
import time
import types
import unittest
from unittest.mock import patch
from notification_fixture import extract, SCRIPTS, templates, LANGUAGES
from notification_final_fixture import deliver
class RecoveryEvidenceTests(unittest.TestCase):
def test_cpu_success_provenance_is_persisted_only_after_normal_samples(self):
events=[]
with tempfile.TemporaryDirectory() as scratch:
db=scratch+'/health.sqlite'
conn=sqlite3.connect(db)
conn.execute('CREATE TABLE errors(id INTEGER PRIMARY KEY,error_key TEXT,details TEXT,resolved_at TEXT,resolution_type TEXT,resolution_reason TEXT)')
conn.execute("INSERT INTO errors(error_key,details) VALUES ('cpu_usage','{}')")
conn.commit();conn.close()
@contextlib.contextmanager
def connection():
c=sqlite3.connect(db)
try:yield c
finally:c.close()
ns={'datetime':datetime.datetime,'json':json}
resolve=extract(SCRIPTS/'health_persistence.py','_resolve_error_impl','HealthPersistence',ns)
store=types.SimpleNamespace(_db_connection=connection,_entity_from_details=lambda details:'',_record_event=lambda cursor,kind,key,data:events.append(data))
store.resolve_error=lambda key,reason,**kw:resolve(store,key,reason,**kw)
ns={'Dict':dict,'Any':object,'os':os,'time':time,'health_persistence':store,'psutil':types.SimpleNamespace(cpu_percent=lambda **kw:20,cpu_count=lambda:4)}
check=extract(SCRIPTS/'health_monitor.py','_check_cpu_with_hysteresis','HealthMonitor',ns)
target=types.SimpleNamespace(state_history={'cpu_usage':[{'value':20,'time':time.time()-i*10} for i in range(10)]},CPU_CRITICAL=95,CPU_WARNING=85,CPU_RECOVERY=75,CPU_CRITICAL_DURATION=300,CPU_WARNING_DURATION=300,CPU_RECOVERY_DURATION=120,_check_cpu_temperature=lambda:None)
result=check(target)
self.assertEqual(result['status'],'OK')
self.assertTrue(events[-1].get('check_evidence'),events)
proof=events[-1]['check_evidence']
self.assertEqual(proof['check'],'cpu_usage')
self.assertGreaterEqual(proof['checked_at'],time.time()-5)
# Existing generic resolve callers (cleanup/exclusion) get no proof.
conn=sqlite3.connect(db);conn.execute('UPDATE errors SET resolved_at=NULL');conn.commit();conn.close()
resolve(store,'cpu_usage','No longer present')
self.assertFalse(events[-1].get('check_evidence'))
def test_recovery_query_requires_fresh_same_incident_proof(self):
with tempfile.TemporaryDirectory() as scratch:
db=scratch+'/health.sqlite'
conn=sqlite3.connect(db)
conn.execute('CREATE TABLE errors(id INTEGER PRIMARY KEY,error_key TEXT,first_seen TEXT,last_seen TEXT,resolved_at TEXT,acknowledged INTEGER)')
conn.execute('CREATE TABLE events(id INTEGER PRIMARY KEY,event_type TEXT,error_key TEXT,timestamp TEXT,data TEXT)')
now=datetime.datetime.now(); first=(now-datetime.timedelta(minutes=10)).isoformat(); last=(now-datetime.timedelta(minutes=1)).isoformat(); resolved=now.isoformat()
proof={'check':'cpu_usage','checked_at':now.timestamp()}
conn.execute('INSERT INTO errors VALUES(1,?,?,?,?,0)',('cpu_usage',first,last,resolved))
conn.execute('INSERT INTO events VALUES(1,?,?,?,?)',('resolved','cpu_usage',resolved,json.dumps({'check_evidence':proof})))
conn.commit();conn.close()
@contextlib.contextmanager
def connection(**kwargs):
c=sqlite3.connect(db)
try:yield c
finally:c.close()
ns={'datetime':datetime.datetime,'json':json,'time':time}
tree=(SCRIPTS/'health_persistence.py').read_text()
query=extract(SCRIPTS/'health_persistence.py','get_recovery_evidence','HealthPersistence',ns) if 'def get_recovery_evidence(' in tree else lambda *args:None
store=types.SimpleNamespace(_db_connection=connection)
self.assertEqual(query(store,'cpu_usage',first),proof)
self.assertIsNone(query(store,'cpu_usage','different incident'))
for field,value in [('acknowledged',1),('resolved_at',None),('last_seen',(now+datetime.timedelta(seconds=1)).isoformat())]:
conn=sqlite3.connect(db);conn.execute(f'UPDATE errors SET {field}=?',(value,));conn.commit();conn.close()
self.assertIsNone(query(store,'cpu_usage',first))
conn=sqlite3.connect(db);conn.execute('UPDATE errors SET acknowledged=0,resolved_at=?,last_seen=?',(resolved,last));conn.commit();conn.close()
for bad in (None,{'check':'cpu_usage','checked_at':now.timestamp()-7201},{'check':'storage_removed','checked_at':now.timestamp()},{'check':'cpu_usage','checked_at':float('inf')},{'check':'cpu_usage','checked_at':10**400}):
conn=sqlite3.connect(db);conn.execute('UPDATE events SET data=?',(json.dumps({'check_evidence':bad}),));conn.commit();conn.close()
self.assertIsNone(query(store,'cpu_usage',first))
def test_poller_and_all_consumers_distinguish_proven_recovery_from_disappearance(self):
import sys
ns={'time':time,'json':json,'Dict':dict,'NotificationEvent':lambda *a,**kw:types.SimpleNamespace(event_type=a[0],severity=a[1],data=a[2])}
poll=extract(SCRIPTS/'notification_events.py','_check_persistent_health','PollingCollector',ns)
for proof in (None,{'check':'cpu_usage','checked_at':time.time()}):
events=[]
store=types.SimpleNamespace(get_active_errors=lambda:[],is_error_acknowledged=lambda key:False,get_recovery_evidence=lambda *a:proof)
collector=types.SimpleNamespace(_hostname='node-a',_ENTITY_MAP={'cpu':('node','')},_first_poll_done=True,_known_errors={'cpu_usage':{'category':'cpu','reason':'CPU high','severity':'WARNING','first_seen':'2026-09-30T00:00:00'}},_notified_severity={'cpu_usage':'WARNING'},_last_notified={'cpu_usage':1},_queue=types.SimpleNamespace(put=events.append),_guest_storage_error_is_now_foreign=lambda *a:False,_save_known_errors_meta=lambda:None)
with patch.dict(sys.modules,{'health_persistence':types.SimpleNamespace(health_persistence=store)}):poll(collector)
self.assertEqual(len(events),1)
event=events[0]
self.assertEqual(event.data.get('recovery_outcome'),'resolved' if proof else 'no_longer_reported')
self.assertEqual(event.data['is_recovery'],bool(proof))
for lang in LANGUAGES:
for manual in (False,True):
result=deliver(event.event_type,event.data,event.severity,lang,manual=manual)
if proof:
self.assertIn(templates.runtime_message('healthRecovery.title',lang,hostname='node-a',category='cpu',entity_suffix=''),result['title'])
self.assertIn('background:#f0fdf4;',result['html'])
else:self.assertNotIn('background:#f0fdf4;',result['html'])
self.assertEqual(result['text'].count(event.data['reason']),1)
def test_manual_recovery_flag_alone_is_not_authoritative_evidence(self):
data={'hostname':'node-a','category':'cpu','reason':'Observation disappeared','duration':'1h','original_severity':'WARNING','recovery_outcome':'resolved'}
for lang in LANGUAGES:
for manual in (False,True):
result=deliver('error_resolved',data,'OK',lang,manual=manual)
self.assertNotIn('background:#f0fdf4;',result['html'])
self.assertNotIn(templates.runtime_message('healthRecovery.body',lang,**data),result['body'])
if __name__=='__main__':unittest.main()