From ade240b392563914c1bddc228a3eb00585177d4c Mon Sep 17 00:00:00 2001 From: Matt Riedemann Date: Wed, 29 Aug 2018 10:56:09 -0400 Subject: [PATCH] Add debug logs for when provider inventory changes Because of the ProviderTree caching involved in both the ResourceTracker and SchedulerReportClient, it can be hard to know if inventory changes are being correctly reported to the placement service as expected, especially with things like configurable allocation ratios. This adds debug logs to the SchedulerReportClient and ProviderTree to determine if inventory has changed and when it's flushed back to placement. Change-Id: Ia6ab3ab4dea08b479bb6b794f408fd2e6f678c50 Related-Bug: #1789654 --- nova/compute/provider_tree.py | 4 ++++ nova/scheduler/client/report.py | 17 ++++++++++++++--- 2 files changed, 18 insertions(+), 3 deletions(-) diff --git a/nova/compute/provider_tree.py b/nova/compute/provider_tree.py index 1f1de71a5f48..d101f65660b3 100644 --- a/nova/compute/provider_tree.py +++ b/nova/compute/provider_tree.py @@ -168,8 +168,12 @@ class _Provider(object): """ self._update_generation(generation, 'update_inventory') if self.has_inventory_changed(inventory): + LOG.debug('Updating inventory in ProviderTree for provider %s ' + 'with inventory: %s', self.uuid, inventory) self.inventory = copy.deepcopy(inventory) return True + LOG.debug('Inventory has not changed in ProviderTree for provider: %s', + self.uuid) return False def have_traits_changed(self, new): diff --git a/nova/scheduler/client/report.py b/nova/scheduler/client/report.py index 66c31b4a3892..ff5c11adc9f5 100644 --- a/nova/scheduler/client/report.py +++ b/nova/scheduler/client/report.py @@ -756,6 +756,9 @@ class SchedulerReportClient(object): if curr is None: return None + LOG.debug('Updating ProviderTree inventory for provider %s from ' + '_refresh_and_get_inventory using data: %s', rp_uuid, + curr['inventories']) self._provider_tree.update_inventory( rp_uuid, curr['inventories'], generation=curr['resource_provider_generation']) @@ -863,12 +866,15 @@ class SchedulerReportClient(object): # update_resource_stats() is called? :( curr = self._refresh_and_get_inventory(context, rp_uuid) if curr is None: + LOG.debug('No inventory for provider: %s', rp_uuid, inv_data) return False cur_gen = curr['resource_provider_generation'] # Check to see if we need to update placement's view if not self._provider_tree.has_inventory_changed(rp_uuid, inv_data): + LOG.debug('Inventory has not changed for provider %s based ' + 'on inventory data: %s', rp_uuid, inv_data) return True payload = { @@ -961,11 +967,11 @@ class SchedulerReportClient(object): # Update our view of the generation for next time updated_inventories_result = result.json() new_gen = updated_inventories_result['resource_provider_generation'] - + LOG.debug('Updating ProviderTree inventory for provider %s with ' + 'generation %s from _update_inventory_attempt with data: ' + '%s', rp_uuid, new_gen, inv_data) self._provider_tree.update_inventory(rp_uuid, inv_data, generation=new_gen) - LOG.debug('Updated inventory for %s at generation %i', - rp_uuid, new_gen) return True @safe_connect @@ -1110,6 +1116,8 @@ class SchedulerReportClient(object): # If not different from what we've got, short out if not self._provider_tree.has_inventory_changed(rp_uuid, inv_data): + LOG.debug('Inventory has not changed for provider %s based ' + 'on inventory data: %s', rp_uuid, inv_data) return # Ensure non-standard resource classes exist, creating them if needed. @@ -1125,6 +1133,9 @@ class SchedulerReportClient(object): resp = do_put(url, payload) if resp.status_code == 200: + LOG.debug('Updated inventory for provider %s with generation %s ' + 'in Placement from _set_inventory_for_provider using ' + 'data: %s', rp_uuid, generation, inv_data) json = resp.json() self._provider_tree.update_inventory( rp_uuid, json['inventories'],