From 89bcef70e412de214cbe937829166f3662d6d575 Mon Sep 17 00:00:00 2001 From: Felix Ruess Date: Mon, 3 Apr 2017 16:14:33 +0200 Subject: [PATCH] use monotonic time for delays, etc. --- supervisor/monotonic.py | 166 +++++++++++++++++++++++++++ supervisor/process.py | 20 ++-- supervisor/scripts/loop_eventgen.py | 6 +- supervisor/supervisord.py | 5 +- supervisor/tests/test_process.py | 13 ++- supervisor/tests/test_supervisord.py | 3 +- 6 files changed, 193 insertions(+), 20 deletions(-) create mode 100644 supervisor/monotonic.py diff --git a/supervisor/monotonic.py b/supervisor/monotonic.py new file mode 100644 index 000000000..99d5d60fd --- /dev/null +++ b/supervisor/monotonic.py @@ -0,0 +1,166 @@ +# -*- coding: utf-8 -*- +""" + monotonic + ~~~~~~~~~ + + This module provides a ``monotonic()`` function which returns the + value (in fractional seconds) of a clock which never goes backwards. + + On Python 3.3 or newer, ``monotonic`` will be an alias of + ``time.monotonic`` from the standard library. On older versions, + it will fall back to an equivalent implementation: + + +-------------+----------------------------------------+ + | Linux, BSD | ``clock_gettime(3)`` | + +-------------+----------------------------------------+ + | Windows | ``GetTickCount`` or ``GetTickCount64`` | + +-------------+----------------------------------------+ + | OS X | ``mach_absolute_time`` | + +-------------+----------------------------------------+ + + If no suitable implementation exists for the current platform, + attempting to import this module (or to import from it) will + cause a ``RuntimeError`` exception to be raised. + + + Copyright 2014, 2015, 2016 Ori Livneh + + Licensed under the Apache License, Version 2.0 (the "License"); + you may not use this file except in compliance with the License. + You may obtain a copy of the License at + + http://www.apache.org/licenses/LICENSE-2.0 + + Unless required by applicable law or agreed to in writing, software + distributed under the License is distributed on an "AS IS" BASIS, + WITHOUT WARRANTIES OR CONDITIONS OF ANY KIND, either express or implied. + See the License for the specific language governing permissions and + limitations under the License. + +""" +import ctypes +import ctypes.util +import os +import sys +import threading +import time + + +try: + monotonic = time.monotonic +except AttributeError: + try: + if sys.platform == 'darwin': # OS X, iOS + # See Technical Q&A QA1398 of the Mac Developer Library: + # + libc = ctypes.CDLL('/usr/lib/libc.dylib', use_errno=True) + + class mach_timebase_info_data_t(ctypes.Structure): + """System timebase info. Defined in .""" + _fields_ = (('numer', ctypes.c_uint32), + ('denom', ctypes.c_uint32)) + + mach_absolute_time = libc.mach_absolute_time + mach_absolute_time.restype = ctypes.c_uint64 + + timebase = mach_timebase_info_data_t() + libc.mach_timebase_info(ctypes.byref(timebase)) + ticks_per_second = timebase.numer / timebase.denom * 1.0e9 + + def monotonic(): + """Monotonic clock, cannot go backward.""" + return mach_absolute_time() / ticks_per_second + + elif sys.platform.startswith('win32') or sys.platform.startswith('cygwin'): + if sys.platform.startswith('cygwin'): + # Note: cygwin implements clock_gettime (CLOCK_MONOTONIC = 4) since + # version 1.7.6. Using raw WinAPI for maximum version compatibility. + + # Ugly hack using the wrong calling convention (in 32-bit mode) + # because ctypes has no windll under cygwin (and it also seems that + # the code letting you select stdcall in _ctypes doesn't exist under + # the preprocessor definitions relevant to cygwin). + # This is 'safe' because: + # 1. The ABI of GetTickCount and GetTickCount64 is identical for + # both calling conventions because they both have no parameters. + # 2. libffi masks the problem because after making the call it doesn't + # touch anything through esp and epilogue code restores a correct + # esp from ebp afterwards. + try: + kernel32 = ctypes.cdll.kernel32 + except OSError: # 'No such file or directory' + kernel32 = ctypes.cdll.LoadLibrary('kernel32.dll') + else: + kernel32 = ctypes.windll.kernel32 + + GetTickCount64 = getattr(kernel32, 'GetTickCount64', None) + if GetTickCount64: + # Windows Vista / Windows Server 2008 or newer. + GetTickCount64.restype = ctypes.c_ulonglong + + def monotonic(): + """Monotonic clock, cannot go backward.""" + return GetTickCount64() / 1000.0 + + else: + # Before Windows Vista. + GetTickCount = kernel32.GetTickCount + GetTickCount.restype = ctypes.c_uint32 + + get_tick_count_lock = threading.Lock() + get_tick_count_last_sample = 0 + get_tick_count_wraparounds = 0 + + def monotonic(): + """Monotonic clock, cannot go backward.""" + global get_tick_count_last_sample + global get_tick_count_wraparounds + + with get_tick_count_lock: + current_sample = GetTickCount() + if current_sample < get_tick_count_last_sample: + get_tick_count_wraparounds += 1 + get_tick_count_last_sample = current_sample + + final_milliseconds = get_tick_count_wraparounds << 32 + final_milliseconds += get_tick_count_last_sample + return final_milliseconds / 1000.0 + + else: + try: + clock_gettime = ctypes.CDLL(ctypes.util.find_library('c'), + use_errno=True).clock_gettime + except AttributeError: + clock_gettime = ctypes.CDLL(ctypes.util.find_library('rt'), + use_errno=True).clock_gettime + + class timespec(ctypes.Structure): + """Time specification, as described in clock_gettime(3).""" + _fields_ = (('tv_sec', ctypes.c_long), + ('tv_nsec', ctypes.c_long)) + + if sys.platform.startswith('linux'): + CLOCK_MONOTONIC = 1 + elif sys.platform.startswith('freebsd'): + CLOCK_MONOTONIC = 4 + elif sys.platform.startswith('sunos5'): + CLOCK_MONOTONIC = 4 + elif 'bsd' in sys.platform: + CLOCK_MONOTONIC = 3 + elif sys.platform.startswith('aix'): + CLOCK_MONOTONIC = ctypes.c_longlong(10) + + def monotonic(): + """Monotonic clock, cannot go backward.""" + ts = timespec() + if clock_gettime(CLOCK_MONOTONIC, ctypes.pointer(ts)): + errno = ctypes.get_errno() + raise OSError(errno, os.strerror(errno)) + return ts.tv_sec + ts.tv_nsec / 1.0e9 + + # Perform a sanity-check. + if monotonic() - monotonic() > 0: + raise ValueError('monotonic() is not monotonic!') + + except Exception: + raise RuntimeError('no suitable implementation for this system') diff --git a/supervisor/process.py b/supervisor/process.py index e2fef5b70..a5804536c 100644 --- a/supervisor/process.py +++ b/supervisor/process.py @@ -28,6 +28,8 @@ from supervisor.socket_manager import SocketManager +from supervisor.monotonic import monotonic + @total_ordering class Subprocess(object): @@ -169,7 +171,7 @@ def change_state(self, new_state, expected=True): events.notify(event) if new_state == ProcessStates.BACKOFF: - now = time.time() + now = monotonic() self.backoff += 1 self.delay = now + self.backoff @@ -204,7 +206,7 @@ def spawn(self): self.system_stop = False self.administrative_stop = False - self.laststart = time.time() + self.laststart = monotonic() self._assertInState(ProcessStates.EXITED, ProcessStates.FATAL, ProcessStates.BACKOFF, ProcessStates.STOPPED) @@ -265,7 +267,7 @@ def _spawn_as_parent(self, pid): options.close_child_pipes(self.pipes) options.logger.info('spawned: %r with pid %s' % (self.config.name, pid)) self.spawnerr = None - self.delay = time.time() + self.config.startsecs + self.delay = monotonic() + self.config.startsecs options.pidhistory[pid] = self return pid @@ -360,7 +362,7 @@ def stop(self): def stop_report(self): """ Log a 'waiting for x to stop' message with throttling. """ if self.state == ProcessStates.STOPPING: - now = time.time() + now = monotonic() if now > (self.laststopreport + 2): # every 2 seconds self.config.options.logger.info( 'waiting for %s to stop' % self.config.name) @@ -379,7 +381,7 @@ def kill(self, sig): Return None if the signal was sent, or an error message string if an error occurred or if the subprocess is not running. """ - now = time.time() + now = monotonic() options = self.config.options # If the process is in BACKOFF and we want to stop or kill it, then @@ -490,7 +492,7 @@ def finish(self, pid, sts): es, msg = decode_wait_status(sts) - now = time.time() + now = monotonic() self.laststop = now processname = self.config.name @@ -590,7 +592,7 @@ def get_state(self): return self.state def transition(self): - now = time.time() + now = monotonic() state = self.state logger = self.config.options.logger @@ -818,7 +820,7 @@ def transition(self): dispatch_capable = True if dispatch_capable: if self.dispatch_throttle: - now = time.time() + now = monotonic() if now - self.last_dispatch < self.dispatch_throttle: return self.dispatch() @@ -833,7 +835,7 @@ def dispatch(self): # to process any further events in the buffer self._acceptEvent(event, head=True) break - self.last_dispatch = time.time() + self.last_dispatch = monotonic() def _acceptEvent(self, event, head=False): # events are required to be instances diff --git a/supervisor/scripts/loop_eventgen.py b/supervisor/scripts/loop_eventgen.py index 3a167ac55..a6dc0a0a1 100755 --- a/supervisor/scripts/loop_eventgen.py +++ b/supervisor/scripts/loop_eventgen.py @@ -7,9 +7,11 @@ import sys import time from supervisor import childutils +from supervisor.monotonic import monotonic + def main(max): - start = time.time() + start = monotonic() report = open('/tmp/report', 'w') i = 0 while 1: @@ -19,7 +21,7 @@ def main(max): report.flush() i+=1 if max and i >= max: - end = time.time() + end = monotonic() report.write('%s per second\n' % (i / (end - start))) sys.exit(0) diff --git a/supervisor/supervisord.py b/supervisor/supervisord.py index 96fef320b..9d1dc1e48 100755 --- a/supervisor/supervisord.py +++ b/supervisor/supervisord.py @@ -35,6 +35,7 @@ import signal from supervisor.medusa import asyncore_25 as asyncore +from supervisor.monotonic import monotonic from supervisor.options import ServerOptions from supervisor.options import signame @@ -146,7 +147,7 @@ def shutdown_report(self): if unstopped: # throttle 'waiting for x to die' reports - now = time.time() + now = monotonic() if now > (self.lastshutdownreport + 3): # every 3 secs names = [ p.config.name for p in unstopped ] namestr = ', '.join(names) @@ -263,7 +264,7 @@ def tick(self, now=None): the period for the event type rolls over """ if now is None: # now won't be None in unit tests - now = time.time() + now = monotonic() for event in events.TICK_EVENTS: period = event.period last_tick = self.ticks.get(period) diff --git a/supervisor/tests/test_process.py b/supervisor/tests/test_process.py index 7144b4c7d..91dd1d536 100644 --- a/supervisor/tests/test_process.py +++ b/supervisor/tests/test_process.py @@ -6,6 +6,7 @@ from supervisor.compat import as_bytes from supervisor.compat import maxint +from supervisor.monotonic import monotonic from supervisor.tests.base import Mock, patch, sentinel from supervisor.tests.base import DummyOptions @@ -683,7 +684,7 @@ def test_stop(self): instance.dispatchers = {'foo':dispatcher} from supervisor.states import ProcessStates instance.state = ProcessStates.RUNNING - instance.laststopreport = time.time() + instance.laststopreport = monotonic() instance.stop() self.assertTrue(instance.administrative_stop) self.assertEqual(instance.laststopreport, 0) @@ -1044,7 +1045,7 @@ def test_finish_starting_state_laststart_in_future(self): pipes = {'stdout':'','stderr':''} instance.pipes = pipes instance.config.exitcodes =[-1] - instance.laststart = time.time() + 3600 # 1 hour into the future + instance.laststart = monotonic() + 3600 # 1 hour into the future from supervisor.states import ProcessStates from supervisor import events instance.state = ProcessStates.STARTING @@ -1085,7 +1086,7 @@ def test_finish_starting_state_exited_too_quickly(self): pipes = {'stdout':'','stderr':''} instance.pipes = pipes instance.config.exitcodes =[-1] - instance.laststart = time.time() + instance.laststart = monotonic() from supervisor.states import ProcessStates from supervisor import events instance.state = ProcessStates.STARTING @@ -1115,7 +1116,7 @@ def test_finish_running_state_laststart_in_future(self): pipes = {'stdout':'','stderr':''} instance.pipes = pipes instance.config.exitcodes =[-1] - instance.laststart = time.time() + 3600 # 1 hour into the future + instance.laststart = monotonic() + 3600 # 1 hour into the future from supervisor.states import ProcessStates from supervisor import events instance.state = ProcessStates.RUNNING @@ -1996,7 +1997,7 @@ def test_transition_event_proc_running_with_dispatch_throttle_notyet(self): gconfig = DummyPGroupConfig(options, pconfigs=[pconfig1]) pool = self._makeOne(gconfig) pool.dispatch_throttle = 5 - pool.last_dispatch = time.time() + pool.last_dispatch = monotonic() pool.processes = {'process1': process1} event = DummyEvent() from supervisor.states import EventListenerStates @@ -2017,7 +2018,7 @@ def test_transition_event_proc_running_with_dispatch_throttle_ready(self): gconfig = DummyPGroupConfig(options, pconfigs=[pconfig1]) pool = self._makeOne(gconfig) pool.dispatch_throttle = 5 - pool.last_dispatch = time.time() - 1000 + pool.last_dispatch = monotonic() - 1000 pool.processes = {'process1': process1} event = DummyEvent() from supervisor.states import EventListenerStates diff --git a/supervisor/tests/test_supervisord.py b/supervisor/tests/test_supervisord.py index df1523296..742b3f5e7 100644 --- a/supervisor/tests/test_supervisord.py +++ b/supervisor/tests/test_supervisord.py @@ -6,6 +6,7 @@ import tempfile import shutil +from supervisor.monotonic import monotonic from supervisor.tests.base import DummyOptions from supervisor.tests.base import DummyPConfig from supervisor.tests.base import DummyPGroupConfig @@ -236,7 +237,7 @@ def test_handle_sigusr2(self): pconfig1 = DummyPConfig(options, 'process1', 'process1','/bin/process1') from supervisor.process import ProcessStates process1 = DummyProcess(pconfig1, state=ProcessStates.STOPPING) - process1.delay = time.time() - 1 + process1.delay = monotonic() - 1 supervisord = self._makeOne(options) pconfigs = [DummyPConfig(options, 'foo', 'foo', '/bin/foo')] options.process_group_configs = DummyPGroupConfig(