Use monotonic time for process state tracking

This makes sure system time changes (e.g. via ntp) doesn't result in odd
assertion failures due to processes entering the running state before being
started.

Supervisor#281
Supervisor#468
https://bugs.activestate.com/show_bug.cgi?id=104508
https://activestate.atlassian.net/browse/STO-859

supervisor/compat.py

@@ -0,0 +1,30 @@
+from __future__ import absolute_import
+
+import sys
+
+try:  # pragma: no cover
+    from time import monotonic as monotonic_time
+except ImportError:  # pragma: no cover
+    if sys.platform == "linux2":
+        # Adapted from http://stackoverflow.com/questions/1205722/
+        import ctypes
+        import os
+        CLOCK_MONOTONIC_RAW = 4  # see <linux/time.h>
+
+        class timespec(ctypes.Structure):
+            _fields_ = [
+                ('tv_sec', ctypes.c_long),
+                ('tv_nsec', ctypes.c_long)
+            ]
+        librt = ctypes.CDLL('librt.so.1', use_errno=True)
+        clock_gettime = librt.clock_gettime
+        clock_gettime.argtypes = [ctypes.c_int32, ctypes.POINTER(timespec)]
+
+        def monotonic_time():
+            t = timespec()
+            if clock_gettime(CLOCK_MONOTONIC_RAW, ctypes.pointer(t)) != 0:
+                errno_ = ctypes.get_errno()
+                raise OSError(errno_, os.strerror(errno_))
+            return t.tv_sec + t.tv_nsec * 1e-9
+    else:
+        from time import monotonic  # raises ImportError

supervisor/process.py

@@ -1,12 +1,13 @@
 import os
 import sys
-import time
 import errno
 import shlex
 import StringIO
 import traceback
 import signal
 
+from supervisor.compat import monotonic_time
+
 from supervisor.medusa import asyncore_25 as asyncore
 
 from supervisor.states import ProcessStates
@@ -158,7 +159,7 @@ def change_state(self, new_state, expected=True):
             events.notify(event)
 
         if new_state == ProcessStates.BACKOFF:
-            now = time.time()
+            now = monotonic_time()
             self.backoff = self.backoff + 1
             self.delay = now + self.backoff
 
@@ -193,7 +194,7 @@ def spawn(self):
         self.system_stop = 0
         self.administrative_stop = 0
 
-        self.laststart = time.time()
+        self.laststart = monotonic_time()
 
         self._assertInState(ProcessStates.EXITED, ProcessStates.FATAL,
                             ProcessStates.BACKOFF, ProcessStates.STOPPED)
@@ -253,7 +254,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_time() + self.config.startsecs
         options.pidhistory[pid] = self
         return pid
 
@@ -343,7 +344,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_time()
         options = self.config.options
         if not self.pid:
             msg = ("attempted to kill %s with sig %s but it wasn't running" %
@@ -402,7 +403,7 @@ def finish(self, pid, sts):
 
         es, msg = decode_wait_status(sts)
 
-        now = time.time()
+        now = monotonic_time()
         self.laststop = now
         processname = self.config.name
 
@@ -493,7 +494,7 @@ def get_state(self):
         return self.state
 
     def transition(self):
-        now = time.time()
+        now = monotonic_time()
         state = self.state
 
         logger = self.config.options.logger
@@ -714,7 +715,7 @@ def transition(self):
                     dispatch_capable = True
         if dispatch_capable:
             if self.dispatch_throttle:
-                now = time.time()
+                now = monotonic_time()
                 if now - self.last_dispatch < self.dispatch_throttle:
                     return
             self.dispatch()
@@ -729,7 +730,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_time()
 
     def _acceptEvent(self, event, head=False):
         # events are required to be instances

supervisor/rpcinterface.py

@@ -3,6 +3,8 @@
 import datetime
 import errno
 
+from supervisor.compat import monotonic_time
+
 from supervisor.options import readFile
 from supervisor.options import tailFile
 from supervisor.options import NotExecutable
@@ -288,12 +290,12 @@ def startit():
                 # function appears to not work (symptom: 2nd or 3rd
                 # call through, it forgets about 'started', claiming
                 # it's undeclared).
-                started.append(time.time())
+                started.append(monotonic_time())
 
             if not wait or not startsecs:
                 return True
 
-            t = time.time()
+            t = monotonic_time()
             runtime = (t - started[0])
             state = process.get_state()
 
@@ -505,7 +507,7 @@ def getProcessInfo(self, name):
 
         start = int(process.laststart)
         stop = int(process.laststop)
-        now = int(time.time())
+        now = int(monotonic_time())
 
         state = process.get_state()
         spawnerr = process.spawnerr or ''

supervisor/supervisord.py

@@ -31,11 +31,12 @@
 """
 
 import os
-import time
 import errno
 import select
 import signal
 
+from supervisor.compat import monotonic_time
+
 from supervisor.medusa import asyncore_25 as asyncore
 
 from supervisor.options import ServerOptions
@@ -147,7 +148,7 @@ def shutdown_report(self):
 
         if unstopped:
             # throttle 'waiting for x to die' reports
-            now = time.time()
+            now = monotonic_time()
             if now > (self.lastshutdownreport + 3): # every 3 secs
                 names = [ p.config.name for p in unstopped ]
                 namestr = ', '.join(names)
@@ -266,7 +267,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_time()
         for event in events.TICK_EVENTS:
             period = event.period
             last_tick = self.ticks.get(period)