Skip to content

Commit 7da741f

Browse files
committed
feat: fail integration tests that run N+1 queries
Every request sent through the integration TestCase is now inspected for N+1 query patterns, and the test fails when it finds one. Extension authors get the feedback while writing the feature rather than when a forum grows: this session alone, one extension was issuing a query per post on every page of every discussion, found only by hand-profiling a live forum. An N+1 is one query shape executed once per record. The detector groups a request's query log by normalised SQL — IN lists collapsed, literals replaced — and fails when a shape repeats past a threshold. Bindings are counted separately rather than folded into the shape: the same SQL run for four different users is not the same defect as one query per row, and conflating them produces false positives (it fooled me on one extension before this distinction existed). On by default. A single legitimate shape can be exempted with allowedRepeatedQueries(); a test case can override detectsRepeatedQueries(); FLARUM_DETECT_REPEATED_QUERIES=0 disables it for a whole run. Verified against core's api suite: identical results with detection on and off (353 tests, same pre-existing failures, no findings), and against a real N+1 reintroduced in an extension, where it fails with '10x (10 distinct bindings)' naming the offending query.
1 parent c2e5209 commit 7da741f

3 files changed

Lines changed: 378 additions & 1 deletion

File tree

Lines changed: 120 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,120 @@
1+
<?php
2+
3+
/*
4+
* This file is part of Flarum.
5+
*
6+
* For detailed copyright and license information, please view the
7+
* LICENSE file that was distributed with this source code.
8+
*/
9+
10+
namespace Flarum\Testing\integration;
11+
12+
/**
13+
* Spots N+1 query patterns in the queries a request ran.
14+
*
15+
* An N+1 is one query shape executed many times with different values — a
16+
* relationship loaded per model, a permission check per row, a serializer
17+
* callback hitting the database for each item. Grouping the query log by
18+
* normalised SQL surfaces them: legitimate work uses a handful of distinct
19+
* shapes, while an N+1 repeats one shape as many times as there are records.
20+
*
21+
* Bindings are counted, not folded into the shape. Two executions of the same
22+
* SQL with the *same* bindings are usually memoisation the caller could have
23+
* done, but they don't grow with the data; a shape repeated with *different*
24+
* bindings is the real N+1 signal. Reporting them separately is what stops
25+
* "the same SQL text appeared 4 times" from being mistaken for an N+1 when the
26+
* queries were for four different users.
27+
*/
28+
class RepeatedQueryDetector
29+
{
30+
/**
31+
* @param array<array{query: string, bindings: array}> $queries
32+
* @param int $threshold Repetitions of one shape before it is reported.
33+
* @return array<array{sql: string, count: int, distinctBindings: int}>
34+
*/
35+
public static function findRepeats(array $queries, int $threshold): array
36+
{
37+
$shapes = [];
38+
39+
foreach ($queries as $query) {
40+
$sql = $query['query'] ?? '';
41+
42+
if ($sql === '' || ! self::isWorthCounting($sql)) {
43+
continue;
44+
}
45+
46+
$shape = self::normalise($sql);
47+
48+
if (! isset($shapes[$shape])) {
49+
$shapes[$shape] = ['sql' => $sql, 'count' => 0, 'bindings' => []];
50+
}
51+
52+
$shapes[$shape]['count']++;
53+
$shapes[$shape]['bindings'][json_encode($query['bindings'] ?? [])] = true;
54+
}
55+
56+
$repeats = [];
57+
58+
foreach ($shapes as $shape) {
59+
if ($shape['count'] < $threshold) {
60+
continue;
61+
}
62+
63+
$repeats[] = [
64+
'sql' => $shape['sql'],
65+
'count' => $shape['count'],
66+
'distinctBindings' => count($shape['bindings']),
67+
];
68+
}
69+
70+
usort($repeats, fn ($a, $b) => $b['count'] <=> $a['count']);
71+
72+
return $repeats;
73+
}
74+
75+
/**
76+
* Reduce a query to its shape: values that vary between executions of the
77+
* same code path are replaced, so `id in (1, 2, 3)` and `id in (4, 5)`
78+
* count as one shape.
79+
*/
80+
public static function normalise(string $sql): string
81+
{
82+
// Collapse IN lists (both placeholders and inlined values) first, so
83+
// batched loads of different sizes are recognised as the same shape.
84+
$sql = preg_replace('/\bin\s*\([^()]*\)/i', 'in (?)', $sql);
85+
86+
// Inlined numbers and quoted strings.
87+
$sql = preg_replace('/\b\d+\b/', '?', $sql);
88+
$sql = preg_replace("/'[^']*'/", '?', $sql);
89+
90+
return preg_replace('/\s+/', ' ', trim($sql));
91+
}
92+
93+
/**
94+
* Transactions, savepoints and the like are issued per test by the harness
95+
* itself and say nothing about the code under test.
96+
*/
97+
private static function isWorthCounting(string $sql): bool
98+
{
99+
return (bool) preg_match('/^\s*(select|insert|update|delete)\b/i', $sql);
100+
}
101+
102+
/**
103+
* @param array<array{sql: string, count: int, distinctBindings: int}> $repeats
104+
*/
105+
public static function describe(array $repeats): string
106+
{
107+
$lines = [];
108+
109+
foreach ($repeats as $repeat) {
110+
$lines[] = sprintf(
111+
' %dx (%d distinct bindings): %s',
112+
$repeat['count'],
113+
$repeat['distinctBindings'],
114+
strlen($repeat['sql']) > 160 ? substr($repeat['sql'], 0, 160).'' : $repeat['sql']
115+
);
116+
}
117+
118+
return implode("\n", $lines);
119+
}
120+
}

