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

Friday, 25 January 2019

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...

2024

2023

2022

2021

2020

2019

2018

2017

2016

2015

2014

2013

2012

2011

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