+2

[Laravel Masterclass] Giải mã enableQueryLog(): Vũ khí Debug SQL cực bén và Quả bom Memory Leak chực chờ

Chào anh em. Code Laravel thì ai cũng biết gõ User::with('posts')->get(). Nhưng có bao giờ anh em tự hỏi: "Bên dưới cái hàm ảo diệu kia, Laravel thực sự đẩy câu lệnh SQL gì xuống MySQL?"

Để tối ưu Database (như bài đánh Index mình đã chia sẻ), anh em PHẢI nhìn thấy được câu raw SQL. Công cụ thô sơ và hiệu quả nhất mà Laravel cấp cho anh em chính là DB::enableQueryLog().

1. Cách xài cơ bản: "Lật tẩy" Eloquent

Logic nghe rất đơn giản: Bật máy ghi âm -> Chạy code -> Tắt máy và lấy băng ghi âm đó ra nghe.

use Illuminate\Support\Facades\DB;

// 1. Bật tính năng ghi log
DB::connection()->enableQueryLog();

// 2. Chạy một mớ logic Eloquent phức tạp
$users = User::where('status', 'active')
             ->where('age', '>', 18)
             ->orderBy('created_at', 'desc')
             ->limit(10)
             ->get();

// 3. Lấy toàn bộ log ra xem
$queries = DB::getQueryLog();

// In ra màn hình
dd($queries);

Kết quả anh em nhận được sẽ là một mảng Array:

[
  {
    "query": "select * from `users` where `status` = ? and `age` > ? order by `created_at` desc limit 10",
    "bindings": ["active", 18],
    "time": 2.45
  }
    ]

Nó cho anh em biết chính xác 3 thứ:

  1. Câu SQL thô (chưa có tham số).
  2. Các tham số truyền vào (bindings) để chống SQL Injection.
  3. Thời gian chạy câu query đó mất bao nhiêu mili-giây (time).

2. Lắp ghép SQL thô: Vấn đề nhức nhối

Anh em nhìn kết quả ở trên xem, Laravel trả về câu query chứa toàn dấu ?. Nếu anh em muốn copy câu SQL này ném vào DBeaver hay phpMyAdmin để chạy thử EXPLAIN ANALYZE thì anh em phải hì hục gõ tay thay từng cái dấu ? bằng data thật. Rất mất thời gian!

Giải pháp cho anh em Senior: Tự viết một đoạn code mix (trộn) query và bindings lại với nhau:

$queries = DB::getQueryLog();
foreach ($queries as $query) {
    // Lấy câu SQL có dấu ?
    $sql = $query['query'];
    
    // Bọc nháy đơn cho các giá trị string
    $bindings = array_map(function ($value) {
        return is_string($value) ? "'{$value}'" : $value;
    }, $query['bindings']);

    // Dùng hàm Str::replaceArray của Laravel để đắp data vào
    $rawSql = \Illuminate\Support\Str::replaceArray('?', $bindings, $sql);
    
    // In ra câu SQL có thể copy-paste chạy ngay!
    Log::info($rawSql);
}

Pro-Tip Laravel 10+: Nếu anh em chỉ muốn check 1 câu Query Builder duy nhất, không cần phải bật enableQueryLog() rườm rà. Laravel 10 đã cung cấp sẵn hàm toRawSql(). Chỉ cần gõ: User::where('status', 'active')->toRawSql(); -> Nó trả về luôn chuỗi select * from users where status = 'active'. Cực kì nhàn!

3. Quả bom Memory Leak trên Production (CỰC KÌ NGUY HIỂM)

Đây là phần "nặng đô" nhất của bài viết.

Nhiều anh em sau khi debug xong, lười hoặc quên xóa dòng DB::enableQueryLog(), và vô tình đẩy luôn đoạn code đó lên Production. Hoặc có anh em "thông minh" hơn, bỏ cái lệnh này vào Middleware để lưu mọi query của hệ thống vào file log.

Anh em có biết bên dưới Laravel, enableQueryLog hoạt động thế nào không?

Nó tạo ra một cái Mảng (Array) lưu trên RAM của server. Mỗi khi có 1 câu query chạy qua, nó array_push cái SQL, Bindings và Time vào mảng đó. Nếu anh em chạy Web request thông thường, chạy xong request thì mảng đó bị xóa. Không sao cả. Nhưng thảm họa xảy ra khi anh em kết hợp enableQueryLog() với Laravel Queue Worker (hoặc Laravel Octane). Như mình đã nói ở bài Queue, Worker là một tiến trình sống dai dẳng (Long-lived process). Nếu bạn bật Query Log bên trong Worker, cái Array lưu Log đó sẽ KHÔNG BAO GIỜ ĐƯỢC XÓA. Nó cứ phình to dần, phình to dần theo từng giây. Cứ mỗi đơn hàng xử lý xong, nó lại nhét thêm chục dòng SQL vào RAM. Chỉ sau vài tiếng, tiến trình Queue Worker sẽ nuốt cạn hàng chục GB RAM, và bạn sẽ được diện kiến sát thủ OOM Killer mà chúng ta đã học ở bài trước. Hệ thống treo cứng, Queue chết sạch!

4. Cách Log Query trên Production chuẩn Kĩ sư hệ thống

Nếu trên Production, sếp bắt bạn phải Log lại những câu query nào chạy chậm quá 50ms để tối ưu, BẠN TUYỆT ĐỐI KHÔNG ĐƯỢC DÙNG enableQueryLog().

Thay vào đó, hãy lắng nghe Event của Database thông qua DB::listen(). Mở file AppServiceProvider.php ra và phang đoạn code này vào hàm boot():

use Illuminate\Support\Facades\DB;
use Illuminate\Support\Facades\Log;

public function boot()
{
    // Lắng nghe mọi câu query chạy trong hệ thống
    DB::listen(function ($query) {
        // Chỉ ghi log những câu query mất hơn 50 mili-giây
        if ($query->time > 50) {
            $sql = $query->sql;
            $bindings = implode(', ', $query->bindings);
            $time = $query->time;

            // Ghi thẳng xuống file vật lý, KHÔNG LƯU TRÊN RAM!
            Log::warning("Slow Query [{$time}ms]: {$sql} - Bindings: [{$bindings}]");
        }
    });
}

Cách này an toàn tuyệt đối, vì dữ liệu đi qua Event được ghi thẳng ra file laravel.log trên ổ cứng rồi bị hủy ngay trên RAM. Không bao giờ lo Memory Leak!

Tổng kết

Tóm tắt lại cho anh em chiếu mới:

  1. Debug ở môi trường Local? Cứ xài enableQueryLog() thoải mái, nhưng khuyên thật là nên cài package Laravel Debugbar hoặc Laravel Telescope để nó vẽ UI cho anh em xem sướng con mắt, khỏi cần gõ code.
  2. Debug 1 câu query nhanh? Xài ->toRawSql().
  3. Cần bắt Slow Query trên Production? Tuyệt đối không bật Query Log, hãy xài Event DB::listen().

Anh em thấy sao? Chỉ một cái hàm đơn giản thôi mà nếu không hiểu sâu về vòng đời của Framework và RAM thì cũng đủ để tiễn server về cõi vĩnh hằng.

Bài tới anh em muốn tiếp tục đào sâu vào Laravel (như vòng đời Service Container, Middleware, Trait) hay muốn chuyển qua phần vận hành Deploy (Docker, Nginx Config) nào? Ném request xuống comment để mình lên bài tiếp nhé!


All rights reserved

Viblo
Hãy đăng ký một tài khoản Viblo để nhận được nhiều bài viết thú vị hơn.
Đăng kí