[ovirt-users] Re: 4.3.0 rc2 cannot mount glusterfs volumes on ovirt node ng

On Fri, Jan 25, 2019 at 3:18 PM Jorick Astrego <jorick(a)netbulae.eu&gt; wrote: > Hi, > > We're having problems mounting the preexisting 3.12 glusterfs storage > domains in ovirt node ng 4.3.0 rc2. > > Getting > > There are no iptables blocks on the storage network, the ip's are > pingable bothe ways. I can telnet to the glusterfs ports and I see no > messages in the logs of the glusterfs servers. > > When I try the mount command manually it hangs for ever: > > /usr/bin/mount -t glusterfs -o backup-volfile-servers=*.*.*.*:*.*.*.* > *.*.*.*:/sdd8 /mnt/temp > > I haven't submitted a bug yet.... > > from supervdsm.log > > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:42:45,282::supervdsm_server::100::SuperVdsm.ServerCallback::(wrapper) > call volumeInfo with (u'sdd8', u'*.*.*.*') {} > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:42:45,282::commands::198::root::(execCmd) /usr/bin/taskset --cpu-list > 0-63 /usr/sbin/gluster --mode=script volume info --remote-host=*.*.*.* sdd8 > --xml (cwd None) > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:44:45,399::commands::219::root::(execCmd) FAILED: <err> = ''; <rc> = 1 > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:44:45,399::logutils::319::root::(_report_stats) ThreadedHandler is ok > in the last 120 seconds (max pending: 2) > This looks like https://bugzilla.redhat.com/show_bug.cgi?id=1666123#c18 We should see "ThreadedHandler is ok" every 60 seconds when using debug log level. Looks like your entire supervdsmd process was hang for 120 seconds. > MainProcess|jsonrpc/2::ERROR::2019-01-25 > 13:44:45,399::supervdsm_server::104::SuperVdsm.ServerCallback::(wrapper) > Error in volumeInfo > Traceback (most recent call last): > File "/usr/lib/python2.7/site-packages/vdsm/supervdsm_server.py", line > 102, in wrapper > res = func(*args, **kwargs) > File "/usr/lib/python2.7/site-packages/vdsm/gluster/cli.py", line 529, > in volumeInfo > xmltree = _execGlusterXml(command) > File "/usr/lib/python2.7/site-packages/vdsm/gluster/cli.py", line 131, > in _execGlusterXml > return _getTree(rc, out, err) > File "/usr/lib/python2.7/site-packages/vdsm/gluster/cli.py", line 112, > in _getTree > raise ge.GlusterCmdExecFailedException(rc, out, err) > GlusterCmdExecFailedException: Command execution failed > error: E > r > r > o > r > > : > > R > e > q > u > e > s > t > > t > i > m > e > d > > o > u > t > Looks like side effect of https://gerrit.ovirt.org/c/94784/ GlusterException assumes that it accept list of lines, but we started to raise strings. The class should be fixed to handle strings.

