Browse Source

- Reduced Sequencer logging to debug.
- Added Setting to change sequencer log level for various actions.

Thorsten Eckel 6 years ago
parent
commit
967105b97f

+ 42 - 0
db/migrate/20180622140531_sequencer_log_level_setting.rb

@@ -0,0 +1,42 @@
+class SequencerLogLevelSetting < ActiveRecord::Migration[5.1]
+  def change
+
+    # return if it's a new setup
+    return if !Setting.find_by(name: 'system_init_done')
+
+    Setting.create_if_not_exists(
+      title:       'Sequencer log level',
+      name:        'sequencer_log_level',
+      area:        'Core',
+      description: 'Defines the log levels for various logging actions of the Sequencer.',
+      options:     {},
+      state:       {
+        sequence: {
+          start_finish: :debug,
+          unit:         :debug,
+          result:       :debug,
+        },
+        state: {
+          optional:                 :debug,
+          set:                      :debug,
+          get:                      :debug,
+          attribute_initialization: {
+            start_finish: :debug,
+            attributes:   :debug,
+          },
+          parameter_initialization: {
+            parameters:   :debug,
+            start_finish: :debug,
+            unused:       :debug,
+          },
+          expectations_initialization: :debug,
+          cleanup: {
+            start_finish: :debug,
+            remove:       :debug,
+          }
+        }
+      },
+      frontend: false,
+    )
+  end
+end

+ 35 - 0
db/seeds/settings.rb

@@ -2938,6 +2938,41 @@ Setting.create_if_not_exists(
   frontend: false
 )
 
+Setting.create_if_not_exists(
+  title:       'Sequencer log level',
+  name:        'sequencer_log_level',
+  area:        'Core',
+  description: 'Defines the log levels for various logging actions of the Sequencer.',
+  options:     {},
+  state:       {
+    sequence: {
+      start_finish: :debug,
+      unit:         :debug,
+      result:       :debug,
+    },
+    state: {
+      optional: :debug,
+      set:      :debug,
+      get:      :debug,
+      attribute_initialization: {
+        start_finish: :debug,
+        attributes:   :debug,
+      },
+      parameter_initialization: {
+        parameters:   :debug,
+        start_finish: :debug,
+        unused:       :debug,
+      },
+      expectations_initialization: :debug,
+      cleanup: {
+        start_finish: :debug,
+        remove:       :debug,
+      }
+    }
+  },
+  frontend: false,
+)
+
 Setting.create_if_not_exists(
   title: 'Time Accounting',
   name: 'time_accounting',

+ 18 - 3
lib/sequencer.rb

@@ -25,6 +25,17 @@ class Sequencer
     new(sequence, *args).process
   end
 
+  # Provides the log level definition for the requested Sequencer component.
+  #
+  # @example
+  #  Sequencer.log_level_for(:state)
+  #  #=> { get: :debug, set: :debug, ... }
+  #
+  # @return [ActiveSupport::HashWithIndifferentAcces] the log level definition
+  def self.log_level_for(component)
+    Setting.get('sequencer_log_level').with_indifferent_access[component]
+  end
+
   # Initializes a new Sequencer instance for the given Sequence with parameters and expecting result.
   #
   # @example
@@ -55,13 +66,13 @@ class Sequencer
   #
   # @return [Hash{Symbol => Object}] the final result state attributes and values
   def process
-    log_start_finish(:info, "Sequence '#{sequence.name}'") do
+    log_start_finish(log_level[:start_finish], "Sequence '#{sequence.name}'") do
 
       sequence.units.each_with_index do |unit, index|
 
         state.process do
 
-          log_start_finish(:info, "Sequence '#{sequence.name}' Unit '#{unit.name}' (index: #{index})") do
+          log_start_finish(log_level[:unit], "Sequence '#{sequence.name}' Unit '#{unit.name}' (index: #{index})") do
             unit.process(state)
           end
         end
@@ -69,7 +80,7 @@ class Sequencer
     end
 
     state.to_h.tap do |result|
-      logger.debug { "Returning Sequence '#{sequence.name}' result: #{result.inspect}" }
+      logger.public_send(log_level[:result]) { "Returning Sequence '#{sequence.name}' result: #{result.inspect}" }
     end
   end
 
@@ -80,4 +91,8 @@ class Sequencer
                                     parameters: @parameters,
                                     expecting:  @expecting)
   end
