[Build "Ubuntu 12.04.3 LTS" 2.0-2434~icehouse]:VM spawn failed due to exception in /usr/lib/python2.7/dist-packages/contrail_vrouter_api/vrouter_api.py", line 128, in add_port

Bug #1389157 reported by Sandip Dey
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
Juniper Openstack
Fix Committed
Medium
Hampapur Ajay
R2.0
Fix Committed
Medium
Hampapur Ajay
R2.1
Fix Committed
Medium
Hampapur Ajay

Bug Description

VM spawn failed. Error as below.

Logs saved at http://mayamruga/Docs/bugs/<bug-id>

2014-11-03 21:47:47.503 2339 AUDIT nova.compute.manager [req-19144961-bdde-42a1-af1b-7896791594f3 0f0adedc1a284424bc86b4f89c140536 7f422a31d0e14a719697f8881c7ce7e8] [instance: cf8c7cfa-06ad-426b-ab04-4ce39ce8c689] Terminating instance
2014-11-03 21:47:47.858 2339 ERROR nova.compute.manager [req-04b601f4-a2ad-40c1-80c0-a3f027a3f39b 9b0f7f00cbe84789bceee9ede888d7cc 7f422a31d0e14a719697f8881c7ce7e8] [instance: a067ca59-eb29-48af-97c8-f976b706c965] Instance failed to spawn
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] Traceback (most recent call last):
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1717, in _spawn
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] block_device_info)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 2265, in spawn
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] block_device_info)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 3667, in _create_domain_and_network
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] self.plug_vifs(instance, network_info)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 858, in plug_vifs
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] self.vif_driver.plug(instance, vif)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/nova_contrail_vif/contrailvif.py", line 207, in plug
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] **kwargs)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/vrouter_api.py", line 128, in add_port
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] result = self._client.AddPort([data])
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/gen_py/instance_service/InstanceService.py", line 150, in AddPort
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] return self.recv_AddPort()
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/gen_py/instance_service/InstanceService.py", line 161, in recv_AddPort
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] (fname, mtype, rseqid) = self._iprot.readMessageBegin()
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/protocol/TBinaryProtocol.py", line 126, in readMessageBegin
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] sz = self.readI32()
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/protocol/TBinaryProtocol.py", line 206, in readI32
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] buff = self.trans.readAll(4)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/transport/TTransport.py", line 58, in readAll
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] chunk = self.read(sz - have)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/transport/TTransport.py", line 271, in read
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] self.readFrame()
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/transport/TTransport.py", line 275, in readFrame
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] buff = self.__trans.readAll(4)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/transport/TTransport.py", line 58, in readAll
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] chunk = self.read(sz - have)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/thrift/transport/TSocket.py", line 103, in read
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] buff = self.handle.recv(sz)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/eventlet/greenio.py", line 262, in recv
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] timeout_exc=socket.timeout("timed out"))
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/eventlet/hubs/__init__.py", line 151, in trampoline
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] listener = hub.add(hub.READ, fileno, current.switch)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/eventlet/hubs/epolls.py", line 48, in add
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] listener = BaseHub.add(self, evtype, fileno, cb)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] File "/usr/lib/python2.7/dist-packages/eventlet/hubs/hub.py", line 126, in add
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] evtype, fileno, evtype))
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965] RuntimeError: Second simultaneous read on fileno 9 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False)
2014-11-03 21:47:47.858 2339 TRACE nova.compute.manager [instance: a067ca59-eb29-48af-97c8-f976b706c965]
2014-11-03 21:47:48.349 2339 ERROR nova.compute.manager [req-093c796a-27dd-41cd-8372-99ed971fa4d5 0f0adedc1a284424bc86b4f89c140536 7f422a31d0e14a719697f8881c7ce7e8] [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] Instance failed to spawn
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] Traceback (most recent call last):
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/nova/compute/manager.py", line 1717, in _spawn
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] block_device_info)
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 2265, in spawn
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] block_device_info)
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 3667, in _create_domain_and_network
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] self.plug_vifs(instance, network_info)
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/nova/virt/libvirt/driver.py", line 858, in plug_vifs
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] self.vif_driver.plug(instance, vif)
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/nova_contrail_vif/contrailvif.py", line 207, in plug
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] **kwargs)
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/vrouter_api.py", line 128, in add_port
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] result = self._client.AddPort([data])
2014-11-03 21:47:48.349 2339 TRACE nova.compute.manager [instance: c3a7fc44-106b-4c49-ab69-2f97bd71a9cf] AttributeError: 'NoneType' object has no attribute 'AddPort'

