Series Nâng cao Kibana & Elastic APM #3: Custom Spans và Nghệ thuật Tương quan Log-Trace (Trạm cuối)

1. Custom Spans: Soi thấu từng thuật toán lõi

Trong hệ thống AFC Metro, việc tính toán giá vé đôi khi rất phức tạp (tùy thuộc vào ga đi, ga đến, loại thẻ vé tháng hay vé lượt, giờ cao điểm hay thấp điểm). Quá trình chạy thuật toán này thuần túy bằng PHP, không gọi ra ngoài, nên APM mặc định sẽ gộp chung nó vào một khối thời gian mờ nhạt.

Để bóc tách chính xác khối logic này, chúng ta sẽ gọi trực tiếp API của Elastic APM Agent để tạo ra một Span (Khoảng đo lường) riêng biệt:

namespace App\Services;

use Elastic\Apm\ElasticApm;

class FareCalculationService
{
    public function calculateFare($cardUid, $entryStation, $exitStation)
    {
        // Lấy Transaction hiện tại mà APM Agent đang tự động theo dõi
        $transaction = ElasticApm::getCurrentTransaction();
        $span = null;

        if ($transaction !== null) {
            // Khởi tạo một Span mới có tên là 'Calculate_Fare_Logic'
            $span = $transaction->beginCurrentSpan(
                'Calculate_Fare_Logic', 
                'app.internal.logic' // Phân loại (Type)
            );
        }

        try {
            // --- BẮT ĐẦU ĐOẠN CODE LOGIC CẦN ĐO LƯỜNG ---
            $fare = 0;
            // Thuật toán duyệt qua ma trận giá vé phức tạp mất khoảng 300ms...
            $matrix = $this->loadMatrix(); 
            $fare = $this->applyDiscounts($matrix, $cardUid);
            // --- KẾT THÚC ĐOẠN CODE ---

            return $fare;
        } finally {
            // Đảm bảo kết thúc bấm giờ dù code có chạy thành công hay văng Exception
            if ($span !== null) {
                $span->end();
            }
        }
    }
}

Bây giờ, khi bạn mở biểu đồ Waterfall trên Kibana, bên cạnh thanh thời gian của Database, bạn sẽ thấy xuất hiện một thanh màu cam ghi rõ Calculate_Fare_Logic: 300ms. Bạn lập tức biết được thuật toán tính giá của mình đang quá chậm và cần phải đem đi tối ưu (có thể bằng cách Cache ma trận giá vé vào Redis).

2. Sự đứt gãy giữa Log và Trace

Hãy hình dung quy trình debug thực tế:

1. Bạn thấy một API bị lỗi 500 trên APM Dashboard lúc 10:05:22.
2. Bạn phải mở tab Discover (Log hệ thống) lên, vất vả chọn bộ lọc thời gian từ 10:05:20 đến 10:05:25, rồi căng mắt tìm xem trong hàng ngàn dòng log từ tất cả các trạm đổ về, dòng log nào thực sự thuộc về cái API bị lỗi kia.

Đây là sự đứt gãy chí mạng gây lãng phí thời gian.

3. Nghệ thuật Log Correlation (Tương quan dữ liệu)

Chuẩn Senior: Mỗi khi APM ghi nhận một Request (Transaction), nó sinh ra một mã định danh duy nhất gọi là trace.id. Nếu chúng ta lấy được cái trace.id này, lén "nhét" nó vào file log của Monolog (Laravel), Kibana sẽ tự động nối hai thế giới này lại với nhau!

Trong Laravel, bạn có thể tạo một Log Processor (Bộ xử lý Log) để tự động đính kèm thông tin này vào mọi dòng Log::info() hay Log::error().

Tạo file ElasticApmProcessor.php:

namespace App\Logging;

use Elastic\Apm\ElasticApm;
use Monolog\LogRecord;

class ElasticApmProcessor
{
    public function __invoke(LogRecord $record): LogRecord
    {
        // Kiểm tra xem APM Agent có đang chạy không
        if (!class_exists(ElasticApm::class)) {
            return $record;
        }

        $transaction = ElasticApm::getCurrentTransaction();
        if ($transaction !== null) {
            // Chèn trace.id và transaction.id vào mảng context của Log
            $record->extra['trace.id'] = $transaction->getTraceId();
            $record->extra['transaction.id'] = $transaction->getId();
        }

        return $record;
    }
}

Sau đó, đăng ký Processor này vào Kênh Log elasticsearch (hoặc filebeat) của bạn trong config/logging.php:

'filebeat' => [
            'driver' => 'daily',
            'path' => storage_path('logs/kibana.log'),
            'tap' => [App\Logging\ElasticApmProcessor::class], // Đính kèm Processor vào đây
            'formatter' => Monolog\Formatter\JsonFormatter::class,
        ],

4. Tận hưởng Sức mạnh trên Kibana

Từ giây phút đoạn code trên được đưa lên Production, trải nghiệm Debug của bạn sẽ thay đổi một cách thần kỳ:

1. Trên màn hình APM, bạn phát hiện hàm đồng bộ lỗi. Bạn click vào cái Trace màu đỏ đó.
2. Kibana sẽ hiển thị biểu đồ Waterfall. Và kỳ diệu chưa: Ngay bên dưới biểu đồ, xuất hiện một tab có tên là Logs.
3. Bạn click vào tab Logs, nó chỉ hiển thị ĐÚNG 3 dòng log (Log::info(), Log::error()) được sinh ra trong chính chu kỳ sống của cái Request đó, bỏ qua hàng triệu dòng log rác khác của hệ thống.

Bạn không còn phải đi mò kim đáy bể nữa. Bạn nhìn thấy Trace chậm ở đâu, và lập tức đọc được chính xác dòng log mô tả tại sao nó chậm ngay tại một màn hình duy nhất.

Tổng kết Series Nâng cao Kibana & Elastic APM

Với mảnh ghép cuối cùng này, cỗ máy giám sát của chúng ta đã đạt đến mức hoàn hảo:

1. APM Server & Agent: "Nội soi" toàn bộ thời gian chạy của hệ thống mà không làm ảnh hưởng đến luồng code chính.
2. Alerting & Webhook: Tự động rú còi báo động qua Telegram khi hệ thống đối tác nghẽn mạng hoặc vượt ngưỡng trễ.
3. Custom Spans & Log Correlation: Cung cấp độ sâu tuyệt đối, chỉ đích danh khối code làm chậm hệ thống và ghim thẳng các dòng log chi tiết vào từng Trace.