diff --git a/backend/app/services/drift_service.py b/backend/app/services/drift_service.py index e8a3ea3b..9bb5d069 100644 --- a/backend/app/services/drift_service.py +++ b/backend/app/services/drift_service.py @@ -47,6 +47,7 @@ import difflib import json import logging import os +import re import sys from datetime import datetime @@ -388,6 +389,23 @@ def _with_expected_waf(app_id, config): return injected if injected is not None else config +# A vhost written before the timed log format (plan 86 §A1) has a bare +# `access_log ;`. That is not drift: the format only changes what the log +# records, and the next regeneration adopts it. Read such lines as the timed +# form so an upgrade doesn't flag (and notify about) every existing site. +_LEGACY_ACCESS_LOG_RE = re.compile( + r'^(\s*access_log /var/log/nginx/[^\s;]+\.access\.log);$', re.MULTILINE) + + +def _nginx_read_actual(paths): + actual = _default_read_actual(paths) + return { + path: (_LEGACY_ACCESS_LOG_RE.sub(r'\1 serverkit_timed;', content) + if content is not None else None) + for path, content in actual.items() + } + + def _nginx_repair(app_id): from app.models.application import Application from app.services.nginx_service import NginxService @@ -425,6 +443,7 @@ register_check({ 'supported': _linux_only, 'list_resources': _nginx_list_resources, 'render_expected': _nginx_render_expected, + 'read_actual': _nginx_read_actual, 'repair': _nginx_repair, }) diff --git a/backend/app/services/environment_domain_service.py b/backend/app/services/environment_domain_service.py index 045621c2..6d6be24f 100644 --- a/backend/app/services/environment_domain_service.py +++ b/backend/app/services/environment_domain_service.py @@ -30,7 +30,7 @@ class EnvironmentDomainService: listen [::]:80; server_name {domain}; - access_log /var/log/nginx/{site_name}.access.log; + access_log /var/log/nginx/{site_name}.access.log serverkit_timed; error_log /var/log/nginx/{site_name}.error.log; {extra_headers} diff --git a/backend/app/services/nginx_service.py b/backend/app/services/nginx_service.py index 48782ce3..00147ccd 100644 --- a/backend/app/services/nginx_service.py +++ b/backend/app/services/nginx_service.py @@ -58,7 +58,7 @@ class NginxService: root {root_path}; index index.php index.html index.htm; - access_log /var/log/nginx/{name}.access.log; + access_log /var/log/nginx/{name}.access.log serverkit_timed; error_log /var/log/nginx/{name}.error.log; location / {{ @@ -101,7 +101,7 @@ class NginxService: listen [::]:80; server_name {domains}; - access_log /var/log/nginx/{name}.access.log; + access_log /var/log/nginx/{name}.access.log serverkit_timed; error_log /var/log/nginx/{name}.error.log; location / {{ @@ -132,7 +132,7 @@ class NginxService: root {root_path}; index index.html index.htm; - access_log /var/log/nginx/{name}.access.log; + access_log /var/log/nginx/{name}.access.log serverkit_timed; error_log /var/log/nginx/{name}.error.log; location / {{ @@ -152,7 +152,7 @@ class NginxService: listen [::]:80; server_name {domains}; - access_log /var/log/nginx/{name}.access.log; + access_log /var/log/nginx/{name}.access.log serverkit_timed; error_log /var/log/nginx/{name}.error.log; location / {{ @@ -222,7 +222,7 @@ limit_req_zone $server_name$binary_remote_addr zone=serverkit_wp_xmlrpc:10m rate listen [::]:80; server_name {domains}; - access_log /var/log/nginx/{name}.access.log; + access_log /var/log/nginx/{name}.access.log serverkit_timed; error_log /var/log/nginx/{name}.error.log; location / {{ @@ -360,6 +360,23 @@ location = /wordpress {{ }} ''' + # ==================== TIMED ACCESS LOG (plan 86 §A1) ==================== + # Every vhost ServerKit writes logs in this format. The combined fields come + # first, unchanged, so every existing combined-format reader (bandwidth + # accounting, the fail2ban `^ -` filters) keeps matching; the timing + # fields are appended after them. The app id is the log file itself + # (/var/log/nginx/.access.log) — a per-vhost `set` variable would make + # `nginx -t` warn on every server block that never sets it. + TIMED_LOG_FORMAT = 'serverkit_timed' + TIMED_LOG_CONF_NAME = 'serverkit-log-format.conf' + TIMED_LOG_FORMAT_SNIPPET = """# ServerKit timed access-log format (auto-generated; do not edit). +# Combined fields first (compatible with combined parsers), then timing. +log_format serverkit_timed '$remote_addr - $remote_user [$time_local] "$request" ' + '$status $body_bytes_sent "$http_referer" "$http_user_agent" ' + 'rt=$request_time urt="$upstream_response_time" ' + 'cs=$upstream_cache_status h=$host'; +""" + # ==================== MICRO-CACHE (task #21) ==================== # Opt-in per-site micro-cache: a very short (10s) full-page cache in front # of proxied/PHP sites, with hard bypasses for anything personalized. @@ -757,6 +774,27 @@ location /p/ {{ except Exception as e: return {'success': False, 'error': str(e)} + @classmethod + def ensure_log_format(cls) -> Dict: + """Write the ``serverkit_timed`` log_format to conf.d (idempotent). + + ``log_format`` is http-context only, so like the micro-cache zone it is + a conf.d snippet, not part of any vhost. :meth:`write_vhost` calls this + before writing any vhost that references the format. + """ + conf_path = os.path.join(cls.NGINX_CONF_DIR, 'conf.d', cls.TIMED_LOG_CONF_NAME) + try: + if os.path.isfile(conf_path): + with open(conf_path, 'r') as f: + if f.read() == cls.TIMED_LOG_FORMAT_SNIPPET: + return {'success': True, 'changed': False, 'path': conf_path} + written = write_privileged_file(conf_path, cls.TIMED_LOG_FORMAT_SNIPPET) + if not written['success']: + return {'success': False, 'error': written['error']} + return {'success': True, 'changed': True, 'path': conf_path} + except Exception as e: + return {'success': False, 'error': str(e)} + @classmethod def purge_micro_cache(cls) -> Dict: """Wipe the shared micro-cache directory contents. Linux-only. @@ -903,6 +941,14 @@ location /p/ {{ or name in ('.', '..') or '\x00' in name): return {'success': False, 'error': f'Invalid site name: {name!r}'} + # A vhost naming the timed format fails `nginx -t` until the + # http-level log_format exists — declare it first. + if f' {cls.TIMED_LOG_FORMAT};' in content: + fmt = cls.ensure_log_format() + if not fmt.get('success'): + return {'success': False, + 'error': f"log format setup failed: {fmt.get('error')}"} + available_path = os.path.join(cls.SITES_AVAILABLE, name) enabled_path = os.path.join(cls.SITES_ENABLED, name) previous = cls.read_vhost(name) diff --git a/backend/tests/test_nginx_timed_log.py b/backend/tests/test_nginx_timed_log.py new file mode 100644 index 00000000..53297214 --- /dev/null +++ b/backend/tests/test_nginx_timed_log.py @@ -0,0 +1,129 @@ +"""The timed access-log format every generated vhost uses (plan 86 §A1). + +The format appends request/upstream timing and cache status AFTER the standard +combined fields, so the readers that already parse these logs (bandwidth +accounting, the fail2ban `^ -` filters) keep working on both the old and +the new line shape. Asserted here from both ends: what the templates write, and +what the existing parser still reads. +""" +import os +from datetime import date + +import pytest + +from app.services.bandwidth_service import BandwidthService +from app.services.drift_service import _nginx_read_actual +from app.services.nginx_service import NginxService + +OLD_LINE = ('203.0.113.9 - - [03/Jul/2026:10:00:00 +0000] "GET / HTTP/1.1" ' + '200 512 "-" "curl/8"') +NEW_LINE = (OLD_LINE + + ' rt=0.042 urt="0.040" cs=HIT h=shop.example.com') + + +@pytest.mark.parametrize('kwargs', [ + dict(app_type='docker', port=8003), + dict(app_type='static', root_path='/var/www/shop'), + dict(app_type='php', root_path='/var/www/shop'), + dict(app_type='python', port=8004, root_path='/srv/shop'), + dict(app_type='remote', upstream='10.8.0.2:8080'), + dict(app_type='docker', port=8003, micro_cache=True, + ssl_cert='/c.pem', ssl_key='/k.pem'), +]) +def test_every_vhost_flavor_logs_in_the_timed_format(kwargs): + rendered = NginxService.render_site_config( + 'shop', domains=['shop.example.com'], **kwargs) + assert rendered['success'], rendered + assert ('access_log /var/log/nginx/shop.access.log serverkit_timed;' + in rendered['config']) + + +def test_the_format_keeps_combined_fields_first(): + snippet = NginxService.TIMED_LOG_FORMAT_SNIPPET + assert 'log_format serverkit_timed' in snippet + combined = ('$remote_addr - $remote_user [$time_local] "$request" ' + "'\n '" + '$status $body_bytes_sent "$http_referer" "$http_user_agent"') + assert combined in snippet + for field in ('$request_time', '$upstream_response_time', + '$upstream_cache_status', '$host'): + assert field in snippet + assert snippet.index(field) > snippet.index('$http_user_agent') + + +@pytest.mark.parametrize('line', [OLD_LINE, NEW_LINE]) +def test_bandwidth_parser_reads_old_and_new_lines(tmp_path, line): + log = tmp_path / 'shop.access.log' + log.write_text(line + '\n') + per_host, plain, skipped = BandwidthService.parse_log_file( + str(log), date(2026, 7, 3)) + assert plain == [512, 1] + assert skipped == 0 + assert per_host == {} + + +class TestWriteVhostDeclaresTheFormat: + @pytest.fixture + def nginx(self, tmp_path, monkeypatch, fake_subprocess): + from subprocess_stub import FakeProc + + conf = tmp_path / 'nginx' + for d in ('sites-available', 'sites-enabled', 'conf.d'): + (conf / d).mkdir(parents=True) + monkeypatch.setattr(NginxService, 'NGINX_CONF_DIR', str(conf)) + monkeypatch.setattr(NginxService, 'SITES_AVAILABLE', str(conf / 'sites-available')) + monkeypatch.setattr(NginxService, 'SITES_ENABLED', str(conf / 'sites-enabled')) + monkeypatch.setattr('app.services.nginx_service.is_command_available', + lambda *a, **k: True) + + def tee(argv, kwargs): + with open(argv[-1], 'w') as fh: + fh.write(kwargs.get('input', '')) + return FakeProc() + + def ln(argv, kwargs): + open(argv[-1], 'w').close() + return FakeProc() + + fake_subprocess.when(['tee'], tee) + fake_subprocess.when(['ln'], ln) + fake_subprocess.script(['cat'], returncode=1) + fake_subprocess.script(['nginx', '-t']) + fake_subprocess.script(['systemctl']) + return conf + + def test_snippet_is_written_before_a_timed_vhost(self, nginx): + res = NginxService.write_vhost( + 'shop', 'server { access_log /x.log serverkit_timed; }') + assert res['success'], res + snippet = nginx / 'conf.d' / NginxService.TIMED_LOG_CONF_NAME + assert snippet.read_text() == NginxService.TIMED_LOG_FORMAT_SNIPPET + + def test_a_vhost_without_the_format_does_not_write_it(self, nginx): + assert NginxService.write_vhost('shop', 'server {}')['success'] + assert not (nginx / 'conf.d' / NginxService.TIMED_LOG_CONF_NAME).exists() + + +def test_drift_reads_a_legacy_access_log_line_as_the_timed_form(tmp_path): + """An upgrade must not flag every pre-§A1 vhost as drifted.""" + vhost = tmp_path / 'shop' + vhost.write_text('server {\n' + ' access_log /var/log/nginx/shop.access.log;\n' + ' error_log /var/log/nginx/shop.error.log;\n' + '}\n') + got = _nginx_read_actual([str(vhost)])[str(vhost)] + assert ' access_log /var/log/nginx/shop.access.log serverkit_timed;\n' in got + assert ' error_log /var/log/nginx/shop.error.log;\n' in got + + +def test_drift_leaves_a_hand_edited_access_log_alone(tmp_path): + """Only the exact legacy line is equivalent; anything else is real drift.""" + vhost = tmp_path / 'shop' + body = 'server {\n access_log off;\n}\n' + vhost.write_text(body) + assert _nginx_read_actual([str(vhost)])[str(vhost)] == body + + +def test_drift_reports_a_missing_file_as_none(tmp_path): + missing = str(tmp_path / 'nope') + assert _nginx_read_actual([missing]) == {missing: None} diff --git a/backend/tests/test_nginx_write_vhost.py b/backend/tests/test_nginx_write_vhost.py index 8e5c837b..16587775 100644 --- a/backend/tests/test_nginx_write_vhost.py +++ b/backend/tests/test_nginx_write_vhost.py @@ -27,6 +27,8 @@ def nginx(tmp_path, monkeypatch, fake_subprocess): enabled = tmp_path / 'sites-enabled' available.mkdir() enabled.mkdir() + (tmp_path / 'conf.d').mkdir() # http-level snippets (timed log format) + monkeypatch.setattr(NginxService, 'NGINX_CONF_DIR', str(tmp_path)) monkeypatch.setattr(NginxService, 'SITES_AVAILABLE', str(available)) monkeypatch.setattr(NginxService, 'SITES_ENABLED', str(enabled)) monkeypatch.setattr('app.services.nginx_service.is_command_available', diff --git a/backend/tests/test_real_nginx_vhost_syntax.py b/backend/tests/test_real_nginx_vhost_syntax.py index d654c879..c4c28774 100644 --- a/backend/tests/test_real_nginx_vhost_syntax.py +++ b/backend/tests/test_real_nginx_vhost_syntax.py @@ -61,7 +61,7 @@ def _nginx_t(tmp_path, vhost_config): relies on: writable log/cache dirs, the fastcgi_params file that `include fastcgi_params;` resolves against the conf prefix (= tmp_path under `-c`), and the http-level micro-cache zones ServerKit installs - as a conf.d snippet. + and timed log format ServerKit installs as conf.d snippets. """ (tmp_path / 'log').mkdir(exist_ok=True) # nginx -t mkdirs the *_cache_path leaf dirs itself, but not parents. @@ -74,6 +74,7 @@ def _nginx_t(tmp_path, vhost_config): zones.write_text( _localize(NginxService.MICROCACHE_ZONE_SNIPPET, tmp_path) + NginxService.WORDPRESS_RATE_LIMIT_ZONE_SNIPPET + + NginxService.TIMED_LOG_FORMAT_SNIPPET ) vhost = tmp_path / 'vhost.conf' vhost.write_text(_localize(vhost_config, tmp_path))