185 lines
8.9 KiB
Python
185 lines
8.9 KiB
Python
from __future__ import annotations
|
|
|
|
import json
|
|
import logging
|
|
from datetime import datetime, timezone
|
|
from pathlib import Path
|
|
|
|
import pytest
|
|
from fastapi import FastAPI, HTTPException
|
|
from fastapi.testclient import TestClient
|
|
|
|
from hockey_data.auth_bridge import HockeyUser
|
|
from hockey_data.program_log import (MOSCOW, ProgramLogHandler, ProgramLogStore,
|
|
redact, redact_text, retention_cutoff,
|
|
set_log_context, reset_log_context)
|
|
from hockey_data.program_log_router import create_program_log_router
|
|
|
|
UTC = timezone.utc
|
|
NOW = datetime(2026, 10, 21, 12, tzinfo=UTC)
|
|
|
|
|
|
@pytest.fixture
|
|
def store(tmp_path):
|
|
instance = ProgramLogStore(tmp_path / 'journal', now=lambda: NOW)
|
|
instance.start()
|
|
assert instance._ready.wait(3)
|
|
yield instance
|
|
assert instance.close()
|
|
|
|
|
|
def emit(store, timestamp=NOW, **kwargs):
|
|
assert store.emit(timestamp=timestamp, **kwargs)
|
|
assert store.flush()
|
|
|
|
|
|
def test_failed_command_details_are_searchable_by_actor_match_and_date(store):
|
|
emit(store, datetime(2026, 10, 20, 21, 0, tzinfo=UTC), level='ERROR', category='mapping',
|
|
event='delivery.failed', message='vMix отказал', actor_id='42', actor_login='operator',
|
|
game_id='100', device_id='GFX1', details={'function': 'SetText', 'reason': 'HTTP 500'})
|
|
assert len(store.query(date_from='2026-10-21', date_to='2026-10-21', actor='42', game_id='100', q='HTTP 500')['items']) == 1
|
|
assert not store.query(date_from='2026-10-20', date_to='2026-10-20')['items']
|
|
assert not store.query(level='INFO')['items']
|
|
assert store.options()['actors'] == [{'id':'42','login':'operator'}]
|
|
|
|
|
|
def test_calendar_month_retention_december_january_and_leap_year():
|
|
assert retention_cutoff(datetime(2026, 1, 1, tzinfo=UTC)) == datetime(2025, 11, 30, 21, tzinfo=UTC)
|
|
assert retention_cutoff(datetime(2024, 3, 1, tzinfo=UTC)) == datetime(2024, 1, 31, 21, tzinfo=UTC)
|
|
# Moscow is already November while UTC is still October.
|
|
assert retention_cutoff(datetime(2026,10,31,22,tzinfo=UTC)) == datetime(2026,9,30,21,tzinfo=UTC)
|
|
|
|
|
|
def test_cleanup_only_older_regular_partitions_and_does_not_follow_symlinks(tmp_path):
|
|
directory = tmp_path / 'journal'
|
|
directory.mkdir()
|
|
older = directory / 'program-2026-08.sqlite3'; older.write_bytes(b'old')
|
|
september = directory / 'program-2026-09.sqlite3'; september.write_bytes(b'keep')
|
|
unrelated = directory / 'application.sqlite3'; unrelated.write_bytes(b'keep')
|
|
outside = tmp_path / 'outside'; outside.write_bytes(b'keep')
|
|
link = directory / 'program-2026-07.sqlite3'; link.symlink_to(outside)
|
|
store = ProgramLogStore(directory, now=lambda:NOW)
|
|
store._prepare_directory()
|
|
assert store.cleanup(force=True) == 1
|
|
assert not older.exists() and september.exists() and unrelated.exists()
|
|
assert link.is_symlink() and outside.read_bytes() == b'keep'
|
|
|
|
|
|
def test_no_directory_symlink_traversal(tmp_path):
|
|
actual = tmp_path/'actual'; actual.mkdir()
|
|
link = tmp_path/'link'; link.symlink_to(actual, target_is_directory=True)
|
|
store = ProgramLogStore(link/'journal', now=lambda:NOW)
|
|
with pytest.raises(ValueError): store._prepare_directory()
|
|
|
|
|
|
def test_rollover_daily_cleanup_without_restart(tmp_path):
|
|
clock = [datetime(2026, 10, 31, 20, tzinfo=UTC)]
|
|
store = ProgramLogStore(tmp_path/'journal',now=lambda:clock[0])
|
|
store.start(); assert store._ready.wait(3)
|
|
emit(store,datetime(2026,9,1,tzinfo=UTC),message='september')
|
|
emit(store,clock[0],message='october')
|
|
assert (store.directory/'program-2026-09.sqlite3').exists()
|
|
clock[0] = datetime(2026,10,31,21,1,tzinfo=UTC)
|
|
emit(store,clock[0],message='november')
|
|
assert not (store.directory/'program-2026-09.sqlite3').exists()
|
|
assert (store.directory/'program-2026-10.sqlite3').exists()
|
|
assert (store.directory/'program-2026-11.sqlite3').exists()
|
|
store.close()
|
|
|
|
|
|
def test_redaction_nested_credentials_urls_and_tracebacks(store):
|
|
secret = {'password': 'hidden-pass', 'device_secret': 'hidden-device',
|
|
'nested': {'Authorization': 'Bearer hidden-auth', 'url': 'https://server/api?token=hidden-url'},
|
|
'safe': 'match-42', 'DATABASE_URL':'postgresql://user:pass@db/name'}
|
|
emit(store,message='password=hidden-inline Bearer hidden-bearer /vmix/session/hidden-path/info',details=secret)
|
|
text = json.dumps(store.query()['items'],ensure_ascii=False)
|
|
for forbidden in ('hidden-pass','hidden-device','hidden-auth','hidden-url','hidden-inline','hidden-bearer','hidden-path','user:pass'):
|
|
assert forbidden not in text
|
|
assert 'match-42' in text and '[REDACTED]' in text
|
|
assert redact({'mapping_profile': 42, 'pin': 'unsafe'}) == {'mapping_profile': 42, 'pin': '[REDACTED]'}
|
|
|
|
|
|
def test_bounded_queue_reports_drops_and_does_not_block(tmp_path):
|
|
store=ProgramLogStore(tmp_path/'journal',queue_size=1,now=lambda:NOW)
|
|
assert store.emit(message='first')
|
|
assert not store.emit(message='second')
|
|
assert store.stats()['dropped']==1
|
|
store.start();assert store._ready.wait(3)
|
|
assert store.flush()
|
|
items=store.query()['items']
|
|
assert any(item['message']=='first' for item in items)
|
|
assert any(item['event']=='records.dropped' for item in items)
|
|
store.close()
|
|
|
|
|
|
def test_cursor_no_duplicates_across_months_and_identical_timestamps(store):
|
|
for n in range(12):
|
|
assert store.emit(timestamp=datetime(2026,9,30,20 if n<6 else 21,tzinfo=UTC),message=str(n))
|
|
assert store.flush()
|
|
seen=[];cursor=''
|
|
while True:
|
|
page=store.query(preset='all',limit=3,cursor=cursor,sort='asc')
|
|
seen.extend(item['id'] for item in page['items'])
|
|
if not page['has_more']:break
|
|
cursor=page['next_cursor']
|
|
assert len(seen)==len(set(seen))==12
|
|
with pytest.raises(ValueError):store.query(preset='all',limit=3,cursor=cursor,sort='desc')
|
|
|
|
|
|
def test_week_is_rolling_seven_days(store):
|
|
emit(store,NOW.replace(day=14,hour=11),message='outside')
|
|
emit(store,NOW.replace(day=14,hour=12),message='boundary')
|
|
assert [item['message'] for item in store.query(preset='week')['items']]==['boundary']
|
|
|
|
|
|
def test_handler_context_and_exception_redaction(store):
|
|
token=set_log_context(actor_id='42',actor_login='Op',game_id='123')
|
|
record=logging.LogRecord('hockey.test',logging.ERROR,__file__,1,'cannot open %s',('password=secretword',),None)
|
|
ProgramLogHandler(store).emit(record)
|
|
reset_log_context(token)
|
|
assert store.flush()
|
|
item=store.query()['items'][0]
|
|
assert item['actor_id']=='42' and item['game_id']=='123'
|
|
assert 'secretword' not in item['message']
|
|
|
|
|
|
def test_txt_jsonl_download_and_literal_percent_search(store):
|
|
emit(store,message='progress 100%_done',details={'count':42})
|
|
assert len(store.query(q='100%_')['items'])==1
|
|
text=b''.join(store.download(preset='all',format='txt')).decode()
|
|
assert 'Europe/Moscow' in text and 'MSK' in text and 'progress' in text
|
|
lines=b''.join(store.download(preset='all',format='jsonl')).decode().splitlines()
|
|
assert len(lines)==1 and json.loads(lines[0])['details']=={'count':42}
|
|
|
|
|
|
def test_routes_require_authenticated_admin_and_download_filtered(store):
|
|
current=[None]
|
|
async def auth():
|
|
if current[0] is None:raise HTTPException(401,'login')
|
|
return current[0]
|
|
app=FastAPI();app.include_router(create_program_log_router(store,auth))
|
|
emit(store,category='mapping',actor_login='Op',message='fail')
|
|
with TestClient(app) as client:
|
|
assert client.get('/api/hockey/program-logs').status_code==401
|
|
current[0]=HockeyUser(id='viewer',login='viewer',display_name='viewer')
|
|
for path in ('','/options','/download'):
|
|
assert client.get('/api/hockey/program-logs'+path).status_code==403
|
|
current[0]=HockeyUser(id='admin',login='admin',display_name='admin',is_admin=True)
|
|
response=client.get('/api/hockey/program-logs',params={'q':'fail'})
|
|
assert response.status_code==200 and len(response.json()['items'])==1
|
|
assert response.headers['cache-control']=='private, no-store'
|
|
result=client.get('/api/hockey/program-logs/download',params={'category':'mapping','format':'jsonl'})
|
|
assert result.status_code==200 and json.loads(result.text)['actor_login']=='Op'
|
|
assert 'attachment;' in result.headers['content-disposition']
|
|
assert client.get('/api/hockey/program-logs',params={'date_from':'bad'}).status_code==422
|
|
assert client.get('/api/hockey/program-logs',params={'date_to':'9999-12-31'}).status_code==422
|
|
assert client.get('/api/hockey/program-logs',params={'date_from':'2026-10-22','date_to':'2026-10-20'}).status_code==422
|
|
|
|
|
|
def test_redact_quoted_keys_in_dict_json_and_database_exception():
|
|
for text in ('{"password": "qa_hidden_password"}', "{'password': 'qa_hidden_password'}",
|
|
"{'session_token': 'qa_hidden_password'}",
|
|
"[parameters: {'p': 'qa_hidden_password'}]",
|
|
"[SQL: SELECT :pwd]\n[parameters: {'pwd': 'qa_hidden_password'}]"):
|
|
assert 'qa_hidden_password' not in redact_text(text)
|