KeyError when checking if channel should be recycled

[kdavis]

After 16 requests, the error starts occurring.

The params:

app.config['FLASK_PIKA_POOL_PARAMS'] = {
    'pool_size': 16,
    'pool_recycle': 600
}

The trace stack is shown below

File "D:\project\controllers\pikatest.py", line 32, in test_place
    ch = pika.channel()
  File "C:\Program Files (x86)\Python36-32\lib\site-packages\flask_pika.py", line 132, in channel
    if self.__should_recycle_channel(ch):
  File "C:\Program Files (x86)\Python36-32\lib\site-packages\flask_pika.py", line 115, in __should_recycle_channel
    recycle_time = self.channel_recycle_times[hash(channel)]
KeyError: 4410099

The code that gets executed every request.

ch = pika.channel()
ch.basic_publish(exchange='', routing_key='place', body=json.dumps(body))
pika.return_channel(ch)

[mayhem]

We're seeing the same problem -- have you got some interesting workaround?

[kdavis]

Nope, not found a resolution yet. The queue section of my project is currently on hold. Could it be to do with the latest Python versions?

@mayhem What Python version are you using?

However, it seems to be an issue with the hashing I believe?

[mayhem]

3.6 here -- I'm going to review the whole code in a little while and see if I can spot any obvious mistakes.

[kdavis]

3.6 here too. Maybe a recent update to Python broke this extension? Let me know when you find anything

[mayhem]

There are several things about this module I dislike -- for instance why are recycle times not stored with channels? They could just be in one dict in the queue and that would ensure they could not get separated.

[kdavis]

A rewrite is in place?

[mayhem]

I'm probably going to abandon Flask-pika, and use pika-pool instead.

[mayhem]

Yep, https://pypi.python.org/pypi/pika-pool seems a lot more solid. Better interface too.

[kdavis]

I'll leave this issue open until someone at WDTInc wishes to look at this and/or if another user comes here looking for a solution.

[lrobb-zz]

We haven't seen this behavior... I will note that we are on python 2.7 where this extension is used. Do you have output from the app logger?

[youzipi]

I had the same problem. after review the code and add some extra logs i found the problem. the reason is that the ProxyContextManager and channel return different hash.

• environment:

python=3.5.1
flask=0.12
pika==0.10.0

below is part of log, search 0x105dc3128 and 0x108306390 on this page you can find the order:

• app request channel
• create channel 0x105dc3128
• set recycle for channel 0x105dc3128
• wrap channel 0x105dc3128 to proxy 0x108306390
• app use proxy 0x108306390
• app return proxy 0x108306390
  • queue.put proxy 0x108306390
• app request channel
• queue.get => proxy 0x108306390

and then, proxy 0x108306390's hash is 277022265 but in the channel_recycle_times is -9223372036580195566 ( the hash of channel 0x105dc3128) it crash.

