From 4bd5870f62df771f2a346b0003fd03e44d7fac19 Mon Sep 17 00:00:00 2001 From: Ryan Harper Date: Mon, 30 Apr 2018 08:27:22 -0600 Subject: 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. --- cloudinit/stages.py | 22 ++++++++++++++-------- cloudinit/util.py | 4 +++- 2 files changed, 17 insertions(+), 9 deletions(-) (limited to 'cloudinit') diff --git a/cloudinit/stages.py b/cloudinit/stages.py index bc4ebc85..3998cf68 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 2828ca38..fc30018c 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): -- cgit v1.2.3