Can not stop application gracefully; timers are lost.

[EugenKon]

Description

I tried to stop application server gracefully from callback function for non-blocking request.

... sub{
	Mojo::IOLoop->stop_gracefully;
	$server->stop;
	undef $server; # Must destroy server otherwise it does not stop.
}

But sometimes it works OK and sometimes fails because of error:

Mojo::Reactor::Poll: I/O watcher failed: Can't call method "_finish" on an undefined value at ../local-lib/lib/perl5/Mojo/Server/Daemon.pm line 247.

Mojo::Reactor::Poll
sub _write {
  my ($self, $id) = @_;
  ...
  $self->ioloop->stream($id)->write($chunk => sub { $self->$next($id) }); # <<< line 247
}

In the case when it fails finish event for transaction is not called.

For both cases scheduled timers are not run.

The example with a timer

use Mojo::Server::Daemon;
use Mojolicious::Lite;
use Mojo::UserAgent;
use Mojo::IOLoop;


hook after_build_tx => sub{
	my( $tx, $app ) =  @_;
	print "New transaction >>$tx<<\n";
	$tx->on( finish => sub{
		my( $tx ) =  @_;
		print "Finished transaction >>$tx<<\n";
	});
};

get '/test' => sub{
	Mojo::IOLoop->timer( 2 => sub {
		print "Timer\n";
	});

	shift->render( text => 'Ok' )
};



my $server =  Mojo::Server::Daemon->new( app => app(),  listen => ['http://*:7543']);
$server->start;

my $ua =  Mojo::UserAgent->new( server => undef );
print "Issue request:\n";
$ua->get( 'http://127.0.0.1:7543/test', sub{
	Mojo::IOLoop->stop_gracefully;
	$server->stop;
	undef $server;
});

Mojo::IOLoop->start   unless Mojo::IOLoop->is_running;

How to reproduce

use Mojolicious::Lite;
use Mojo::Server::Daemon;
use Mojo::UserAgent;

hook after_build_tx => sub{
	my( $tx, $app ) =  @_;
	print "New transaction >>$tx<<\n";
	$tx->on( finish => sub{
		my( $tx ) =  @_;
		print "Finished transaction >>$tx<<\n";
	});
};

get '/test' => sub{ shift->render( text => 'Ok' ) };

my $server =  Mojo::Server::Daemon->new( app => app(),  listen => ['http://*:7543']);
$server->start;

my $ua =  Mojo::UserAgent->new( server => undef );
print "Issue request:\n";
$ua->get( 'http://127.0.0.1:7543/test', sub{
	Mojo::IOLoop->stop_gracefully;
	$server->stop;
	undef $server;
});

Mojo::IOLoop->start   unless Mojo::IOLoop->is_running;

$ perl -I ../local-lib/lib/perl5/ t/gracefull.t 
[2025-10-13 17:32:47.05852] [128220] [info] Listening at "http://*:7543"
Web application available at http://127.0.0.1:7543
New transaction >>Mojo::Transaction::HTTP=HASH(0x614dd2368838)<<
[2025-10-13 17:32:47.06055] [128220] [trace] [0crZtoV1yxCB] GET "/test"
[2025-10-13 17:32:47.06080] [128220] [trace] [0crZtoV1yxCB] Routing to a callback
[2025-10-13 17:32:47.06100] [128220] [trace] [0crZtoV1yxCB] 200 OK (0.000441s, 2267.574/s)
Finished transaction >>Mojo::Transaction::HTTP=HASH(0x614dd2368838)<<

$ perl -I ../local-lib/lib/perl5/ t/gracefull.t 
[2025-10-13 17:32:53.69074] [128257] [info] Listening at "http://*:7543"
Web application available at http://127.0.0.1:7543
New transaction >>Mojo::Transaction::HTTP=HASH(0x596c2acbc778)<<
[2025-10-13 17:32:53.69256] [128257] [trace] [HYS2zjcvO9XO] GET "/test"
[2025-10-13 17:32:53.69274] [128257] [trace] [HYS2zjcvO9XO] Routing to a callback
[2025-10-13 17:32:53.69286] [128257] [trace] [HYS2zjcvO9XO] 200 OK (0.00029s, 3448.276/s)
Mojo::Reactor::Poll: I/O watcher failed: Can't call method "_finish" on an undefined value at ../local-lib/lib/perl5/Mojo/Server/Daemon.pm line 247.

