Merge pull request #567 from jrafanie/rails71-broadcast-logger

Wrap all automate logger calls to process the request_id

Author: Fryguy

lib/manageiq/automation_engine/engine.rb

@@ -19,7 +19,7 @@ def self.plugin_name
       def self.init_loggers
         # This require avoids autoload during rails boot
         require 'manageiq/automation_engine/logger'
-        $miq_ae_logger ||= Vmdb::Loggers.create_logger("automation.log", ManageIQ::AutomationEngine::Logger)
+        $miq_ae_logger ||= ManageIQ::AutomationEngine::Logger.create_log_wrapper
       end
 
       def self.apply_logger_config(config)

lib/manageiq/automation_engine/logger.rb

@@ -1,6 +1,20 @@
 module ManageIQ
   module AutomationEngine
     class Logger < ManageIQ::Loggers::Base
+      attr_reader :automation_log_wrapper
+
+      def initialize(*args, automation_log_wrapper:, **kwargs)
+        @automation_log_wrapper = automation_log_wrapper
+        super(*args, **kwargs)
+      end
+
+      def self.create_log_wrapper(io = File::NULL)
+        # We modify the interface of logger methods such as info/warn/etc. to allow the keyword argument
+        # resource_id. Therefore, we need to wrap all client logger calls to these methods to process the resource_id,
+        # cut the request_log entry and forward the remaining arguments to the logger.
+        new(io, :progname => "automation", :automation_log_wrapper => Vmdb::Loggers.create_logger("automation.log"))
+      end
+
       private def add_to_db(severity, message = nil, progname = nil, resource_id: nil)
         return [severity, message, progname] unless resource_id
 
@@ -28,31 +42,37 @@ class Logger < ManageIQ::Loggers::Base
 
       def info(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(INFO, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
 
       def debug(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(DEBUG, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
 
       def warn(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(WARN, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
 
       def error(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(ERROR, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
 
       def fatal(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(FATAL, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
 
       def unknown(progname = nil, resource_id: nil, &block)
         severity, message, progname = add_to_db(UNKNOWN, nil, progname, resource_id: resource_id, &block)
+        automation_log_wrapper.add(severity, message, progname, &block)
         add(severity, message, progname, &block)
       end
     end

spec/lib/manageiq/automation_engine/logger_spec.rb

@@ -1,7 +1,7 @@
 describe ManageIQ::AutomationEngine::Logger do
   let(:io) { StringIO.new }
   subject do
-    described_class.new(io).tap do |logger|
+    described_class.create_log_wrapper(io).tap do |logger|
       logger.level = Logger::DEBUG
     end
   end
@@ -70,8 +70,15 @@
   end
 
   describe "supports container logging" do
-    subject { Vmdb::Loggers.create_logger("automation.log", described_class) }
-    let(:container_log) { subject.try(:wrapped_logger) }
+    subject { described_class.create_log_wrapper }
+    let(:automation_log_wrapper) { subject.automation_log_wrapper }
+    let(:container_log) do
+      if automation_log_wrapper.respond_to?(:broadcasts)
+        automation_log_wrapper.broadcasts.last
+      else
+        automation_log_wrapper.wrapped_logger
+      end
+    end
 
     before do
       stub_const("ENV", ENV.to_h.merge("CONTAINER" => "true"))
@@ -120,7 +127,7 @@
 
     it "without a resource_id and with a block" do
       expect(subject.logdev).to be_nil # i.e. won't write to a file
-      expect(subject).to       receive(:add).with(Logger::INFO, nil, nil).and_call_original
+      expect(subject).to receive(:add).with(Logger::INFO, nil, nil).and_call_original
       expect(container_log).to receive(:add).with(Logger::INFO, nil, nil).and_call_original
       expect(container_log.logdev).to receive(:write).with(/"message":"foo"/)