Dev. CI. Automatic endpoint performance monitoring js_keys__get

.github/perf/js_keys_perf.py

@@ -0,0 +1,142 @@
+#!/usr/bin/env python3
+"""
+Measures cleantalk-antispam/v1/js_keys__get on a clean WP install.
+
+Server-side metrics are read from the Server-Timing header, which the plugin sends
+only when APBCT_SERVICE__PERF_METRICS_HEADER is true. Thresholds come from env
+(GitHub repository variables); an empty threshold is not checked.
+Never exits non-zero: problems are reported as workflow warnings and in the job summary.
+"""
+
+import os
+import re
+import sys
+import time
+import urllib.error
+import urllib.request
+
+URL = os.environ.get('PERF_URL', 'http://localhost:8080/?rest_route=/cleantalk-antispam/v1/js_keys__get')
+REQUESTS = int(os.environ.get('PERF_REQUESTS') or 5)
+WARMUP = int(os.environ.get('PERF_WARMUP') or 1)
+TIMEOUT = 30
+
+# key, column title, unit, threshold env name (None - not checked), description
+METRICS = [
+    ('client', 'Client', 'ms', 'PERF_JS_KEYS_CLIENT_MS', 'Full response time seen by HTTP client'),
+    ('total', 'Total (PHP)', 'ms', 'PERF_JS_KEYS_TOTAL_MS', 'PHP time from request start to response'),
+    ('boot', 'WP boot', 'ms', None, 'WP core load before CleanTalk (not ours, for reference)'),
+    ('init', 'Plugin init', 'ms', 'PERF_JS_KEYS_INIT_MS', 'CleanTalk load + WP init + REST routing'),
+    ('handler', 'Handler', 'ms', 'PERF_JS_KEYS_HANDLER_MS', 'js_keys__get handler itself'),
+    ('sql', 'SQL', '', 'PERF_JS_KEYS_SQL', 'SQL queries for the whole request'),
+    ('mem', 'Peak mem', 'MB', 'PERF_JS_KEYS_MEM_MB', 'PHP peak memory'),
+]
+
+TIMING_RE = re.compile(r'(\w+)\s*;\s*(?:dur=([\d.]+)|desc="?([\d.]+)"?)')
+
+
+def threshold(env_name):
+    if not env_name:
+        return None
+    raw = (os.environ.get(env_name) or '').strip()
+    try:
+        return float(raw) if raw else None
+    except ValueError:
+        print(f'::warning title=Perf js_keys__get::Variable {env_name}="{raw}" is not a number, ignored')
+        return None
+
+
+def parse_server_timing(header):
+    result = {}
+    for name, dur, desc in TIMING_RE.findall(header or ''):
+        result[name] = float(dur or desc)
+    return result
+
+
+def do_request():
+    req = urllib.request.Request(URL, data=b'', method='POST')
+    start = time.perf_counter()
+    try:
+        with urllib.request.urlopen(req, timeout=TIMEOUT) as resp:
+            body = resp.read().decode('utf-8', 'replace')
+            status = resp.status
+            header = resp.headers.get('Server-Timing', '')
+    except urllib.error.HTTPError as e:
+        body, status, header = e.read().decode('utf-8', 'replace'), e.code, e.headers.get('Server-Timing', '')
+    except Exception as e:  # connection problems are reported, not raised
+        return {'error': str(e), 'client': (time.perf_counter() - start) * 1000}
+
+    row = parse_server_timing(header)
+    row['client'] = (time.perf_counter() - start) * 1000
+    row['status'] = status
+    if status != 200 or '"js_key"' not in body:
+        row['error'] = f'HTTP {status}, body: {" ".join(body[:200].split())}'
+    elif not header:
+        row['error'] = 'No Server-Timing header (is APBCT_SERVICE__PERF_METRICS_HEADER defined?)'
+    return row
+
+
+def fmt(value, unit):
+    if value is None:
+        return '—'
+    if unit == '':
+        return str(int(value))
+    return f'{value:.2f}'
+
+
+def main():
+    sys.stdout.reconfigure(encoding='utf-8')
+
+    for _ in range(WARMUP):
+        do_request()
+
+    rows = [do_request() for _ in range(REQUESTS)]
+    limits = {key: threshold(env) for key, _, _, env, _ in METRICS}
+
+    problems = []
+    for i, row in enumerate(rows, 1):
+        if 'error' in row:
+            problems.append(f'Request #{i}: {row["error"]}')
+        for key, title, unit, _, _ in METRICS:
+            limit, value = limits[key], row.get(key)
+            if limit is not None and value is not None and value > limit:
+                problems.append(f'Request #{i}: {title} = {fmt(value, unit)} {unit} > threshold {fmt(limit, unit)} {unit}')
+
+    head = '| # | ' + ' | '.join(f'{t}{", " + u if u else ""}' for _, t, u, _, _ in METRICS) + ' |'
+    lines = [
+        '## js_keys__get performance',
+        '',
+        f'Endpoint: `{URL}`, requests: {REQUESTS} (+{WARMUP} warm-up, not counted).',
+        '',
+        head,
+        '|' + '---|' * (len(METRICS) + 1),
+    ]
+    for i, row in enumerate(rows, 1):
+        cells = []
+        for key, _, unit, _, _ in METRICS:
+            value = row.get(key)
+            mark = ' ⚠️' if limits[key] is not None and value is not None and value > limits[key] else ''
+            cells.append(fmt(value, unit) + mark)
+        if 'error' in row:
+            cells[0] += ' ❌'
+        lines.append(f'| {i} | ' + ' | '.join(cells) + ' |')
+    lines.append('| **Threshold** | ' + ' | '.join(
+        fmt(limits[key], unit) if limits[key] is not None else 'not set' for key, _, unit, _, _ in METRICS
+    ) + ' |')
+    lines += ['', '**Columns:**', '']
+    lines += [f'- **{t}** — {d}' + (f' (var `{e}`)' if e else '') for _, t, _, e, d in METRICS]
+    lines += ['', '### Result', '']
+    lines += [f'- ⚠️ {p}' for p in problems] if problems else ['✅ All requests are within thresholds.']
+
+    report = '\n'.join(lines) + '\n'
+    print(report)
+    summary_file = os.environ.get('GITHUB_STEP_SUMMARY')
+    if summary_file:
+        with open(summary_file, 'a', encoding='utf-8') as f:
+            f.write(report)
+
+    for p in problems:
+        print(f'::warning title=Perf js_keys__get::{p}')
+
+
+if __name__ == '__main__':
+    main()

