From 4183c6ea0a50584b036247daf8cdeafabc57e91d Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 14:16:47 +0100 Subject: [PATCH 1/7] Include unprepared query in `SqlQuery` and change it to `readonly` class (breaking change!) --- .github/workflows/ci.yml | 5 +---- README.md | 18 ++++++++--------- composer.json | 2 +- src/Formatter.php | 6 +++--- src/SqlLogger.php | 24 +++++++++++++---------- src/SqlQuery.php | 34 ++++++--------------------------- src/Writer.php | 30 ++++++++++++++++++++++++----- tests/Feature/FormatterTest.php | 15 +++------------ tests/Feature/SqlLoggerTest.php | 16 ++++++++++++---- tests/Feature/WriterTest.php | 32 +++++++++++++++---------------- tests/Unit/SqlQueryTest.php | 21 -------------------- 11 files changed, 90 insertions(+), 113 deletions(-) delete mode 100644 tests/Unit/SqlQueryTest.php diff --git a/.github/workflows/ci.yml b/.github/workflows/ci.yml index f447303..a3e6517 100644 --- a/.github/workflows/ci.yml +++ b/.github/workflows/ci.yml @@ -8,7 +8,7 @@ jobs: strategy: fail-fast: true matrix: - php: [8.3, 8.2, 8.1] + php: [8.3, 8.2] laravel: [11.*, 10.*] stability: [prefer-lowest, prefer-stable] include: @@ -16,9 +16,6 @@ jobs: testbench: 9.* - laravel: 10.* testbench: 8.* - exclude: - - laravel: 11.* - php: 8.1 name: P${{ matrix.php }} - L${{ matrix.laravel }} - ${{ matrix.stability }} - ${{ matrix.os }} diff --git a/README.md b/README.md index 7bec40e..c433ce4 100644 --- a/README.md +++ b/README.md @@ -19,16 +19,16 @@ It reports a lot of metadata like total query count, total execution time, origi ```bash $ composer require onlime/laravel-sql-reporter --dev ``` - in console to install this module (Notice `--dev` flag - it's recommended to use this package only for development). + in console to install this module (Notice `--dev` flag - it's recommended to use this package only for development). Laravel uses package auto-discovery, and it will automatically load this service provider, so you don't need to add anything into the `providers` section of `config/app.php`. - + 2. Run the following in your console to publish the default configuration file: - + ```bash $ php artisan vendor:publish --provider="Onlime\LaravelSqlReporter\Providers\ServiceProvider" ``` - + By default, you should not edit published file because all the settings are loaded from `.env` file by default. 3. In your `.env` file add the following entries: @@ -48,7 +48,7 @@ It reports a lot of metadata like total query count, total execution time, origi SQL_REPORTER_FORMAT_HEADER_FIELDS="origin,datetime,status,user,env,agent,ip,host,referer" SQL_REPORTER_FORMAT_ENTRY_FORMAT="-- Query [query_nr] [[query_time]]\\n[query]" ``` - + and adjust values to your needs. You can skip variables for which you want to use default values. To only log DML / modifying queries like `INSERT`, `UPDATE`, `DELETE`, but not logging any updates on @@ -58,11 +58,11 @@ It reports a lot of metadata like total query count, total execution time, origi SQL_REPORTER_QUERIES_INCLUDE_PATTERN="/^(?!SELECT).*/i" SQL_REPORTER_QUERIES_EXCLUDE_PATTERN="/^UPDATE.*(last_visit|remember_token)/i" ``` - + If you have also `.env.example` it's recommended to add those entries also in `.env.example` file just to make sure everyone knows about those env variables. Be aware that `SQL_REPORTER_DIRECTORY` is directory inside storage directory. - + To find out more about those setting please take a look at [Configuration file](config/sql-reporter.php) - + 4. Make sure directory specified in `.env` file exists in storage path, and you have valid permissions to create and modify files in this directory (If it does not exist this package will automatically create it when needed, but it's recommended to create it manually with valid file permissions) 5. Make sure on live server you will set logging SQL queries to false in your `.env` file: `SQL_REPORTER_QUERIES_ENABLED=false`. This package is recommended to be used only for development to not impact production application performance. @@ -101,7 +101,7 @@ This package was inspired by [mnabialek/laravel-sql-logger](https://github.com/m - Query logging is not triggered upon each query execution but instead at a final step, using `RequestHandled` and `CommandFinished` events. - This allows us to include much more information about the whole query executions like total query count, total execution time, and very detailed header information like origin (request URL/console command), authenticated user, app environment, client browser agent / IP / hostname. -- This package is greatly simplified and only provides support for Laravel 10+ / PHP 8.1+ +- This package is greatly simplified and only provides support for Laravel 10+ / PHP 8.2+ - It uses the Laravel built-in query logging (`DB::enableQueryLog()`) which logs all queries in memory, which should perform much better than writing every single query to the log file. - By default, `onlime/laravel-sql-reporter` produces much nicer log output, especially since we only write header information before the first query. diff --git a/composer.json b/composer.json index 2579570..20de3c7 100644 --- a/composer.json +++ b/composer.json @@ -14,7 +14,7 @@ } ], "require": { - "php": "^8.1", + "php": "^8.2", "illuminate/support": "^10.15|^11.0", "illuminate/filesystem": "^10.15|^11.0", "illuminate/container": "^10.15|^11.0" diff --git a/src/Formatter.php b/src/Formatter.php index e8ec947..0c90ed6 100644 --- a/src/Formatter.php +++ b/src/Formatter.php @@ -23,9 +23,9 @@ public function __construct( public function getLine(SqlQuery $query): string { $replace = [ - '[query_nr]' => $query->number(), + '[query_nr]' => $query->number, '[datetime]' => Carbon::now()->toDateTimeString(), - '[query_time]' => $this->time($query->time()), + '[query_time]' => $this->time($query->time), '[query]' => $this->getQueryLine($query), '[separator]' => $this->separatorLine(), '\n' => PHP_EOL, @@ -115,7 +115,7 @@ protected function originLine(): string */ protected function getQueryLine(SqlQuery $query): string { - return $query->rawQuery().';'; + return $query->rawQuery.';'; } /** diff --git a/src/SqlLogger.php b/src/SqlLogger.php index a874c51..e94224a 100644 --- a/src/SqlLogger.php +++ b/src/SqlLogger.php @@ -2,15 +2,11 @@ namespace Onlime\LaravelSqlReporter; +use Illuminate\Support\Collection; use Illuminate\Support\Facades\DB; class SqlLogger { - /** - * Number of executed queries. - */ - private int $queryNumber = 0; - /** * SqlLogger constructor. */ @@ -24,11 +20,19 @@ public function __construct( */ public function log(): void { - foreach (DB::getRawQueryLog() as $query) { - $this->writer->writeQuery( - new SqlQuery(++$this->queryNumber, $query['raw_query'], $query['time']) - ); - } + $queryLog = DB::getQueryLog(); + + // getQueryLog() and getRawQueryLog() have the same keys + Collection::make(DB::getRawQueryLog()) + ->map(fn (array $query, int $key) => new SqlQuery( + $key + 1, + $query['raw_query'], + $query['time'], + $queryLog[$key]['query'], + $queryLog[$key]['bindings'] + )) + ->each(fn (SqlQuery $query) => $this->writer->writeQuery($query)); + $this->writer->report(); } } diff --git a/src/SqlQuery.php b/src/SqlQuery.php index 8c92e12..2cc6aa1 100644 --- a/src/SqlQuery.php +++ b/src/SqlQuery.php @@ -2,36 +2,14 @@ namespace Onlime\LaravelSqlReporter; -class SqlQuery +readonly class SqlQuery { public function __construct( - private int $number, - private string $rawQuery, - private float $time + public int $number, + public string $rawQuery, + public float $time, + public string $query, + public array $bindings = [] ) { } - - /** - * Get query number. - */ - public function number(): int - { - return $this->number; - } - - /** - * Get raw SQL query with embedded bindings. - */ - public function rawQuery(): string - { - return $this->rawQuery; - } - - /** - * Get query execution time. - */ - public function time(): float - { - return $this->time; - } } diff --git a/src/Writer.php b/src/Writer.php index 6e97699..ec72217 100644 --- a/src/Writer.php +++ b/src/Writer.php @@ -2,6 +2,7 @@ namespace Onlime\LaravelSqlReporter; +use Closure; use Onlime\LaravelSqlReporter\Events\QueryLogWritten; class Writer @@ -22,6 +23,11 @@ class Writer */ private array $reportQueries = []; + /** + * Callback to determine whether query should be reported. + */ + private static ?Closure $shouldReportQuery = null; + public function __construct( private Formatter $formatter, private Config $config, @@ -29,6 +35,14 @@ public function __construct( ) { } + /** + * Set callback to determine whether query should be reported. + */ + public static function shouldReportQuery(callable $callback): void + { + self::$shouldReportQuery = $callback; + } + /** * Write a query to log. * @@ -36,7 +50,7 @@ public function __construct( */ public function writeQuery(SqlQuery $query): bool { - $this->createDirectoryIfNotExists($query->number()); + $this->createDirectoryIfNotExists($query->number); if ($this->shouldLogQuery($query)) { if ($this->loggedQueryCount === 0) { @@ -62,7 +76,13 @@ public function writeQuery(SqlQuery $query): bool */ private function shouldReportSqlQuery(SqlQuery $query): bool { - return preg_match($this->config->queriesReportPattern(), $query->rawQuery()) === 1; + $pattern = $this->config->queriesReportPattern(); + + if ($pattern && preg_match($pattern, $query->rawQuery) !== 1) { + return false; + } + + return call_user_func(self::$shouldReportQuery ?? fn () => true, $query); } /** @@ -92,9 +112,9 @@ protected function directory(): string protected function shouldLogQuery(SqlQuery $query): bool { return $this->config->queriesEnabled() && - $query->time() >= $this->config->queriesMinExecTime() && - preg_match($this->config->queriesIncludePattern(), $query->rawQuery()) && - ! preg_match($this->config->queriesExcludePattern(), $query->rawQuery()); + $query->time >= $this->config->queriesMinExecTime() && + preg_match($this->config->queriesIncludePattern(), $query->rawQuery) && + ! preg_match($this->config->queriesExcludePattern(), $query->rawQuery); } /** diff --git a/tests/Feature/FormatterTest.php b/tests/Feature/FormatterTest.php index 950b8e1..c59f405 100644 --- a/tests/Feature/FormatterTest.php +++ b/tests/Feature/FormatterTest.php @@ -108,13 +108,10 @@ $now = '2015-03-04 08:12:07'; Carbon::setTestNow($now); - $query = Mockery::mock(SqlQuery::class); $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query->shouldReceive('number')->once()->withNoArgs()->andReturn($number); - $query->shouldReceive('rawQuery')->once()->withNoArgs()->andReturn($sql); - $query->shouldReceive('time')->once()->withNoArgs()->andReturn($time); + $query = new SqlQuery($number, $sql, $time, $sql); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); @@ -139,13 +136,10 @@ $now = '2015-03-04 08:12:07'; Carbon::setTestNow($now); - $query = Mockery::mock(SqlQuery::class); $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query->shouldReceive('number')->once()->withNoArgs()->andReturn($number); - $query->shouldReceive('rawQuery')->once()->withNoArgs()->andReturn($sql); - $query->shouldReceive('time')->once()->withNoArgs()->andReturn($time); + $query = new SqlQuery($number, $sql, $time, $sql); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); @@ -171,13 +165,10 @@ $now = '2015-03-04 08:12:07'; Carbon::setTestNow($now); - $query = Mockery::mock(SqlQuery::class); $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query->shouldReceive('number')->once()->withNoArgs()->andReturn($number); - $query->shouldReceive('rawQuery')->once()->withNoArgs()->andReturn($sql); - $query->shouldReceive('time')->once()->withNoArgs()->andReturn($time); + $query = new SqlQuery($number, $sql, $time, $sql); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); diff --git a/tests/Feature/SqlLoggerTest.php b/tests/Feature/SqlLoggerTest.php index e319cd9..4c1f04e 100644 --- a/tests/Feature/SqlLoggerTest.php +++ b/tests/Feature/SqlLoggerTest.php @@ -11,11 +11,15 @@ }); it('runs writer with valid query', function () { + DB::shouldReceive('getQueryLog')->once()->withNoArgs()->andReturn([ + ['query' => 'anything', 'bindings' => []], + ]); + DB::shouldReceive('getRawQueryLog')->once()->withNoArgs()->andReturn([ ['raw_query' => 'anything', 'time' => 1.23], ]); - $sqlQuery = new SqlQuery(1, 'anything', 1.23); + $sqlQuery = new SqlQuery(1, 'anything', 1.23, 'anything'); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery == $arg)); $this->writer->shouldReceive('report')->once()->withNoArgs(); @@ -24,19 +28,23 @@ }); it('uses valid query number for multiple queries', function () { + DB::shouldReceive('getQueryLog')->once()->withNoArgs()->andReturn([ + ['query' => 'anything', 'bindings' => []], + ['query' => 'anything2', 'bindings' => []], + ]); + DB::shouldReceive('getRawQueryLog')->once()->withNoArgs()->andReturn([ ['raw_query' => 'anything', 'time' => 1.23], ['raw_query' => 'anything2', 'time' => 4.56], ]); - $sqlQuery = new SqlQuery(1, 'anything', 1.23); + $sqlQuery = new SqlQuery(1, 'anything', 1.23, 'anything'); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery == $arg)); - $sqlQuery2 = new SqlQuery(2, 'anything2', 4.56); + $sqlQuery2 = new SqlQuery(2, 'anything2', 4.56, 'anything2'); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery2 == $arg)); $this->writer->shouldReceive('report')->once()->withNoArgs(); $this->logger->log(); - expect(true)->toBeTrue(); }); diff --git a/tests/Feature/WriterTest.php b/tests/Feature/WriterTest.php index 544c284..7a1ab32 100644 --- a/tests/Feature/WriterTest.php +++ b/tests/Feature/WriterTest.php @@ -35,7 +35,7 @@ function setConfig(string|array $key, mixed $value =null) } it('creates directory if it does not exist for 1st query', function () { - $query = new SqlQuery(1, 'test', 5.41); + $query = new SqlQuery(1, 'test', 5.41, 'test'); setConfig('queries.enabled', false); expect($this->directory)->not()->toBeDirectory(); $this->writer->writeQuery($query); @@ -44,7 +44,7 @@ function setConfig(string|array $key, mixed $value =null) }); it('does not create directory if it does not exist for 2nd query', function () { - $query = new SqlQuery(2, 'test', 5.41); + $query = new SqlQuery(2, 'test', 5.41, 'test'); setConfig('queries.enabled', false); expect($this->directory)->not()->toBeDirectory(); $this->writer->writeQuery($query); @@ -56,7 +56,7 @@ function setConfig(string|array $key, mixed $value =null) $expectedContent = "-- header\nSample log line\n"; $expectedFileName = $this->now->format('Y-m').'-log.sql'; - $query = new SqlQuery(1, 'test', 5.41); + $query = new SqlQuery(1, 'test', 5.41, 'test'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); @@ -79,7 +79,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = $initialContent."-- header\nSample log line\n"; - $query = new SqlQuery(1, 'test', 5.41); + $query = new SqlQuery(1, 'test', 5.41, 'test'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig('queries.include_pattern', '#.*#i'); @@ -100,7 +100,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "-- header\nSample log line\n"; - $query = new SqlQuery(1, 'test', 5.41); + $query = new SqlQuery(1, 'test', 5.41, 'test'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig([ @@ -124,8 +124,8 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "-- header\n$lineContent\n$lineContent\n"; - $query1 = new SqlQuery(1, 'test', 5.41); - $query2 = new SqlQuery(2, 'test', 5.41); + $query1 = new SqlQuery(1, 'test', 5.41, 'test'); + $query2 = new SqlQuery(2, 'test', 5.41, 'test'); $this->formatter->shouldReceive('getLine')->twice()->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig([ @@ -146,7 +146,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'select * FROM test', 5.41); + $query = new SqlQuery(1, 'select * FROM test', 5.41, 'select * FROM test'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^SELECT .*$#i'); @@ -159,7 +159,7 @@ function setConfig(string|array $key, mixed $value =null) }); it('doesnt save select query to file when pattern set to insert or update queries', function () { - $query = new SqlQuery(1, 'select * FROM test', 5.41); + $query = new SqlQuery(1, 'select * FROM test', 5.41, 'select * FROM test'); setConfig('queries.include_pattern', '#^(?:UPDATE|INSERT) .*$#i'); $this->writer->writeQuery($query); expect($this->directory)->toBeFile() @@ -171,7 +171,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41); +$query = new SqlQuery(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41, 'INSERT INTO test(one, two, three) values(?, ?, ?)'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^(?:UPDATE|INSERT) .*$#i'); @@ -188,7 +188,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'UPDATE test SET x = 2 WHERE id = 3', 5.41); + $query = new SqlQuery(1, 'UPDATE test SET x = 2 WHERE id = 3', 5.41, 'UPDATE test SET x = 2 WHERE id = 3'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^(?:UPDATE test SET x = \d |INSERT ).*$#i'); @@ -201,8 +201,8 @@ function setConfig(string|array $key, mixed $value =null) }); it('only logs slow queries', function () { - $query1 = new SqlQuery(1, 'test1', 5.41); - $query2 = new SqlQuery(2, 'test2', 500.5); + $query1 = new SqlQuery(1, 'test1', 5.41, 'test1'); + $query2 = new SqlQuery(2, 'test2', 500.5, 'test2'); setConfig('queries.min_exec_time', 500); @@ -219,9 +219,9 @@ function setConfig(string|array $key, mixed $value =null) }); it('respects query patterns', function () { - $query1 = new SqlQuery(1, 'select foo from bar', 5.41); - $query2 = new SqlQuery(2, 'update bar set foo = 1', 3.55); - $query3 = new SqlQuery(3, "update bar set last_visit = '2021-06-03 10:26:00'", 3.22); + $query1 = new SqlQuery(1, 'select foo from bar', 5.41, 'select foo from bar'); + $query2 = new SqlQuery(2, 'update bar set foo = 1', 3.55, 'update bar set foo = 1'); + $query3 = new SqlQuery(3, "update bar set last_visit = '2021-06-03 10:26:00'", 3.22, "update bar set last_visit = '2021-06-03 10:26:00'"); setConfig([ 'queries.include_pattern' => '/^(?!SELECT).*$/i', diff --git a/tests/Unit/SqlQueryTest.php b/tests/Unit/SqlQueryTest.php deleted file mode 100644 index 00c7a34..0000000 --- a/tests/Unit/SqlQueryTest.php +++ /dev/null @@ -1,21 +0,0 @@ -number())->toBe($value); -}); - -it('returns valid raw query', function () { - $value = "SELECT * FROM tests WHERE a = 'test'"; - $query = new SqlQuery(56, $value, 130); - expect($query->rawQuery())->toBe($value); -}); - -it('returns valid time', function () { - $value = 130.0; - $query = new SqlQuery(56, 'test', $value); - expect($query->time())->toBe($value); -}); From f23606184243c954f14720efe7451d7098c56929 Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 14:30:39 +0100 Subject: [PATCH 2/7] Update SqlLogger.php --- src/SqlLogger.php | 5 ++++- 1 file changed, 4 insertions(+), 1 deletion(-) diff --git a/src/SqlLogger.php b/src/SqlLogger.php index e94224a..17aae38 100644 --- a/src/SqlLogger.php +++ b/src/SqlLogger.php @@ -23,6 +23,7 @@ public function log(): void $queryLog = DB::getQueryLog(); // getQueryLog() and getRawQueryLog() have the same keys + // see \Illuminate\Database\Connection::getRawQueryLog() Collection::make(DB::getRawQueryLog()) ->map(fn (array $query, int $key) => new SqlQuery( $key + 1, @@ -31,7 +32,9 @@ public function log(): void $queryLog[$key]['query'], $queryLog[$key]['bindings'] )) - ->each(fn (SqlQuery $query) => $this->writer->writeQuery($query)); + ->each(function (SqlQuery $query) { + $this->writer->writeQuery($query); + }); $this->writer->report(); } From 53589d275b512e89e082262082593c7a2696f293 Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 14:42:20 +0100 Subject: [PATCH 3/7] Added tests for the `Writer::shouldReportSqlQuery()` method --- src/Config.php | 2 +- src/Writer.php | 2 +- tests/Feature/WriterTest.php | 28 +++++++++++++++++++++++++++- 3 files changed, 29 insertions(+), 3 deletions(-) diff --git a/src/Config.php b/src/Config.php index 0d11214..83001b0 100644 --- a/src/Config.php +++ b/src/Config.php @@ -88,7 +88,7 @@ public function queriesExcludePattern(): string */ public function queriesReportPattern(): string { - return $this->repository->get('sql-reporter.queries.report_pattern'); + return $this->repository->get('sql-reporter.queries.report_pattern') ?: ''; } /** diff --git a/src/Writer.php b/src/Writer.php index ec72217..6db2652 100644 --- a/src/Writer.php +++ b/src/Writer.php @@ -74,7 +74,7 @@ public function writeQuery(SqlQuery $query): bool /** * Verify whether query should be reported. */ - private function shouldReportSqlQuery(SqlQuery $query): bool + public function shouldReportSqlQuery(SqlQuery $query): bool { $pattern = $this->config->queriesReportPattern(); diff --git a/tests/Feature/WriterTest.php b/tests/Feature/WriterTest.php index 7a1ab32..d472fb6 100644 --- a/tests/Feature/WriterTest.php +++ b/tests/Feature/WriterTest.php @@ -2,7 +2,9 @@ use Carbon\Carbon; use Illuminate\Filesystem\Filesystem; +use Illuminate\Support\Facades\Event; use Onlime\LaravelSqlReporter\Config; +use Onlime\LaravelSqlReporter\Events\QueryLogWritten; use Onlime\LaravelSqlReporter\FileName; use Onlime\LaravelSqlReporter\Formatter; use Onlime\LaravelSqlReporter\SqlQuery; @@ -171,7 +173,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; -$query = new SqlQuery(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41, 'INSERT INTO test(one, two, three) values(?, ?, ?)'); + $query = new SqlQuery(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41, 'INSERT INTO test(one, two, three) values(?, ?, ?)'); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^(?:UPDATE|INSERT) .*$#i'); @@ -240,3 +242,27 @@ function setConfig(string|array $key, mixed $value =null) ->and($writer->writeQuery($query2))->toBeTrue() ->and($writer->writeQuery($query3))->toBeFalse(); }); + +it('respects the report pattern from the config to determine if a query should be reported', function (string $query, bool $report) { + expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); +})->with([ + ['select * from users', false], + ['delete from users', true], +]); + +it('can provide a callback to the writer to determine if a query should be reported', function (string $query, bool $report) { + config(['sql-reporter.queries.report_pattern' => null]); + Writer::shouldReportQuery(fn (SqlQuery $query) => ! str_contains($query->rawQuery, 'sessions')); + expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); +})->with([ + ['delete from sessions', false], + ['delete from users', true], +]); + +it('does not dispatch an event when there are no queries to report', function () { + Event::fake(); + + $this->writer->report(); + + Event::assertNotDispatched(QueryLogWritten::class); +}); From bb0a6b99bc7fabbf830d14bd16878e88c2be475c Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 14:49:51 +0100 Subject: [PATCH 4/7] Added test for `QueryLogWritten` event --- tests/Feature/WriterTest.php | 34 ++++++++++++++++++++++++++++++++++ 1 file changed, 34 insertions(+) diff --git a/tests/Feature/WriterTest.php b/tests/Feature/WriterTest.php index d472fb6..e9b192f 100644 --- a/tests/Feature/WriterTest.php +++ b/tests/Feature/WriterTest.php @@ -259,6 +259,40 @@ function setConfig(string|array $key, mixed $value =null) ['delete from users', true], ]); +it('can combine the report pattern config and the callback to determine if a query should be reported', function (string $query, bool $report) { + config(['sql-reporter.queries.report_pattern' => '/^DELETE.*$/i']); + Writer::shouldReportQuery(fn (SqlQuery $query) => ! str_contains($query->rawQuery, 'sessions')); + expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); +})->with([ + ['select * from users', false], + ['delete from sessions', false], + ['delete from users', true], +]); + +it('dispatches an event when there are queries to report', function () { + Event::fake(); + + $query1 = new SqlQuery(1, 'select * from users', 5.41, 'select * from users'); + $query2 = new SqlQuery(2, 'delete from users', 5.41, 'delete from users'); + + $expectedFileName = $this->now->format('Y-m').'-log.sql'; + $lineContent1 = 'Sample log line 1'; + $lineContent2 = 'Sample log line 2'; + + $this->formatter->shouldReceive('getLine')->once()->with($query1)->andReturn($lineContent1); + $this->formatter->shouldReceive('getLine')->once()->with($query2)->andReturn($lineContent2); + $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); + $this->filename->shouldReceive('getLogfile')->times(3)->withNoArgs()->andReturn($expectedFileName); + + $this->writer->writeQuery($query1); + $this->writer->writeQuery($query2); + $this->writer->report(); + + Event::assertDispatched(function (QueryLogWritten $event) use ($lineContent2) { + return count($event->reportQueries) === 1 && $event->reportQueries[0] === $lineContent2; + }); +}); + it('does not dispatch an event when there are no queries to report', function () { Event::fake(); From 64daa544294ea4927d8c6154758d04d76dc0c8ac Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 14:57:44 +0100 Subject: [PATCH 5/7] Update README.md --- README.md | 16 ++++++++++++++++ 1 file changed, 16 insertions(+) diff --git a/README.md b/README.md index c433ce4..b3430dc 100644 --- a/README.md +++ b/README.md @@ -67,6 +67,22 @@ It reports a lot of metadata like total query count, total execution time, origi 5. Make sure on live server you will set logging SQL queries to false in your `.env` file: `SQL_REPORTER_QUERIES_ENABLED=false`. This package is recommended to be used only for development to not impact production application performance. +## `QueryLogWritten` event + +This package fires a `QueryLogWritten` event after the log file has been written. You may use this event to further debug or analyze the logged queries in your application. The queries are filtered by the `SQL_REPORTER_QUERIES_REPORT_PATTERN` setting, which comes with a sensible default to exclude `SELECT` queries and some default tables like `sessions`, `jobs`, `bans`, `logins`. If you don't want to filter any queries, you may leave this setting empty. + +In addition to the pattern, you may also configure a callback to define your own custom filtering logic, for example, in your `AppServiceProvider`: + +```php +use Onlime\LaravelSqlReporter\SqlQuery; +use Onlime\LaravelSqlReporter\Writer; + +Writer::shouldReportQuery(function (SqlQuery $query) { + // Only include queries in the `QueryLogWritten` event that took longer than 100ms + return $query->time > 100; +}); +``` + ## Optional For optional GeoIP support (adding country information to client IP in log headers), you may install [stevebauman/location](https://github.com/stevebauman/location) in your project: From 6e9b7a80f9f2fe5b13f6253cbdf0f22435456e08 Mon Sep 17 00:00:00 2001 From: Pascal Baljet Date: Thu, 21 Mar 2024 15:33:01 +0100 Subject: [PATCH 6/7] Added `SqlQuery::make()` helper method for cleanup --- src/SqlQuery.php | 10 ++++++++ tests/Feature/FormatterTest.php | 6 ++--- tests/Feature/SqlLoggerTest.php | 6 ++--- tests/Feature/WriterTest.php | 42 ++++++++++++++++----------------- 4 files changed, 37 insertions(+), 27 deletions(-) diff --git a/src/SqlQuery.php b/src/SqlQuery.php index 2cc6aa1..61dd70b 100644 --- a/src/SqlQuery.php +++ b/src/SqlQuery.php @@ -12,4 +12,14 @@ public function __construct( public array $bindings = [] ) { } + + public static function make( + int $number, + string $rawQuery, + float $time, + ?string $query = null, + array $bindings = [] + ): self { + return new self($number, $rawQuery, $time, $query ?? $rawQuery, $bindings); + } } diff --git a/tests/Feature/FormatterTest.php b/tests/Feature/FormatterTest.php index c59f405..6cca944 100644 --- a/tests/Feature/FormatterTest.php +++ b/tests/Feature/FormatterTest.php @@ -111,7 +111,7 @@ $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query = new SqlQuery($number, $sql, $time, $sql); + $query = SqlQuery::make($number, $sql, $time); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); @@ -139,7 +139,7 @@ $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query = new SqlQuery($number, $sql, $time, $sql); + $query = SqlQuery::make($number, $sql, $time); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); @@ -168,7 +168,7 @@ $number = 434; $time = 617.24; $sql = 'SELECT * FROM somewhere'; - $query = new SqlQuery($number, $sql, $time, $sql); + $query = SqlQuery::make($number, $sql, $time); $formatter = new Formatter($app, $config); $result = $formatter->getLine($query); diff --git a/tests/Feature/SqlLoggerTest.php b/tests/Feature/SqlLoggerTest.php index 4c1f04e..557f042 100644 --- a/tests/Feature/SqlLoggerTest.php +++ b/tests/Feature/SqlLoggerTest.php @@ -19,7 +19,7 @@ ['raw_query' => 'anything', 'time' => 1.23], ]); - $sqlQuery = new SqlQuery(1, 'anything', 1.23, 'anything'); + $sqlQuery = SqlQuery::make(1, 'anything', 1.23); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery == $arg)); $this->writer->shouldReceive('report')->once()->withNoArgs(); @@ -38,10 +38,10 @@ ['raw_query' => 'anything2', 'time' => 4.56], ]); - $sqlQuery = new SqlQuery(1, 'anything', 1.23, 'anything'); + $sqlQuery = SqlQuery::make(1, 'anything', 1.23); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery == $arg)); - $sqlQuery2 = new SqlQuery(2, 'anything2', 4.56, 'anything2'); + $sqlQuery2 = SqlQuery::make(2, 'anything2', 4.56); $this->writer->shouldReceive('writeQuery')->once()->with(Mockery::on(fn ($arg) => $sqlQuery2 == $arg)); $this->writer->shouldReceive('report')->once()->withNoArgs(); diff --git a/tests/Feature/WriterTest.php b/tests/Feature/WriterTest.php index e9b192f..af2bf14 100644 --- a/tests/Feature/WriterTest.php +++ b/tests/Feature/WriterTest.php @@ -37,7 +37,7 @@ function setConfig(string|array $key, mixed $value =null) } it('creates directory if it does not exist for 1st query', function () { - $query = new SqlQuery(1, 'test', 5.41, 'test'); + $query = SqlQuery::make(1, 'test', 5.41); setConfig('queries.enabled', false); expect($this->directory)->not()->toBeDirectory(); $this->writer->writeQuery($query); @@ -46,7 +46,7 @@ function setConfig(string|array $key, mixed $value =null) }); it('does not create directory if it does not exist for 2nd query', function () { - $query = new SqlQuery(2, 'test', 5.41, 'test'); + $query = SqlQuery::make(2, 'test', 5.41); setConfig('queries.enabled', false); expect($this->directory)->not()->toBeDirectory(); $this->writer->writeQuery($query); @@ -58,7 +58,7 @@ function setConfig(string|array $key, mixed $value =null) $expectedContent = "-- header\nSample log line\n"; $expectedFileName = $this->now->format('Y-m').'-log.sql'; - $query = new SqlQuery(1, 'test', 5.41, 'test'); + $query = SqlQuery::make(1, 'test', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); @@ -81,7 +81,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = $initialContent."-- header\nSample log line\n"; - $query = new SqlQuery(1, 'test', 5.41, 'test'); + $query = SqlQuery::make(1, 'test', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig('queries.include_pattern', '#.*#i'); @@ -102,7 +102,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "-- header\nSample log line\n"; - $query = new SqlQuery(1, 'test', 5.41, 'test'); + $query = SqlQuery::make(1, 'test', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig([ @@ -126,8 +126,8 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "-- header\n$lineContent\n$lineContent\n"; - $query1 = new SqlQuery(1, 'test', 5.41, 'test'); - $query2 = new SqlQuery(2, 'test', 5.41, 'test'); + $query1 = SqlQuery::make(1, 'test', 5.41); + $query2 = SqlQuery::make(2, 'test', 5.41); $this->formatter->shouldReceive('getLine')->twice()->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn('-- header'); setConfig([ @@ -148,7 +148,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'select * FROM test', 5.41, 'select * FROM test'); + $query = SqlQuery::make(1, 'select * FROM test', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^SELECT .*$#i'); @@ -161,7 +161,7 @@ function setConfig(string|array $key, mixed $value =null) }); it('doesnt save select query to file when pattern set to insert or update queries', function () { - $query = new SqlQuery(1, 'select * FROM test', 5.41, 'select * FROM test'); + $query = SqlQuery::make(1, 'select * FROM test', 5.41); setConfig('queries.include_pattern', '#^(?:UPDATE|INSERT) .*$#i'); $this->writer->writeQuery($query); expect($this->directory)->toBeFile() @@ -173,7 +173,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41, 'INSERT INTO test(one, two, three) values(?, ?, ?)'); + $query = SqlQuery::make(1, 'INSERT INTO test(one, two, three) values(?, ?, ?)', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^(?:UPDATE|INSERT) .*$#i'); @@ -190,7 +190,7 @@ function setConfig(string|array $key, mixed $value =null) $lineContent = 'Sample log line'; $expectedContent = "\n$lineContent\n"; - $query = new SqlQuery(1, 'UPDATE test SET x = 2 WHERE id = 3', 5.41, 'UPDATE test SET x = 2 WHERE id = 3'); + $query = SqlQuery::make(1, 'UPDATE test SET x = 2 WHERE id = 3', 5.41); $this->formatter->shouldReceive('getLine')->once()->with($query)->andReturn($lineContent); $this->formatter->shouldReceive('getHeader')->once()->withNoArgs()->andReturn(''); setConfig('queries.include_pattern', '#^(?:UPDATE test SET x = \d |INSERT ).*$#i'); @@ -203,8 +203,8 @@ function setConfig(string|array $key, mixed $value =null) }); it('only logs slow queries', function () { - $query1 = new SqlQuery(1, 'test1', 5.41, 'test1'); - $query2 = new SqlQuery(2, 'test2', 500.5, 'test2'); + $query1 = SqlQuery::make(1, 'test1', 5.41); + $query2 = SqlQuery::make(2, 'test2', 500.5); setConfig('queries.min_exec_time', 500); @@ -221,9 +221,9 @@ function setConfig(string|array $key, mixed $value =null) }); it('respects query patterns', function () { - $query1 = new SqlQuery(1, 'select foo from bar', 5.41, 'select foo from bar'); - $query2 = new SqlQuery(2, 'update bar set foo = 1', 3.55, 'update bar set foo = 1'); - $query3 = new SqlQuery(3, "update bar set last_visit = '2021-06-03 10:26:00'", 3.22, "update bar set last_visit = '2021-06-03 10:26:00'"); + $query1 = SqlQuery::make(1, 'select foo from bar', 5.41); + $query2 = SqlQuery::make(2, 'update bar set foo = 1', 3.55); + $query3 = SqlQuery::make(3, "update bar set last_visit = '2021-06-03 10:26:00'", 3.22); setConfig([ 'queries.include_pattern' => '/^(?!SELECT).*$/i', @@ -244,7 +244,7 @@ function setConfig(string|array $key, mixed $value =null) }); it('respects the report pattern from the config to determine if a query should be reported', function (string $query, bool $report) { - expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); + expect($this->writer->shouldReportSqlQuery(SqlQuery::make(1, $query, 1)))->toBe($report); })->with([ ['select * from users', false], ['delete from users', true], @@ -253,7 +253,7 @@ function setConfig(string|array $key, mixed $value =null) it('can provide a callback to the writer to determine if a query should be reported', function (string $query, bool $report) { config(['sql-reporter.queries.report_pattern' => null]); Writer::shouldReportQuery(fn (SqlQuery $query) => ! str_contains($query->rawQuery, 'sessions')); - expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); + expect($this->writer->shouldReportSqlQuery(SqlQuery::make(1, $query, 1)))->toBe($report); })->with([ ['delete from sessions', false], ['delete from users', true], @@ -262,7 +262,7 @@ function setConfig(string|array $key, mixed $value =null) it('can combine the report pattern config and the callback to determine if a query should be reported', function (string $query, bool $report) { config(['sql-reporter.queries.report_pattern' => '/^DELETE.*$/i']); Writer::shouldReportQuery(fn (SqlQuery $query) => ! str_contains($query->rawQuery, 'sessions')); - expect($this->writer->shouldReportSqlQuery(new SqlQuery(1, $query, 1, $query)))->toBe($report); + expect($this->writer->shouldReportSqlQuery(SqlQuery::make(1, $query, 1)))->toBe($report); })->with([ ['select * from users', false], ['delete from sessions', false], @@ -272,8 +272,8 @@ function setConfig(string|array $key, mixed $value =null) it('dispatches an event when there are queries to report', function () { Event::fake(); - $query1 = new SqlQuery(1, 'select * from users', 5.41, 'select * from users'); - $query2 = new SqlQuery(2, 'delete from users', 5.41, 'delete from users'); + $query1 = SqlQuery::make(1, 'select * from users', 5.41); + $query2 = SqlQuery::make(2, 'delete from users', 5.41); $expectedFileName = $this->now->format('Y-m').'-log.sql'; $lineContent1 = 'Sample log line 1'; From 96c684e47e9b198f089fb718d1d136136beb3a4f Mon Sep 17 00:00:00 2001 From: Philip Iezzi Date: Thu, 21 Mar 2024 23:16:05 +0100 Subject: [PATCH 7/7] restructure README optional features made Writer constructor props readonly --- README.md | 36 +++++++++++--------- src/Providers/SqlReporterServiceProvider.php | 4 +-- src/Writer.php | 6 ++-- 3 files changed, 25 insertions(+), 21 deletions(-) diff --git a/README.md b/README.md index b3430dc..25748c4 100644 --- a/README.md +++ b/README.md @@ -67,7 +67,20 @@ It reports a lot of metadata like total query count, total execution time, origi 5. Make sure on live server you will set logging SQL queries to false in your `.env` file: `SQL_REPORTER_QUERIES_ENABLED=false`. This package is recommended to be used only for development to not impact production application performance. -## `QueryLogWritten` event +## Optional + +### GeoIP support + +For optional GeoIP support (adding country information to client IP in log headers), you may install [stevebauman/location](https://github.com/stevebauman/location) in your project: + +```bash +$ composer require stevebauman/location +$ php artisan vendor:publish --provider="Stevebauman\Location\LocationServiceProvider" +``` + +It will be auto-detected, no configuration needed for this. If you wish to use a different driver than the default [IpApi](https://ip-api.com/), e.g. `MaxMind` make sure you correctly configure it according to the docs: [Available Drivers](https://github.com/stevebauman/location#available-drivers) + +### `QueryLogWritten` event This package fires a `QueryLogWritten` event after the log file has been written. You may use this event to further debug or analyze the logged queries in your application. The queries are filtered by the `SQL_REPORTER_QUERIES_REPORT_PATTERN` setting, which comes with a sensible default to exclude `SELECT` queries and some default tables like `sessions`, `jobs`, `bans`, `logins`. If you don't want to filter any queries, you may leave this setting empty. @@ -83,16 +96,7 @@ Writer::shouldReportQuery(function (SqlQuery $query) { }); ``` -## Optional - -For optional GeoIP support (adding country information to client IP in log headers), you may install [stevebauman/location](https://github.com/stevebauman/location) in your project: - -```bash -$ composer require stevebauman/location -$ php artisan vendor:publish --provider="Stevebauman\Location\LocationServiceProvider" -``` - -It will be auto-detected, no configuration needed for this. If you wish to use a different driver than the default [IpApi](https://ip-api.com/), e.g. `MaxMind` make sure you correctly configure it according to the docs: [Available Drivers](https://github.com/stevebauman/location#available-drivers) +With the `SqlQuery` object, you have access to both `$rawQuery` and the (unprepared) `$query`/`$bindings`. The filter possibilities by providing a callback to `Writer::shouldReportQuery()` are endless! ## Development @@ -103,10 +107,10 @@ $ git clone https://github.com/onlime/laravel-sql-reporter.git $ cd laravel-sql-reporter $ composer install -# run unit tests -$ vendor/bin/phpunit +# run both Feature and Unit tests +$ vendor/bin/pest # run unit tests with coverage report -$ XDEBUG_MODE=coverage vendor/bin/phpunit +$ vendor/bin/pest --coverage ``` ## FAQ @@ -168,8 +172,8 @@ All changes are listed in [CHANGELOG](CHANGELOG.md) ## Caveats -- If your application crashes, this package will not log any queries, as logging is only triggered at the end. As alternative, you could use [mnabialek/laravel-sql-logger](https://github.com/mnabialek/laravel-sql-logger) which triggers sql logging on each query execution. -- It's currently not possible to log slow queries into a separate logfile. I wanted to keep that package simpel. +- If your application crashes, this package will not log any queries, as logging is only triggered at the end of the request cycle. As alternative, you could use [mnabialek/laravel-sql-logger](https://github.com/mnabialek/laravel-sql-logger) which triggers sql logging on each query execution. +- It's currently not possible to log slow queries into a separate logfile. I wanted to keep that package simple. ## TODO diff --git a/src/Providers/SqlReporterServiceProvider.php b/src/Providers/SqlReporterServiceProvider.php index 4e56ee7..95ded11 100644 --- a/src/Providers/SqlReporterServiceProvider.php +++ b/src/Providers/SqlReporterServiceProvider.php @@ -17,7 +17,7 @@ class SqlReporterServiceProvider extends ServiceProvider /** * {@inheritdoc} */ - public function register() + public function register(): void { $this->config = $this->app->make(Config::class); @@ -31,7 +31,7 @@ public function register() /** * {@inheritdoc} */ - public function boot() + public function boot(): void { $this->publishes([ $this->configFileLocation() => config_path('sql-reporter.php'), diff --git a/src/Writer.php b/src/Writer.php index 6db2652..4ebee88 100644 --- a/src/Writer.php +++ b/src/Writer.php @@ -29,9 +29,9 @@ class Writer private static ?Closure $shouldReportQuery = null; public function __construct( - private Formatter $formatter, - private Config $config, - private FileName $fileName + private readonly Formatter $formatter, + private readonly Config $config, + private readonly FileName $fileName ) { }