port-list with filter crashes api-server at times

[Senthilnathan Murugappan]

version: 4.1.0.0-29~mitaka
OS: ubuntu1404

Sanity testcases fails once in a while during "nova list --all-tenants"
Report: http://10.204.216.50/Docs/logs/4.1.0.0-29_jenkins-VT_CB_mainline_ub1404_Mitaka-10_1503530075.82/junit-noframes.html

Neutron call (port-list with device-id filter):
2017-08-23 21:38:30.436 5703 INFO neutron.wsgi [req-62597d16-c625-43de-b759-04452281bf5e 58e2089945c74c4393ce92e12f25b2f2 8a571bdcd75f4f84b09b673b4e3a837a - - -] 10.10.0.4 - - [23/Aug/2017 21:38:30] "GET /v2.0/ports.json?device_id=fad71c97-e847-4a8f-a46a-d90e10991ba7&device_id=d03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea&device_id=7807f2b5-2251-49aa-8274-f05f3ff1fcbe&device_id=7f3fc798-ffc4-4611-86a0-ffadb53c44bd&device_id=5167c4b3-fad8-4f73-b1ac-f900b290001f&device_id=58e39166-8b1a-4bb8-8bf8-21c9d6de40af&device_id=8d838bad-4768-41c0-8374-51c98eac5105 HTTP/1.1" 500 314 0.973520

Please find the detailed traceback from contrail-api-0-stdout.log below.

ERROR:contrail-api:__default__ [SYS_ERR]: VncApiError: <type 'exceptions.AttributeError'>
Python 2.7.6: /usr/bin/python
Wed Aug 23 21:38:30 2017

A problem occurred in a Python script. Here is the sequence of
function calls leading up to the error, in the order they occurred.

 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py in handler_trap_exception(*args=(), **kwargs={})
 1575 (code, err_msg) = status
 1576 raise cfgm_common.exceptions.HttpError(code, err_msg)
 1577 response = handler(*args, **kwargs)
 1578 self._generate_rest_api_response_trace(trace, response)
 1579
response undefined
handler = <functools.partial object>
args = ()
kwargs = {}

 /usr/lib/python2.7/dist-packages/cfgm_common/vnc_api_stats.py in wrapper(api_server_obj=<vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>, resource_type='virtual_machine_interface', *args=(), **kwargs={})
   15 statistics = VncApiStatistics(
   16 obj_type=resource_type.replace('-', '_'))
   17 response = func(api_server_obj, resource_type, *args, **kwargs)
   18 statistics.response_size = len(str(response))
   19 statistics.response_code = bottle.response.status_code
response undefined
func = <function http_resource_list>
api_server_obj = <vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>
resource_type = 'virtual_machine_interface'
args = ()
kwargs = {}

 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py in http_resource_list(self=<vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>, obj_type='virtual_machine_interface')
 1036 obj_uuids, is_count, is_detail, filters,
 1037 req_fields, include_shared, exclude_hrefs,
 1038 pagination)
 1039 # end http_resource_list
 1040
pagination = {}

 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py in _list_collection(self=<vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>, obj_type='virtual_machine_interface', parent_uuids=None, back_ref_uuids=[u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], obj_uuids=None, is_count=False, is_detail=True, filters={}, req_fields=[u'logical_router_back_refs', u'instance_ip_back_refs', u'floating_ip_back_refs'], include_shared=False, exclude_hrefs=True, pagination={})
 2922 include_shared=include_shared,
 2923 paginate_start=page_start,
 2924 paginate_count=page_count)
 2925 if not ok:
 2926 self.config_object_error(None, None, '%ss' %(obj_type),
paginate_count undefined
page_count = None

 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_db.py in dbe_list(self=<vnc_cfg_api_server.vnc_db.VncDbClient object>, obj_type='virtual_machine_interface', parent_uuids=None, back_ref_uuids=[u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], obj_uuids=None, is_count=False, filters={}, paginate_start=None, paginate_count=None, is_detail=True, field_names=[u'logical_router_back_refs', u'instance_ip_back_refs', u'floating_ip_back_refs'], include_shared=False)
 1307 count=is_count, filters=filters,
 1308 paginate_start=paginate_start,
 1309 paginate_count=paginate_count)
 1310
 1311 if not ok or is_count:
