commit de2e0e3a40b5f01af94bf3093e9cc06b85058789 Author: Damian Johnson <atagar@torproject.org> Date: Sat Apr 16 11:43:24 2016 -0700 Add SYSTEM_CALL_TIME to the stem.util.system module Nyx needs the ability to determine how much time is spent on subcommands so we can account for those in our 'nyx cpu usage'. On reflection other applications using os.times() will need this too - easy addition. --- docs/change_log.rst | 1 + stem/util/system.py | 19 ++++++++++++++++++- test/integ/util/system.py | 9 +++++++++ 3 files changed, 28 insertions(+), 1 deletion(-) diff --git a/docs/change_log.rst b/docs/change_log.rst index 1c6f491..13824b2 100644 --- a/docs/change_log.rst +++ b/docs/change_log.rst @@ -84,6 +84,7 @@ The following are only available within Stem's `git repository * Recognize IPv4-mapped IPv6 addresses in our utils (:trac:`18079`) * Allow :func:`stem.util.conf.Config.set` to remove values when provided with a **None** value * Additional information when :func:`~stem.util.system.call` fails through a :class:`~stem.util.system.CallError` + * Added **stem.util.system.SYSTEM_CALL_TIME** with the total time spent on system calls * Added an **is_ipv6** value to :class:`~stem.util.connection.Connection` instances * Added :func:`~stem.util.system.pids_by_user` * Added :func:`~stem.util.__init__.datetime_to_unix` diff --git a/stem/util/system.py b/stem/util/system.py index b9baa28..5ef61c6 100644 --- a/stem/util/system.py +++ b/stem/util/system.py @@ -10,6 +10,10 @@ best-effort, providing **None** if the lookup fails. Dropped the get_* prefix from several function names. The old names still work, but are deprecated aliases. +.. versionchanged:: 1.5.0 + Added the **SYSTEM_CALL_TIME** global, which tracks total time spent making + system commands. + **Module Overview:** :: @@ -52,6 +56,7 @@ import platform import re import subprocess import tarfile +import threading import time import stem.util.proc @@ -127,6 +132,13 @@ _PROCESS_NAME = None _MAX_NAME_LENGTH = -1 +# Tracks total time spent shelling out to other commands like 'ps' and +# 'netstat', so we can account for it as part of our cpu time along with +# os.times(). + +SYSTEM_CALL_TIME = 0.0 +SYSTEM_CALL_TIME_LOCK = threading.RLock() + class CallError(OSError): """ @@ -1035,17 +1047,19 @@ def call(command, default = UNDEFINED, ignore_exit_status = False, env = None): **OSError** subclass """ + global SYSTEM_CALL_TIME + if isinstance(command, str): command_list = command.split(' ') else: command_list = command exit_status, runtime, stdout, stderr = None, None, None, None + start_time = time.time() try: is_shell_command = command_list[0] in SHELL_COMMANDS - start_time = time.time() process = subprocess.Popen(command_list, stdout = subprocess.PIPE, stderr = subprocess.PIPE, shell = is_shell_command, env = env) stdout, stderr = process.communicate() @@ -1078,6 +1092,9 @@ def call(command, default = UNDEFINED, ignore_exit_status = False, env = None): return default else: raise CallError(str(exc), ' '.join(command_list), exit_status, runtime, stdout, stderr) + finally: + with SYSTEM_CALL_TIME_LOCK: + SYSTEM_CALL_TIME += time.time() - start_time def get_process_name(): diff --git a/test/integ/util/system.py b/test/integ/util/system.py index 3207f9d..7933492 100644 --- a/test/integ/util/system.py +++ b/test/integ/util/system.py @@ -563,6 +563,15 @@ class TestSystem(unittest.TestCase): self.assertEqual(home_dir, stem.util.system.expand_path('~%s' % username)) self.assertEqual(os.path.join(home_dir, 'foo'), stem.util.system.expand_path('~%s/foo' % username)) + def test_call_time_tracked(self): + """ + Check that time taken in the call() function is tracked by SYSTEM_CALL_TIME. + """ + + initial = stem.util.system.SYSTEM_CALL_TIME + stem.util.system.call('sleep 0.5') + self.assertTrue(stem.util.system.SYSTEM_CALL_TIME - initial > 0.4) + def test_set_process_name(self): """ Exercises the get_process_name() and set_process_name() methods.