Bug #125414 for POE: POE Stacktrace

Mon May 28 06:37:56 2018 markus.schraeder [...] cryptomagic.eu - Ticket created

Subject:	POE Stacktrace
Date:	Mon, 28 May 2018 12:26:41 +0200
To:	bug-poe [...] rt.cpan.org
From:	Markus Schräder <markus.schraeder [...] cryptomagic.eu>

please report this stacktrace to bug-poe@rt.cpan.org at /usr/share/perl5/POE/Kernel.pm line 1070. POE::Kernel::_dispatch_event(POE::Kernel=ARRAY(0x55688a50a180), undef, POE::Kernel=ARRAY(0x55688a50a180), "_stop", 8, ARRAY(0x55688b9baba8), "/usr/share/perl5/POE/Resource/Sessions.pm", 572, ...) called at /usr/share/perl5/POE/Resource/Sessions.pm line 569 POE::Kernel::_data_ses_stop(POE::Kernel=ARRAY(0x55688a50a180), 6) called at /usr/share/perl5/POE/Resource/Signals.pm line 551 POE::Kernel::_data_sig_free_terminated_sessions(POE::Kernel=ARRAY(0x55688a50a180)) called at /usr/share/perl5/POE/Kernel.pm line 990 POE::Kernel::_dispatch_signal_event(POE::Kernel=ARRAY(0x55688a50a180), POE::Session=ARRAY(0x55688b9ba5a8), POE::Kernel=ARRAY(0x55688a50a180), "_signal", 4096, ARRAY(0x55688ba7ea88), "/usr/share/perl5/POE/Kernel.pm", 1136, ...) called at /usr/share/perl5/POE/Resource/Events.pm line 381 POE::Kernel::_data_ev_dispatch_due(POE::Kernel=ARRAY(0x55688a50a180)) called at /usr/share/perl5/POE/Loop/Select.pm line 309 POE::Kernel::loop_do_timeslice(POE::Kernel=ARRAY(0x55688a50a180)) called at /usr/share/perl5/POE/Loop/Select.pm line 317 POE::Kernel::loop_run(POE::Kernel=ARRAY(0x55688a50a180)) called at /usr/share/perl5/POE/Kernel.pm line 1291 POE::Kernel::run(POE::Kernel=ARRAY(0x55688a50a180)) called at loader.pl line 25 The problem only occures if I use the following function: sub poe_sleep { my $seconds = shift; POE::Session->create( inline_states => { _start => sub { $poe_kernel->delay("done" => $seconds); }, done => sub { undef $seconds; }, }, ); while (defined($seconds)) { $poe_kernel->run_one_timeslice; }; } -- Markus Schräder Geschäftsführer CryptoMagic GmbH, Werner-von-Siemens Str. 6, 86159 Augsburg, https://www.cryptomagic.eu Tel: 0821 / 217 009-0 (Durchwahl: -11), Fax: 0821/217 009-99 Geschäftsführer: Markus Schräder Sitz der Gesellschaft: Augsburg; Registergericht: Amtsgericht Augsburg; Registernummer: HRB30402 USt-ID: DE305330428, St-Nr: 103/123/80744

Mon May 28 08:25:40 2018 PRIVI [...] cpan.org - Correspondence added

I reduced to problem to the following: ------------- use POE; sub run { my $config = shift; my $done = 0; POE::Session->create( inline_states => { _start => sub { print "START\n"; }, _stop => sub { print "STOP\n"; $done++; }, }, ); while (!$done) { $poe_kernel->run_one_timeslice; }; } POE::Session->create( inline_states => { _start => sub { run(); run(); }, } ); $poe_kernel->run(); ------------ root@wawicwdev:/opt/server# perl demo.pl START STOP please report this stacktrace to bug-poe@rt.cpan.org at /usr/share/perl5/POE/Kernel.pm line 1070. POE::Kernel::_dispatch_event(POE::Kernel=ARRAY(0x5561f159a540), undef, POE::Kernel=ARRAY(0x5561f159a540), "_child", 128, ARRAY(0x5561f1853380), "/usr/share/perl5/POE/Kernel.pm", 1514, ...) called at /usr/share/perl5/POE/Kernel.pm line 1512 POE::Kernel::session_alloc(POE::Kernel=ARRAY(0x5561f159a540), POE::Session=ARRAY(0x5561f1133440)) called at /usr/share/perl5/POE/Session.pm line 192 POE::Session::try_alloc(POE::Session=ARRAY(0x5561f1133440)) called at /usr/share/perl5/POE/Session.pm line 373 POE::Session::create("POE::Session", "inline_states", HASH(0x5561f1117170)) called at demo.pl line 29 === 7049 === Sessions were started, but POE::Kernel's run() method was never === 7049 === called to execute them. This usually happens because an error === 7049 === occurred before POE::Kernel->run() could be called. Please fix === 7049 === any errors above this notice, and be sure that POE::Kernel->run() === 7049 === is called. See documentation for POE::Kernel's run() method for === 7049 === another way to disable this warning. root@wawicwdev:/opt/server#

