Memory leak?

[Htbaa]

Hi,

When using the SQLite backend I noticed that my long running worker processes steadily grew in size when it comes to memory usage. Maybe it's because of SQLite as I see it happen with the Storable backend as well, and they both store their data on disk. I tested it with the PostgreSQL backend as well and the memory usage doesn't increase after processing jobs.

I created a noop job:

$app->minion->add_task(foobar => sub {});

And then added a command to my app to test it:

package MyApp::Command::memtest;
use Mojo::Base 'Mojolicious::Command';
use FindBin;
use Scalar::Util qw(weaken);
use Memory::Usage;

has description => 'Memory test';
has usage       => "Usage: APPLICATION memtest\n";

sub run {
    my ($self) = @_;
    my $mu = Memory::Usage->new;
    $mu->record('before');
    do {
        for(1..1000) {
            $self->app->minion->enqueue('foobar');
        }
    };
    $self->app->minion->perform_jobs();
    $mu->record('after');
    $mu->dump();
}

1;

Which can be run as:

$ perl script/myapp memtest

Which gives me the following:

time    vsz (  diff)    rss (  diff) shared (  diff)   code (  diff)   data (  diff)
    0  190820 ( 190820)  88808 ( 88808)  10436 ( 10436)   1852 (  1852)  78372 ( 78372) before
    5  192572 (  1752)  91348 (  2540)  11044 (   608)   1852 (     0)  80092 (  1720) after

As you can see the data diff for after is high. When I run it with the PostgreSQL backend the data diff is 0 (although in some runs it's at around 130, but after the next run it's at 0 again):

time    vsz (  diff)    rss (  diff) shared (  diff)   code (  diff)   data (  diff)
    0  259180 ( 259180)  91468 ( 91468)  13296 ( 13296)   1852 (  1852)  77832 ( 77832) before
    14  259180 (     0)  91688 (   220)  13296 (     0)   1852 (     0)  77832 (     0) after

[polettix]

I made a similar test: created two processes running a Minion worker each, one using SQLite as backend and the other one using Pg. Had a third process monitoring /proc/<pid>/smaps for the two pids and let it run for about 15 hours. The two processes actually did nothing at all: no task was defined, nor they were "stimulated" in any way. Here's the code:

#!/usr/bin/env perl
use Mojolicious::Lite;
plugin Minion => {shift, $ENV{DB}};
@ARGV = qw< minion worker >;
app->start;

String Pg or SQLite is set on the command line for easy identification of the process after it's started. The more "complex" database URL is passed via environment variable DB instead.
Then, @ARGV is set to make app->start start the minion worker process.

The Pg backend didn't move after the startup.

The SQLite backend exposed this behaviour:

I also tracked the memory consumption of the SQLite.so XS library but that didn't move too, so I suspect it's something accumulating somewhere in the Perl code.

Raw data filtered from smaps can be found here.

[Htbaa]

I skimmed through the source code of Minion::Backend::SQLite and I didn't see anything that looked like a possible leak. So I looked a bit further and saw this modules uses Mojo::SQLite which is a layer on top of DBD::SQLite. The code of Mojo::SQLite has several circular references that with the use of Scalar::Util's weaken are getting dealt with. So maybe the leak is inside that module?

[Htbaa]

Well, I had some time to check this out and it seems the issue is with Mojo::SQLite. Since Minion workers need to check if there's work to be done database queries are executed every now and then it makes sense that even when no jobs are defined it's still checking for work.

use strict;
use Mojo::SQLite;
use Memory::Usage;
use v5.20;

my $mu = Memory::Usage->new;
my $sql = Mojo::SQLite->new('sqlite:/tmp/test.db');
$mu->record('before');
for(1..10000) {
    $sql->db->query('select sqlite_version() as version');
}
$mu->record('after');
$mu->dump();

Which results in:

time    vsz (  diff)    rss (  diff) shared (  diff)   code (  diff)   data (  diff)
    0  74392 ( 74392)  21920 ( 21920)   5064 (  5064)   1852 (  1852)  17240 ( 17240) before
    1  80004 (  5612)  28312 (  6392)   5696 (   632)   1852 (     0)  22820 (  5580) after

[Htbaa]

Actually, it already happens when calling $sql->db. I reported my findings in Grinnz/Mojo-SQLite#7

[Grinnz]

Closing this as the underlying issue should be resolved in Mojo::SQLite.

[Htbaa]

Maybe an update to the cpanfile to use Mojo::SQLite 1.002 could be done to prevent users from using the version with the memory leak?

[Grinnz]

Sure, I will bump the dependency