Fixes #3360 - Unclear why entities are skipped in import(s).

lib/sequencer/sequence/import/exchange/folder_contact.rb

@@ -10,8 +10,8 @@ class Sequencer
               'Import::Common::RemoteId::CaseSensitive',
               'Import::Exchange::FolderContact::Mapping::FromConfig',
               'Import::Exchange::FolderContact::Mapping::Login',
-              'Import::Common::Model::Skip::Blank::Mapped',
               'Common::ModelClass::User',
+              'Import::Common::Model::Skip::Blank::Mapped',
               'Import::Exchange::FolderContact::ExternalSyncSource',
               'Import::Common::Model::Lookup::ExternalSync',
               'Import::Common::Model::Associations::Extract',

lib/sequencer/unit/import/common/model/attributes/check_mandatory.rb

@@ -16,6 +16,7 @@ class Sequencer
                 mandatory.each do |mapped_attribute|
                   next if mapped[mapped_attribute].present?
 
+                  logger.info { "Skipping. Missing mandatory attribute '#{mapped_attribute}'." }
                   state.provide(:action, :skipped)
                   break
                 end

lib/sequencer/unit/import/common/model/mixin/log/context_identification_string.rb

@@ -0,0 +1,112 @@
+# When building generic Sequencer Units in various contexts it's not possible know
+# which model, resource, mapped or instance is present at the moment or even used
+# in the Sequence at all.
+# But at the same time it's desirable to write an expressive log line that eases
+# the Debugging Experience and makes it possible to identify the processed data context.
+# This Mixin provides the method `context_identification_string` to build a String
+# that includes all available information ready to write to the log.
+class Sequencer
+  class Unit
+    module Import
+      module Common
+        module Model
+          module Mixin
+            module Log
+              module ContextIdentificationString
+
+                def self.included(base)
+                  base.optional :model_class, :resource, :mapped, :instance
+                end
+
+                # Call this method in your Unit. It contains all the available context information.
+                #
+                # @example
+                #  context_identification_string
+                #  # => 'for Model 'User' possible identified by 'id, email, login' from resource identified by '{id: 1337}...
+                #
+                def context_identification_string
+                  "#{model_identifier_part}#{resource_identifier_part}#{mapped_identifier_part}#{instance_identifier_part}"
+                end
+
+                def possible_identifier_attributes
+                  @possible_identifier_attributes ||= begin
+                    lookup_keys = model_class.present? ? model_class.lookup_keys : []
+                    # add default lookup attributes to the lookup keys of a possibly present Model
+                    lookup_keys | %i[id name login email number]
+                  end
+                end
+
+                def model_identifier_part
+                  return if model_class.blank?
+
+                  " for Model '#{model_class}' possibly identified by '#{possible_identifier_attributes.join(', ')}'"
+                end
+
+                def resource_identifier_part
+                  return if resource.blank?
+
+                  return ' from unidentifiable resource' if resource_identifier_part_data.blank?
+
+                  " from resource identified by '#{resource_identifier_part_data.inspect}'"
+                end
+
+                def mapped_identifier_part
+                  return if mapped.blank?
+
+                  mapped_identifier_part_data = mapped.slice(*possible_identifier_attributes)
+
+                  return ' without mapped identifiers' if mapped_identifier_part_data.blank?
+
+                  " with mapped identifiers '#{mapped_identifier_part_data.inspect}'"
+                end
+
+                def instance_identifier_part
+                  return if instance.blank?
+
+                  instance_identifier_part_data = {}
+                  possible_identifier_attributes.each do |key|
+                    next if !instance.respond_to?(key)
+
+                    instance_identifier_part_data[key] = instance.public_send(key)
+                  end
+
+                  return ' with unidentifiable instance' if instance_identifier_part_data.blank?
+
+                  " with instance identified by '#{instance_identifier_part_data.inspect}'"
+                end
+
+                private
+
+                def resource_identifier_part_data
+                  @resource_identifier_part_data ||= begin
+                    if resource.respond_to?(:[])
+                      resource_identifier_part_data_from_hash
+                    else
+                      resource_identifier_part_data_from_methods
+                    end
+                  end
+                end
+
+                def resource_identifier_part_data_from_hash
+                  possible_identifier_attributes.each_with_object({}) do |key, result|
+                    next if resource[key].blank?
+
+                    result[key] = resource[key]
+                  end
+                end
+
+                def resource_identifier_part_data_from_methods
+                  possible_identifier_attributes.each_with_object({}) do |key, result|
+                    next if !resource.respond_to?(key)
+
+                    result[key] = resource.public_send(key)
+                  end
+                end
+              end
+            end
+          end
+        end
+      end
+    end
+  end
+end

lib/sequencer/unit/import/common/model/skip/blank/base.rb

@@ -1,5 +1,8 @@
 require_dependency 'sequencer/unit/common/mixin/dynamic_attribute'
