Using Swoole Tracker to troubleshoot memory leak issues in laravel-s

Environment#

The environment is built using the swoole:alpine image.

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

# Quickly install PHP extensions 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"]

When installing laravels, you can comment out the last two lines of the Dockerfile to start the environment first.

## Replace [/mnt/d/xxxx] with the code directory on the host machine
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

Errors#

The online machine keeps reporting error logs.

[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

Official Documentation Explanation#

Set Cleaners.
Common Issues: A comprehensive list of known issues and solutions.

About Memory Leaks#

Avoid using global variables; if necessary, manually clean or reset them.
Continuously appending elements to global variables, static variables, or singletons will lead to memory overflow.

class Test
{
    public static $array = [];
    public static $string = '';
}
// Some controller
public function test(Request $req)
{
    // Memory overflow
    Test::$array[] = $req->input('param1');
    Test::$string .= $req->input('param2');
}

Memory leak detection methods:
1. Modify config/laravels.php: worker_num=1, max_request=1000000, remember to change it back after testing;
2. Add route /debug-memory-leak, without setting any route middleware, to observe memory changes in Worker processes;
```
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. Start LaravelS, request /debug-memory-leak, until diff_mem is less than or equal to zero; if diff_mem remains greater than zero, it indicates that there may be a memory leak in the global middleware or Laravel framework;
2. After completing step 3, alternately request business routes and /debug-memory-leak (it is recommended to use ab/wrk to make a large number of requests to the business routes), the initial increase in memory is normal. After a large number of requests to the business routes, if diff_mem remains greater than zero and curr_mem continues to increase, there is a high probability of a memory leak; if curr_mem remains within a certain range without continuous increase, there is a high probability of no memory leak.
3. If the issue cannot be resolved, max_request is the last resort.

After modifying the configuration according to the documentation and adding the route, enter the container to operate.#

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}

After running for a while, it was found that diff_mem was always greater than zero. After some investigation, it was discovered that the issue was in the configuration of laravels.register_providers.
Because using dcat-admin with laravel-s requires adding \Dcat\Admin\AdminServiceProvider::class to register_providers.
If this is not registered, it will cause abnormal access to the backend. Therefore, alternative methods must be sought.

Using `Swoole Tracker 3.1` to Diagnose Issues#

First, Swoole Tracker has a commercial version and a free version (which took me a long time to figure out), we can use the free version.
Installation tutorial https://wenda.swoole.com/detail/107688.
If you are using a container build like me, directly download the so file and place it in the container, then modify php.ini to enable the extension. After that, if you see swoole-tracker when running php -m, it means the installation was successful.
Then follow the official usage, first add the trackerHookMalloc function, then open another command line and execute 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]

Based on the above logs, check each file to see where the leak occurs. Here is an example of checking /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);
    });
}

## Then check the starting method
public static function starting(Closure $callback)
{
    static::$bootstrappers[] = $callback;
}

After reviewing the code, it can be basically determined that the memory leak in this place is due to the repeated registration of commands, continuously appending elements to static::$bootstrappers.
Since we added \Dcat\Admin\AdminServiceProvider::class in laravels.register_providers, this means that the register and boot methods of this service provider will be executed on every request.
Let's take a look at the AdminServiceProvider::register method.

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);
    }
}

Here, the commands method is called, causing elements to be added to the array on every request, leading to a memory leak.

Using Swoole Tracker to troubleshoot memory leak issues in laravel-s

Environment#

Errors#

Official Documentation Explanation#

About Memory Leaks#

After modifying the configuration according to the documentation and adding the route, enter the container to operate.#

Using Swoole Tracker 3.1 to Diagnose Issues#

Using `Swoole Tracker 3.1` to Diagnose Issues#