From e9c8e182d338af470244d05db944b378439fac9f Mon Sep 17 00:00:00 2001
From: Alan Guo Xiang Tan <gxtan1990@gmail.com>
Date: Wed, 29 May 2024 11:15:20 +0800
Subject: [PATCH] DEV: Use Unicorn logger to log Sidekiq signal handling events
 (#27239)

This commit updates all Sidekiq signal handling event logs to go through
Unicorn's logger instead of logging to STDOUT. Going through a proper logger
means the log messages are logged in the format which the logger has configured.
This means we get proper timestamp for the log messages.
---
 config/unicorn.conf.rb |  4 ++--
 lib/demon/sidekiq.rb   | 43 +++++++++++++++++++++++++++++++++++++++---
 2 files changed, 42 insertions(+), 5 deletions(-)

diff --git a/config/unicorn.conf.rb b/config/unicorn.conf.rb
index 4bfe1480eef..c3708e9edf2 100644
--- a/config/unicorn.conf.rb
+++ b/config/unicorn.conf.rb
@@ -84,12 +84,12 @@ before_fork do |server, worker|
       server.logger.info "starting #{sidekiqs} supervised sidekiqs"
 
       require "demon/sidekiq"
+      Demon::Sidekiq.logger = server.logger
       Demon::Sidekiq.after_fork { DiscourseEvent.trigger(:sidekiq_fork_started) }
-
       Demon::Sidekiq.start(sidekiqs)
 
       Signal.trap("SIGTSTP") do
-        STDERR.puts "#{Time.now}: Issuing stop to sidekiq"
+        Demon::Sidekiq.log("Issuing stop to Sidekiq")
         Demon::Sidekiq.stop
       end
 
diff --git a/lib/demon/sidekiq.rb b/lib/demon/sidekiq.rb
index 1c1776d80ca..def77f03bea 100644
--- a/lib/demon/sidekiq.rb
+++ b/lib/demon/sidekiq.rb
@@ -3,6 +3,8 @@
 require "demon/base"
 
 class Demon::Sidekiq < ::Demon::Base
+  cattr_accessor :logger
+
   def self.prefix
     "sidekiq"
   end
@@ -11,6 +13,37 @@ class Demon::Sidekiq < ::Demon::Base
     blk ? (@blk = blk) : @blk
   end
 
+  def self.format(message)
+    "[#{Time.now.utc.strftime("%Y-%m-%dT%H:%M:%S.%6N")} ##{Process.pid}] #{message}"
+  end
+
+  def self.log(message, level: :info)
+    # We use an IO pipe and log messages using the logger in a seperate thread to avoid the `log writing failed. can't be called from trap context`
+    # error message that is raised when trying to log from within a `Signal.trap` block.
+    if logger
+      if !defined?(@logger_read_pipe)
+        @logger_read_pipe, @logger_write_pipe = IO.pipe
+
+        @logger_thread =
+          Thread.new do
+            begin
+              while readable_io = IO.select([@logger_read_pipe])
+                logger.public_send(level, readable_io.first[0].gets.strip)
+              end
+            rescue => e
+              STDOUT.puts self.format(
+                            "Error in Sidekiq demon logger thread: #{e.message}\n#{e.backtrace.join("\n")}",
+                          )
+            end
+          end
+      end
+
+      @logger_write_pipe.puts(message)
+    else
+      STDOUT.puts self.format(message)
+    end
+  end
+
   private
 
   def suppress_stdout
@@ -21,18 +54,22 @@ class Demon::Sidekiq < ::Demon::Base
     false
   end
 
+  def log(message, level: :info)
+    self.class.log(message, level:)
+  end
+
   def after_fork
     Demon::Sidekiq.after_fork&.call
 
-    puts "Loading Sidekiq in process id #{Process.pid}"
+    log("Loading Sidekiq in process id #{Process.pid}")
     require "sidekiq/cli"
     cli = Sidekiq::CLI.instance
 
     # Unicorn uses USR1 to indicate that log files have been rotated
     Signal.trap("USR1") do
-      puts "Sidekiq PID #{Process.pid} reopening logs..."
+      log("Sidekiq reopening logs...")
       Unicorn::Util.reopen_logs
-      puts "Sidekiq PID #{Process.pid} done reopening logs..."
+      log("Sidekiq done reopening logs...")
     end
 
     options = ["-c", GlobalSetting.sidekiq_workers.to_s]