Cinder Volume and rabbitmq connections is getting terminated very frequently

[Satyanarayana Patibandla]

High level description:

We are using master branch code to deploy multinode openstack using kolla project. After deploying the services when we verify cinder volume logs, we can see cinder volume - rabbitmq connection terminated error messages. The first error appears after one hour from starting cinder volume. After that every four minutes there is a error saying that cinder volume - rabbitmq connection is terminated again.

Pre-conditions:
Mutinode deployment using master branch.

Error logs:

cinder-volume:

2016-12-27 19:39:34.030 63 ERROR oslo.messaging._drivers.impl_rabbit [-] [db4b0016-15e2-486d-831f-2bce7e396a1b] AMQP server x.x.x.x:5672 closed the connection. Check login credentials: Socket closed.
2016-12-27 19:43:20.846 63 INFO oslo.messaging._drivers.impl_rabbit [-] A recoverable connection/channel error occurred, trying to reconnect: Socket closed

rabbitmq:

=ERROR REPORT==== 27-Dec-2016::19:36:05 ===
closing AMQP connection <0.11343.0> (x.x.x.x:39353 -> x.x.x.x:5672 - cinder-volume:63:db4b0016-15e2-486d-831f-2bce7e396a1b):
missed heartbeats from client, timeout: 60s

Version:
master branch

Perceived severity: High

[Satyanarayana Patibandla (satya-patibandla)]

It seems the all TCP connections created by cinder volume service are getting closed and reestablished and then again closed. This process continues. This is happening only for cinder-volume service.

After deploying cinder services:

(cinder-volume)[root@xyz700 /]# date
Thu Dec 29 13:12:52 UTC 2016
(cinder-volume)[root@slcan700 /]# lsof -np 57 | grep 'amqp\|mysql'
cinder-vo 57 cinder 7u IPv4 334254 0t0 TCP 10.241.70.102:60554->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 8u IPv4 279463 0t0 TCP 10.241.70.80:52225->10.241.70.80:amqp (ESTABLISHED)
cinder-vo 57 cinder 11u IPv4 334255 0t0 TCP 10.241.70.102:60556->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 12u IPv4 253549 0t0 TCP 10.241.70.80:44608->10.241.70.80:amqp (ESTABLISHED)
cinder-vo 57 cinder 13u IPv4 334256 0t0 TCP 10.241.70.102:60559->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 14u IPv4 253548 0t0 TCP 10.241.70.80:60119->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 16u IPv4 334257 0t0 TCP 10.241.70.102:60561->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 21u IPv4 279464 0t0 TCP 10.241.70.80:39505->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 22u IPv4 279465 0t0 TCP 10.241.70.80:39507->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 24u IPv4 285372 0t0 TCP 10.241.70.80:48079->10.241.70.81:amqp (ESTABLISHED)

After 10 mins:

(cinder-volume)[root@xyz700 /]# date; lsof -np 57 | grep 'amqp\|mysql'
Thu Dec 29 13:22:28 UTC 2016
cinder-vo 57 cinder 7u IPv4 334254 0t0 TCP 10.241.70.102:60554->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 8u IPv4 279463 0t0 TCP 10.241.70.80:52225->10.241.70.80:amqp (ESTABLISHED)
cinder-vo 57 cinder 11u IPv4 334255 0t0 TCP 10.241.70.102:60556->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 12u IPv4 253549 0t0 TCP 10.241.70.80:44608->10.241.70.80:amqp (ESTABLISHED)
cinder-vo 57 cinder 13u IPv4 334256 0t0 TCP 10.241.70.102:60559->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 14u IPv4 253548 0t0 TCP 10.241.70.80:60119->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 16u IPv4 334257 0t0 TCP 10.241.70.102:60561->10.241.70.102:mysql (ESTABLISHED)
cinder-vo 57 cinder 18u IPv4 515267 0t0 TCP 10.241.70.80:53462->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 21u IPv4 279464 0t0 TCP 10.241.70.80:39505->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 22u IPv4 279465 0t0 TCP 10.241.70.80:39507->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 24u IPv4 285372 0t0 TCP 10.241.70.80:48079->10.241.70.81:amqp (ESTABLISHED)

After 27 mins:

(cinder-volume)[root@xyz700 /]# date; lsof -np 57 | grep 'amqp\|mysql'
Thu Dec 29 13:39:25 UTC 2016
cinder-vo 57 cinder 7u IPv4 732537 0t0 TCP 10.241.70.80:52802->10.241.70.81:amqp (ESTABLISHED)
cinder-vo 57 cinder 8u IPv4 279463 0t0 TCP 10.241.70.80:52225->10.241.70.80:amqp (ESTABLISHED)
cinder-vo 57 cinde...

[Satya Sanjibani Routray (satroutr)]

seems its a regression "https://bugs.launchpad.net/cinder/+bug/1167841"