KeyError: 10 in io-loop

[phoet]

we are running a recent version of thumbor (f813c18) and once and a while we see huge stack traces where i don't have a clue for how to debug it. unfortunately we don't see which image is causing this as we have many thousand requests on that app.

it looks like this is killing the whole tornado io-loop, wreak havoc and leaving the instance unhealthy.

Jul 22 12:44:00 thumbor thumbor:  2016-07-22 10:44:00 tornado.application:ERROR Exception in callback None
Jul 22 12:44:00 thumbor thumbor:  Traceback (most recent call last):
Jul 22 12:44:00 thumbor thumbor:  File "/usr/local/lib/python2.7/site-packages/tornado/ioloop.py", line 886, in start
Jul 22 12:44:00 thumbor thumbor:  fd_obj, handler_func = self._handlers[fd]
Jul 22 12:44:00 thumbor thumbor:  KeyError: 10
Jul 22 12:44:00 thumbor thumbor:  2016-07-22 10:44:00 tornado.application:ERROR Exception in callback None
Jul 22 12:44:00 thumbor thumbor:  Traceback (most recent call last):
Jul 22 12:44:00 thumbor thumbor:  File "/usr/local/lib/python2.7/site-packages/tornado/ioloop.py", line 886, in start
Jul 22 12:44:00 thumbor thumbor:  fd_obj, handler_func = self._handlers[fd]
Jul 22 12:44:00 thumbor thumbor:  KeyError: 10
Jul 22 12:44:00 thumbor thumbor:  2016-07-22 10:44:00 tornado.application:ERROR Exception in callback None
Jul 22 12:44:00 thumbor thumbor:  Traceback (most recent call last):
Jul 22 12:44:00 thumbor thumbor:  File "/usr/local/lib/python2.7/site-packages/tornado/ioloop.py", line 886, in start
Jul 22 12:44:00 thumbor thumbor:  fd_obj, handler_func = self._handlers[fd]
Jul 22 12:44:00 thumbor thumbor:  KeyError: 10

[...  many hundred lines to come ...]

[rfloriano]

Hi @phoet,
I'm confused about this issue.
Can you paste the complete traceback?

[phoet]

created a gist with the complete stack trace: https://gist.github.com/phoet/7bb0b898b59e4603e6a00e95278a4d63

[savar]

@phoet does this still happen to you with a recent version?

[phoet]

unfortunately, i'm not working on that project any more. maybe @sbstjn want's to take over?

[masom]

Seems like a file descriptor is being closed, ( the fd 10 ) but is still registered in tornado.

[savar]

yeah but isn't this a tornado interna part or are we messing with tornado? It doesn't look like (starting the ioloop and using 2 callbacks, but one had an issue which is fixed in #808 )

[masom]

Jul 22 12:44:00 thumbor thumbor:  fd_obj, handler_func = self._handlers[fd]
Jul 22 12:44:00 thumbor thumbor:  KeyError: 10

What is raising the KeyError is self._handlers[10], which is a file descriptor for tornado.

[savar]

what I mean was: is this a thumbor bug or a tornado bug? :)

[masom]

@savar Not sure, probably a tornado bug but might be induced by Thumbor.

Thumbor relies on so many third-party dependencies it's hard to know why something fails.

[savar]

so we need more information from @sbstjn which version is he using.. except the threadpool part I don't see any chance to mess around with tornado (but I didn't check everything)

[sbstjn]

We have not seen the KeyError: 10 in a while. I'm digging through the log files, but could not find a related entry in the last weeks …

[savar]

so @sbstjn should we close the issue and re-open it in case you have this issue again?

[sbstjn]

Yes, feel free to close the issue :)

[savar]

I cannot do that :D .. @phoet or @masom ?

[phoet]

thx anyways

[imirzadeh]

This link provide good details about this issue:
http://y.tsutsumi.io/keyerror-in-self_handlers-a-journey-deep-into-tornados-internals.html