Try to shut down more aggressively

Add a separate `_shutdown` method called by `run` and by signal handlers. It's responsible for removing the PID file and for setting `continue` to `0`. This should ensure that it's always called at least once, and is safe to call multiple times. Either way the PID file should now always be deleted and the shutdown activity properly logged. Also set all the signal handlers in the `_signal_handlers` method, and teach it to nest signal handlers if necessary. This will keep the consumer from wiping out its own handlers. I have no reason to think they have been, but it seems best to play it as safe as possible. Add a slew of new tests to test all these behaviors thoroughly.
pgxn · Feb 17, 2024 · 2084b09 · 2084b09
1 parent 19a3ff6
commit 2084b09
Show file tree

Hide file tree

Showing 3 changed files with 159 additions and 19 deletions.
diff --git a/Changes b/Changes
@@ -9,9 +9,9 @@ Revision history for Perl extension PGXN::Manager
        - Added a logger to the Consumer and the Mastodon and Twitter handlers,
          so that they now log debug and info messages about what's being sent.
        - Moved PID file cleanup from the `DEMOLISH` method to the `run` method,
-         where it should always execute. This will hopefully fix the issue
-         where the consumer mysteriously ceases running and doesn't remove its
-         PID file, so never restarts.
+         and the signal handlers, where it should always execute at least once.
+         This will hopefully fix the issue where the consumer mysteriously
+         ceases running and doesn't remove its PID file, so never restarts.
        - Replaced use of the deprecated `given`/`when` syntax with plain old
          `if`/`elsif`/`else`.
 

diff --git a/lib/PGXN/Manager/Consumer.pm b/lib/PGXN/Manager/Consumer.pm
@@ -77,16 +77,43 @@ sub go {
     );
     $cfg->{pid_file} = delete $cfg->{'pid-file'} if exists $cfg->{'pid-file'};
     my $cmd = $class->new( $cfg );
-    $SIG{$_} = $cmd->_signal_handler($_) for qw(TERM INT QUIT);
+    $cmd->_signal_handlers;
     $cmd->run(@ARGV);
 }
 