.github/workflows/perf-js-keys.yml

@@ -0,0 +1,92 @@
+name: Performance js_keys__get
+
+on:
+  push:
+    branches:
+      - beta
+  workflow_dispatch:
+
+concurrency:
+  group: perf-js-keys-${{ github.ref }}
+  cancel-in-progress: true
+
+permissions:
+  contents: read
+
+env:
+  WP_IMAGE: ${{ vars.PERF_WP_IMAGE || 'wordpress:php8.1-apache' }}
+  DB_IMAGE: mysql:8.0
+  DB_ENV: -e WORDPRESS_DB_HOST=db:3306 -e WORDPRESS_DB_USER=wordpress -e WORDPRESS_DB_PASSWORD=wordpress -e WORDPRESS_DB_NAME=wordpress
+
+jobs:
+  measure:
+    if: ${{ !contains(github.event.head_commit.message, '[skip ci]') }}
+    runs-on: ubuntu-latest
+    timeout-minutes: 15
+
+    steps:
+      - name: Checkout code
+        uses: actions/checkout@v4
+
+      - name: Start MySQL
+        run: |
+          docker network create wp
+          docker run -d --name db --network wp \
+            -e MYSQL_ROOT_PASSWORD=password \
+            -e MYSQL_DATABASE=wordpress \
+            -e MYSQL_USER=wordpress \
+            -e MYSQL_PASSWORD=wordpress \
+            "$DB_IMAGE"
+
+      - name: Start WordPress with the plugin mounted
+        run: |
+          docker run -d --name wp --network wp -p 8080:80 $DB_ENV \
+            -e WORDPRESS_CONFIG_EXTRA="define('APBCT_SERVICE__PERF_METRICS_HEADER', true);" \
+            -v "$GITHUB_WORKSPACE:/var/www/html/wp-content/plugins/cleantalk-spam-protect" \
+            "$WP_IMAGE"
+
+      - name: Wait for WordPress container
+        run: |
+          for i in $(seq 1 30); do
+            code=$(curl -s -o /dev/null -w '%{http_code}' http://localhost:8080/ || true)
+            if [ "$code" != "000" ] && docker exec wp test -f /var/www/html/wp-config.php; then
+              echo "WordPress container is up (HTTP $code)"
+              exit 0
+            fi
+            echo "Attempt $i/30: not ready yet"
+            sleep 3
+          done
+          docker logs wp
+          exit 1
+
+      - name: Install WordPress and activate the plugin
+        run: |
+          wp() {
+            docker run --rm --volumes-from wp --network wp $DB_ENV wordpress:cli wp "$@"
+          }
+          # MySQL 8 may restart once during init, so retry the install.
+          for i in $(seq 1 20); do
+            if wp core install --url="http://localhost:8080" --title="Perf" \
+                 --admin_user=admin --admin_password=password --admin_email=admin@example.com --skip-email; then
+              break
+            fi
+            echo "Attempt $i/20: DB not ready yet"
+            sleep 5
+          done
+          wp core is-installed
+          wp plugin activate cleantalk-spam-protect
+          wp plugin list --status=active
+          wp core version
+
+      - name: Measure js_keys__get
+        env:
+          PERF_URL: http://localhost:8080/?rest_route=/cleantalk-antispam/v1/js_keys__get
+          PERF_REQUESTS: ${{ vars.PERF_JS_KEYS_REQUESTS || '5' }}
+          PERF_WARMUP: '1'
+          PERF_JS_KEYS_CLIENT_MS: ${{ vars.PERF_JS_KEYS_CLIENT_MS }}
+          PERF_JS_KEYS_TOTAL_MS: ${{ vars.PERF_JS_KEYS_TOTAL_MS }}
+          PERF_JS_KEYS_INIT_MS: ${{ vars.PERF_JS_KEYS_INIT_MS }}
+          PERF_JS_KEYS_HANDLER_MS: ${{ vars.PERF_JS_KEYS_HANDLER_MS }}
+          PERF_JS_KEYS_SQL: ${{ vars.PERF_JS_KEYS_SQL }}
+          PERF_JS_KEYS_MEM_MB: ${{ vars.PERF_JS_KEYS_MEM_MB }}
+        run: python3 .github/perf/js_keys_perf.py

.gitignore

@@ -13,4 +13,6 @@ checkstyle.xml
 /lib/Cleantalk/Common/ContactsEncoder/tests/
 /coverage.xml
 /tests/.phpunit.result.cache
-.phpunit.result.cache
+.phpunit.result.cache
+__pycache__/
+*.pyc

cleantalk.php

@@ -59,6 +59,9 @@
     die('Not allowed!');
 }
 
