Bug 1790736

Summary:

gluster volume list returning wrong volume list / volume list time out

Product:

[Community] GlusterFS

Reporter:

akshsy <akshayvijapur>

Component:

glusterd

Assignee:

Sanju <srakonde>

Status:

CLOSED UPSTREAM

QA Contact:

Severity:

urgent

Docs Contact:

Priority:

unspecified

Version:

CC:

bugs, moagrawa, pasik, sankarshan.mukhopadhyay, sheggodu, srakonde, vbellur

Target Milestone:

---

Keywords:

Triaged

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:

2020-03-17 03:33:52 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:

Attachments:

Description	Flags
logs	none
GLuster logs	none

Description akshsy 2020-01-14 03:59:02 UTC

Description of problem:

Issue No 1:

I observed that gluster volume list was returning wrong volume information.

Consider i have 5 volumes say
1. clusterfs
2. Vol1
3. vol2
4. vol3
5. vol4

If i do gluster volume list. It should return me back (Clusterfs, vol1, vol2, vol3, vol4).

But sometime i am seeing it is returning only four volumes (i.e clusterfs, vol1,vol2,vol3).

this issue is not consistently reproducible. So i wrote some scripts to capture this scenario. Basically my scripts will start three machines (VM's) and try to form a gluster cluster.

Issue no 2:

Some times i am seeing that volume list is timing out.

volume list Error : Request timed out

If i do gluster volume info i can see

Volume Name: clusterfs
Type: Replicate
Volume ID: 86d7d811-272d-4f28-a2c1-6b84ae2427d3
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x 2 = 2
Transport-type: tcp
Bricks:
Brick1: 10.223.96.188:/mnt/glusterfs/bricks/clusterfs
Brick2: 10.223.96.189:/mnt/glusterfs/bricks/clusterfs
Options Reconfigured:
performance.client-io-threads: off
transport.address-family: inet
storage.fips-mode-rchecksum: on

Version-Release number of selected component (if applicable): 7.1

How reproducible:

Often i can see this behavior which is causing huge problems in our cluster.

Steps to Reproduce:

I am attaching all the scripts which you can use to run and reproduce the scenario

Details of scripts:

I am using three ubuntu nodes which are running on KVM's. I am suing virsh to control the vm's

glusterunittest.sh : This is the main script which will drive other scripts. please run this script for the test run.
addbrick.sh : This will add brick to the volume.
createvolume.sh : this will create a volume on first machine.
glustercleanup.sh : this will clean up all the previous volumes and associated bricks.
peerprobe.sh : this will probe other members from first machine.

Keep all the scripts in /opt/unittest/ directory.

Actual results:

In the logs file "script_logs.logs:, line 1331, i saw it returned only four volumes.

Expected results:

we need five volumes to be returned.

Additional info:

Attached logs of all the five machines along my script logs.

Please download the script and logs from

https://drive.google.com/drive/folders/1JAg5ychq7sTCi3wk_-4FjqmGlo8pL8qx?usp=sharing

Thanks,
akshay

Comment 1 Sunil Kumar Acharya 2020-01-14 05:24:31 UTC

Moving the bug to upstream

Comment 2 sankarshan 2020-01-20 05:02:05 UTC

Since the severity is set to 'Urgent' is there a maintainer assigned to review the topic and confirm the reproducer?

Comment 3 Ravishankar N 2020-01-27 05:46:21 UTC

Adding glusted/cli maintainers to the BZ since that seems to be the right component.

Comment 4 Sanju 2020-01-28 07:29:13 UTC

I'm unable to reproduce this issue by the specified reproducer. Also, shared logs have the standard outputs only. Please share the glusterd.log and cmd-history.log to debug further.

Thanks,
Sanju

Comment 5 akshsy 2020-01-28 09:36:17 UTC

@sanju all the logs (cmd_history.logs, cli.logs ) are in the same location

https://drive.google.com/drive/folders/15ctoyAE1EAHkv_fV70CgZIIA96UtUi3N.

I have also attached the script which you can use to reproduce with 3-5 VM's on ubuntu.

Thanks
akshay

Comment 6 Sanju 2020-01-28 11:39:07 UTC

Hi Akshay,

I can access the logs now. But looks like, you have attached the logs of 4 days which are huge. It is very difficult to analyse such logs.

Please share the following when you hit this issue again:
1. gluster v info
2. gluster v status
3. ls /var/lib/glusterd/vols/
4. glusterd.log around that timestamp

Thanks,
Sanju

Comment 7 akshsy 2020-01-30 03:32:51 UTC

Hi Sanju,

The issues which i listed above cannot be reproduced with a specific test steps (that is why u guys are not able to reproduce this bug). I have created the scripts to test gluster stability itself and figured out It is happening intermittently which is breaking our system. 

All the scripts are attached with this thread. You can execute those steps directly on 3-5 Virtual machines(KVM) and you will hit the issue definitely.

Let me know for any further clarification and thanks a lot for your kind help to looking on to this issue.

Thanks,
Akshay

Comment 8 akshsy 2020-02-10 04:30:08 UTC

Hi,

Please let me know any workaround for these issues ?

Comment 9 Sanju 2020-02-10 05:13:18 UTC

Please share the following when you hit this issue:
1. gluster v info
2. gluster v list
3. gluster v status
4. ls /var/lib/glusterd/vols/
5. glusterd.log around that timestamp

Thanks,
Sanju

Comment 10 akshsy 2020-02-10 08:01:36 UTC

Created attachment 1662075 [details]
logs

Comment 11 Sanju 2020-02-10 08:43:48 UTC

this is what I see in the attachment:
 /var/lib/glusterd/vols/
clusterfs  testapp_test_vol


Please share the requested data.

Comment 12 akshsy 2020-02-10 09:16:56 UTC

Created attachment 1662091 [details]
GLuster logs

Gluster logs

Comment 13 akshsy 2020-02-10 09:23:39 UTC

Hi Sanju,

Here is the data:

1. gluster v info  :- Output is blank, (Gluster is not returning any output for any command ) 
2. gluster v list  :- Output is blank,  (Gluster is not returning any output for any command ) 
3. gluster v status:- Output is blank,   (Gluster is not returning any output for any command ) 
4. ls /var/lib/glusterd/vols/ :- clusterfs  testapp_test_vol
5. glusterd.log around that timestamp:

[2020-02-10 06:10:40.519397] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:10:45.262752] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:10:45.262810] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:10:45.262837] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:10:45.263077] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:10:46.238716] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:10:46.238782] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:10:46.238802] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:10:46.239083] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:10:47.180855] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:10:47.180929] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:10:47.180951] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:10:47.181245] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:10:47.668767] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:10:47.668808] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:10:47.668820] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:10:47.668971] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:10:48.039756] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:10:48.039808] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:10:48.039818] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:10:48.039924] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:10:48.097022] I [MSGID: 106163] [glusterd-handshake.c:1433:__glusterd_mgmt_hndsk_versions_ack] 0-management: using the op-version 70000 
[2020-02-10 06:10:53.683796] I [MSGID: 106490] [glusterd-handler.c:2434:__glusterd_handle_incoming_friend_req] 0-glusterd: Received probe from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8 
[2020-02-10 06:10:54.098334] I [MSGID: 106493] [glusterd-handler.c:3715:glusterd_xfer_friend_add_resp] 0-glusterd: Responded to 192.168.2.173 (0), ret: 0, op_ret: 0 
[2020-02-10 06:10:54.826758] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: nfs already stopped 
[2020-02-10 06:10:54.826829] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: nfs service is stopped 
[2020-02-10 06:10:54.826870] I [MSGID: 106599] [glusterd-nfs-svc.c:81:glusterd_nfssvc_manager] 0-management: nfs/server.so xlator is not installed 
[2020-02-10 06:10:54.827196] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: quotad already stopped 
[2020-02-10 06:10:54.827237] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: quotad service is stopped 
[2020-02-10 06:10:54.827478] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: bitd already stopped 
[2020-02-10 06:10:54.827518] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: bitd service is stopped 
[2020-02-10 06:10:54.827708] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: scrub already stopped 
[2020-02-10 06:10:54.827739] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: scrub service is stopped 
[2020-02-10 06:10:54.830228] I [MSGID: 106618] [glusterd-svc-helper.c:901:glusterd_attach_svc] 0-glusterd: adding svc glustershd (volume=clusterfs) to existing process with pid 51 
[2020-02-10 06:10:54.831746] I [MSGID: 106617] [glusterd-svc-helper.c:680:glusterd_svc_attach_cbk] 0-management: svc glustershd of volume clusterfs attached successfully to pid 51 
[2020-02-10 06:10:54.832627] I [MSGID: 106618] [glusterd-svc-helper.c:901:glusterd_attach_svc] 0-glusterd: adding svc glustershd (volume=testapp_test_vol) to existing process with pid 51 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 13 times between [2020-02-10 06:10:40.519397] and [2020-02-10 06:10:54.832858]
[2020-02-10 06:10:54.833877] I [MSGID: 106617] [glusterd-svc-helper.c:680:glusterd_svc_attach_cbk] 0-management: svc glustershd of volume testapp_test_vol attached successfully to pid 51 
[2020-02-10 06:10:54.884526] I [MSGID: 106492] [glusterd-handler.c:2619:__glusterd_handle_friend_update] 0-glusterd: Received friend update from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8 
[2020-02-10 06:10:55.019603] I [MSGID: 106502] [glusterd-handler.c:2660:__glusterd_handle_friend_update] 0-management: Received my uuid as Friend 
[2020-02-10 06:10:55.863563] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 2 times between [2020-02-10 06:10:55.863563] and [2020-02-10 06:10:57.915039]
[2020-02-10 06:10:58.260425] I [MSGID: 106493] [glusterd-rpc-ops.c:681:__glusterd_friend_update_cbk] 0-management: Received ACC from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8 
[2020-02-10 06:10:58.560035] I [MSGID: 106493] [glusterd-rpc-ops.c:468:__glusterd_friend_add_cbk] 0-glusterd: Received ACC from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8, host: 192.168.2.173, port: 0 
[2020-02-10 06:10:58.691486] I [MSGID: 106492] [glusterd-handler.c:2619:__glusterd_handle_friend_update] 0-glusterd: Received friend update from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8 
[2020-02-10 06:10:58.821689] I [MSGID: 106502] [glusterd-handler.c:2660:__glusterd_handle_friend_update] 0-management: Received my uuid as Friend 
[2020-02-10 06:10:58.936082] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:10:59.618535] I [MSGID: 106493] [glusterd-rpc-ops.c:681:__glusterd_friend_update_cbk] 0-management: Received ACC from uuid: 644519f2-d1e8-41fb-9b1b-9c299229f4e8 
[2020-02-10 06:10:59.963590] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 98 times between [2020-02-10 06:10:59.963590] and [2020-02-10 06:12:40.021437]
[2020-02-10 06:12:41.052867] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:12:58.219479] I [MSGID: 106004] [glusterd-handler.c:6204:__glusterd_peer_rpc_notify] 0-management: Peer <192.168.2.171> (<9778a5dc-2765-435b-a0e2-d8c72ac6a85e>), in state <Peer in Cluster>, has disconnected from glusterd. 
[2020-02-10 06:12:58.219766] W [glusterd-locks.c:796:glusterd_mgmt_v3_unlock] (-->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x235ca) [0x7fae7ac9f5ca] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x2e2d0) [0x7fae7acaa2d0] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0xe84d3) [0x7fae7ad644d3] ) 0-management: Lock for vol clusterfs not held 
[2020-02-10 06:12:58.219803] W [MSGID: 106117] [glusterd-handler.c:6225:__glusterd_peer_rpc_notify] 0-management: Lock not released for clusterfs 
[2020-02-10 06:12:58.219855] W [glusterd-locks.c:796:glusterd_mgmt_v3_unlock] (-->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x235ca) [0x7fae7ac9f5ca] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x2e2d0) [0x7fae7acaa2d0] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0xe84d3) [0x7fae7ad644d3] ) 0-management: Lock for vol testapp_test_vol not held 
[2020-02-10 06:12:58.219880] W [MSGID: 106117] [glusterd-handler.c:6225:__glusterd_peer_rpc_notify] 0-management: Lock not released for testapp_test_vol 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:12:41.052867] and [2020-02-10 06:14:39.705675]
[2020-02-10 06:14:40.738887] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:07.860752] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:07.860822] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:07.860844] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:07.861137] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:07.879866] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:07.879897] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:07.879909] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:07.880077] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:07.881651] I [MSGID: 106493] [glusterd-rpc-ops.c:468:__glusterd_friend_add_cbk] 0-glusterd: Received ACC from uuid: 9778a5dc-2765-435b-a0e2-d8c72ac6a85e, host: 192.168.2.171, port: 0 
[2020-02-10 06:15:08.717225] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: nfs already stopped 
[2020-02-10 06:15:08.717331] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: nfs service is stopped 
[2020-02-10 06:15:08.717375] I [MSGID: 106599] [glusterd-nfs-svc.c:81:glusterd_nfssvc_manager] 0-management: nfs/server.so xlator is not installed 
[2020-02-10 06:15:08.717656] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: quotad already stopped 
[2020-02-10 06:15:08.717769] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: quotad service is stopped 
[2020-02-10 06:15:08.718115] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: bitd already stopped 
[2020-02-10 06:15:08.718188] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: bitd service is stopped 
[2020-02-10 06:15:08.718386] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: scrub already stopped 
[2020-02-10 06:15:08.718428] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: scrub service is stopped 
[2020-02-10 06:15:08.721611] I [MSGID: 106618] [glusterd-svc-helper.c:901:glusterd_attach_svc] 0-glusterd: adding svc glustershd (volume=clusterfs) to existing process with pid 51 
[2020-02-10 06:15:08.725442] I [MSGID: 106618] [glusterd-svc-helper.c:901:glusterd_attach_svc] 0-glusterd: adding svc glustershd (volume=testapp_test_vol) to existing process with pid 51 
[2020-02-10 06:15:08.725974] I [MSGID: 106493] [glusterd-rpc-ops.c:681:__glusterd_friend_update_cbk] 0-management: Received ACC from uuid: 9778a5dc-2765-435b-a0e2-d8c72ac6a85e 
[2020-02-10 06:15:08.728250] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:08.728295] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:08.728314] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:08.728530] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:08.729622] I [MSGID: 106617] [glusterd-svc-helper.c:680:glusterd_svc_attach_cbk] 0-management: svc glustershd of volume clusterfs attached successfully to pid 51 
[2020-02-10 06:15:08.730058] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:08.730094] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:08.730113] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:08.730308] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:08.742981] I [MSGID: 106617] [glusterd-svc-helper.c:680:glusterd_svc_attach_cbk] 0-management: svc glustershd of volume testapp_test_vol attached successfully to pid 51 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 27 times between [2020-02-10 06:14:40.738887] and [2020-02-10 06:15:08.758408]
[2020-02-10 06:15:08.759438] I [MSGID: 106163] [glusterd-handshake.c:1433:__glusterd_mgmt_hndsk_versions_ack] 0-management: using the op-version 70000 
[2020-02-10 06:15:08.811801] I [MSGID: 106490] [glusterd-handler.c:2434:__glusterd_handle_incoming_friend_req] 0-glusterd: Received probe from uuid: 9778a5dc-2765-435b-a0e2-d8c72ac6a85e 
[2020-02-10 06:15:08.885168] I [MSGID: 106009] [glusterd-utils.c:3577:glusterd_compare_friend_volume] 0-management: Version of volume clusterfs differ. local version = 14, remote version = 15 on peer 192.168.2.171 
[2020-02-10 06:15:08.885265] I [MSGID: 106009] [glusterd-utils.c:3577:glusterd_compare_friend_volume] 0-management: Version of volume testapp_test_vol differ. local version = 13, remote version = 14 on peer 192.168.2.171 
[2020-02-10 06:15:08.918591] I [MSGID: 106493] [glusterd-handler.c:3715:glusterd_xfer_friend_add_resp] 0-glusterd: Responded to 192.168.2.171 (0), ret: 0, op_ret: 0 
[2020-02-10 06:15:10.307449] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: nfs service is stopped 
[2020-02-10 06:15:10.307467] I [MSGID: 106599] [glusterd-nfs-svc.c:81:glusterd_nfssvc_manager] 0-management: nfs/server.so xlator is not installed 
[2020-02-10 06:15:10.307832] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: quotad already stopped 
[2020-02-10 06:15:10.307875] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: quotad service is stopped 
[2020-02-10 06:15:10.308142] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: bitd already stopped 
[2020-02-10 06:15:10.308186] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: bitd service is stopped 
[2020-02-10 06:15:10.308379] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: scrub already stopped 
[2020-02-10 06:15:10.308413] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: scrub service is stopped 
[2020-02-10 06:15:10.309295] I [socket.c:864:__socket_shutdown] 0-management: intentional socket shutdown(25)
[2020-02-10 06:15:10.310108] E [MSGID: 106558] [glusterd-volgen.c:3201:volgen_graph_build_clients] 0-glusterd: volume inconsistency: brick count is 0 
[2020-02-10 06:15:10.310158] E [MSGID: 106068] [glusterd-shd-svc.c:191:glusterd_shdsvc_create_volfile] 0-management: Failed to create volfile 
[2020-02-10 06:15:11.093844] I [glusterd-utils.c:6465:glusterd_brick_start] 0-management: discovered already-running brick /mnt/glusterfs/bricks/clusterfs
[2020-02-10 06:15:11.093936] I [MSGID: 106142] [glusterd-pmap.c:290:pmap_registry_bind] 0-pmap: adding brick /mnt/glusterfs/bricks/clusterfs on port 49153 
[2020-02-10 06:15:11.094070] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-management: setting frame-timeout to 600
[2020-02-10 06:15:11.094190] I [socket.c:4342:ssl_setup_connection_params] 0-management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:11.094211] I [socket.c:4352:ssl_setup_connection_params] 0-management: using certificate depth 1
[2020-02-10 06:15:11.094460] I [socket.c:4397:ssl_setup_connection_params] 0-management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:11.177096] I [MSGID: 106618] [glusterd-svc-helper.c:901:glusterd_attach_svc] 0-glusterd: adding svc glustershd (volume=clusterfs) to existing process with pid 51 
[2020-02-10 06:15:11.177193] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:11.177234] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:11.177810] I [MSGID: 106492] [glusterd-handler.c:2619:__glusterd_handle_friend_update] 0-glusterd: Received friend update from uuid: 9778a5dc-2765-435b-a0e2-d8c72ac6a85e 
[2020-02-10 06:15:11.361415] I [MSGID: 106502] [glusterd-handler.c:2660:__glusterd_handle_friend_update] 0-management: Received my uuid as Friend 
[2020-02-10 06:15:11.445483] I [MSGID: 106493] [glusterd-rpc-ops.c:681:__glusterd_friend_update_cbk] 0-management: Received ACC from uuid: 9778a5dc-2765-435b-a0e2-d8c72ac6a85e 
[2020-02-10 06:15:11.445597] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:11.445610] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:11.445617] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:11.445773] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:11.446292] W [MSGID: 106056] [glusterd-snapshot-utils.c:376:glusterd_snap_volinfo_find_by_volume_id] 0-management: Snap volume not found 
The message "W [MSGID: 106056] [glusterd-snapshot-utils.c:376:glusterd_snap_volinfo_find_by_volume_id] 0-management: Snap volume not found" repeated 2 times between [2020-02-10 06:15:11.446292] and [2020-02-10 06:15:11.446365]
[2020-02-10 06:15:11.454382] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:12.177593] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:12.177691] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:12.487376] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:13.178078] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:13.178187] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:13.517693] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:14.178488] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:14.178599] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:14.547791] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:15.178907] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:15.179069] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:15.577644] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:16.179379] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:16.179488] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:16.608411] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:17.180074] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:17.180177] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:17.643567] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:18.180452] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:18.180546] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:18.674809] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:19.180819] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:19.180921] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:19.706461] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:20.181227] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:20.181334] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:20.740318] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:21.181571] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:21.181648] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:21.775642] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:22.181970] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:22.182129] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:22.811600] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:23.182436] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:23.182542] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:23.842280] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:24.182682] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:24.182737] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:24.874510] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:25.183062] E [MSGID: 106048] [glusterd-handshake.c:323:build_volfile_path] 0-management: Couldn't find volinfo for volid=clusterfs 
[2020-02-10 06:15:25.183170] E [MSGID: 106617] [glusterd-svc-helper.c:775:__glusterd_send_svc_configure_req] 0-management: Unable to stat  (No such file or directory) 
[2020-02-10 06:15:25.908499] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:25.974988] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:25.975091] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:25.975112] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:25.975379] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:26.110574] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:26.110630] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:26.110651] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:26.110866] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:26.183474] W [MSGID: 106617] [glusterd-svc-helper.c:932:glusterd_attach_svc] 0-glusterd: attach failed for glustershd(volume=clusterfs) 
[2020-02-10 06:15:26.183736] E [MSGID: 106048] [glusterd-shd-svc.c:483:glusterd_shdsvc_start] 0-glusterd: Failed to attach shd svc(volume=clusterfs) to pid=51 
[2020-02-10 06:15:26.203109] I [socket.c:864:__socket_shutdown] 0-management: intentional socket shutdown(33)
[2020-02-10 06:15:26.203868] E [MSGID: 106558] [glusterd-volgen.c:3201:volgen_graph_build_clients] 0-glusterd: volume inconsistency: brick count is 0 
[2020-02-10 06:15:26.203918] E [MSGID: 106068] [glusterd-shd-svc.c:191:glusterd_shdsvc_create_volfile] 0-management: Failed to create volfile 
[2020-02-10 06:15:26.644384] I [glusterd-utils.c:6465:glusterd_brick_start] 0-management: discovered already-running brick /mnt/glusterfs/bricks/testapp_test_vol
[2020-02-10 06:15:26.644441] I [MSGID: 106142] [glusterd-pmap.c:290:pmap_registry_bind] 0-pmap: adding brick /mnt/glusterfs/bricks/testapp_test_vol on port 49154 
[2020-02-10 06:15:26.644560] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-management: setting frame-timeout to 600
[2020-02-10 06:15:26.644676] I [socket.c:4342:ssl_setup_connection_params] 0-management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:26.644696] I [socket.c:4352:ssl_setup_connection_params] 0-management: using certificate depth 1
[2020-02-10 06:15:26.644925] I [socket.c:4397:ssl_setup_connection_params] 0-management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:26.685957] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-glustershd: setting frame-timeout to 600
[2020-02-10 06:15:26.686159] I [socket.c:4342:ssl_setup_connection_params] 0-glustershd: SSL support for glusterd is ENABLED
[2020-02-10 06:15:26.686187] I [socket.c:4352:ssl_setup_connection_params] 0-glustershd: using certificate depth 1
[2020-02-10 06:15:26.686398] I [socket.c:4397:ssl_setup_connection_params] 0-glustershd: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:26.687416] I [MSGID: 106567] [glusterd-svc-mgmt.c:230:glusterd_svc_start] 0-management: Starting glustershd service 
The message "I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: nfs already stopped" repeated 2 times between [2020-02-10 06:15:08.717225] and [2020-02-10 06:15:27.719753]
[2020-02-10 06:15:27.719774] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: nfs service is stopped 
[2020-02-10 06:15:27.719844] I [MSGID: 106599] [glusterd-nfs-svc.c:81:glusterd_nfssvc_manager] 0-management: nfs/server.so xlator is not installed 
[2020-02-10 06:15:27.719973] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: quotad already stopped 
[2020-02-10 06:15:27.720043] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: quotad service is stopped 
[2020-02-10 06:15:27.720167] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: bitd already stopped 
[2020-02-10 06:15:27.720192] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: bitd service is stopped 
[2020-02-10 06:15:27.720323] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: scrub already stopped 
[2020-02-10 06:15:27.720365] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: scrub service is stopped 
[2020-02-10 06:15:27.720701] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume clusterfs.192.168.2.175.mnt-glusterfs-bricks-clusterfs 
[2020-02-10 06:15:27.721233] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume shd/clusterfs 
[2020-02-10 06:15:27.721431] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume /clusterfs 
[2020-02-10 06:15:27.721832] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume testapp_test_vol.192.168.2.175.mnt-glusterfs-bricks-testapp_test_vol 
[2020-02-10 06:15:27.722361] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume testapp_test_vol 
[2020-02-10 06:15:27.725787] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.725818] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.725833] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.726105] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.728147] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume clusterfs.192.168.2.175.mnt-glusterfs-bricks-clusterfs 
[2020-02-10 06:15:27.728758] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume shd/testapp_test_vol 
[2020-02-10 06:15:27.729043] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume /clusterfs 
[2020-02-10 06:15:27.729611] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume testapp_test_vol.192.168.2.175.mnt-glusterfs-bricks-testapp_test_vol 
[2020-02-10 06:15:27.730261] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume testapp_test_vol 
[2020-02-10 06:15:27.732477] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.732528] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.732552] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.732822] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.752982] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume shd/clusterfs 
[2020-02-10 06:15:27.753303] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.753329] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.753345] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.753502] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.775571] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume shd/testapp_test_vol 
[2020-02-10 06:15:27.775893] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.775918] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.775935] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.776123] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.777036] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:27.799673] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.799708] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.799725] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.799904] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.812183] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.812210] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.812220] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.812326] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.823641] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.823669] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.823680] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.823792] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.835242] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.835269] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.835280] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.835388] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:27.835869] I [MSGID: 106496] [glusterd-handshake.c:935:__server_getspec] 0-management: Received mount request for volume shd/testapp_test_vol 
[2020-02-10 06:15:27.857810] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:27.857836] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:27.857863] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:27.857976] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:28.810507] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:15:29.328235] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:29.328298] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:29.328317] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:29.328566] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:29.329667] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:29.329707] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:29.329726] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:29.330058] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:29.561093] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:29.561147] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:29.561167] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:29.561371] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:30.892835] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:30.892866] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:30.892876] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:30.893048] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:30.952763] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:30.952816] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:30.952842] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:30.953083] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:31.385523] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:31.385574] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:31.385593] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:31.385809] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:31.404124] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:31.404152] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:31.404162] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:31.404274] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:15:35.530637] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:15:35.530676] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:15:35.530688] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:15:35.530849] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 70 times between [2020-02-10 06:15:28.810507] and [2020-02-10 06:16:39.995121]
[2020-02-10 06:16:41.029508] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:16:41.029508] and [2020-02-10 06:18:39.699358]
[2020-02-10 06:18:40.729542] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 116 times between [2020-02-10 06:18:40.729542] and [2020-02-10 06:20:40.412990]
[2020-02-10 06:20:41.448536] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:20:41.448536] and [2020-02-10 06:22:40.132383]
[2020-02-10 06:22:41.164074] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:22:41.164074] and [2020-02-10 06:24:39.831492]
[2020-02-10 06:24:40.861512] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:24:40.861512] and [2020-02-10 06:26:39.544603]
[2020-02-10 06:26:40.574163] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 116 times between [2020-02-10 06:26:40.574163] and [2020-02-10 06:28:40.280502]
[2020-02-10 06:28:41.312045] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:28:41.312045] and [2020-02-10 06:30:39.938793]
[2020-02-10 06:30:40.968560] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:31:28.790435] W [socket.c:774:__socket_rwv] 0-management: readv on 192.168.2.174:24007 failed (No data available)
[2020-02-10 06:31:28.790584] I [MSGID: 106004] [glusterd-handler.c:6204:__glusterd_peer_rpc_notify] 0-management: Peer <192.168.2.174> (<f4170777-7458-46b2-b9b9-55bd924f9ef8>), in state <Peer in Cluster>, has disconnected from glusterd. 
[2020-02-10 06:31:28.791152] W [glusterd-locks.c:796:glusterd_mgmt_v3_unlock] (-->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x235ca) [0x7fae7ac9f5ca] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x2e2d0) [0x7fae7acaa2d0] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0xe84d3) [0x7fae7ad644d3] ) 0-management: Lock for vol clusterfs not held 
[2020-02-10 06:31:28.791206] W [MSGID: 106117] [glusterd-handler.c:6225:__glusterd_peer_rpc_notify] 0-management: Lock not released for clusterfs 
[2020-02-10 06:31:28.791285] W [glusterd-locks.c:796:glusterd_mgmt_v3_unlock] (-->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x235ca) [0x7fae7ac9f5ca] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0x2e2d0) [0x7fae7acaa2d0] -->/usr/lib64/glusterfs/7.1/xlator/mgmt/glusterd.so(+0xe84d3) [0x7fae7ad644d3] ) 0-management: Lock for vol testapp_test_vol not held 
[2020-02-10 06:31:28.791316] W [MSGID: 106117] [glusterd-handler.c:6225:__glusterd_peer_rpc_notify] 0-management: Lock not released for testapp_test_vol 
[2020-02-10 06:31:28.791423] C [MSGID: 106003] [glusterd-server-quorum.c:348:glusterd_do_volume_quorum_action] 0-management: Server quorum regained for volume clusterfs. Starting local bricks. 
[2020-02-10 06:31:29.470810] C [MSGID: 106003] [glusterd-server-quorum.c:348:glusterd_do_volume_quorum_action] 0-management: Server quorum regained for volume testapp_test_vol. Starting local bricks. 
[2020-02-10 06:31:56.090248] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:31:56.090321] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:31:56.090342] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:31:56.090667] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
The message "I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req" repeated 115 times between [2020-02-10 06:30:40.968560] and [2020-02-10 06:32:40.021434]
[2020-02-10 06:32:41.051418] I [MSGID: 106487] [glusterd-handler.c:1339:__glusterd_handle_cli_list_friends] 0-glusterd: Received cli list req 
[2020-02-10 06:32:49.422711] I [socket.c:4339:ssl_setup_connection_params] 0-socket.management: SSL support on the I/O path is ENABLED
[2020-02-10 06:32:49.422756] I [socket.c:4342:ssl_setup_connection_params] 0-socket.management: SSL support for glusterd is ENABLED
[2020-02-10 06:32:49.422766] I [socket.c:4352:ssl_setup_connection_params] 0-socket.management: using certificate depth 1
[2020-02-10 06:32:49.422897] I [socket.c:4397:ssl_setup_connection_params] 0-socket.management: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:32:49.617181] I [MSGID: 106163] [glusterd-handshake.c:1433:__glusterd_mgmt_hndsk_versions_ack] 0-management: using the op-version 70000 
[2020-02-10 06:32:55.124261] I [MSGID: 106490] [glusterd-handler.c:2434:__glusterd_handle_incoming_friend_req] 0-glusterd: Received probe from uuid: f4170777-7458-46b2-b9b9-55bd924f9ef8 
[2020-02-10 06:32:55.295989] I [MSGID: 106493] [glusterd-handler.c:3715:glusterd_xfer_friend_add_resp] 0-glusterd: Responded to 192.168.2.174 (0), ret: 0, op_ret: 0 
[2020-02-10 06:32:57.153119] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: nfs already stopped 
[2020-02-10 06:32:57.153267] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: nfs service is stopped 
[2020-02-10 06:32:57.153311] I [MSGID: 106599] [glusterd-nfs-svc.c:81:glusterd_nfssvc_manager] 0-management: nfs/server.so xlator is not installed 
[2020-02-10 06:32:57.153607] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: quotad already stopped 
[2020-02-10 06:32:57.153646] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: quotad service is stopped 
[2020-02-10 06:32:57.153879] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: bitd already stopped 
[2020-02-10 06:32:57.153914] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: bitd service is stopped 
[2020-02-10 06:32:57.154164] I [MSGID: 106131] [glusterd-proc-mgmt.c:86:glusterd_proc_stop] 0-management: scrub already stopped 
[2020-02-10 06:32:57.154204] I [MSGID: 106568] [glusterd-svc-mgmt.c:265:glusterd_svc_stop] 0-management: scrub service is stopped 
[2020-02-10 06:32:57.154331] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-snapd: setting frame-timeout to 600
[2020-02-10 06:32:57.154563] I [socket.c:4342:ssl_setup_connection_params] 0-snapd: SSL support for glusterd is ENABLED
[2020-02-10 06:32:57.154587] I [socket.c:4352:ssl_setup_connection_params] 0-snapd: using certificate depth 1
[2020-02-10 06:32:57.154828] I [socket.c:4397:ssl_setup_connection_params] 0-snapd: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:32:57.156076] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-snapd: setting frame-timeout to 600
[2020-02-10 06:32:57.156193] I [socket.c:4342:ssl_setup_connection_params] 0-snapd: SSL support for glusterd is ENABLED
[2020-02-10 06:32:57.156224] I [socket.c:4352:ssl_setup_connection_params] 0-snapd: using certificate depth 1
[2020-02-10 06:32:57.156415] I [socket.c:4397:ssl_setup_connection_params] 0-snapd: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:32:57.157466] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-gfproxyd: setting frame-timeout to 600
[2020-02-10 06:32:57.157575] I [socket.c:4342:ssl_setup_connection_params] 0-gfproxyd: SSL support for glusterd is ENABLED
[2020-02-10 06:32:57.157596] I [socket.c:4352:ssl_setup_connection_params] 0-gfproxyd: using certificate depth 1
[2020-02-10 06:32:57.157787] I [socket.c:4397:ssl_setup_connection_params] 0-gfproxyd: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:32:57.158891] I [rpc-clnt.c:1014:rpc_clnt_connection_init] 0-gfproxyd: setting frame-timeout to 600
[2020-02-10 06:32:57.159063] I [socket.c:4342:ssl_setup_connection_params] 0-gfproxyd: SSL support for glusterd is ENABLED
[2020-02-10 06:32:57.159090] I [socket.c:4352:ssl_setup_connection_params] 0-gfproxyd: using certificate depth 1
[2020-02-10 06:32:57.159299] I [socket.c:4397:ssl_setup_connection_params] 0-gfproxyd: failed to open /etc/ssl/dhparam.pem, DH ciphers are disabled
[2020-02-10 06:32:57.162809] I [MSGID: 106568] [glusterd-proc-mgmt.c:92:glusterd_proc_stop] 0-management: Stopping glustershd daemon running in pid: 51

Comment 14 akshsy 2020-02-10 09:24:56 UTC

Hi Sanju,

I have attached a folder called   "GLuster logs". It has all the files (/var/logs/glusterfs). Please have a look over it.

Thanks
akshay

Comment 15 Sanju 2020-03-02 11:46:35 UTC

From the logs, There is a friend-handshaking going on when the gluster commands were issued. Glusterd is a single epoll thread, so it can only process one request at a time. It might happen that the request is in queue and before glusterd could process it, cli can timed out after 120 seconds.

I believe this is not a bug.

Thanks,
Sanju

Comment 16 Worker Ant 2020-03-17 03:33:52 UTC

This bug is moved to https://github.com/gluster/glusterfs/issues/1116, and will be tracked there from now on. Visit GitHub issues URL for further details