cloud-init-dev team mailing list archive

[Ryan Harper <ryan.harper@xxxxxxxxxxxxx>]

Ryan Harper has proposed merging ~raharper/cloud-init:fix/azure-ds-activate-events into cloud-init:master.

Commit message:
Add reporting events and log_time around early source of blocking time
    
In looking at some boot time for Xenial, Artful and Bionic, we noticed
some long amounts of time that appeared to be part of the DataSource
but we related to resolving URLs. In Artful and Bionic, there was an
issue (bug: #1739672) that resulted in slow getaddrinfo() calls when
systemd-resolved was in use.  This patch adds two events that track
time for datasource.setup_datasource() and datasource.activate_datasource()
Additionally use log_time() to wrapper util.is_resolvable_url() which
leaves info in cloud-init.log about how much time was spent.


Requested reviews:
  cloud-init commiters (cloud-init-dev)

For more details, see:
https://code.launchpad.net/~raharper/cloud-init/+git/cloud-init/+merge/343123
-- 
Your team cloud-init commiters is requested to review the proposed merge of ~raharper/cloud-init:fix/azure-ds-activate-events into cloud-init:master.

diff --git a/cloudinit/stages.py b/cloudinit/stages.py
index bc4ebc8..3998cf6 100644
--- a/cloudinit/stages.py
+++ b/cloudinit/stages.py
@@ -362,16 +362,22 @@ class Init(object):
         self._store_vendordata()
 
     def setup_datasource(self):
-        if self.datasource is None:
-            raise RuntimeError("Datasource is None, cannot setup.")
-        self.datasource.setup(is_new_instance=self.is_new_instance())
+        with events.ReportEventStack("setup-datasource",
+                                     "setting up datasource",
+                                     parent=self.reporter):
+            if self.datasource is None:
+                raise RuntimeError("Datasource is None, cannot setup.")
+            self.datasource.setup(is_new_instance=self.is_new_instance())
 
     def activate_datasource(self):
-        if self.datasource is None:
-            raise RuntimeError("Datasource is None, cannot activate.")
-        self.datasource.activate(cfg=self.cfg,
-                                 is_new_instance=self.is_new_instance())
-        self._write_to_cache()
+        with events.ReportEventStack("activate-datasource",
+                                     "activating datasource",
+                                     parent=self.reporter):
+            if self.datasource is None:
+                raise RuntimeError("Datasource is None, cannot activate.")
+            self.datasource.activate(cfg=self.cfg,
+                                     is_new_instance=self.is_new_instance())
+            self._write_to_cache()
 
     def _store_userdata(self):
         raw_ud = self.datasource.get_userdata_raw()
diff --git a/cloudinit/util.py b/cloudinit/util.py
index acdc0d8..8ee71b2 100644
--- a/cloudinit/util.py
+++ b/cloudinit/util.py
@@ -1154,7 +1154,9 @@ def gethostbyaddr(ip):
 
 def is_resolvable_url(url):
     """determine if this url is resolvable (existing or ip)."""
-    return is_resolvable(urlparse.urlparse(url).hostname)
+    return log_time(logfunc=LOG.debug, msg="Resolving URL: " + url,
+                    func=is_resolvable,
+                    args=(urlparse.urlparse(url).hostname,))
 
 
 def search_for_mirror(candidates):