Instrument process shutdown and add some more info to replaced fork e…

…vent

So we at least can tell when it received a SIGKILL or when it exited normally.

lib/solid_queue/log_subscriber.rb

@@ -61,6 +61,17 @@ def start_process(event)
     info formatted_event(event, action: "Started #{process.kind}", **attributes)
   end
 
+  def shutdown_process(event)
+    process = event.payload[:process]
+
+    attributes = {
+      pid: process.pid,
+      hostname: process.hostname
+    }.merge(process.metadata)
+
+    info formatted_event(event, action: "Shut down #{process.kind}", **attributes)
+  end
+
   def register_process(event)
     process_kind = event.payload[:kind]
     attributes = event.payload.slice(:pid, :hostname)
@@ -119,10 +130,15 @@ def unhandled_signal_error(event)
 
   def replace_fork(event)
     status = event.payload[:status]
-    attributes = event.payload.slice(:pid).merge(status: status.exitstatus, pid_from_status: status.pid)
+    attributes = event.payload.slice(:pid).merge \
+      status: (status.exitstatus || "no exit status set"),
+      pid_from_status: status.pid,
+      signaled: status.signaled?,
+      stopsig: status.stopsig,
+      termsig: status.termsig
 
     if replaced_fork = event.payload[:fork]
-      info formatted_event(event, action: "Replaced #{replaced_fork.kind}", **attributes.merge(hostname: replaced_fork.hostname))
+      info formatted_event(event, action: "Replaced terminated #{replaced_fork.kind}", **attributes.merge(hostname: replaced_fork.hostname))
     else
       warn formatted_event(event, action: "Tried to replace forked process but it had already died", **attributes)
     end

lib/solid_queue/processes/poller.rb

@@ -34,7 +34,9 @@ def start_loop
           end
         end
       ensure
-        run_callbacks(:shutdown) { shutdown }
+        SolidQueue.instrument(:shutdown_process, process: self) do
+          run_callbacks(:shutdown) { shutdown }
+        end
       end
 
       def poll

test/integration/instrumentation_test.rb

@@ -25,11 +25,11 @@ class InstrumentationTest < ActiveSupport::TestCase
     events = subscribed(/release.*_claimed\.solid_queue/) do
       worker = SolidQueue::Worker.new.tap(&:start)
 
-      wait_while_with_timeout(1.seconds) { SolidQueue::ReadyExecution.any? }
+      wait_while_with_timeout(3.seconds) { SolidQueue::ReadyExecution.any? }
       process = SolidQueue::Process.last
 
       worker.stop
-      wait_for_registered_processes(0, timeout: 1.second)
+      wait_for_registered_processes(0, timeout: 3.second)
     end
 
     assert_equal 2, events.size
@@ -59,12 +59,12 @@ class InstrumentationTest < ActiveSupport::TestCase
 
     events = subscribed(/(register|deregister)_process\.solid_queue/) do
       worker = SolidQueue::Worker.new.tap(&:start)
-      wait_while_with_timeout(1.seconds) { SolidQueue::ReadyExecution.any? }
+      wait_while_with_timeout(3.seconds) { SolidQueue::ReadyExecution.any? }
 
       process = SolidQueue::Process.last
 
       worker.stop
-      wait_for_registered_processes(0, timeout: 1.second)
+      wait_for_registered_processes(0, timeout: 3.second)
     end
 
     assert_equal 2, events.size