Add logging for failed realization

Change-Id: Ia721d46272d3dca67bb2ba09bce6977dec886495

vmware_nsxlib/tests/unit/v3/test_resources.py

@@ -1790,7 +1790,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             user_tags = [{'scope': 'user', 'tag': 'k8s'}]
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_scope_only(self):
         """Test search of resources with the specified tag."""
@@ -1798,7 +1798,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             user_tags = [{'scope': 'user'}]
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_tag_only(self):
         """Test search of resources with the specified tag."""
@@ -1806,7 +1806,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             user_tags = [{'tag': 'k8s'}]
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_with_extra_attribute(self):
         """Test search of resource with specified tags and one attribute."""
@@ -1815,7 +1815,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             query = "%s AND %s" % (self.nsxlib._build_query(tags=user_tags),
                                    'marked_for_delete:False')
             self.nsxlib.search_by_tags(tags=user_tags, marked_for_delete=False)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_with_multi_attributes(self):
         """Test search of resource with tags and multiple attributes."""
@@ -1825,7 +1825,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
                                    'tea:boo AND coffee:False')
             self.nsxlib.search_by_tags(
                 tags=user_tags, tea='boo', coffee=False)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_by_resouce_type_and_attributes(self):
         with mock.patch.object(self.nsxlib.client, 'url_get') as search:
@@ -1868,7 +1868,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             user_tags = [{'tag': 'k8s'}, {'scope': 'user'}]
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_and_resource_type(self):
         """Test search of specified resource with the specified tag."""
@@ -1879,7 +1879,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             # Add resource_type to the query
             query = "resource_type:%s AND %s" % (res_type, query)
             self.nsxlib.search_by_tags(tags=user_tags, resource_type=res_type)
-            search.assert_called_with(self.search_path % query)
+            search.assert_called_with(self.search_path % query, silent=False)
 
     def test_nsx_search_tags_and_cursor(self):
         """Test search of resources with the specified tag and cursor."""
@@ -1888,7 +1888,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags, cursor=50)
             search.assert_called_with(
-                (self.search_path + '&cursor=50') % query)
+                (self.search_path + '&cursor=50') % query, silent=False)
 
     def test_nsx_search_tags_and_page_size(self):
         """Test search of resources with the specified tag and page size."""
@@ -1897,7 +1897,7 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             query = self.nsxlib._build_query(tags=user_tags)
             self.nsxlib.search_by_tags(tags=user_tags, page_size=100)
             search.assert_called_with(
-                (self.search_path + '&page_size=100') % query)
+                (self.search_path + '&page_size=100') % query, silent=False)
 
     def test_nsx_search_invalid_query_fail(self):
         """Test search query failure for missing tag argument."""
@@ -1946,8 +1946,9 @@ class TestNsxSearch(nsxlib_testcase.NsxClientTestCase):
             query = self.nsxlib._build_query(tags=user_tags)
             results = self.nsxlib.search_all_by_tags(tags=user_tags)
             search.assert_has_calls([
-                mock.call(self.search_path % query),
-                mock.call((self.search_path + '&cursor=2') % query)])
+                mock.call(self.search_path % query, silent=False),
+                mock.call((self.search_path + '&cursor=2') % query,
+                          silent=False)])
             self.assertEqual(3, len(results))
 
     @mock.patch("vmware_nsxlib.v3.lib.NsxLibBase._search_all")

vmware_nsxlib/v3/lib.py

@@ -127,7 +127,7 @@ class NsxLibBase(object):
     # TODO(abhiraut): Revisit this method to generate complex boolean
     #                 queries to search resources.
     def search_by_tags(self, tags, resource_type=None, cursor=None,
-                       page_size=None, **extra_attrs):
+                       page_size=None, silent=False, **extra_attrs):
         """Return the list of resources searched based on tags.
 
         Currently the query only supports AND boolean operator.
@@ -139,6 +139,7 @@ class NsxLibBase(object):
         :param cursor: Opaque cursor to be used for getting next page of
                        records (supplied by current result page).
         :param page_size: Maximum number of results to return in this page.
+        :param silent: Silence the logging if True.
         :param extra_attrs: Support querying by user specified attributes.
                             Multiple attributes will be ANDed.
         """
