Featured image of post 使用 Swoole Tracker 排查 laravel-s 内存泄漏问题

使用 Swoole Tracker 排查 laravel-s 内存泄漏问题

使用了 laravel-s 之后,速度的确飞快, 但是随之而来的问题也多了

环境

  • 使用的是swoole:alpine的镜像构建环境
FROM phpswoole/swoole:php7.4-alpine

RUN sed -i 's/dl-cdn.alpinelinux.org/mirrors.aliyun.com/g' /etc/apk/repositories && cat /etc/apk/repositories

# 快速安装 PHP 扩展 install-php-extensions xxx
COPY --from=mlocati/php-extension-installer /usr/bin/install-php-extensions /usr/local/bin/
RUN install-php-extensions pcntl redis pdo_mysql

WORKDIR /var/www
COPY . .
RUN chmod -R 0777 storage && \
    chmod -R 0777 bootstrap/cache && \
    composer config -g repo.packagist composer https://mirrors.aliyun.com/composer/ && \
    composer install --optimize-autoloader --no-dev && \
    php artisan config:cache && \
    php artisan route:cache && \
    php artisan view:cache && \
    php artisan laravels publish --no-interaction

CMD ["php", "bin/laravels", "start", "--env=product"]
  • 安装laravels的时候可以先注释Dockerfile最后两行,先让环境启动起来
## 把 [/mnt/d/xxxx] 替换成宿主机的代码目录
docker build . -t test-image
docker run -d -it -p 80:5200 -v [/mnt/d/xxxx]:/var/dev  --name=test-service -w /var/dev test-image /bin/sh
docker exec -it memory-service /bin/sh

错误

  • 线上的机器一直报错日志
[2022-01-01 02:29:45 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1641, id=5) abnormal exit, status=255, signal=0
[2022-01-01 02:30:24 *1642.0]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 65536 bytes) in /var/www/vendor/monolog/monolog/src/Monolog/DateTimeImmutable.php on line 22
[2022-01-01 02:30:24 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1642, id=0) abnormal exit, status=255, signal=0
[2022-01-01 02:31:07 *1646.2]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /var/www/vendor/nunomaduro/collision/src/Highlighter.php on line 138
[2022-01-01 02:31:07 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1646, id=2) abnormal exit, status=255, signal=0
[2022-01-01 02:31:14 *1647.3]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /var/www/vendor/nunomaduro/collision/src/Adapters/Laravel/Inspector.php on line 30
[2022-01-01 02:31:14 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1647, id=3) abnormal exit, status=255, signal=0
[2022-01-01 02:32:11 *1644.1]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 32768 bytes) in /var/www/vendor/nunomaduro/collision/src/Writer.php on line 1
[2022-01-01 02:32:11 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1644, id=1) abnormal exit, status=255, signal=0
[2022-01-01 02:32:22 *1645.6]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 65536 bytes) in /var/www/vendor/nunomaduro/collision/src/Writer.php on line 135
[2022-01-01 02:32:22 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1645, id=6) abnormal exit, status=255, signal=0
[2022-01-01 02:33:44 *1653.3]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 32768 bytes) in /var/www/vendor/nunomaduro/collision/src/Writer.php on line 1
[2022-01-01 02:33:44 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1653, id=3) abnormal exit, status=255, signal=0
[2022-01-01 02:33:55 *1650.5]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /var/www/vendor/monolog/monolog/src/Monolog/Utils.php on line 141
[2022-01-01 02:33:55 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1650, id=5) abnormal exit, status=255, signal=0
[2022-01-01 02:34:22 *1652.2]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 32768 bytes) in /var/www/vendor/filp/whoops/src/Whoops/Run.php on line 1
[2022-01-01 02:34:22 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1652, id=2) abnormal exit, status=255, signal=0
[2022-01-01 02:34:24 *1649.4]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 32768 bytes) in /var/www/vendor/nunomaduro/collision/src/Writer.php on line 1
[2022-01-01 02:34:24 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1649, id=4) abnormal exit, status=255, signal=0
[2022-01-01 02:34:38 *1651.0]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 20480 bytes) in /var/www/vendor/nunomaduro/collision/src/Writer.php on line 193
[2022-01-01 02:34:38 $19.0]	WARNING	Server::check_worker_exit_status(): worker(pid=1651, id=0) abnormal exit, status=255, signal=0
[2022-01-01 02:36:13 *1656.3]	ERROR	php_swoole_server_rshutdown() (ERRNO 503): Fatal error: Allowed memory size of 134217728 bytes exhausted (tried to allocate 32768 bytes) in /var/www/vendor/nunomaduro/collision/src/Adapters/Laravel/IgnitionSolutionsRepository.php on line 1

官方文档的说明

关于内存泄露

  • 避免使用全局变量,如一定要,请手动清理或重置。
  • 无限追加元素到全局变量、静态变量、单例,将导致内存溢出。
