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
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. /bugs.launchpad .net/bugs/ 855030 ption rc~20110909. r1155-0ub on Oneiric . Repeating the following: pymodules/ python2. 7/nova/ utils.py: 672 pymodules/ python2. 7/nova/ utils.py: 677 pymodules/ python2. 7/nova/ utils.py: 165 pymodules/ python2. 7/nova/ utils.py: 165 pymodules/ python2. 7/nova/ utils.py: 165 pymodules/ python2. 7/nova/ utils.py: 165 pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 628, in _process_data pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 673, in reply self.msg_ id, *args, **kwargs) pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 781, in msg_reply send(msg_ id, msg) pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 562, in __exit__ pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 547, in _done .reset( ) pymodules/ python2. 7/nova/ rpc/impl_ kombu.py" , line 382, in reset close() python2. 7/dist- packages/ amqplib/ client_ 0_8/channel. py", line 194, in close python2. 7/dist- packages/ amqplib/ client_ 0_8/abstract_ channel. py", line 97, in wait method( method_ sig, args, content) python2. 7/dist- packages/ amqplib/ client_ 0_8/abstract_ channel. py", line 115, in dispatch_method python2. 7/dist- packages/ amqplib/ client_ 0_8/channel. py", line 273, in _close ption: (404, u"NOT_FOUND - no exchange '3ff1ba7e274a4e c2a2b0a217d7532 c70' in vhost '/'", (60, 40), 'Channel. basic_publish' ) c2a2b0a217d7532 c70' in vhost '/'", (60, 40), 'Channel. basic_publish' ) to caller 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', 'AMQPChannelExc eption: (404, u"NOT_FOUND - no exchange \'3ff1ba7e274a4 ec2a2b0a217d753 2c70\' in vhost \'/\'", (60, 40), \'Channel. basic_publish\ ')\n'] 2011::13: 22:59 === not_found, c2a2b0a217d7532 c70' in vhost '/'", /etc/nova/ nova-compute. conf d_auth flagfile= /etc/nova/ nova.conf /usr/bin/ nova-dhcpbridge n=mysql: //nova: notnova@ 172.18. 0.141/nova 172.18. 0.141 host=172. 18.0.141 api_servers= 172.18. 0.141:9292 /var/log/ nova path=/var/ lib/nova path=/var/ lock/nova 172.18. 0.141:8773/ services/ Cloud 172.18. 0.141/32 range=172. 18.77.0/ 27 network_ dhcp_start= 172.18. 7.6 service= nova.image. glance. GlanceImageServ ice interface= eth1 network_ bridge= br100 manager= nova.network. manager. FlatDHCPManager interface= eth0 host=172. 18.0.141 /bugs.launchpad .net/nova/ +bug/855030/ +subscriptions
> 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:/
>
> Title:
> Encountering sporadic AMQPChannelExce
>
> Status in OpenStack Compute (Nova):
> New
>
> Bug description:
> Running one controller and one compute, using nova-network version
> 2011.3~
>
> 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/
> 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/
> 2011-09-20 13:22:59,296 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-save -t filter from (pid=1082) execute /usr/lib/
> 2011-09-20 13:22:59,311 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-restore from (pid=1082) execute /usr/lib/
> 2011-09-20 13:22:59,350 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-save -t nat from (pid=1082) execute /usr/lib/
> 2011-09-20 13:22:59,366 DEBUG nova.utils [-] Running cmd (subprocess): sudo iptables-restore from (pid=1082) execute /usr/lib/
> 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/
> (nova.rpc): TRACE: ctxt.reply(None, None)
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: msg_reply(
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: conn.direct_
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: self._done()
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: self.connection
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: self.channel.
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: (20, 41), # Channel.close_ok
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: return self.dispatch_
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: return amqp_method(self, args)
> (nova.rpc): TRACE: File "/usr/lib/
> (nova.rpc): TRACE: (class_id, method_id))
> (nova.rpc): TRACE: AMQPChannelExce
> (nova.rpc): TRACE:
> 2011-09-20 13:22:59,451 ERROR nova.rpc [-] Returning exception (404, u"NOT_FOUND - no exchange '3ff1ba7e274a4e
> 2011-09-20 13:22:59,452 ERROR nova.rpc [-] ['Traceback (most recent call last):\n', ' File "/usr/lib/
>
>
> I also see this at the same time in the rabbitmq log:
>
> =ERROR REPORT==== 20-Sep-
> connection <0.1061.0>, channel 1 - error:
> {amqp_error,
> "no exchange '3ff1ba7e274a4e
> 'basic.publish'}
>
>
>
> --flagfile=
> --use_deprecate
> --dhcpbridge_
> --dhcpbridge=
> --sql_connectio
> --s3_host=
> --rabbit_
> --glance_
> --logdir=
> --state_
> --lock_
> --verbose
> --ec2_url=http://
> --dmz_cidr=
> --fixed_
> --network_size=8
> --flat_
> --image_
> --bridge_
> --flat_
> --network_
> --public_
> --multi_host
> --osapi_
>
> To manage notifications about this bug go to:
> https:/