276 lines
16 KiB
Python
276 lines
16 KiB
Python
"""Synthetic human log projections and durable low-noise escalation checks."""
|
|
import concurrent.futures
|
|
import http.client
|
|
import json
|
|
from pathlib import Path
|
|
import tempfile
|
|
import threading
|
|
import unittest
|
|
from unittest.mock import patch
|
|
from agent_control.store import Store, Invalid, Conflict
|
|
from agent_control.server import Server
|
|
|
|
|
|
def sample(**overrides):
|
|
data = dict(source='synthetic-worker',event_id='failure-1',severity='warning',
|
|
status='firing',summary='Worker unavailable',impact='Checks paused',
|
|
action='Recorded failure',next_step='Check recovery',evidence=['Process exited'])
|
|
data.update(overrides)
|
|
return data
|
|
|
|
|
|
def escalation(**overrides):
|
|
data = dict(source='synthetic-worker',event_id='failure-1',reason='Unhealthy for 120 seconds')
|
|
data.update(overrides)
|
|
return data
|
|
|
|
|
|
class LogTests(unittest.TestCase):
|
|
def setUp(self):
|
|
self.tmp = tempfile.TemporaryDirectory()
|
|
self.path = Path(self.tmp.name)/'logs.sqlite3'
|
|
self.store = Store(self.path)
|
|
|
|
def tearDown(self):
|
|
self.tmp.cleanup()
|
|
|
|
def test_legacy_short_mirror_interruption_is_warning_without_changing_audit(self):
|
|
self.store.hook(sample(source='bridge-mirror',severity='critical'))
|
|
self.store.hook(sample(source='bridge-mirror',severity='critical',status='resolved'))
|
|
entry=self.store.logs()['logs'][0]
|
|
self.assertEqual((entry['level'],entry['status']),('warning','resolved'))
|
|
with self.store.db() as db:
|
|
original=json.loads(db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()['data'])
|
|
self.assertEqual(original['severity'],'critical')
|
|
|
|
def test_empty_four_levels_status_independent_and_filters(self):
|
|
self.assertEqual(self.store.logs(),dict(logs=[],total_count=0,has_more=False))
|
|
for level in ('info','warning','error','critical'):
|
|
self.store.hook(sample(event_id=level,severity=level))
|
|
self.store.hook(sample(event_id='warning',severity='info',status='resolved'))
|
|
self.assertEqual(self.store.logs()['total_count'],4)
|
|
self.assertEqual(len(self.store.logs(status='active')['logs']),3)
|
|
entry = self.store.logs(level='warning',status='resolved')['logs'][0]
|
|
self.assertEqual(entry['level'],'warning')
|
|
self.assertEqual(entry['status'],'resolved')
|
|
self.assertIsNotNone(entry['resolved_at'])
|
|
self.assertEqual(self.store.logs(level='critical',status='resolved')['logs'],[])
|
|
for args in [dict(level='fatal'),dict(status='firing')]:
|
|
with self.assertRaises(Invalid): self.store.logs(**args)
|
|
|
|
def test_duplicates_merge_count_without_touching_audit_or_notifications(self):
|
|
with patch('agent_control.store.time.time',return_value=100):
|
|
original = self.store.hook(sample())
|
|
with self.store.db() as db:
|
|
audit = db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()[0]
|
|
with patch('agent_control.store.time.time',return_value=120):
|
|
for _ in range(3):
|
|
self.assertTrue(self.store.hook(sample())['duplicate'])
|
|
entry = Store(self.path).logs()['logs'][0]
|
|
self.assertEqual(entry['repeat_count'],4)
|
|
self.assertEqual(entry['first_seen'],100)
|
|
self.assertEqual(entry['last_seen'],120)
|
|
self.assertEqual(entry['id'],original['notifications'][0]['hook']['log_id'])
|
|
self.assertNotIn('escalated',original['notifications'][0]['hook'])
|
|
self.assertEqual(len(self.store.state()['events']),1)
|
|
self.assertEqual(self.store.hook_notifications()['pending_count'],1)
|
|
with self.store.db() as db:
|
|
self.assertEqual(db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()[0],audit)
|
|
with self.assertRaises(Conflict): self.store.hook(sample(summary='Different observation'))
|
|
self.assertEqual(self.store.logs()['logs'][0]['repeat_count'],4)
|
|
|
|
def test_recovery_time_warning_never_notifies_human(self):
|
|
with patch('agent_control.store.time.time',return_value=100):
|
|
first = self.store.hook(sample())
|
|
with patch('agent_control.store.time.time',return_value=150):
|
|
resolved = self.store.hook(sample(status='resolved',summary='Worker recovered',action='Checks resumed'))
|
|
entry = self.store.logs()['logs'][0]
|
|
self.assertEqual(entry['resolved_at'],150)
|
|
self.assertEqual(entry['last_seen'],150)
|
|
self.assertEqual(entry['summary'],'Worker unavailable')
|
|
self.assertEqual(entry['action'],'Checks resumed')
|
|
self.assertEqual(entry['repeat_count'],1)
|
|
self.assertEqual({n['target'] for n in first['notifications']+resolved['notifications']},{'control'})
|
|
|
|
def test_escalation_is_persistent_idempotent_and_recovery_inherits(self):
|
|
self.store.hook(sample())
|
|
with self.store.db() as db:
|
|
audit = db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()[0]
|
|
with patch('subprocess.run',side_effect=AssertionError('no execution')):
|
|
upgraded = self.store.hook_escalate(escalation(impact='Work remains blocked'))
|
|
self.assertFalse(upgraded['duplicate'])
|
|
self.assertEqual(upgraded['hook']['severity'],'critical')
|
|
self.assertEqual(upgraded['hook']['status'],'firing')
|
|
self.assertEqual({n['target'] for n in upgraded['notifications']},{'control','human'})
|
|
self.assertTrue(all(n['hook']['escalated'] is True for n in upgraded['notifications']))
|
|
again = Store(self.path).hook_escalate(escalation(impact='Work remains blocked'))
|
|
self.assertTrue(again['duplicate'])
|
|
self.assertEqual(again['notifications'],upgraded['notifications'])
|
|
self.assertEqual(self.store.hook_notifications()['pending_count'],3)
|
|
entry = self.store.logs()['logs'][0]
|
|
self.assertEqual(entry['level'],'critical')
|
|
self.assertEqual(entry['status'],'active')
|
|
self.assertEqual(entry['impact'],'Work remains blocked')
|
|
self.assertEqual(entry['id'],upgraded['notifications'][0]['hook']['log_id'])
|
|
self.assertEqual(entry['repeat_count'],1)
|
|
self.assertEqual(self.store.state()['hooks']['active_firing'],1)
|
|
self.assertEqual(len(self.store.state()['events']),2)
|
|
with self.store.db() as db:
|
|
self.assertEqual(db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()[0],audit)
|
|
self.assertEqual(db.execute("SELECT count(*) FROM hooks WHERE status='escalated'").fetchone()[0],1)
|
|
resolved = self.store.hook(sample(status='resolved',severity='info'))
|
|
self.assertEqual(resolved['hook']['severity'],'critical')
|
|
self.assertEqual({n['target'] for n in resolved['notifications']},{'control','human'})
|
|
self.assertTrue(all(n['hook']['escalated'] for n in resolved['notifications']))
|
|
self.assertTrue(all(n['hook']['log_id']==entry['id'] for n in resolved['notifications']))
|
|
self.assertEqual(self.store.logs()['logs'][0]['status'],'resolved')
|
|
self.assertTrue(self.store.hook(sample(status='resolved',severity='warning'))['duplicate'])
|
|
|
|
def test_escalation_conflicts_unknown_recovered_already_critical_and_changed_reason(self):
|
|
with self.assertRaises(Conflict): self.store.hook_escalate(escalation())
|
|
self.store.hook(sample())
|
|
self.store.hook_escalate(escalation())
|
|
with self.assertRaises(Conflict): self.store.hook_escalate(escalation(reason='Another reason'))
|
|
with self.assertRaises(Conflict): self.store.hook_escalate(escalation(impact='Changed'))
|
|
self.store.hook(sample(status='resolved'))
|
|
with self.assertRaises(Conflict): self.store.hook_escalate(escalation())
|
|
self.store.hook(sample(event_id='critical',severity='critical'))
|
|
with self.assertRaises(Conflict): self.store.hook_escalate(escalation(event_id='critical'))
|
|
ordinary = self.store.hook(sample(event_id='critical',severity='warning',status='resolved'))
|
|
self.assertEqual({n['target'] for n in ordinary['notifications']},{'control','human'})
|
|
self.assertTrue(all('escalated' not in n['hook'] for n in ordinary['notifications']))
|
|
|
|
def test_strict_escalation_schema_and_hook_cannot_claim_escalation(self):
|
|
self.store.hook(sample())
|
|
for changes in [dict(reason=''),dict(reason='x'*2001),dict(reason=None),
|
|
dict(impact=None),dict(impact='x'*2001),dict(authorization=True)]:
|
|
with self.assertRaises(Invalid): self.store.hook_escalate(escalation(**changes))
|
|
for changes in [dict(escalated=True),dict(log_id='forged')]:
|
|
with self.assertRaises(Invalid): self.store.hook(sample(**changes))
|
|
self.assertEqual(self.store.hook_notifications()['pending_count'],1)
|
|
|
|
def test_concurrent_repeat_and_upgrade_remain_one_audit_and_pair(self):
|
|
self.store.hook(sample())
|
|
with concurrent.futures.ThreadPoolExecutor(max_workers=8) as pool:
|
|
list(pool.map(lambda _:self.store.hook(sample()),range(12)))
|
|
results=list(pool.map(lambda _:self.store.hook_escalate(escalation()),range(12)))
|
|
self.assertEqual(sum(not r['duplicate'] for r in results),1)
|
|
self.assertEqual(self.store.logs()['logs'][0]['repeat_count'],13)
|
|
self.assertEqual(len(self.store.state()['events']),2)
|
|
self.assertEqual(self.store.hook_notifications()['pending_count'],3)
|
|
|
|
def test_escalation_outbox_failure_rolls_back_everything(self):
|
|
self.store.hook(sample())
|
|
with self.store.db() as db:
|
|
db.execute("CREATE TRIGGER fail_upgrade BEFORE INSERT ON hook_notifications BEGIN SELECT RAISE(ABORT,'synthetic'); END")
|
|
with self.assertRaises(Exception): self.store.hook_escalate(escalation())
|
|
self.assertEqual(self.store.logs()['logs'][0]['level'],'warning')
|
|
self.assertEqual(len(self.store.state()['events']),1)
|
|
with self.store.db() as db:
|
|
self.assertEqual(db.execute('SELECT count(*) FROM hook_escalations').fetchone()[0],0)
|
|
|
|
def test_legacy_audit_projection_and_bounded_recent_results(self):
|
|
self.store.hook(sample())
|
|
with self.store.db() as db:
|
|
db.execute('DELETE FROM hook_observations')
|
|
self.assertEqual(self.store.logs()['logs'][0]['repeat_count'],1)
|
|
self.store.hook(sample())
|
|
self.assertEqual(self.store.logs()['logs'][0]['repeat_count'],2)
|
|
for i in range(104):
|
|
with patch('agent_control.store.time.time',return_value=1000+i):
|
|
self.store.hook(sample(event_id='event-'+str(i),severity='error'))
|
|
result=self.store.logs(level='error')
|
|
self.assertEqual(result['total_count'],104)
|
|
self.assertTrue(result['has_more'])
|
|
self.assertEqual(len(result['logs']),100)
|
|
self.assertEqual(result['logs'][0]['event_id'],'event-103')
|
|
|
|
def test_sensitive_header_cookie_file_uri_and_private_key_variants(self):
|
|
for text in ['Authorization: SensitiveValue', 'Cookie: session=SensitiveValue',
|
|
'密钥=SensitiveValue', '令牌: SensitiveValue',
|
|
'file:///home/SensitiveValue/secret.txt',
|
|
'-----BEGIN RSA PRIVATE KEY----- SensitiveValue -----END RSA PRIVATE KEY-----',
|
|
'https://person:SensitiveValue@example.invalid',
|
|
r'\\\\host\\SensitiveValue\\secret.txt']:
|
|
self.assertNotIn('SensitiveValue',self.store._safe_log_text(text))
|
|
|
|
def test_sensitive_projection_never_changes_original_audit(self):
|
|
secrets = ['abc-token-value','my-password','key-abcdefghi','private-content',
|
|
'alice','private.txt','jwtcontents','superlongcredential123456789012345678901234']
|
|
values = ['token=abc-token-value failed','password: my-password',
|
|
'Authorization: Bearer key-abcdefghi',
|
|
'-----BEGIN OPENSSH PRIVATE KEY-----\nprivate-content\n-----END OPENSSH PRIVATE KEY-----',
|
|
'/home/alice/private.txt unavailable',
|
|
r'C:\Example\private.txt unavailable',
|
|
'eyJhbGciOiJIUzI1NiJ9.jwtcontents.signature',
|
|
'superlongcredential123456789012345678901234']
|
|
self.store.hook(sample(summary=values[0],impact=values[1],action=values[2],
|
|
next_step=values[4],evidence=values))
|
|
projected=json.dumps(self.store.logs(),ensure_ascii=False)
|
|
for value in secrets:
|
|
self.assertNotIn(value,projected)
|
|
self.assertIn('已隐藏',projected)
|
|
with self.store.db() as db:
|
|
original=db.execute("SELECT data FROM hooks WHERE status='firing'").fetchone()[0]
|
|
self.assertIn('abc-token-value',original)
|
|
self.assertIn('private-content',original)
|
|
self.assertEqual(set(self.store.logs()['logs'][0]),
|
|
{'id','source','event_id','level','status','summary','impact','action','next_step',
|
|
'evidence','first_seen','last_seen','resolved_at','repeat_count'})
|
|
|
|
|
|
class LogHTTPTests(unittest.TestCase):
|
|
def setUp(self):
|
|
self.tmp = tempfile.TemporaryDirectory()
|
|
root = Path(self.tmp.name)
|
|
root.chmod(0o700)
|
|
token = root / 'token'
|
|
self.secret = 'h'*48
|
|
token.write_text(self.secret)
|
|
token.chmod(0o600)
|
|
self.metrics = patch('agent_control.server.MetricsCache')
|
|
mock = self.metrics.start()
|
|
mock.return_value.snapshot.return_value = {'status':'synthetic'}
|
|
self.server = Server(dict(bind='127.0.0.1',port=0,runtime_root=str(root),token_file=str(token)))
|
|
self.thread = threading.Thread(target=self.server.serve_forever, daemon=True)
|
|
self.thread.start()
|
|
|
|
def tearDown(self):
|
|
self.server.shutdown()
|
|
self.server.server_close()
|
|
self.thread.join()
|
|
self.metrics.stop()
|
|
self.tmp.cleanup()
|
|
|
|
def request(self,path,method='GET',payload=None,headers=None):
|
|
conn = http.client.HTTPConnection(*self.server.server_address,timeout=3)
|
|
merged = {'Authorization':'Bearer '+self.secret,'X-CSRF-Token':'1','Content-Type':'application/json'}
|
|
merged.update(headers or {})
|
|
conn.request(method,path,json.dumps(payload) if payload is not None else None,merged)
|
|
response = conn.getresponse()
|
|
status, body = response.status,json.loads(response.read())
|
|
conn.close()
|
|
return status, body
|
|
|
|
|
|
def test_logs_and_escalation_auth_filters_and_csrf(self):
|
|
for path in ['/api/logs','/api/logs?level=warning']:
|
|
self.assertEqual(self.request(path,headers={'Authorization':''})[0],401)
|
|
self.assertEqual(self.request(path,headers={'Sec-Fetch-Site':'cross-site'})[0],403)
|
|
self.assertEqual(self.request('/api/logs')[1]['logs'],[])
|
|
self.assertEqual(self.request('/api/hooks','POST',sample())[0],200)
|
|
self.assertEqual(self.request('/api/logs?level=warning&status=active')[1]['total_count'],1)
|
|
for query in ['level=fatal','status=firing','level=','level=info&level=warning','source=x']:
|
|
self.assertEqual(self.request('/api/logs?'+query)[0],400)
|
|
path='/api/hooks/escalate'
|
|
for headers,code in [({'Authorization':''},401),({'X-CSRF-Token':''},403),
|
|
({'Origin':'https://untrusted.example'},403)]:
|
|
self.assertEqual(self.request(path,'POST',escalation(),headers)[0],code)
|
|
self.assertEqual(self.request(path,'POST',escalation(unknown=True))[0],400)
|
|
self.assertEqual(self.request(path,'POST',escalation())[0],200)
|
|
self.assertTrue(self.request(path,'POST',escalation())[1]['duplicate'])
|
|
self.assertEqual(self.request('/api/logs?level=warning')[1]['total_count'],0)
|
|
self.assertEqual(self.request('/api/logs?level=critical')[1]['total_count'],1)
|
|
self.assertEqual(self.request('/api/hooks','POST',sample(status='resolved'))[0],200)
|
|
self.assertEqual(self.request(path,'POST',escalation())[0],409)
|