+// Define plugin start time for performance metrics
+define('APBCT_PERF_PLUGIN_START', microtime(true));
+
 /**
  * @var State $apbct
  */

lib/Cleantalk/ApbctWP/AJAXService.php

@@ -233,6 +233,45 @@ class_exists($handler_class)
      */
     public static function getJSKeys()
     {
-        die(json_encode(array('js_key' => ct_get_checkjs_value())));
+        $handler_start = microtime(true);
+        $js_key        = ct_get_checkjs_value();
+
+        if ( Constant::is(Constant::APBCT_SERVICE__PERF_METRICS_HEADER, true) ) {
+            self::sendPerfMetricsHeader($handler_start);
+        }
+
+        die(json_encode(array('js_key' => $js_key)));
+    }
+
+    /**
+     * Sends Server-Timing header: boot (WP core before the plugin), init (plugin load + WP init + routing),
+     * handler, total. Non-time metrics are passed via desc.
+     *
+     * @param float $handler_start
+     *
+     * @return void
+     */
+    private static function sendPerfMetricsHeader($handler_start)
+    {
+        global $wpdb;
+
+        if ( headers_sent() ) {
+            return;
+        }
+
+        $now           = microtime(true);
+        $request_start = isset($_SERVER['REQUEST_TIME_FLOAT']) ? $_SERVER['REQUEST_TIME_FLOAT'] : $handler_start;
+        $plugin_start  = defined('APBCT_PERF_PLUGIN_START') ? (float)APBCT_PERF_PLUGIN_START : $request_start;
+
+        $metrics = array(
+            sprintf('boot;dur=%.2f', ($plugin_start - $request_start) * 1000), // Time taken for WP core before the plugin
+            sprintf('init;dur=%.2f', ($handler_start - $plugin_start) * 1000), // Time taken for plugin load + WP init + routing
+            sprintf('handler;dur=%.2f', ($now - $handler_start) * 1000), // Time taken for the AJAX handler
+            sprintf('total;dur=%.2f', ($now - $request_start) * 1000), // Total time taken for the request
+            sprintf('sql;desc="%d"', isset($wpdb->num_queries) ? (int)$wpdb->num_queries : 0), // Number of SQL queries executed
+            sprintf('mem;desc="%.2f"', memory_get_peak_usage(true) / 1048576), // Peak memory usage in MB
+        );
+
+        header('Server-Timing: ' . implode(', ', $metrics));
     }
 }

lib/Cleantalk/ApbctWP/Constant.php

@@ -236,6 +236,13 @@ class Constant
      * @var bool
      */
     const APBCT_SERVICE__DISABLE_INTEGRATION_METRICS = 'APBCT_SERVICE__DISABLE_INTEGRATION_METRICS';
+
+    /**
+     * If true, js_keys__get responses carry a Server-Timing header with performance metrics.
+     *
+     * @var bool
+     */
+    const APBCT_SERVICE__PERF_METRICS_HEADER = 'APBCT_SERVICE__PERF_METRICS_HEADER';
     /**
      * Registry cache. Built once per request by self::getRegistry().
      *
@@ -538,6 +545,13 @@ private static function getRegistry()
                     'type'        => 'bool',
                     'description' => 'If defined, integration metrics will be disabled.',
                 ),
+                self::APBCT_SERVICE__PERF_METRICS_HEADER   => array(
+                    'names'       => array(
+                        self::APBCT_SERVICE__PERF_METRICS_HEADER,
+                    ),
+                    'type'        => 'bool',
+                    'description' => 'If true, js_keys__get responses carry a Server-Timing header with performance metrics. CI usage.',
+                ),
             );
         }