KeyError when checking if channel should be recycled

kdavis commented 7 years ago

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 commented 7 years ago

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

kdavis commented 7 years ago

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 commented 7 years ago

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 commented 7 years ago

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

mayhem commented 7 years ago

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 commented 7 years ago

A rewrite is in place?

mayhem commented 7 years ago

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

mayhem commented 7 years ago

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

kdavis commented 7 years ago

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 commented 7 years ago

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 commented 6 years ago

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 commented 5 years ago

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 commented 4 years ago

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

xuwei0455 commented 4 years ago

@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

wdtinc / flask-pika

KeyError when checking if channel should be recycled #8