KeyError: 19

[Nick Jennings]

Hi All, I was running tornado 2.3 and got this message today after an
on_close() call. I just upgraded to 2.4, so there's a chance the error
won't come back, but I was wondering if anyone had seen this before?


[ERROR] 05-09-2012 19:51:13 [140320774530816] ioloop.py start[337]:
Exception in I/O handler for fd 13
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py",
line 327, in start
self._handlers[fd](fd, events)
KeyError: 13
[INFO] 05-09-2012 19:51:13 [140320782923520] listener.py
_unregister[334]: d1f1470d-1f81-46ad-a341-8ffcdd0ab3de
[ERROR] 05-09-2012 19:55:00 [140320782923520] ioloop.py start[337]:
Exception in I/O handler for fd 7
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py",
line 327, in start
self._handlers[fd](fd, events)
KeyError: 7
[ERROR] 05-09-2012 19:56:23 [140320774530816] ioloop.py start[337]:
Exception in I/O handler for fd 19
Traceback (most recent call last):
File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py",
line 327, in start
self._handlers[fd](fd, events)
KeyError: 19


Cheers
Nick

[Lorenzo Bolla]

Yes, I saw it before, with old Tornado. It had to do with the the
client/OS/nginx (can't remember) closing the socket used to talk to
Tornado and Tornado throwing this error when trying to clean things
up. It could be safely ignored.

L.

[Ben Darnell]

I've seen this error before, but haven't personally run in to it in a
while. I don't think there were any relevant changes between 2.3 and
2.4 so the bug is probably still around. Assuming this is just a case
of one handler unregistering another while it still has events in the
queue, we should probably just skip over any events where the fd is no
longer in _handlers.

-Ben

[A. Jesse Jiryu Davis]

I've also seen it, frequently enough that in Motor I wrap an IOStream.close() call in "except KeyError:". In that case the IOStream is connected to MongoDB and some event (server went down, etc.) has closed the underlying socket. Lorenzo's explanation sounds right to me.

[Nick Jennings]

Thanks for the input guys. I modified ioloop.py to pass on KeyError,
however I just ran into another case (two lines above the current call
I added the exception for):

Exception in thread Thread-6:

Traceback (most recent call last):

File "/usr/lib/python2.7/threading.py", line 551, in __bootstrap_inner
self.run()
File "/opt/belvedere/notify/listener.py", line 453, in run
tornado.ioloop.IOLoop.instance().start()
File "/usr/local/lib/python2.7/dist-packages/tornado/ioloop.py",
line 325, in start
fd, events = self._events.popitem()
KeyError: 'popitem(): dictionary is empty'

Any idea what that could be about? I've never seen it before. Should I
wrap that call in a try and pass on KeyError again?
Cheers
Nick

[aliane abdelouahab]

it's bizarre because if you "catched" the Error then, it dont show the
error next time, so the KeyError here happens in other place, not
where you get the exception handling.

[Nick Jennings]

Yeah, it's happening two lines up, line 325 of iostream.py during the
popitem() call.

[Ben Darnell]

This looks like a threading problem - are you calling remove_handler
from some other thread? Remember that it's not safe to do anything
with an IOLoop from another thread except add_callback.

-Ben

On Tue, Sep 11, 2012 at 7:27 AM, Nick Jennings

[Nick Jennings]

Hi Ben,

On Tue, Sep 11, 2012 at 7:27 PM, Ben Darnell <b...@bendarnell.com> wrote:
> This looks like a threading problem - are you calling remove_handler
> from some other thread? Remember that it's not safe to do anything
> with an IOLoop from another thread except add_callback.
>

I just grepped my code and yes, in fact, it seems in the on_close()
handler I'm calling self.session.remove_handler(self). I don't recall
when or why I added this:

line 238:
https://bitbucket.org/silverbucket/belvedere/src/8ad37aec16d5/notify/listener.py

I will remove that call and see if it helps. If you see anything else
I may be doing incorrectly I'd be greatly appreciative of the
feedback!
Thanks,
Nick

[Ben Darnell]

I don't see where you're creating Listener objects, but you're
starting IOLoop.instance both in Listener.run and in the __main__
block. This is almost certainly not what you want; it looks like each
Listener thread should create its own IOLoop.

-Ben

On Tue, Sep 11, 2012 at 10:49 AM, Nick Jennings

[Nick Jennings]

Hi Ben,

On Tue, Sep 11, 2012 at 7:53 PM, Ben Darnell <b...@bendarnell.com> wrote:
> I don't see where you're creating Listener objects, but you're
> starting IOLoop.instance both in Listener.run and in the __main__
> block. This is almost certainly not what you want; it looks like each
> Listener thread should create its own IOLoop.

The listener.py is only run directly when I'm doing quick tests.
Normally it's run from here:

line 41:
https://bitbucket.org/silverbucket/belvedere/src/8ad37aec16d5/notify/plugin.py

And can be several listeners on different ports. So, in the intended
use-case. just Listener.run() is called, not the __main__ block.

With that in mind, do you think it makes sense to have the IOLoop
start in Listener.run()?

[Ben Darnell]

If there are multiple Listeners then this definitely won't work. If
you want to use threads you'll need to give each thread its own
IOLoop.

-Ben

On Tue, Sep 11, 2012 at 11:11 AM, Nick Jennings

[Nick Jennings]

Hi Ben,

On Tue, Sep 11, 2012 at 9:40 PM, Ben Darnell <b...@bendarnell.com> wrote:
> If there are multiple Listeners then this definitely won't work. If
> you want to use threads you'll need to give each thread its own
> IOLoop.
>

Isn't that what I've got there?

In plugin.py a thread is created using the Listener class (in
listener.py) which inherits threading.Thread. So plugin.py calls
start() to start each thread.

From there the Listener.run() executes the IOLoop. So it's contained
within that thread. Is that what you mean or am I missing something?
This is my first foray into this realm so it's very possible I'm
misunderstanding what you're saying.

Thanks for your help!

[Ben Darnell]

No, each thread is reusing the same IOLoop, the singleton returned by
IOLoop.instance().

In Listener.run, you need to create an IOLoop and then use that IOLoop
for everything that runs on that thread:

self.io_loop = IOLoop()
self.application.listen(self.port, io_loop=self.io_loop)
self.io_loop.start()

-Ben

On Tue, Sep 11, 2012 at 12:51 PM, Nick Jennings

[Nick Jennings]

That makes perfect sense! Don't know why I didn't realize that before.
Thanks a lot for the clarification Ben!
-Nick