Profiler for a long running daemon and gevent's backdoor

[opensourcegeek]

Hi guys,

I've been using gevent for concurrency on a backend application. This is is not web based, I would like to profile it to see what's blocking in the application. There are few monkey patches which I'm not sure is blocking or what. Since this is a long running daemon, are there any tools to look at the internals as the app is running? I don't think GreenletProfiler for example works that way, it seems like it waits till the program exits to collect the stats.

I can see gevent has a backdoor api, what does it do? Can I use it to check what is blocking in the code? I'm happy to show some code if you would like to know more about the problem.

Cheers

Praveen

[Shahaf Abileah]

I've been tinkering around with the following code...

    import gevent.monkey

    gevent.monkey.patch_all()

    import psycogreen.gevent

    psycogreen.gevent.patch_psycopg()

    # Log how much time each greenlet runs before it yields control back to the gevent loop.

    # 

    # This can help diagnose issues where it appears that some greenlets are running for too 

    # long before yielding, and thus causing other greenlets to starve.

    # 

    # More info:

    # https://groups.google.com/forum/#!topic/gevent/pfy-jx3O_yM

    # http://www.rfk.id.au/blog/entry/detect-gevent-blocking-with-greenlet-settrace/

    if environ.get('LOG_GREENLET_RUN_DURATIONS') and environ.get('LOG_GREENLET_RUN_DURATIONS').lower() == 'true':

        import time, greenlet, gevent.hub, threading

        MIN_DURATION_TO_LOG = float(environ.get('MIN_GREENLET_RUN_DURATION_TO_LOG', 0.5)) # seconds

        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() and blocking_time > MIN_DURATION_TO_LOG:

                    msg = "Greenlet ran for %.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)

Hope this helps.

--S

--
You received this message because you are subscribed to the Google Groups "gevent: coroutine-based Python network library" group.
To unsubscribe from this group and stop receiving emails from it, send an email to gevent+un...@googlegroups.com.
For more options, visit https://groups.google.com/d/optout.

--

http://twitter.com/shahafabileah

[opensourcegeek]

Thanks, I have code that passes functions to gevent.spawn, and I'm not sure how to see which function blocks. It just prints gevent.greenlet.Greent as the class name at the moment. Any quick hints?

[Shahaf Abileah]

Sorry, I don't have an answer.  If I were you I'd try to play with inspect.stack().

--S

[opensourcegeek]

I think inspect.stack won't work too as the call stack gets replaced by gevent? I will give it a go anyway. Thanks.

[Todd Sinclair]

I've got a single-threaded, gevent application that registers a SIGQUIT handler to dump its 'stack'.  The SIGQUIT handler is regsitered through normal Python means, not through gevent - so Python treats it more like an interrupt.  It doesn't always work - there was a case where someone called into the non-gevent threading library accidently, and deadlocked in there - but a simple greenlet in a 'while True: pass' loop seems to get caught fine.

Once you're in, inspect does work, for every greenlet other than the one you're running in.  The other greenlets have a gr_frame member that seems to store the full stack of that greenlet.

        # The running greenlet has no frame list, so we have to get that one
        # through traditional means.
        if greenlet.gr_frame:
            frames = inspect.getouterframes(greenlet.gr_frame)
        else:
            frames = inspect.stack()

From there, you can loop on the frames and call inspect.getframeinfo(frame[0]) to get the information.

The only issue is that you need to know what greenlets exist.  Gevent doesn't provide any way to find all of the ones that exist.  Going through gc can do it, but is slow, and I, at least, was worried about picking up greenlets that were internal to gevent.  We make sure to add all greenlets to a Group class, just to hold references to them.  Also lets us cleanly shut down the system by issuing a single kill() to that group.