Connection to broker lost?


#1

Any idea why this happens?

I let the app run on cloud foundry for a few days and this happens

2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR Connection to broker lost, trying to re-establish connection...
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR Traceback (most recent call last):
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/mixins.py", line 199, in consume
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     conn.drain_events(timeout=safety_interval)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/connection.py", line 288, in drain_events
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return self.transport.drain_events(self.connection, **kwargs)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/transport/pyamqp.py", line 95, in drain_events
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return connection.drain_events(**kwargs)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/connection.py", line 303, in drain_events
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     chanmap, None, timeout=timeout,
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/connection.py", line 366, in _wait_multiple
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     channel, method_sig, args, content = read_timeout(timeout)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/connection.py", line 337, in read_timeout
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return self.method_reader.read_method()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/method_framing.py", line 189, in read_method
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     raise m
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/method_framing.py", line 107, in _next_method
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     frame_type, channel, payload = read_frame()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/transport.py", line 154, in read_frame
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     frame_header = read(7, True)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/transport.py", line 277, in _read
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     s = recv(n - len(rbuf))
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/greenio/base.py", line 360, in recv
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return self._recv_loop(self.fd.recv, b'', bufsize, flags)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/greenio/base.py", line 354, in _recv_loop
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     self._read_trampoline()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/greenio/base.py", line 325, in _read_trampoline
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     timeout_exc=socket_timeout('timed out'))
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/greenio/base.py", line 207, in _trampoline
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     mark_as_closed=self._mark_as_closed)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/hubs/__init__.py", line 163, in trampoline
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return hub.switch()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/eventlet/hubs/hub.py", line 295, in switch
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return self.greenlet.switch()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR socket.timeout: timed out
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR During handling of the above exception, another exception occurred:
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR Traceback (most recent call last):
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/mixins.py", line 177, in run
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     for _ in self.consume(limit=None):  # pragma: no cover
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/mixins.py", line 201, in consume
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     conn.heartbeat_check()
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/connection.py", line 277, in heartbeat_check
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return self.transport.heartbeat_check(self.connection, rate=rate)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/kombu/transport/pyamqp.py", line 135, in heartbeat_check
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     return connection.heartbeat_tick(rate=rate)
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR   File "/home/vcap/deps/0/conda/envs/dep_env/lib/python3.5/site-packages/amqp/connection.py", line 915, in heartbeat_tick
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR     raise ConnectionForced('Too many heartbeats missed')
   2018-08-12T09:25:04.25-0700 [APP/PROC/WEB/0] ERR amqp.exceptions.ConnectionForced: Too many heartbeats missed
   2018-08-12T09:25:16.28-0700 [APP/PROC/WEB/0] ERR Error connecting to broker at amqp://G6VXlVHbjD4VB_Vk:ym1FDCGS7IiCfKG2@10.11.241.15:50164 (Socket closed).
   2018-08-12T09:25:16.28-0700 [APP/PROC/WEB/0] ERR Retrying in 2.0 seconds.
   2018-08-12T09:25:16.57-0700 [APP/PROC/WEB/0] ERR Retrying in 2.0 seconds.
   2018-08-12T09:25:16.57-0700 [APP/PROC/WEB/0] ERR Error connecting to broker at amqp://G6VXlVHbjD4VB_Vk:ym1FDCGS7IiCfKG2@10.11.241.15:50164 (Socket closed).
   2018-08-12T09:25:17.45-0700 [APP/PROC/WEB/0] ERR Error connecting to broker at amqp://G6VXlVHbjD4VB_Vk:ym1FDCGS7IiCfKG2@10.11.241.15:50164 (Socket closed).
   2018-08-12T09:25:17.45-0700 [APP/PROC/WEB/0] ERR Retrying in 2.0 seconds.

#2

Your service has lost its connection to the RabbitMQ broker. It will keep retrying like this until it manages to reconnect. It looks like your broker is refusing new connections.

I’ve not used CloudFoundry before. How is the RabbitMQ broker configured?


#3

We receive a ampq uri from CF. Is there a way to configure heart in nameko ? Is it using a URL like amqp://host:port?heartbeat=300 ?


#4

Heartbeats are enabled by default on consumer connections since Nameko 2.4.4. The default value is 60 seconds and you can change it by setting the HEARTBEAT config key.

I doubt that heartbeats will help in this scenario though – your service is failing to reconnect to the broker. A (shorter) heartbeat will probably just mean that it notices the disconnection sooner. Keeping the connection alive with a heartbeat may help if Cloud Foundry is removing the broker because it thinks its idle or something.