Tags: sanity vrouter
tags: added: blocker
information type: Proprietary → Public
Revision history for this message
Ashish Ranjan (aranjan-n) wrote :

Pedro, Ajay

  Could you analyze this bug. From my limited understanding of python, the code for add_port in vrouter_api.py looks buggy.

https://github.com/Juniper/contrail-controller/blob/master/src/vnsw/contrail-vrouter-api/contrail_vrouter_api/vrouter_api.py

If we set _client to ‘None’, depending on where we are in the function we can have exception. Isn’t it? Is intention is to run add_port exclusively. If yes, then we should have a lock. I think from the bt it feels like there is some kind of concurrency issue. Any insight will be helpful.

Bug link:
https://bugs.launchpad.net/juniperopenstack/+bug/1389157

thanks
Ashish

Changed in juniperopenstack:
importance: Undecided → Medium
assignee: nobody → Hampapur Ajay (hajay)
tags: added: releasenote
removed: blocker
Revision history for this message
Kumar Harsh (hkumar) wrote :
Download full text (9.3 KiB)

Hit this issue in [Build "Ubuntu 14.04 LTS" 2.0-22~juno] MultiNode Single Intf Sanity

While trying to spawn vm in testcase 'test_mx_gateway '

Topology :
Config Nodes : [u'nodei11', u'nodei12']
Control Nodes : [u'nodei12', u'nodei13']
Compute Nodes : [u'nodei14', u'nodei15']
Openstack Node : nodei11
WebUI Node : nodei11
Analytics Nodes : [u'nodei11']

/var/log/nova/nova-compute.log :

2014-12-24 07:35:29.582 2180 AUDIT nova.compute.claims [req-f5ae398e-014f-4ab6-821e-deae98200d10 None] [instance: c13062f0-1fbc-4425-ae07-b4e8babe785b] Claim successful
2014-12-24 07:35:29.754 2180 INFO nova.scheduler.client.report [req-f5ae398e-014f-4ab6-821e-deae98200d10 None] Compute_service record updated for ('nodei14', 'nodei14.englab.juniper.net')
2014-12-24 07:35:29.938 2180 INFO nova.scheduler.client.report [req-f5ae398e-014f-4ab6-821e-deae98200d10 None] Compute_service record updated for ('nodei14', 'nodei14.englab.juniper.net')
2014-12-24 07:35:30.524 2180 INFO nova.virt.libvirt.driver [req-f5ae398e-014f-4ab6-821e-deae98200d10 None] [instance: c13062f0-1fbc-4425-ae07-b4e8babe785b] Creating image
2014-12-24 07:35:31.093 2180 INFO nova.scheduler.client.report [-] Compute_service record updated for ('nodei14', 'nodei14.englab.juniper.net')
2014-12-24 07:35:31.303 2180 INFO nova.virt.disk.vfs.api [req-f5ae398e-014f-4ab6-821e-deae98200d10 None] Unable to import guestfsfalling back to VFSLocalFS
2014-12-24 07:35:31.861 2180 ERROR root [-] Second simultaneous read on fileno 21 detected. Unless you really know what you're doing, make sure that only one greenthread can read any particular socket. Consider using a pools.Pool. If you do know what you're doing and want to disable this error, call eventlet.debug.hub_prevent_multiple_readers(False)
2014-12-24 07:35:31.861 2180 TRACE root Traceback (most recent call last):
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/vrouter_api.py", line 171, in periodic_connection_check
2014-12-24 07:35:31.861 2180 TRACE root self._client.KeepAliveCheck()
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/gen_py/instance_service/InstanceService.py", line 176, in KeepAliveCheck
2014-12-24 07:35:31.861 2180 TRACE root return self.recv_KeepAliveCheck()
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/contrail_vrouter_api/gen_py/instance_service/InstanceService.py", line 186, in recv_KeepAliveCheck
2014-12-24 07:35:31.861 2180 TRACE root (fname, mtype, rseqid) = self._iprot.readMessageBegin()
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/thrift/protocol/TBinaryProtocol.py", line 126, in readMessageBegin
2014-12-24 07:35:31.861 2180 TRACE root sz = self.readI32()
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/thrift/protocol/TBinaryProtocol.py", line 206, in readI32
2014-12-24 07:35:31.861 2180 TRACE root buff = self.trans.readAll(4)
2014-12-24 07:35:31.861 2180 TRACE root File "/usr/lib/python2.7/dist-packages/thrift/transport/TTransport.py", line 58, in readAll
2014-12-24 07:35:31.861 2180 TRACE ...