php-packages/testing/src/integration/TestCase.php

Lines changed: 104 additions & 1 deletion
Original file line numberDiff line numberDiff line change
@@ -295,7 +295,110 @@ protected function rowsThroughFactory(string $modelClass, array $rows): array
295295
*/
296296
protected function send(ServerRequestInterface $request): ResponseInterface
297297
{
298-
return $this->server()->handle($request);
298+
if (! $this->detectsRepeatedQueries()) {
299+
return $this->server()->handle($request);
300+
}
301+
302+
$database = $this->database();
303+
$wasLogging = $database->logging();
304+
305+
$database->flushQueryLog();
306+
$database->enableQueryLog();
307+
308+
try {
309+
$response = $this->server()->handle($request);
310+
} finally {
311+
$queries = $database->getQueryLog();
312+
313+
if (! $wasLogging) {
314+
$database->disableQueryLog();
315+
}
316+
}
317+
318+
$this->reportRepeatedQueries($request, $queries);
319+
320+
return $response;
321+
}
322+
323+
/**
324+
* Whether requests sent through this test case are inspected for N+1 query
325+
* patterns, failing the test when one is found.
326+
*
327+
* On by default: an N+1 is a defect, and finding it while writing the
328+
* feature is far cheaper than finding it in production. Override in a test
329+
* case that legitimately needs it off:
330+
*
331+
* protected function detectsRepeatedQueries(): bool
332+
* {
333+
* return false; // and say why
334+
* }
335+
*
336+
* Prefer {@see allowedRepeatedQueries()} to exempt one known query shape
337+
* rather than disabling the check for the whole test case. Setting
338+
* FLARUM_DETECT_REPEATED_QUERIES=0 turns it off for a whole run, which is
339+
* useful when bisecting an unrelated failure.
340+
*/
341+
protected function detectsRepeatedQueries(): bool
342+
{
343+
$env = getenv('FLARUM_DETECT_REPEATED_QUERIES');
344+
345+
return $env === false || $env === '' ? true : (bool) filter_var($env, FILTER_VALIDATE_BOOLEAN);
346+
}
347+
348+
/**
349+
* Repetitions of one query shape tolerated before a request is reported.
350+
* Small fixed-size loops (the actor, a couple of authors) are normal; an
351+
* N+1 grows with the fixture, so it clears any sensible threshold.
352+
*/
353+
protected function repeatedQueryThreshold(): int
354+
{
355+
return (int) (getenv('FLARUM_REPEATED_QUERY_THRESHOLD') ?: 5);
356+
}
357+
358+
/**
359+
* Query shapes this test case knowingly repeats, as substrings of the
360+
* normalised SQL — e.g. `'from `sessions`'`. A shape matching any of these
361+
* does not fail the test.
362+
*
363+
* Preferable to turning the check off wholesale: the rest of the request
364+
* stays covered. Say why each entry is legitimate.
365+
*
366+
* @return string[]
367+
*/
368+
protected function allowedRepeatedQueries(): array
369+
{
370+
return [];
371+
}
372+
373+
/**
374+
* @param array<array{query: string, bindings: array}> $queries
375+
*/
376+
private function reportRepeatedQueries(ServerRequestInterface $request, array $queries): void
377+
{
378+
$repeats = RepeatedQueryDetector::findRepeats($queries, $this->repeatedQueryThreshold());
379+
380+
foreach ($this->allowedRepeatedQueries() as $allowed) {
381+
$repeats = array_values(array_filter(
382+
$repeats,
383+
fn (array $repeat) => ! str_contains(RepeatedQueryDetector::normalise($repeat['sql']), $allowed)
384+
));
385+
}
386+
387+
if (! $repeats) {
388+
return;
389+
}
390+
391+
self::fail(sprintf(
392+
"%s %s ran repeated queries — likely an N+1.\n\n%s\n\n"
393+
."A query shape repeated with different bindings is usually a relationship, permission check or\n"
394+
."serialized field resolved per model; load it for the whole page instead (eager loading, a\n"
395+
."batched relation, or a single grouped query). If the repetition is legitimate, list the shape\n"
396+
."in %s::allowedRepeatedQueries() with a comment saying why.",
397+
$request->getMethod(),
398+
(string) $request->getUri()->getPath(),
399+
RepeatedQueryDetector::describe($repeats),
400+
static::class
401+
));
299402
}
300403