class Test
{
    public static $array = [];
    public static $string = '';
}
// 某控制器
public function test(Request $req)
{
    // 内存溢出
    Test::$array[] = $req->input('param1');
    Test::$string .= $req->input('param2');
}
  • 内存泄露的检测方法

    1. 修改config/laravels.phpworker_num=1, max_request=1000000,测试完成后记得改回去;
    2. 增加路由/debug-memory-leak,不设置任何路由中间件,用于观察Worker进程的内存变化情况;
    Route::get('/debug-memory-leak', function () {
        global $previous;
        $current = memory_get_usage();
        $stats = [
            'prev_mem' => $previous,
            'curr_mem' => $current,
            'diff_mem' => $current - $previous,
        ];
        $previous = $current;
        return $stats;
    });
    
    1. 启动LaravelS,请求/debug-memory-leak,直到diff_mem小于或等于零;如果diff_mem一直大于零,说明全局中间件Laravel框架可能存在内存泄露;
    2. 完成步骤3后,交替请求业务路由与/debug-memory-leak(建议使用ab/wrk对业务路由进行大量的请求),刚开始出现的内存增涨是正常现象。业务路由经过大量请求后,如果diff_mem一直大于零,并且curr_mem持续增大,则大概率存在内存泄露;如果curr_mem始终在一定范围内变化,没有持续变大,则大概率不存在内存泄露。
    3. 如果始终没法解决,max_request是最后兜底的方案。

按照文档修改好配置并添加路由之后, 进入容器操作

docker exec -it memory-service /bin/sh
watch -n 1 127.0.0.1:5200/debug-memory-leak
Every 1.0s: curl 127.0.0.1:5200/debug-memory-leak                                                                                                                                                                   2022-01-05 03:48:15

{"prev_mem":22620816,"curr_mem":22626592,"diff_mem":5776}
  • 经过一段时间的运行,发现diff_mem一直都大于零, 经过一段时间的排查发现问题在于laravels.register_providers的配置
  • 因为使用dcat-admin适配laravel-s需要在register_providers增加\Dcat\Admin\AdminServiceProvider::class
  • 如果不注册这个会导致后台访问不正常. 所以只能另寻方法

使用Swoole Tracker3.1排查问题

  • 首先Swoole Tracker分商业版和免费版(折腾人了好久), 我们使用免费版即可
  • 安装教程https://wenda.swoole.com/detail/107688
  • 如果和我一样使用容器构建的, 直接下载so文件放入容器中,然后修改php.ini开启扩展, 之后php -m看到swoole-tracker就代表安装成功了
  • 然后按着官方使用, 先增加trackerHookMalloc函数, 然后打开另一个命令行执行php -r "trackerAnalyzeLeak();"即可.
[29260 (Loop 4252)] /var/dev/vendor/facade/ignition/src/QueryRecorder/QueryRecorder.php:44 => [-192]
               Free Pre (Loop 4052) : /var/dev/vendor/laravel/framework/src/Illuminate/Database/Query/Grammars/Grammar.php:1264 => [64]
               Free Pre (Loop 4052) : /var/dev/vendor/facade/ignition/src/QueryRecorder/Query.php:26 => [128]
[29260 (Loop 4252)] /var/dev/vendor/laravel/framework/src/Illuminate/Foundation/Application.php:745 => [160]
[29260 (Loop 4252)] /var/dev/vendor/dcat/laravel-admin/src/Extend/Manager.php:503 => [256]
[29260 (Loop 4252)] /var/dev/vendor/dcat/laravel-admin/src/Extend/ServiceProvider.php:143 => [48]
[29260 (Loop 4252)] /var/dev/vendor/laravel/framework/src/Illuminate/Support/ServiceProvider.php:403 => [1392]
[29260 (Loop 4252)] /var/dev/vendor/laravel/framework/src/Illuminate/Support/ServiceProvider.php:165 => [696]
[29260 (Loop 4252)] /var/dev/vendor/laravel/framework/src/Illuminate/Routing/RouteFileRegistrar.php:35 => [3280]
[29260 (Loop 4252)] /var/dev/vendor/laravel/framework/src/Illuminate/Database/Query/Grammars/Grammar.php:1264 => [64]
[29260 (Loop 4252)] /var/dev/vendor/facade/ignition/src/QueryRecorder/Query.php:26 => [128]
[29260 (Loop 4252)] ❌  This Loop TotalLeak: [5832]
  • 对着上面的日志, 一个一个文件排查哪里会出现泄漏. 这里举例看一下/var/dev/vendor/laravel/framework/src/Illuminate/Support/ServiceProvider.php:403
cat /var/dev/vendor/laravel/framework/src/Illuminate/Support/ServiceProvider.php | tail -n +400 | head -n 5
### output
public function commands($commands)
{
    $commands = is_array($commands) ? $commands : func_get_args();

    Artisan::starting(function ($artisan) use ($commands) {
        $artisan->resolveCommands($commands);
    });
}

## 然后查看 starting 方法
public static function starting(Closure $callback)
{
    static::$bootstrappers[] = $callback;
}
  • 经过代码查看,基本就可以确定这个地方内存泄漏是重复注册命令了,不断的往static::$bootstrappers追加元素
  • 由于我们在laravels.register_providers添加\Dcat\Admin\AdminServiceProvider::class, 这样之后每次请求来都会执行这个服务提供者的registerboot方法
  • 我们看一下AdminServiceProvider::register方法
public function register()
{
    $this->aliasAdmin();
    $this->loadAdminAuthConfig();
    $this->registerRouteMiddleware();
    $this->registerServices();
    $this->registerExtensions();

    $this->commands($this->commands);

    if (config('app.debug')) {
        $this->commands($this->devCommands);
    }
}
  • 这里调用了commands方法,导致每次请求来都会往数组里添加元素,导致内存泄漏