Log info whenever gevent switches from one greenlet to another

717 views
Skip to first unread message

Shahaf Abileah

unread,
Apr 2, 2014, 7:15:46 PM4/2/14
to gev...@googlegroups.com
Is it possible to log info anytime gevent switches from one greenlet to another?

Why I want to do this...

I'm investigating an issue where it appears that greenlets aren't getting swapped in quickly enough.  I see situations where a greenlet makes an async call and therefore yields, but it doesn't get to run again for a long time (1-2 minutes), long past the point where (I believe) the resource it was waiting for is available.

Worth noting that the CPU usage is pegged at 100%, so the problem may very well be a lack of actual resources, but I'd like to make sure.  If could print a greenlet ID + timestamp whenever a greenlet is swapped in or out, I could verify whether this is what's happening.

I started looking at the source code, adding my own print statements using id(getcurrent()) in various switch/switch_out functions, but so far I haven't found the right approach, so I would appreciate some guidance.

Related - does gevent schedule greenlets in FIFO order?  In other words, does gevent look at all greenlets that are not blocked and pick the one that started waiting longest ago to run next?

thanks,

--S

Shaun Lindsay

unread,
Apr 2, 2014, 7:38:34 PM4/2/14
to gev...@googlegroups.com
If your CPU is maxed out, you likely have a greenlet doing something cpu-heavy that isn't yielding.  You can use a profiler (https://github.com/srlindsay/gevent-profiler is one, maybe there are others now?) to figure out which greenlet is causing the issue.


--
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.

Shahaf Abileah

unread,
Apr 2, 2014, 8:02:23 PM4/2/14
to gev...@googlegroups.com
Thanks Shaun.

This issue has been happening in production, but not locally.  Moreover, in production we're also memory constrained (not just CPU constrained), so I hesitate to include code that may accumulate lots of profiling info in memory.  That's why I was hoping to simply log info and do the analysis from the logs after the fact.


I gather that greenlet.switch(...) is the way to switch to a given greenlet.  So I attempted to print a "start" timestamp when a greenlet begins execution by changing greenlet.py like so:

...

# New stuff
import time

class Greenlet(greenlet):
    """A light-weight cooperatively-scheduled execution unit."""

    ....

    # New stuff
    def switch(self, *args, **kwargs):
        print '{t} Greenlet.switch to {i}'.format(t=time.time(), i=id(self))
        return super(Greenlet, self).switch(*args, **kwargs)
    ...

Does this seem right?

How can I go about printing a corresponding "stop" timestamp anytime a greenlet yields control?

thanks,

--S


Matthias Urlichs

unread,
Apr 3, 2014, 4:15:25 AM4/3/14
to gev...@googlegroups.com
Hi,

Shahaf Abileah:
> def switch(self, *args, **kwargs):
> print '{t} Greenlet.switch to {i}'.format(t=time.time(), i=id(self))
> return super(Greenlet, self).switch(*args, **kwargs)
>
> How can I go about printing a corresponding "stop" timestamp anytime a
> greenlet yields control?

Why would you need to do that?
It's the same as the greenlet you switched to previously.

Alternately. greenlet.getcurrent() gets you the currently-running greenlet,
which by definition is the one you're switching away from.

--
-- Matthias Urlichs

Ralf Schmitt

unread,
Apr 3, 2014, 6:16:13 AM4/3/14
to gev...@googlegroups.com
Shahaf Abileah <sha...@gmail.com> writes:

> Is it possible to log info anytime gevent switches from one greenlet to
> another?

Please have a look at greenlet.settrace.

--
Cheers
Ralf

Shahaf Abileah

unread,
Apr 3, 2014, 1:56:29 PM4/3/14
to gev...@googlegroups.com
Thanks for bringing up greenlet.settrace.  That looks like the right approach.


Is the trace function called before or after the switch?  In other words, if I call threading.current_thread() inside the trace function, does it tell me about the origin greenlet or the target greenlet?

thanks,

--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.
Reply all
Reply to author
Forward
0 new messages