Comment 10 for bug 855030

Revision history for this message
Vish Ishaya (vishvananda) wrote : Re: [Bug 855030] Encountering sporadic AMQPChannelException

Hmm,

One further question. Are you using mysql or sqlite? Sqlite doesn't really support concurrency well, so you could be getting db locking errors that are bubbling up to the messaging layer. If you are using sqlite, could you see if you get the same error with mysql?

On Sep 22, 2011, at 11:11 AM, David Kranz wrote:

> I'm kind of at a loss here. The ampqlib version is the same as you said.
> I used pip to uninstall kombu and upgrade to 1.3.5. That was the latest
> version this morning though the latest seems to be 1.4.0 right how.
> Anyway it made no difference. I am no expert on the mess that is the
> relationship between python package versions between pip and dpkg so it
> is possible nova was still using the old kombu after my upgrade. I don't
> think so because just invoking python from the command line showed the
> new version of kombu when I imported it.
>
> This does happen under load in the sense that I used the euca command to
> create 4 instances at once. Has any one else done something like this
> with Oneiric? On the one hand it is hard to see how I am having this
> problem if others are not, but I don't see what I could be doing wrong
> either given that everything works for instance creations where this
> does not happen.
>
> --
> You received this bug notification because you are a member of Nova Bug
> Team, which is subscribed to OpenStack Compute (nova).
> https://bugs.launchpad.net/bugs/855030
>
> Title:
> Encountering sporadic AMQPChannelException
>
> Status in OpenStack Compute (Nova):
> New
>
> Bug description:
> Running one controller and one compute, using nova-network version
> 2011.3~rc~20110909.r1155-0ub on Oneiric . Repeating the following:
>
> Create four instances, terminate them.
>
> This mostly works but one in every three or four times, one of the vms
> does not come up and I see this error in the nova-network log. This
> can occur both in the controller node (also running compute) or the
> compute node. (contents of nova.conf follows)
>
> 2011-09-20 13:22:59,295 DEBUG nova.utils [-] Attempting to grab semaphore "iptables" for method "apply"... from (pid=1082) inner /usr/lib/pymodules/python2.7/nova/utils.py:672
> 2011-09-20 13:22:59,295 DEBUG nova.utils [-] Attempting to grab file lock "iptables" for method "apply"... from (pid=1082) inner /usr/lib/pymodules/python2.7/nova/utils.py:677
> 2011-09-20 13:22:59,296 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-save -t filter from (pid=1082) execute /usr/lib/pymodules/python2.7/nova/utils.py:165
> 2011-09-20 13:22:59,311 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-restore from (pid=1082) execute /usr/lib/pymodules/python2.7/nova/utils.py:165
> 2011-09-20 13:22:59,350 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-save -t nat from (pid=1082) execute /usr/lib/pymodules/python2.7/nova/utils.py:165
> 2011-09-20 13:22:59,366 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-restore from (pid=1082) execute /usr/lib/pymodules/python2.7/nova/utils.py:165
> 2011-09-20 13:22:59,424 ERROR nova.rpc [-] Exception during message handling
> (nova.rpc): TRACE: Traceback (most recent call last):
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 628, in _process_data
> (nova.rpc): TRACE: ctxt.reply(None, None)
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 673, in reply
> (nova.rpc): TRACE: msg_reply(self.msg_id, *args, **kwargs)
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 781, in msg_reply
> (nova.rpc): TRACE: conn.direct_send(msg_id, msg)
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 562, in __exit__
> (nova.rpc): TRACE: self._done()
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 547, in _done
> (nova.rpc): TRACE: self.connection.reset()
> (nova.rpc): TRACE: File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 382, in reset
> (nova.rpc): TRACE: self.channel.close()
> (nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 194, in close
> (nova.rpc): TRACE: (20, 41), # Channel.close_ok
> (nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 97, in wait
> (nova.rpc): TRACE: return self.dispatch_method(method_sig, args, content)
> (nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 115, in dispatch_method
> (nova.rpc): TRACE: return amqp_method(self, args)
> (nova.rpc): TRACE: File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 273, in _close
> (nova.rpc): TRACE: (class_id, method_id))
> (nova.rpc): TRACE: AMQPChannelException: (404, u"NOT_FOUND - no exchange '3ff1ba7e274a4ec2a2b0a217d7532c70' in vhost '/'", (60, 40), 'Channel.basic_publish')
> (nova.rpc): TRACE:
> 2011-09-20 13:22:59,451 ERROR nova.rpc [-] Returning exception (404, u"NOT_FOUND - no exchange '3ff1ba7e274a4ec2a2b0a217d7532c70' in vhost '/'", (60, 40), 'Channel.basic_publish') to caller
> 2011-09-20 13:22:59,452 ERROR nova.rpc [-] ['Traceback (most recent call last):\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 628, in _process_data\n ctxt.reply(None, None)\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 673, in reply\n msg_reply(self.msg_id, *args, **kwargs)\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 781, in msg_reply\n conn.direct_send(msg_id, msg)\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 562, in __exit__\n self._done()\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 547, in _done\n self.connection.reset()\n', ' File "/usr/lib/pymodules/python2.7/nova/rpc/impl_kombu.py", line 382, in reset\n self.channel.close()\n', ' File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 194, in close\n (20, 41), # Channel.close_ok\n', ' File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 97, in wait\n return self.dispatch_method(method_sig, args, content)\n', ' File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/abstract_channel.py", line 115, in dispatch_method\n return amqp_method(self, args)\n', ' File "/usr/lib/python2.7/dist-packages/amqplib/client_0_8/channel.py", line 273, in _close\n (class_id, method_id))\n', 'AMQPChannelException: (404, u"NOT_FOUND - no exchange \'3ff1ba7e274a4ec2a2b0a217d7532c70\' in vhost \'/\'", (60, 40), \'Channel.basic_publish\')\n']
>
>
> I also see this at the same time in the rabbitmq log:
>
> =ERROR REPORT==== 20-Sep-2011::13:22:59 ===
> connection <0.1061.0>, channel 1 - error:
> {amqp_error,not_found,
> "no exchange '3ff1ba7e274a4ec2a2b0a217d7532c70' in vhost '/'",
> 'basic.publish'}
>
>
>
> --flagfile=/etc/nova/nova-compute.conf
> --use_deprecated_auth
> --dhcpbridge_flagfile=/etc/nova/nova.conf
> --dhcpbridge=/usr/bin/nova-dhcpbridge
> --sql_connection=mysql://nova:notnova@172.18.0.141/nova
> --s3_host=172.18.0.141
> --rabbit_host=172.18.0.141
> --glance_api_servers=172.18.0.141:9292
> --logdir=/var/log/nova
> --state_path=/var/lib/nova
> --lock_path=/var/lock/nova
> --verbose
> --ec2_url=http://172.18.0.141:8773/services/Cloud
> --dmz_cidr=172.18.0.141/32
> --fixed_range=172.18.77.0/27
> --network_size=8
> --flat_network_dhcp_start=172.18.7.6
> --image_service=nova.image.glance.GlanceImageService
> --bridge_interface=eth1
> --flat_network_bridge=br100
> --network_manager=nova.network.manager.FlatDHCPManager
> --public_interface=eth0
> --multi_host
> --osapi_host=172.18.0.141
>
> To manage notifications about this bug go to:
> https://bugs.launchpad.net/nova/+bug/855030/+subscriptions