Whenever CloudForms is notified of a change related to a managed object, a message is queued for a full EMS refresh. There is never more than one EMS refresh operation in progress for each provider at any one time, with at most one further refresh queued.

If a new refresh is called for, the miq_queue table is first examined to see if a refresh message already exists in the "ready" state for the intended EMS. If no such message already exists, a new one is created. If a message already exists and it is for a full refresh, the new request is ignored.

As might be expected, the more managed objects in an OpenShift Container Platform cluster, the longer a full refresh takes to complete. Tests on an OpenShift Container Platform cluster containing 3000 pods (each with 1 container) and 3000 images have shown that a full refresh of a cluster of this size takes between 50 and 70 seconds, depending on master node and VMDB database activity.

The refresh time has a knock-on effect for the process or workflow that initiated the refresh. In most cases this is inconvenient but not critical, such as a delay in seeing a container’s status change in the WebUI. In other cases however - particularly when using an automate workflow - a very long EMS refresh may cause the triggering workflow to timeout and exit with an error condition.

A refresh operation has two significant phases that each contribute to the overall performance:

Fortunately the line printed to evm.log at the completion of the operation contains detailed timings of each stage of the operation, and these can be used to determine bottlenecks. A typical log line is as follows:

 ... MIQ(ManageIQ::Providers::Openshift::ContainerManager::Refresher#refresh) ⏎
 EMS: [OpenShift], id: [1000000000004] Refreshing targets for EMS...Complete ⏎
 - Timings { ⏎
 :collect_inventory_for_targets=>4.851187705993652, ⏎
 :parse_targeted_inventory=>4.859905481338501, ⏎
 :save_inventory=>5.751120328903198, ⏎
 :manager_refresh_post_processing=>1.8835067749023438e-05, ⏎
 :ems_refresh=>15.463248014450073}

The timing values are described as follows:

Extracting the timings^[10] from the log line shown above reveals the following performance values:

Refresh timings:
  collect_inventory_for_targets:       4.851188 seconds
  parse_targeted_inventory:            4.859905 seconds
  save_inventory:                      5.751120 seconds
  manager_refresh_post_processing:     0.000019 seconds
  ems_refresh:                         15.463248 seconds

This shows that two of the significant time components to this operation were extracting and parsing the inventory from the OpenShift Container Platform Master node (4.85 seconds), and loading the data into the database (5.75 seconds).

Refresh problems are best identified by establishing baseline timings when the managed OpenShift Container Platform cluster is least busy. To determine the relative data collection and database load times, the ':collect_inventory_for_targets' and ':save_inventory' timing counters from evm.log can be plotted. For this example the cfme-log-parsing/ems_refresh_timings.rb script is used, as follows:

ruby ~/git/cfme-log-parsing/ems_refresh_timings.rb ⏎
 -i evm.log -o ems_refresh_timings.out

grep collect_inventory_for_targets ems_refresh_timings.out | ⏎
awk '{print $2}' > parse_targeted_inventory.txt

grep save_inventory ems_refresh_timings.out | ⏎
awk '{print $2}' > save_inventory.txt

A significant increase or wide variation in data extraction times from this baseline can indicate that the master node is experiencing high load and not responding quickly to API requests.

Some variation in database load times throughout a 24 hour period is expected, but sustained periods of long load times can indicate that the database is overloaded.

There is little CloudForms tuning that can be done to improve the data extraction time of a refresh. If the extraction times vary significantly throughout the day then some investigation into the performance of the EMS itself may be warranted.

If database load times are high, then CPU, memory and I/O load on the database appliance should be investigated and if necessary tuned. The top_output.log and vmstat_output.log files in /var/www/miq/vmdb/log on the database appliance can be used to correlate the times of high CPU and memory demand against the long database load times.

:ems_refresh:
...
  :openshift:
    :refresh_interval: 15.minutes
    :inventory_object_refresh: true
    :inventory_collections:
      :saver_strategy: :batch
    :get_container_images: true
    :store_unused_images: true