为什么要做接口日志记录
方便快速排查问题
系统在运行过程中，偶尔会出现线上问题，通过接口日志可以快速地查询到请求的参数、运行过程中的异常以及响应的结果，有助于开发人员快速排查问题。
方便操作审计
通过接口日志，可以快速查询到用户在什么时间对系统进行了什么操作，方便溯源和审计工作。
接口请求频率与性能分析
通过日志记录，可以查询到接口在指定时间内请求的次数以及每次请求所耗费的时间，方便接口分析工作。
如何做接口日志记录
用到的技术与工具
- thinkphp框架异常处理、钩子和行为、think-queue队列
- supervisor进程管理工具
- PHP反射类
流程
用户操作系统发起接口请求，系统处理请求过程中发生的异常以及处理正常的结果都通过抛出异常的方式响应给用户，这些异常会被预先定义好的异常处理器捕获，在异常处理器中获取本次请求的信息与结果，并推送到日志队列，日志队列再保存到日志数据库。
步骤
自定义异常基类
<?php
namespace app\library\exception;
use app\common\MyLog;
use think\Exception;
/**
* Class BaseException
* 自定义异常类的基类
*/
class BaseException extends Exception {
public $code = 400;
public $msg = '无效参数';
public $error_code = '999';
public $content = '';
public $request_url = '';
public $log_id = '';
/**
* 构造函数，接收一个关联数组
* @param array $params 关联数组只应包含code、msg和error_code，且不应该是空值
*/
public function __construct($params=[]) {
if(!is_array($params)){
return;
}
if(array_key_exists('code',$params)){
$this->code = $params['code'];
}
if(array_key_exists('msg',$params)){
$this->msg = $params['msg'];
}
if(array_key_exists('error_code',$params)){
$this->error_code = (int)$params['error_code'];
}
if(array_key_exists('content',$params)){
$this->content = $params['content'];
}
if(array_key_exists('request_url',$params)){
$this->request_url = $params['request_url'];
}
$this->log_id = MyLog::setLogId();
}
}定义成功和失败异常返回类,继承BaseException类
<?php
namespace app\library\exception;
/**
* 创建成功（如果不需要返回任何消息）
*/
class SuccessMessage extends BaseException
{
public $code = 201;
public $msg = 'ok';
public $error_code = 0;
public $content = '';
}<?php
namespace app\library\exception;
/**
* 创建失败（如果不需要返回任何消息）
*/
class FailMessage extends BaseException
{
public $code = 201;
public $msg = '操作失败';
public $error_code = 1;
public $content = '';
}修改thinkphp异常处理器方法，捕获到接口抛出的SuccessMessage、FailMessage异常以及系统运行的异常，并在application/tags.php定义钩子行为，通过Hook::listen('before_response_result', $result)钩子传给日志处理类处理
<?php
namespace app\library\exception;
use app\common\MyLog;
use app\cooperation\service\EnDecryptDataService;
use GuzzleHttp\Client;
use GuzzleHttp\Exception\ClientException;
use GuzzleHttp\Exception\RequestException;
use think\exception\Handle;
use Exception;
use think\facade\Config;
use think\facade\Env;
use think\facade\Hook;
use think\facade\Request;
/*
* 重写Handle的render方法，实现自定义异常消息
*/
class ExceptionHandler extends Handle {
private $code;
private $msg;
private $error_code;
private $content;
private $request_url;
private $log_id;
public function render(Exception $e) {
if ($e instanceof BaseException) {
//如果是自定义异常，则控制http状态码，不需要记录日志
//因为这些通常是因为客户端传递参数错误或者是用户请求造成的异常 不应当记录日志
$this->code = $e->code;
$this->msg = $e->msg;
$this->error_code = $e->error_code;
$this->content = $e->content;
$this->request_url = $e->request_url;
$this->log_id = $e->log_id;
$res = [
'code' => $this->code,
'msg' => $this->msg,
'error_code' => $this->error_code,
'content' => $this->content,
];
MyLog::infoLog('[debug]',' [Url]:' . Request::url(true) . ' [Method]:' . Request::method() . ' [Header]:' . json_encode(Request::header(), JSON_UNESCAPED_UNICODE) . ' [Request]:'. json_encode(Request::param(),JSON_UNESCAPED_UNICODE) . ' [Response]:'. json_encode($res,JSON_UNESCAPED_UNICODE),'api');
} else{
$this->code = 500;
$this->msg = 'sorry，这是一个未知错误. (^o^)Y';
$this->error_code = 999;
$this->log_id = MyLog::setLogId();
if(config('app_debug')){
return parent::render($e);
}
}
$result = [
'msg' => $this->msg,
'error_code' => $this->error_code,
'content' => $this->content,
'scope' => session('scope'),
'log_id' => $this->log_id,
];
Hook::listen('before_response_result', $result);
if ($e instanceof RpcResponseSuccess || $e instanceof RpcResponseFail){
return json(EnDecryptDataService::encryptData('hopo_share', json_encode($result, JSON_UNESCAPED_SLASHES|JSON_UNESCAPED_UNICODE)));
}
return json($result, $this->code);
}<?php
// +----------------------------------------------------------------------
// | ThinkPHP [ WE CAN DO IT JUST THINK ]
// +----------------------------------------------------------------------
// | Copyright (c) 2006~2018 http://thinkphp.cn All rights reserved.
// +----------------------------------------------------------------------
// | Licensed ( http://www.apache.org/licenses/LICENSE-2.0 )
// +----------------------------------------------------------------------
// | Author: liu21st <liu21st@gmail.com>1111
// +----------------------------------------------------------------------
// 应用行为扩展定义文件
return [
// 应用初始化
'app_init' => [
'app\\admin\\behavior\\CORS',
],
// 应用开始
'app_begin' => [],
// 模块初始化
'module_init' => [],
// 操作开始执行
'action_begin' => [
],
// 视图内容过滤
'view_filter' => [],
// 日志写入
'log_write' => [],
// 应用结束
'app_end' => [],
// 返回结果前
'before_response_result' => [
\app\behavior\ApiRequestStatistics::class
]
];安装think-queue扩展，因为用的是thinkphp5.1框架，所以think-queue要选2.0版本 think-queue ，队列进程可以使用 supervisor 进行管理，使用队列来异步处理以及保存日志可以避免接口请求速度受到太大影响，安装后定义日志保存的Job，这里的例子是把日志保存到数据库，考虑到日志数量可能会很多，建议采用其它合适的方式存储
composer require topthink/think-queue=^2.0 <?php
namespace app\job\jobs;
use app\common\MyLog;
use app\models\ApiStatistics;
use think\queue\Job;
class ApiStatisticsJob
{
public function fire(Job $job, $data)
{
try {
if (empty($data)){
$job->delete();
return false;
}
ApiStatistics::insertGetId($data);
$job->delete();
return true;
}catch (\Exception $e){
MyLog::errorLog('api_statistics_data', $data, 'api_statistics');
MyLog::errorLog('api_statistics', $e->getMessage() . $e->getFile() . $e->getLine(), 'api_statistics');
$job->delete();
}
return true;
}
public function fail()
{
}
}定义日志处理类，通过反射类以及thinkphp自带的方法获取接口相关信息，例如请求的模块、用户、接口地址、接口参数、请求时间、接口描述等等，并把这些信息推送到上面定义好的日志处理Job来保存日志
<?php
namespace app\behavior;
use app\common\MyLog;
use app\models\ClientElement;
use app\service\LoginSv;
use app\service\QueueService;
use think\facade\App;
use think\facade\Request;
class ApiRequestStatistics
{
const MODULE_MAP = [
'admin' => '总部管理端',
'agency' => '经销商管理端',
'api' => '客户端',
'saler' => 'CRM端',
'cooperation' => '开放接口'
];
public function run($response)
{
try {
$this->saveApiInfo($response);
$this->saveClientInfo();
$this->saveSearchInfo($response);
}catch (\Exception $e){
MyLog::infoLog('debug', $e->getFile() . $e->getLine() . $e->getMessage(), 'api_statistics_and_client_element_track_debug');
}
}
protected function saveApiInfo($response)
{
$action = Request::action(true);
$class = $this->parseClass();
$reflection = new \ReflectionClass($class);
$classInfo = $this->getClassInfo($reflection);
$methodInfo = $this->getMethodInfo($reflection, $action);
$start = App::getBeginTime();
$end = microtime(true);
$timeConsuming = bcsub($end, $start, 6);
$userInfo = $this->getUserInfo();
$module = Request::module();
$data = [
'user_id' => $userInfo['user_id'],
'user_name' => $userInfo['user_name'],
'user_agent' => Request::header('user-agent') ?: '',
'ip' => Request::ip() ?: '',
'module' => $module,
'module_name' => self::MODULE_MAP[$module] ?? '',
'class' => $classInfo['class'],
'class_name' => $classInfo['class_name'],
'method' => $methodInfo['method'],
'method_name' => $methodInfo['method_name'],
'url' => Request::path(),
'request_params' => json_encode(Request::param(), JSON_UNESCAPED_UNICODE|JSON_UNESCAPED_SLASHES),
'response_content' => json_encode($response, JSON_UNESCAPED_SLASHES|JSON_UNESCAPED_UNICODE),
'time_consuming' => bcmul($timeConsuming, 1000, 1),
'create_time' => time()
];
QueueService::push('api_statistics', $data);
}
protected function saveClientInfo()
{
$elementIds = Request::param('element_ids', '');
if (!$elementIds){
return true;
}
$elementIds = explode(',', $elementIds);
if (!is_array($elementIds) || empty($elementIds)){
return true;
}
$elements = ClientElement::where('element_id', 'in', $elementIds)->select()->toArray();
$userInfo = $this->getUserInfo();
foreach ($elements as $element) {
$data = [
'element_id' => $element['id'],
'element_type' => $element['element_type'],
'element_title' => $element['element_title'],
'user_id' => $userInfo['user_id'],
'user_name' => $userInfo['user_name'],
'user_agent' => Request::header('user-agent') ?: '',
'ip' => Request::ip() ?: '',
'create_time' => time()
];
QueueService::push('client_element_track', $data);
}
return true;
}
protected function parseClass()
{
$module = Request::module();
$controller = Request::controller();
$controllerData = explode('.', $controller);
$controllerDir = '';
if (count($controllerData) == 2){
$controllerDir = strtolower($controllerData[0]);
}
$className = end($controllerData);
$class = "app\\$module\\controller\\";
$controllerDir && $class .= "$controllerDir\\";
$class .= "$className";
return $class;
}
protected function getClassInfo(\ReflectionClass $reflectionClass)
{
$class = $reflectionClass->getName();
$doc = $reflectionClass->getDocComment();
$className = '';
if(preg_match("/\/\*\*\s+\*(.*?)\s+\*/", $doc, $match)) {
if(isset($match[1]) && $match[1]) {
$className = $match[1];
}
}
return [
'class' => trim($class),
'class_name' => trim($className)
];
}
/**
* 获取方法信息
* @param \ReflectionClass $reflectionClass
* @param $action
* @return array
* @throws \ReflectionException
*/
protected function getMethodInfo(\ReflectionClass $reflectionClass, $action)
{
$method = $reflectionClass->getMethod($action);
$name = $method->getName();
$document= $method->getDocComment();
preg_match("/\/\*\*\s+\*(.*?)\s+\*/", $document, $content);
return [
'method' => trim($name),
'method_name' => trim($content[1] ?? '')
];
}
protected function getUserInfo()
{
$userInfo = [
'user_id' => 0,
'user_name' => '未知'
];
$module = Request::module();
if (!isset(self::MODULE_MAP[$module])){
return $userInfo;
}
$authorization = Request()->header('Authorization');
if (!$authorization){
return $userInfo;
}
if ($module == 'admin'){ // 总部管理端
$token = $authorization;
}else{ // 经销商管理端、客户端、CRM端
preg_match('/^Bearer\s+(.*?)$/', $authorization, $matches);
$token = $matches[1] ?? '';
}
if (empty($token)){
return $userInfo;
}
$loginSv = $loginService = new LoginSv($token);
$user = $loginSv->getAllUsers();
if ($module == 'admin'){ // 总部管理端
$userInfo = [
'user_id' => $user['admin_id'] ?? 0,
'user_name' => $user['admin_name'] ?? '未知'
];
}else{ // 经销商管理端、客户端、CRM端
$userInfo = [
'user_id' => $user['staff_id'] ?? 0,
'user_name' => $user['staff_name'] ?? '未知'
];
}
return $userInfo;
}
protected function saveSearchInfo($response){
if(Request::path()!='api/v2/search_goods'){
return false;
}
$keywords=Request::param('keywords');
$list= $response['content']['lists']['data'] ?? [];
$content=[];
foreach ($list as $item){
$content[]=[
"goods_id"=> $item['goods_id']??'',
"goods_name"=> $item['goods_name']??'',
"goods_name_full"=> $item['goods_name_full']??'',
"goods_sn"=> $item['goods_sn']??'',
"goods_sn_full"=> $item['goods_sn_full']??'',
];
unset($item);
}
if(empty($keywords)){
return false;
}
$start = App::getBeginTime();
$end = microtime(true);
$timeConsuming = bcsub($end, $start, 6);
$userInfo = $this->getUserInfo();
$data = [
'user_id' => $userInfo['user_id'],
'user_name' => $userInfo['user_name'],
'user_agent' => Request::header('user-agent') ?: '',
'ip' => Request::ip() ?: '',
'url' => Request::path(),
'keyword' => trim($keywords),
'content' => json_encode($content, JSON_UNESCAPED_SLASHES|JSON_UNESCAPED_UNICODE),
'time_consuming' => bcmul($timeConsuming, 1000, 1),
'create_time' => time()
];
QueueService::push('save_search_history', $data);
}
}