Hide Forgot
Description of problem: logging module was changed for some commands so Run and protect commands sent to backend now contains either 'None' or 'True' instead of command status (0) and output. new behavior: Thread-2678::INFO::2011-11-18 10:35:55,508::logUtils::39::dispatcher::(wrapper) Run and protect: public_createStorageDomain, Return response: None old (desired) behavior: :Thread-4448::INFO::2011-11-10 14:12:02,231::dispatcher::100::Storage.Dispatcher.Protect::(run) Run and protect: createStorageDomain, Return response: {'status': {'message': 'OK', 'code': 0}} git log: 6b0a82392c2e4e3095b11787eb324e35eeecbd4f
That's very odd, I cannot reproduce that on my host. Does it happen for all verbs? Does it happen for all hosts? I was testing current HEAD e926e817f7563ba4e46fa509401967a2ebc32833.
doesn't happen for all verbs, for example, detach storage domain: Thread-467::INFO::2011-11-24 08:20:27,059::logUtils::37::dispatcher::(wrapper) Run and protect: public_detachStorageDomain(sdUUID='d5339a39-723a-479e-b314-ad651f46779a', spUUID='1d467335-45cb-46ad-8a6e-ec176b138312', msdUUID='00000000-0000-0000-0000-000000000000', masterVersion=2, options=None) Thread-467::DEBUG::2011-11-24 08:20:27,059::resourceManager::174::ResourceManager.Request::(__init__) ResName=`Storage.1d467335-45cb-46ad-8a6e-ec176b138312`ReqID=`8942e38b-d09a-44a3-ac24-f500d0af9db3`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '516' at 'public_detachStorageDomain' Thread-467::DEBUG::2011-11-24 08:20:27,062::resourceManager::174::ResourceManager.Request::(__init__) ResName=`Storage.d5339a39-723a-479e-b314-ad651f46779a`ReqID=`65df0eeb-0fd5-45a3-998a-2efee4c913d7`::Request was made in '/usr/share/vdsm/storage/hsm.py' line '517' at 'public_detachStorageDomain' Thread-467::INFO::2011-11-24 08:20:28,602::logUtils::39::dispatcher::(wrapper) Run and protect: public_detachStorageDomain, Return response: None note that due to this change, engine doesn't know when commands are failing. take this log for example: - engine send detach storage domain - during command, i killed iscsid on host and command throw exception - vdsm returned 'None', and command so called succeeded in engine, domain moved to detach, but stay attached at pool (vdsm - metadata). using 93275cc061520b56995a65b85ffe0ceec70ac3ef
I can reproduce the issue also on the latest revision (git hash c8bcccb21cd6e912dee1d73ba42303309460078a). Haim are you sure that the None and True values are reported to the engine? Looking at the code (and enabling the debug in ruth) I see that the correct dictionaries are reported. Basically the logged() decorator returns the exact return value of the method called (eg: public_createStorageDomain), and in some cases it can be None or True. This output is then managed in dispatcher.Protect.run where the return value (if it's a dict) is merged in the standard STATUS_OK reply ({'status': {'code': 0, 'message': "OK"}}). Apparently it's just a logging issue.
The issue was introduced by: d90d6eb Made the logging mechanism more generic If we want to maintain the old output we probably need to move the logging back into the dispatcher.
We do not need to maintain the old log, but we need to record the error code that we report to the Engine. Otherwise, QA would have to forge only ovirt-engine's log in order to deceive us to believe that we have a bug.
Closing old bugs. If this issue is still relevant/important in current version, please re-open the bug.