Mon May 28 08:25:46 2018 The RT System itself - Status changed from 'new' to 'open'

Mon May 28 08:42:09 2018 PRIVI [...] cpan.org - Correspondence added

... Amazingly this works... The "$done++" has just been moved from _stop to _start. use POE; sub run { my $config = shift; my $done = 0; POE::Session->create( inline_states => { _start => sub { print "START\n"; $done++; }, _stop => sub { print "STOP\n"; }, }, ); while (!$done) { $poe_kernel->run_one_timeslice; }; } POE::Session->create( inline_states => { _start => sub { run(); run(); }, } ); $poe_kernel->run();

Mon May 28 09:25:50 2018 PRIVI [...] cpan.org - Correspondence added

It seems that the problem is that POE sees a session is dead and has to be removed, if you - call loop_do_timeslice within a handler - the session would be dead without a running handler . This normaly donnot happen, cause withing the handler POE normaly donnot kill a session - only if you call loop_do_timeslice manually inside of a handler. If you add a delay, then it has outstanding events, so it will not look dead so it donnot want to kill it. Workaround via delay; if you comment in the two delay lines the problem goes away. Without the problem appears. ---------- use POE; POE::Session->create( # Session 1 inline_states => { _start => sub { my $done = 0; POE::Session->create( inline_states => { _start => sub { }, _stop => sub { $done++; }, }, ); #$poe_kernel->delay("blub" => 99999999999999999); while (!$done) { $poe_kernel->loop_do_timeslice; # ^ Wipes Session 1 }; #$poe_kernel->delay("blub" => undef); # Crash, cause creating a session in the context of a dead on is not possible! POE::Session->create( inline_states => { _start => sub { }, _stop => sub { $done++; }, }, ); }, } ); $poe_kernel->run();

Mon May 28 18:47:43 2018 RCAPUTO [...] cpan.org - Correspondence added

On Mon May 28 09:25:50 2018, PRIVI wrote: Show quoted text

> > If you add a delay, then it has outstanding events, so it will not > look dead so it donnot want to kill it.

Thanks for the test case. It's really good. I've modified it so it's clearer what's going on: #!perl use warnings; use strict; use POE; sub run { my $done = 0; POE::Session->create( inline_states => { _start => sub { print "INNER STARTED\n"; }, _stop => sub { print "INNER STOPPED\n"; $done++; }, }, ); while (!$done) { $poe_kernel->run_one_timeslice; }; } POE::Session->create( inline_states => { _start => sub { print "outer starting...\n"; run(); run(); print "outer started...\n"; }, _stop => sub { print "outer stopped\n"; }, } ); POE::Kernel->run(); __END__ And the output looks like this: outer starting... INNER STARTED INNER STOPPED outer stopped please report this stacktrace to bug-poe@rt.cpan.org at /Users/troc/projects/poe/poe/lib/POE/Kernel.pm line 1070. [etc.] As you've noticed, the problem is the run_one_timeslice() loop inside your sub run(). It allows the "outer" session to become inactive before _start is done. I'm not yet sure how (or if) that can be resolved inside POE::Kernel. Another work around is to call run() from the "outer" session's _child handler. _child is called synchronously as part of the "inner" session _stop, so the timing is right. An example: #!perl use warnings; use strict; use POE; sub run { my $done = 0; POE::Session->create( inline_states => { _start => sub { print "INNER STARTED\n"; }, _stop => sub { print "INNER STOPPED\n"; $done++; }, }, ); while (!$done) { $poe_kernel->run_one_timeslice; }; } POE::Session->create( inline_states => { _start => sub { print "outer starting...\n"; $_[HEAP]{runs_left} = 2; # Simulate a child session stopping. POE::Kernel->yield('_child', 'lose'); print "outer started...\n"; }, _child => sub { # Only start another when the last is done. return if $_[ARG0] ne 'lose'; return if $_[HEAP]{runs_left}-- <= 0; run(); }, _stop => sub { print "outer stopped\n"; }, } ); POE::Kernel->run(); __END__ And the output: % perl bug-125414.pl outer starting... outer started... INNER STARTED INNER STOPPED INNER STARTED INNER STOPPED outer stopped