+require_dependency 'sequencer/unit/import/common/model/mixin/log/context_identification_string'
 
+# This unit checks if an Sequencer state attribute (e.g. `mapped`) is blank.
+# Don't confuse it with e.g. 'Import::Common::Model::Skip::MissingMandatory::Base' which checks if an attribute key (e.g. mapped[:some_key]) is blank/missing.
 class Sequencer
   class Unit
     module Import
@@ -10,15 +13,18 @@ class Sequencer
               class Base < Sequencer::Unit::Base
                 include ::Sequencer::Unit::Common::Mixin::DynamicAttribute
                 prepend ::Sequencer::Unit::Import::Common::Model::Mixin::Skip::Action
+                include ::Sequencer::Unit::Import::Common::Model::Mixin::Log::ContextIdentificationString
 
                 skip_any_action
 
                 provides :action
 
+                optional :model_class
+
                 def process
                   return if !skip?
 
-                  logger.debug { "Skipping. Blank #{attribute} found: #{attribute_value.inspect}" }
+                  logger.info { skip_log_message }
                   state.provide(:action, :skipped)
                 end
 
@@ -34,6 +40,10 @@ class Sequencer
                   relevant_blank?
                 end
 
+                def skip_log_message
+                  "Skipping. Blank attribute '#{attribute}' found (#{attribute_value.inspect})#{context_identification_string}"
+                end
+
                 def relevant_blank?
                   attribute_value.except(*ignore).values.none?(&:present?)
                 end

lib/sequencer/unit/import/common/model/skip/missing_mandatory/base.rb

@@ -1,4 +1,5 @@
 require_dependency 'sequencer/unit/common/mixin/dynamic_attribute'
+require_dependency 'sequencer/unit/import/common/model/mixin/log/context_identification_string'
 
 class Sequencer
   class Unit
@@ -10,6 +11,7 @@ class Sequencer
               class Base < Sequencer::Unit::Base
                 include ::Sequencer::Unit::Common::Mixin::DynamicAttribute
                 prepend ::Sequencer::Unit::Import::Common::Model::Mixin::Skip::Action
+                include ::Sequencer::Unit::Import::Common::Model::Mixin::Log::ContextIdentificationString
 
                 skip_any_action
 
@@ -18,7 +20,7 @@ class Sequencer
                 def process
                   return if !skip?
 
-                  logger.debug { "Skipping. Missing mandatory attributes for #{attribute}: #{attribute_value.inspect}" }
+                  logger.info { skip_log_message }
                   state.provide(:action, :skipped)
                 end
 
@@ -31,14 +33,15 @@ class Sequencer
                 def skip?
                   return true if attribute_value.blank?
 
-                  mandatory_missing?
+                  missing_for_keys.blank?
                 end
 
-                def mandatory_missing?
+                def skip_log_message
-                  values = attribute_value.fetch_values(*mandatory)
+                  "Skipping. Missing values for mandatory keys '#{missing_for_keys.join(', ')}' in attribute '#{attribute}'#{context_identification_string}"
-                  values.none?(&:present?)
+                end
-                rescue KeyError
+
-                  false
+                def missing_for_keys
+                  @missing_for_keys ||= mandatory.select { |key| attribute_value[key].blank? }
                 end
               end
             end

lib/sequencer/unit/import/ldap/user/attributes/role_ids/unassigned.rb

@@ -30,8 +30,8 @@ class Sequencer
                     instance.update!(active: false)
                     state.provide(:action, :deactivated)
                   else
-                    # skip instance creation if no existing
+                    # skip instance creation if no existing instance was found yet
-                    # instance was found yet
+                    logger.info { "Skipping. No Role assignment found for login '#{mapped[:login]}'" }
                     state.provide(:action, :skipped)
                   end
                 end

lib/sequencer/unit/import/zendesk/ticket/comment/attachment/request.rb

@@ -14,22 +14,16 @@ class Sequencer
                 provides :response, :action
 
                 def process
-                  if failed?
+                  if response.success?
-                    state.provide(:action, :skipped)
-                  else
                     state.provide(:response, response)
+                  else
+                    logger.error "Skipping. Error while downloading Attachment from '#{resource.content_url}': #{response.error}"
+                    state.provide(:action, :skipped)
                   end
                 end
 
                 private
 
