Bug 1652876

Summary:	creating a volume with existing name fails with wrong error "Error: Failed to allocate new volume: No space"
Product:	[Red Hat Storage] Red Hat Gluster Storage	Reporter:	Nag Pavan Chilakam <nchilaka>
Component:	heketi	Assignee:	John Mulligan <jmulligan>
Status:	CLOSED DUPLICATE	QA Contact:	Prasanth <pprakash>
Severity:	medium	Docs Contact:
Priority:	unspecified
Version:	rhgs-3.4	CC:	hchiramm, jmulligan, kramdoss, madam, nchilaka, rhs-bugs, rtalur, sankarshan, storage-qa-internal
Target Milestone:	---	Keywords:	ZStream
Target Release:	---
Hardware:	Unspecified
OS:	Unspecified
Whiteboard:
Fixed In Version:		Doc Type:	If docs needed, set a value
Doc Text:		Story Points:	---
Clone Of:		Environment:
Last Closed:	2019-02-06 09:42:47 UTC	Type:	Bug
Regression:	---	Mount Type:	---
Documentation:	---	CRM:
Verified Versions:		Category:	---
oVirt Team:	---	RHEL 7.3 requirements from Atomic Host:
Cloudforms Team:	---	Target Upstream Version:
Embargoed:

Description Nag Pavan Chilakam 2018-11-23 11:27:05 UTC

Description of problem:
-------------------------
when you try to create a volume with the same name as existing volume it fails with wrong error message "Error: Failed to allocate new volume: No space"

We need to change the error message as it  is misleading
 
Volume Name: pavan
Type: Replicate
Volume ID: e737c0f8-0cd0-4cbe-ab73-5fad22525df3
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x 3 = 3
Transport-type: tcp
Bricks:
Brick1: 10.70.35.127:/var/lib/heketi/mounts/vg_dec248812ec759881e9875df51d045ba/brick_e55f23fc8c1dedcbd35c0327ef6ee4a7/brick
Brick2: 10.70.35.184:/var/lib/heketi/mounts/vg_e14eb56a460c9639fea86fc125afb70f/brick_1a90d34236086f0816e0248c9ba1b01c/brick
Brick3: 10.70.35.83:/var/lib/heketi/mounts/vg_bd0abf9f16b98d1bff7c6fe8e2db1dcf/brick_acc31116704d7494471769b7c2f7b835/brick
Options Reconfigured:
transport.address-family: inet
nfs.disable: on
performance.client-io-threads: off
cluster.brick-multiplex: enable



[root@dhcp35-72 ~]# heketi-cli volume create --name pavan --size 2
Error: Failed to allocate new volume: No space
[root@dhcp35-72 ~]# heketi-cli volume create --name pavan --size 3
Error: Failed to allocate new volume: No space



Version-Release number of selected component (if applicable):
==================
Error: Failed to allocate new volume: No space
[root@dhcp35-72 ~]# heketi --version
Heketi 7.0.0
[root@dhcp35-72 ~]# rpm -qa|grep heketi
heketi-7.0.0-15.el7rhgs.x86_64
heketi-client-7.0.0-15.el7rhgs.x86_64
glusterfs-server-3.12.2-29.el7rhgs.x86_64

How reproducible:
================
always

Steps to Reproduce:
1.create a 4 node cluster
2.create a volume say with name as "pavan" using heketi
3.after volume is created , now try to create a new volume with same name "pavan"

Actual results:
=============
fails with misleading error message

Expected results:
===================
fail with better message like "namespace already exists" or something similar

Comment 2 John Mulligan 2018-11-27 22:06:45 UTC

Could you please provide the version of heketi being used as well as any logging associated with the error.
Recent versions have tried to improve the error handling and I would like to determine if this is an area already covered or an previously unknown oversight.
Thanks!

Comment 3 Nag Pavan Chilakam 2018-11-30 11:45:48 UTC

I had tried on heketi v7
Retried now on heketi v8 (and problem still exists)

Below are the details

