commit f197a670cacbc09279179a2cea559b2ddcecdb39 parent b183e3a195cc301431577f52fa6aa365ab757bad Author: Florian Dold <dold@taler.net> Date: Fri, 11 Sep 2026 19:35:04 +0200 monitoring: derive exchange request latency from nginx logs Aggregate timing records locally with Fluent Bit when enabled by the monitoring bundle. Include ordinary API GETs while excluding requested long polls, and expose bounded latency histograms through the mTLS proxy. Persist the tail cursor and rotate timing logs. Histogram state remains in memory for operational monitoring. Diffstat:
15 files changed, 457 insertions(+), 3 deletions(-)
diff --git a/README b/README @@ -496,8 +496,78 @@ that run's snapshot. Retry after the existing backup finishes; a reboot playbook aborts before rebooting on this failure. Pruning and compaction are skipped after an unsuccessful or warning-producing archive creation. +## Exchange HTTP latency monitoring + +Sentol can opt an exchange into latency collection with +`monitoring_nginx_latency_enabled: true` in its external-host inventory. Its +exported public bundle then contains `monitoring_client.nginx_latency.enabled: +true`. Redistribute the bundle and deploy this repository with `enable_monitoring` +enabled. Missing or false capability values disable the feature; the capability +must be a boolean and the exchange domain must be a safe hostname. + +Fluent Bit tails `/var/log/nginx/<exchange_domain>.tal` and aggregates nginx's +`rt` field into `nginx_request_duration_seconds` histogram buckets, sum and count. +The labels are `operation`, `method` and `status`. The checked-in +`roles/monitoring/files/exchange-latency-routes.json` allowlist is shared by nginx +GET selection and Fluent Bit classification; update it alongside exchange API +route changes. Operation names omit identifiers; `/batch-deposit` is `deposit`. +Unrecognized mutation routes are `other`. Malformed records increment +`nginx_timing_log_parse_errors_total`; oversized lines are skipped so tailing can +continue. Fluent Bit diagnostics report oversized lines separately. + +POST, PATCH and DELETE keep their existing coverage. The exchange's nginx +virtual host additionally logs known API GETs, including ordinary requests to +endpoints that optionally long-poll. Reserve status, deposit tracking, purse +merge/deposit status, KYC check and KYC info GETs are included only when +`timeout_ms` is absent or consists entirely of zero digits. Purse requests also +check the documented `deposit_timeout_ms` argument conservatively. Calls with a +positive timeout are excluded even when they return immediately. + +On these polling-capable routes, repeated timeout arguments, malformed values, +and queries containing percent escapes or plus signs are excluded. This may omit +unusual ordinary calls, but prevents encoded polling arguments entering latency +charts. Query strings are inspected only inside nginx and are not added to timing +logs. Ordinary `/keys` requests remain included when server trouble makes them +slow. Unknown GET routes, metrics endpoints, static downloads, HEAD and OPTIONS +are excluded. Other services' timing-log selection is unaffected. + +Generated metrics listen on `127.0.0.1:2021/metrics` and are exposed through the +existing Sentol-only mTLS proxy at `/nginx/metrics`. Port 2021 must not conflict +with the configured node exporter or metrics proxy. The usual collector-health +endpoint on port 2020 and journal forwarding continue separately; timing records +are consumed locally and never sent to VictoriaLogs. + +First enrollment starts at the end of the existing timing log. Later starts +resume `/var/lib/fluent-bit/exchange-timing.db`; deployment must not remove this +cursor. Rotation should rename the file and tell nginx to reopen its logs; +Fluent Bit continues watching the old descriptor for 30 seconds. Rotation while +the collector is stopped can lose observations: the input follows the active +filename and does not replay rotated archives. A dedicated logrotate rule retains 14 +daily timing logs with delayed compression, matching Debian's standard nginx +policy (whose `*.log` pattern does not cover `.tal`). This rule remains installed +when latency metrics are disabled, since mutation timing logs are still written. + +Histogram state is in memory and resets on collector restart. Prometheus retains +already scraped history, but can lose observations since its last scrape. Unread +records appear when processed after recovery, which can temporarily distort +rates. This is operational monitoring, not exact accounting. The Perses dashboard +uses counter-aware five-minute queries and defers latency alert thresholds until +a baseline is available. Disabling the capability removes the scrape route and +collector input after redeployment, while preserving the cursor for later use. + +Diagnose collection locally with `curl http://127.0.0.1:2021/metrics` and +`journalctl -u fluent-bit`; inspect the latency dashboard's scrape and parse-error +panels on Sentol. Before deployment, configuration is checked with the pinned +Fluent Bit binary's `--dry-run` mode and nginx's `-t` mode. + ## Regression checks +`python3 contrib/tests/test_nginx_latency.py` checks the timing parser and bounded +route classification (requires Python Jinja2 and Lua). The `tsys-infra/monitoring` +Podman suite exercises this repository's real monitoring role, nginx GET +selection, pinned Fluent Bit histograms, mTLS scraping, rotation, cursor recovery, +and Perses queries across resets and idle windows. + Run python3 contrib/tests/test_backup.py for isolated concurrency, failure, cleanup and archive round-trip checks (requires Borg and Python Jinja2). The extended ./test also exercises real systemd shutdown, package-start diff --git a/contrib/tests/test_monitoring_listeners.py b/contrib/tests/test_monitoring_listeners.py @@ -72,6 +72,34 @@ class MonitoringListenersTest(unittest.TestCase): with self.assertRaises(ValueError): VALIDATOR.validate_listeners(self.node(bind)) + def test_latency_listener_conflicts_only_when_enabled(self): + for node in [self.node('*', port=2021), self.node(port=2021), + self.node(backend='127.0.0.1:2021'), self.node(backend='[::1]:2021')]: + VALIDATOR.validate_listeners(node) + with self.assertRaisesRegex(ValueError, 'nginx latency'): + VALIDATOR.validate_listeners(node, True) + VALIDATOR.validate_listeners(self.node('192.0.2.10', port=2021), True) + + def test_latency_route_is_opt_in(self): + self.assertNotIn('location = /nginx/metrics', self.render(self.node())) + env = Environment(undefined=StrictUndefined) + env.filters['to_json'] = json.dumps + rendered = env.from_string( + (REPO / 'roles/monitoring/templates/nginx.conf.j2').read_text() + ).render(monitoring_public_bundle={'monitoring_client': { + 'node_exporter': self.node(), 'nginx_latency': {'enabled': True}}}) + self.assertIn('location = /nginx/metrics', rendered) + self.assertIn('proxy_pass http://127.0.0.1:2021/metrics;', rendered) + + def test_invalid_latency_capabilities(self): + for latency in [True, None, 'true', {'enabled': 'false'}, {'enabled': 1}]: + public = {'identity': 'exchange.example', 'node_exporter': self.node(), + 'logs': {'protocol': 'jsonline', 'url': 'https://sentol.example/jsonline'}, + 'nginx_latency': latency} + with self.assertRaisesRegex(ValueError, 'boolean enabled'): + VALIDATOR.validate({'public': {'monitoring_client': public}, + 'secrets': {'monitoring_client_secrets': {}}}) + if __name__ == '__main__': unittest.main() diff --git a/contrib/tests/test_nginx_latency.py b/contrib/tests/test_nginx_latency.py @@ -0,0 +1,62 @@ +#!/usr/bin/env python3 +"""Exercise the exchange latency classifier with the Lua interpreter.""" +import json +from pathlib import Path +import re +import subprocess +import unittest + +from jinja2 import Environment, StrictUndefined + +REPO = Path(__file__).resolve().parents[2] +ROUTES = json.loads((REPO / 'roles/monitoring/files/exchange-latency-routes.json').read_text()) + + +def render(relative, **values): + env = Environment(undefined=StrictUndefined) + env.filters['to_json'] = json.dumps + return env.from_string((REPO / relative).read_text()).render( + monitoring_nginx_latency_routes=ROUTES, **values) + + +class LatencyTest(unittest.TestCase): + def test_route_allowlist(self): + seen = set() + for row in ROUTES: + key = (row['method'], row['pattern']) + self.assertNotIn(key, seen) + seen.add(key) + self.assertRegex(row['operation'], r'^[a-z][a-z0-9-]*$') + re.compile('^' + row['pattern'] + '$') + self.assertEqual(sum(row['polling'] > 1 and row['method'] == 'GET' for row in ROUTES), 6) + + def test_classifier(self): + source = render('roles/monitoring/templates/exchange-latency.lua.j2') + cases = [ + ('POST', '/batch-deposit', '200', '0.005', '0.001', '0.004', 'deposit'), + ('GET', '/config', '304', '0.000', '-', '-', 'config'), + ('GET', '/reserves/SECRET', '404', '0.1', '-', '-', 'reserves'), + ('POST', '/withdraw', '502', '0.5', '0.001, 0.002', '0.1, 0.3', 'withdraw'), + ('POST', '/coins/SECRET/refund', '200', '11.001', '0.001 : 0.002', '0.2 : 10.1', 'coins-refund'), + ('PATCH', '/unknown/SECRET', '400', '0.2', '-', '-', 'other'), + ('DELETE', '/purses/SECRET', '204', '0.001', '-', '-', 'purses'), + ] + for method, uri, status, duration, uct, urt, operation in cases: + line = f'm={method} uri={uri} s={status} uct={uct} urt={urt} rt={duration} rl=10 bs=20' + source += '\ndo\nlocal _, _, r = exchange_latency("test", 42, {log=' + json.dumps(line) + '})\n' + source += f'assert(r.valid == "true" and r.operation == "{operation}")\n' + source += f'assert(r.duration == {duration} and r.method == "{method}" and r.status == "{status}")\n' + source += 'assert(r.uri == nil and r.log == nil)\nend\n' + for line in ['garbage', 'm=GET uri=/unknown s=200 uct=- urt=- rt=0.1 rl=1 bs=1', + 'm=HEAD uri=/config s=200 uct=- urt=- rt=0.1 rl=1 bs=1', + 'm=POST uri=/withdraw s=999 uct=- urt=- rt=0.1 rl=1 bs=1', + 'm=POST uri=/withdraw s=200 uct=- urt=- rt=-1 rl=1 bs=1', + 'm=POST uri=/withdraw s=200 uct=- urt=- rt=NaN rl=1 bs=1', + 'm=POST uri=/withdraw s=200 uct=- urt=- rt=' + '9' * 400 + ' rl=1 bs=1']: + source += '\ndo\nlocal _, _, r = exchange_latency("test", 42, {log=' + json.dumps(line) + '})\nassert(r.valid == "false")\nend\n' + result = subprocess.run(['lua', '-'], input=source, text=True, capture_output=True) + self.assertEqual(result.returncode, 0, result.stderr) + + +if __name__ == '__main__': + unittest.main() diff --git a/roles/exchange/templates/etc/nginx/sites-available/exchange-nginx.conf.j2 b/roles/exchange/templates/etc/nginx/sites-available/exchange-nginx.conf.j2 @@ -21,7 +21,7 @@ server { error_log /var/log/nginx/{{ exchange_domain }}.err; access_log /var/log/nginx/{{ exchange_domain }}.log; - access_log /var/log/nginx/{{ exchange_domain }}.tal taler if=$log_perf; + access_log /var/log/nginx/{{ exchange_domain }}.tal taler if=$exchange_log_perf; location / { proxy_pass http://unix:/var/run/taler-exchange/httpd/exchange-http.sock; diff --git a/roles/monitoring/files/exchange-latency-routes.json b/roles/monitoring/files/exchange-latency-routes.json @@ -0,0 +1,70 @@ +[ + {"method": "DELETE", "pattern": "/purses/[^/]+", "operation": "purses", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/accounts", "operation": "aml-accounts", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/attributes/[^/]+", "operation": "aml-attributes", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/decisions", "operation": "aml-decisions", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/kyc-statistics/[^/]+", "operation": "aml-kyc-statistics", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/legitimizations", "operation": "aml-legitimizations", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/measures", "operation": "aml-measures", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/transfers-credit", "operation": "aml-transfers-credit", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/transfers-debit", "operation": "aml-transfers-debit", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/transfers-kycauth", "operation": "aml-transfers-kycauth", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+/wallet-credit", "operation": "aml-wallet-credit", "polling": 1}, + {"method": "GET", "pattern": "/aml/[^/]+", "operation": "aml", "polling": 1}, + {"method": "GET", "pattern": "/coins/[^/]+/history", "operation": "coins-history", "polling": 1}, + {"method": "GET", "pattern": "/config", "operation": "config", "polling": 1}, + {"method": "GET", "pattern": "/contracts/[^/]+", "operation": "contracts", "polling": 1}, + {"method": "GET", "pattern": "/deposits/[^/]+/[^/]+/[^/]+/[^/]+", "operation": "deposits", "polling": 2}, + {"method": "GET", "pattern": "/keys", "operation": "keys", "polling": 1}, + {"method": "GET", "pattern": "/kyc-check/[^/]+", "operation": "kyc-check", "polling": 2}, + {"method": "GET", "pattern": "/kyc-info/[^/]+", "operation": "kyc-info", "polling": 2}, + {"method": "GET", "pattern": "/kyc-proof/[^/]+", "operation": "kyc-proof", "polling": 1}, + {"method": "GET", "pattern": "/kyc-spa/[^/]+", "operation": "kyc-spa", "polling": 1}, + {"method": "GET", "pattern": "/kyc-webhook/[^/]+/.+", "operation": "kyc-webhook", "polling": 1}, + {"method": "POST", "pattern": "/kyc-webhook/[^/]+/.+", "operation": "kyc-webhook", "polling": 1}, + {"method": "GET", "pattern": "/management/keys", "operation": "management-keys", "polling": 1}, + {"method": "GET", "pattern": "/purses/[^/]+/merge", "operation": "purses-merge", "polling": 3}, + {"method": "GET", "pattern": "/purses/[^/]+/deposit", "operation": "purses-deposit", "polling": 3}, + {"method": "GET", "pattern": "/reserves/[^/]+/attest", "operation": "reserves-attest", "polling": 1}, + {"method": "GET", "pattern": "/reserves/[^/]+/history", "operation": "reserves-history", "polling": 1}, + {"method": "GET", "pattern": "/reserves/[^/]+", "operation": "reserves", "polling": 2}, + {"method": "GET", "pattern": "/seed", "operation": "seed", "polling": 1}, + {"method": "GET", "pattern": "/transfers/[^/]+", "operation": "transfers", "polling": 1}, + {"method": "GET", "pattern": "/wads/[^/]+", "operation": "wads", "polling": 1}, + {"method": "POST", "pattern": "/aml/[^/]+/decision", "operation": "aml-decision", "polling": 1}, + {"method": "POST", "pattern": "/aml/[^/]+/render-form", "operation": "aml-render-form", "polling": 1}, + {"method": "POST", "pattern": "/auditors/[^/]+/[^/]+", "operation": "auditors", "polling": 1}, + {"method": "POST", "pattern": "/batch-deposit", "operation": "deposit", "polling": 1}, + {"method": "POST", "pattern": "/blinding-prepare", "operation": "blinding-prepare", "polling": 1}, + {"method": "POST", "pattern": "/coins/[^/]+/refund", "operation": "coins-refund", "polling": 1}, + {"method": "POST", "pattern": "/kyc-bulk/[^/]+", "operation": "kyc-bulk", "polling": 1}, + {"method": "POST", "pattern": "/kyc-import/[^/]+", "operation": "kyc-import", "polling": 1}, + {"method": "POST", "pattern": "/kyc-start/[^/]+", "operation": "kyc-start", "polling": 1}, + {"method": "POST", "pattern": "/kyc-upload/[^/]+", "operation": "kyc-upload", "polling": 1}, + {"method": "POST", "pattern": "/kyc-wallet", "operation": "kyc-wallet", "polling": 1}, + {"method": "POST", "pattern": "/management/aml-officers", "operation": "management-aml-officers", "polling": 1}, + {"method": "POST", "pattern": "/management/auditors/[^/]+/disable", "operation": "management-auditors-disable", "polling": 1}, + {"method": "POST", "pattern": "/management/auditors", "operation": "management-auditors", "polling": 1}, + {"method": "POST", "pattern": "/management/denominations/[^/]+/revoke", "operation": "management-denominations-revoke", "polling": 1}, + {"method": "POST", "pattern": "/management/drain", "operation": "management-drain", "polling": 1}, + {"method": "POST", "pattern": "/management/global-fees", "operation": "management-global-fees", "polling": 1}, + {"method": "POST", "pattern": "/management/keys", "operation": "management-keys", "polling": 1}, + {"method": "POST", "pattern": "/management/partners", "operation": "management-partners", "polling": 1}, + {"method": "POST", "pattern": "/management/signkeys/[^/]+/revoke", "operation": "management-signkeys-revoke", "polling": 1}, + {"method": "POST", "pattern": "/management/wire/disable", "operation": "management-wire-disable", "polling": 1}, + {"method": "POST", "pattern": "/management/wire-fee", "operation": "management-wire-fee", "polling": 1}, + {"method": "POST", "pattern": "/management/wire", "operation": "management-wire", "polling": 1}, + {"method": "POST", "pattern": "/melt", "operation": "melt", "polling": 1}, + {"method": "POST", "pattern": "/purses/[^/]+/create", "operation": "purses-create", "polling": 1}, + {"method": "POST", "pattern": "/purses/[^/]+/deposit", "operation": "purses-deposit", "polling": 3}, + {"method": "POST", "pattern": "/purses/[^/]+/merge", "operation": "purses-merge", "polling": 3}, + {"method": "POST", "pattern": "/recoup-refresh", "operation": "recoup-refresh", "polling": 1}, + {"method": "POST", "pattern": "/recoup-withdraw", "operation": "recoup-withdraw", "polling": 1}, + {"method": "POST", "pattern": "/reserves/[^/]+/attest", "operation": "reserves-attest", "polling": 1}, + {"method": "POST", "pattern": "/reserves/[^/]+/close", "operation": "reserves-close", "polling": 1}, + {"method": "POST", "pattern": "/reserves/[^/]+/open", "operation": "reserves-open", "polling": 1}, + {"method": "POST", "pattern": "/reserves/[^/]+/purse", "operation": "reserves-purse", "polling": 1}, + {"method": "POST", "pattern": "/reveal-melt", "operation": "reveal-melt", "polling": 1}, + {"method": "POST", "pattern": "/reveal-withdraw", "operation": "reveal-withdraw", "polling": 1}, + {"method": "POST", "pattern": "/withdraw", "operation": "withdraw", "polling": 1} +] diff --git a/roles/monitoring/files/validate-bundle.py b/roles/monitoring/files/validate-bundle.py @@ -33,7 +33,7 @@ def address(value): raise ValueError('Monitoring proxy bind address must be an IP address.') from None -def validate_listeners(node): +def validate_listeners(node, nginx_latency=False): backend = node['backend_listen_address'] require(isinstance(backend, str), 'Invalid node_exporter backend address.') match = re.fullmatch(r'(127\.0\.0\.1|\[::1\]):([0-9]+)', backend) @@ -52,6 +52,9 @@ def validate_listeners(node): 'The monitoring proxy conflicts with Fluent Bit metrics.') require(not (overlaps_backend and node['proxy_port'] == int(match[2])), 'Monitoring proxy and backend listeners must not conflict.') + if nginx_latency: + require(int(match[2]) != 2021 and not (overlaps_backend and node['proxy_port'] == 2021), + 'Monitoring listeners conflict with nginx latency metrics.') def openssl(*args): @@ -78,7 +81,10 @@ def validate(bundle): raise ValueError('Invalid monitoring log port.') from None require(port(target_port if target_port is not None else 443) and port(node['proxy_port']), 'Invalid monitoring port.') - validate_listeners(node) + latency = public.get('nginx_latency', {}) + require(isinstance(latency, dict) and type(latency.get('enabled', False)) is bool, + 'The nginx latency capability must contain a boolean enabled value.') + validate_listeners(node, latency.get('enabled', False)) # TemporaryDirectory is private (0700); private files are created as 0600. # Validate the complete pair before Ansible replaces any live material. diff --git a/roles/monitoring/tasks/fluent-bit.yml b/roles/monitoring/tasks/fluent-bit.yml @@ -113,6 +113,35 @@ mode: "0644" notify: Restart monitoring Fluent Bit +- name: Install exchange latency collector configuration + ansible.builtin.template: + src: "{{ item }}.j2" + dest: "/etc/fluent-bit/{{ item }}" + owner: root + group: root + mode: "0600" + loop: + - exchange-latency.lua + - exchange-latency.conf + when: monitoring_nginx_latency_enabled + notify: Restart monitoring Fluent Bit + +- name: Install logrotate for exchange timing logs + ansible.builtin.apt: + name: logrotate + state: present + install_recommends: false + when: monitoring_nginx_latency_enabled + +- name: Rotate the exchange timing log alongside standard nginx logs + ansible.builtin.template: + src: exchange-timing-logrotate.j2 + dest: /etc/logrotate.d/taler-exchange-timing + owner: root + group: root + mode: "0644" + when: monitoring_nginx_latency_enabled + - name: Configure buffered JSON Lines forwarding ansible.builtin.template: src: fluent-bit.conf.j2 diff --git a/roles/monitoring/tasks/preflight.yml b/roles/monitoring/tasks/preflight.yml @@ -69,3 +69,23 @@ - ansible_facts['distribution_major_version'] == '13' - ansible_facts['architecture'] in ['x86_64', 'aarch64'] quiet: true + +- name: Read the optional nginx latency capability + ansible.builtin.set_fact: + monitoring_nginx_latency_enabled: >- + {{ monitoring_public_bundle.monitoring_client.get('nginx_latency', {}).get('enabled', false) }} + +- name: Load the exchange latency route allowlist + ansible.builtin.set_fact: + monitoring_nginx_latency_routes: >- + {{ lookup('ansible.builtin.file', role_path ~ '/files/exchange-latency-routes.json') | from_json }} + when: monitoring_nginx_latency_enabled + +- name: Require a safe exchange timing log name + ansible.builtin.assert: + that: + - exchange_domain is defined + - exchange_domain is match('^[A-Za-z0-9][A-Za-z0-9.-]*$') + fail_msg: Nginx latency collection needs the exchange domain to identify its timing log. + quiet: true + when: monitoring_nginx_latency_enabled diff --git a/roles/monitoring/templates/exchange-latency.conf.j2 b/roles/monitoring/templates/exchange-latency.conf.j2 @@ -0,0 +1,58 @@ +# Managed by Ansible. Histograms are local; only journal records are shipped. +[INPUT] + Name tail + Alias exchange_timing + Tag exchange.timing + Path /var/log/nginx/{{ exchange_domain }}.tal + DB /var/lib/fluent-bit/exchange-timing.db + DB.Sync Full + Read_From_Head Off + Refresh_Interval 1 + Rotate_Wait 30 + Buffer_Max_Size 64k + Skip_Long_Lines On + Mem_Buf_Limit 16M + +[FILTER] + Name lua + Match exchange.timing + Script /etc/fluent-bit/exchange-latency.lua + Call exchange_latency + +[FILTER] + Name log_to_metrics + Match exchange.timing + Tag exchange.metrics + Metric_Mode histogram + Metric_Namespace nginx + Metric_Subsystem request + Metric_Name duration_seconds + Metric_Description Completed exchange request duration in seconds + Value_Field duration + Regex valid ^true$ + Label_Field operation + Label_Field method + Label_Field status + Flush_Interval_Sec 1 +{% for bucket in [0.005, 0.01, 0.025, 0.05, 0.1, 0.25, 0.5, 1, 2.5, 5, 10] %} + Bucket {{ bucket }} +{% endfor %} + +[FILTER] + Name log_to_metrics + Match exchange.timing + Tag exchange.metrics + Metric_Mode counter + Metric_Namespace nginx + Metric_Subsystem timing_log + Metric_Name parse_errors_total + Metric_Description Malformed exchange timing log records + Regex valid ^false$ + Flush_Interval_Sec 1 + Discard_Logs On + +[OUTPUT] + Name prometheus_exporter + Match exchange.metrics + Host 127.0.0.1 + Port 2021 diff --git a/roles/monitoring/templates/exchange-latency.lua.j2 b/roles/monitoring/templates/exchange-latency.lua.j2 @@ -0,0 +1,37 @@ +-- Managed by Ansible. Classify the compact nginx 'taler' format locally. +-- Route patterns are shared with nginx GET selection; identifiers never become labels. +local routes = { +{% for route in monitoring_nginx_latency_routes %} + { {{ route.method | to_json }}, {{ ('^' ~ route.pattern ~ '$') | replace('-', '%-') | to_json }}, {{ route.operation | to_json }} }, +{% endfor %} +} + +function exchange_latency(tag, timestamp, record) + local line = record["log"] + if type(line) ~= "string" then + return 2, timestamp, { valid = "false" } + end + local method, uri, status, duration = line:match( + "^m=(%u+) uri=(%S+) s=(%d%d%d) uct=.- urt=.- rt=(%d+%.?%d*) rl=%d+ bs=%d+$") + local seconds = tonumber(duration) + if not seconds or seconds == math.huge or + (method ~= "GET" and method ~= "POST" and method ~= "PATCH" and method ~= "DELETE") or + (status ~= "000" and (tonumber(status) < 100 or tonumber(status) > 599)) then + return 2, timestamp, { valid = "false" } + end + local operation = "other" + for _, route in ipairs(routes) do + if method == route[1] and uri:match(route[2]) then + operation = route[3] + break + end + end + -- GET selection is performed by nginx; reject unknown GETs defensively. + if method == "GET" and operation == "other" then + return 2, timestamp, { valid = "false" } + end + return 2, timestamp, { + valid = "true", duration = seconds, + method = method, status = status, operation = operation + } +end diff --git a/roles/monitoring/templates/exchange-timing-logrotate.j2 b/roles/monitoring/templates/exchange-timing-logrotate.j2 @@ -0,0 +1,13 @@ +# Managed by Ansible. Debian's nginx rule only matches *.log, not *.tal. +/var/log/nginx/{{ exchange_domain }}.tal { + daily + missingok + rotate 14 + compress + delaycompress + notifempty + create 0640 www-data adm + postrotate + invoke-rc.d nginx rotate >/dev/null 2>&1 + endscript +} diff --git a/roles/monitoring/templates/fluent-bit.conf.j2 b/roles/monitoring/templates/fluent-bit.conf.j2 @@ -49,3 +49,7 @@ Retry_Limit False storage.total_limit_size {{ monitoring_fluent_bit_queue_limit }} Log_Response_Payload Off +{% if monitoring_nginx_latency_enabled | default(false) %} + +@INCLUDE /etc/fluent-bit/exchange-latency.conf +{% endif %} diff --git a/roles/monitoring/templates/nginx.conf.j2 b/roles/monitoring/templates/nginx.conf.j2 @@ -51,6 +51,14 @@ http { proxy_set_header Connection ""; proxy_buffering off; } +{% if monitoring_public_bundle.monitoring_client.get('nginx_latency', {}).get('enabled', false) %} + location = /nginx/metrics { + proxy_pass http://127.0.0.1:2021/metrics; + proxy_http_version 1.1; + proxy_set_header Connection ""; + proxy_buffering off; + } +{% endif %} location / { return 404; } diff --git a/roles/webserver/tasks/main.yml b/roles/webserver/tasks/main.yml @@ -40,6 +40,15 @@ mode: "0644" notify: Restart nginx +- name: Configure exchange timing log request selection + ansible.builtin.template: + src: exchange-latency.conf.j2 + dest: /etc/nginx/conf.d/exchange-latency.conf + owner: root + group: root + mode: "0644" + notify: Restart nginx + - name: Remove obsolete global HTTP2/HTTP3 configuration ansible.builtin.file: path: /etc/nginx/conf.d/http2-http3.conf diff --git a/roles/webserver/templates/exchange-latency.conf.j2 b/roles/webserver/templates/exchange-latency.conf.j2 @@ -0,0 +1,40 @@ +# Managed by Ansible. Only the exchange virtual host uses $exchange_log_perf. +# 0: unknown/mutation, 1: ordinary GET, 2: optional polling, 3: purse polling. +map "$request_method:$uri" $exchange_latency_get_route { + default 0; +{% if enable_monitoring | default(false) | bool and monitoring_nginx_latency_enabled | default(false) | bool %} +{% for route in monitoring_nginx_latency_routes if route.method == 'GET' %} + {{ ('~^GET:' ~ route.pattern ~ '$') | to_json }} {{ route.polling }}; +{% endfor %} +{% endif %} +} + +# Do not persist query strings. Treat encoded/ambiguous query arguments as +# potentially polling on polling-capable routes. Backend argument decoding +# differs from nginx's $arg_* lookup, particularly for encoded parameter names. +map $args $exchange_latency_args_ambiguous { + default 0; + ~[%+] 1; + ~*(^|&)timeout_ms(?:=[^&]*)?(?:&[^&]*)*&timeout_ms(?:=|&|$) 1; + ~*(^|&)deposit_timeout_ms(?:=[^&]*)?(?:&[^&]*)*&deposit_timeout_ms(?:=|&|$) 1; +} +map $args $exchange_latency_timeout_safe { + default 1; + ~*(^|&)timeout_ms=0+(&|$) 1; + ~*(^|&)timeout_ms(=|&|$) 0; +} +map $args $exchange_latency_deposit_timeout_safe { + default 1; + ~*(^|&)deposit_timeout_ms=0+(&|$) 1; + ~*(^|&)deposit_timeout_ms(=|&|$) 0; +} +map "$exchange_latency_get_route:$exchange_latency_args_ambiguous:$exchange_latency_timeout_safe:$exchange_latency_deposit_timeout_safe" $exchange_latency_get_allowed { + default 0; + ~^1: 1; + ~^2:0:1: 1; + "3:0:1:1" 1; +} +map $exchange_latency_get_allowed $exchange_log_perf { + default $log_perf; + 1 1; +}