Description of problem: Sending valid jsonrpc request fail because treat the request incorrectly as ordered map, while the request is unordered. Create a file: # cat args.json { "ipv6_enabled": false, "connection": "2620:52:0:2300:868f:69ff:fef9:6760", "password": "", "port": 3260, "user": "" } Send a request: # vdsm-client -f args.json ISCSIConnection discoverSendTargets vdsm-client: Command ISCSIConnection.discoverSendTargets with args {u'ipv6_enabled': False, u'connection': u'2620:52:0:2300:868f:69ff:fef9:6760', u'password': u'', u'port': 3260, u'user': u''} failed: (code=100, message=invalid literal for int() with base 10: '') In vdsm log we see: 2018-08-06 18:29:18,857+0300 INFO (Reactor thread) [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:50648 (protocoldetector:61) 2018-08-06 18:29:18,863+0300 DEBUG (Reactor thread) [ProtocolDetector.Detector] Using required_size=11 (protocoldetector:89) 2018-08-06 18:29:18,867+0300 INFO (Reactor thread) [ProtocolDetector.Detector] Detected protocol stomp from ::1:50648 (protocoldetector:125) 2018-08-06 18:29:18,867+0300 INFO (Reactor thread) [Broker.StompAdapter] Processing CONNECT request (stompserver:94) 2018-08-06 18:29:18,867+0300 DEBUG (Reactor thread) [protocoldetector.StompDetector] Stomp detected from ('::1', 50648) (stompserver:412) 2018-08-06 18:29:18,869+0300 INFO (JsonRpc (StompReactor)) [Broker.StompAdapter] Subscribe command received (stompserver:123) 2018-08-06 18:29:18,909+0300 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Calling 'ISCSIConnection.discoverSendTargets' in bridge with {u'ipv6_enabled': False, u'connection': u'2620:52:0:2300:8 68f:69ff:fef9:6760', u'password': '********', u'port': 3260, u'user': u''} (__init__:328) 2018-08-06 18:29:18,910+0300 INFO (jsonrpc/5) [vdsm.api] START discoverSendTargets(con={'ipv6_enabled': False, 'connection': 3260, 'password': False, 'port': u'', 'user': '********'}, optio ns=None) from=::1,50648, task_id=ffb7095f-addd-4081-86bc-be5bc46eceda (api:47) 2018-08-06 18:29:18,910+0300 INFO (jsonrpc/5) [vdsm.api] FINISH discoverSendTargets error=invalid literal for int() with base 10: '' from=::1,50648, task_id=ffb7095f-addd-4081-86bc-be5bc46e ceda (api:51) 2018-08-06 18:29:18,910+0300 ERROR (jsonrpc/5) [storage.TaskManager.Task] (Task='ffb7095f-addd-4081-86bc-be5bc46eceda') Unexpected error (task:875) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run return fn(*args, **kargs) File "<string>", line 2, in discoverSendTargets File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 49, in method ret = func(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2937, in discoverSendTargets port = int(con['port']) ValueError: invalid literal for int() with base 10: '' 2018-08-06 18:29:18,910+0300 INFO (jsonrpc/5) [storage.TaskManager.Task] (Task='ffb7095f-addd-4081-86bc-be5bc46eceda') aborting: Task is aborted: u"invalid literal for int() with base 10: ' '" - code 100 (task:1181) Note that jsonrpc server got the correct map send by the client: 2018-08-06 18:29:18,909+0300 DEBUG (jsonrpc/5) [jsonrpc.JsonRpcServer] Calling 'ISCSIConnection.discoverSendTargets' in bridge with {u'ipv6_enabled': False, u'connection': u'2620:52:0:2300:8 68f:69ff:fef9:6760', u'password': '********', u'port': 3260, u'user': u''} (__init__:328) But storage layer got wrong values: 2018-08-06 18:29:18,910+0300 INFO (jsonrpc/5) [vdsm.api] START discoverSendTargets(con={'ipv6_enabled': False, 'connection': 3260, 'password': False, 'port': u'', 'user': '********'}, optio ns=None) from=::1,50648, task_id=ffb7095f-addd-4081-86bc-be5bc46eceda (api:47) jsonrpc messages are dicts, they are not ordered by definition, so the way the jsonrpc server map the call to the storage layer is wrong. This probably works for engine since the engine build the request in specific order, but once engine will change the order, api calls will break. Version-Release number of selected component (if applicable): vdsm-4.30.0-497.gite86a50d.el7.x86_64 How reproducible: Always Steps to Reproduce: 1. Send request using vdsm-client Actual results: Storage layer get incorrect map Expected results: Storage layer should get the same map sent by the client, as received by the jsonrpc server
Based on what I see in the code the json you are referring to is not correct and the call is expected to be rejected. Based on the schema [1] and the api [2] there are following params required: - host, port, and optional - user, password, ipv6_enabled For Jsonrpc it is correct to send not ordered dicts and we will order it correctly. You found issue that we do not validate correctly ctor params which needs to be fixed. If you want to use the verb please provide correct parameters. [1] https://github.com/oVirt/vdsm/blob/master/lib/vdsm/api/vdsm-api.yml#L8623 [2] https://github.com/oVirt/vdsm/blob/33013c21a614ebd64ff30e034c2af5bfcd2477eb/lib/vdsm/API.py#L966
Thanks Piotr, the json file I used was wrong, but it exposed bad validation. I think this should fail with something like: "Required parameter is missing: 'host'"
It's just missing validation, so lowering severity, but worth fixing, so moving to 4.2.6
Unfortunately this breaks ipv6 support, here is an example of a valid request that is handled incorrectly: # cat req.json { "host": "2620:52:0:2300:868f:69ff:fef9:6760", "port": 3260, "ipv6_enabled": true } # vdsm-client -f req.json ISCSIConnection discoverSendTargets vdsm-client: Command ISCSIConnection.discoverSendTargets with args {u'ipv6_enabled': True, u'host': u'2620:52:0:2300:868f:69ff:fef9:6760', u'port': 3260} failed: (code=100, message='str' object has no attribute 'value') vdsm.log: 2018-08-07 13:58:38,909+0300 INFO (Reactor thread) [ProtocolDetector.AcceptorImpl] Accepted connection from ::1:59582 (protocoldetector:61) 2018-08-07 13:58:38,918+0300 DEBUG (Reactor thread) [ProtocolDetector.Detector] Using required_size=11 (protocoldetector:89) 2018-08-07 13:58:38,925+0300 INFO (Reactor thread) [ProtocolDetector.Detector] Detected protocol stomp from ::1:59582 (protocoldetector:125) 2018-08-07 13:58:38,925+0300 INFO (Reactor thread) [Broker.StompAdapter] Processing CONNECT request (stompserver:95) 2018-08-07 13:58:38,925+0300 DEBUG (Reactor thread) [protocoldetector.StompDetector] Stomp detected from ('::1', 59582) (stompserver:413) 2018-08-07 13:58:38,926+0300 INFO (JsonRpc (StompReactor)) [Broker.StompAdapter] Subscribe command received (stompserver:124) 2018-08-07 13:58:38,966+0300 DEBUG (jsonrpc/2) [jsonrpc.JsonRpcServer] Calling 'ISCSIConnection.discoverSendTargets' in bridge with {u'ipv6_enabled': True, u'host': u'2620:52:0:2300:868f:69ff:fef9:6760', u'port': 3260} (__init__:329) 2018-08-07 13:58:38,967+0300 INFO (jsonrpc/2) [vdsm.api] START discoverSendTargets(con={'ipv6_enabled': False, 'connection': u'2620:52:0:2300:868f:69ff:fef9:6760', 'password': '', 'port': 3260, 'user': True}, options=None) from=::1,59582, task_id=cab4fcfd-df75-4ffa-8139-6e5bed067d46 (api:47) 2018-08-07 13:58:39,087+0300 INFO (jsonrpc/2) [vdsm.api] FINISH discoverSendTargets error='str' object has no attribute 'value' from=::1,59582, task_id=cab4fcfd-df75-4ffa-8139-6e5bed067d46 (api:51) 2018-08-07 13:58:39,087+0300 ERROR (jsonrpc/2) [storage.TaskManager.Task] (Task='cab4fcfd-df75-4ffa-8139-6e5bed067d46') Unexpected error (task:875) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run return fn(*args, **kargs) File "<string>", line 2, in discoverSendTargets File "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 49, in method ret = func(*args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2968, in discoverSendTargets targets = iscsi.discoverSendTargets(iface, portal, cred) File "/usr/lib/python2.7/site-packages/vdsm/storage/iscsi.py", line 271, in discoverSendTargets addIscsiPortal(iface, portal, credentials) File "/usr/lib/python2.7/site-packages/vdsm/storage/iscsi.py", line 249, in addIscsiPortal for key, value in credentials.getIscsiadmOptions(): File "/usr/lib/python2.7/site-packages/vdsm/storage/iscsi.py", line 309, in getIscsiadmOptions res.append(("auth.password", self.password.value)) AttributeError: 'str' object has no attribute 'value' 2018-08-07 13:58:39,087+0300 INFO (jsonrpc/2) [storage.TaskManager.Task] (Task='cab4fcfd-df75-4ffa-8139-6e5bed067d46') aborting: Task is aborted: u"'str' object has no attribute 'value'" - code 100 (task:1181) 2018-08-07 13:58:39,088+0300 ERROR (jsonrpc/2) [storage.Dispatcher] FINISH discoverSendTargets error='str' object has no attribute 'value' (dispatcher:84) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line 71, in wrapper result = ctask.prepare(func, *args, **kwargs) File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 108, in wrapper return m(self, *a, **kw) File "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1189, in prepare raise self.error AttributeError: 'str' object has no attribute 'value' 2018-08-07 13:58:39,088+0300 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call ISCSIConnection.discoverSendTargets failed (error 100) in 0.12 seconds (__init__:312) jsonrpc server got: {u'ipv6_enabled': True, u'host': u'2620:52:0:2300:868f:69ff:fef9:6760', u'port': 3260} API.ISCSIConnection.__init__ was created with: {'ipv6_enabled': False, 'connection': u'2620:52:0:2300:868f:69ff:fef9:6760', 'password': '', 'port': 3260, 'user': True} The value of "user" and "ipv6_enabled" are swapped.
Moving back to high, since this blocks ipv6 support.
I think the fix we have in master is good enough for 4.2, so we can open RFE for better error handling in ctor args for 4.3.
Nir, that was my intension. Once we unblock the qe i want to open new BZ to fix validation and ordering.
I created BZ #1617989 to track ctor validation and ordering fixes.
Piotr, in which version it suppose to be fixed? I updated host to latest 4.2.6 vdsm = vdsm-4.20.37-1.el7ev.x86_64 and I am still getting same missmatch: 2018-08-23 13:47:43,402+0200 INFO (jsonrpc/6) [vdsm.api] START discoverSendTargets(con={'ipv6_enabled': False, 'connection': u'2620:52:0:2300:868f:69ff:fef9:6760', 'password': '', 'port': 3260, 'user': True}, options=None) from=::1,59596, task_id=f030c8ed-e385-4acc-a59e-24618289bdb7 (api:46)
The commit was not tagged yet and it is not part of 4.20.37. Any tag which will be next will contain the fix.
waiting for new build which will include fix
For other fixed and validations see comment 8, Verified on vdsm.x86_64 4.20.35-1.el7ev 2018-08-30 10:46:44,573+0200 INFO (jsonrpc/4) [vdsm.api] START discoverSendTargets(con={'ipv6_enabled': False, 'connection': 3260, 'password': False, 'port': u'', 'user': '********'}, options=None) from=::1,43140, task_id=367154bd-2df1-4ba1-b59d-6e02e1998faa (api:46)