-                def failed?
-                  return false if response.success?
-
-                  logger.error response.error
-                  true
-                end
-
                 def response
                   @response ||= begin
                     UserAgent.get(

lib/sequencer/unit/import/zendesk/ticket/skip/deleted.rb

@@ -12,6 +12,7 @@ class Sequencer
               def process
                 return if resource.status != 'deleted'
 
+                logger.info { "Skipping. Zendesk Ticket ID '#{resource.id}' is in 'deleted' state." }
                 state.provide(:action, :skipped)
               end
             end

lib/sequencer/unit/import/zendesk/ticket_field/check_custom.rb

@@ -11,6 +11,7 @@ class Sequencer
             def process
               return if custom?
 
+              logger.info { "Skipping. Default field '#{attribute}' found for field '#{resource.type}'." }
               state.provide(:action, :skipped)
             end
 
@@ -21,7 +22,7 @@ class Sequencer
             end
 
             def attribute
-              mapping.fetch(resource.type, resource.type)
+              @attribute ||= mapping.fetch(resource.type, resource.type)
             end
 
             def mapping

spec/lib/sequencer/unit/import/common/model/mixin/log/context_identification_string_spec.rb

@@ -0,0 +1,105 @@
+require 'rails_helper'
+
+RSpec.describe Sequencer::Unit::Import::Common::Model::Mixin::Log::ContextIdentificationString do
+
+  before do
+    stub_const unit_class_namespace, unit_class
+  end
+
+  let(:unit_class_namespace) { "#{Sequencer::Unit::PREFIX}SomeIdentifyingUnit" }
+
+  let(:unit_class) do
+    Class.new(Sequencer::Unit::Base) do
+      include Sequencer::Unit::Import::Common::Model::Mixin::Log::ContextIdentificationString
+
+      provides :context_identification_string
+
+      def process
+        state.provide(:context_identification_string, context_identification_string)
+      end
+    end
+  end
+
+  let(:result) do
+    result = Sequencer::Unit.process(unit_class_namespace, parameters)
+    result[:context_identification_string]
+  end
+
+  context 'when no attributes to identify by are given' do
+
+    let(:parameters) { {} }
+
+    it 'returns an empty string' do
+      expect(result).to eq ''
+    end
+  end
+
+  context "when 'model_class' attribute is given" do
+
+    let(:model_class) { ::User }
+    let(:parameters) { { model_class: model_class } }
+
+    it 'adds Model class name and lookup_keys' do
+      expect(result).to include(model_class.name, *model_class.lookup_keys.map(&:to_s))
+    end
+  end
+
+  context "when 'resource' attribute is given" do
+
+    let(:parameters) { { resource: resource } }
+
+    context "when 'resource' has identifier methods" do
+
+      let(:resource) { double('Some remote resource', id: SecureRandom.base58, foo: SecureRandom.base58) } # rubocop:disable RSpec/VerifiedDoubles
+
+      it 'adds resource identifiers' do
+        expect(result).to include(resource.id)
+      end
+
+      it "doesn't include other resource attributes" do
+        expect(result).not_to include(resource.foo)
+      end
+    end
+
+    context "when 'resource' has Hash like accessor" do
+
+      let(:resource) { { id: SecureRandom.base58, foo: SecureRandom.base58 } }
+
+      it 'adds resource identifiers' do
+        expect(result).to include(resource[:id])
+      end
+
+      it "doesn't include other resource attributes" do
+        expect(result).not_to include(resource[:foo])
+      end
+    end
+  end
+
+  context "when 'mapped' attribute is given" do
+
+    let(:mapped) { { id: SecureRandom.base58, foo: SecureRandom.base58 } }
+    let(:parameters) { { mapped: mapped } }
+
+    it 'adds mapped identifiers' do
+      expect(result).to include(mapped[:id])
+    end
+
+    it "doesn't include other mapped attributes" do
+      expect(result).not_to include(mapped[:foo])
+    end
+  end
+
+  context "when 'instance' attribute is given" do
+
+    let(:instance) { build(:user, password: 'foo') }
+    let(:parameters) { { instance: instance } }
+
+    it 'adds instance identifiers' do
+      expect(result).to include(*instance.class.lookup_keys.map(&:to_s))
+    end
+
+    it "doesn't include other instance attributes" do
+      expect(result).not_to include(instance.password)
+    end
+  end
+end

spec/lib/sequencer/unit/import/zendesk/ticket/comment/attachment/request_spec.rb

@@ -4,19 +4,7 @@ RSpec.describe Sequencer::Unit::Import::Zendesk::Ticket::Comment::Attachment::Re
 
   context 'when fetching large attachements from Zendesk' do
 
-    before(:all) do
+    let(:mock_parameters) do
-
-      described_class.class_eval do
-
-        private
-
-        def failed?
-          false
-        end
-      end
-    end
-
-    def mock_parameters
       {
         resource: double(
           content_url: ''
@@ -24,9 +12,13 @@ RSpec.describe Sequencer::Unit::Import::Zendesk::Ticket::Comment::Attachment::Re
       }
     end
 
+    let(:response) { double() }
+
     it 'open timeout should be 20s and read timeout should be 240s' do
-      expect(UserAgent).to receive(:get).with(any_args, { open_timeout: 20, read_timeout: 240 })
+      allow(response).to receive(:success?).and_return(true)
+      allow(UserAgent).to receive(:get).with(any_args, { open_timeout: 20, read_timeout: 240 }).and_return(response)
       process(mock_parameters)
+      expect(UserAgent).to have_received(:get)
     end
   end
 end