@@ -162,7 +163,7 @@ class NsxLibBase(object):
         @utils.retry_upon_exception(exceptions.NsxSearchError,
                                     max_attempts=self.client.max_attempts)
         def do_search(url):
-            return self.client.url_get(url)
+            return self.client.url_get(url, silent=silent)
 
         return do_search(url)
 

vmware_nsxlib/v3/policy/core_resources.py

@@ -258,6 +258,7 @@ class NsxPolicyResourceBase(object):
             sleep = self.nsxlib_config.realization_wait_sec
         if max_attempts is None:
             max_attempts = self.nsxlib_config.realization_max_attempts
+        info = {}
 
         @utils.retry_upon_none_result(max_attempts, delay=sleep, random=True)
         def get_info():
@@ -281,6 +282,10 @@ class NsxPolicyResourceBase(object):
             raise e
         except Exception:
             # max retries reached
+            LOG.error("_wait_until_realized maxed-out for "
+                      "resource: %s. Last realization info was %s",
+                      resource_def.get_resource_full_path(), info)
+
             raise exceptions.RealizationTimeoutError(
                 resource_type=resource_def.resource_type(),
                 resource_id=resource_def.get_id(),
@@ -291,7 +296,7 @@ class NsxPolicyResourceBase(object):
                                      sleep=None, max_attempts=None,
                                      with_refresh=False):
         res_path = res_def.get_resource_full_path()
-
+        state = {}
         if sleep is None:
             sleep = self.nsxlib_config.realization_wait_sec
         if max_attempts is None:
@@ -307,6 +312,9 @@ class NsxPolicyResourceBase(object):
                 if con_state == 'SUCCESS':
                     return True
                 if con_state == 'ERROR':
+                    LOG.error("_wait_until_state_successful errored for "
+                              "resource: %s. Last consolidated_status result "
+                              "was %s", res_path, state)
                     raise exceptions.RealizationErrorStateError(
                         resource_type=res_def.resource_type(),
                         resource_id=res_def.get_id(),
@@ -323,6 +331,10 @@ class NsxPolicyResourceBase(object):
             raise e
         except Exception:
             # max retries reached
+            LOG.error("_wait_until_state_successful maxed-out for "
+                      "resource: %s. Last consolidated_status result was %s",
+                      res_path, state)
+
             raise exceptions.RealizationTimeoutError(
                 resource_type=res_def.resource_type(),
                 resource_id=res_def.get_id(),
@@ -332,7 +344,7 @@ class NsxPolicyResourceBase(object):
     @check_allowed_passthrough
     def _get_realized_id_using_search(self, policy_resource_path,
                                       mp_resource_type, resource_def=None,
-                                      entity_type=None,
+                                      entity_type=None, silent=False,
                                       sleep=None, max_attempts=None):
         """Wait until the policy path will be found using search api
 
@@ -346,12 +358,13 @@ class NsxPolicyResourceBase(object):
 
         tag = [{'scope': 'policyPath',
                 'tag': utils.escape_tag_data(policy_resource_path)}]
-
+        resources = []
         test_num = 0
         while test_num < max_attempts:
             # Use the search api to find the realization id of this entity.
             resources = self.nsx_api.search_by_tags(
-                tags=tag, resource_type=mp_resource_type)['results']
+                tags=tag, resource_type=mp_resource_type,
+                silent=silent)['results']
             if resources:
                 # If status exists, make sure the state is successful
                 if (not resources[0].get('status') or
@@ -366,6 +379,9 @@ class NsxPolicyResourceBase(object):
                 if info and info['state'] == constants.STATE_ERROR:
                     error_msg, error_code, related_error_codes = \
                         self._get_realization_error_message_and_code(info)
+                    LOG.error("_get_realized_id_using_search Failed for "
+                              "resource: %s. Got error in realization info %s",
+                              policy_resource_path, info)
                     raise exceptions.RealizationErrorStateError(
                         resource_type=resource_def.resource_type(),
                         resource_id=resource_def.get_id(),
@@ -381,6 +397,10 @@ class NsxPolicyResourceBase(object):
             test_num += 1
 
         # max retries reached
+        LOG.error("_get_realized_id_using_search maxed-out for "
+                  "resource: %s. Last search result was %s",
+                  policy_resource_path, resources)
+
         raise exceptions.RealizationTimeoutError(
             resource_type=mp_resource_type,
             resource_id=policy_resource_path,