commit 3148caa37ba406610ddb0187468107205581c105 Author: Damian Johnson atagar@torproject.org Date: Wed Apr 13 10:10:04 2016 -0700

Account for subcommands in nyx cpu usage

Shelling out to other commands isn't accounted for in os.times(). As such wrapping stem's call() function so shelling out is accounted for in the nyx cpu usage we show. --- nyx/panel/header.py | 53 ++++++++++++++++++++++++++++++++++++---------------- test/panel/header.py | 13 ++++++++++--- 2 files changed, 47 insertions(+), 19 deletions(-)

diff --git a/nyx/panel/header.py b/nyx/panel/header.py index 998a20d..f29d232 100644 --- a/nyx/panel/header.py +++ b/nyx/panel/header.py @@ -12,14 +12,17 @@ import time import threading

import stem +import stem.control +import stem.util.proc +import stem.util.str_tools +import stem.util.system

import nyx.controller import nyx.panel import nyx.popups import nyx.tracker

-from stem.control import Listener, State -from stem.util import conf, log, proc, str_tools, system +from stem.util import conf, log from nyx import msg, tor_controller

from nyx.curses import RED, GREEN, YELLOW, CYAN, WHITE, BOLD, HIGHLIGHT @@ -28,6 +31,13 @@ MIN_DUAL_COL_WIDTH = 141 # minimum width where we'll show two columns SHOW_FD_THRESHOLD = 60 # show file descriptor usage if usage is over this percentage UPDATE_RATE = 5 # rate in seconds at which we refresh

+# 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. + +SYSTEM_CALL_TIME = 0.0 +SYSTEM_CALL_TIME_LOCK = threading.RLock() +SYSTEM_CALL_ORIG = stem.util.system.call + CONFIG = conf.config_dict('nyx', { 'attr.flag_colors': {}, 'attr.version_status_colors': {}, @@ -35,6 +45,21 @@ CONFIG = conf.config_dict('nyx', { })

+def call_wrapper(*args, **kwargs): + global SYSTEM_CALL_TIME + + start_time = time.time() + + try: + return SYSTEM_CALL_ORIG(*args, **kwargs) + finally: + with SYSTEM_CALL_TIME_LOCK: + SYSTEM_CALL_TIME += time.time() - start_time + + +stem.util.system.call = call_wrapper + + class HeaderPanel(nyx.panel.Panel, threading.Thread): """ Top area containing tor settings and system information. @@ -232,7 +257,7 @@ class HeaderPanel(nyx.panel.Panel, threading.Thread): def reset_listener(self, controller, event_type, _): self._update()

- if event_type == State.CLOSED: + if event_type == stem.control.State.CLOSED: log.notice('Tor control port closed')

def _update(self): @@ -282,10 +307,10 @@ class Sampling(object):

pid = controller.get_pid('') tor_resources = nyx.tracker.get_resource_tracker().get_value() - nyx_total_cpu_time = sum(os.times()[:3]) + nyx_total_cpu_time = sum(os.times()[:3], SYSTEM_CALL_TIME)

- or_listeners = controller.get_listeners(Listener.OR, []) - control_listeners = controller.get_listeners(Listener.CONTROL, []) + or_listeners = controller.get_listeners(stem.control.Listener.OR, []) + control_listeners = controller.get_listeners(stem.control.Listener.CONTROL, [])

if controller.get_conf('HashedControlPassword', None): auth_type = 'password' @@ -295,18 +320,14 @@ class Sampling(object): auth_type = 'open'

try: - fd_used = proc.file_descriptors_used(pid) + fd_used = stem.util.proc.file_descriptors_used(pid) except IOError: fd_used = None

if last_sampling: nyx_cpu_delta = nyx_total_cpu_time - last_sampling.nyx_total_cpu_time nyx_time_delta = retrieved - last_sampling.retrieved - - python_cpu_time = nyx_cpu_delta / nyx_time_delta - sys_call_cpu_time = 0.0 # TODO: add a wrapper around call() to get this - - nyx_cpu = python_cpu_time + sys_call_cpu_time + nyx_cpu = nyx_cpu_delta / nyx_time_delta else: nyx_cpu = 0.0

@@ -334,14 +355,14 @@ class Sampling(object):

'auth_type': auth_type, 'pid': pid, - 'start_time': system.start_time(pid), + 'start_time': stem.util.system.start_time(pid), 'fd_limit': int(controller.get_info('process/descriptor-limit', '-1')), 'fd_used': fd_used,

'nyx_total_cpu_time': nyx_total_cpu_time, 'tor_cpu': '%0.1f' % (100 * tor_resources.cpu_sample), 'nyx_cpu': '%0.1f' % (nyx_cpu), - 'memory': str_tools.size_label(tor_resources.memory_bytes) if tor_resources.memory_bytes > 0 else 0, + 'memory': stem.util.str_tools.size_label(tor_resources.memory_bytes) if tor_resources.memory_bytes > 0 else 0, 'memory_percent': '%0.1f' % (100 * tor_resources.memory_percent),

'hostname': os.uname()[1], @@ -354,7 +375,7 @@ class Sampling(object): formatted_msg = message.format(**self._attr)

if crop_width is not None: - formatted_msg = str_tools.crop(formatted_msg, crop_width) + formatted_msg = stem.util.str_tools.crop(formatted_msg, crop_width)

return formatted_msg

@@ -444,7 +465,7 @@ def _draw_resource_usage(subwindow, x, y, width, vals, pause_time): else: now = time.time()

- uptime = str_tools.short_time_label(now - vals.start_time) + uptime = stem.util.str_tools.short_time_label(now - vals.start_time) else: uptime = ''

diff --git a/test/panel/header.py b/test/panel/header.py index 7ea2510..6e0f275 100644 --- a/test/panel/header.py +++ b/test/panel/header.py @@ -5,10 +5,12 @@ Unit tests for nyx.panel.header. import time import unittest

-import nyx.panel.header import stem.control import stem.exit_policy import stem.version +import stem.util.system + +import nyx.panel.header import test

from test import require_curses @@ -16,13 +18,18 @@ from mock import patch, Mock

class TestHeader(unittest.TestCase): + def test_system_call_time_tracked(self): + initial = nyx.panel.header.SYSTEM_CALL_TIME + stem.util.system.call('sleep 0.5') + self.assertTrue(nyx.panel.header.SYSTEM_CALL_TIME - initial > 0.4) + @patch('nyx.panel.header.tor_controller') @patch('nyx.tracker.get_resource_tracker') @patch('time.time', Mock(return_value = 1234.5)) @patch('os.times', Mock(return_value = (0.08, 0.03, 0.0, 0.0, 18759021.31))) @patch('os.uname', Mock(return_value = ('Linux', 'odin', '3.5.0-54-generic', '#81~precise1-Ubuntu SMP Tue Jul 15 04:05:58 UTC 2014', 'i686'))) - @patch('nyx.panel.header.system.start_time', Mock(return_value = 5678)) - @patch('nyx.panel.header.proc.file_descriptors_used', Mock(return_value = 89)) + @patch('stem.util.system.start_time', Mock(return_value = 5678)) + @patch('stem.util.proc.file_descriptors_used', Mock(return_value = 89)) def test_sample(self, resource_tracker_mock, tor_controller_mock): tor_controller_mock().is_alive.return_value = True tor_controller_mock().connection_time.return_value = 567.8