Attachment 1449033 Details for Bug 1588741 – vdsm.log

vdsm.log

vdsm.log (text/plain), 7.39 KB, created by dearfriend on 2018-06-08 09:26:38 UTC

(hide)

Description:

Filename:

MIME Type:

Creator: dearfriend

Created: 2018-06-08 09:26:38 UTC

Size: 7.39 KB

patch

obsolete

>2018-06-07 21:31:49,886+0300 WARN  (vdsm.Scheduler) [Executor] Worker blocked: <Worker name=jsonrpc/1 running <Task <JsonRpcTask {'params': {u'connectionParams': [{u'netIfaceName': u'eth3.15', u'id': u'3d4f9b42-448d-4c82-897c-d82bb07b2b0b', u'connection': u'10.0.1.15', u'iqn': u'iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4', u'user': u'user_iscsi', u'tpgt': u'1036', u'ifaceName': u'eth3.15', u'password': '********', u'port': u'3260'}, {u'netIfaceName': u'eth3.15', u'id': u'5e226086-101d-4fe4-95f1-e0e70927bd7b', u'connection': u'10.0.2.16', u'iqn': u'iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4', u'user': u'user_iscsi', u'tpgt': u'1038', u'ifaceName': u'eth3.15', u'password': '********', u'port': u'3260'}, {u'netIfaceName': u'eth4.16', u'id': u'63033747-e652-4ab1-bde0-bc146f32d86d', u'connection': u'10.0.1.15', u'iqn': u'iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4', u'user': u'user_iscsi', u'tpgt': u'1036', u'ifaceName': u'eth4.16', u'password': '********', u'port': u'3260'}, {u'netIfaceName': u'eth4.16', u'id': u'5d5eaa7c-6c4a-4d97-9a9d-5894bcb03d4d', u'connection': u'10.0.2.16', u'iqn': u'iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4', u'user': u'user_iscsi', u'tpgt': u'1038', u'ifaceName': u'eth4.16', u'password': '********', u'port': u'3260'}], u'storagepoolID': u'33b255a6-675e-11e8-947b-00163e35e422', u'domainType': 3}, 'jsonrpc': '2.0', 'method': u'StoragePool.connectStorageServer', 'id': u'1c13ca40-0ff4-4eb3-9744-d47f3535ea0f'} at 0x7f5fe0595dd0> timeout=60, duration=240 at 0x7f5fe0595850> task#=10044 at 0x7f60001a1dd0>, traceback:
>File: "/usr/lib64/python2.7/threading.py", line 785, in __bootstrap
>  self.__bootstrap_inner()
>File: "/usr/lib64/python2.7/threading.py", line 812, in __bootstrap_inner
>  self.run()
>File: "/usr/lib64/python2.7/threading.py", line 765, in run
>  self.__target(*self.__args, **self.__kwargs)
>File: "/usr/lib/python2.7/site-packages/vdsm/common/concurrent.py", line 194, in run
>  ret = func(*args, **kwargs)
>File: "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 301, in _run
>  self._execute_task()
>File: "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 315, in _execute_task
>  task()
>File: "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 391, in __call__
>  self._callable()
>File: "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 523, in __call__
>  self._handler(self._ctx, self._req)
>File: "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 566, in _serveRequest
>  response = self._handle_request(req, ctx)
>File: "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 606, in _handle_request
>  res = method(**params)
>File: "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 201, in _dynamicMethod
>  result = fn(*methodArgs)
>File: "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1070, in connectStorageServer
>  connectionParams)
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line 73, 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 1179, in prepare
>  result = self._run(func, *args, **kwargs)
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in _run
>  return fn(*args, **kargs)
>File: "<string>", line 2, in connectStorageServer
>File: "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 48, in method
>  ret = func(*args, **kwargs)
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2395, in connectStorageServer
>  conObj.connect()
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/storageServer.py", line 487, in connect
>  iscsi.addIscsiNode(self._iface, self._target, self._cred)
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/iscsi.py", line 217, in addIscsiNode
>  iscsiadm.node_login(iface.name, target.address, target.iqn)
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/iscsiadm.py", line 327, in node_login
>  portal, "-l"])
>File: "/usr/lib/python2.7/site-packages/vdsm/storage/iscsiadm.py", line 122, in _runCmd
>  return misc.execCmd(cmd, printable=printCmd, sudo=True, sync=sync)
>File: "/usr/lib/python2.7/site-packages/vdsm/common/commands.py", line 80, in execCmd
>  (out, err) = p.communicate(data)
>File: "/usr/lib64/python2.7/site-packages/subprocess32.py", line 924, in communicate
>  stdout, stderr = self._communicate(input, endtime, timeout)
>File: "/usr/lib64/python2.7/site-packages/subprocess32.py", line 1706, in _communicate
>  orig_timeout)
>File: "/usr/lib64/python2.7/site-packages/subprocess32.py", line 1779, in _communicate_with_poll
>  ready = poller.poll(self._remaining_time(endtime)) (executor:363)
>2018-06-07 21:31:50,104+0300 INFO  (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
>2018-06-07 21:31:50,107+0300 INFO  (jsonrpc/6) [vdsm.api] START repoStats(domains=[u'aa7bc620-4348-4649-880a-fcc617ac5fe3']) from=::1,37930, task_id=d38d6c81-bb37-45ca-aaaa-999d31820879 (api:46)
>2018-06-07 21:31:50,108+0300 INFO  (jsonrpc/6) [vdsm.api] FINISH repoStats return={u'aa7bc620-4348-4649-880a-fcc617ac5fe3': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.000337091', 'lastCheck': '2.7', 'valid': True}} from=::1,37930, task_id=d38d6c81-bb37-45ca-aaaa-999d31820879 (api:52)
>2018-06-07 21:31:50,108+0300 INFO  (jsonrpc/6) [jsonrpc.JsonRpcServer] RPC call Host.getStorageRepoStats succeeded in 0.00 seconds (__init__:573)
>2018-06-07 21:31:51,004+0300 INFO  (jsonrpc/0) [jsonrpc.JsonRpcServer] RPC call Host.ping2 succeeded in 0.00 seconds (__init__:573)
>2018-06-07 21:31:51,008+0300 INFO  (jsonrpc/5) [api.virt] START getStats() from=::1,37930, vmId=57c0d1c5-bd6e-4f5a-bdcd-e2a016d95d30 (api:46)
>2018-06-07 21:31:51,008+0300 INFO  (jsonrpc/5) [api] FINISH getStats error=Virtual machine does not exist: {'vmId': u'57c0d1c5-bd6e-4f5a-bdcd-e2a016d95d30'} (api:127)
>2018-06-07 21:31:51,008+0300 INFO  (jsonrpc/5) [api.virt] FINISH getStats return={'status': {'message': "Virtual machine does not exist: {'vmId': u'57c0d1c5-bd6e-4f5a-bdcd-e2a016d95d30'}", 'code': 1}} from=::1,37930, vmId=57c0d1c5-bd6e-4f5a-bdcd-e2a016d95d30 (api:52)
>2018-06-07 21:31:51,008+0300 INFO  (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call VM.getStats failed (error 1) in 0.00 seconds (__init__:573)
>2018-06-07 21:31:52,014+0300 ERROR (jsonrpc/1) [storage.HSM] Could not connect to storageServer (hsm:2398)
>Traceback (most recent call last):
>  File "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2395, in connectStorageServer
>    conObj.connect()
>  File "/usr/lib/python2.7/site-packages/vdsm/storage/storageServer.py", line 487, in connect
>    iscsi.addIscsiNode(self._iface, self._target, self._cred)
>  File "/usr/lib/python2.7/site-packages/vdsm/storage/iscsi.py", line 217, in addIscsiNode
>    iscsiadm.node_login(iface.name, target.address, target.iqn)
>  File "/usr/lib/python2.7/site-packages/vdsm/storage/iscsiadm.py", line 337, in node_login
>    raise IscsiNodeError(rc, out, err)
>IscsiNodeError: (8, ['Logging in to [iface: eth4.16, target: iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4, portal: 10.0.1.15,3260] (multiple)'], ['iscsiadm: Could not login to [iface: eth4.16, target: iqn.1993-09.com.netapp:sn.1dc6f28e663121e7afbf00a098b54749:vs.4, portal: 10.0.1.15,3260].', 'iscsiadm: initiator reported error (8 - connection timed out)', 'iscsiadm: Could not log into all portals'])

Actions: View

Attachments on bug 1588741: 1449033