def enable_greenlet_tracing(): # Tracing seems to cause a 2-5% performance loss. import greenlet greenlet.GREENLET_USE_TRACING = True def trace(*args): time_since_last_switch = time.time() - trace.last_switch # Record the time of the current switch trace.last_switch = time.time() if args[0] == "switch": # We are switching from the greenlet args[1][0] to the greenlet # args[1][1] args[1][0].__dict__.setdefault("_trace_time", 0) args[1][0].__dict__["_trace_time"] += time_since_last_switch args[1][0].__dict__.setdefault("_trace_switches", 0) args[1][0].__dict__["_trace_switches"] += 1 elif args[0] == "throw": pass trace.last_switch = time.time() greenlet.settrace(trace) # pylint: disable=no-member
def enable_debug(): import inspect import greenlet import logging def trace_green(event, args): src, target = args if event == "switch": logging.info("from %s switch to %s" % (src, target)) elif event == "throw": logging.info("from %s throw exception to %s" % (src, target)) if src.gr_frame: tracebacks = inspect.getouterframes(src.gr_frame) buff = [] for traceback in tracebacks: srcfile, lineno, func_name, codesample = traceback[1:-1] trace_line = '''File "%s", line %s, in %s\n%s ''' codesample = "".join(codesample) if codesample else "" buff.append(trace_line % (srcfile, lineno, func_name, codesample)) #logging.info("".join(buff)) logging.info(buff[0]) greenlet.settrace(trace_green)
def gbn_detach(): """ Detach gbn to reduce overhead. Please do not use gbn after detach. """ settrace(None) state['attached'] = False
def enable_debug(): if IS_PYPY: sys.stderr.write("settrace api unsupported on pypy") sys.stderr.flush() return import inspect def trace_green(event, args): src, target = args if event == "switch": print("from %s switch to %s" % (src, target)) elif event == "throw": print("from %s throw exception to %s" % (src, target)) if src.gr_frame: tracebacks = inspect.getouterframes(src.gr_frame) buff = [] for traceback in tracebacks: srcfile, lineno, func_name, codesample = traceback[1:-1] trace_line = '''File "%s", line %d, in %s\n%s ''' buff.append(trace_line % (srcfile, lineno, func_name, "".join(codesample))) print("".join(buff)) greenlet.settrace(trace_green)
def start(self): self.start_time = time.time() greenlet.settrace(self._trace) # Spawn a separate OS thread to periodically check if the active # greenlet on the main thread is blocking. self._thread_id = gevent._threading.start_new_thread( self._monitoring_thread, ())
def gbn_attach(): """ Attach gbn to pause/continue counting time on switch from/to original greenlet. Please do it once before using gbn. """ settrace(_gbn_tracer) state['attached'] = True
def init_process(self): # Check if we need a background thread to monitor memory use. needs_monitoring_thread = False if MAX_MEMORY_USAGE: self._last_memory_check_time = time.time() needs_monitoring_thread = True # Set up a greenlet tracing hook to monitor for event-loop blockage, # but only if monitoring is both possible and required. if hasattr(greenlet, "settrace") and MAX_BLOCKING_TIME > 0: # Grab a reference to the gevent hub. # It is needed in a background thread, but is only visible from # the main thread, so we need to store an explicit reference to it. self._active_hub = gevent.hub.get_hub() # Set up a trace function to record each greenlet switch. self._active_greenlet = None self._greenlet_switch_counter = 0 greenlet.settrace(self._greenlet_switch_tracer) self._main_thread_id = _real_get_ident() needs_monitoring_thread = True # Create a real thread to monitor out execution. # Since this will be a long-running daemon thread, it's OK to # fire-and-forget using the low-level start_new_thread function. if needs_monitoring_thread: _real_start_new_thread(self._process_monitoring_thread, ()) # Continue to superclass initialization logic. # Note that this runs the main loop and never returns. super(MozSvcGeventWorker, self).init_process()
def stop_profiler(): # we keep the _state around for the user until the next session # Unregister the profiler in this order, otherwise we will have extra # measurements in the end sys.setprofile(None) threading.setprofile(None) greenlet.settrace(None) # pylint: disable=no-member
def tearDown(self): monitor.start_new_thread = self._orig_start_new_thread monitor.thread_sleep = self._orig_thread_sleep prev = self.pmt.previous_trace_function self.pmt.kill() assert gettrace() is prev, (gettrace(), prev) settrace(None) super(_AbstractTestPeriodicMonitoringThread, self).tearDown()
def tearDown(self): monitor.start_new_thread = self._orig_start_new_thread monitor.thread_sleep = self._orig_thread_sleep prev = self.pmt._greenlet_tracer.previous_trace_function self.pmt.kill() assert gettrace() is prev, (gettrace(), prev) settrace(None) super(_AbstractTestPeriodicMonitoringThread, self).tearDown()
def bench_trivial_tracer(loops): def trivial(_event, _args): return greenlet.settrace(trivial) try: return _run(loops) finally: greenlet.settrace(None)
def kill(self): if not self.should_run: # Prevent overwriting trace functions. return # Stop this monitoring thread from running. self.should_run = False # Uninstall our tracing hook settrace(self.previous_trace_function) self.previous_trace_function = None
def stop(self) -> None: # Unregister the profiler in this order, otherwise we will have extra # measurements in the end sys.setprofile(None) threading.setprofile(None) greenlet.settrace(self.previous_callback) # pylint: disable=c-extension-no-member self.collector.stop() self.collector = None
def green_monitor(self): """ Start point method for setting up greenlet trace for finding out blocked green threads. """ self._green_hub = gevent.hub.get_hub() self._green_active = None self._green_counter = 0 greenlet.settrace(self._green_callback) monkey.get_original('_thread', 'start_new_thread')(self._green_monitor_thread, ()) self._green_main_threadid = monkey.get_original('_thread', 'get_ident')()
def __init__(self, ctx): _ThreadSpinMonitor.MAIN_INSTANCE = self self.main_thread_id = threading.current_thread().ident self.cur_pid = os.getpid() self.last_spin = 0 self.ctx = ctx self.spin_count = 0 self.last_cal_log = 0 # limit how often CAL logs self.stopping = False greenlet.settrace(self._greenlet_spin_trace) self._start_thread()
def stop(self): """Called after all report output, including output from all plugins, has been sent to the stream. Use this to print final test results or perform final cleanup. Return None to allow other plugins to continue printing, or any other value to stop them. """ #Disable alarm if self._started: signal.alarm(0) greenlet.settrace(self.oldtrace) self._started = False
def gxray_attach(count_stacks=False, cumulative=False, grep=None): """ Attach and configure gxray: @param count_stacks: bool - Count stacks of each spot to understand who calls this spot and how time is distributed. @param cumulative: bool - Show cumulative time: spot itself + everything called by this spot. @param grep: tuple(file_name: str, first_line_number: int, func_name: str)|None - Count only this spot and everything called by this spot. """ global _count_stacks, _cumulative, _grep _count_stacks, _cumulative, _grep = count_stacks, cumulative, grep greenlet.settrace(_tracer) sys.setprofile(_profiler)
def init_process(self): if MAX_BLOCKING_TIME: # Get a reference to the main thread's hub. self._hub = gevent.hub.get_hub() self._active_greenlet = None self._switch_flag = False self._main_thread_id = gevent._threading.get_ident() greenlet.settrace(self._trace) # Spawn a separate OS thread to periodically check if the active # greenlet on the main thread is blocking. gevent._threading.start_new_thread(self._monitoring_thread, ()) super(InboxWSGIWorker, self).init_process()
def serve_forever(self): ctx = context.get_context() ctx.running = True try: # set up greenlet switch monitoring import greenlet greenlet.settrace(ctx._trace) except AttributeError: pass # oh well if not self.prefork: self.start() log_msg = 'Group initialized and serving forever...' ctx.log.critical('GROUP.INIT').success(log_msg) if ctx.dev and ctx.dev_service_repl_enabled and os.isatty(0): if not hasattr(os, "getpgrp"): # Windows fg = True else: try: fg = os.getpgrp() == os.tcgetpgrp(sys.stdout.fileno()) except OSError: fg = False if fg: # only start REPL on unix machines if running in foreground async .start_repl({'server': ctx.server_group}) try: while 1: async .sleep(1.0) finally: self.stop() return if not ufork: raise RuntimeError( 'attempted to run pre-forked on platform without fork') if ctx.tracing: # a little bit hacky, disable tracing in aribter self.trace_in_child = True ctx.set_greenlet_trace(False) else: self.trace_in_child = False self.arbiter = ufork.Arbiter(post_fork=self._post_fork, child_pre_exit=self.stop, parent_pre_stop=ctx.stop, size=self.num_workers, sleep=async .sleep, fork=gevent.fork, child_memlimit=ctx.worker_memlimit) if self.daemonize: pgrpfile = os.path.join(ctx.process_group_file_path, '{0}.pgrp'.format(ctx.appname)) self.arbiter.spawn_daemon(pgrpfile=pgrpfile) else: self.arbiter.run()
def set_greenlet_trace(self, value): 'Turn on tracking of greenlet switches.' if value not in (True, False): raise ValueError("value must be True or False") if value and not getattr(self, "tracing", False): self.tracing = True self.thread_spin_monitor = _ThreadSpinMonitor(self) if value is False: self.tracing = False self.thread_spin_monitor = None try: greenlet.settrace(None) except AttributeError: pass # not the end of the world
def enable_slow_greenlet_log_warning(max_duration=1.0, logger=None): """ Enables warnings about slow greenlet written to the log :param max_duration: maximum duration in seconds afterwhich a greenlet is considered slow :param logger: logger to use, or None if using the default logger """ global _slow_greenlet_max_duration, _last_switch_time, _logger if logger is None: logger = get_logger() now = get_time() _slow_greenlet_max_duration = max_duration _last_switch_time = now current_id = id(gevent.getcurrent()) logger.debug("enabling logging of greenlet switching, current greenlet (main) is {}".format(current_id)) greenlet.settrace(partial(_switch_time_tracer, logger))
def start_profiler(): global _state _state = GlobalState() frame = sys._getframe(0) current_greenlet = greenlet.getcurrent() # pylint: disable=no-member thread_state = ensure_thread_state(current_greenlet, frame) _state.last = thread_state # this needs to be instantiate before the handler is installed greenlet.settrace(greenlet_profiler) # pylint: disable=no-member sys.setprofile(thread_profiler) threading.setprofile(thread_profiler)
def serve_forever(self): ctx = context.get_context() ctx.running = True try: # set up greenlet switch monitoring import greenlet greenlet.settrace(ctx._trace) except AttributeError: pass # oh well if not self.prefork: self.start() log_msg = 'Group initialized and serving forever...' ctx.log.critical('GROUP.INIT').success(log_msg) if ctx.dev and ctx.dev_service_repl_enabled and os.isatty(0): if not hasattr(os, "getpgrp"): # Windows fg = True else: try: fg = os.getpgrp() == os.tcgetpgrp(sys.stdout.fileno()) except OSError: fg = False if fg: # only start REPL on unix machines if running in foreground async.start_repl({'server': ctx.server_group}) try: while 1: async.sleep(1.0) finally: self.stop() return if not ufork: raise RuntimeError('attempted to run pre-forked on platform without fork') if ctx.tracing: # a little bit hacky, disable tracing in aribter self.trace_in_child = True ctx.set_greenlet_trace(False) else: self.trace_in_child = False self.arbiter = ufork.Arbiter( post_fork=self._post_fork, child_pre_exit=self.stop, parent_pre_stop=ctx.stop, size=self.num_workers, sleep=async.sleep, fork=gevent.fork, child_memlimit=ctx.worker_memlimit) if self.daemonize: pgrpfile = os.path.join(ctx.process_group_file_path, '{0}.pgrp'.format(ctx.appname)) self.arbiter.spawn_daemon(pgrpfile=pgrpfile) else: self.arbiter.run()
def enable_slow_greenlet_log_warning(max_duration=1.0, logger=None): """ Enables warnings about slow greenlet written to the log :param max_duration: maximum duration in seconds afterwhich a greenlet is considered slow :param logger: logger to use, or None if using the default logger """ global _slow_greenlet_max_duration, _last_switch_time, _logger if logger is None: logger = get_logger() now = get_time() _slow_greenlet_max_duration = max_duration _last_switch_time = now current_id = id(gevent.getcurrent()) logger.debug( "enabling logging of greenlet switching, current greenlet (main) is {}" .format(current_id)) greenlet.settrace(partial(_switch_time_tracer, logger))
def test_previous_trace(self): self.pmt.kill() self.assertIsNone(gettrace()) called = [] def f(*args): called.append(args) settrace(f) self.pmt = monitor.PeriodicMonitoringThread(self.hub) self.assertEqual(gettrace(), self.pmt.greenlet_trace) self.assertIs(self.pmt.previous_trace_function, f) self.pmt.greenlet_trace('event', 'args') self.assertEqual([('event', 'args')], called)
def test_previous_trace(self): self.pmt.kill() self.assertIsNone(gettrace()) called = [] def f(*args): called.append(args) settrace(f) self.pmt = monitor.PeriodicMonitoringThread(self.hub) self.assertEqual(gettrace(), self.pmt._greenlet_tracer) self.assertIs(self.pmt._greenlet_tracer.previous_trace_function, f) self.pmt._greenlet_tracer('event', ('args',)) self.assertEqual([('event', ('args',))], called)
def test_exception_disables_tracing(self): main = greenlet.getcurrent() actions = [] def trace(*args): actions.append(args) raise SomeError() def dummy(): main.switch() g = greenlet.greenlet(dummy) g.switch() oldtrace = greenlet.settrace(trace) try: self.assertRaises(SomeError, g.switch) self.assertEqual(greenlet.gettrace(), None) finally: greenlet.settrace(oldtrace) self.assertEqual(actions, [ ('switch', (main, g)), ])
def __init__(self, collector, sample_interval=0.1): self.collector = collector self.sample_interval = sample_interval self.last_timestamp = time.time() # Save the old frame to have proper stack reporting. If the following # code is executed: # # slow() # At this point a new sample is *not* needed # f2() # When this calls happens a new sample is needed, *because # # of the previous function* # # The above gets worse because a context switch can happen after the # call to slow, if this is not taken into account a completely wrong # stack trace will be reported. self.old_frame = None greenlet.settrace(self._greenlet_profiler) # pylint: disable=c-extension-no-member sys.setprofile(self._thread_profiler)
def init_process(self): # Set up a greenlet tracing hook to monitor for event-loop blockage, # but only if monitoring is both possible and required. if hasattr(greenlet, "settrace") and \ self.app.cfg.gevent_check_interval > 0: # Grab a reference to the gevent hub. # It is needed in a background thread, but is only visible from # the main thread, so we need to store an explicit reference to it. self._active_hub = gevent.hub.get_hub() # Set up a trace function to record each greenlet switch. self._active_greenlet = None self._greenlet_switch_counter = 0 greenlet.settrace(self._greenlet_switch_tracer) self._main_thread_id = _real_get_ident() # Create a real thread to monitor out execution. # Since this will be a long-running daemon thread, it's OK to # fire-and-forget using the low-level start_new_thread function. _real_start_new_thread(self._process_monitoring_thread, ()) return super(GeventThriftPyWorker, self).init_process()
def start(self): # A trace function that gets executed on every greenlet switch. # It checks how much time has elapsed and logs an error if it was excessive. # The Hub gets an exemption, because it's allowed to block on I/O. if self._started: # Already started. Do nothing. return self.oldtrace = greenlet.settrace(self._switch_time_tracer) signal.signal(signal.SIGALRM, self._alarm_handler) self._started = True
def test_greenlet_tracing(): def callback(event, args): print event, 'from', id(args[0]), 'to', id(args[1]) def dummy(): g2.switch() def dummyexception(): raise Exception('except in coroutine') main = greenlet.getcurrent() g1 = greenlet(dummy) g2 = greenlet(dummyexception) print 'main id %s, gr1 id %s, gr2 is %s' % (id(main), id(g1), (g2)) oldtrace = greenlet.settrace(callback) try: g1.switch() except: print 'Exception' finally: greenlet.settrace(oldtrace)
def start(self): if self._started: # Already started. Do nothing. return # A trace function that gets executed on every greenlet switch. # It checks how much time has elapsed and logs an error if it was excessive. # The Hub gets an exemption, because it's allowed to block on I/O. self.oldtrace = greenlet.settrace(self._switch_time_tracer) self._active_hub = gevent.hub.get_hub() self._main_thread_id = _real_get_ident() _real_start_new_thread(self._greenlet_blocking_monitor, ()) self._started = True
def test_greenlet_tracing(): def callback(event, args): print event, 'from', id(args[0]), 'to', id(args[1]) def dummy(): gr2.switch() def dummyException(): raise Exception("Except in coroutine!") main = greenlet.getcurrent() gr1 = greenlet.greenlet(dummy) gr2 = greenlet.greenlet(dummyException) print "main id %s, gr1 id %s, gr2 id %s" % (id(main), id(gr1), id(gr2)) oldtrace = greenlet.settrace(callback) try: gr1.switch() except: print "Exception" finally: greenlet.settrace(oldtrace)
def init_process(self): # Set up a greenlet tracing hook to monitor for event-loop blockage, # but only if monitoring is both possible and required. if hasattr(greenlet, "settrace") and MAX_BLOCKING_TIME > 0: # Grab a reference to the gevent hub. # It is needed in a background thread, but it only visible from # the main thread, so we need to store a reference to it. self._active_hub = gevent.hub.get_hub() # Set up a trace function to record each greenlet switch. self._active_greenlet = None self._greenlet_switch_counter = 0 greenlet.settrace(self._greenlet_switch_tracer) # Create a real thread to monitor for blocking of greenlets. # Since this will be a long-running daemon thread, it's OK to # fire-and-forget using the low-level start_new_thread function. self._main_thread_id = _real_get_ident() _real_start_new_thread(self._greenlet_blocking_monitor, ()) # Continue to superclass initialization logic. # Note that this runs the main loop and never returns. super(MozSvcWorker, self).init_process()
def test_greenlet_tracing(self): main = greenlet.getcurrent() actions = [] def trace(*args): actions.append(args) def dummy(): pass def dummyexc(): raise SomeError() oldtrace = greenlet.settrace(trace) try: g1 = greenlet.greenlet(dummy) g1.switch() g2 = greenlet.greenlet(dummyexc) self.assertRaises(SomeError, g2.switch) finally: greenlet.settrace(oldtrace) self.assertEqual(actions, [ ('switch', (main, g1)), ('switch', (g1, main)), ('switch', (main, g2)), ('throw', (g2, main)), ])
def install_switch_log(): # Do not overwrite the previous installed tracing function, this could be # another profiling tool, and if the callback is overwriten the tool would # not work as expected (e.g. a trace sampler) previous_callback = greenlet.gettrace() def log_every_switch(event: str, args: Any) -> None: if event == "switch": origin, target = args # Collecting the complete stack frame because the top-level # function will be a greenlet, and the bottom function may be an # external library. To understand what is going on the application # code, the whole stack is necessary. frame = sys._getframe(0) callstack = collect_frames(frame) # Using `print` because logging will not work here, the logger may # not be properly initialized on a fresh greenlet and will try to # use a nullable variable. print( json.dumps({ "event": "Switching", "origin": str(origin), "target": str(target), "target_callstack": callstack, "time": datetime.utcnow().isoformat(), })) if previous_callback is not None: return previous_callback(event, args) return None greenlet.settrace(log_every_switch) return previous_callback
def enable_gevent_integration(): # References: # https://greenlet.readthedocs.io/en/latest/api.html#greenlet.settrace # https://greenlet.readthedocs.io/en/latest/tracing.html # Note: gevent.version_info is WRONG (gevent.__version__ must be used). try: if tuple(int(x) for x in gevent.__version__.split('.')[:2]) <= (20, 0): if not GEVENT_SHOW_PAUSED_GREENLETS: return if not hasattr(greenlet, 'settrace'): # In older versions it was optional. # We still try to use if available though (because without it pydev_log.debug( 'greenlet.settrace not available. GEVENT_SHOW_PAUSED_GREENLETS will have no effect.' ) return try: greenlet.settrace(greenlet_events) except: pydev_log.exception('Error with greenlet.settrace.') except: pydev_log.exception('Error setting up gevent %s.', gevent.__version__)
def detach(self): sys.setprofile(None) greenlet.settrace(None)
def set(self): self.start_time = time.time() greenlet.settrace(self._trace)
def stop(self): if self._started: self._stop_monitor = True greenlet.settrace(self.oldtrace) self._started = False
MIN_DURATION_TO_LOG = 0.001 _last_switch_time = None def log_greenlet_run_duration(what, (origin, target)): global _last_switch_time then = _last_switch_time now = _last_switch_time = time.time() if then is not None: blocking_time = now - then if origin is not gevent.hub.get_hub(): msg = "Greenlet took %.4f seconds (%s from %s %s to %s %s).\n" msg = msg % (blocking_time, what, type(origin), id(origin), type(target), id(target)) print msg greenlet.settrace(log_greenlet_run_duration) def redis_exec(): """ retrieve redis info array """ connection = redis.Redis(connection_pool=POOL) return connection.info() def mysql_exec(): """ retrieve mysql hosts """ dbase = pymysql.connect(host='127.0.0.1', port=3306, user='******', passwd='mysql', db='mysql') result = dbase.cursor()
def disable_slow_greenlet_log_warning(): """Disables the slow greenlet log warnings by removing the trace function from greenlet.""" greenlet.settrace(None)
def execute(self): self.log.debug("Executing {}".format(self.graph)) # Initialize graph if self.graph.state == ComponentState.NOT_INITIALIZED: self.graph.initialize() self.graph.state = ComponentState.INITIALIZED # Enable tracing old_trace = greenlet.gettrace() if self.DETECT_BLOCKING: greenlet.settrace(self._blocking_greenlet_detector) self._running = True try: all_components = set() self._graph_lookup = {} for component, graph in self.graph.get_all_components(include_graphs=True): self._graph_lookup[component] = graph all_components.add(component) component.executor = self # Component should always be in a INITIALIZED state when first # running! if component.state != ComponentState.INITIALIZED: raise exc.ComponentStateError( component, "state is {}, but expected INITIALIZED".format(component.state) ) component.state = ComponentState.ACTIVE self.log.debug("Components in {}: {}".format(self.graph, ", ".join(map(str, all_components)))) self._recv_queues = collections.defaultdict(queue.Queue) self._coroutines = dict( [ (gevent.spawn(self._create_component_runner(comp), None, None), comp) # in_queues # out_queues for comp in filter(lambda c: not isinstance(c, Graph), all_components) ] ) last_exception = None def thread_error_handler(coroutine): """ Handles component coroutine exceptions that get raised. This should terminate execution of all other coroutines. """ last_exception = coroutine.exception component = self._coroutines[coroutine] self.log.error( 'Component "{}" failed with {}: {}'.format( component.name, coroutine.exception.__class__.__name__, coroutine.exception.message ) ) for c in all_components: if c.is_alive(): c.terminate(ex=last_exception) # Wire up error handler (so that exceptions aren't swallowed) for coroutine in self._coroutines.keys(): coroutine.link_exception(thread_error_handler) # Wait for all coroutines to terminate gevent.wait(self._coroutines.keys()) self.graph.terminate(ex=last_exception) self._final_checks() self._reset_components() self.log.debug("Finished graph execution") finally: self._running = False if self.DETECT_BLOCKING: # Unset tracer greenlet.settrace(old_trace)
def begin(self): # A trace function that gets executed on every greenlet switch. # It checks how much time has elapsed and logs an error if it was excessive. # The Hub gets an exemption, because it's allowed to block on I/O. greenlet.settrace(switch_time_tracer) signal.signal(signal.SIGALRM, alarm_handler)
def attach(self): self.last_event_at = self.get_time() greenlet.settrace(self.dispatch_greenlet_event) sys.setprofile(self.dispatch_trace_event)
def start(self): self.start_time = time.time() greenlet.settrace(self._trace) # Spawn a separate OS thread to periodically check if the active # greenlet on the main thread is blocking. gevent._threading.start_new_thread(self._monitoring_thread, ())