I. Đặt vấn đề
Chào mọi người, chắc hẳn a/e khi làm dự án đều sử dụng Log rồi nhỉ, ít nhiều thì cũng đã từng trace log để debug. Tuy nhiên, đôi khi chúng ta chưa thật sự chú trọng vào việc mình Log đã hiệu quả chưa, chỉ đến khi có issue cần sử dụng Log để điều tra thì lúc đó mới ngớ người ra vì thông tin log bị thiếu, rời rạc, không thống nhất format thậm trí là quên không log nên rất khó để trace. Vì vậy, hôm nay mình sẽ tổng hợp một số trải nghiệm của mình về Log trong Laravel khi làm dự án để a/e có thể tham khảo, biết đâu có thể áp dụng vào dự án của mình. Nhìn Log chuyên nghiệp hơn, nâng skill mình hơn.
II. Một số lỗi thường gặp khi Log
- Lỗi đầu tiên, quên không Log: ví dụ khi có exception, chỉ chăm chăm response lỗi mà quên không Log lại exception.
Đặc biệt là khi call API sang bên thứ 3, rất nhiều a/e không log lại request (url, params...) và response. Đến khi Khách hàng báo Bug thì không có tý thông tin nào của request đó, không biết lỗi do bên mình hay bên thứ 3. - Log thông tin rời rạc
Nhìn code thì cứ tưởng ngon ăn, đẹp đấy. Test thử dưới Local log đẹp luôn (Vì chỉ có 1 request 🤭). Nhưng khi triển khai trên server lúc này lượng truy cập vào hệ thống không còn một mình mình nữa, lúc này các log chồng chéo lên nhau, không biết những line nào là cùng 1 request. Log coi như bỏLog::error('Exception create invoice: '); Log::error('Message', $e->getMessage()); Log::error('Line', $e->getLine()); Log::error('File', $e->getFile());
--> Cần gộp lại thông tin trong một logLog::error('Exception create invoice: ', [ 'Message' => $e->getMessage(), 'Line' => $e->getLine(), 'File' => $e->getFile() ]); - Không phân luồng Log, cho những ai chưa biết, Laravel đã hỗ trợ sẵn việc chia thread Log rồi. A/e có thể define trong
config/logging.phpsử dụngchannelsđể quản lý log theo từng module.'channels' => [ 'invoice' => [ 'driver' => 'single', 'path' => storage_path('logs/invoice.log'), 'days' => 14 // rotate log after 14 days ] ] Sử dụng: Log::channel('invoice', $message, $context) - Cuối cùng, mình thấy có nhiều dự án không thống nhất cách Log, mỗi người "mạnh ai người nấy log". Nên khi có việc cần debug phải sử dụng log của member khác, hay thậm trí sử dụng lại log của chính mình ngày xưa, mất nhiều thời gian để tìm được thông tin mình cần.
III. Custom Log trong Laravel
Ok, giờ chúng ta sẽ đi vào vấn đề chính của bài hôm nay, đó là custom Log sao cho toàn bộ dự án có chung 1 format Log, dễ đọc và dễ dàng maintain Log của người khác.
Với Laravel các thông tin chung mà log nào cũng nên có (Tùy vào nhu cầu dự án mà pick các thông tin mình cần) là:
- Date Time
- Log type (hoặc log level)
- Message
- Context
- Request URL
- Method
- Request Parameters
- User info (Nếu có)
- IP Address (optional)
- User-Agent (optional)
Để thực hiện điều đó, chúng ta cần tạo CustomizeFormat
<?php namespace App\Common\Logger; use Common\Auth\Facade\AuthUser;
use Illuminate\Http\Request;
use Monolog\Formatter\LineFormatter; class CustomizeFormatter
{ // Đây sẽ là format log của mình, muốn log thêm field nào sử dụng cú phát %field% const LOG_FORMAT = "[%datetime%] %channel%.%level_name%, 'message': %message%, 'context': %context%\n'url': %url%, 'method': %method%, 'request-params': %request-params%, 'user': %user%, 'ip': %ip%, 'user-agent': %user-agent%}\n"; // Đây sẽ là format date của field %datetime% const DATE_FORMAT = 'Y-m-d H:i:s'; /** * @var Request */ protected Request $request; public function __construct(Request $request) { $this->request = $request; } public function __invoke($logger) { $formatter = new LineFormatter(self::LOG_FORMAT, self::DATE_FORMAT); /** @var \Monolog\Logger $logger */ foreach ($logger->getHandlers() as $handler) { if (!($handler instanceof \Monolog\Handler\NullHandler)) { $handler->setFormatter($formatter); $this->customizeHandler($handler); } } } /** * configure display data to %field% * %field% in LOG_FORMAT * * @param $handler */ public function customizeHandler($handler) { // Đây chính là nơi mà mình muốn log thêm các fields mong muốn, nhớ mapping vs %field% ở LOG_FORMAT nhé $handler->pushProcessor(function ($record) { $record['url'] = $this->request->url(); $record['method'] = $this->request->getMethod(); $record['request-params'] = $this->request->all(); $record['ip'] = $this->request->getClientIp(); $record['user-agent'] = $this->request->header()['user-agent'] ?? ''; $record['user'] = AuthUser::getCustomerId() ?? null; return $record; }); }
} Ok, việc setup cơ bản xong rồi đấy. Bây giờ mình sẽ hướng dẫn một vài cách implement CustomizeFormatter trên
1. Sử dụng tap trong logging
Cái này mình thấy rất ít anh em sử dụng trong config/logging.php
'channels' => [ 'invoice' => [ 'driver' => 'single', 'path' => storage_path('logs/invoice.log'), 'days' => 14, // rotate log after 14 days 'tap' => [\App\Common\Logger\CustomizeFormatter::class] ]
]
Giải thích 1 chút thì key 'tap' ở đây sẽ là 1 mảng bao gồm các class callback, nó được dùng để customize Log, các class này bắt buộc phải có 1 method __invoke với tham số là Illuminate\Log\Logger. Hay nói cách khác đó chính là class CustomizeFormatter mà chúng ta vừa define ở trên.
Tap sẽ được gọi khi channel invoice có event write Log . Chính vì vậy, ngoài việc customize Log chúng ta có thể tận dụng để làm 1 vài tác vụ khác tùy vào nghiệp vụ dự án, ví dụ như gửi notification, email đến 1 kênh nào đó khi có Log error...
Giờ thử sử dụng Log xem như thế nào nhé
\Log::channel('invoice')->info('Created invoice, info', [ 'id' => 'I0008572', 'customer-name' => 'QuanLx', 'employee-name' => 'JohnWick', 'total' => '406000', 'method' => 'MoMo'
]);
Đây là kết quả Log:
[2023-11-22 16:04:58] local.INFO, 'message': Created invoice, info, 'context': {"id":"I0008572","customer-name":"QuanLx","employee-name":"JohnWick","total":"406000","method":"MoMo"}
'url': http://localhost/list, 'method': GET, 'request-params': {"customer_name":"QuanLx","total_amount":"406000","payment_method":"MoMo"}, 'user': NULL, 'ip': 172.21.0.1, 'user-agent': ["Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"]}
2. Sử dụng ServiceProvider
Thông thường thì sẽ sử dụng cách 1 là ổn rồi. Tuy nhiên, có bạn lại thấy hơi mất thời gian khi mà channel nào cũng phải thêm tay phần tap và thấy ngứa mắt khi bị lặp lại code, cùng xử lý nhé.
Đầu tiên, tạo 1 CustomLogManager extend từ class base trong core Log của Laravel là LogManager
<?php namespace App\Common\Logger; use App\Common\Logger\CustomizeFormatter;
use Illuminate\Log\Logger;
use Illuminate\Log\LogManager as BaseLogManager; class CustomLogManager extends BaseLogManager
{ /** * Apply the configured taps for the logger. * If channel a has an empty tap, get the tap from CustomizeFormatter * * @param string $name * @param \Illuminate\Log\Logger $logger * @return \Illuminate\Log\Logger * @throws \Illuminate\Contracts\Container\BindingResolutionException */ protected function tap($name, Logger $logger) { foreach ($this->configurationFor($name)['tap'] ?? [CustomizeFormatter::class] as $tap) { [$class, $arguments] = $this->parseTap($tap); $this->app->make($class)->__invoke($logger, ...explode(',', $arguments)); } return $logger; }
}
Mục đích chính là overwrite lại function tap: Nếu config channel không đề cập đến tap thì mặc định sẽ được customize Log theo CustomizeFormatter
'channels' => [ 'invoice' => [ 'driver' => 'single', 'path' => storage_path('logs/invoice.log'), 'days' => 14, // rotate log after 14 days ], 'product' => [ 'driver' => 'single', 'path' => storage_path('logs/product.log'), 'days' => 14, // rotate log after 14 days ], 'transaction' => [ 'driver' => 'single', 'path' => storage_path('logs/transaction.log'), 'days' => 14, // rotate log after 14 days 'tap' => [\App\Common\Logger\SpecificFormatter::class] ]
]
Như ví dự trên, 2 channel invoice & product sẽ auto được customize Log theo CustomizeFormatter, còn channel transaction được define tap cụ thể nên sẽ được customize Log theo SpecificFormatter
Tiếp theo chúng ta sẽ register serviceProvider, ở đây tôi sẽ sử dụng luôn trong AppServiceProvider, còn chuẩn chỉ anh em có thể tạo riêng 1 LogServiceProvider
public function register()
{ $this->app->singleton('custom-log', function ($app) { return new CustomLogManager($app); });
}
Tạo 1 Facade CustomLog để thay thế Facade Log của Laravel
<?php namespace Common\Facade; use Illuminate\Support\Facades\Facade; /** * * Class CustomLog * @package Common\Facade */
class CustomLog extends Facade
{ /** * ファサードとして振る舞うコンポーネントの登録名を取得する * * @return string */ protected static function getFacadeAccessor(): string { return 'custom-log'; }
} Cuối cùng là đăng ký Alias trong config/app.php
'aliases' => [ ... 'CustomLog' => Common\Auth\Facade\CustomLog::class,
]
Xong, thử chạy thôi:
CustomLog::channel('product')->info('Created Product, info', [ 'id' => 'P0008572', 'name' => 'Điều Hòa', 'price' => '14000000'
]);
Cùng kiểm tra log nào product.log
[2023-11-22 16:49:50] local.INFO, 'message': Created Product, info, 'context': {"id":"P0008572","name":"Điều Hòa","price":"14000000"}
'url': http://localhost/product, 'method': POST, 'request-params': {"name":"Điều Hòa","price":"14000000"}, 'user': NULL, 'ip': 172.21.0.1, 'user-agent': ["Mozilla/5.0 (X11; Linux x86_64) AppleWebKit/537.36 (KHTML, like Gecko) Chrome/107.0.0.0 Safari/537.36"]}
Vấn đề
Cách 2 này, lúc đầu tôi muốn overwrite lại chính Facade Log của Laravel mà không cần phải tạo Facade mới CustomLog cơ. Bằng cách cho binding lại log trong AppServiceProvider
public function register()
{ $this->app->singleton('log', function ($app) { return new CustomLogManager($app); // Trong core Laravel LogServiceProvider chỗ này đang là: return new LogManager($app); });
}
Cơ mà không hiểu sao khi dùng Log::info() hay Log::channel('product')->info() thi nó vẫn trả về LogManager chứ không phải là CustomLogManager của tôi. CAY VÃI!!!
Anh em nào biết lý do thì thông não cho mình với nhé. Lúc đầu nghĩ là do singleton không cho phép overwrite lại nhưng không phải, tôi thử sửa trong core là bind thì vẫn không được. Cay quá nên mới phải dùng cách tạo Facade mới.
Update: mình đã điều tra thêm và biết nguyên nhân tại sao không overwrite lại được Facade Log rồi, lý do là khi build khởi tạo, instance LogManager đã được bind và lưu vào cache rồi, nên khi gọi Facade sau đó thì nó sẽ lấy trong cache ra thôi. Mình thử comment cache (trong core nhé, để test thôi) thì nó đã trả về CustomLogManager đúng như mong đợi của mình.
IV. Tổng kết
Trên đây là cách mình triển khai customize Log trong Laravel, anh em có thể tham khảo và implement nó vào khi dựng base dự án. Hi vọng có thể giúp ích cho anh em trong việc triển khai log chuyên nghiệp và debug log một cách thuận tiện & hiệu quả nhất.
Tài liệu tham khảo: