xslate / p5-Mouse

Lightweight class builder for Perl, as a subset of Moose
https://metacpan.org/release/Mouse
Other
46 stars 32 forks source link

Memory leak in Mouse::Util::apply_all_role #17

Closed hirose31 closed 9 years ago

hirose31 commented 10 years ago

It looks like Mouse::Util::apply_all_role leaks memory. https://gist.github.com/hirose31/8703122#file-mouse-leak-pl

I found using Data::Validator with "my" declaration. https://gist.github.com/hirose31/8703122#file-dval-leak-pl

tokuhirom commented 10 years ago

ping

yappo commented 10 years ago

ping

tokuhirom commented 10 years ago

I guess applying roles for object takes memory forever. It's spec.

tokuhirom commented 10 years ago

No, gfx says Mouse removes all trash in DESTROY. It's not spec.

tokuhirom commented 10 years ago
use strict;
use warnings;

package Foo;
use Mouse::Role;

package main;

my $n = shift(@ARGV) || 200;

{
    my $o = bless {};

    memory_usage();

    for (1 .. $n) { Foo->meta->apply($o) }
    memory_usage();

    for (1 .. $n) { Foo->meta->apply($o) }
    memory_usage();

    undef $o;
}

memory_usage();

sub memory_usage { system("ps uw -p $$") }

__END__

USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
500       3461  5.0  0.3 129500  7432 pts/125  S+   15:51   0:00 perl -Mblib leak.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
500       3461 24.0  0.5 133468 11348 pts/125  S+   15:51   0:00 perl -Mblib leak.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
500       3461 38.5  1.0 142428 20328 pts/125  S+   15:51   0:00 perl -Mblib leak.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
500       3461 38.5  1.0 142428 20328 pts/125  S+   15:51   0:00 perl -Mblib leak.pl
gfx commented 10 years ago

I could have fixed this issue if there was a unit test (using Test::LeakTrace) :(

hirose31 commented 10 years ago

@gfx

use strict;
use warnings;

use Test::More;
use Test::LeakTrace;

{
    package FooRole;
    use Mouse::Role;
}

my $o = bless {};
no_leaks_ok {
    Mouse::Util::apply_all_roles($o, 'FooRole');
} 'apply_all_roles';

done_testing;

output is here (very long): https://gist.github.com/hirose31/9383427

syohex commented 10 years ago

@hirose31 Is your test code correct ?

Test::LeakTrace::no_leaks_ok evaluates code block 2 times and test whether there is memory usage difference between 1st time and 2nd time. So each block evaluation should behave the same way. But I suppose your test code does not behave such way, state of $o is different between 1st time and 2nd time(But this behavior may be wrong at first place)

See also http://d.hatena.ne.jp/hiratara/20120105/1325753543 (Japanese)

There is no memory leak with following code.

use strict;
use warnings;

use Test::More;
use Test::LeakTrace;

{
    package FooRole;
    use Mouse::Role;
}

no_leaks_ok {
    my $o = bless {}; # declare in code block
    Mouse::Util::apply_all_roles($o, 'FooRole');
} 'apply_all_roles';

done_testing;
syohex commented 10 years ago

What is expected behavior when applying same role several times ? Mouse behavior looks like Moose one.

use strict;
use warnings;

package Foo;
use Moose::Role;

package main;

my $n = shift(@ARGV) || 200;

{
    my $o = bless {};

    memory_usage();

    for (1 .. $n) { Foo->meta->apply($o) }
    memory_usage();

    for (1 .. $n) { Foo->meta->apply($o) }
    memory_usage();

    undef $o;
}

memory_usage();

sub memory_usage { system("ps uw -p $$") }

__END__
% perl moose.pl 2>/dev/null
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
syohei   25218  0.0  0.2  55476 17696 pts/0    S+   14:50   0:00 perl moose.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
syohei   25218  0.0  0.2  59952 21988 pts/0    S+   14:50   0:00 perl moose.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
syohei   25218  109  0.3  69096 31148 pts/0    S+   14:50   0:02 perl moose.pl
USER       PID %CPU %MEM    VSZ   RSS TTY      STAT START   TIME COMMAND
syohei   25218  109  0.3  69096 31320 pts/0    S+   14:50   0:02 perl moose.pl

Memory usage grows by each applying role.

tokuhirom commented 10 years ago

@gfx says, Mouse clean up anonymous class' @ISA, stash in the object's DESTROY phase. If there is memory growing, it's the bug.

hirose31 commented 10 years ago

I'm happy that Data::Validator with "my" declaration does not take more and more memory by call: https://gist.github.com/hirose31/8703122#file-dval-leak-pl

tokuhirom commented 10 years ago

Here is the best test case.

use strict;
use warnings;

use Test::More;
use Test::LeakTrace;

{
    package Role1;
    use Mouse::Role;
}

{
    package Role2;
    use Mouse::Role;
}

no_leaks_ok {
    foo();
} 'apply_all_roles';

done_testing;

sub foo {
    my $self = bless {}, 'Iyan';
    Mouse::Util::apply_all_roles($self, 'Role1', 'Role2');
}
syohex commented 10 years ago

@tokuhirom I got following error when executing your test script(missing Iyan package).

% perl -Mblib leak.pl
Could not load class (Iyan) because : Can't locate Iyan.pm in @INC (you may need to install the Iyan module) (@INC contains: /home/syohei/program/perl/Mouse/blib/arch /home/syohei/program/perl/Mouse/blib/lib /home/syohei/.plenv/versions/5.18.1/lib/perl5/site_perl/5.18.1/x86_64-linux-thread-multi /home/syohei/.plenv/versions/5.18.1/lib/perl5/site_perl/5.18.1 /home/syohei/.plenv/versions/5.18.1/lib/perl5/5.18.1/x86_64-linux-thread-multi /home/syohei/.plenv/versions/5.18.1/lib/perl5/5.18.1 .) at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Util.pm line 283.
 at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Util.pm line 292.
    Mouse::Util::load_class("Iyan") called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Meta/Class.pm line 58
    Mouse::Meta::Class::superclasses(Mouse::Meta::Class=HASH(0x1a97098), "Iyan") called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Meta/Module.pm line 234
    Mouse::Meta::Module::create("Mouse::Meta::Class", undef, "superclasses", ARRAY(0x1a97260), "roles", ARRAY(0x1a972a8), "cache", 1, "in_application_to_instance", ...) called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Meta/Class.pm line 39
    Mouse::Meta::Class::create_anon_class("Mouse::Meta::Class", "superclasses", ARRAY(0x1a97260), "roles", ARRAY(0x1a972a8), "cache", 1, "in_application_to_instance", 1, ...) called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Meta/Role/Application.pm line 56
    Mouse::Meta::Role::Application::apply(Mouse::Meta::Role::Application::RoleSummation=HASH(0x1a96ca8), Mouse::Meta::Role::Composite=HASH(0x1ca9ad8), Iyan=HASH(0x1a0e2d8)) called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Meta/Role/Composite.pm line 107
    Mouse::Meta::Role::Composite::apply(Mouse::Meta::Role::Composite=HASH(0x1ca9ad8), Iyan=HASH(0x1a0e2d8)) called at /home/syohei/program/perl/Mouse/blib/lib/Mouse/Util.pm line 333
    Mouse::Util::apply_all_roles(Iyan=HASH(0x1a0e2d8), "Role1", "Role2") called at leak.pl line 25
    main::foo() called at leak.pl line 18
    main::__ANON__() called at /home/syohei/.plenv/versions/5.18.1/lib/perl5/site_perl/5.18.1/x86_64-linux-thread-multi/Test/LeakTrace.pm line 90
    Test::LeakTrace::leaks_cmp_ok(CODE(0x1c7cb50), "<=", 0, "apply_all_roles") called at leak.pl line 19

@gfx @tokuhirom Which should destructor be called for clean up ? And How do I confirm whether clean up is done ?

tokuhirom commented 10 years ago

Oops. I forgot to add package Iyan.

use strict;
use warnings;

use Test::More;
use Test::LeakTrace;

{
    package Iyan;
    use Mouse;
}

{
    package Role1;
    use Mouse::Role;
}

{
    package Role2;
    use Mouse::Role;
}

no_leaks_ok {
    foo();
} 'apply_all_roles';

done_testing;

sub foo {
    my $self = bless {}, 'Iyan';
    Mouse::Util::apply_all_roles($self, 'Role1', 'Role2');
}

Testing result: https://gist.github.com/tokuhirom/834792bb3cc75417045b

@syohex Mouse should clean up the @ISA and stash in Mouse::Meta::Class::ANON::10's DESTROY(). @gfx says Mouse's anon class should not leak any memory.

syohex commented 10 years ago

@tokuhirom Is Mouse::Meta::Class::ANON::anon_serial_id destructor DESTROY in xs-src/Mouse.xs, right ?

tokuhirom commented 10 years ago

I don't know about details. Please ask @gfx.

syohex commented 10 years ago

Oh sorry. Ping @gfx

gfx commented 10 years ago

(will look into it later...)

tokuhirom commented 10 years ago

@gfx ping

hirose31 commented 10 years ago

@gfx ping

tokuhirom commented 10 years ago

@gfx ping

gfx commented 10 years ago

(will look into it later...)

tokuhirom commented 10 years ago

@gfx ping

gfx commented 10 years ago

pong! you should notify it at weekend ;)

tokuhirom commented 10 years ago

@gfx ping

gfx commented 10 years ago

It seems that composed roles are never destroyed when the host object is released. I guess there is a cyclic reference in somewhere.

gfx commented 10 years ago

@syohex There is Class::Meta::Module::DESTROY which cleans up both roles and classes.

syohex commented 10 years ago

Thanks for information.

syohex commented 10 years ago

There is no memory leak by applying following patch.

diff --git a/lib/Mouse/Meta/Role/Application.pm b/lib/Mouse/Meta/Role/Application.pm
index 1914fdc..7e82cf4 100644
--- a/lib/Mouse/Meta/Role/Application.pm
+++ b/lib/Mouse/Meta/Role/Application.pm
@@ -57,7 +57,7 @@ sub apply {
             ->create_anon_class(
                 superclasses => [ref $instance],
                 roles        => [$role],
-                cache        => 1,
+                cache        => 0,

                 in_application_to_instance => 1, # suppress to apply roles
             );

I suppose that caching may cause this issue. If cache option of Module::Meta::Class is true, some objects are cached in %Mouse::Meta::Module::METAS and %Mouse::Meta::Module::IMMORTALS.

Should we clean up those variables in destructor ?

gfx commented 10 years ago

Thanks to the investigation. I think metaclasses can be cached in a particular condition but it is just for performance, so disabled it.

gfx commented 10 years ago

@syohex @hirose31 Can you check tne new version 2.3.0? It includes cache bug fixes but might change the behavior.

hirose31 commented 10 years ago

It looks like dval-leak.pl (see top of this issue) does not leak memory. yay!!

But @tokuhirom 's applying roles code (https://github.com/gfx/p5-Mouse/issues/17#issuecomment-36715101) still growing. Is this assumed behavior?

syohex commented 10 years ago

@hirose31 I'll check that test and its behavior.