Send attack reports after the response is flushed

[lbajsarowicz]

Problem

Plugin\Shield::aroundDispatch calls Report::sendReport() as soon as Waf::matchRequest() returns anything, before the block decision, and for report-action rules too. sendReport() is a blocking curl POST to shield.sansec.io with setTimeout(5).

The client therefore waits for that POST on every matched request:

• healthy endpoint: response time grows by one round trip, 30–150 ms;
• slow or unreachable endpoint: up to the full 5 s timeout, on top of a request whose own work was already finished.

The worker-pool cost is worse than the latency. A worker is occupied for the whole POST, so with a pool of 50 workers and a 5 s timeout the site can absorb 50 / 5 = 10 matched requests per second before every worker is sitting in curl. A trivial flood of requests that hit a WAF rule (exactly the traffic the module exists to catch) saturates the pool, and legitimate traffic queues behind it. The blocked attacker pays nothing; the shop pays.

Design

Report gains two public methods and keeps sendReport() untouched for any third-party caller:

• sendReportDeferred(RequestInterface $request, array $rules) — builds the JSON payload right away, pushes it onto an in-process queue, and registers flushDeferredReports with register_shutdown_function() the first time it is called. A $shutdownRegistered flag keeps the registration to one per process even if several requests match in a single worker lifetime, and the queue means several matches within one request all get reported.
• flushDeferredReports() — drains the queue, calls fastcgi_finish_request() when that function exists, and posts each payload. It empties the queue before posting, so a second call is a no-op.

Plugin\Shield changes by one line: sendReport becomes sendReportDeferred. The block decision and the 403 response are untouched.

Ordering in Bootstrap::run() is what makes this work: $application->launch() runs the front controller (and this plugin), and only then $response->sendResponse() echoes the headers and body. Shutdown functions run after the script body, i.e. after sendResponse(). Under PHP-FPM fastcgi_finish_request() closes the connection to the web server at that point, so the client is served while the worker still holds the POST.

Notes on the edge cases:

• Payload is built eagerly, not at shutdown. This is the one place the obvious implementation would have been wrong. sendReport() reads $request->getContent() and calls ProductMetadataInterface::getVersion(), which in Magento\Framework\App\ProductMetadata goes through CacheInterface (mage-version) and, on a miss, through ComposerInformation. At shutdown the cache backend connection (Redis, DB) may already be gone, and the request body stream is not guaranteed readable after fastcgi_finish_request(). Serialising in sendReportDeferred() (while the application stack is still fully up) removes that whole class of failure and guarantees a byte-identical payload. The only observable difference is that timestamp is now the moment of the match rather than the moment of the POST, which is arguably more correct.
• A shutdown function still runs when later code throws. If a controller or another plugin blows up after the match, the report is still sent. Today it would also be sent, because the POST happened before the throw; behaviour is preserved and the report survives fatal errors too.
• exit paths: Magento does not exit on the normal flow, and register_shutdown_function callbacks run on exit() as well, so an early exit somewhere else does not lose the report.
• CLI and mod_php. fastcgi_finish_request() does not exist there, so the call is skipped and the POST simply happens at shutdown instead of mid-dispatch, no worse than today.
• Memory: the request object was alive until shutdown anyway; the queue holds serialised JSON strings, which is less than holding the request.

What does not change

• The payload: same keys, same values, same filtered headers (Cookie, Set-Cookie, Authorization), same serializer. The POST body is byte-identical apart from timestamp, which now marks the match.
• The timeout: still setTimeout(5). Because the client is no longer waiting, that 5 s now bounds only how long a worker can be occupied after the response has been flushed. It no longer bounds the user's page load.
• Dashboard immediacy: the POST still happens inside the same request lifecycle, milliseconds after the response is flushed. No cron, no consumer, no polling interval. Reports for both block and report actions are still sent, and the blocked response is still 403 with the access_denied.phtml template.
• Dependencies: still magento/framework only.

Rejected alternatives

• AMQP / magento/framework-message-queue: adds a dependency the module does not have, requires operators to run a consumer (and to notice when it dies), delays the dashboard by the consumer's poll interval, and, with the DB queue fallback, parks full request bodies, headers and IPs in queue_message rows. That is attack payloads and PII at rest in the merchant's database for as long as the queue is not drained. Wrong trade for a module whose value is that it is small.
• Fire-and-forget curl with a sub-second timeout: cheap to write, but it turns every report into a coin flip: any endpoint slower than the timeout silently loses the report, and slow endpoints are exactly the case this PR is about. Deferral keeps delivery reliable and moves the cost off the critical path instead of trading correctness for it.
• Registering the shutdown function in the plugin: keeps Report simple but scatters lifecycle handling into the plugin and makes the queueing untestable. The plugin stays a one-line call.

Testing

Unit tests (vendor/bin/phpunit Test, 63 tests green):

• Test/Model/ReportTest.php — new. Covers that sendReportDeferred() posts nothing at call time; that flushDeferredReports() then posts one payload per deferred report, to the configured URL, with the expected JSON; that a second flush is a no-op; and that nothing is queued or posted when report_enabled is off. flushDeferredReports() is public precisely so the flush can be driven directly. register_shutdown_function cannot be fired from a test.
• Test/Plugin/ShieldTest.php — two new cases: a matched report rule calls sendReportDeferred() once and sendReport() never while dispatch still proceeds; a matched block rule defers the report, logs the block, and returns the 403 instead of dispatching.
• Test/RequestStub.php gained getHeaders(), getFiles() and getScheme(), which Report needs to build a payload.

Manual scenario. The response must not wait for a dead endpoint:

1. Point the module at a listener that accepts the connection and never answers:

   nc -l 9999
   bin/magento config:set sansec_shield/general/report_url http://127.0.0.1:9999/report
   bin/magento config:set sansec_shield/general/report_enabled 1
   bin/magento cache:flush
   

2. Trigger the built-in test rule and measure:

   curl -s -o /dev/null -w 'status=%{http_code} total=%{time_total}\n' \
     'https://example.test/?SANSEC-SHIELD-TEST'
   

3. Before this change: total is ~5.0 s. The 403 body arrives only after curl inside the worker gives up. After this change: status=403 with total in the low tens of milliseconds. The nc listener still shows the connection opening, and top/fpm status shows the worker busy for a further 5 s, which is the timeout now bounding worker occupancy rather than page load.

4. Re-point report_url at the real endpoint and confirm the attack shows up in the dashboard immediately, and that var/log/sansec_shield.log records the block as before.