Read more...

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote : A change has been merged

Reviewed: https://review.opencontrail.org/7018
Committed: http://github.org/Juniper/contrail-controller/commit/4e2344356fbca3943a4eb698b0195fe680a078f1
Submitter: Zuul
Branch: R2.1

commit 4e2344356fbca3943a4eb698b0195fe680a078f1
Author: ashoksingh <email address hidden>
Date: Wed Feb 4 18:11:13 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Partial-Bug: #1389157

Change-Id: I004f404e4c1101d65531865f429a694ac24553a7

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote :

Reviewed: https://review.opencontrail.org/7073
Committed: http://github.org/Juniper/contrail-controller/commit/3b4fb07eb863e210196d1939bab165f080cab279
Submitter: Zuul
Branch: master

commit 3b4fb07eb863e210196d1939bab165f080cab279
Author: ashoksingh <email address hidden>
Date: Thu Feb 5 14:53:11 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Partial-Bug: #1389157

Change-Id: I5f2a552967cafadbb950d962d428399fbc097070

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote :

Reviewed: https://review.opencontrail.org/7074
Committed: http://github.org/Juniper/contrail-nova-vif-driver/commit/3bea814ae43ada89e2deb7dd02fc72b47f9f8d9f
Submitter: Zuul
Branch: master

commit 3bea814ae43ada89e2deb7dd02fc72b47f9f8d9f
Author: ashoksingh <email address hidden>
Date: Thu Feb 5 15:01:33 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Partial-Bug: #1389157

Change-Id: I79662c7e82f31f230250597aa86c00ccb3bb51dc

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote :

Reviewed: https://review.opencontrail.org/7019
Committed: http://github.org/Juniper/contrail-nova-vif-driver/commit/433c78b4bfa8000cdf4730a3cacb587365eb1ce6
Submitter: Zuul
Branch: R2.1

commit 433c78b4bfa8000cdf4730a3cacb587365eb1ce6
Author: ashoksingh <email address hidden>
Date: Wed Feb 4 18:18:52 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Partial-Bug: #1389157

Change-Id: I8e86e900c1d7ce5e4b5a4e7f0429aea9575b7d22

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote :

Reviewed: https://review.opencontrail.org/7191
Committed: http://github.org/Juniper/contrail-controller/commit/550babffbee9a75ce143d96c0fce5068f3fd0bb5
Submitter: Zuul
Branch: R2.0

commit 550babffbee9a75ce143d96c0fce5068f3fd0bb5
Author: ashoksingh <email address hidden>
Date: Mon Feb 9 10:34:52 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Partial-Bug: #1389157

Change-Id: Ibb775b0e30b4241a2552d5698e7c4d2ccf49d338

Revision history for this message
OpenContrail Admin (ci-admin-f) wrote :

Reviewed: https://review.opencontrail.org/7338
Committed: http://github.org/Juniper/contrail-nova-vif-driver/commit/751a395fa92ce11f2b2e9869b6bd69e649e98954
Submitter: Zuul
Branch: R2.0

commit 751a395fa92ce11f2b2e9869b6bd69e649e98954
Author: ashoksingh <email address hidden>
Date: Thu Feb 12 09:15:06 2015 +0530

Fix AttributeError exception raised by Nova-compute
Add locks to ensure that client object of ContrailVRouterApi is not used while it is being modified.
Closes-Bug: #1389157

Change-Id: I42bff175600d61beaff24904cbb86b21543829a1

tags: removed: releasenote
Changed in juniperopenstack:
status: New → Fix Committed
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.