Commit 6b6d7306 authored by Alain Takoudjou's avatar Alain Takoudjou

use profile to log promises resource consumption

parent c49161fb
...@@ -630,7 +630,7 @@ stderr_logfile_backups=1 ...@@ -630,7 +630,7 @@ stderr_logfile_backups=1
promise_dir = os.path.join(instance_path, 'etc', 'promise') promise_dir = os.path.join(instance_path, 'etc', 'promise')
if not checkPromiseList(promise_dir, self.promise_timeout, uid=uid, gid=gid, if not checkPromiseList(promise_dir, self.promise_timeout, uid=uid, gid=gid,
cwd=instance_path, logger=self.logger, profile=True, cwd=instance_path, logger=self.logger, profile=False,
raise_on_failure=True): raise_on_failure=True):
self.logger.info("No promise.") self.logger.info("No promise.")
......
...@@ -38,6 +38,7 @@ import subprocess ...@@ -38,6 +38,7 @@ import subprocess
import sys import sys
import logging import logging
import time import time
import psutil
from datetime import datetime from datetime import datetime
from slapos.grid.exception import BuildoutFailedError, WrongPermissionError from slapos.grid.exception import BuildoutFailedError, WrongPermissionError
...@@ -370,7 +371,7 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None, ...@@ -370,7 +371,7 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None,
""" """
Check a promise list and return the result or raise in case of failure Check a promise list and return the result or raise in case of failure
if `raise_on_failure` is set to True if `raise_on_failure` is set to True
When `profile` is set to True, log each promise execution duration. When `profile` is set to True, log each promise resource usage.
""" """
if logger is None: if logger is None:
logging.basicConfig(format="%(asctime)s - %(levelname)s - %(message)s") logging.basicConfig(format="%(asctime)s - %(levelname)s - %(message)s")
...@@ -415,9 +416,27 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None, ...@@ -415,9 +416,27 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None,
# Check if the promise finished every tenth of second, # Check if the promise finished every tenth of second,
# but timeout after promise_timeout. # but timeout after promise_timeout.
sleep_time = 0.1 sleep_time = 0.1
check_profile = False
if profile:
try:
psutil_process = psutil.Process(process_handler.pid)
check_profile = True
except psutil.NoSuchProcess:
# process is gone
pass
increment_limit = int(promise_timeout / sleep_time) increment_limit = int(promise_timeout / sleep_time)
for current_increment in range(0, increment_limit): for current_increment in range(0, increment_limit):
if process_handler.poll() is None: if process_handler.poll() is None:
if check_profile:
logger.debug(
"CPU: %s%%, MEMORY: %s MB (%s%%), DISK: %s Read - %s Write" % (
psutil_process.cpu_percent(),
psutil_process.memory_info().rss / float(2 ** 20),
round(psutil_process.memory_percent(), 4),
psutil_process.io_counters().read_count,
psutil_process.io_counters().write_count
)
)
time.sleep(sleep_time) time.sleep(sleep_time)
continue continue
result_dict["execution-time"] = current_increment * sleep_time result_dict["execution-time"] = current_increment * sleep_time
...@@ -450,9 +469,7 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None, ...@@ -450,9 +469,7 @@ def checkPromiseList(promise_dir, promise_timeout, uid=None, gid=None, cwd=None,
result_dict["execution-time"] = current_increment * sleep_time result_dict["execution-time"] = current_increment * sleep_time
promise_result_list.append(result_dict) promise_result_list.append(result_dict)
logger.info("Finished promise %r in %s second(s)." % (
if profile: promise, result_dict["execution-time"]))
logger.info("Finished promise %r in %s second(s)." % (
promise, result_dict["execution-time"]))
return promise_result_list return promise_result_list
Markdown is supported
0%
or
You are about to add 0 people to the discussion. Proceed with caution.
Finish editing this message first!
Please register or to comment