NotFoundException sometimes in Cassandra.py while deleting a port

[Vedamurthy Joshi]

Build 1.10 2261

I have a script which creates port with varying arguments and deletes them.

For one of such ports, a create was immediately followed by a delete. While the port does get deleted, the below traceback is seen in contrail-api-0.log. Looks like this exception was thrown during the add of the port ?

10.204.217.7 - - [2014-07-21 12:10:09] "PUT /virtual-machine-interface/714b1fcc-c78a-4e59-aa69-53ef681568bd HTTP/1.1" 200 287 0.003737
10.204.217.7 - - [2014-07-21 12:10:09] "GET /virtual-network/e65a0b43-6b3f-4153-84b0-eefe68037655?exclude_back_refs=True&exclude_children=True HTTP/1.1" 200 1689 0.002795
INFO:api-0:Sending request(xid=2052): Delete(path=u'/fq-name-to-uuid/virtual_machine_interface:default-domain:admin:714b1fcc-c78a-4e59-aa69-53ef681568bd', version=-1)
ERROR:vnc_cfg_api_server.vnc_cfg_api_server:Exception in REST api handler:
<class 'pycassa.cassandra.ttypes.NotFoundException'>
Python 2.7.3: /usr/bin/python
Mon Jul 21 12:10:09 2014

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={})
  413 def handler_trap_exception(*args, **kwargs):
  414 try:
  415 return handler(*args, **kwargs)
  416 except Exception as e:
  417 string_buf = StringIO()
handler = <bound method VncApiServer.ref_update_http_post ...i_server.vnc_cfg_api_server.VncApiServer object>>
args = ()
kwargs = {}
 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py in ref_update_http_post(self=<vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>)
  517 obj_type = obj_type.replace('-', '_')
  518 try:
  519 id = self._db_conn.ref_update(obj_type, obj_uuid, ref_type, ref_uuid, {'attr': attr}, operation)
  520 except NoIdError:
  521 bottle.abort(404, 'uuid ' + obj_uuid + ' not found')
builtinid = <built-in function id>
self = <vnc_cfg_api_server.vnc_cfg_api_server.VncApiServer object>
self._db_conn = <vnc_cfg_api_server.vnc_cfg_ifmap.VncDbClient object>
self._db_conn.ref_update = <bound method VncDbClient.ref_update of <vnc_cfg_api_server.vnc_cfg_ifmap.VncDbClient object>>
obj_type = u'virtual_machine_interface'
obj_uuid = u'714b1fcc-c78a-4e59-aa69-53ef681568bd'
ref_type = u'routing_instance'
ref_uuid = u'b2f55ed1-520f-46f9-b8fa-61dffeb0354d'
attr = {u'direction': u'both', u'dst_mac': None, u'mpls_label': None, u'protocol': None, u'service_chain_address': None, u'src_mac': None, u'vlan_tag': None}
operation = u'ADD'
 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_ifmap.py in ref_update(self=<vnc_cfg_api_server.vnc_cfg_ifmap.VncDbClient object>, obj_type=u'virtual_machine_interface', obj_uuid=u'714b1fcc-c78a-4e59-aa69-53ef681568bd', ref_type=u'routing_instance', ref_uuid=u'b2f55ed1-520f-46f9-b8fa-61dffeb0354d', ref_data={'attr': {u'direction': u'both', u'dst_mac': None, u'mpls_label': None, u'protocol': None, u'service_chain_address': None, u'src_mac': None, u'vlan_tag': None}}, operation=u'ADD')
 1513 else:
 1514 pass
 1515 self._cassandra_db.update_last_modified(bch, obj_uuid)
 1516 bch.send()
 1517 self._msgbus.dbe_update_publish(obj_type.replace('_', '-'), {'uuid':obj_uuid})
self = <vnc_cfg_api_server.vnc_cfg_ifmap.VncDbClient object>
self._cassandra_db = <vnc_cfg_api_server.vnc_cfg_ifmap.VncCassandraClient object>
self._cassandra_db.update_last_modified = <bound method VncCassandraClient.update_last_mod..._server.vnc_cfg_ifmap.VncCassandraClient object>>
bch = <pycassa.batch.CfMutator object>
obj_uuid = u'714b1fcc-c78a-4e59-aa69-53ef681568bd'

 /usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_ifmap.py in update_last_modified(self=<vnc_cfg_api_server.vnc_cfg_ifmap.VncCassandraClient object>, bch=<pycassa.batch.CfMutator object>, obj_uuid=u'714b1fcc-c78a-4e59-aa69-53ef681568bd', id_perms=None)
  712 def update_last_modified(self, bch, obj_uuid, id_perms=None):
  713 if id_perms is None:
  714 id_perms = json.loads(self._obj_uuid_cf.get(obj_uuid, ['prop:id_perms'])['prop:id_perms'])
  715 id_perms['last_modified'] = datetime.datetime.utcnow().isoformat()
  716 self._update_prop(bch, obj_uuid, 'id_perms', {'id_perms': id_perms})
id_perms = None
global json = <module 'json' from '/usr/lib/python2.7/json/__init__.pyc'>
json.loads = <function loads>
self = <vnc_cfg_api_server.vnc_cfg_ifmap.VncCassandraClient object>
self._obj_uuid_cf = <pycassa.columnfamily.ColumnFamily object>
self._obj_uuid_cf.get = <bound method ColumnFamily.get of <pycassa.columnfamily.ColumnFamily object>>
obj_uuid = u'714b1fcc-c78a-4e59-aa69-53ef681568bd'

 /usr/lib/python2.7/dist-packages/pycassa/columnfamily.py in get(self=<pycassa.columnfamily.ColumnFamily object>, key=u'714b1fcc-c78a-4e59-aa69-53ef681568bd', columns=['prop:id_perms'], column_start='', column_finish='', column_reversed=False, column_count=100, include_timestamp=False, super_column=None, read_consistency_level=None, include_ttl=False)
  650 cp = self._column_path(super_column, column)
  651 col_or_super = self.pool.execute('get', packed_key, cp,
  652 read_consistency_level or self.read_consistency_level)
  653 return self._cosc_to_dict([col_or_super], include_timestamp, include_ttl)
  654 else:
read_consistency_level = None
self = <pycassa.columnfamily.ColumnFamily object>
self.read_consistency_level = 2

 /usr/lib/python2.7/dist-packages/pycassa/pool.py in execute(self=<pycassa.pool.ConnectionPool object>, f='get', *args=(u'714b1fcc-c78a-4e59-aa69-53ef681568bd', ColumnPath(column_family='obj_uuid_table', column='prop:id_perms', super_column=None), 2), **kwargs={})
  575 try:
  576 conn = self.get()
  577 return getattr(conn, f)(*args, **kwargs)
  578 finally:
  579 if conn:
builtingetattr = <built-in function getattr>
conn = <pycassa.pool.ConnectionWrapper object>
f = 'get'
args = (u'714b1fcc-c78a-4e59-aa69-53ef681568bd', ColumnPath(column_family='obj_uuid_table', column='prop:id_perms', super_column=None), 2)
kwargs = {}

 /usr/lib/python2.7/dist-packages/pycassa/pool.py in new_f(self=<pycassa.pool.ConnectionWrapper object>, *args=(u'714b1fcc-c78a-4e59-aa69-53ef681568bd', ColumnPath(column_family='obj_uuid_table', column='prop:id_perms', super_column=None), 2), **kwargs={})
  125 self._pool._replace_wrapper() # puts a new wrapper in the queue
  126 self._replace(self._pool.get()) # swaps out transport
  127 result = f(self, *args, **kwargs)
  128 self._retry_count = 0 # reset the count after a success
  129 return result