> > return code: 1 > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:44:45,400::supervdsm_server::100::SuperVdsm.ServerCallback::(wrapper) > call mount with (<vdsm.supervdsm_server._SuperVdsm object at > 0x7f6eb8d0a2d0>, u'*.*.*.*:/sdd8', > u'/rhev/data-center/mnt/glusterSD/*.*.*.*:_sdd8') {'vfstype': u'glusterfs', > 'mntOpts': u'backup-volfile-servers=*.*.*.*:*.*.*.*', 'cgroup': > 'vdsm-glusterfs'} > MainProcess|jsonrpc/2::DEBUG::2019-01-25 > 13:44:45,400::commands::198::root::(execCmd) /usr/bin/taskset --cpu-list > 0-63 /usr/bin/systemd-run --scope --slice=vdsm-glusterfs /usr/bin/mount -t > glusterfs -o backup-volfile-servers=*.*.*.*:*.*.*.* *.*.*.*:/sdd8 > /rhev/data-center/mnt/glusterSD/*.*.*.*:_sdd8 (cwd None) > MainProcess|jsonrpc/0::DEBUG::2019-01-25 > 13:45:02,884::commands::219::root::(execCmd) FAILED: <err> = 'Running scope > as unit run-38676.scope.\nMount failed. Please check the log file for more > details.\n'; <rc> = 1 > MainProcess|jsonrpc/0::ERROR::2019-01-25 > 13:45:02,884::supervdsm_server::104::SuperVdsm.ServerCallback::(wrapper) > Error in mount > Traceback (most recent call last): > File "/usr/lib/python2.7/site-packages/vdsm/supervdsm_server.py", line > 102, in wrapper > res = func(*args, **kwargs) > File "/usr/lib/python2.7/site-packages/vdsm/supervdsm_server.py", line > 144, in mount > cgroup=cgroup) > File "/usr/lib/python2.7/site-packages/vdsm/storage/mount.py", line > 277, in _mount > _runcmd(cmd) > File "/usr/lib/python2.7/site-packages/vdsm/storage/mount.py", line > 305, in _runcmd > raise MountError(rc, b";".join((out, err))) > MountError: (1, ';Running scope as unit run-38676.scope.\nMount failed. > Please check the log file for more details.\n') > The mount failure is probably related to glusterfs. There are glusterfs logs on the host that can give more info on this error. > MainProcess|jsonrpc/0::DEBUG::2019-01-25 > 13:45:02,894::supervdsm_server::100::SuperVdsm.ServerCallback::(wrapper) > call volumeInfo with (u'ssd9', u'*.*.*.*') {} > MainProcess|jsonrpc/0::DEBUG::2019-01-25 > 13:45:02,894::commands::198::root::(execCmd) /usr/bin/taskset --cpu-list > 0-63 /usr/sbin/gluster --mode=script volume info --remote-host=*.*.*.* ssd9 > --xml (cwd None) > > > from vdsm.log > > 2019-01-25 13:46:03,519+0100 WARN (vdsm.Scheduler) [Executor] Worker > blocked: <Worker name=jsonrpc/2 running <Task <JsonRpcTask {'params': > {u'connectionParams': [{u'mnt_options': > u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'6b6b7899-c82b-4417-b453-0b3b0ac11deb', u'connection': u'*.*.*.*:ssd4', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'b036005a-d44d-4689-a8c3-13e1bbf55af7', u'connection': u'*.*.*.*:ssd5', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'40d191b0-b7f8-48f9-bf6f-327275f51fef', u'connection': u'*.*.*.*:ssd6', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'26fbd2d6-6f25-4520-ab7f-15e9001f07b9', u'connection': u'*.*.*.*:/hdd2', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'f11fed97-513a-4a10-b85c-2afe68f42608', u'connection': u'*.*.*.*:/ssd3', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'f20b8691-528e-4e38-89ad-1e27684dee8b', u'connection': u'*.*.*.*:/sdd8', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'188e71dc-3d81-43d3-b930-238a4c6711e6', u'connection': u'*.*.*.*:/ssd9', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], > u'storagepoolID': u'00000001-0001-0001-0001-000000000043', u'domainType': > 7}, 'jsonrpc': '2.0', 'method': u'StoragePool.connectStorageServer', 'id': > u'581e2ad3-0682-4d44-95b4-bdc088b45f66'} at 0x7f9be815c850> timeout=60, > duration=1260.00 at 0x7f9be815ca10> task#=98 at 0x7f9be83bb750>, 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 > 195, 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 262, > in __call__ > self._handler(self._ctx, self._req) > File: "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 305, > in _serveRequest > response = self._handle_request(req, ctx) > File: "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 345, > in _handle_request > res = method(**params) > File: "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 194, in > _dynamicMethod > result = fn(*methodArgs) > File: "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1103, in > connectStorageServer > connectionParams) > File: "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line > 72, 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 50, in > method > ret = func(*args, **kwargs) > File: "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2410, > in connectStorageServer > conObj.connect() > > from messages: > > Jan 25 13:49:07 node9 vdsm[31968]: WARN Worker blocked: <Worker > name=jsonrpc/3 running <Task <JsonRpcTask {'params': {u'connectionParams': > [{u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'6b6b7899-c82b-4417-b453-0b3b0ac11deb', u'connection': u'192.168.99.15:ssd4', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'b036005a-d44d-4689-a8c3-13e1bbf55af7', u'connection': u'*.*.*.*:ssd5', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'40d191b0-b7f8-48f9-bf6f-327275f51fef', u'connection': u'*.*.*.*:ssd6', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'26fbd2d6-6f25-4520-ab7f-15e9001f07b9', u'connection': u'*.*.*.*:/hdd2', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'f11fed97-513a-4a10-b85c-2afe68f42608', u'connection': u'*.*.*.*:/ssd3', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'f20b8691-528e-4e38-89ad-1e27684dee8b', u'connection': u'*.*.*.*:/sdd8', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}, > {u'mnt_options': u'backup-volfile-servers=*.*.*.*:*.*.*.*', u'id': > u'188e71dc-3d81-43d3-b930-238a4c6711e6', u'connection': u'*.*.*.*:/ssd9', > u'iqn': u'', u'user': u'', u'tpgt': u'1', u'ipv6_enabled': u'false', > u'vfs_type': u'glusterfs', u'password': '********', u'port': u''}], > u'storagepoolID': u'00000001-0001-0001-0001-000000000043', u'domainType': > 7}, 'jsonrpc': '2.0', 'method': u'StoragePool.connectStorageServer', 'id': > u'918f4d06-ca89-4ec0-a396-3407f1bdb8f9'} at 0x7f9be82ff250> timeout=60, > duration=840.00 at 0x7f9be82ffa50> task#=93 at 0x7f9be83bba10>, > traceback:#012File: "/usr/lib64/python2.7/threading.py", line 785, in > __bootstrap#012 self.__bootstrap_inner()#012File: > "/usr/lib64/python2.7/threading.py", line 812, in __bootstrap_inner#012 > self.run()#012File: "/usr/lib64/python2.7/threading.py", line 765, in > run#012 self.__target(*self.__args, **self.__kwargs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/common/concurrent.py", line 195, in > run#012 ret = func(*args, **kwargs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 301, in _run#012 > self._execute_task()#012File: > "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 315, in > _execute_task#012 task()#012File: > "/usr/lib/python2.7/site-packages/vdsm/executor.py", line 391, in > __call__#012 self._callable()#012File: > "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 262, in > __call__#012 self._handler(self._ctx, self._req)#012File: > "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 305, in > _serveRequest#012 response = self._handle_request(req, ctx)#012File: > "/usr/lib/python2.7/site-packages/yajsonrpc/__init__.py", line 345, in > _handle_request#012 res = method(**params)#012File: > "/usr/lib/python2.7/site-packages/vdsm/rpc/Bridge.py", line 194, in > _dynamicMethod#012 result = fn(*methodArgs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/API.py", line 1103, in > connectStorageServer#012 connectionParams)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line 72, in > wrapper#012 result = ctask.prepare(func, *args, **kwargs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 108, in > wrapper#012 return m(self, *a, **kw)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 1179, in > prepare#012 result = self._run(func, *args, **kwargs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/task.py", line 882, in > _run#012 return fn(*args, **kargs)#012File: "<string>", line 2, in > connectStorageServer#012File: > "/usr/lib/python2.7/site-packages/vdsm/common/api.py", line 50, in > method#012 ret = func(*args, **kwargs)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/hsm.py", line 2410, in > connectStorageServer#012 conObj.connect()#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/storageServer.py", line 172, > in connect#012 self._mount.mount(self.options, self._vfsType, > cgroup=self.CGROUP)#012File: > "/usr/lib/python2.7/site-packages/vdsm/storage/mount.py", line 207, in > mount#012 cgroup=cgroup)#012File: > "/usr/lib/python2.7/site-packages/vdsm/common/supervdsm.py", line 56, in > __call__#012 return callMethod()#012File: > "/usr/lib/python2.7/site-packages/vdsm/common/supervdsm.py", line 54, in > <lambda>#012 **kwargs)#012File: "<string>", line 2, in mount#012File: > "/usr/lib64/python2.7/multiprocessing/managers.py", line 759, in > _callmethod#012 kind, result = conn.recv() > This matches the theory of blocked supervdsmd. Met vriendelijke groet, With kind regards, > > Jorick Astrego > > *Netbulae Virtualization Experts * > ------------------------------ > Tel: 053 20 30 270 info(a)netbulae.eu Staalsteden 4-3A KvK 08198180 > Fax: 053 20 30 271 www.netbulae.eu 7547 TA Enschede BTW NL821234584B01 > ------------------------------ > > _______________________________________________ > Users mailing list -- users(a)ovirt.org > To unsubscribe send an email to users-leave(a)ovirt.org > Privacy Statement: https://www.ovirt.org/site/privacy-policy/ > oVirt Code of Conduct: > https://www.ovirt.org/community/about/community-guidelines/ > List Archives: > https://lists.ovirt.org/archives/list/users@ovirt.org/message/UEFI2DXVP4D... >