This is a multi-part message in MIME format. --------------060105040505080104010504 Content-Type: text/plain; charset=utf-8; format=flowed Content-Transfer-Encoding: 7bit Hi, In sampling.py, remove() is being called without calling add() before, which throws: JsonRpc (StompReactor)::DEBUG::2015-04-28 17:35:55,061::stompReactor::94::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command=u'SEND'> Thread-37401::DEBUG::2015-04-28 17:35:55,062::__init__::445::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'VM.destroy' in bridge with {u'vmID': u'6ec9c0a0-2879-4bfe-9a79-92471881ebfe'} JsonRpcServer::DEBUG::2015-04-28 17:35:55,062::__init__::482::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request Thread-37401::INFO::2015-04-28 17:35:55,062::API::334::vds::(destroy) vmContainerLock acquired by vm 6ec9c0a0-2879-4bfe-9a79-92471881ebfe Thread-37401::DEBUG::2015-04-28 17:35:55,062::vm::3513::vm.Vm::(destroy) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::destroy Called Thread-37401::INFO::2015-04-28 17:35:55,062::vm::3444::vm.Vm::(releaseVm) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::Release VM resources Thread-37401::WARNING::2015-04-28 17:35:55,062::vm::375::vm.Vm::(_set_lastStatus) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::trying to set state to Powering down when already Down Thread-37401::ERROR::2015-04-28 17:35:55,063::__init__::469::jsonrpc.JsonRpcServer::(_serveRequest) Internal server error Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 464, in _serveRequest res = method(**params) File "/usr/share/vdsm/rpc/Bridge.py", line 273, in _dynamicMethod result = fn(*methodArgs) File "/usr/share/vdsm/API.py", line 339, in destroy res = v.destroy() File "/usr/share/vdsm/virt/vm.py", line 3515, in destroy result = self.doDestroy() File "/usr/share/vdsm/virt/vm.py", line 3533, in doDestroy return self.releaseVm() File "/usr/share/vdsm/virt/vm.py", line 3448, in releaseVm sampling.stats_cache.remove(self.id) File "/usr/share/vdsm/virt/sampling.py", line 428, in remove if vmid in self._vm_last_timestamp.keys(): KeyError: u'6ec9c0a0-2879-4bfe-9a79-92471881ebfe' Thread-37401::DEBUG::2015-04-28 17:35:55,063::stompReactor::158::yajsonrpc.StompServer::(send) Sending response In file '/usr/share/vdsm/virt/sampling.py': def add(self, vmid): """ Warm up the cache for the given VM. This is to avoid races during the first sampling and the first reporting, which may result in a VM wrongly reported as unresponsive. """ with self._lock: self._vm_last_timestamp[vmid] = self._clock() def remove(self, vmid): """ Remove any data from the cache related to the given VM. """ with self._lock: * if vmid in self._vm_last_timestamp.keys():**<----------------- I patched here as a workarround ** del self._vm_last_timestamp[vmid]* --------------060105040505080104010504 Content-Type: text/html; charset=utf-8 Content-Transfer-Encoding: 8bit <html> <head> <meta http-equiv="content-type" content="text/html; charset=utf-8"> </head> <body bgcolor="#FFFFFF" text="#000000"> Hi,<br> <br> In sampling.py, remove() is being called without calling add() before, which throws:<br> <blockquote>JsonRpc (StompReactor)::DEBUG::2015-04-28 17:35:55,061::stompReactor::94::Broker.StompAdapter::(handle_frame) Handling message <StompFrame command=u'SEND'><br> Thread-37401::DEBUG::2015-04-28 17:35:55,062::__init__::445::jsonrpc.JsonRpcServer::(_serveRequest) Calling 'VM.destroy' in bridge with {u'vmID': u'6ec9c0a0-2879-4bfe-9a79-92471881ebfe'}<br> JsonRpcServer::DEBUG::2015-04-28 17:35:55,062::__init__::482::jsonrpc.JsonRpcServer::(serve_requests) Waiting for request<br> Thread-37401::INFO::2015-04-28 17:35:55,062::API::334::vds::(destroy) vmContainerLock acquired by vm 6ec9c0a0-2879-4bfe-9a79-92471881ebfe<br> Thread-37401::DEBUG::2015-04-28 17:35:55,062::vm::3513::vm.Vm::(destroy) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::destroy Called<br> Thread-37401::INFO::2015-04-28 17:35:55,062::vm::3444::vm.Vm::(releaseVm) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::Release VM resources<br> Thread-37401::WARNING::2015-04-28 17:35:55,062::vm::375::vm.Vm::(_set_lastStatus) vmId=`6ec9c0a0-2879-4bfe-9a79-92471881ebfe`::trying to set state to Powering down when already Down<br> Thread-37401::ERROR::2015-04-28 17:35:55,063::__init__::469::jsonrpc.JsonRpcServer::(_serveRequest) Internal server error<br> Traceback (most recent call last):<br> File "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 464, in _serveRequest<br> res = method(**params)<br> File "/usr/share/vdsm/rpc/Bridge.py", line 273, in _dynamicMethod<br> result = fn(*methodArgs)<br> File "/usr/share/vdsm/API.py", line 339, in destroy<br> res = v.destroy()<br> File "/usr/share/vdsm/virt/vm.py", line 3515, in destroy<br> result = self.doDestroy()<br> File "/usr/share/vdsm/virt/vm.py", line 3533, in doDestroy<br> return self.releaseVm()<br> File "/usr/share/vdsm/virt/vm.py", line 3448, in releaseVm<br> sampling.stats_cache.remove(self.id)<br> File "/usr/share/vdsm/virt/sampling.py", line 428, in remove<br> if vmid in self._vm_last_timestamp.keys():<br> KeyError: u'6ec9c0a0-2879-4bfe-9a79-92471881ebfe'<br> Thread-37401::DEBUG::2015-04-28 17:35:55,063::stompReactor::158::yajsonrpc.StompServer::(send) Sending response<br> </blockquote> In file '/usr/share/vdsm/virt/sampling.py':<br> <br> def add(self, vmid):<br> """<br> Warm up the cache for the given VM.<br> This is to avoid races during the first sampling and the first<br> reporting, which may result in a VM wrongly reported as unresponsive.<br> """<br> with self._lock:<br> self._vm_last_timestamp[vmid] = self._clock()<br> <br> def remove(self, vmid):<br> """<br> Remove any data from the cache related to the given VM.<br> """<br> with self._lock:<br> <b> if vmid in self._vm_last_timestamp.keys():</b><b> <----------------- I patched here as a workarround<br> </b><b> del self._vm_last_timestamp[vmid]</b><br> <br> </body> </html> --------------060105040505080104010504--