Comment 3 for bug 1189385

Revision history for this message
Jack McCann (jack-mccann) wrote :

We've seen this a few times but have not gotten to the root cause. When we've seen this, it appears to be related to an AMQPConnectionException (trace below).

2013-04-26 18:32:00 ERROR [quantum.api.v2.resource] create failed
Traceback (most recent call last):
File "/usr/lib/python2.7/dist-packages/quantum/api/v2/resource.py", line 82, in resource
result = method(request=request, **args)
File "/usr/lib/python2.7/dist-packages/quantum/api/v2/base.py", line 370, in create
return notify({self._resource: self._view(obj)})
File "/usr/lib/python2.7/dist-packages/quantum/api/v2/base.py", line 350, in notify
notifier_method)
File "/usr/lib/python2.7/dist-packages/quantum/api/v2/base.py", line 234, in _send_dhcp_notification
self._dhcp_agent_notifier.notify(context, data, methodname)
File "/usr/lib/python2.7/dist-packages/quantum/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 131, in notify
self._notification(context, methodname, data, network_id)
File "/usr/lib/python2.7/dist-packages/quantum/api/rpc/agentnotifiers/dhcp_rpc_agent_api.py", line 82, in _notification
topic='%s.%s' % (topic, host))
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/proxy.py", line 113, in cast
rpc.cast(context, self._get_topic(topic), msg)
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/_init_.py", line 158, in cast
return _get_impl().cast(CONF, context, topic, msg)
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/impl_kombu.py", line 805, in cast
rpc_amqp.get_connection_pool(conf, Connection))
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/amqp.py", line 625, in cast
conn.topic_send(topic, rpc_common.serialize_msg(msg))
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/amqp.py", line 152, in _exit_
self._done()
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/amqp.py", line 141, in _done
self.connection.reset()
File "/usr/lib/python2.7/dist-packages/quantum/openstack/common/rpc/impl_kombu.py", line 596, in reset
self.channel = self.connection.channel()
File "/usr/lib/python2.7/dist-packages/kombu/connection.py", line 159, in channel
chan = self.transport.create_channel(self.connection)
File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 235, in create_channel
return connection.channel()
File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 144, in channel
return Channel(self, channel_id)
File "/usr/lib/python2.7/dist-packages/kombu/transport/pyamqplib.py", line 183, in _init_
super(Channel, self)._init_(*args, **kwargs)
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 82, in _init_
self._x_open()
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 471, in _x_open
(20, 11), # Channel.open_ok
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 95, in wait
self.channel_id, allowed_methods)
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/connection.py", line 231, in _wait_method
self.wait()
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 97, in wait
return self.dispatch_method(method_sig, args, content)
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 115, in dispatch_method
return amqp_method(self, args)
File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/connection.py", line 380, in _close
raise AMQPConnectionException(reply_code, reply_text, (class_id, method_id))
AMQPConnectionException: (503, u"COMMAND_INVALID - second 'channel.open' seen", (20, 10), 'Channel.open')

From the rabbitmq server log we see:

=ERROR REPORT==== 26-Apr-2013::18:32:00 ===
connection <0.4636.4664>, channel 1 - error:
{amqp_error,command_invalid,"second 'channel.open' seen",'channel.open'}

=INFO REPORT==== 26-Apr-2013::18:32:00 ===
closing TCP connection <0.4636.4664> from 10.14.4.10:43696

=INFO REPORT==== 26-Apr-2013::18:32:00 ===
accepted TCP connection on [::]:5672 from 10.14.4.10:56491

=INFO REPORT==== 26-Apr-2013::18:32:00 ===
starting TCP connection <0.1651.4844> from 10.14.4.10:56491