[root@dhcp35-72 heketi]# heketi-cli volume create --name basevol --size 5
Name: basevol
Size: 5
Volume Id: 462fdf4357dc8678322208f65afbc280
Cluster Id: 6c77b0471fd950d36e1f0b35fe46f96a
Mount: 10.70.35.38:basevol
Mount Options: backup-volfile-servers=10.70.35.140,10.70.35.218,10.70.35.127,10.70.35.83,10.70.35.184
Block: false
Free Size: 0
Reserved Size: 0
Block Hosting Restriction: (none)
Block Volumes: []
Durability Type: replicate
Distributed+Replica: 3
[root@dhcp35-72 heketi]# heketi-cli volume create --name basevol --size 5
Error: Failed to allocate new volume: No space
[root@dhcp35-72 heketi]# 


Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [negroni] Started POST /volumes
Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] DEBUG 2018/11/30 17:13:28 /src/github.com/heketi/heketi/apps/glusterfs/volume_entry.go:102: [990215ca9e6ffc064fe92b23093ca642] Replica 3
Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] ERROR 2018/11/30 17:13:28 /src/github.com/heketi/heketi/apps/glusterfs/volume_entry.go:970: Name basevol already in use in cluster 6c77b0471fd950d36e1f0b35fe46f96a
Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] ERROR 2018/11/30 17:13:28 /src/github.com/heketi/heketi/apps/glusterfs/volume_entry.go:590: No clusters eligible to satisfy create volume request
Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] ERROR 2018/11/30 17:13:28 /src/github.com/heketi/heketi/apps/glusterfs/operations_manage.go:89: Create Volume Build Failed: No space
Nov 30 17:13:28 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [negroni] Completed 500 Internal Server Error in 1.738942ms
Nov 30 17:14:20 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:20 Starting Node Health Status refresh
Nov 30 17:14:20 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:20 Check Glusterd service status in node 10.70.35.38
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:21 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.38:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:51 IST; 46min ago
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 13299 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 13300 (glusterd)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 16
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─13300 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─14847 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/08b1786daa579553.socket --xlator-option *replicate*.node-uuid=495f5b69-3bb3-4730-8074-5dd682e2d356
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-38.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:51 dhcp35-38.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:21 Periodic health check status: node 22b39ea7598fad8a94ca313103b9da36 up=true
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:21 Check Glusterd service status in node 10.70.35.140
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:21 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.140:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:52 IST; 46min ago
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 18684 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 18685 (glusterd)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 16
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─18685 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─20239 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/e5cbc20bd5a07f70.socket --xlator-option *replicate*.node-uuid=38bf33b3-f397-4964-9be0-705f12222adc
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-140.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:52 dhcp35-140.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:21 Periodic health check status: node 3752a67883e31a60bfb09c80383d7dd7 up=true
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:21 Check Glusterd service status in node 10.70.35.218
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:21 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.218:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:51 IST; 46min ago
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 12745 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 12746 (glusterd)
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 36
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─12746 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─14395 /usr/sbin/glusterfsd -s 10.70.35.218 --volfile-id basevol.10.70.35.218.var-lib-heketi-mounts-vg_88dde558fbd2ac519f68b94d734af7a4-brick_f753bfec40ae9dcecdf96bc536799ae9-brick -p /var/run/gluster/vols/basevol/10.70.35.218-var-lib-heketi-mounts-vg_88dde558fbd2ac519f68b94d734af7a4-brick_f753bfec40ae9dcecdf96bc536799ae9-brick.pid -S /var/run/gluster/b50524783e55c160.socket --brick-name /var/lib/heketi/mounts/vg_88dde558fbd2ac519f68b94d734af7a4/brick_f753bfec40ae9dcecdf96bc536799ae9/brick -l /var/log/glusterfs/bricks/var-lib-heketi-mounts-vg_88dde558fbd2ac519f68b94d734af7a4-brick_f753bfec40ae9dcecdf96bc536799ae9-brick.log --xlator-option *-posix.glusterd-uuid=da0d4363-ba68-4d88-be13-e2feae16acee --brick-port 49152 --xlator-option basevol-server.listen-port=49152
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─14416 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/6de719c14a251aaf.socket --xlator-option *replicate*.node-uuid=da0d4363-ba68-4d88-be13-e2feae16acee
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-218.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:51 dhcp35-218.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:21 Periodic health check status: node 8d3639ab057773418a1d09a6d0382cc7 up=true
Nov 30 17:14:21 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:21 Check Glusterd service status in node 10.70.35.127
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:22 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.127:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:51 IST; 46min ago
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 20908 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 20909 (glusterd)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 36
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─20909 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─22523 /usr/sbin/glusterfsd -s 10.70.35.127 --volfile-id basevol.10.70.35.127.var-lib-heketi-mounts-vg_86ea2b008f10c31410fd635e90220ce1-brick_5985c28413c4d5453d4b205d7a813c80-brick -p /var/run/gluster/vols/basevol/10.70.35.127-var-lib-heketi-mounts-vg_86ea2b008f10c31410fd635e90220ce1-brick_5985c28413c4d5453d4b205d7a813c80-brick.pid -S /var/run/gluster/417d51878bcd8f9e.socket --brick-name /var/lib/heketi/mounts/vg_86ea2b008f10c31410fd635e90220ce1/brick_5985c28413c4d5453d4b205d7a813c80/brick -l /var/log/glusterfs/bricks/var-lib-heketi-mounts-vg_86ea2b008f10c31410fd635e90220ce1-brick_5985c28413c4d5453d4b205d7a813c80-brick.log --xlator-option *-posix.glusterd-uuid=347f9ac9-68ac-4798-8759-2d6208eb5360 --brick-port 49152 --xlator-option basevol-server.listen-port=49152
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─22544 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/11ed0e703a549320.socket --xlator-option *replicate*.node-uuid=347f9ac9-68ac-4798-8759-2d6208eb5360
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-127.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:51 dhcp35-127.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:22 Periodic health check status: node ce3a0387cf239004b3869c78d4686d08 up=true
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:22 Check Glusterd service status in node 10.70.35.83
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:22 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.83:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:52 IST; 46min ago
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 14887 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 14888 (glusterd)
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 36
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─14888 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─16504 /usr/sbin/glusterfsd -s 10.70.35.83 --volfile-id basevol.10.70.35.83.var-lib-heketi-mounts-vg_4614f6b98debc09716e1fce4d4a08df7-brick_6a39f30b81b0719d3c6d4ae53c0fbe6a-brick -p /var/run/gluster/vols/basevol/10.70.35.83-var-lib-heketi-mounts-vg_4614f6b98debc09716e1fce4d4a08df7-brick_6a39f30b81b0719d3c6d4ae53c0fbe6a-brick.pid -S /var/run/gluster/5974db49d90b7c81.socket --brick-name /var/lib/heketi/mounts/vg_4614f6b98debc09716e1fce4d4a08df7/brick_6a39f30b81b0719d3c6d4ae53c0fbe6a/brick -l /var/log/glusterfs/bricks/var-lib-heketi-mounts-vg_4614f6b98debc09716e1fce4d4a08df7-brick_6a39f30b81b0719d3c6d4ae53c0fbe6a-brick.log --xlator-option *-posix.glusterd-uuid=fc265524-ce7b-4127-b6e2-dd870e857a6b --brick-port 49152 --xlator-option basevol-server.listen-port=49152
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─16525 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/ddcb0a66496fa8b0.socket --xlator-option *replicate*.node-uuid=fc265524-ce7b-4127-b6e2-dd870e857a6b
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-83.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:52 dhcp35-83.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:22 Periodic health check status: node eff771e48ba1c236cfb03a407ff949fa up=true
Nov 30 17:14:22 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] INFO 2018/11/30 17:14:22 Check Glusterd service status in node 10.70.35.184
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [cmdexec] DEBUG 2018/11/30 17:14:23 /src/github.com/heketi/heketi/pkg/utils/ssh/ssh.go:173: Host: 10.70.35.184:22 Command: /bin/bash -c 'systemctl status glusterd'
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Result: ● glusterd.service - GlusterFS, a clustered file-system server
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Loaded: loaded (/usr/lib/systemd/system/glusterd.service; enabled; vendor preset: disabled)
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Active: active (running) since Fri 2018-11-30 16:27:51 IST; 46min ago
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Process: 11972 ExecStart=/usr/sbin/glusterd -p /var/run/glusterd.pid --log-level $LOG_LEVEL $GLUSTERD_OPTIONS (code=exited, status=0/SUCCESS)
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Main PID: 11973 (glusterd)
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Tasks: 16
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: CGroup: /system.slice/glusterd.service
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: ├─11973 /usr/sbin/glusterd -p /var/run/glusterd.pid --log-level INFO
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: └─13385 /usr/sbin/glusterfs -s localhost --volfile-id gluster/glustershd -p /var/run/gluster/glustershd/glustershd.pid -l /var/log/glusterfs/glustershd.log -S /var/run/gluster/eaf3b8c9c4d885d2.socket --xlator-option *replicate*.node-uuid=da204c1e-ee06-4bbc-b272-08e0dffec394
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:48 dhcp35-184.lab.eng.blr.redhat.com systemd[1]: Starting GlusterFS, a clustered file-system server...
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: Nov 30 16:27:51 dhcp35-184.lab.eng.blr.redhat.com systemd[1]: Started GlusterFS, a clustered file-system server.
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:23 Periodic health check status: node f5e8bd3127f0fc94f1525112d60e5b4b up=true
Nov 30 17:14:23 dhcp35-72.lab.eng.blr.redhat.com heketi[2671]: [heketi] INFO 2018/11/30 17:14:23 Cleaned 0 nodes from health cache

[root@dhcp35-72 heketi]# rpm -qa|grep heke
heketi-client-8.0.0-1.el7rhgs.x86_64
heketi-8.0.0-1.el7rhgs.x86_64

Comment 4 John Mulligan 2018-11-30 16:43:15 UTC

OK, thank you for confirming. The log snippet was helpful.
I see that the checks for the name are occurring at a different level in the code than the one previously improved.

Comment 5 Raghavendra Talur 2019-01-24 19:23:11 UTC

Patch posted upstream at https://github.com/heketi/heketi/pull/1450