Fix pruned attribute on deregister_process event

It was being set to the whole payload ^_^U

Also, use iso8601 format for dates in log events.

Author: rosa

lib/solid_queue/log_subscriber.rb

@@ -40,7 +40,8 @@ def release_blocked(event)
   end
 
   def enqueue_recurring_task(event)
-    attributes = event.payload.slice(:task, :active_job_id, :enqueue_error, :at)
+    attributes = event.payload.slice(:task, :active_job_id, :enqueue_error)
+    attributes[:at] = event.payload[:at]&.iso8601
 
     if event.payload[:other_adapter]
       action = attributes[:active_job_id].present? ? "Enqueued recurring task outside Solid Queue" : "Error enqueuing recurring task"
@@ -96,9 +97,9 @@ def deregister_process(event)
       process_id: process.id,
       pid: process.pid,
       hostname: process.hostname,
-      last_heartbeat_at: process.last_heartbeat_at,
+      last_heartbeat_at: process.last_heartbeat_at.iso8601,
       claimed_size: process.claimed_executions.size,
-      pruned: event.payload
+      pruned: event.payload[:pruned]
     }
 
     if error = event.payload[:error]

test/unit/log_subscriber_test.rb

@@ -28,23 +28,36 @@ def set_logger(logger)
 
   test "recurring task enqueued succesfully" do
     attach_log_subscriber
-    instrument "enqueue_recurring_task.solid_queue", task: :example_task, active_job_id: "b944ddbc-6a37-43c0-b661-4b56e57195f5", at: Time.now
+    time = Time.now
+    instrument "enqueue_recurring_task.solid_queue", task: :example_task, active_job_id: "b944ddbc-6a37-43c0-b661-4b56e57195f5", at: time
 
-    assert_match_logged :info, "Enqueued recurring task", "task: :example_task, active_job_id: \"b944ddbc-6a37-43c0-b661-4b56e57195f5\""
+    assert_match_logged :info, "Enqueued recurring task", "task: :example_task, active_job_id: \"b944ddbc-6a37-43c0-b661-4b56e57195f5\", at: \"#{time.iso8601}\""
   end
 
   test "recurring task skipped" do
     attach_log_subscriber
-    instrument "enqueue_recurring_task.solid_queue", task: :example_task, skipped: true, at: Time.now
+    time = Time.now
+    instrument "enqueue_recurring_task.solid_queue", task: :example_task, skipped: true, at: time
 
-    assert_match_logged :info, "Skipped recurring task – already dispatched", "task: :example_task"
+    assert_match_logged :info, "Skipped recurring task – already dispatched", "task: :example_task, at: \"#{time.iso8601}\""
   end
 
   test "error enqueuing recurring task" do
     attach_log_subscriber
-    instrument "enqueue_recurring_task.solid_queue", task: :example_task, enqueue_error: "Everything is broken", at: Time.now
+    time = Time.now
+    instrument "enqueue_recurring_task.solid_queue", task: :example_task, enqueue_error: "Everything is broken", at: time
 
-    assert_match_logged :info, "Error enqueuing recurring task", "task: :example_task, enqueue_error: \"Everything is broken\""
+    assert_match_logged :info, "Error enqueuing recurring task", "task: :example_task, enqueue_error: \"Everything is broken\", at: \"#{time.iso8601}\""
+  end
+
+  test "deregister process" do
+    process = SolidQueue::Process.register(kind: "Worker", pid: 42, hostname: "localhost")
+    last_heartbeat_at = process.last_heartbeat_at.iso8601
+
+    attach_log_subscriber
+    instrument "deregister_process.solid_queue", process: process, pruned: false
+
+    assert_match_logged :info, "Deregister Worker", "process_id: #{process.id}, pid: 42, hostname: \"localhost\", last_heartbeat_at: \"#{last_heartbeat_at}\", claimed_size: 0, pruned: false"
   end
 
   private