Connected to pydev debugger (build 171.3780.115)
__set_recycle_for_channel::channel= <flask_pika.PrePopulationChannel object at 0x108306860>
__set_recycle_for_channel::hash(channel) 277022342
__set_recycle_for_channel::channel= <flask_pika.PrePopulationChannel object at 0x1083068d0>
__set_recycle_for_channel::hash(channel) 277022349
running dev
02-27-2018 16:22:07 - INFO - connect channel
__should_recycle_channel::channel= <flask_pika.PrePopulationChannel object at 0x108306860>
hash(channel)= 277022342
self.channel_recycle_times =
{277022349: -1, 277022342: -1}
02-27-2018 16:22:07 - INFO - Connecting to 192.168.0.107:5672
__create_channel::channel=<pika.adapters.blocking_connection.BlockingChannel object at 0x105dc3128>
__set_recycle_for_channel::channel= <pika.adapters.blocking_connection.BlockingChannel object at 0x105dc3128>
__set_recycle_for_channel::hash(channel) -9223372036580195566
return_channel::channel= <flask_pika.ProxyContextManager object at 0x108306390>
pool_queue=
[277022349, 277022265]
02-27-2018 16:22:07 - INFO - Created channel=1
02-27-2018 16:22:08 - INFO - connect channel
02-27-2018 16:22:08 - INFO - Connecting to 192.168.0.107:5672
hash(channel)= 277022349
self.channel_recycle_times =
{277022349: -1, -9223372036580195566: 1519720327000}
02-27-2018 16:22:08 - INFO - Created channel=1
__create_channel::channel=<pika.adapters.blocking_connection.BlockingChannel object at 0x108bc0cc0>
__set_recycle_for_channel::channel= <pika.adapters.blocking_connection.BlockingChannel object at 0x108bc0cc0>
__set_recycle_for_channel::hash(channel) 277594316
return_channel::channel= <flask_pika.ProxyContextManager object at 0x108bc0cf8>
pool_queue=
[277022265, -9223372036577181489]
######################
######################
######################
__should_recycle_channel::channel= <flask_pika.ProxyContextManager object at 0x108306390>
hash(channel)= 277022265
__should_recycle_channel::ProxyContextManager.instance(aka: channel)=<pika.adapters.blocking_connection.BlockingChannel object at 0x105dc3128>
self.channel_recycle_times =
{277594316: 1519720328000, -9223372036580195566: 1519720327000}
######################
######################
######################
02-27-2018 16:22:09 - INFO - connect channel
[2018-02-27 16:22:09,777] ERROR in app: Exception on /auth [POST]
Traceback (most recent call last):
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/app.py", line 1982, in wsgi_app
    response = self.full_dispatch_request()
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/app.py", line 1614, in full_dispatch_request
    rv = self.handle_user_exception(e)
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/app.py", line 1517, in handle_user_exception
    reraise(exc_type, exc_value, tb)
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/_compat.py", line 33, in reraise
    raise value
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/app.py", line 1612, in full_dispatch_request
    rv = self.dispatch_request()
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask/app.py", line 1598, in dispatch_request
    return self.view_functions[rule.endpoint](**req.view_args)
  File "/Users/youzipi/projects/1zhijia/master-name-server/app.py", line 125, in wrapper
    result = f(*args, **kwargs)
  File "/Users/youzipi/projects/1zhijia/master-name-server/server.py", line 72, in auth
    channel = get_channel()
  File "/Users/youzipi/projects/1zhijia/master-name-server/app.py", line 105, in get_channel
    channel = fpika.channel()  # type:Channel
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask_pika.py", line 145, in channel
    if self.__should_recycle_channel(ch):
  File "/Users/youzipi/.pyenv/versions/3.5.1/lib/python3.5/site-packages/flask_pika.py", line 128, in __should_recycle_channel
    recycle_time = self.channel_recycle_times[hash(channel)]
KeyError: 277022265

more test: after I comment these lines, it works.

# flask_pika.Pika#channel
  def channel(self):
      ....
        # add support context manager
        def close():
            self.return_channel(ch)
        ch = ProxyContextManager(instance=ch, close_callback=close)

here is my PR:#9

[oren-sarid]

I am seeing this issue now as well, Python 3.5.6, Flask- Pika 0.3.8, Flask 1.0.2 and the latest RabbitMQ docker (rabbitmq:3.6.11-management-alpine)

Any way I can workaround this?

    with self.rabbit_conn.channel() as ch:
  File "/usr/local/lib/python3.5/site-packages/flask_pika.py", line 132, in channel
    if self.__should_recycle_channel(ch):
  File "/usr/local/lib/python3.5/site-packages/flask_pika.py", line 115, in __should_recycle_channel
    recycle_time = self.channel_recycle_times[hash(channel)]
KeyError: 8763097123192

[jpmeijers]

I'm also affected by this. Using the latest pip release of flask-pika in Python 3.6.9

[xuwei0455]

@youzipi tks for your report and I have some other suggestions.

For my understanding, ProxyContextManager is a proxy that needs to be transparent.

So, we can only modify the hash method to return the proxied instance's hash.

like this:

class ProxyContextManager(object):
    """ ... """
    def __hash__(self):
        return hash(self.instance)

And this is my PR, https://github.com/wdtinc/flask-pika/pull/12