-sub _signal_handler {
+sub _signal_handlers {
     my ($self, $sig) = @_;
-    return sub {
-        $self->log(INFO => "$sig signal caught; flagging shutdown for next loop");
+    for my $sig (qw(TERM INT QUIT)) {
+        my $handler = sub {
+            $self->log(INFO => "$sig signal caught");
+            $self->_shutdown;
+        };
+        if (my $code = $SIG{$sig}) {
+            $SIG{$sig} = sub { $handler->(); $code->(); };
+        } else {
+            $SIG{$sig} = $handler;
+        }
+    }
+    return 1;
+}
+
+sub _shutdown {
+    my $self = shift;
+
+    # Always try to delete the PID file.
+    if (my $path = $self->pid_file) {
+        $self->log(DEBUG => "Unlinked PID file ", $self->pid_file)
+            if unlink $path;
+        $self->pid_file('');
+    }
+
+    if ($self->continue) {
+        # Tell the loop to stop on the next iteration.
         $self->continue(0);
-    };
+        $self->log(INFO => 'Shutting down') ;
+    }
+
+    return 1;
 }
 
 sub run {
@@ -107,12 +134,7 @@ sub run {
         sleep($self->interval);
     }
 
-    if (my $path = $self->pid_file) {
-        $self->log(DEBUG => "Unlinking PID file ", $self->pid_file);
-        unlink $path;
-    }
-
-    $self->log(INFO => 'Shutting down');
+    $self->_shutdown;
     return 0;
 }
 

diff --git a/t/consumer.t b/t/consumer.t
@@ -8,7 +8,7 @@ use Encode qw(encode_utf8);
 use JSON::XS;
 use File::Temp ();
 
-use Test::More tests => 122;
+use Test::More tests => 190;
 # use Test::More 'no_plan';
 use Test::Output;
 use Test::MockModule;
@@ -345,8 +345,7 @@ RUN: {
         "$logtime - DEBUG: Configuring PGXN::Manager::Consumer::mastodon for release",
         "$logtime - DEBUG: Loading PGXN::Manager::Consumer::twitter",
         "$logtime - DEBUG: Configuring PGXN::Manager::Consumer::twitter for release",
-        "$logtime - DEBUG: Unlinking PID file $fn",
-        "$logtime - INFO: Shutting down",
+        "$logtime - DEBUG: Unlinked PID file $fn",
         '',
     ), 'Should have startup, loading, PID, and shutdown log entries';
     is_deeply \@done, $exp_done, 'Should have listened to all channels';
@@ -371,7 +370,6 @@ RUN: {
     is_deeply output(), join("", map { "$logtime - $_\n" }
         "INFO: Starting $CLASS " . $CLASS->VERSION,
         "WARN: No consumers configured; messages will be dropped",
-        "INFO: Shutting down",
     ), 'Should have warning about no consumers';
     is @{ $params }, 1, 'Should have passed one param to consume';
     is_deeply [keys %{ $params->[0] }], [], 'Should have no key in param';
@@ -389,11 +387,131 @@ RUN: {
     is_deeply output(), join("", map { "$logtime - $_\n" }
         "INFO: Starting $CLASS " . $CLASS->VERSION,
         "INFO: Listening on $chans",
-        "INFO: Shutting down",
     ), 'Should have verbose output';
     $mocker->unmock('consume');
 };
 
+##############################################################################
+# Test shutdown.
+SHUTDOWN: {
+    # Set up a PID file.
+    my $tmp = File::Temp->new(UNLINK => 0);
+    my $fn = $tmp->filename;
+
+    # Set up the consumer.
+    my $consumer = new_ok $CLASS, [logger => $logger, pid_file => $fn];
+    is $consumer->continue, 1, 'Should have default continue 1';
+    is $consumer->logger, $logger, 'Should have set logger';
+    is $consumer->pid_file, $fn, 'Should have set pid_file';
+    file_exists_ok $fn, 'PID file should exist';
+
+    # Start with the PID file and shutdown.
+    local $logger->{verbose} = 2;
+    ok $consumer->_shutdown, 'Shutdown';
+    is $consumer->continue, 0, 'Should have unset continue';
+    is $consumer->logger, $logger, 'Should still have logger';
+    is $consumer->pid_file, '', 'Should have unset pid_file';
+    file_not_exists_ok $fn, 'PID file should be gone';
+
+    # Should have debug output.
+    is output(), join("\n",
+        "$logtime - DEBUG: Unlinked PID file $fn",
+        "$logtime - INFO: Shutting down",
+        '',
+    ), 'Should have debug and info logs';
+
+    # Try again with pid_file unset and continue false.
+    ok $consumer->_shutdown, 'Shutdown again';
+    is $consumer->continue, 0, 'Should still have continue 0';
+    is $consumer->logger, $logger, 'Should still have logger';
+    is $consumer->pid_file, '', 'Should still have no pid_file';
+    file_not_exists_ok $fn, 'PID file should still be gone';
+    is output(), '', 'Should have no output';
+
+    # Try with a pid file again.
+    $consumer->pid_file($fn);
+    is $consumer->pid_file, $fn, 'Should have set pid_file again';
+    ok $consumer->_shutdown, 'Shutdown three';
+    is $consumer->continue, 0, 'Should again have continue 0';
+    is $consumer->pid_file, '', 'Should have unset pid_file again';
+    file_not_exists_ok $fn, 'PID file should still be gone';
+    is output(), '', 'Should have no output';
+
+    # Now create another PID file.
+    $tmp = File::Temp->new(UNLINK => 0);
+    $fn = $tmp->filename;
+    file_exists_ok $fn, 'PID file should exist';
+    $consumer->pid_file($fn);
+    is $consumer->pid_file, $fn, 'Should have set pid_file once again';
+    ok $consumer->_shutdown, 'Shutdown four';
+    is $consumer->continue, 0, 'Should once more have continue 0';
+    is $consumer->pid_file, '', 'Should have unset pid_file three';
+    file_not_exists_ok $fn, 'PID file should again be gone';
+    is output(), "$logtime - DEBUG: Unlinked PID file $fn\n",
+        'Should have only PID file log item';
+
+    # Set continue to true again.
+    $consumer->continue(1);
+    ok $consumer->_shutdown, 'Shutdown five';
+    is $consumer->continue, 0, 'Should again have unset continue';
+    is $consumer->pid_file, '', 'Should still have unset pid_file three';
+    is output(), "$logtime - INFO: Shutting down\n",
+        'Should have just the shutdown log item';
+}
+
+##############################################################################
+# Test signals.
+SIGNALS: {
+    # Set up a PID file.
+    my $tmp = File::Temp->new(UNLINK => 0);
+    my $fn = $tmp->filename;
+
+    # Set up the consumer.
+    my $consumer = new_ok $CLASS, [logger => $logger, pid_file => $fn];
+    is $consumer->continue, 1, 'Should have default continue 1';
+    is $consumer->logger, $logger, 'Should have set logger';
+    is $consumer->pid_file, $fn, 'Should have set pid_file';
+    file_exists_ok $fn, 'PID file should exist';
+
+    # Should have set no sigals.
+    my @sigs = qw(TERM INT QUIT);
+    is $SIG{$_}, undef, "$_ signal should not be set" for @sigs;
+
+    # Set them up.
+    ok $consumer->_signal_handlers, 'Set up signal handlers';
+    isa_ok $SIG{$_}, 'CODE', "$_ signal should be set" for @sigs;
+
+    # Let's execute them. Mock _shutdown.
+    my $mock = Test::MockModule->new($CLASS);
+    my $shutdown_called;
+    $mock->mock(_shutdown => sub { $shutdown_called = 1 });
+
+    # Now try them.
+    for my $sig (@sigs) {
+        ok $SIG{$sig}->(), "Call $sig";
+        ok $shutdown_called, "$sig should have called shutdown";
+        is output(), "$logtime - INFO: $sig signal caught\n",
+            "Should have logged the $sig signal";
+        $shutdown_called = 0;
+    }
+
+    # Make sure they nest. Call _signal_handlers again.
+    ok $consumer->_signal_handlers, 'Set up signal handlers again';
+    isa_ok $SIG{$_}, 'CODE', "$_ signal should still be set" for @sigs;
+
+    # Now try them again.
+    for my $sig (@sigs) {
+        ok $SIG{$sig}->(), "Call $sig again";
+        ok $shutdown_called, "$sig should have again called shutdown";
+        is output(), join("\n",
+            "$logtime - INFO: $sig signal caught",
+            "$logtime - INFO: $sig signal caught",
+            '',
+        ), "Should have logged the $sig signal twice";
+        $shutdown_called = 0;
+    }
+}
+
 ##############################################################################
 # Test consume.
 CONSUME: {