diff --git a/zuul/driver/bubblewrap/__init__.py b/zuul/driver/bubblewrap/__init__.py index 1566f8515d..52db3fc53a 100644 --- a/zuul/driver/bubblewrap/__init__.py +++ b/zuul/driver/bubblewrap/__init__.py @@ -19,6 +19,7 @@ import fcntl import grp import logging import os +import psutil import pwd import shlex import subprocess @@ -52,7 +53,7 @@ class WrappedPopen(object): if fd not in pass_fds: pass_fds.append(fd) kwargs['pass_fds'] = pass_fds - proc = subprocess.Popen(args, *sub_args, **kwargs) + proc = psutil.Popen(args, *sub_args, **kwargs) finally: self.__del__() return proc diff --git a/zuul/driver/nullwrap/__init__.py b/zuul/driver/nullwrap/__init__.py index 178e4c7fcc..2e8f4c1160 100644 --- a/zuul/driver/nullwrap/__init__.py +++ b/zuul/driver/nullwrap/__init__.py @@ -15,7 +15,7 @@ # under the License. import logging -import subprocess +import psutil from zuul.driver import (Driver, WrapperInterface) from zuul.execution_context import BaseExecutionContext @@ -25,7 +25,7 @@ class NullExecutionContext(BaseExecutionContext): log = logging.getLogger("zuul.NullExecutionContext") def getPopen(self, **kwargs): - return subprocess.Popen + return psutil.Popen class NullwrapDriver(Driver, WrapperInterface): diff --git a/zuul/executor/server.py b/zuul/executor/server.py index 535ce70f3f..237a70f41c 100644 --- a/zuul/executor/server.py +++ b/zuul/executor/server.py @@ -636,6 +636,9 @@ class AnsibleJob(object): self.executor_variables_file = None + self.cpu_times = {'user': 0, 'system': 0, + 'children_user': 0, 'children_system': 0} + if self.executor_server.config.has_option('executor', 'variables'): self.executor_variables_file = self.executor_server.config.get( 'executor', 'variables') @@ -952,6 +955,13 @@ class AnsibleJob(object): pre_failed = True break + self.log.debug( + "Overall ansible cpu times: user=%.2f, system=%.2f, " + "children_user=%.2f, children_system=%.2f" % + (self.cpu_times['user'], self.cpu_times['system'], + self.cpu_times['children_user'], + self.cpu_times['children_system'])) + if not pre_failed: ansible_timeout = self.getAnsibleTimeout(time_started, job_timeout) job_status, job_code = self.runAnsiblePlaybook( @@ -1575,6 +1585,17 @@ class AnsibleJob(object): line = line[:1024].rstrip() self.log.debug("Ansible output: %s" % (line,)) self.log.debug("Ansible output terminated") + cpu_times = self.proc.cpu_times() + self.log.debug("Ansible cpu times: user=%.2f, system=%.2f, " + "children_user=%.2f, " + "children_system=%.2f" % + (cpu_times.user, cpu_times.system, + cpu_times.children_user, + cpu_times.children_system)) + self.cpu_times['user'] += cpu_times.user + self.cpu_times['system'] += cpu_times.system + self.cpu_times['children_user'] += cpu_times.children_user + self.cpu_times['children_system'] += cpu_times.children_system ret = self.proc.wait() self.log.debug("Ansible exit code: %s" % (ret,)) finally: