Bug 1711054
Summary: | Ovirt not setting network.remote-dio on new volumes leaves them unable to be added as storage domains | ||||||||
---|---|---|---|---|---|---|---|---|---|
Product: | [oVirt] ovirt-engine | Reporter: | Darrell <budic> | ||||||
Component: | BLL.Gluster | Assignee: | Sahina Bose <sabose> | ||||||
Status: | CLOSED DUPLICATE | QA Contact: | SATHEESARAN <sasundar> | ||||||
Severity: | medium | Docs Contact: | |||||||
Priority: | unspecified | ||||||||
Version: | 4.3.3.7 | CC: | bugs, guillaume.pavese, hunter86_bg, kdhananj, nsoffer, sabose | ||||||
Target Milestone: | --- | ||||||||
Target Release: | --- | ||||||||
Hardware: | x86_64 | ||||||||
OS: | Linux | ||||||||
Whiteboard: | |||||||||
Fixed In Version: | Doc Type: | If docs needed, set a value | |||||||
Doc Text: | Story Points: | --- | |||||||
Clone Of: | Environment: | ||||||||
Last Closed: | 2019-06-17 07:25:09 UTC | Type: | Bug | ||||||
Regression: | --- | Mount Type: | --- | ||||||
Documentation: | --- | CRM: | |||||||
Verified Versions: | Category: | --- | |||||||
oVirt Team: | Gluster | RHEL 7.3 requirements from Atomic Host: | |||||||
Cloudforms Team: | --- | Target Upstream Version: | |||||||
Embargoed: | |||||||||
Attachments: |
|
Description
Darrell
2019-05-16 20:00:26 UTC
Discussion on ovirt-users list: https://lists.ovirt.org/archives/list/users@ovirt.org/thread/REDV54BH7CIIDRCRUPCUYN4TX5Z3SL6R/#RO6PQQ4XQ6KZXRUOHKMM2J2HFN2LTEGB *** Bug 1711060 has been marked as a duplicate of this bug. *** The same behaviour can be seen on 4.3.4 RC1 with gluster 6.1 . 'Optimize for virt store' did not provide the option which prevented using the volume as gluster-based storage. 1.Could you provide the output of `gluster volume info $VOLNAME` for the affected volume? 2. Also the brick and mount logs of the affected volume for a failed run when `dd if=/dev/zero of=/path/to/mountoint/test bs=4096 count=1 oflag=direct` is executed? If this requires you to toggle remote-dio value just to hit the failure, please do that and share the logs for that run. -Krutika Let's keep the communication in BZ 1711060. ignore the last comment. Created attachment 1569959 [details]
part of the vdsm log on 4.3.4 RC1
Created attachment 1569960 [details]
Gluster mount log created during the failiure of the creation
New volume info at that time: Volume Name: data_fast4 Type: Replicate Volume ID: fe9144fa-2fa2-4fde-b17c-0b41308b205f Status: Started Snapshot Count: 0 Number of Bricks: 1 x (2 + 1) = 3 Transport-type: tcp Bricks: Brick1: gluster1:/gluster_bricks/data_fast4/data_fast4 Brick2: gluster2:/gluster_bricks/data_fast4/data_fast4 Brick3: ovirt3:/gluster_bricks/data_fast4/data_fast4 (arbiter) Options Reconfigured: network.ping-timeout: 30 cluster.granular-entry-heal: enable performance.strict-o-direct: on storage.owner-gid: 36 storage.owner-uid: 36 server.event-threads: 4 client.event-threads: 4 user.cifs: off features.shard: on cluster.shd-wait-qlength: 10000 cluster.shd-max-threads: 8 cluster.locking-scheme: granular cluster.data-self-heal-algorithm: full cluster.server-quorum-type: server cluster.quorum-type: auto cluster.eager-lock: enable network.remote-dio: off performance.low-prio-threads: 32 performance.io-cache: off performance.read-ahead: off performance.quick-read: off transport.address-family: inet nfs.disable: on performance.client-io-threads: on cluster.enable-shared-storage: enable Set the remote-dio to on in order to create the storage domain. The strange thing is that setting back the gluster volume to remote-dio off and mounting it on '/mnt' doesn't cause the issue. [root@ovirt1 mnt]# dd if=/dev/zero of=$(pwd)/test bs=4096 count=1 oflag=direct 1+0 records in 1+0 records out 4096 bytes (4.1 kB) copied, 0.00368095 s, 1.1 MB/s Here is a snip from vdsm log for another fresh gluster volume and the command is a little bit different: 2019-05-16 10:15:21,175+0300 INFO (jsonrpc/2) [storage.StorageDomain] sdUUID=591d9b61-5c7d-4388-a6b7-ab03181dff8a domainName=data_fast2 remotePath=gluster1:/data_fast2 domClass=1, block_size=512, alignment=1048576 (nfsSD:86) 2019-05-16 10:15:21,195+0300 INFO (jsonrpc/2) [IOProcessClient] (591d9b61-5c7d-4388-a6b7-ab03181dff8a) Starting client (__init__:308) 2019-05-16 10:15:21,207+0300 INFO (ioprocess/16362) [IOProcess] (591d9b61-5c7d-4388-a6b7-ab03181dff8a) Starting ioprocess (__init__:434) 2019-05-16 10:15:21,216+0300 INFO (jsonrpc/2) [storage.StorageDomain] Creating domain metadata directory u'/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md' (fileSD:450) 2019-05-16 10:15:21,253+0300 INFO (jsonrpc/2) [storage.xlease] Formatting index for lockspace u'591d9b61-5c7d-4388-a6b7-ab03181dff8a' (version=1) (xlease:673) 2019-05-16 10:15:21,296+0300 INFO (jsonrpc/2) [vdsm.api] FINISH createStorageDomain error=Command ['/usr/bin/dd', 'iflag=fullblock', u'of=/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases', 'oflag=direct,seek_bytes', 'seek=1048576', 'bs=256512', 'count=1', 'conv=notrunc,nocreat,fsync'] failed with rc=1 out='[suppressed]' err="/usr/bin/dd: error writing '/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases': Invalid argument\n1+0 records in\n0+0 records out\n0 bytes (0 B) copied, 0.0138582 s, 0.0 kB/s\n" from=::ffff:192.168.1.2,43864, flow_id=4a54578a, task_id=d2535d0f-c7f7-4f31-a10f-704923ce1790 (api:52) 2019-05-16 10:15:21,296+0300 ERROR (jsonrpc/2) [storage.TaskManager.Task] (Task='d2535d0f-c7f7-4f31-a10f-704923ce1790') 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 createStorageDomain 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 2614, in createStorageDomain storageType, domVersion, block_size, alignment) File "/usr/lib/python2.7/site-packages/vdsm/storage/nfsSD.py", line 106, in create block_size) File "/usr/lib/python2.7/site-packages/vdsm/storage/fileSD.py", line 466, in _prepareMetadata cls.format_external_leases(sdUUID, xleases_path) File "/usr/lib/python2.7/site-packages/vdsm/storage/sd.py", line 1255, in format_external_leases xlease.format_index(lockspace, backend) File "/usr/lib/python2.7/site-packages/vdsm/storage/xlease.py", line 681, in format_index index.dump(file) File "/usr/lib/python2.7/site-packages/vdsm/storage/xlease.py", line 843, in dump file.pwrite(INDEX_BASE, self._buf) File "/usr/lib/python2.7/site-packages/vdsm/storage/xlease.py", line 1076, in pwrite self._run(args, data=buf[:]) File "/usr/lib/python2.7/site-packages/vdsm/storage/xlease.py", line 1093, in _run raise cmdutils.Error(args, rc, "[suppressed]", err) Error: Command ['/usr/bin/dd', 'iflag=fullblock', u'of=/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases', 'oflag=direct,seek_bytes', 'seek=1048576', 'bs=256512', 'count=1', 'conv=notrunc,nocreat,fsync'] failed with rc=1 out='[suppressed]' err="/usr/bin/dd: error writing '/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases': Invalid argument\n1+0 records in\n0+0 records out\n0 bytes (0 B) copied, 0.0138582 s, 0.0 kB/s\n" 2019-05-16 10:15:21,296+0300 INFO (jsonrpc/2) [storage.TaskManager.Task] (Task='d2535d0f-c7f7-4f31-a10f-704923ce1790') aborting: Task is aborted: u'Command [\'/usr/bin/dd\', \'iflag=fullblock\', u\'of=/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases\', \'oflag=direct,seek_bytes\', \'seek=1048576\', \'bs=256512\', \'count=1\', \'conv=notrunc,nocreat,fsync\'] failed with rc=1 out=\'[suppressed]\' err="/usr/bin/dd: error writing \'/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases\': Invalid argument\\n1+0 records in\\n0+0 records out\\n0 bytes (0 B) copied, 0.0138582 s, 0.0 kB/s\\n"' - code 100 (task:1181) 2019-05-16 10:15:21,297+0300 ERROR (jsonrpc/2) [storage.Dispatcher] FINISH createStorageDomain error=Command ['/usr/bin/dd', 'iflag=fullblock', u'of=/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases', 'oflag=direct,seek_bytes', 'seek=1048576', 'bs=256512', 'count=1', 'conv=notrunc,nocreat,fsync'] failed with rc=1 out='[suppressed]' err="/usr/bin/dd: error writing '/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases': Invalid argument\n1+0 records in\n0+0 records out\n0 bytes (0 B) copied, 0.0138582 s, 0.0 kB/s\n" (dispatcher:87) Traceback (most recent call last): File "/usr/lib/python2.7/site-packages/vdsm/storage/dispatcher.py", line 74, 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 Error: Command ['/usr/bin/dd', 'iflag=fullblock', u'of=/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases', 'oflag=direct,seek_bytes', 'seek=1048576', 'bs=256512', 'count=1', 'conv=notrunc,nocreat,fsync'] failed with rc=1 out='[suppressed]' err="/usr/bin/dd: error writing '/rhev/data-center/mnt/glusterSD/gluster1:_data__fast2/591d9b61-5c7d-4388-a6b7-ab03181dff8a/dom_md/xleases': Invalid argument\n1+0 records in\n0+0 records out\n0 bytes (0 B) copied, 0.0138582 s, 0.0 kB/s\n" Not sure I understand. Are you saying turning remote-dio off is no longer causing IO to fail? Have you tried toggling it multiple times to see if it is stable? Let's wait for Darrel also to get back. Also, brick logs I'd need for the failure. They'd be under /var/log/glusterfs/bricks. -Krutika It seems so. I will try to create a fresh volume via cli and then to provide the logs. My system is 4.3.4 RC1 but gluster has not been touched between 4.3.3.7 -> 4.3.4 RC1 Let's see Darell's output... Redid the experiment as I'd destroyed the volume from the first test already, reconfirmed same results. Created volume in the web GUI, tried to add storage domain, failed with same error (as expected). Note that the DIRECT_IO_TEST file is created, but empty and owned by root. Same for DD tests when run on the volume mounted on /mnt. These logs are from the engine's attempt to create the storage domain. Root ownership of the DIRECT_IO_TEST file was important, as I had to remove it before being able to create the domain after enabling network.remote-dio just to confirm it was the only change needed. Expected, perhaps, but would be good if it had been cleaned up by the engine when the original test failed. [root@boneyard telsin]# gluster vol info test Volume Name: test Type: Replicate Volume ID: c4a22ffc-b328-4d5c-a63f-5adab1e9a93e Status: Started Snapshot Count: 0 Number of Bricks: 1 x 3 = 3 Transport-type: tcp Bricks: Brick1: 10.50.3.11:/v0/bricks/test Brick2: 10.50.3.10:/v0/bricks/test Brick3: 10.50.3.12:/v0/bricks/test Options Reconfigured: network.ping-timeout: 30 cluster.granular-entry-heal: enable performance.strict-o-direct: on storage.owner-gid: 36 storage.owner-uid: 36 server.event-threads: 4 client.event-threads: 4 cluster.choose-local: off features.shard: on cluster.shd-wait-qlength: 10000 cluster.shd-max-threads: 8 cluster.locking-scheme: granular cluster.data-self-heal-algorithm: full cluster.server-quorum-type: server cluster.quorum-type: auto cluster.eager-lock: enable network.remote-dio: off performance.low-prio-threads: 32 performance.io-cache: off performance.read-ahead: off performance.quick-read: off auth.allow: * user.cifs: off transport.address-family: inet nfs.disable: on performance.client-io-threads: on cluster.server-quorum-ratio: 50 vdsm.log: 2019-05-17 10:48:02,787-0500 INFO (jsonrpc/5) [vdsm.api] START connectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': u'00000000-0000-0000-0000-000000000000', u'connection': u'10.50.3.11:/test', 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''}], options=None) from=::ffff:10.100.90.5,44732, flow_id=d0bc00dd-b181-4636-afd0-4064283195d7, task_id=0ef787fa-d714-4962-a6e8-95ac45b59b59 (api:48) 2019-05-17 10:48:02,815-0500 INFO (jsonrpc/2) [vdsm.api] FINISH getStoragePoolInfo return={'info': {'name': 'No Description', 'isoprefix': '', 'pool_status': 'connected', 'lver': 41L, 'domains': u'3747c20e-34ba-44ac-9476-61818f88a269:Active,0dce69a7-40c2-4860-85db-4f3a5526bc11:Active', 'master_uuid': u'0dce69a7-40c2-4860-85db-4f3a5526bc11', 'version': '4', 'spm_id': 2, 'type': 'GLUSTERFS', 'master_ver': 134}, 'dominfo': {u'3747c20e-34ba-44ac-9476-61818f88a269': {'status': u'Active', 'diskfree': '398593884160', 'isoprefix': '', 'alerts': [], 'disktotal': '410640973824', 'version': 4}, u'0dce69a7-40c2-4860-85db-4f3a5526bc11': {'status': u'Active', 'diskfree': '398535950336', 'isoprefix': '', 'alerts': [], 'disktotal': '416429375488', 'version': 4}}} from=::ffff:10.100.90.5,43830, task_id=682d746d-68d2-41c7-91c5-3f0927e39459 (api:54) 2019-05-17 10:48:02,815-0500 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC call StoragePool.getInfo succeeded in 0.05 seconds (__init__:312) 2019-05-17 10:48:02,939-0500 INFO (jsonrpc/5) [storage.StorageServer.MountConnection] Creating directory u'/rhev/data-center/mnt/glusterSD/10.50.3.11:_test' (storageServer:168) 2019-05-17 10:48:02,940-0500 INFO (jsonrpc/5) [storage.fileUtils] Creating directory: /rhev/data-center/mnt/glusterSD/10.50.3.11:_test mode: None (fileUtils:199) 2019-05-17 10:48:02,940-0500 WARN (jsonrpc/5) [storage.StorageServer.MountConnection] Using user specified backup-volfile-servers option (storageServer:275) 2019-05-17 10:48:02,940-0500 INFO (jsonrpc/5) [storage.Mount] mounting 10.50.3.11:/test at /rhev/data-center/mnt/glusterSD/10.50.3.11:_test (mount:204) 2019-05-17 10:48:03,089-0500 INFO (jsonrpc/5) [IOProcessClient] (Global) Starting client (__init__:308) 2019-05-17 10:48:03,096-0500 INFO (ioprocess/12048) [IOProcess] (Global) Starting ioprocess (__init__:434) 2019-05-17 10:48:03,114-0500 INFO (itmap/0) [IOProcessClient] (/glusterSD/10.50.3.11:_test) Starting client (__init__:308) 2019-05-17 10:48:03,121-0500 INFO (itmap/1) [IOProcessClient] (/glusterSD/dev-san:_gv0) Starting client (__init__:308) 2019-05-17 10:48:03,123-0500 INFO (ioprocess/12097) [IOProcess] (/glusterSD/10.50.3.11:_test) Starting ioprocess (__init__:434) 2019-05-17 10:48:03,128-0500 INFO (itmap/2) [IOProcessClient] (/glusterSD/dev-san:_gvOvirt) Starting client (__init__:308) 2019-05-17 10:48:03,131-0500 INFO (ioprocess/12105) [IOProcess] (/glusterSD/dev-san:_gv0) Starting ioprocess (__init__:434) 2019-05-17 10:48:03,136-0500 INFO (ioprocess/12111) [IOProcess] (/glusterSD/dev-san:_gvOvirt) Starting ioprocess (__init__:434) 2019-05-17 10:48:03,139-0500 INFO (jsonrpc/5) [vdsm.api] FINISH connectStorageServer return={'statuslist': [{'status': 0, 'id': u'00000000-0000-0000-0000-000000000000'}]} from=::ffff:10.100.90.5,44732, flow_id=d0bc00dd-b181-4636-afd0-4064283195d7, task_id=0ef787fa-d714-4962-a6e8-95ac45b59b59 (api:54) 2019-05-17 10:48:03,139-0500 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC call StoragePool.connectStorageServer succeeded in 0.35 seconds (__init__:312) 2019-05-17 10:48:03,883-0500 INFO (jsonrpc/1) [vdsm.api] START connectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': u'253295f9-e5a2-4864-992e-7dc6f54b2222', u'connection': u'10.50.3.11:/test', 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''}], options=None) from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, task_id=c121c2a0-05ec-42d2-aed7-13bfc4d485e4 (api:48) 2019-05-17 10:48:03,887-0500 INFO (jsonrpc/1) [vdsm.api] FINISH connectStorageServer return={'statuslist': [{'status': 0, 'id': u'253295f9-e5a2-4864-992e-7dc6f54b2222'}]} from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, task_id=c121c2a0-05ec-42d2-aed7-13bfc4d485e4 (api:54) 2019-05-17 10:48:03,888-0500 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC call StoragePool.connectStorageServer succeeded in 0.01 seconds (__init__:312) 2019-05-17 10:48:03,892-0500 INFO (jsonrpc/7) [vdsm.api] START createStorageDomain(storageType=7, sdUUID=u'f8222c62-65d0-4257-913b-b8309a195e97', domainName=u'gTest', typeSpecificArg=u'10.50.3.11:/test', domClass=1, domVersion=u'4', block_size=512, max_hosts=250, options=None) from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, task_id=e1ac11d3-f19e-4e32-a210-9cd88742b8b8 (api:48) 2019-05-17 10:48:04,205-0500 WARN (jsonrpc/7) [storage.LVM] Reloading VGs failed (vgs=[u'f8222c62-65d0-4257-913b-b8309a195e97'] rc=5 out=[] err=[' Volume group "f8222c62-65d0-4257-913b-b8309a195e97" not found', ' Cannot process volume group f8222c62-65d0-4257-913b-b8309a195e97']) (lvm:442) 2019-05-17 10:48:04,224-0500 INFO (periodic/31) [vdsm.api] START repoStats(domains=()) from=internal, task_id=c65982d4-6a9d-4eaf-a7cb-34f6b84e44d4 (api:48) 2019-05-17 10:48:04,225-0500 INFO (periodic/31) [vdsm.api] FINISH repoStats return={u'3747c20e-34ba-44ac-9476-61818f88a269': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00101691', 'lastCheck': '6.1', 'valid': True}, u'0dce69a7-40c2-4860-85db-4f3a5526bc11': {'code': 0, 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00131841', 'lastCheck': '5.7', 'valid': True}} from=internal, task_id=c65982d4-6a9d-4eaf-a7cb-34f6b84e44d4 (api:54) 2019-05-17 10:48:04,238-0500 INFO (jsonrpc/7) [storage.StorageDomain] sdUUID=f8222c62-65d0-4257-913b-b8309a195e97 domainName=gTest remotePath=10.50.3.11:/test domClass=1, block_size=512, alignment=1048576 (nfsSD:86) 2019-05-17 10:48:04,254-0500 INFO (jsonrpc/7) [IOProcessClient] (f8222c62-65d0-4257-913b-b8309a195e97) Starting client (__init__:308) 2019-05-17 10:48:04,261-0500 INFO (ioprocess/12146) [IOProcess] (f8222c62-65d0-4257-913b-b8309a195e97) Starting ioprocess (__init__:434) 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.fileSD] Underlying file system doesn't supportdirect IO (fileSD:110) 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [vdsm.api] FINISH createStorageDomain error=Storage Domain target is unsupported: () from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, task_id=e1ac11d3-f19e-4e32-a210-9cd88742b8b8 (api:52) 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.TaskManager.Task] (Task='e1ac11d3-f19e-4e32-a210-9cd88742b8b8') Unexpected error (task:875) 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [storage.TaskManager.Task] (Task='e1ac11d3-f19e-4e32-a210-9cd88742b8b8') aborting: Task is aborted: 'Storage Domain target is unsupported: ()' - code 399 (task:1181) 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.Dispatcher] FINISH createStorageDomain error=Storage Domain target is unsupported: () (dispatcher:83) 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC call StorageDomain.create failed (error 399) in 0.42 seconds (__init__:312) 2019-05-17 10:48:05,106-0500 INFO (jsonrpc/3) [vdsm.api] START disconnectStorageServer(domType=7, spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': u'253295f9-e5a2-4864-992e-7dc6f54b2222', u'connection': u'10.50.3.11:/test', 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''}], options=None) from=::ffff:10.100.90.5,44732, flow_id=f7709310-0b0d-4fce-b01c-4a42dd50072c, task_id=6245c346-7bfa-48a9-9edf-8532ef491347 (api:48) 2019-05-17 10:48:05,107-0500 INFO (jsonrpc/3) [storage.Mount] unmounting /rhev/data-center/mnt/glusterSD/10.50.3.11:_test (mount:212) 2019-05-17 10:48:05,313-0500 INFO (jsonrpc/3) [vdsm.api] FINISH disconnectStorageServer return={'statuslist': [{'status': 0, 'id': u'253295f9-e5a2-4864-992e-7dc6f54b2222'}]} from=::ffff:10.100.90.5,44732, flow_id=f7709310-0b0d-4fce-b01c-4a42dd50072c, task_id=6245c346-7bfa-48a9-9edf-8532ef491347 (api:54) 2019-05-17 10:48:05,314-0500 INFO (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC call StoragePool.disconnectStorageServer succeeded in 0.20 seconds (__init__:312) brick logs: [2019-05-17 15:47:16.857040] I [MSGID: 100030] [glusterfsd.c:2849:main] 0-/usr/s bin/glusterfsd: Started running /usr/sbin/glusterfsd version 6.1 (args: /usr/sbi n/glusterfsd -s 10.50.3.11 --volfile-id test.10.50.3.11.v0-bricks-test -p /var/r un/gluster/vols/test/10.50.3.11-v0-bricks-test.pid -S /var/run/gluster/35185988e 170e6ed.socket --brick-name /v0/bricks/test -l /var/log/glusterfs/bricks/v0-bric ks-test.log --xlator-option *-posix.glusterd-uuid=7643ebf9-7661-4b9b-935b-93fa4c 85ab6f --process-name brick --brick-port 49152 --xlator-option test-server.liste n-port=49152) [2019-05-17 15:47:16.857723] I [glusterfsd.c:2556:daemonize] 0-glusterfs: Pid of current running process is 11027 [2019-05-17 15:47:16.862835] I [socket.c:902:__socket_server_bind] 0-socket.glus terfsd: closing (AF_UNIX) reuse check socket 9 [2019-05-17 15:47:16.869909] I [MSGID: 101190] [event-epoll.c:680:event_dispatch _epoll_worker] 0-epoll: Started thread with index 0 [2019-05-17 15:47:16.869947] I [MSGID: 101190] [event-epoll.c:680:event_dispatch _epoll_worker] 0-epoll: Started thread with index 1 [2019-05-17 15:47:16.874653] I [MSGID: 101190] [event-epoll.c:680:event_dispatch _epoll_worker] 0-epoll: Started thread with index 2 [2019-05-17 15:47:16.874700] I [MSGID: 101190] [event-epoll.c:680:event_dispatch _epoll_worker] 0-epoll: Started thread with index 3 [2019-05-17 15:47:16.874928] I [rpcsvc.c:2698:rpcsvc_set_outstanding_rpc_limit] 0-rpc-service: Configured rpc.outstanding-rpc-limit with value 64 [2019-05-17 15:47:16.876961] I [socket.c:902:__socket_server_bind] 0-socket.test -changelog: closing (AF_UNIX) reuse check socket 14 [2019-05-17 15:47:16.877172] I [trash.c:2450:init] 0-test-trash: no option speci fied for 'eliminate', using NULL Final graph: +------------------------------------------------------------------------------+ 1: volume test-posix 2: type storage/posix 3: option glusterd-uuid 7643ebf9-7661-4b9b-935b-93fa4c85ab6f 4: option directory /v0/bricks/test 5: option volume-id c4a22ffc-b328-4d5c-a63f-5adab1e9a93e 6: option shared-brick-count 1 7: option brick-uid 36 8: option brick-gid 36 9: end-volume 10: 11: volume test-trash 12: type features/trash 13: option trash-dir .trashcan 14: option brick-path /v0/bricks/test 15: option trash-internal-op off 16: subvolumes test-posix 17: end-volume 18: 19: volume test-changelog 20: type features/changelog 21: option changelog-brick /v0/bricks/test 22: option changelog-dir /v0/bricks/test/.glusterfs/changelogs 23: option changelog-barrier-timeout 120 24: subvolumes test-trash 25: end-volume 26: 27: volume test-bitrot-stub 28: type features/bitrot-stub 29: option export /v0/bricks/test 30: option bitrot disable 31: subvolumes test-changelog 32: end-volume 33: 34: volume test-access-control 35: type features/access-control 36: subvolumes test-bitrot-stub 37: end-volume 38: 39: volume test-locks 40: type features/locks 41: option enforce-mandatory-lock off 42: subvolumes test-access-control 43: end-volume 44: 45: volume test-worm 46: type features/worm 47: option worm off 48: option worm-file-level off 49: option worm-files-deletable on 50: subvolumes test-locks 51: end-volume 52: 53: volume test-read-only 54: type features/read-only 55: option read-only off 56: subvolumes test-worm 57: end-volume 58: 59: volume test-leases 60: type features/leases 61: option leases off 62: subvolumes test-read-only 63: end-volume 64: 65: volume test-upcall 66: type features/upcall 67: option cache-invalidation off 68: subvolumes test-leases 69: end-volume 70: 71: volume test-io-threads 72: type performance/io-threads 73: option low-prio-threads 32 74: subvolumes test-upcall 75: end-volume 76: 77: volume test-selinux 78: type features/selinux 79: option selinux on 80: subvolumes test-io-threads 81: end-volume 82: 83: volume test-marker 84: type features/marker 85: option volume-uuid c4a22ffc-b328-4d5c-a63f-5adab1e9a93e 86: option timestamp-file /var/lib/glusterd/vols/test/marker.tstamp 87: option quota-version 0 88: option xtime off 89: option gsync-force-xtime off 90: option quota off 91: option inode-quota off 92: subvolumes test-selinux 93: end-volume 94: 95: volume test-barrier 96: type features/barrier 97: option barrier disable 98: option barrier-timeout 120 99: subvolumes test-marker 100: end-volume 101: 102: volume test-index 103: type features/index 104: option index-base /v0/bricks/test/.glusterfs/indices 105: option xattrop-dirty-watchlist trusted.afr.dirty 106: option xattrop-pending-watchlist trusted.afr.test- 107: subvolumes test-barrier 108: end-volume 109: 110: volume test-quota 111: type features/quota 112: option volume-uuid test 113: option server-quota off 114: option deem-statfs off 115: subvolumes test-index 116: end-volume 117: 118: volume test-io-stats 119: type debug/io-stats 120: option unique-id /v0/bricks/test 121: option log-level INFO 122: option latency-measurement off 123: option count-fop-hits off 124: subvolumes test-quota 125: end-volume 126: 127: volume /v0/bricks/test 128: type performance/decompounder 129: option auth.addr./v0/bricks/test.allow * 130: option auth-path /v0/bricks/test 131: option auth.login.24909ee0-24cc-4f78-af68-275187589fae.password 2ce65fd a-fb86-416d-9e29-861ac3a738c6 132: option auth.login./v0/bricks/test.allow 24909ee0-24cc-4f78-af68-2751875 89fae 133: subvolumes test-io-stats 134: end-volume 135: 136: volume test-server 137: type protocol/server 138: option transport.socket.listen-port 49152 139: option rpc-auth.auth-glusterfs on 140: option rpc-auth.auth-unix on 141: option rpc-auth.auth-null on 142: option rpc-auth-allow-insecure on 143: option transport-type tcp 144: option transport.address-family inet 145: option auth.login./v0/bricks/test.allow 24909ee0-24cc-4f78-af68-2751875 89fae 146: option auth.login.24909ee0-24cc-4f78-af68-275187589fae.password 2ce65fd a-fb86-416d-9e29-861ac3a738c6 147: option auth-path /v0/bricks/test 148: option auth.addr./v0/bricks/test.allow * 149: option transport.socket.keepalive 1 150: option transport.socket.ssl-enabled off 151: option event-threads 4 152: option transport.socket.keepalive-time 20 153: option transport.socket.keepalive-interval 2 154: option transport.socket.keepalive-count 9 155: option transport.listen-backlog 1024 156: subvolumes /v0/bricks/test 157: end-volume 158: +------------------------------------------------------------------------------+ [2019-05-17 15:47:18.977033] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.12" [2019-05-17 15:47:18.977055] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:47:18.977068] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:263830b2-de4d-4f5b-9049-e829 925db095-GRAPH_ID:6-PID:22730-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-clie nt-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:47:18.979652] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.12" [2019-05-17 15:47:18.979670] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:47:18.979693] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:360b06ff-d4a7-4d68-b6e9-bde7 096e3d82-GRAPH_ID:0-PID:6085-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-clien t-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:47:18.980363] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] 0-rpc-servi ce: spawned a request handler thread for queue 0 [2019-05-17 15:47:19.017248] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.11" [2019-05-17 15:47:19.017275] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:47:19.017294] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:d424cc54-9a87-403e-b217-6313 62eeaff3-GRAPH_ID:0-PID:11061-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test-cli ent-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:47:20.602649] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.10" [2019-05-17 15:47:20.602669] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:47:20.602679] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:a332606e-0f41-4f72-9060-a474 2add08b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME:test-c lient-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:47:20.611796] I [MSGID: 115036] [server.c:499:server_rpc_notify] 0-test-server: disconnecting connection from CTX_ID:a332606e-0f41-4f72-9060-a474 2add08b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME:test-c lient-0-RECON_NO:-0 [2019-05-17 15:47:20.611900] I [MSGID: 101055] [client_t.c:436:gf_client_unref] 0-test-server: Shutting down connection CTX_ID:a332606e-0f41-4f72-9060-a4742add0 8b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME:test-client -0-RECON_NO:-0 [2019-05-17 15:47:20.855104] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.10" [2019-05-17 15:47:20.855134] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:47:20.855144] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:f654a9a1-0241-4415-a88f-b0a2 b83b2301-GRAPH_ID:0-PID:26419-HOST:necropolis.int.ohgnetworks.com-PC_NAME:test-c lient-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:47:20.856227] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] 0-rpc-servi ce: spawned a request handler thread for queue 1 [2019-05-17 15:48:03.062247] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.11" [2019-05-17 15:48:03.062271] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:48:03.062282] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:471a7ddb-e566-4364-a171-8de6 c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test-cli ent-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:48:04.264875] E [MSGID: 113069] [posix-entry-ops.c:2123:posix_cre ate] 0-test-posix: open on /v0/bricks/test/__DIRECT_IO_TEST__ failed [Invalid ar gument] [2019-05-17 15:48:04.264931] I [MSGID: 115071] [server-rpc-fops_v2.c:1546:server 4_create_cbk] 0-test-server: 25: CREATE /__DIRECT_IO_TEST__ (00000000-0000-0000- 0000-000000000001/__DIRECT_IO_TEST__), client: CTX_ID:471a7ddb-e566-4364-a171-8d e6c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test-c lient-0-RECON_NO:-0, error-xlator: test-posix [Invalid argument] [2019-05-17 15:48:05.120532] I [MSGID: 115036] [server.c:499:server_rpc_notify] 0-test-server: disconnecting connection from CTX_ID:471a7ddb-e566-4364-a171-8de6 c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test-cli ent-0-RECON_NO:-0 [2019-05-17 15:48:05.120658] I [MSGID: 101055] [client_t.c:436:gf_client_unref] 0-test-server: Shutting down connection CTX_ID:471a7ddb-e566-4364-a171-8de6c75b9 dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test-client-0 -RECON_NO:-0 [2019-05-17 15:50:15.508396] I [addr.c:54:compare_addr_and_update] 0-/v0/bricks/ test: allowed = "*", received addr = "10.50.3.12" [2019-05-17 15:50:15.508429] I [login.c:110:gf_auth] 0-auth/login: allowed user names: 24909ee0-24cc-4f78-af68-275187589fae [2019-05-17 15:50:15.508439] I [MSGID: 115029] [server-handshake.c:550:server_se tvolume] 0-test-server: accepted client from CTX_ID:35a55e7e-7e14-4653-918e-0959 97a81ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-clien t-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test [2019-05-17 15:50:15.526169] I [MSGID: 115036] [server.c:499:server_rpc_notify] 0-test-server: disconnecting connection from CTX_ID:35a55e7e-7e14-4653-918e-0959 97a81ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-clien t-0-RECON_NO:-0 [2019-05-17 15:50:15.526271] I [MSGID: 101055] [client_t.c:436:gf_client_unref] 0-test-server: Shutting down connection CTX_ID:35a55e7e-7e14-4653-918e-095997a81 ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-client-0-R ECON_NO:-0 [2019-05-17 15:52:16.992388] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] 0-rpc-servi ce: spawned a request handler thread for queue 2 It seems that my case is different from Darell's while the symptoms are the same. Now I have destroyed all 4 Storage Domains, gluster volumes and vdo and recreated again (4 gluster volumes on a single vdo). This time vdo has '--emulate512=true' and no issues have been observed. Gluster volume options before 'Optimize for virt': Volume Name: data_fast Type: Replicate Volume ID: 378804bf-2975-44d8-84c2-b541aa87f9ef Status: Started Snapshot Count: 0 Number of Bricks: 1 x (2 + 1) = 3 Transport-type: tcp Bricks: Brick1: gluster1:/gluster_bricks/data_fast/data_fast Brick2: gluster2:/gluster_bricks/data_fast/data_fast Brick3: ovirt3:/gluster_bricks/data_fast/data_fast (arbiter) Options Reconfigured: transport.address-family: inet nfs.disable: on performance.client-io-threads: off cluster.enable-shared-storage: enable Gluster volume after 'Optimize for virt': Volume Name: data_fast Type: Replicate Volume ID: 378804bf-2975-44d8-84c2-b541aa87f9ef Status: Stopped Snapshot Count: 0 Number of Bricks: 1 x (2 + 1) = 3 Transport-type: tcp Bricks: Brick1: gluster1:/gluster_bricks/data_fast/data_fast Brick2: gluster2:/gluster_bricks/data_fast/data_fast Brick3: ovirt3:/gluster_bricks/data_fast/data_fast (arbiter) Options Reconfigured: network.ping-timeout: 30 performance.strict-o-direct: on storage.owner-gid: 36 storage.owner-uid: 36 server.event-threads: 4 client.event-threads: 4 cluster.choose-local: off user.cifs: off features.shard: on cluster.shd-wait-qlength: 10000 cluster.shd-max-threads: 8 cluster.locking-scheme: granular cluster.data-self-heal-algorithm: full cluster.server-quorum-type: server cluster.quorum-type: auto cluster.eager-lock: enable network.remote-dio: off performance.low-prio-threads: 32 performance.io-cache: off performance.read-ahead: off performance.quick-read: off transport.address-family: inet nfs.disable: on performance.client-io-threads: on cluster.enable-shared-storage: enable After that adding the volumes as storage domains (via UI) worked without any issues. (In reply to Darrell from comment #12) > Redid the experiment as I'd destroyed the volume from the first test > already, reconfirmed same results. Created volume in the web GUI, tried to > add storage domain, failed with same error (as expected). Note that the > DIRECT_IO_TEST file is created, but empty and owned by root. Same for DD > tests when run on the volume mounted on /mnt. These logs are from the > engine's attempt to create the storage domain. > > Root ownership of the DIRECT_IO_TEST file was important, as I had to remove > it before being able to create the domain after enabling network.remote-dio > just to confirm it was the only change needed. Expected, perhaps, but would > be good if it had been cleaned up by the engine when the original test > failed. > > [root@boneyard telsin]# gluster vol info test > > Volume Name: test > Type: Replicate > Volume ID: c4a22ffc-b328-4d5c-a63f-5adab1e9a93e > Status: Started > Snapshot Count: 0 > Number of Bricks: 1 x 3 = 3 > Transport-type: tcp > Bricks: > Brick1: 10.50.3.11:/v0/bricks/test > Brick2: 10.50.3.10:/v0/bricks/test > Brick3: 10.50.3.12:/v0/bricks/test > Options Reconfigured: > network.ping-timeout: 30 > cluster.granular-entry-heal: enable > performance.strict-o-direct: on > storage.owner-gid: 36 > storage.owner-uid: 36 > server.event-threads: 4 > client.event-threads: 4 > cluster.choose-local: off > features.shard: on > cluster.shd-wait-qlength: 10000 > cluster.shd-max-threads: 8 > cluster.locking-scheme: granular > cluster.data-self-heal-algorithm: full > cluster.server-quorum-type: server > cluster.quorum-type: auto > cluster.eager-lock: enable > network.remote-dio: off > performance.low-prio-threads: 32 > performance.io-cache: off > performance.read-ahead: off > performance.quick-read: off > auth.allow: * > user.cifs: off > transport.address-family: inet > nfs.disable: on > performance.client-io-threads: on > cluster.server-quorum-ratio: 50 > > vdsm.log: > 2019-05-17 10:48:02,787-0500 INFO (jsonrpc/5) [vdsm.api] START > connectStorageServer(domType=7, > spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': > u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': > u'00000000-0000-0000-0000-000000000000', u'connection': u'10.50.3.11:/test', > 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''}], > options=None) from=::ffff:10.100.90.5,44732, > flow_id=d0bc00dd-b181-4636-afd0-4064283195d7, > task_id=0ef787fa-d714-4962-a6e8-95ac45b59b59 (api:48) > 2019-05-17 10:48:02,815-0500 INFO (jsonrpc/2) [vdsm.api] FINISH > getStoragePoolInfo return={'info': {'name': 'No Description', 'isoprefix': > '', 'pool_status': 'connected', 'lver': 41L, 'domains': > u'3747c20e-34ba-44ac-9476-61818f88a269:Active,0dce69a7-40c2-4860-85db- > 4f3a5526bc11:Active', 'master_uuid': > u'0dce69a7-40c2-4860-85db-4f3a5526bc11', 'version': '4', 'spm_id': 2, > 'type': 'GLUSTERFS', 'master_ver': 134}, 'dominfo': > {u'3747c20e-34ba-44ac-9476-61818f88a269': {'status': u'Active', 'diskfree': > '398593884160', 'isoprefix': '', 'alerts': [], 'disktotal': '410640973824', > 'version': 4}, u'0dce69a7-40c2-4860-85db-4f3a5526bc11': {'status': > u'Active', 'diskfree': '398535950336', 'isoprefix': '', 'alerts': [], > 'disktotal': '416429375488', 'version': 4}}} from=::ffff:10.100.90.5,43830, > task_id=682d746d-68d2-41c7-91c5-3f0927e39459 (api:54) > 2019-05-17 10:48:02,815-0500 INFO (jsonrpc/2) [jsonrpc.JsonRpcServer] RPC > call StoragePool.getInfo succeeded in 0.05 seconds (__init__:312) > 2019-05-17 10:48:02,939-0500 INFO (jsonrpc/5) > [storage.StorageServer.MountConnection] Creating directory > u'/rhev/data-center/mnt/glusterSD/10.50.3.11:_test' (storageServer:168) > 2019-05-17 10:48:02,940-0500 INFO (jsonrpc/5) [storage.fileUtils] Creating > directory: /rhev/data-center/mnt/glusterSD/10.50.3.11:_test mode: None > (fileUtils:199) > 2019-05-17 10:48:02,940-0500 WARN (jsonrpc/5) > [storage.StorageServer.MountConnection] Using user specified > backup-volfile-servers option (storageServer:275) > 2019-05-17 10:48:02,940-0500 INFO (jsonrpc/5) [storage.Mount] mounting > 10.50.3.11:/test at /rhev/data-center/mnt/glusterSD/10.50.3.11:_test > (mount:204) > 2019-05-17 10:48:03,089-0500 INFO (jsonrpc/5) [IOProcessClient] (Global) > Starting client (__init__:308) > 2019-05-17 10:48:03,096-0500 INFO (ioprocess/12048) [IOProcess] (Global) > Starting ioprocess (__init__:434) > 2019-05-17 10:48:03,114-0500 INFO (itmap/0) [IOProcessClient] > (/glusterSD/10.50.3.11:_test) Starting client (__init__:308) > 2019-05-17 10:48:03,121-0500 INFO (itmap/1) [IOProcessClient] > (/glusterSD/dev-san:_gv0) Starting client (__init__:308) > 2019-05-17 10:48:03,123-0500 INFO (ioprocess/12097) [IOProcess] > (/glusterSD/10.50.3.11:_test) Starting ioprocess (__init__:434) > 2019-05-17 10:48:03,128-0500 INFO (itmap/2) [IOProcessClient] > (/glusterSD/dev-san:_gvOvirt) Starting client (__init__:308) > 2019-05-17 10:48:03,131-0500 INFO (ioprocess/12105) [IOProcess] > (/glusterSD/dev-san:_gv0) Starting ioprocess (__init__:434) > 2019-05-17 10:48:03,136-0500 INFO (ioprocess/12111) [IOProcess] > (/glusterSD/dev-san:_gvOvirt) Starting ioprocess (__init__:434) > 2019-05-17 10:48:03,139-0500 INFO (jsonrpc/5) [vdsm.api] FINISH > connectStorageServer return={'statuslist': [{'status': 0, 'id': > u'00000000-0000-0000-0000-000000000000'}]} from=::ffff:10.100.90.5,44732, > flow_id=d0bc00dd-b181-4636-afd0-4064283195d7, > task_id=0ef787fa-d714-4962-a6e8-95ac45b59b59 (api:54) > 2019-05-17 10:48:03,139-0500 INFO (jsonrpc/5) [jsonrpc.JsonRpcServer] RPC > call StoragePool.connectStorageServer succeeded in 0.35 seconds > (__init__:312) > 2019-05-17 10:48:03,883-0500 INFO (jsonrpc/1) [vdsm.api] START > connectStorageServer(domType=7, > spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': > u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': > u'253295f9-e5a2-4864-992e-7dc6f54b2222', u'connection': u'10.50.3.11:/test', > 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''}], > options=None) from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, > task_id=c121c2a0-05ec-42d2-aed7-13bfc4d485e4 (api:48) > 2019-05-17 10:48:03,887-0500 INFO (jsonrpc/1) [vdsm.api] FINISH > connectStorageServer return={'statuslist': [{'status': 0, 'id': > u'253295f9-e5a2-4864-992e-7dc6f54b2222'}]} from=::ffff:10.100.90.5,44732, > flow_id=2b3475ad, task_id=c121c2a0-05ec-42d2-aed7-13bfc4d485e4 (api:54) > 2019-05-17 10:48:03,888-0500 INFO (jsonrpc/1) [jsonrpc.JsonRpcServer] RPC > call StoragePool.connectStorageServer succeeded in 0.01 seconds > (__init__:312) > 2019-05-17 10:48:03,892-0500 INFO (jsonrpc/7) [vdsm.api] START > createStorageDomain(storageType=7, > sdUUID=u'f8222c62-65d0-4257-913b-b8309a195e97', domainName=u'gTest', > typeSpecificArg=u'10.50.3.11:/test', domClass=1, domVersion=u'4', > block_size=512, max_hosts=250, options=None) from=::ffff:10.100.90.5,44732, > flow_id=2b3475ad, task_id=e1ac11d3-f19e-4e32-a210-9cd88742b8b8 (api:48) > 2019-05-17 10:48:04,205-0500 WARN (jsonrpc/7) [storage.LVM] Reloading VGs > failed (vgs=[u'f8222c62-65d0-4257-913b-b8309a195e97'] rc=5 out=[] err=[' > Volume group "f8222c62-65d0-4257-913b-b8309a195e97" not found', ' Cannot > process volume group f8222c62-65d0-4257-913b-b8309a195e97']) (lvm:442) > 2019-05-17 10:48:04,224-0500 INFO (periodic/31) [vdsm.api] START > repoStats(domains=()) from=internal, > task_id=c65982d4-6a9d-4eaf-a7cb-34f6b84e44d4 (api:48) > 2019-05-17 10:48:04,225-0500 INFO (periodic/31) [vdsm.api] FINISH repoStats > return={u'3747c20e-34ba-44ac-9476-61818f88a269': {'code': 0, 'actual': True, > 'version': 4, 'acquired': True, 'delay': '0.00101691', 'lastCheck': '6.1', > 'valid': True}, u'0dce69a7-40c2-4860-85db-4f3a5526bc11': {'code': 0, > 'actual': True, 'version': 4, 'acquired': True, 'delay': '0.00131841', > 'lastCheck': '5.7', 'valid': True}} from=internal, > task_id=c65982d4-6a9d-4eaf-a7cb-34f6b84e44d4 (api:54) > 2019-05-17 10:48:04,238-0500 INFO (jsonrpc/7) [storage.StorageDomain] > sdUUID=f8222c62-65d0-4257-913b-b8309a195e97 domainName=gTest > remotePath=10.50.3.11:/test domClass=1, block_size=512, alignment=1048576 > (nfsSD:86) > 2019-05-17 10:48:04,254-0500 INFO (jsonrpc/7) [IOProcessClient] > (f8222c62-65d0-4257-913b-b8309a195e97) Starting client (__init__:308) > 2019-05-17 10:48:04,261-0500 INFO (ioprocess/12146) [IOProcess] > (f8222c62-65d0-4257-913b-b8309a195e97) Starting ioprocess (__init__:434) > 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.fileSD] Underlying > file system doesn't supportdirect IO (fileSD:110) > 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [vdsm.api] FINISH > createStorageDomain error=Storage Domain target is unsupported: () > from=::ffff:10.100.90.5,44732, flow_id=2b3475ad, > task_id=e1ac11d3-f19e-4e32-a210-9cd88742b8b8 (api:52) > 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.TaskManager.Task] > (Task='e1ac11d3-f19e-4e32-a210-9cd88742b8b8') Unexpected error (task:875) > 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [storage.TaskManager.Task] > (Task='e1ac11d3-f19e-4e32-a210-9cd88742b8b8') aborting: Task is aborted: > 'Storage Domain target is unsupported: ()' - code 399 (task:1181) > 2019-05-17 10:48:04,306-0500 ERROR (jsonrpc/7) [storage.Dispatcher] FINISH > createStorageDomain error=Storage Domain target is unsupported: () > (dispatcher:83) > 2019-05-17 10:48:04,306-0500 INFO (jsonrpc/7) [jsonrpc.JsonRpcServer] RPC > call StorageDomain.create failed (error 399) in 0.42 seconds (__init__:312) > 2019-05-17 10:48:05,106-0500 INFO (jsonrpc/3) [vdsm.api] START > disconnectStorageServer(domType=7, > spUUID=u'00000000-0000-0000-0000-000000000000', conList=[{u'mnt_options': > u'backup-volfile-servers=10.50.3.10:10.50.3.12', u'id': > u'253295f9-e5a2-4864-992e-7dc6f54b2222', u'connection': u'10.50.3.11:/test', > 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''}], > options=None) from=::ffff:10.100.90.5,44732, > flow_id=f7709310-0b0d-4fce-b01c-4a42dd50072c, > task_id=6245c346-7bfa-48a9-9edf-8532ef491347 (api:48) > 2019-05-17 10:48:05,107-0500 INFO (jsonrpc/3) [storage.Mount] unmounting > /rhev/data-center/mnt/glusterSD/10.50.3.11:_test (mount:212) > 2019-05-17 10:48:05,313-0500 INFO (jsonrpc/3) [vdsm.api] FINISH > disconnectStorageServer return={'statuslist': [{'status': 0, 'id': > u'253295f9-e5a2-4864-992e-7dc6f54b2222'}]} from=::ffff:10.100.90.5,44732, > flow_id=f7709310-0b0d-4fce-b01c-4a42dd50072c, > task_id=6245c346-7bfa-48a9-9edf-8532ef491347 (api:54) > 2019-05-17 10:48:05,314-0500 INFO (jsonrpc/3) [jsonrpc.JsonRpcServer] RPC > call StoragePool.disconnectStorageServer succeeded in 0.20 seconds > (__init__:312) > > brick logs: > [2019-05-17 15:47:16.857040] I [MSGID: 100030] [glusterfsd.c:2849:main] > 0-/usr/s > bin/glusterfsd: Started running /usr/sbin/glusterfsd version 6.1 (args: > /usr/sbi > n/glusterfsd -s 10.50.3.11 --volfile-id test.10.50.3.11.v0-bricks-test -p > /var/r > un/gluster/vols/test/10.50.3.11-v0-bricks-test.pid -S > /var/run/gluster/35185988e > 170e6ed.socket --brick-name /v0/bricks/test -l > /var/log/glusterfs/bricks/v0-bric > ks-test.log --xlator-option > *-posix.glusterd-uuid=7643ebf9-7661-4b9b-935b-93fa4c > 85ab6f --process-name brick --brick-port 49152 --xlator-option > test-server.liste > n-port=49152) > [2019-05-17 15:47:16.857723] I [glusterfsd.c:2556:daemonize] 0-glusterfs: > Pid of > current running process is 11027 > [2019-05-17 15:47:16.862835] I [socket.c:902:__socket_server_bind] > 0-socket.glus > terfsd: closing (AF_UNIX) reuse check socket 9 > [2019-05-17 15:47:16.869909] I [MSGID: 101190] > [event-epoll.c:680:event_dispatch > _epoll_worker] 0-epoll: Started thread with index 0 > [2019-05-17 15:47:16.869947] I [MSGID: 101190] > [event-epoll.c:680:event_dispatch > _epoll_worker] 0-epoll: Started thread with index 1 > [2019-05-17 15:47:16.874653] I [MSGID: 101190] > [event-epoll.c:680:event_dispatch > _epoll_worker] 0-epoll: Started thread with index 2 > [2019-05-17 15:47:16.874700] I [MSGID: 101190] > [event-epoll.c:680:event_dispatch > _epoll_worker] 0-epoll: Started thread with index 3 > [2019-05-17 15:47:16.874928] I > [rpcsvc.c:2698:rpcsvc_set_outstanding_rpc_limit] > 0-rpc-service: Configured rpc.outstanding-rpc-limit with value 64 > [2019-05-17 15:47:16.876961] I [socket.c:902:__socket_server_bind] > 0-socket.test > -changelog: closing (AF_UNIX) reuse check socket 14 > [2019-05-17 15:47:16.877172] I [trash.c:2450:init] 0-test-trash: no option > speci > fied for 'eliminate', using NULL > Final graph: > +---------------------------------------------------------------------------- > --+ > 1: volume test-posix > 2: type storage/posix > 3: option glusterd-uuid 7643ebf9-7661-4b9b-935b-93fa4c85ab6f > 4: option directory /v0/bricks/test > 5: option volume-id c4a22ffc-b328-4d5c-a63f-5adab1e9a93e > 6: option shared-brick-count 1 > 7: option brick-uid 36 > 8: option brick-gid 36 > 9: end-volume > 10: > 11: volume test-trash > 12: type features/trash > 13: option trash-dir .trashcan > 14: option brick-path /v0/bricks/test > 15: option trash-internal-op off > 16: subvolumes test-posix > 17: end-volume > 18: > 19: volume test-changelog > 20: type features/changelog > 21: option changelog-brick /v0/bricks/test > 22: option changelog-dir /v0/bricks/test/.glusterfs/changelogs > 23: option changelog-barrier-timeout 120 > 24: subvolumes test-trash > 25: end-volume > 26: > 27: volume test-bitrot-stub > 28: type features/bitrot-stub > 29: option export /v0/bricks/test > 30: option bitrot disable > 31: subvolumes test-changelog > 32: end-volume > 33: > 34: volume test-access-control > 35: type features/access-control > 36: subvolumes test-bitrot-stub > 37: end-volume > 38: > 39: volume test-locks > 40: type features/locks > 41: option enforce-mandatory-lock off > 42: subvolumes test-access-control > 43: end-volume > 44: > 45: volume test-worm > 46: type features/worm > 47: option worm off > 48: option worm-file-level off > 49: option worm-files-deletable on > 50: subvolumes test-locks > 51: end-volume > 52: > 53: volume test-read-only > 54: type features/read-only > 55: option read-only off > 56: subvolumes test-worm > 57: end-volume > 58: > 59: volume test-leases > 60: type features/leases > 61: option leases off > 62: subvolumes test-read-only > 63: end-volume > 64: > 65: volume test-upcall > 66: type features/upcall > 67: option cache-invalidation off > 68: subvolumes test-leases > 69: end-volume > 70: > 71: volume test-io-threads > 72: type performance/io-threads > 73: option low-prio-threads 32 > 74: subvolumes test-upcall > 75: end-volume > 76: > 77: volume test-selinux > 78: type features/selinux > 79: option selinux on > 80: subvolumes test-io-threads > 81: end-volume > 82: > 83: volume test-marker > 84: type features/marker > 85: option volume-uuid c4a22ffc-b328-4d5c-a63f-5adab1e9a93e > 86: option timestamp-file /var/lib/glusterd/vols/test/marker.tstamp > 87: option quota-version 0 > 88: option xtime off > 89: option gsync-force-xtime off > 90: option quota off > 91: option inode-quota off > 92: subvolumes test-selinux > 93: end-volume > 94: > 95: volume test-barrier > 96: type features/barrier > 97: option barrier disable > 98: option barrier-timeout 120 > 99: subvolumes test-marker > 100: end-volume > 101: > 102: volume test-index > 103: type features/index > 104: option index-base /v0/bricks/test/.glusterfs/indices > 105: option xattrop-dirty-watchlist trusted.afr.dirty > 106: option xattrop-pending-watchlist trusted.afr.test- > 107: subvolumes test-barrier > 108: end-volume > 109: > 110: volume test-quota > 111: type features/quota > 112: option volume-uuid test > 113: option server-quota off > 114: option deem-statfs off > 115: subvolumes test-index > 116: end-volume > 117: > 118: volume test-io-stats > 119: type debug/io-stats > 120: option unique-id /v0/bricks/test > 121: option log-level INFO > 122: option latency-measurement off > 123: option count-fop-hits off > 124: subvolumes test-quota > 125: end-volume > 126: > 127: volume /v0/bricks/test > 128: type performance/decompounder > 129: option auth.addr./v0/bricks/test.allow * > 130: option auth-path /v0/bricks/test > 131: option auth.login.24909ee0-24cc-4f78-af68-275187589fae.password > 2ce65fd > a-fb86-416d-9e29-861ac3a738c6 > 132: option auth.login./v0/bricks/test.allow > 24909ee0-24cc-4f78-af68-2751875 > 89fae > 133: subvolumes test-io-stats > 134: end-volume > 135: > 136: volume test-server > 137: type protocol/server > 138: option transport.socket.listen-port 49152 > 139: option rpc-auth.auth-glusterfs on > 140: option rpc-auth.auth-unix on > 141: option rpc-auth.auth-null on > 142: option rpc-auth-allow-insecure on > 143: option transport-type tcp > 144: option transport.address-family inet > 145: option auth.login./v0/bricks/test.allow > 24909ee0-24cc-4f78-af68-2751875 > 89fae > 146: option auth.login.24909ee0-24cc-4f78-af68-275187589fae.password > 2ce65fd > a-fb86-416d-9e29-861ac3a738c6 > 147: option auth-path /v0/bricks/test > 148: option auth.addr./v0/bricks/test.allow * > 149: option transport.socket.keepalive 1 > 150: option transport.socket.ssl-enabled off > 151: option event-threads 4 > 152: option transport.socket.keepalive-time 20 > 153: option transport.socket.keepalive-interval 2 > 154: option transport.socket.keepalive-count 9 > 155: option transport.listen-backlog 1024 > 156: subvolumes /v0/bricks/test > 157: end-volume > 158: > +---------------------------------------------------------------------------- > --+ > [2019-05-17 15:47:18.977033] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.12" > [2019-05-17 15:47:18.977055] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:47:18.977068] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:263830b2-de4d-4f5b-9049-e829 > 925db095-GRAPH_ID:6-PID:22730-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test- > clie > nt-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:47:18.979652] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.12" > [2019-05-17 15:47:18.979670] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:47:18.979693] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:360b06ff-d4a7-4d68-b6e9-bde7 > 096e3d82-GRAPH_ID:0-PID:6085-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test- > clien > t-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:47:18.980363] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] > 0-rpc-servi > ce: spawned a request handler thread for queue 0 > [2019-05-17 15:47:19.017248] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.11" > [2019-05-17 15:47:19.017275] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:47:19.017294] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:d424cc54-9a87-403e-b217-6313 > 62eeaff3-GRAPH_ID:0-PID:11061-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test- > cli > ent-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:47:20.602649] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.10" > [2019-05-17 15:47:20.602669] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:47:20.602679] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:a332606e-0f41-4f72-9060-a474 > 2add08b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME: > test-c > lient-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:47:20.611796] I [MSGID: 115036] > [server.c:499:server_rpc_notify] > 0-test-server: disconnecting connection from > CTX_ID:a332606e-0f41-4f72-9060-a474 > 2add08b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME: > test-c > lient-0-RECON_NO:-0 > [2019-05-17 15:47:20.611900] I [MSGID: 101055] > [client_t.c:436:gf_client_unref] > 0-test-server: Shutting down connection > CTX_ID:a332606e-0f41-4f72-9060-a4742add0 > 8b0-GRAPH_ID:0-PID:26592-HOST:necropolis.int.ohgnetworks.com-PC_NAME:test- > client > -0-RECON_NO:-0 > [2019-05-17 15:47:20.855104] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.10" > [2019-05-17 15:47:20.855134] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:47:20.855144] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:f654a9a1-0241-4415-a88f-b0a2 > b83b2301-GRAPH_ID:0-PID:26419-HOST:necropolis.int.ohgnetworks.com-PC_NAME: > test-c > lient-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:47:20.856227] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] > 0-rpc-servi > ce: spawned a request handler thread for queue 1 > [2019-05-17 15:48:03.062247] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.11" > [2019-05-17 15:48:03.062271] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:48:03.062282] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:471a7ddb-e566-4364-a171-8de6 > c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test- > cli > ent-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:48:04.264875] E [MSGID: 113069] > [posix-entry-ops.c:2123:posix_cre > ate] 0-test-posix: open on /v0/bricks/test/__DIRECT_IO_TEST__ failed > [Invalid ar > gument] > [2019-05-17 15:48:04.264931] I [MSGID: 115071] > [server-rpc-fops_v2.c:1546:server > 4_create_cbk] 0-test-server: 25: CREATE /__DIRECT_IO_TEST__ > (00000000-0000-0000- > 0000-000000000001/__DIRECT_IO_TEST__), client: > CTX_ID:471a7ddb-e566-4364-a171-8d > e6c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME: > test-c > lient-0-RECON_NO:-0, error-xlator: test-posix [Invalid argument] > [2019-05-17 15:48:05.120532] I [MSGID: 115036] > [server.c:499:server_rpc_notify] > 0-test-server: disconnecting connection from > CTX_ID:471a7ddb-e566-4364-a171-8de6 > c75b9dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test- > cli > ent-0-RECON_NO:-0 > [2019-05-17 15:48:05.120658] I [MSGID: 101055] > [client_t.c:436:gf_client_unref] > 0-test-server: Shutting down connection > CTX_ID:471a7ddb-e566-4364-a171-8de6c75b9 > dde-GRAPH_ID:0-PID:12024-HOST:boneyard.int.ohgnetworks.com-PC_NAME:test- > client-0 > -RECON_NO:-0 > [2019-05-17 15:50:15.508396] I [addr.c:54:compare_addr_and_update] > 0-/v0/bricks/ > test: allowed = "*", received addr = "10.50.3.12" > [2019-05-17 15:50:15.508429] I [login.c:110:gf_auth] 0-auth/login: allowed > user > names: 24909ee0-24cc-4f78-af68-275187589fae > [2019-05-17 15:50:15.508439] I [MSGID: 115029] > [server-handshake.c:550:server_se > tvolume] 0-test-server: accepted client from > CTX_ID:35a55e7e-7e14-4653-918e-0959 > 97a81ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test- > clien > t-0-RECON_NO:-0 (version: 6.1) with subvol /v0/bricks/test > [2019-05-17 15:50:15.526169] I [MSGID: 115036] > [server.c:499:server_rpc_notify] > 0-test-server: disconnecting connection from > CTX_ID:35a55e7e-7e14-4653-918e-0959 > 97a81ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test- > clien > t-0-RECON_NO:-0 > [2019-05-17 15:50:15.526271] I [MSGID: 101055] > [client_t.c:436:gf_client_unref] > 0-test-server: Shutting down connection > CTX_ID:35a55e7e-7e14-4653-918e-095997a81 > ed3-GRAPH_ID:0-PID:9455-HOST:ossuary.int.ohgnetworks.com-PC_NAME:test-client- > 0-R > ECON_NO:-0 > [2019-05-17 15:52:16.992388] I [rpcsvc.c:870:rpcsvc_handle_rpc_call] > 0-rpc-servi > ce: spawned a request handler thread for queue 2 In your case, open() itself failed with O_DIRECT. Seems like the backend fs on which your gluster bricks are hosted don't support O_DIRECT. [2019-05-17 15:48:04.264875] E [MSGID: 113069] [posix-entry-ops.c:2123:posix_create] 0-test-posix: open on /v0/bricks/test/__DIRECT_IO_TEST__ failed [Invalid argument] What FS are you using for bricks? Turning on remote-dio helps in your case because the job of that option is to knock off O_DIRECT flag before open(). See https://github.com/gluster/glusterfs/blob/836e5b6b76ee74a486b6d41c4a2d3de91e4ad2c1/xlators/protocol/client/src/client.c#L37 What this means is that your volume will no longer be honoring O_DIRECT flag. Going by Nir's thread, oVirt expects the io operations to be DIRECT IO. Sahina/Nir, Is the "DIRECT-IO" nature of the io operations a strict requirement for oVirt? Do we expect any consistency issues in case the flag is not honored under the hood? -Krutika Ah, that makes sense, I had ZFS as bricks for that one, and it (zfs on linux 0.7.x) won't support O_DIRECT until version 0.8, still in rc status. To confirm, I created a new volume for my production systems with XFS bricks, applied the virt group and then disabled network.remote-dio on the volume. Ovirt was able to create a storage domain with no problem. Looks like the two of us had different edge cases going, sorry for the trouble. And here comes the question ... Do we really support storage that can emulate 512 ? We have 3PARs that report 4096/16384 (minumum/optimum) and in such case - this type of storage will be unavailable. (In reply to Strahil Nikolov from comment #16) > And here comes the question ... > Do we really support storage that can emulate 512 ? We have 3PARs that > report 4096/16384 (minumum/optimum) and in such case - this type of storage > will be unavailable. We do not support storage that cannot emulate 512b at least until Bug 1592916 is fixed. Closing this bug. *** This bug has been marked as a duplicate of bug 1592916 *** |