diff --git a/CHANGELOG.md b/CHANGELOG.md index a1d67ba..894d648 100644 --- a/CHANGELOG.md +++ b/CHANGELOG.md @@ -1,6 +1,14 @@ # Changelog +## 2.0.0 - 2025-07-28 +- Added Backtrace queries info +- Changes to key names in debug json + - `query` -> `sql` + - `n_plus_one` -> `repeated_queries` +- Sorting long queries by execution time +- Refactor + ## 1.0.3 - 2025-03-28 - Fix for debugging temporary files diff --git a/README.md b/README.md index 1231d8c..b001ae9 100644 --- a/README.md +++ b/README.md @@ -34,60 +34,77 @@ When you send an API request and `APP_DEBUG=true`, you'll receive the following "time": 14.57, "data": [ { - "query": "select * from `domains` where `is_active` = ? limit 1", - "bindings": [ - true - ], - "time": 10.09 + "sql": "select * from `domains` where `is_active` = ? limit 1", + "bindings": [true], + "time": 10.09, + "trace": [ + "/var/www/html/app/Support/Domains/Domain.php:101", + "/var/www/html/app/Http/Middleware/SetClientDomain.php:32", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `products` limit 1", + "sql": "select * from `products` limit 1", "bindings": [], - "time": 0.75 + "time": 0.75, + "trace": [ + "/var/www/html/app/Http/Controllers/ProductController.php:27", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `menu_items` where (`domain_id` = ? or `domain_id` is null) order by `weight` asc", - "bindings": [ - "8e591823-4f64-4e90-b564-e0c090696d6e" - ], - "time": 0.82 + "sql": "select * from `menu_items` where (`domain_id` = ? or `domain_id` is null) order by `weight` asc", + "bindings": ["8e591823-4f64-4e90-b564-e0c090696d6e"], + "time": 0.82, + "trace": [ + "/var/www/html/app/Support/Menu/MenuLoader.php:17", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `pages` where `slug` = ? and (`domain_id` = ? or `domain_id` is null) and `status` = ? order by `weight` asc, `created_at` asc limit 1", - "bindings": [ - "contacts", - "8e591823-4f64-4e90-b564-e0c090696d6e", - "published" - ], - "time": 0.76 + "sql": "select * from `pages` where `slug` = ? and (`domain_id` = ? or `domain_id` is null) and `status` = ? order by `weight` asc, `created_at` asc limit 1", + "bindings": ["contacts", "8e591823-4f64-4e90-b564-e0c090696d6e", "published"], + "time": 0.76, + "trace": [ + "/var/www/html/app/Support/Pages/PageService.php:89", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `comparisons` where `guest_id` = ?", - "bindings": [ - "62afacc1-37b2-464d-8028-818745e56de5" - ], - "time": 0.61 + "sql": "select * from `comparisons` where `guest_id` = ?", + "bindings": ["62afacc1-37b2-464d-8028-818745e56de5"], + "time": 0.61, + "trace": [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:19", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `comparisons` where `guest_id` = ?", - "bindings": [ - "62afacc1-37b2-464d-8028-818745e56de5" - ], - "time": 0.61 + "sql": "select * from `comparisons` where `guest_id` = ?", + "bindings": ["62afacc1-37b2-464d-8028-818745e56de5"], + "time": 0.61, + "trace": [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:20", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `comparisons` where `guest_id` = ?", - "bindings": [ - "62afacc1-37b2-464d-8028-818745e56de5" - ], - "time": 0.63 + "sql": "select * from `comparisons` where `guest_id` = ?", + "bindings": ["62afacc1-37b2-464d-8028-818745e56de5"], + "time": 0.63, + "trace": [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:21", + "/var/www/html/public/index.php:51" + ] }, { - "query": "select * from `seos` where `path` = ? limit 1", - "bindings": [ - "" - ], - "time": 0.93 + "sql": "select * from `seos` where `path` = ? limit 1", + "bindings": [""], + "time": 0.93, + "trace": [ + "/var/www/html/app/Http/Controllers/SeoController.php:14", + "/var/www/html/public/index.php:51" + ] } ], "long_queries": [ @@ -96,13 +113,32 @@ When you send an API request and `APP_DEBUG=true`, you'll receive the following "bindings": [ true ], - "time": 10.09 + "time": 10.09, + "trace": [ + "/var/www/html/app/Support/Domains/Domain.php:101", + "/var/www/html/app/Http/Middleware/SetClientDomain.php:32", + "/var/www/html/public/index.php:51" + ] } ], - "n_plus_one": [ + "repeated_queries": [ { "query": "select * from `comparisons` where `guest_id` = ?", - "count": 3 + "count": 3, + "backtrace": [ + [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:19", + "/var/www/html/public/index.php:51" + ], + [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:20", + "/var/www/html/public/index.php:51" + ], + [ + "/var/www/html/app/Http/Middleware/ComparisonMiddleware.php:21", + "/var/www/html/public/index.php:51" + ] + ] } ] }, diff --git a/src/Support/ApiDebugger.php b/src/Support/ApiDebugger.php index 3c9c949..6f1880c 100644 --- a/src/Support/ApiDebugger.php +++ b/src/Support/ApiDebugger.php @@ -10,6 +10,8 @@ class ApiDebugger { + private array $queries = []; + /** * Check if the debugger is active based on APP_DEBUG environment variable. * @@ -27,9 +29,24 @@ public function isActive(): bool */ public function startDebug(): void { - if ($this->isActive()) { - DB::enableQueryLog(); + if (!$this->isActive()) { + return; } + + $this->queries = []; + + DB::listen(function ($query) { + $this->queries[] = [ + 'sql' => $query->sql, + 'bindings' => $query->bindings, + 'time' => $query->time, + 'trace' => collect(debug_backtrace(DEBUG_BACKTRACE_IGNORE_ARGS)) + ->filter(fn ($trace) => isset($trace['file']) && !str_contains($trace['file'], 'vendor')) + ->map(fn ($trace) => "{$trace['file']}:{$trace['line']}") + ->values() + ->all(), + ]; + }); } /** @@ -69,18 +86,18 @@ protected function getRequestInfo(Request $request): array */ protected function getQueriesInfo(): array { - $queries = DB::getQueryLog(); - $totalTime = round(array_reduce($queries, fn ($carry, $query) => $carry + $query['time'], 0), 2); + $queries = $this->queries; + $totalTime = round(array_reduce($queries, fn ($carry, $query) => $carry + $query['time'], 0), 2); $longQueries = $this->checkLongQueries($queries); - $nPlusOneIssues = $this->checkNPlusOne($queries); + $repeatedQueries = $this->checkRepeatedQueries($queries); return [ 'count' => count($queries), 'time' => $totalTime, 'data' => $queries, 'long_queries' => $longQueries, - 'n_plus_one' => $nPlusOneIssues, + 'repeated_queries' => $repeatedQueries, ]; } @@ -93,15 +110,11 @@ protected function getQueriesInfo(): array */ protected function checkLongQueries(array $queries, float $threshold = 10.0): array { - $longQueries = []; - - foreach ($queries as $query) { - if ($query['time'] > $threshold) { - $longQueries[] = $query; - } - } - - return $longQueries; + return collect($queries) + ->filter(fn ($query) => $query['time'] > $threshold) + ->sortByDesc('time') + ->values() + ->all(); } /** @@ -112,29 +125,31 @@ protected function checkLongQueries(array $queries, float $threshold = 10.0): ar * @param array $queries * @return array */ - protected function checkNPlusOne(array $queries): array + protected function checkRepeatedQueries(array $queries): array { - $queryCounts = []; - $nPlusOneIssues = []; + $queryMap = []; + $repeatedQueries = []; foreach ($queries as $query) { - $queryKey = $query['query']; - if (isset($queryCounts[$queryKey])) { - $queryCounts[$queryKey]++; - } else { - $queryCounts[$queryKey] = 1; - } + $queryKey = $query['sql']; + $queryMap[$queryKey][] = $query; } - foreach ($queryCounts as $queryKey => $count) { - if ($count > 1) { - $nPlusOneIssues[] = [ - 'query' => $queryKey, - 'count' => $count, + foreach ($queryMap as $sql => $instances) { + if (count($instances) > 1) { + $backtraces = array_map( + fn ($q) => $q['trace'], + $instances + ); + + $repeatedQueries[] = [ + 'sql' => $sql, + 'count' => count($instances), + 'backtrace' => $backtraces, ]; } } - return $nPlusOneIssues; + return $repeatedQueries; } }