301404
/**
Lines changed: 154 additions & 0 deletions
Original file line numberDiff line numberDiff line change
@@ -0,0 +1,154 @@
1+
<?php
2+
3+
/*
4+
* This file is part of Flarum.
5+
*
6+
* For detailed copyright and license information, please view the
7+
* LICENSE file that was distributed with this source code.
8+
*/
9+
10+
namespace Flarum\Testing\Tests\unit;
11+
12+
use Flarum\Testing\integration\RepeatedQueryDetector;
13+
use PHPUnit\Framework\Attributes\Test;
14+
use PHPUnit\Framework\TestCase;
15+
16+
class RepeatedQueryDetectorTest extends TestCase
17+
{
18+
/**
19+
* @param array<array{0: string, 1: array}> $queries
20+
*/
21+
private function log(array $queries): array
22+
{
23+
return array_map(fn ($q) => ['query' => $q[0], 'bindings' => $q[1]], $queries);
24+
}
25+
26+
#[Test]
27+
public function a_relationship_loaded_per_model_is_reported()
28+
{
29+
// The shape of a real N+1: one query per record, different binding
30+
// each time. (Taken from a post listing loading each post's warnings.)
31+
$queries = [];
32+
33+
for ($id = 100; $id < 110; $id++) {
34+
$queries[] = ['select * from `warnings` where `warnings`.`post_id` = ?', [$id]];
35+
}
36+
37+
$repeats = RepeatedQueryDetector::findRepeats($this->log($queries), 5);
38+
39+
$this->assertCount(1, $repeats);
40+
$this->assertSame(10, $repeats[0]['count']);
41+
$this->assertSame(10, $repeats[0]['distinctBindings']);
42+
}
43+
44+
#[Test]
45+
public function batched_loads_of_differing_sizes_are_one_shape_not_an_n_plus_one()
46+
{
47+
// Eager loading emits `in (...)` lists of whatever length; those are
48+
// the fix for an N+1, not an instance of one.
49+
$repeats = RepeatedQueryDetector::findRepeats($this->log([
50+
['select * from `users` where `users`.`id` in (1, 2, 3)', []],
51+
['select * from `users` where `users`.`id` in (4, 5)', []],
52+
]), 5);
53+
54+
$this->assertSame([], $repeats);
55+
}
56+
57+
#[Test]
58+
public function a_handful_of_distinct_queries_is_not_reported()
59+
{
60+
$repeats = RepeatedQueryDetector::findRepeats($this->log([
61+
['select * from `discussions` where `id` = ?', [1]],
62+
['select * from `posts` where `discussion_id` = ?', [1]],
63+
['select * from `users` where `id` in (?, ?)', [1, 2]],
64+
]), 5);
65+
66+
$this->assertSame([], $repeats);
67+
}
68+
69+
#[Test]
70+
public function repeats_below_the_threshold_are_left_alone()
71+
{
72+
// Small fixed-size loops are everywhere in a request (the actor, a
73+
// couple of authors) and must not be flagged.
74+
$queries = [];
75+
76+
for ($id = 1; $id <= 4; $id++) {
77+
$queries[] = ['select * from `groups` where `user_id` = ?', [$id]];
78+
}
79+
80+
$this->assertSame([], RepeatedQueryDetector::findRepeats($this->log($queries), 5));
81+
}
82+
83+
#[Test]
84+
public function the_same_query_with_the_same_bindings_is_distinguished_from_an_n_plus_one()
85+
{
86+
// A missed memoisation: the same rows fetched repeatedly. Worth
87+
// reporting, but the binding count tells the reader it does NOT grow
88+
// with the data — the distinction that stops false N+1 diagnoses.
89+
$queries = array_fill(0, 6, ['select * from `settings` where `key` = ?', ['foo']]);
90+
91+
$repeats = RepeatedQueryDetector::findRepeats($this->log($queries), 5);
92+
93+
$this->assertCount(1, $repeats);
94+
$this->assertSame(6, $repeats[0]['count']);
95+
$this->assertSame(1, $repeats[0]['distinctBindings']);
96+
}
97+
98+
#[Test]
99+
public function harness_transactions_are_ignored()
100+
{
101+
$queries = array_fill(0, 10, ['SAVEPOINT trans1', []]);
102+
$queries[] = ['BEGIN', []];
103+
104+
$this->assertSame([], RepeatedQueryDetector::findRepeats($this->log($queries), 5));
105+
}
106+
107+
#[Test]
108+
public function inlined_values_normalise_to_the_same_shape_as_placeholders()
109+
{
110+
// Some code paths inline values instead of binding them; they are the
111+
// same shape and must count together.
112+
$repeats = RepeatedQueryDetector::findRepeats($this->log([
113+
['select * from `posts` where `id` = 1', []],
114+
['select * from `posts` where `id` = 2', []],
115+
['select * from `posts` where `id` = ?', [3]],
116+
['select * from `posts` where `id` = ?', [4]],
117+
['select * from `posts` where `id` = ?', [5]],
118+
]), 5);
119+
120+
$this->assertCount(1, $repeats);
121+
$this->assertSame(5, $repeats[0]['count']);
122+
}
123+
124+
#[Test]
125+
public function the_worst_offender_is_reported_first()
126+
{
127+
$queries = [];
128+
129+
for ($i = 0; $i < 6; $i++) {
130+
$queries[] = ['select * from `flags` where `post_id` = ?', [$i]];
131+
}
132+
for ($i = 0; $i < 12; $i++) {
133+
$queries[] = ['select * from `warnings` where `post_id` = ?', [$i]];
134+
}
135+
136+
$repeats = RepeatedQueryDetector::findRepeats($this->log($queries), 5);
137+
138+
$this->assertCount(2, $repeats);
139+
$this->assertStringContainsString('warnings', $repeats[0]['sql']);
140+
$this->assertSame(12, $repeats[0]['count']);
141+
}
142+
143+
#[Test]
144+
public function the_description_names_counts_and_binding_diversity()
145+
{
146+
$description = RepeatedQueryDetector::describe([
147+
['sql' => 'select * from `warnings` where `post_id` = ?', 'count' => 10, 'distinctBindings' => 10],
148+
]);
149+
150+
$this->assertStringContainsString('10x', $description);
151+
$this->assertStringContainsString('10 distinct bindings', $description);
152+
$this->assertStringContainsString('warnings', $description);
153+
}
154+
}

0 commit comments

Comments
 (0)