paginate_count = None

 /usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py in wrapper(*args=('virtual_machine_interface',), **kwargs={'back_ref_uuids': [u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], 'count': False, 'filters': {}, 'obj_uuids': None, 'paginate_count': None, 'paginate_start': None, 'parent_uuids': None})
  480
  481 self.start_time = datetime.datetime.now()
  482 return func(*args, **kwargs)
  483 except (AllServersUnavailable, MaximumRetryException) as e:
  484 if self._conn_state != ConnectionStatus.DOWN:
func = <bound method VncServerCassandraClient.object_li...i_server.vnc_db.VncServerCassandraClient object>>
args = ('virtual_machine_interface',)
kwargs = {'back_ref_uuids': [u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], 'count': False, 'filters': {}, 'obj_uuids': None, 'paginate_count': None, 'paginate_start': None, 'parent_uuids': None}

 /usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py in object_list(self=<vnc_cfg_api_server.vnc_db.VncServerCassandraClient object>, obj_type='virtual_machine_interface', parent_uuids=None, back_ref_uuids=[u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], obj_uuids=None, count=False, filters={}, paginate_start=None, paginate_count=None)
 1140 finish='backref:%s;' % (obj_type),
 1141 num_columns=num_columns,
 1142 timestamp=True)
 1143
 1144 def filter_rows_backref_anchor():
timestamp undefined
builtinTrue = True

 /usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py in multiget(self=<vnc_cfg_api_server.vnc_db.VncServerCassandraClient object>, cf_name='obj_uuid_table', keys=[u'fad71c97-e847-4a8f-a46a-d90e10991ba7', u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea', u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe', u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd', u'5167c4b3-fad8-4f73-b1ac-f900b290001f', u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af', u'8d838bad-4768-41c0-8374-51c98eac5105'], columns=None, start='backref:virtual_machine_interface:', finish='backref:virtual_machine_interface;', timestamp=True, num_columns=None)
  254
  255 for key in results:
  256 for col, val in results[key].items():
  257 try:
  258 if timestamp:
col undefined
val undefined
results = {u'5167c4b3-fad8-4f73-b1ac-f900b290001f': None, u'58e39166-8b1a-4bb8-8bf8-21c9d6de40af': None, u'7807f2b5-2251-49aa-8274-f05f3ff1fcbe': None, u'7f3fc798-ffc4-4611-86a0-ffadb53c44bd': None, u'8d838bad-4768-41c0-8374-51c98eac5105': None, u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea': None}
key = u'd03e6586-0ecb-4ddc-8f80-e6f3cb59e5ea'
].items undefined
<type 'exceptions.AttributeError'>: 'NoneType' object has no attribute 'items'

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 1577, in handler_trap_exception
    response = handler(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/cfgm_common/vnc_api_stats.py", line 17, in wrapper
    response = func(api_server_obj, resource_type, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 1038, in http_resource_list
    pagination)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 2924, in _list_collection
    paginate_count=page_count)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_db.py", line 1309, in dbe_list
    paginate_count=paginate_count)
  File "/usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py", line 482, in wrapper
    return func(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py", line 1142, in object_list
    timestamp=True)
  File "/usr/lib/python2.7/dist-packages/cfgm_common/vnc_cassandra.py", line 256, in multiget
    for col, val in results[key].items():
AttributeError: 'NoneType' object has no attribute 'items'

[OpenContrail Admin (ci-admin-f)]

Review in progress for https://review.opencontrail.org/34923
Submitter: ?douard Thuleau (<email address hidden>)

[OpenContrail Admin (ci-admin-f)]

Reviewed: https://review.opencontrail.org/34923
Committed: http://github.com/Juniper/contrail-controller/commit/91287b79ef46aefaf0157198adec44fd9bd1bf7e
Submitter: Zuul (<email address hidden>)
Branch: master

commit 91287b79ef46aefaf0157198adec44fd9bd1bf7e
Author: Édouard Thuleau <email address hidden>
Date: Fri Aug 25 18:30:36 2017 +0200

[VNC API Server] Ignore stale reults in Cassandra request

Probably due to concurrency access to the DB when a resource is
deleting, pycassa could return key without values when the resource is
fetched. Ignore it

Closes-Bug: #1712905
Change-Id: Ia7bd1fdeb799dd7684b0c912a51ca792ca7e99d9

[Senthilnathan Murugappan (msenthil)]

Issue is still observed with 4.1.0.0-50 build too