Investigations

High level overview of flow is as next:
UA do a request, server do a response, callback is called, IOLoop is stopped, server is destroyed.

During this process Mojolicious leverages 3 file handles:
5 This is a listening socket.
11 is created for UA.
12 is created for server.

And then every next tick these filehandles are checked in random order:

mojo/lib/Mojo/Reactor/Poll.pm

Lines 50 to 56 in 834a1f3

	# I/O
	if (keys %{$self->{io}}) {
	my @poll = map { $_ => $self->{io}{$_}{mode} } keys %{$self->{io}};
	# This may break in the future, but is worth it for performance
	if (IO::Poll::_poll($timeout, @poll) > 0) {
	while (my ($fd, $mode) = splice @poll, 0, 2) {

It is random because of nature of hashes in perl keys %{$self->{io} returns keys in unpredictable order.
io has these filehandles:

        io => {
          11 => {
            cb => &Mojo::IOLoop::Stream::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Stream.pm:63],
            mode => 3,
          },
          12 => {
            cb => &Mojo::IOLoop::Stream::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Stream.pm:63],
            mode => 3,
          },
          5 => {
            cb => &Mojo::IOLoop::Server::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Server.pm:90],
            mode => 3,
          },
        },

Most of the time it does not matter in which order they are processed. But it does after server do a response.
Thus we have two scenarios for code flows after that point.

Scenario 1: No error happened

server do a response and puts the next event _finish (line 247)

mojo/lib/Mojo/Server/Daemon.pm

Lines 244 to 247 in 834a1f3

	my $next = $tx->is_finished ? '_finish' : length $chunk ? '_write' : undef;
	return $self->ioloop->stream($id)->write($chunk) unless $next;
	weaken $self;
	$self->ioloop->stream($id)->write($chunk => sub { $self->$next($id) });

FH 12 handle selected. run _finish for it:

mojo/lib/Mojo/IOLoop/Stream.pm

Line 131 in 834a1f3

undef $self->{buffer}, $self->emit('drain') unless length $self->{buffer};

transaction is closed.

FH 11 handle selected. run read for it and resolve.

callback for $ua->get is called.

IOLoop is stopped gracefully.
server is stopped.
undef $server called.
server destroyed.

Scenario 2: Error happened when FH 11 is processed before FH 12.

server do a response and puts the next event _finish

But FH 11 handle selected. run read for it and resolve.

callback for $ua->get is called.

IOLoop is stopped gracefully.
server is stopped.
undef $server called.
server destroyed. <<<

FH 12 handle selected. try to run _finish for it and FAIL, because $self does not exists already. The server was destroyed a few moments ago.

mojo/lib/Mojo/Server/Daemon.pm

Line 247 in 834a1f3

$self->ioloop->stream($id)->write($chunk => sub { $self->$next($id) });

exception Can't call method "_finish" on an undefined value happened and for transaction finish event is not fired.

Thoughts

1. Easy work around is:

   -$self->ioloop->stream($id)->write($chunk => sub { $self->$next($id) }); 
   +$self->ioloop->stream($id)->write($chunk => sub { $self and $self->$next($id) }); 

   but this does not resolve the problem that finish event is not called for the transaction.

2. Is this Ok, that framework allows application destruction when it has streams which events file handles still are pointed from Mojo::IOLoop?
   Look at this call stack when undef $server happened:
   a. line 26

   mojo/lib/Mojo/Server/Daemon.pm

   Lines 22 to 27 in 834a1f3

   	sub DESTROY {
   	my $self = shift;
   	return if ${^GLOBAL_PHASE} eq 'DESTRUCT';
   	my $loop = $self->ioloop;
   	$loop->remove($_) for keys %{$self->{connections} // {}}, @{$self->acceptors};
   	}

   
   b. line 86

   mojo/lib/Mojo/IOLoop.pm

   Lines 83 to 88 in 834a1f3

   	sub remove {
   	my ($self, $id) = (_instance(shift), @_);
   	my $c = $self->{in}{$id} || $self->{out}{$id};
   	if ($c && (my $stream = $c->{stream})) { return $stream->close_gracefully }
   	$self->_remove($id);
   	}

   pay attention to stream->events->drain:

   $c
   {
     stream => Mojo::IOLoop::Stream {
       buffer => ,
       events => {
         close => [
           &Mojo::IOLoop::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop.pm:234],
           &Mojo::Server::Daemon::__ANON__[lib-nodebug/lib/perl5/Mojo/Server/Daemon.pm:205],
         ],
         drain => [
           &Mojo::EventEmitter::__ANON__[lib-nodebug/lib/perl5/Mojo/EventEmitter.pm:36],
         ],
         error => [
           &Mojo::Server::Daemon::__ANON__[lib-nodebug/lib/perl5/Mojo/Server/Daemon.pm:206],
         ],
         read => [
           &Mojo::Server::Daemon::__ANON__[lib-nodebug/lib/perl5/Mojo/Server/Daemon.pm:207],
         ],
         timeout => [
           &Mojo::Server::Daemon::__ANON__[lib-nodebug/lib/perl5/Mojo/Server/Daemon.pm:208],
         ],
       },
       handle => IO::Socket::IP GLOB,
       reactor => Mojo::Reactor::Poll {
         events => {
           error => [
             &Mojo::IOLoop::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop.pm:29],
           ],
         },
         io => {
           11 => {
             cb => &Mojo::IOLoop::Stream::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Stream.pm:63],
             mode => 3,
           },
           12 => {
             cb => &Mojo::IOLoop::Stream::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Stream.pm:63],
             mode => 7,
           },
         },
         next_tick => [],
         running => 1,
         timers => {
           e90331dbbf9ff2c8d5155034be091f0d => {
             after => 2,
             cb => &Mojo::IOLoop::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop.pm:243],
             recurring => 0,
             time => 36935.478503053,
           },
         },
       },
       read => 109,
       timeout => 0,
       written => 144,
     },
   }

   c. line 30 https://github.com/mojolicious/mojo/blob/834a1f3e58ec72726e9b81f45f8e95f34484085d/lib/Mojo/IOLoop/Stream.pm#L30

   Here stream is writing, because it has subscribers to drain though buffer is empty (server wrote everything and client read). But flow came from Mojo::Server::Daemon::DESTROY sub. We should not try to close stream gracefully because whole application is in process of destruction. And we can not just call ->close here, because this stream is the last in connection. Thus Mojo::IOLoop will be stopped and drain will be never called.
   

   mojo/lib/Mojo/IOLoop.pm

   Line 211 in 834a1f3

   $stream->on(close => sub { $self && $self->_remove($id) });

   
   https://github.com/mojolicious/mojo/blob/834a1f3e58ec72726e9b81f45f8e95f34484085d/lib/Mojo/IOLoop.pm#L197-199

