Poller failure when using Tornado/kqueue

[dsully]

Traceback (most recent call last): File "/Users/dsully/dev/tools/apps/deployment/bin/process-deployment-queue", line 150, in main create_server(fabric.name, http_port).start() File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/tornado/ioloop.py", line 301, in start event_pairs = self._impl.poll(poll_timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/tornado/ioloop.py", line 584, in poll kevents = self._kqueue.control(None, 1000, timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/emulation/select.py", line 150, in control self._readable.wait(timeout=timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/util.py", line 99, in wait scheduler.state.mainloop.switch() File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 535, in mainloop _hit_poller(until - time.time()) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 133, in _hit_poller events = state.poller.poll(timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/poller.py", line 110, in poll evs = self._poller.control(None, 2 * len(self._registry), timeout) ValueError: timeout must be positive or None

Not sure how timeout was assumedly negative.

[teepark]

what timing! I was just putting out a greenhouse release :P

--travis

On Sat, Sep 8, 2012 at 10:22 PM, Dan Sully notifications@github.com wrote:

Traceback (most recent call last): File "/Users/dsully/dev/tools/apps/deployment/bin/process-deployment-queue", line 150, in main create_server(fabric.name, http_port).start() File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/tornado/ioloop.py", line 301, in start event_pairs = self._impl.poll(poll_timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/tornado/ioloop.py", line 584, in poll kevents = self._kqueue.control(None, 1000, timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/emulation/select.py", line 150, in control self._readable.wait(timeout=timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/util.py", line 99, in wait scheduler.state.mainloop.switch() File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 535, in mainloop _hit_poller(until - time.time()) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 133, in _hit_poller events = state.poller.poll(timeout) File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/poller.py", line 110, in poll evs = self._poller.control(None, 2 * len(self._registry), timeout) ValueError: timeout must be positive or None

Not sure how timeout was assumedly negative.

— Reply to this email directly or view it on GitHubhttps://github.com/teepark/greenhouse/issues/9.

[teepark]

is this regularly happening? I can imagine it being a rare race (still needs a fix, but that would be nice to know).

[dsully]

Not regularly, but I am able to reproduce it by keeping a load runner against my process.

The timeout variable is indeed getting set to a negative value:

timeout must be positive or None TIMEOUT: -0.151891946793

[teepark]

can you see if you still get the error when using the select or poll pollers? put this early in your startup script:

from greenhouse import scheduler, poller
scheduler.reset_poller(poller.Select())
# or scheduler.reset_poller(poller.Poll())

The potential race condition I see is in scheduler code so the specific poller shouldn't matter, but on the other hand 152ms should be too big of a difference to be explained by a race.

[dsully]

So if I use poller.Select(), my app doesn't start up at all.. wondering if there's a conflict between Tornado & greenhouse for which event loop to use?

If I try and use Poll():

Traceback (most recent call last):
  File "/Users/dsully/.virtualenvs/test/bin/process-deployment-queue", line 7, in <module>
    execfile(__file__)
  File "/Users/dsully/dev/tools/apps/deployment/bin/process-deployment-queue", line 8, in <module>
    scheduler.reset_poller(poller.Poll())
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/poller.py", line 19, in __init__
    self._poller = self._POLLER()
TypeError: 'NoneType' object is not callable

If I fix that to be an attribute instead of a method call, I get:

$ process-deployment-queue -n -f esv4
Traceback (most recent call last):
  File "/Users/dsully/.virtualenvs/test/bin/process-deployment-queue", line 7, in <module>
    execfile(__file__)
  File "/Users/dsully/dev/tools/apps/deployment/bin/process-deployment-queue", line 5, in <module>
    import greenhouse; greenhouse.emulation.patch()
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/__init__.py", line 27, in <module>
    pause()
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 250, in pause
    state.mainloop.switch()
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 529, in mainloop
    _hit_poller(0)
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/scheduler.py", line 133, in _hit_poller
    events = state.poller.poll(timeout)
  File "/Users/dsully/.virtualenvs/test/lib/python2.6/site-packages/greenhouse/poller.py", line 113, in poll
    evs = self._poller.control(None, 2 * len(self._registry), timeout)
TypeError: descriptor 'control' requires a 'select.kqueue' object but received a 'NoneType'

[teepark]

27a224d fixes the Select poller. the Poll poller shouldn't have worked in the first place ,the 'NoneType' object is not callable error was the right way to fail (it should be a method call on poller.py:19) -- the issue was that the python distributed with OS X is missing select.poll entirely.

So where we are now on this: I'm still kind of stumped by the negative timeout, and would like to see if you get it on the fixed Select poller.

[dsully]

In a local module that I use (which calls out to svn), switching from Python 2.6's subprocess module to subprocess32: http://pypi.python.org/pypi/subprocess32/ appears to fix this problem.