result undefined
f = <unbound method Connection.get>
self = <pycassa.pool.ConnectionWrapper object>
args = (u'714b1fcc-c78a-4e59-aa69-53ef681568bd', ColumnPath(column_family='obj_uuid_table', column='prop:id_perms', super_column=None), 2)
kwargs = {}

 /usr/lib/python2.7/dist-packages/pycassa/cassandra/Cassandra.py in get(self=<pycassa.pool.ConnectionWrapper object>, key=u'714b1fcc-c78a-4e59-aa69-53ef681568bd', column_path=ColumnPath(column_family='obj_uuid_table', column='prop:id_perms', super_column=None), consistency_level=2)
  532 """
  533 self.send_get(key, column_path, consistency_level)
  534 return self.recv_get()
  535
  536 def send_get(self, key, column_path, consistency_level):
self = <pycassa.pool.ConnectionWrapper object>
self.recv_get = <bound method ConnectionWrapper.recv_get of <pycassa.pool.ConnectionWrapper object>>

 /usr/lib/python2.7/dist-packages/pycassa/cassandra/Cassandra.py in recv_get(self=<pycassa.pool.ConnectionWrapper object>)
  559 raise result.ire
  560 if result.nfe is not None:
  561 raise result.nfe
  562 if result.ue is not None:
  563 raise result.ue
result = get_result(ue=None, nfe=NotFoundException(_message=None), te=None, ire=None, success=None)
result.nfe = NotFoundException(_message=None)
<class 'pycassa.cassandra.ttypes.NotFoundException'>: NotFoundException(_message=None)
    __class__ = <class 'pycassa.cassandra.ttypes.NotFoundException'>
    __delattr__ = <method-wrapper '__delattr__' of NotFoundException object>
    __dict__ = {'_message': None}
    __doc__ = '\n A specific column was requested that does not exist.\n '
    __eq__ = <bound method NotFoundException.__eq__ of NotFoundException(_message=None)>
    __format__ = <built-in method __format__ of NotFoundException object>
    __getattribute__ = <method-wrapper '__getattribute__' of NotFoundException object>
    __getitem__ = <method-wrapper '__getitem__' of NotFoundException object>
    __getslice__ = <method-wrapper '__getslice__' of NotFoundException object>
    __hash__ = <method-wrapper '__hash__' of NotFoundException object>
    __init__ = <bound method NotFoundException.__init__ of NotFoundException(_message=None)>
    __module__ = 'pycassa.cassandra.ttypes'
    __ne__ = <bound method NotFoundException.__ne__ of NotFoundException(_message=None)>
    __new__ = <built-in method __new__ of type object>
    __reduce__ = <built-in method __reduce__ of NotFoundException object>
    __reduce_ex__ = <built-in method __reduce_ex__ of NotFoundException object>
    __repr__ = <bound method NotFoundException.__repr__ of NotFoundException(_message=None)>
    __setattr__ = <method-wrapper '__setattr__' of NotFoundException object>
    __setstate__ = <built-in method __setstate__ of NotFoundException object>
    __sizeof__ = <built-in method __sizeof__ of NotFoundException object>
    __str__ = <bound method NotFoundException.__str__ of NotFoundException(_message=None)>
    __subclasshook__ = <built-in method __subclasshook__ of type object>
    __unicode__ = <built-in method __unicode__ of NotFoundException object>
    __weakref__ = None
    _get_message = <bound method NotFoundException._get_message of NotFoundException(_message=None)>
    _message = None
    _set_message = <bound method NotFoundException._set_message of NotFoundException(_message=None)>
    args = (None,)

    message = None
    read = <bound method NotFoundException.read of NotFoundException(_message=None)>
    thrift_spec = ()
    validate = <bound method NotFoundException.validate of NotFoundException(_message=None)>
    write = <bound method NotFoundException.write of NotFoundException(_message=None)>

The above is a description of an error in a Python program. Here is
the original traceback:

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 415, in handler_trap_exception
    return handler(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 519, in ref_update_http_post
    id = self._db_conn.ref_update(obj_type, obj_uuid, ref_type, ref_uuid, {'attr': attr}, operation)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_ifmap.py", line 1515, in ref_update
    self._cassandra_db.update_last_modified(bch, obj_uuid)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_ifmap.py", line 714, in update_last_modified
    id_perms = json.loads(self._obj_uuid_cf.get(obj_uuid, ['prop:id_perms'])['prop:id_perms'])
  File "/usr/lib/python2.7/dist-packages/pycassa/columnfamily.py", line 652, in get
    read_consistency_level or self.read_consistency_level)
  File "/usr/lib/python2.7/dist-packages/pycassa/pool.py", line 577, in execute
    return getattr(conn, f)(*args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/pycassa/pool.py", line 127, in new_f
    result = f(self, *args, **kwargs)
  File "/usr/lib/python2.7/dist-packages/pycassa/cassandra/Cassandra.py", line 534, in get
    return self.recv_get()
  File "/usr/lib/python2.7/dist-packages/pycassa/cassandra/Cassandra.py", line 561, in recv_get
    raise result.nfe
NotFoundException: NotFoundException(_message=None)

Traceback (most recent call last):
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 764, in _handle
    return route.call(**args)
  File "/usr/lib/python2.7/dist-packages/bottle.py", line 1575, in wrapper
    rv = callback(*a, **ka)
  File "/usr/lib/python2.7/dist-packages/vnc_cfg_api_server/vnc_cfg_api_server.py", line 425, in handler_trap_exception
    raise e
NotFoundException: NotFoundException(_message=None)
10.204.217.7 - - [2014-07-21 12:10:09] "POST /ref-update HTTP/1.1" 500 156 0.007659
INFO:api-0:Received response(xid=2051): u'/api-server/subnets/default-domain:admin:name-iFlHXv:54.114.194.0/24/0913490434'
INFO:api-0:Received error(xid=2052) NoNodeError((), {})
127.0.0.1 - - [2014-07-21 12:10:09] "DELETE /virtual-machine-interface/714b1fcc-c78a-4e59-aa69-53ef681568bd HTTP/1.1" 200 115 0.072210
10.204.217.7 - - [2014-07-21 12:10:09] "POST /neutron/port HTTP/1.1" 200 115 0.221766
10.204.217.108 - - [2014-07-21 12:10:09] "GET / HTTP/1.1" 200 9987 0.000937
INFO:api-0:Sending request(xid=2053): Delete(path=u'/api-server/subnets/default-domain:admin:name-iFlHXv:54.114.194.0/24/0913490434', version=-1)
INFO:api-0:Received response(xid=2053): True
                                        u'owner_access': 7},
                             u'uuid': {u'uuid_lslong': 10650411128488728955L,
                                       u'uuid_mslong': 3903524530464309405}},
               u'instance_ip_address': u'54.114.194.2',
               u'uuid': u'362c1ae0-f259-409d-93cd-dc7e3970197b',
               u'virtual_machine_interface_refs': [{u'to': [u'default-domain',
                                                            u'admin',
                                                            u'714b1fcc-c78a-4e59-aa69-53ef681568bd'],
                                                    u'uuid': u'714b1fcc-c78a-4e59-aa69-53ef681568bd'}],
               u'virtual_network_refs': [{u'to': [u'default-domain',
                                                  u'admin',
                                                  u'name-iFlHXv'],
                                          u'uuid': u'e65a0b43-6b3f-4153-84b0-eefe68037655'}]},
 u'oper': u'CREATE',
 u'parent_imid': u'contrail:config-root:root',
 u'type': u'instance-ip',
 u'uuid': u'362c1ae0-f259-409d-93cd-dc7e3970197b'}

Notification Message: {u'imid': u'contrail:instance-ip:362c1ae0-f259-409d-93cd-dc7e3970197b',
 u'obj_dict': {u'fq_name': [u'362c1ae0-f259-409d-93cd-dc7e3970197b'],
               u'id_perms': {u'created': u'2014-07-21T19:10:08.730978',
                             u'description': None,
                             u'enable': True,
                             u'last_modified': u'2014-07-21T19:10:08.730978',
                             u'permissions': {u'group': u'cloud-admin-group',
                                              u'group_access': 7,
                                              u'other_access': 7,
                                              u'owner': u'cloud-admin',
                                              u'owner_access': 7},
                             u'uuid': {u'uuid_lslong': 10650411128488728955L,
                                       u'uuid_mslong': 3903524530464309405}},
               u'instance_ip_address': u'54.114.194.2',
               u'uuid': u'362c1ae0-f259-409d-93cd-dc7e3970197b',
               u'virtual_machine_interface_refs': [{u'attr': None,
                                                    u'href': u'http://0.0.0.0:9100/virtual-machine-interface/714b1fcc-c78a-4e59-aa69-53ef681568bd',
                                                    u'to': [u'default-domain',
                                                            u'admin',
                                                            u'714b1fcc-c78a-4e59-aa69-53ef681568bd'],
                                                    u'uuid': u'714b1fcc-c78a-4e59-aa69-53ef681568bd'}],
               u'virtual_network_refs': [{u'attr': None,
                                          u'href': u'http://0.0.0.0:9100/virtual-network/e65a0b43-6b3f-4153-84b0-eefe68037655',
                                          u'to': [u'default-domain',
                                                  u'admin',
                                                  u'name-iFlHXv'],
                                          u'uuid': u'e65a0b43-6b3f-4153-84b0-eefe68037655'}]},
 u'oper': u'DELETE',
 u'type': u'instance-ip',
 u'uuid': u'362c1ae0-f259-409d-93cd-dc7e3970197b'}

Notification Message: {u'oper': u'UPDATE',
 u'type': u'virtual-machine-interface',
 u'uuid': u'714b1fcc-c78a-4e59-aa69-53ef681568bd'}

Exception in _dbe_oper_subscribe: Unknown id: 714b1fcc-c78a-4e59-aa69-53ef681568bd

Notification Message: {u'imid': u'contrail:virtual-machine-interface:default-domain:admin:714b1fcc-c78a-4e59-aa69-53ef681568bd',
 u'obj_dict': {u'fq_name': [u'default-domain',
                            u'admin',
                            u'714b1fcc-c78a-4e59-aa69-53ef681568bd'],
               u'id_perms': {u'created': u'2014-07-21T19:10:08.643627',
                             u'description': None,
                             u'enable': True,
                             u'last_modified': u'2014-07-21T19:10:08.643627',
                             u'p10.204.217.108 - - [2014-07-21 12:10:09] "POST /fqname-to-id HTTP/1.1" 200 156 0.002071
10.204.217.108 - - [2014-07-21 12:10:09] "GET /virtual-network/eb3a4420-00a0-4507-826b-79262cc29d18?exclude_back_refs=True&exclude_children=True HTTP/1.1" 200 1124 0.003827

[Nagabhushana R (bhushana)]

looks like Ajay fixed it and is not seen in recent builds.