3. If transaction was completed and buffer is empty why drain call is scheduled for later and not called immediately?

4. If application was destroyed its FH should not sit still inside Mojo::Reactor::Poll->{io}. (this happens because Mojo::IOLoop is in graceful stop in progress). Probably we could leave it there, but this FH (12 in my case) should be closed during application destruction.

5. If application is being destroyed probably this is not good idea to wait all its timers to finish (which could be a while), but if Mojo::IOLoop is in graceful stop mode, then it worth. To wait all timers to finish this condition should be improved:
   

   mojo/lib/Mojo/IOLoop.pm

   Lines 197 to 199 in 834a1f3

   	# Connection
   	return undef unless delete $self->{in}{$id} || delete $self->{out}{$id};
   	return $self->stop if $self->{stop} && !$self->_in;

   
   if Mojo::IOLoop still has timers, then we should not stop it here.
   Reactor state with timers

           reactor => Mojo::Reactor::Poll {
             events => {
               error => [
                 &Mojo::IOLoop::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop.pm:29],
               ],
             },
             io => {
               11 => {
                 cb => &Mojo::IOLoop::Stream::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop/Stream.pm:63],
                 mode => 3,
               },
             },
             next_tick => [],
             running => 1,
             timers => {
               a284b4beeddf853b9db6b47e5b33eb8d => {
                 after => 2,
                 cb => &Mojo::IOLoop::__ANON__[lib-nodebug/lib/perl5/Mojo/IOLoop.pm:243],
                 recurring => 0,
                 time => 40348.46695112,
               },
             },
           },

** Looking at the reproduction example probably you could advice me Test::Mojo, but it does not fit my requirements. I want to run ::Prefork server for my actual task. I used Mojo::Server::Daemon here for a minimal reproducible example.