Add benchmark and logging around storage profiles

Collection of storage profiles were not reflected it their own benchmark
timings and were not logged making it difficult to diagnose when their
collection is slow

app/models/manageiq/providers/vmware/infra_manager/refresher.rb

@@ -22,6 +22,7 @@ def provider.use_vim_broker?; @__use_vim_broker; end
       def collect_inventory_for_targets(ems, targets)
         Benchmark.realtime_block(:get_ems_data) { get_ems_data(ems) }
         Benchmark.realtime_block(:get_vc_data) { get_vc_data(ems) }
+        Benchmark.realtime_block(:get_vc_data_storage_profile) { get_vc_data_storage_profile(ems) }
 
         Benchmark.realtime_block(:get_vc_data_ems_customization_specs) { get_vc_data_ems_customization_specs(ems) } if targets.include?(ems)
 
@@ -76,10 +77,22 @@ def post_refresh(ems, start_time)
       # VC data collection methods
       #
 
+      def collect_and_log_inventory(ems, type)
+        log_header = format_ems_for_logging(ems)
+
+        _log.info("#{log_header} Retrieving #{type.to_s.titleize} inventory...")
+
+        inv_hash = yield
+
+        inv_count = inv_hash.blank? ? 0 : inv_hash.length
+        @vc_data[type] = inv_hash unless inv_hash.blank?
+
+        _log.info("#{log_header} Retrieving #{type.to_s.titleize} inventory...Complete - Count: [#{inv_count}]")
+      end
+
       VC_ACCESSORS_HASH = {
         :storage         => :dataStoresByMor,
         :storage_pod     => :storagePodsByMor,
-        :storage_profile => :pbmProfilesByUid,
         :dvportgroup     => :dvPortgroupsByMor,
         :dvswitch        => :dvSwitchesByMor,
         :host            => :hostSystemsByMor,
@@ -115,10 +128,6 @@ def get_vc_data(ems, accessors = VC_ACCESSORS_HASH, mor_filters = {})
             @vc_data[type] = inv_hash unless inv_hash.blank?
             _log.info("#{log_header} Retrieving #{type.to_s.titleize} inventory...Complete - Count: [#{inv_hash.blank? ? 0 : inv_hash.length}]")
           end
-
-          storage_profile_ids = @vc_data[:storage_profile].collect { |uid, _profile| uid }
-          @vc_data[:storage_profile_datastore] = @vi.pbmQueryMatchingHub(storage_profile_ids)
-          @vc_data[:storage_profile_entity]    = @vi.pbmQueryAssociatedEntity(storage_profile_ids)
         end
 
         # Merge Virtual Apps into Resource Pools
@@ -130,6 +139,22 @@ def get_vc_data(ems, accessors = VC_ACCESSORS_HASH, mor_filters = {})
         EmsRefresh.log_inv_debug_trace(@vc_data, "#{_log.prefix} #{log_header} @vc_data:", 2)
       end
 
+      def get_vc_data_storage_profile(ems)
+        log_header = format_ems_for_logging(ems)
+        cleanup_callback = proc { @vc_data = nil }
+
+        retrieve_from_vc(ems, cleanup_callback) do
+          collect_and_log_inventory(ems, :storage_profile) { @vi.pbmProfilesByUid }
+
+          unless @vc_data[:storage_profile].blank?
+            storage_profile_ids = @vc_data[:storage_profile].keys
+
+            collect_and_log_inventory(ems, :storage_profile_datastore) { @vi.pbmQueryMatchingHub(storage_profile_ids) }
+            collect_and_log_inventory(ems, :storage_profile_entity)    { @vi.pbmQueryAssociatedEntity(storage_profile_ids) }
+          end
+        end
+      end
+
       def get_vc_data_ems_customization_specs(ems)
         log_header = format_ems_for_logging(ems)