+
+  def log_level
+    @log_level ||= self.class.log_level_for(:sequence)
+  end
 end

+ 15 - 11
lib/sequencer/state.rb

@@ -88,7 +88,7 @@ class Sequencer
     # @return [Object, nil]
     def optional(attribute)
       return get(attribute) if @attributes.known?(attribute)
-      logger.debug { "Access to unknown optional attribute '#{attribute}'." }
+      logger.public_send(log_level[:optional]) { "Access to unknown optional attribute '#{attribute}'." }
       nil
     end
 
@@ -184,13 +184,13 @@ class Sequencer
     end
 
     def set(attribute, value)
-      logger.debug { "Setting '#{attribute}' value (#{value.class.name}): #{value.inspect}" }
+      logger.public_send(log_level[:set]) { "Setting '#{attribute}' value (#{value.class.name}): #{value.inspect}" }
       @values[attribute] = value
     end
 
     def get(attribute)
       value = @values[attribute]
-      logger.debug { "Getting '#{attribute}' value (#{value.class.name}): #{value.inspect}" }
+      logger.public_send(log_level[:get]) { "Getting '#{attribute}' value (#{value.class.name}): #{value.inspect}" }
       value
     end
 
@@ -207,21 +207,21 @@ class Sequencer
     end
 
     def initialize_attributes(units)
-      log_start_finish(:debug, 'Attributes lifespan initialization') do
+      log_start_finish(log_level[:attribute_initialization][:start_finish], 'Attributes lifespan initialization') do
         @attributes = Sequencer::Units::Attributes.new(units.declarations)
-        logger.debug { "Attributes lifespan: #{@attributes.inspect}" }
+        logger.public_send(log_level[:attribute_initialization][:attributes]) { "Attributes lifespan: #{@attributes.inspect}" }
       end
     end
 
     def initialize_parameters(parameters)
-      logger.debug { "Initializing Sequencer::State with initial parameters: #{parameters.inspect}" }
+      logger.public_send(log_level[:parameter_initialization][:parameters]) { "Initializing Sequencer::State with initial parameters: #{parameters.inspect}" }
 
-      log_start_finish(:debug, 'Attribute value provisioning check and initialization') do
+      log_start_finish(log_level[:parameter_initialization][:start_finish], 'Attribute value provisioning check and initialization') do
 
         @attributes.each do |identifier, attribute|
 
           if !attribute.will_be_used?
-            logger.debug { "Attribute '#{identifier}' is provided by Unit(s) but never used." }
+            logger.public_send(log_level[:parameter_initialization][:unused]) { "Attribute '#{identifier}' is provided by Unit(s) but never used." }
             next
           end
 
@@ -250,23 +250,27 @@ class Sequencer
 
     def initialize_expectations(expected_attributes)
       expected_attributes.each do |identifier|
-        logger.debug { "Adding attribute '#{identifier}' to the list of expected result attributes." }
+        logger.public_send(log_level[:expectations_initialization]) { "Adding attribute '#{identifier}' to the list of expected result attributes." }
         @attributes[identifier].to = @result_index
       end
     end
 
     def cleanup
-      log_start_finish(:info, "State cleanup of Unit #{unit.name} (index: #{@index})") do
+      log_start_finish(log_level[:cleanup][:start_finish], "State cleanup of Unit #{unit.name} (index: #{@index})") do
 
         @attributes.delete_if do |identifier, attribute|
           remove = !attribute.will_be_used?
           remove ||= attribute.to <= @index
           if remove && attribute.will_be_used?
-            logger.debug { "Removing unneeded attribute '#{identifier}': #{@values[identifier].inspect}" }
+            logger.public_send(log_level[:cleanup][:remove]) { "Removing unneeded attribute '#{identifier}': #{@values[identifier].inspect}" }
           end
           remove
         end
       end
     end
+
+    def log_level
+      @log_level ||= Sequencer.log_level_for(:state)
+    end
   end
 end