Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

I have not tested with option attribute-timeout=0 -o entry-timeout=0,
But I think to set that two options to 0 will have impact on performance.
Also set consistent-metadata on will also have impact for performance, so I’d 
rather keep consistent-metadata to be off and use ctime feature to solve the 
tar issue.

cynthia

From: Ravishankar N 
Sent: 2020年3月17日 17:08
To: Zhou, Cynthia (NSB - CN/Hangzhou) ; Kotresh 
Hiremath Ravishankar 
Cc: Gluster Devel 
Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime



On 17/03/20 12:56 pm, Zhou, Cynthia (NSB - CN/Hangzhou) wrote:
Hi,
I know that this may not be your presumption of this ctime feature, however, 
our delima is that

  1.  product need to support date change scenario.
  2.  if we disable ctime feature, we will meet tar issue.
  3.  if we set consistent-metadata to on to work around this tar issue, there 
is another even worse problem: 
https://bugzilla.redhat.com/show_bug.cgi?id=1773476, app just cranshed!
So I have to make this patch.

For what it is worth, the 'file changed as we read it' warning from tar can be 
suppressed with the --warning=no-file-changed flag.

For 3, do you see any visible usability/performance issues with the work-around 
mentioned in the bug (comment 5 and 6)? Just curious.
Regards,
Ravi

Maybe I will keep this as internal use just for our local use scenarios.
Cynthia.

From: Kotresh Hiremath Ravishankar 
<mailto:khire...@redhat.com>
Sent: 2020年3月17日 15:17
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
<mailto:cynthia.z...@nokia-sbell.com>
Cc: Amar Tumballi <mailto:a...@kadalu.io>; Gluster Devel 
<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime

The whole ctime features relies on time provided by clients which are time 
synchronized. This patch brings in the time from server to compare against the 
time sent from client.
As Amar mentioned, this doesn't fit well into the scheme of how ctime is 
designed. Definitely keeping it optional and disabling it by default is one 
way. But is that what your intention
here?

On Tue, Mar 17, 2020 at 10:56 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, thanks for your feedback!
I will do local test to verify this patch first.

cynthia

From: Amar Tumballi mailto:a...@kadalu.io>>
Sent: 2020年3月17日 13:18
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>; Gluster Devel 
mailto:gluster-devel@gluster.org>>
Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime


On Tue, Mar 17, 2020 at 10:18 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs expert,
Our product need to tolerate change date to future and then change back.
How about change like this ?
https://review.gluster.org/#/c/glusterfs/+/24229/1/xlators/storage/posix/src/posix-metadata.c

when time change to future and change back , should still be able to update 
mdata, so the following changes to file can be populated to other clients.


We do like to have people integrating with GlusterFS. But this change is not 
inline with the 'assumptions' we had about the feature.

If you have verified this change works for you, please add it as an 'option' in 
posix, which can be changed through volume set, and keep this option 
disable/off by default. That should be an easier way to get the patch reviewed 
and take it further. Please make sure to provide the 'description' for the 
option with details.

Regards,
Amar


cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 17:31
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
One more question, I find each client has the same future time stamp where are 
those time stamps from, since Since it is different from any brick stored time 
stamp. And after I modify files  from clients, it remains the same.
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 193 Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 10383279039841136109  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.114365172 +0300
Modify: 2020-04-11 12:20:22.121552573 +0300
Change: 2020-04-11 12:20:22.121552573 +0300

[root@mn-0:/home/robot]
# date
Thu Mar 12 11:27:33 EET 2020
[root@mn-0:/home/robot]

[root@mn-0:/home/robot]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/6451

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
I know that this may not be your presumption of this ctime feature, however, 
our delima is that

  1.  product need to support date change scenario.
  2.  if we disable ctime feature, we will meet tar issue.
  3.  if we set consistent-metadata to on to work around this tar issue, there 
is another even worse problem: 
https://bugzilla.redhat.com/show_bug.cgi?id=1773476, app just cranshed!
So I have to make this patch.
Maybe I will keep this as internal use just for our local use scenarios.
Cynthia.

From: Kotresh Hiremath Ravishankar 
Sent: 2020年3月17日 15:17
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Amar Tumballi ; Gluster Devel 
Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime

The whole ctime features relies on time provided by clients which are time 
synchronized. This patch brings in the time from server to compare against the 
time sent from client.
As Amar mentioned, this doesn't fit well into the scheme of how ctime is 
designed. Definitely keeping it optional and disabling it by default is one 
way. But is that what your intention
here?

On Tue, Mar 17, 2020 at 10:56 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, thanks for your feedback!
I will do local test to verify this patch first.

cynthia

From: Amar Tumballi mailto:a...@kadalu.io>>
Sent: 2020年3月17日 13:18
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>; Gluster Devel 
mailto:gluster-devel@gluster.org>>
Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime


On Tue, Mar 17, 2020 at 10:18 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs expert,
Our product need to tolerate change date to future and then change back.
How about change like this ?
https://review.gluster.org/#/c/glusterfs/+/24229/1/xlators/storage/posix/src/posix-metadata.c

when time change to future and change back , should still be able to update 
mdata, so the following changes to file can be populated to other clients.


We do like to have people integrating with GlusterFS. But this change is not 
inline with the 'assumptions' we had about the feature.

If you have verified this change works for you, please add it as an 'option' in 
posix, which can be changed through volume set, and keep this option 
disable/off by default. That should be an easier way to get the patch reviewed 
and take it further. Please make sure to provide the 'description' for the 
option with details.

Regards,
Amar


cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 17:31
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
One more question, I find each client has the same future time stamp where are 
those time stamps from, since Since it is different from any brick stored time 
stamp. And after I modify files  from clients, it remains the same.
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 193 Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 10383279039841136109  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.114365172 +0300
Modify: 2020-04-11 12:20:22.121552573 +0300
Change: 2020-04-11 12:20:22.121552573 +0300

[root@mn-0:/home/robot]
# date
Thu Mar 12 11:27:33 EET 2020
[root@mn-0:/home/robot]

[root@mn-0:/home/robot]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.095981276 +0200
Change: 2020-03-12 11:25:04.095981276 +0200
Birth: 2020-04-11 08:53:26.805163816 +0300


[root@mn-1:/root]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.094913452 +0200
Change: 2020-03-12 11:25:04.095913453 +0200
Birth: 2020-03-12 07:53:26.803783053 +0200



From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 16:09
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok, thanks for your feedback!
I will do local test to verify this patch first.

cynthia

From: Amar Tumballi 
Sent: 2020年3月17日 13:18
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Kotresh Hiremath Ravishankar ; Gluster Devel 

Subject: Re: [Gluster-devel] could you help to check about a glusterfs issue 
seems to be related to ctime


On Tue, Mar 17, 2020 at 10:18 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs expert,
Our product need to tolerate change date to future and then change back.
How about change like this ?
https://review.gluster.org/#/c/glusterfs/+/24229/1/xlators/storage/posix/src/posix-metadata.c

when time change to future and change back , should still be able to update 
mdata, so the following changes to file can be populated to other clients.


We do like to have people integrating with GlusterFS. But this change is not 
inline with the 'assumptions' we had about the feature.

If you have verified this change works for you, please add it as an 'option' in 
posix, which can be changed through volume set, and keep this option 
disable/off by default. That should be an easier way to get the patch reviewed 
and take it further. Please make sure to provide the 'description' for the 
option with details.

Regards,
Amar


cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 17:31
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
One more question, I find each client has the same future time stamp where are 
those time stamps from, since Since it is different from any brick stored time 
stamp. And after I modify files  from clients, it remains the same.
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 193 Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 10383279039841136109  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.114365172 +0300
Modify: 2020-04-11 12:20:22.121552573 +0300
Change: 2020-04-11 12:20:22.121552573 +0300

[root@mn-0:/home/robot]
# date
Thu Mar 12 11:27:33 EET 2020
[root@mn-0:/home/robot]

[root@mn-0:/home/robot]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.095981276 +0200
Change: 2020-03-12 11:25:04.095981276 +0200
Birth: 2020-04-11 08:53:26.805163816 +0300


[root@mn-1:/root]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.094913452 +0200
Change: 2020-03-12 11:25:04.095913453 +0200
Birth: 2020-03-12 07:53:26.803783053 +0200



From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 16:09
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
This is abnormal test case, however, when this happened it will have big impact 
on the apps using those files. And this can not be restored automatically 
unless disable some xlator, I think it is unacceptable for the user apps.


cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月12日 14:37
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

All the perf xlators depend on time (mostly mtime I guess). In my setup, only 
quick read was enabled and hence disabling it worked for me.
All perf xlators needs to be disabled to make it work correctly. But I still 
failed to understand how normal this kind of workload ?

Thanks,
Kotresh

On Thu, Mar 12, 2020 at 11:20 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
When disable both quick-read and performance.io-cache off everything is back to 
normal
I attached the log when only enable quick-read and performance.io-cache is 
still on glusterfs trace log
When execute command “cat /mnt/export/testfile”
Can you help to find why this still to fail to show correct content?
The file size showed is 141, but actually in brick it is longer than that.


cynthia


From: Zh

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs expert,
Our product need to tolerate change date to future and then change back.
How about change like this ?
https://review.gluster.org/#/c/glusterfs/+/24229/1/xlators/storage/posix/src/posix-metadata.c

when time change to future and change back , should still be able to update 
mdata, so the following changes to file can be populated to other clients.

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 17:31
To: 'Kotresh Hiremath Ravishankar' 
Cc: 'Gluster Devel' 
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
One more question, I find each client has the same future time stamp where are 
those time stamps from, since Since it is different from any brick stored time 
stamp. And after I modify files  from clients, it remains the same.
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 193 Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 10383279039841136109  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.114365172 +0300
Modify: 2020-04-11 12:20:22.121552573 +0300
Change: 2020-04-11 12:20:22.121552573 +0300

[root@mn-0:/home/robot]
# date
Thu Mar 12 11:27:33 EET 2020
[root@mn-0:/home/robot]

[root@mn-0:/home/robot]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.095981276 +0200
Change: 2020-03-12 11:25:04.095981276 +0200
Birth: 2020-04-11 08:53:26.805163816 +0300


[root@mn-1:/root]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.094913452 +0200
Change: 2020-03-12 11:25:04.095913453 +0200
Birth: 2020-03-12 07:53:26.803783053 +0200



From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 16:09
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
This is abnormal test case, however, when this happened it will have big impact 
on the apps using those files. And this can not be restored automatically 
unless disable some xlator, I think it is unacceptable for the user apps.


cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月12日 14:37
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

All the perf xlators depend on time (mostly mtime I guess). In my setup, only 
quick read was enabled and hence disabling it worked for me.
All perf xlators needs to be disabled to make it work correctly. But I still 
failed to understand how normal this kind of workload ?

Thanks,
Kotresh

On Thu, Mar 12, 2020 at 11:20 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
When disable both quick-read and performance.io-cache off everything is back to 
normal
I attached the log when only enable quick-read and performance.io-cache is 
still on glusterfs trace log
When execute command “cat /mnt/export/testfile”
Can you help to find why this still to fail to show correct content?
The file size showed is 141, but actually in brick it is longer than that.


cynthia


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 12:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

From my local test only when disable both features.ctime and ctime.noatime this 
issue is gone.
Or
Do echo 3 >/proc/sys/vm/drop_caches after each time when some client change the 
file , can cat command show correct data(same as brick )

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 9:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.qui

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
One more question, I find each client has the same future time stamp where are 
those time stamps from, since Since it is different from any brick stored time 
stamp. And after I modify files  from clients, it remains the same.
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 193 Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 10383279039841136109  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.114365172 +0300
Modify: 2020-04-11 12:20:22.121552573 +0300
Change: 2020-04-11 12:20:22.121552573 +0300

[root@mn-0:/home/robot]
# date
Thu Mar 12 11:27:33 EET 2020
[root@mn-0:/home/robot]

[root@mn-0:/home/robot]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.095981276 +0200
Change: 2020-03-12 11:25:04.095981276 +0200
Birth: 2020-04-11 08:53:26.805163816 +0300


[root@mn-1:/root]
# stat /mnt/bricks/export/brick/testfile
  File: /mnt/bricks/export/brick/testfile
  Size: 193 Blocks: 16 IO Block: 4096   regular file
Device: fc02h/64514dInode: 512015  Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-04-11 12:20:22.100395536 +0300
Modify: 2020-03-12 11:25:04.094913452 +0200
Change: 2020-03-12 11:25:04.095913453 +0200
Birth: 2020-03-12 07:53:26.803783053 +0200



From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 16:09
To: 'Kotresh Hiremath Ravishankar' 
Cc: Gluster Devel 
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
This is abnormal test case, however, when this happened it will have big impact 
on the apps using those files. And this can not be restored automatically 
unless disable some xlator, I think it is unacceptable for the user apps.


cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月12日 14:37
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

All the perf xlators depend on time (mostly mtime I guess). In my setup, only 
quick read was enabled and hence disabling it worked for me.
All perf xlators needs to be disabled to make it work correctly. But I still 
failed to understand how normal this kind of workload ?

Thanks,
Kotresh

On Thu, Mar 12, 2020 at 11:20 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
When disable both quick-read and performance.io-cache off everything is back to 
normal
I attached the log when only enable quick-read and performance.io-cache is 
still on glusterfs trace log
When execute command “cat /mnt/export/testfile”
Can you help to find why this still to fail to show correct content?
The file size showed is 141, but actually in brick it is longer than that.


cynthia


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 12:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

From my local test only when disable both features.ctime and ctime.noatime this 
issue is gone.
Or
Do echo 3 >/proc/sys/vm/drop_caches after each time when some client change the 
file , can cat command show correct data(same as brick )

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 9:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.quick-read  off

however, this issue still exists.
Two clients see different contents.

it seems only after I disable utime this issue is completely gone.
features.ctime  off
ctime.noatime   off


Do you know why is this?


Cynthia
Nokia storage team
From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 22:05
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,

I figured out what's happening.

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
This is abnormal test case, however, when this happened it will have big impact 
on the apps using those files. And this can not be restored automatically 
unless disable some xlator, I think it is unacceptable for the user apps.


cynthia

From: Kotresh Hiremath Ravishankar 
Sent: 2020年3月12日 14:37
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Gluster Devel 
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

All the perf xlators depend on time (mostly mtime I guess). In my setup, only 
quick read was enabled and hence disabling it worked for me.
All perf xlators needs to be disabled to make it work correctly. But I still 
failed to understand how normal this kind of workload ?

Thanks,
Kotresh

On Thu, Mar 12, 2020 at 11:20 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
When disable both quick-read and performance.io-cache off everything is back to 
normal
I attached the log when only enable quick-read and performance.io-cache is 
still on glusterfs trace log
When execute command “cat /mnt/export/testfile”
Can you help to find why this still to fail to show correct content?
The file size showed is 141, but actually in brick it is longer than that.


cynthia


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 12:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: 'Gluster Devel' 
mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

From my local test only when disable both features.ctime and ctime.noatime this 
issue is gone.
Or
Do echo 3 >/proc/sys/vm/drop_caches after each time when some client change the 
file , can cat command show correct data(same as brick )

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 9:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.quick-read  off

however, this issue still exists.
Two clients see different contents.

it seems only after I disable utime this issue is completely gone.
features.ctime  off
ctime.noatime   off


Do you know why is this?


Cynthia
Nokia storage team
From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 22:05
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,

I figured out what's happening. The issue is that the file has 'c|a|m' time set 
to future (The file is created after the date is set to +30 days). This
is done from client-1. On client-2 with correct date, when data is appended, it 
doesn't update the mtime and ctime because of both mtime and ctime is less than
already set time on the file. This protection is required to keep the latest 
time when two clients are writing to the same file. We update c|m|a time only 
if it's greater than
existing time. As a result, the perf xlators on client1 which relies on mtime 
doesn't send read to server as it thinks nothing is changed as in this case the 
times haven't
changed.

Workarounds:
1. Disabling quick-read solved the issue for me.
I don't know how real this kind of workload is? Is this a normal scenario ?
The other thing to do is to remove that protection of updating time only if 
it's greater but that would open up the race when two clients are updating the 
same file.
This would result in keeping the older time than the latest. This requires code 
change and I don't think that should be done.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 3:02 PM Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>> wrote:
Exactly, I am also curious about this. I will debug and update about what's 
exactly happening.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 1:56 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I used to think the file is cached in some client side buffer, because I’ve 
checked from different sn brick, the file content are all correct. But when I 
open client side trace level log, and cat the file, I only find 
lookup/open/flush fop from fuse-bridge side, I am just wondering how is file 
content served to client side? Should not there be readv fop seen from trace 
log?

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月11日 15:54
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to 

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

When disable both quick-read and performance.io-cache off everything is back to 
normal
I attached the log when only enable quick-read and performance.io-cache is 
still on glusterfs trace log
When execute command “cat /mnt/export/testfile”
Can you help to find why this still to fail to show correct content?
The file size showed is 141, but actually in brick it is longer than that.


cynthia


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 12:53
To: 'Kotresh Hiremath Ravishankar' 
Cc: 'Gluster Devel' 
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

From my local test only when disable both features.ctime and ctime.noatime this 
issue is gone.
Or
Do echo 3 >/proc/sys/vm/drop_caches after each time when some client change the 
file , can cat command show correct data(same as brick )

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 9:53
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.quick-read  off

however, this issue still exists.
Two clients see different contents.

it seems only after I disable utime this issue is completely gone.
features.ctime  off
ctime.noatime   off


Do you know why is this?


Cynthia
Nokia storage team
From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 22:05
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,

I figured out what's happening. The issue is that the file has 'c|a|m' time set 
to future (The file is created after the date is set to +30 days). This
is done from client-1. On client-2 with correct date, when data is appended, it 
doesn't update the mtime and ctime because of both mtime and ctime is less than
already set time on the file. This protection is required to keep the latest 
time when two clients are writing to the same file. We update c|m|a time only 
if it's greater than
existing time. As a result, the perf xlators on client1 which relies on mtime 
doesn't send read to server as it thinks nothing is changed as in this case the 
times haven't
changed.

Workarounds:
1. Disabling quick-read solved the issue for me.
I don't know how real this kind of workload is? Is this a normal scenario ?
The other thing to do is to remove that protection of updating time only if 
it's greater but that would open up the race when two clients are updating the 
same file.
This would result in keeping the older time than the latest. This requires code 
change and I don't think that should be done.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 3:02 PM Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>> wrote:
Exactly, I am also curious about this. I will debug and update about what's 
exactly happening.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 1:56 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I used to think the file is cached in some client side buffer, because I’ve 
checked from different sn brick, the file content are all correct. But when I 
open client side trace level log, and cat the file, I only find 
lookup/open/flush fop from fuse-bridge side, I am just wondering how is file 
content served to client side? Should not there be readv fop seen from trace 
log?

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月11日 15:54
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Does that require, that for all the time client should be time synched? What if 
the client time is not synched for a while? And then restored?
I make a test when time has been restored and then client change the file, the 
file’s modify time, access times remains to be wrong, is that correct?

root@mn-0:/home/robot]
# echo "fromm mn-0">>/mnt/export/testfile
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 30  Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 9855109080001305442  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-05-10 09:33:59.713840197 +0300
Modify: 2020-05-10 09:33:59.713840197 +0300
Change: 2020-05-10 09:33:59.714413772 +0300  //remains to be future time
Birth: -
[root@mn-0:/home/robot]
# cat /mnt/export/testfil
cat: /mnt/export/testfil: No such file or directory
[r

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

From my local test only when disable both features.ctime and ctime.noatime this 
issue is gone.
Or
Do echo 3 >/proc/sys/vm/drop_caches after each time when some client change the 
file , can cat command show correct data(same as brick )

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月12日 9:53
To: 'Kotresh Hiremath Ravishankar' 
Cc: Gluster Devel 
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.quick-read  off

however, this issue still exists.
Two clients see different contents.

it seems only after I disable utime this issue is completely gone.
features.ctime  off
ctime.noatime   off


Do you know why is this?


Cynthia
Nokia storage team
From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 22:05
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel mailto:gluster-devel@gluster.org>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,

I figured out what's happening. The issue is that the file has 'c|a|m' time set 
to future (The file is created after the date is set to +30 days). This
is done from client-1. On client-2 with correct date, when data is appended, it 
doesn't update the mtime and ctime because of both mtime and ctime is less than
already set time on the file. This protection is required to keep the latest 
time when two clients are writing to the same file. We update c|m|a time only 
if it's greater than
existing time. As a result, the perf xlators on client1 which relies on mtime 
doesn't send read to server as it thinks nothing is changed as in this case the 
times haven't
changed.

Workarounds:
1. Disabling quick-read solved the issue for me.
I don't know how real this kind of workload is? Is this a normal scenario ?
The other thing to do is to remove that protection of updating time only if 
it's greater but that would open up the race when two clients are updating the 
same file.
This would result in keeping the older time than the latest. This requires code 
change and I don't think that should be done.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 3:02 PM Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>> wrote:
Exactly, I am also curious about this. I will debug and update about what's 
exactly happening.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 1:56 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I used to think the file is cached in some client side buffer, because I’ve 
checked from different sn brick, the file content are all correct. But when I 
open client side trace level log, and cat the file, I only find 
lookup/open/flush fop from fuse-bridge side, I am just wondering how is file 
content served to client side? Should not there be readv fop seen from trace 
log?

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月11日 15:54
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Does that require, that for all the time client should be time synched? What if 
the client time is not synched for a while? And then restored?
I make a test when time has been restored and then client change the file, the 
file’s modify time, access times remains to be wrong, is that correct?

root@mn-0:/home/robot]
# echo "fromm mn-0">>/mnt/export/testfile
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 30  Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 9855109080001305442  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-05-10 09:33:59.713840197 +0300
Modify: 2020-05-10 09:33:59.713840197 +0300
Change: 2020-05-10 09:33:59.714413772 +0300  //remains to be future time
Birth: -
[root@mn-0:/home/robot]
# cat /mnt/export/testfil
cat: /mnt/export/testfil: No such file or directory
[root@mn-0:/home/robot]
# cat /mnt/export/testfile
from mn0
from mn-1
fromm mn-0
[root@mn-0:/home/robot]
# date
Wed 11 Mar 2020 09:05:58 AM EET
[root@mn-0:/home/robot]

cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 15:41
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime



On Wed, Mar 11, 2020 at 12:46 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
But there are times that ntp service went wrong, and time on two storage nodes 
may be not synced.
Or do you mean w

Re: [Gluster-devel] could you help to check about a glusterfs issue seems to be related to ctime

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Thanks for your responding!
I’ve tried to disable quick-read:
[root@mn-0:/home/robot]
# gluster v get export all| grep quick
performance.quick-read  off
performance.nfs.quick-read  off

however, this issue still exists.
Two clients see different contents.

it seems only after I disable utime this issue is completely gone.
features.ctime  off
ctime.noatime   off


Do you know why is this?


Cynthia
Nokia storage team
From: Kotresh Hiremath Ravishankar 
Sent: 2020年3月11日 22:05
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Gluster Devel 
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime

Hi,

I figured out what's happening. The issue is that the file has 'c|a|m' time set 
to future (The file is created after the date is set to +30 days). This
is done from client-1. On client-2 with correct date, when data is appended, it 
doesn't update the mtime and ctime because of both mtime and ctime is less than
already set time on the file. This protection is required to keep the latest 
time when two clients are writing to the same file. We update c|m|a time only 
if it's greater than
existing time. As a result, the perf xlators on client1 which relies on mtime 
doesn't send read to server as it thinks nothing is changed as in this case the 
times haven't
changed.

Workarounds:
1. Disabling quick-read solved the issue for me.
I don't know how real this kind of workload is? Is this a normal scenario ?
The other thing to do is to remove that protection of updating time only if 
it's greater but that would open up the race when two clients are updating the 
same file.
This would result in keeping the older time than the latest. This requires code 
change and I don't think that should be done.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 3:02 PM Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>> wrote:
Exactly, I am also curious about this. I will debug and update about what's 
exactly happening.

Thanks,
Kotresh

On Wed, Mar 11, 2020 at 1:56 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I used to think the file is cached in some client side buffer, because I’ve 
checked from different sn brick, the file content are all correct. But when I 
open client side trace level log, and cat the file, I only find 
lookup/open/flush fop from fuse-bridge side, I am just wondering how is file 
content served to client side? Should not there be readv fop seen from trace 
log?

cynthia

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: 2020年3月11日 15:54
To: 'Kotresh Hiremath Ravishankar' 
mailto:khire...@redhat.com>>
Subject: RE: could you help to check about a glusterfs issue seems to be 
related to ctime

Does that require, that for all the time client should be time synched? What if 
the client time is not synched for a while? And then restored?
I make a test when time has been restored and then client change the file, the 
file’s modify time, access times remains to be wrong, is that correct?

root@mn-0:/home/robot]
# echo "fromm mn-0">>/mnt/export/testfile
[root@mn-0:/home/robot]
# stat /mnt/export/testfile
  File: /mnt/export/testfile
  Size: 30  Blocks: 1  IO Block: 131072 regular file
Device: 28h/40d Inode: 9855109080001305442  Links: 1
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (  
615/_nokfsuifileshare)
Access: 2020-05-10 09:33:59.713840197 +0300
Modify: 2020-05-10 09:33:59.713840197 +0300
Change: 2020-05-10 09:33:59.714413772 +0300  //remains to be future time
Birth: -
[root@mn-0:/home/robot]
# cat /mnt/export/testfil
cat: /mnt/export/testfil: No such file or directory
[root@mn-0:/home/robot]
# cat /mnt/export/testfile
from mn0
from mn-1
fromm mn-0
[root@mn-0:/home/robot]
# date
Wed 11 Mar 2020 09:05:58 AM EET
[root@mn-0:/home/robot]

cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 15:41
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Subject: Re: could you help to check about a glusterfs issue seems to be 
related to ctime



On Wed, Mar 11, 2020 at 12:46 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
But there are times that ntp service went wrong, and time on two storage nodes 
may be not synced.
Or do you mean when can not guarantee that the time on two clients is synched, 
we should not enable this ctime feature?
Yes, that's correct. The ctime feature relies on the time generated at the 
client (that's the utime xlator loaded in client) and hence
expects all clients to be ntp synced.

Without ctime feature, is there some way to avoid this “file changed as we read 
it” issue?
Unfortunately no. That's the only way as of now.
cynthia

From: Kotresh Hiremath Ravishankar 
mailto:khire...@redhat.com>>
Sent: 2020年3月11日 15:12
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
How about this patch? I see there is a failed test, is that related to my 
change?

cynthia

From: Raghavendra Gowdappa 
Sent: Thursday, May 09, 2019 12:13 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Amar Tumballi Suryanarayan ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Thanks!!

On Thu, May 9, 2019 at 8:34 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
Ok, It is posted to https://review.gluster.org/#/c/glusterfs/+/22687/



From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Wednesday, May 08, 2019 7:35 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Amar Tumballi Suryanarayan 
mailto:atumb...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, May 8, 2019 at 1:29 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi 'Milind Changire' ,
The leak is getting more and more clear to me now. the unsolved memory leak is 
because of in gluterfs version 3.12.15 (in my env)the ssl context is a shared 
one, while we do ssl_acept, ssl will allocate some read/write buffer to ssl 
object, however, ssl_free in socket_reset or fini function of socket.c, the 
buffer is returened back to ssl context free list instead of completely freed.

Thanks Cynthia for your efforts in identifying and fixing the leak. If you post 
a patch to gerrit, I'll be happy to merge it and get the fix into the codebase.


So following patch is able to fix the memory leak issue completely.(created for 
gluster master branch)

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -446,6 +446,7 @@ ssl_setup_connection_postfix(rpc_transport_t *this)
 gf_log(this->name, GF_LOG_DEBUG,
"SSL verification succeeded (client: %s) (server: %s)",
this->peerinfo.identifier, this->myinfo.identifier);
+X509_free(peer);
 return gf_strdup(peer_CN);

 /* Error paths. */
@@ -1157,7 +1158,21 @@ __socket_reset(rpc_transport_t *this)
 memset(>incoming, 0, sizeof(priv->incoming));

 event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+if(priv->use_ssl&& priv->ssl_ssl)
+{
+  gf_log(this->name, GF_LOG_TRACE,
+ "clear and reset for socket(%d), free ssl ",
+ priv->sock);
+   if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+ }
+  SSL_shutdown(priv->ssl_ssl);
+  SSL_clear(priv->ssl_ssl);
+  SSL_free(priv->ssl_ssl);
+  priv->ssl_ssl = NULL;
+}
 priv->sock = -1;
 priv->idx = -1;
 priv->connected = -1;
@@ -4675,6 +4690,21 @@ fini(rpc_transport_t *this)
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+   if(priv->use_ssl&& priv->ssl_ssl)
+   {
+ gf_log(this->name, GF_LOG_TRACE,
+"clear and reset for socket(%d), free ssl ",
+priv->sock);
+ if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+     }
+ SSL_shutdown(priv->ssl_ssl);
+ SSL_clear(priv->ssl_ssl);
+ SSL_free(priv->ssl_ssl);
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Monday, May 06, 2019 2:12 PM
To: 'Amar Tumballi Suryanarayan' 
mailto:atumb...@redhat.com>>
Cc: 'Milind Changire' mailto:mchan...@redhat.com>>; 
'gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>' 
mailto:gluster-devel@gluster.org>>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Hi,
From our test valgrind and libleak all blame ssl3_accept
///from valgrind attached to 
glusterfds///
==16673== 198,720 bytes in 12 blocks are definitely lost in loss record 1,114 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855E0C: ssl3_setup_write_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E77: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA61

[Gluster-devel] glusterfs coredump--mempool

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs expert,
I meet glusterfs process coredump again in my env, short after glusterfs 
process startup. The local become NULL, but seems this frame is not destroyed 
yet since the magic number(GF_MEM_HEADER_MAGIC) still untouched.
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/glusterfs --acl --volfile-server=mn-0.local 
--volfile-server=mn-1.loc'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x7f867fcd2971 in client3_3_inodelk_cbk (req=, 
iov=, count=, myframe=0x7f8654008830)
at client-rpc-fops.c:1510
1510  CLIENT_STACK_UNWIND (inodelk, frame, rsp.op_ret,
[Current thread is 1 (Thread 0x7f867d6d4700 (LWP 3046))]
Missing separate debuginfos, use: dnf debuginfo-install 
glusterfs-fuse-3.12.15-1.wos2.wf29.x86_64
(gdb) bt
#0  0x7f867fcd2971 in client3_3_inodelk_cbk (req=, 
iov=, count=, myframe=0x7f8654008830)
at client-rpc-fops.c:1510
#1  0x7f8685ea5584 in rpc_clnt_handle_reply 
(clnt=clnt@entry=0x7f8678070030, pollin=pollin@entry=0x7f86702833e0) at 
rpc-clnt.c:782
#2  0x7f8685ea587b in rpc_clnt_notify (trans=, 
mydata=0x7f8678070060, event=, data=0x7f86702833e0) at 
rpc-clnt.c:975
#3  0x7f8685ea1b83 in rpc_transport_notify (this=this@entry=0x7f8678070270, 
event=event@entry=RPC_TRANSPORT_MSG_RECEIVED,
data=data@entry=0x7f86702833e0) at rpc-transport.c:538
#4  0x7f8680b99867 in socket_event_poll_in (notify_handled=_gf_true, 
this=0x7f8678070270) at socket.c:2260
#5  socket_event_handler (fd=, idx=3, gen=1, 
data=0x7f8678070270, poll_in=, poll_out=,
poll_err=) at socket.c:2645
#6  0x7f8686132911 in event_dispatch_epoll_handler (event=0x7f867d6d3e6c, 
event_pool=0x55e1b2792b00) at event-epoll.c:583
#7  event_dispatch_epoll_worker (data=0x7f867805ece0) at event-epoll.c:659
#8  0x7f8684ea65da in start_thread () from /lib64/libpthread.so.0
#9  0x7f868474eeaf in clone () from /lib64/libc.so.6
(gdb) print *(call_frame_t*)myframe
$3 = {root = 0x7f86540271a0, parent = 0x0, frames = {next = 0x7f8654027898, 
prev = 0x7f8654027898}, local = 0x0, this = 0x7f8678013080, ret = 0x0,
  ref_count = 0, lock = {spinlock = 0, mutex = {__data = {__lock = 0, __count = 
0, __owner = 0, __nusers = 0, __kind = 0, __spins = 0, __elision = 0,
__list = {__prev = 0x0, __next = 0x0}}, __size = '\000' , __align = 0}}, cookie = 0x0, complete = _gf_false, xid = 0,
  op = GF_FOP_NULL, begin = {tv_sec = 0, tv_usec = 0}, end = {tv_sec = 0, 
tv_usec = 0}, wind_from = 0x0, wind_to = 0x0, unwind_from = 0x0, unwind_to = 
0x0}
(gdb) x/4xw  0x7f8654008810
0x7f8654008810:   0xcafebabe 0x 0x 0x
(gdb) p *(pooled_obj_hdr_t *)0x7f8654008810
$2 = {magic = 3405691582, next = 0x0, pool_list = 0x7f8654000b80, power_of_two 
= 8}

I add "uint32_t xid" in data structure _call_frame, and set it according to the 
rcpreq->xid in __save_frame function. In normal situation this xid should only 
be 0 immediately after create_frame from memory pool. But in this case this xid 
is 0, so seems like that the frame has been given out for use before freed. 
Have you any idea how this happen?


cynthia
___

Community Meeting Calendar:

APAC Schedule -
Every 2nd and 4th Tuesday at 11:30 AM IST
Bridge: https://bluejeans.com/836554017

NA/EMEA Schedule -
Every 1st and 3rd Tuesday at 01:00 PM EDT
Bridge: https://bluejeans.com/486278655

Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Ok, It is posted to https://review.gluster.org/#/c/glusterfs/+/22687/



From: Raghavendra Gowdappa 
Sent: Wednesday, May 08, 2019 7:35 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Amar Tumballi Suryanarayan ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, May 8, 2019 at 1:29 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi 'Milind Changire' ,
The leak is getting more and more clear to me now. the unsolved memory leak is 
because of in gluterfs version 3.12.15 (in my env)the ssl context is a shared 
one, while we do ssl_acept, ssl will allocate some read/write buffer to ssl 
object, however, ssl_free in socket_reset or fini function of socket.c, the 
buffer is returened back to ssl context free list instead of completely freed.

Thanks Cynthia for your efforts in identifying and fixing the leak. If you post 
a patch to gerrit, I'll be happy to merge it and get the fix into the codebase.


So following patch is able to fix the memory leak issue completely.(created for 
gluster master branch)

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -446,6 +446,7 @@ ssl_setup_connection_postfix(rpc_transport_t *this)
 gf_log(this->name, GF_LOG_DEBUG,
"SSL verification succeeded (client: %s) (server: %s)",
this->peerinfo.identifier, this->myinfo.identifier);
+X509_free(peer);
 return gf_strdup(peer_CN);

 /* Error paths. */
@@ -1157,7 +1158,21 @@ __socket_reset(rpc_transport_t *this)
 memset(>incoming, 0, sizeof(priv->incoming));

 event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+if(priv->use_ssl&& priv->ssl_ssl)
+{
+  gf_log(this->name, GF_LOG_TRACE,
+ "clear and reset for socket(%d), free ssl ",
+ priv->sock);
+   if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+ }
+  SSL_shutdown(priv->ssl_ssl);
+  SSL_clear(priv->ssl_ssl);
+  SSL_free(priv->ssl_ssl);
+  priv->ssl_ssl = NULL;
+}
 priv->sock = -1;
 priv->idx = -1;
 priv->connected = -1;
@@ -4675,6 +4690,21 @@ fini(rpc_transport_t *this)
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+   if(priv->use_ssl&& priv->ssl_ssl)
+   {
+ gf_log(this->name, GF_LOG_TRACE,
+"clear and reset for socket(%d), free ssl ",
+priv->sock);
+ if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+     }
+             SSL_shutdown(priv->ssl_ssl);
+ SSL_clear(priv->ssl_ssl);
+ SSL_free(priv->ssl_ssl);
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Monday, May 06, 2019 2:12 PM
To: 'Amar Tumballi Suryanarayan' 
mailto:atumb...@redhat.com>>
Cc: 'Milind Changire' mailto:mchan...@redhat.com>>; 
'gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>' 
mailto:gluster-devel@gluster.org>>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Hi,
From our test valgrind and libleak all blame ssl3_accept
///from valgrind attached to 
glusterfds///
==16673== 198,720 bytes in 12 blocks are definitely lost in loss record 1,114 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855E0C: ssl3_setup_write_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E77: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA618420: socket_complete_connection (socket.c:2554)
==16673==by 0xA618788: socket_event_handler (socket.c:2613)
==16673==by 0x4ED6983: event_dispatch_epoll_handler (event-epoll.c:587)
==16673==by 0x4ED6C5A: event_dispatch_epoll_worker (event-epoll.c:663)
==16673==by 0x615C5D9: start_thread (in 
/usr/lib64/libpthread-2.27.so<http://libpthread-2.27.so>)
==16673==
==16673== 200,544 bytes in 12 blocks are definitely lost in loss record 1,115 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855D12: ssl3_setu

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi 'Milind Changire' ,
The leak is getting more and more clear to me now. the unsolved memory leak is 
because of in gluterfs version 3.12.15 (in my env)the ssl context is a shared 
one, while we do ssl_acept, ssl will allocate some read/write buffer to ssl 
object, however, ssl_free in socket_reset or fini function of socket.c, the 
buffer is returened back to ssl context free list instead of completely freed.

So following patch is able to fix the memory leak issue completely.(created for 
gluster master branch)

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -446,6 +446,7 @@ ssl_setup_connection_postfix(rpc_transport_t *this)
 gf_log(this->name, GF_LOG_DEBUG,
"SSL verification succeeded (client: %s) (server: %s)",
this->peerinfo.identifier, this->myinfo.identifier);
+X509_free(peer);
 return gf_strdup(peer_CN);

 /* Error paths. */
@@ -1157,7 +1158,21 @@ __socket_reset(rpc_transport_t *this)
 memset(>incoming, 0, sizeof(priv->incoming));

 event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+if(priv->use_ssl&& priv->ssl_ssl)
+{
+  gf_log(this->name, GF_LOG_TRACE,
+ "clear and reset for socket(%d), free ssl ",
+ priv->sock);
+   if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+ }
+  SSL_shutdown(priv->ssl_ssl);
+  SSL_clear(priv->ssl_ssl);
+  SSL_free(priv->ssl_ssl);
+  priv->ssl_ssl = NULL;
+}
 priv->sock = -1;
 priv->idx = -1;
 priv->connected = -1;
@@ -4675,6 +4690,21 @@ fini(rpc_transport_t *this)
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+   if(priv->use_ssl&& priv->ssl_ssl)
+   {
+ gf_log(this->name, GF_LOG_TRACE,
+"clear and reset for socket(%d), free ssl ",
+priv->sock);
+ if(priv->ssl_ctx)
+ {
+   SSL_CTX_free(priv->ssl_ctx);
+   priv->ssl_ctx = NULL;
+     }
+             SSL_shutdown(priv->ssl_ssl);
+ SSL_clear(priv->ssl_ssl);
+ SSL_free(priv->ssl_ssl);
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Monday, May 06, 2019 2:12 PM
To: 'Amar Tumballi Suryanarayan' 
Cc: 'Milind Changire' ; 'gluster-devel@gluster.org' 

Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Hi,
From our test valgrind and libleak all blame ssl3_accept
///from valgrind attached to 
glusterfds///
==16673== 198,720 bytes in 12 blocks are definitely lost in loss record 1,114 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855E0C: ssl3_setup_write_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E77: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA618420: socket_complete_connection (socket.c:2554)
==16673==by 0xA618788: socket_event_handler (socket.c:2613)
==16673==by 0x4ED6983: event_dispatch_epoll_handler (event-epoll.c:587)
==16673==by 0x4ED6C5A: event_dispatch_epoll_worker (event-epoll.c:663)
==16673==by 0x615C5D9: start_thread (in /usr/lib64/libpthread-2.27.so)
==16673==
==16673== 200,544 bytes in 12 blocks are definitely lost in loss record 1,115 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855D12: ssl3_setup_read_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E68: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA618420: socket_complete_connection (socket.c:2554)
==16673==by 0xA618788: socket_event_handler (socket.c:2613)
==16673==by 0x4ED6983: event_dispatch_epoll_handler (event-epoll.c:587)
==16673==by 0x4ED6C5A: event_dispatch_epoll_worker (event-epoll.c:663)
==16673==by 0x615C5D9: start_thread (in /usr/lib64/libpthread-2.27.so)
==16673==
valgrind --leak-check=f


with libleak

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
From our test valgrind and libleak all blame ssl3_accept
///from valgrind attached to 
glusterfds///
==16673== 198,720 bytes in 12 blocks are definitely lost in loss record 1,114 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855E0C: ssl3_setup_write_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E77: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA618420: socket_complete_connection (socket.c:2554)
==16673==by 0xA618788: socket_event_handler (socket.c:2613)
==16673==by 0x4ED6983: event_dispatch_epoll_handler (event-epoll.c:587)
==16673==by 0x4ED6C5A: event_dispatch_epoll_worker (event-epoll.c:663)
==16673==by 0x615C5D9: start_thread (in /usr/lib64/libpthread-2.27.so)
==16673==
==16673== 200,544 bytes in 12 blocks are definitely lost in loss record 1,115 
of 1,123
==16673==at 0x4C2EB7B: malloc (vg_replace_malloc.c:299)
==16673==by 0x63E1977: CRYPTO_malloc (in /usr/lib64/libcrypto.so.1.0.2p)
==16673==by 0xA855D12: ssl3_setup_read_buffer (in 
/usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA855E68: ssl3_setup_buffers (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA8485D9: ssl3_accept (in /usr/lib64/libssl.so.1.0.2p)
==16673==by 0xA610DDF: ssl_complete_connection (socket.c:400)
==16673==by 0xA617F38: ssl_handle_server_connection_attempt (socket.c:2409)
==16673==by 0xA618420: socket_complete_connection (socket.c:2554)
==16673==by 0xA618788: socket_event_handler (socket.c:2613)
==16673==by 0x4ED6983: event_dispatch_epoll_handler (event-epoll.c:587)
==16673==by 0x4ED6C5A: event_dispatch_epoll_worker (event-epoll.c:663)
==16673==by 0x615C5D9: start_thread (in /usr/lib64/libpthread-2.27.so)
==16673==
valgrind --leak-check=f


with libleak attached to 
glusterfsd/
callstack[2419] expires. count=1 size=224/224 alloc=362 free=350
/home/robot/libleak/libleak.so(malloc+0x25) [0x7f1460604065]
/lib64/libcrypto.so.10(CRYPTO_malloc+0x58) [0x7f145ecd9978]
/lib64/libcrypto.so.10(EVP_DigestInit_ex+0x2a9) [0x7f145ed95749]
/lib64/libssl.so.10(ssl3_digest_cached_records+0x11d) [0x7f145abb6ced]
/lib64/libssl.so.10(ssl3_accept+0xc8f) [0x7f145abadc4f]

/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(ssl_complete_connection+0x5e)
 [0x7f145ae00f3a]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc16d) 
[0x7f145ae0816d]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc68a) 
[0x7f145ae0868a]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc9f2) 
[0x7f145ae089f2]
/lib64/libglusterfs.so.0(+0x9b96f) [0x7f146038596f]
/lib64/libglusterfs.so.0(+0x9bc46) [0x7f1460385c46]
/lib64/libpthread.so.0(+0x75da) [0x7f145f0d15da]
/lib64/libc.so.6(clone+0x3f) [0x7f145e9a7eaf]
callstack[2432] expires. count=1 size=104/104 alloc=362 free=0
/home/robot/libleak/libleak.so(malloc+0x25) [0x7f1460604065]
/lib64/libcrypto.so.10(CRYPTO_malloc+0x58) [0x7f145ecd9978]
/lib64/libcrypto.so.10(BN_MONT_CTX_new+0x17) [0x7f145ed48627]
/lib64/libcrypto.so.10(BN_MONT_CTX_set_locked+0x6d) [0x7f145ed489fd]
/lib64/libcrypto.so.10(+0xff4d9) [0x7f145ed6a4d9]
/lib64/libcrypto.so.10(int_rsa_verify+0x1cd) [0x7f145ed6d41d]
/lib64/libcrypto.so.10(RSA_verify+0x32) [0x7f145ed6d972]
/lib64/libcrypto.so.10(+0x107ff5) [0x7f145ed72ff5]
/lib64/libcrypto.so.10(EVP_VerifyFinal+0x211) [0x7f145ed9dd51]
/lib64/libssl.so.10(ssl3_get_cert_verify+0x5bb) [0x7f145abac06b]
/lib64/libssl.so.10(ssl3_accept+0x988) [0x7f145abad948]

/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(ssl_complete_connection+0x5e)
 [0x7f145ae00f3a]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc16d) 
[0x7f145ae0816d]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc68a) 
[0x7f145ae0868a]
/usr/lib64/glusterfs/3.12.15/rpc-transport/socket.so(+0xc9f2) 
[0x7f145ae089f2]
/lib64/libglusterfs.so.0(+0x9b96f) [0x7f146038596f]
/lib64/libglusterfs.so.0(+0x9bc46) [0x7f1460385c46]
/lib64/libpthread.so.0(+0x75da) [0x7f145f0d15da]
/lib64/libc.so.6(clone+0x3f) [0x7f145e9a7eaf]

one interesting thing is that the memory goes up to about 300m then it stopped  
increasing !!!
I am wondering if this is caused by open-ssl library? But when I search from 
openssl community, there is no such issue reported before.
Is glusterfs using ssl_accept correctly?

cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Monday, May 06, 2019 10:34 AM
To: 'Amar Tumballi Suryanarayan' 
Cc: Milind Changire ; gluster-devel

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Sorry, I am so busy with other issues these days, could you help me to submit 
my patch for review? It is based on glusterfs3.12.15 code. But even with this 
patch , memory leak still exists, from memory leak tool it should be related 
with ssl_accept, not sure if it is because of openssl library or because 
improper use of ssl interfaces.
--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4250,16 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);
 }


From: Amar Tumballi Suryanarayan 
Sent: Wednesday, May 01, 2019 8:43 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Milind Changire ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Hi Cynthia Zhou,

Can you post the patch which fixes the issue of missing free? We will continue 
to investigate the leak further, but would really appreciate getting the patch 
which is already worked on land into upstream master.

-Amar

On Mon, Apr 22, 2019 at 1:38 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, I am clear now.
I’ve added ssl_free in socket reset and socket finish function, though 
glusterfsd memory leak is not that much, still it is leaking, from source code 
I can not find anything else,
Could you help to check if this issue exists in your env? If not I may have a 
try to merge your patch .
Step

1>   while true;do gluster v heal  info,

2>   check the vol-name glusterfsd memory usage, it is obviously increasing.
cynthia

From: Milind Changire mailto:mchan...@redhat.com>>
Sent: Monday, April 22, 2019 2:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Atin Mukherjee mailto:amukh...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

According to BIO_new_socket() man page ...

If the close flag is set then the socket is shut down and closed when the BIO 
is freed.

For Gluster to have more control over the socket shutdown, the BIO_NOCLOSE flag 
is set. Otherwise, SSL takes control of socket shutdown whenever BIO is freed.

___
Gluster-devel mailing list
Gluster-devel@gluster.org<mailto:Gluster-devel@gluster.org>
https://lists.gluster.org/mailman/listinfo/gluster-devel


--
Amar Tumballi (amarts)
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Ok, I see your point ,two rounds of pollin means two different iobref, so the 
first pollin will not affect the second. But from the stack the second poll in 
stuck in iobref_unref LOCK operation,
Do you think it is possible that the iobref_destroy does not deal with this 
iobref->lock will cause it to be some unsanitized value and cause this stuck?

cynthia

From: Raghavendra Gowdappa 
Sent: Thursday, April 25, 2019 2:07 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: gluster-devel@gluster.org
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 15, 2019 at 12:52 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
The reason why I move event_handled to the end of socket_event_poll_in is 
because if event_handled is called before rpc_transport_pollin_destroy, it 
allowed another round of event_dispatch_epoll_handler happen before  
rpc_transport_pollin_destroy, in this way, when the latter poll in goes to 
rpc_transport_pollin_destroy , there is a chance that the pollin->iobref has 
already been destroyed by the first one(there is no lock destroy for 
iobref->lock in iobref_destroy by the way). That may cause stuck in “LOCK 
(>lock);”

But, priv->incoming.iobref (from which pollin->iobref is initialized from) is 
set to NULL in __socket_proto_state_machine:

if (in->record_state == SP_STATE_COMPLETE) {
in->record_state = SP_STATE_NADA;
__socket_reset_priv (priv);
}

And since pollin is an allocated object only one instance of 
socket_event_poll_in will be aware of this object. IOW, multiple instances of 
socket_event_poll_in will get different pollin objects. So, the only way 
pollin->iobref could be shared across multiple invocations of 
socket_event_poll_in is due to common shared object priv->incoming.iobref. But 
that too is sanitized by the time __socket_proto_state_machine completes and 
__socket_proto_state_machine is executed under lock. So, I don't see how two 
different concurrent codepaths can get hold of same iobref.

I find the one of recent patch
SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket

I think the point is to avoid the concurrent handling of the same socket at the 
same time, but after my test with this patch this problem also exists, so I 
think event_handled is still called too early to allow concurrent handling of 
the same socket happen, and after move it to the end of socket_event_poll this 
glusterd stuck issue disappeared.
cynthia
From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Monday, April 15, 2019 2:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 15, 2019 at 11:08 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, thanks for your comment!

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Monday, April 15, 2019 11:52 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15

Cynthia,

On Mon, Apr 15, 2019 at 8:10 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
I made a patch and according to my test, this glusterd stuck issue disappear 
with my patch. Only need to move  event_handled to the end of 
socket_event_poll_in function.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -2305,9 +2305,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }

-if (notify_handled && (ret != -1))
-event_handled (ctx->event_pool, priv->sock, priv->idx,
-   priv->gen);
@@ -2330,6 +2327,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }
 pthread_mutex_unlock (>notify.lock);
 }
+if (notify_handled && (ret != -1))
+event_handled (ctx->event_pool, priv->sock, priv->idx,
+   priv->gen);

Thanks for this tip. Though this helps in fixing the hang, this change has 
performance impact. Moving event_handled to end of poll_in means, socket will 
be added back for polling of new events only _after_ the rpc is msg is 
processed by higher layers (like EC) and higher layers can have significant 
latency  for processing the msg. Which means, socket will be out of polling for 
longer periods of time which decreases the throughput (number of msgs read per 
second) affecting performance. However, this experiment definitely indicates 
there is a codepath whe

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok, I am clear now.
I’ve added ssl_free in socket reset and socket finish function, though 
glusterfsd memory leak is not that much, still it is leaking, from source code 
I can not find anything else,
Could you help to check if this issue exists in your env? If not I may have a 
try to merge your patch .
Step

1>   while true;do gluster v heal  info,

2>   check the vol-name glusterfsd memory usage, it is obviously increasing.
cynthia

From: Milind Changire 
Sent: Monday, April 22, 2019 2:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

According to BIO_new_socket() man page ...

If the close flag is set then the socket is shut down and closed when the BIO 
is freed.

For Gluster to have more control over the socket shutdown, the BIO_NOCLOSE flag 
is set. Otherwise, SSL takes control of socket shutdown whenever BIO is freed.

___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok ,another question, why priv->ssl_sbio = BIO_new_socket(priv->sock, 
BIO_NOCLOSE); use NOCLOSE mode instead of BIO_CLOSE?

cynthia

From: Milind Changire 
Sent: Monday, April 22, 2019 2:21 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

Looks like using BIO_free() is not right. Here's what the SSL_set_bio() man 
page says ...

SSL_set_bio() is similar to SSL_set0_rbio() and SSL_set0_wbio() except that it 
connects both the rbio and the wbio at the same time, and transfers the 
ownership of rbio and wbio to ssl according to the following set of rules:

So, I think you were right about SSL_free() doing the job for the bio. However, 
SSL_free() has no reason to set the priv->ssl_sbio pointer to NULL. I think 
priv->ssl_sbio should be set to NULL immediately after the call to 
SSL_set_bio() is successful. And we need to add a comment while setting 
priv->ssl_sbio to NULL that the ownership of the bio has now been transferred 
to SSL and SSL will free the related memory appropriately.



On Mon, Apr 22, 2019 at 11:37 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I tried to print priv->ssl_sbio after SSL_free() find this pointer is not null, 
so I add free ssl_sbio with BIO_free, however this cause glusterfd coredump
(gdb) bt
#0  0x7f3047867f9b in raise () from /lib64/libc.so.6
#1  0x7f3047869351 in abort () from /lib64/libc.so.6
#2  0x7f30478aa8c7 in __libc_message () from /lib64/libc.so.6
#3  0x7f30478b0e6a in malloc_printerr () from /lib64/libc.so.6
#4  0x7f30478b2835 in _int_free () from /lib64/libc.so.6
#5  0x7f3047c5bbbd in CRYPTO_free () from /lib64/libcrypto.so.10
#6  0x7f3047d07582 in BIO_free () from /lib64/libcrypto.so.10
#7  0x7f3043f9ba4b in __socket_reset (this=0x7f303c1ae710) at socket.c:1032
#8  0x7f3043f9c4aa in socket_event_poll_err (this=0x7f303c1ae710, gen=1, 
idx=17) at socket.c:1232
#9  0x7f3043fa1b7d in socket_event_handler (fd=26, idx=17, gen=1, 
data=0x7f303c1ae710, poll_in=1, poll_out=0, poll_err=0) at socket.c:2669
#10 0x7f3049307984 in event_dispatch_epoll_handler (event_pool=0x1035610, 
event=0x7f3043b14e84) at event-epoll.c:587
#11 0x7f3049307c5b in event_dispatch_epoll_worker (data=0x107e3e0) at 
event-epoll.c:663
#12 0x7f30480535da in start_thread () from /lib64/libpthread.so.0
#13 0x7f3047929eaf in clone () from /lib64/libc.so.6

@@ -1019,7 +1019,20 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+gf_log(this->name, GF_LOG_INFO,"priv->ssl_sbio of socket(%d)is %p 
",priv->sock,priv->ssl_sbio);
+ if(priv->ssl_sbio != NULL)
+ BIO_free(priv->ssl_sbio);
+priv->ssl_ssl = NULL;
+ priv->ssl_sbio = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4251,20 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+ gf_log(this->name, GF_LOG_INFO,"priv->ssl_sbio of socket(%d)is %p 
",priv->sock,priv->ssl_sbio);
+if(priv->ssl_sbio != NULL)
+BIO_free(priv->ssl_sbio);
+priv->ssl_ssl = NULL;
+     priv->ssl_sbio = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);


From: Milind Changire mailto:mchan...@redhat.com>>
Sent: Monday, April 22, 2019 1:35 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Atin Mukherjee mailto:amukh...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

This probably went unnoticed until now.



On Mon, Apr 22, 2019 at 10:45 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Why there is no bio_free called in ssl_teardown_connection then?

cynthia

From: Milind Changire mailto:mchan...@redhat.com>>
Sent: Monday, April 22, 2019 10:21 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sb

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

I do some google. Seems it is not needed to call BIO_free, SSL_free will free 
bio.

https://groups.google.com/forum/#!topic/mailing.openssl.users/8i9cRQGlfDM
From: Milind Changire 
Sent: Monday, April 22, 2019 1:35 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

This probably went unnoticed until now.



On Mon, Apr 22, 2019 at 10:45 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Why there is no bio_free called in ssl_teardown_connection then?

Cynthia

From: Milind Changire mailto:mchan...@redhat.com>>
Sent: Monday, April 22, 2019 10:21 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Atin Mukherjee mailto:amukh...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

After patch 22334<https://review.gluster.org/c/glusterfs/+/22334>, the 
priv->ssl_ctx is now maintained per socket connection and is no longer shared.
So you might want to SSL_free(priv->ssl_ctx) as well and set priv->ssl_ctx to 
NULL.

There might be some strings that are duplicated (gf_strdup()) via the 
socket_init() code path. Please take a look at those as well.

Sorry about that. I missed it.


On Mon, Apr 22, 2019 at 7:25 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:

Hi,
From my code study it seems priv->ssl_ssl is not properly released, I made a 
patch and the glusterfsd memory leak is alleviated with my patch, but some 
otherwhere is still leaking, I have no clue about the other leak points.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4250,16 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+    SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);
 }


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:31 PM
To: 'Atin Mukherjee' mailto:amukh...@redhat.com>>
Cc: 'Raghavendra Gowdappa' mailto:rgowd...@redhat.com>>; 
'gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>' 
mailto:gluster-devel@gluster.org>>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

We scan it use memory-leak tool, there are following prints. We doubt some open 
ssl lib malloc is is not properly freed by glusterfs code.
er+0x2af [libglusterfs.so.0.0.1]\n\t\tstart_thread+0xda 
[libpthread-2.27.so<http://libpthread-2.27.so>]'
13580 bytes in 175 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]'
232904 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
[15:41:56] Top 10 stacks with outstanding allocations:
8792 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
9408 bytes in 42 allocations from stack
b'CRYPTO_realloc+0x4d [libcrypto.so.1.0.2p]'
9723 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
10696 bytes in 21 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11319 bytes in 602 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11431 bytes in 518 allocations from stack
    b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11704 bytes in 371 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'


cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:25 PM
To: 'Atin Mukherjee' mailto:amuk

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

I tried to print priv->ssl_sbio after SSL_free() find this pointer is not null, 
so I add free ssl_sbio with BIO_free, however this cause glusterfd coredump
(gdb) bt
#0  0x7f3047867f9b in raise () from /lib64/libc.so.6
#1  0x7f3047869351 in abort () from /lib64/libc.so.6
#2  0x7f30478aa8c7 in __libc_message () from /lib64/libc.so.6
#3  0x7f30478b0e6a in malloc_printerr () from /lib64/libc.so.6
#4  0x7f30478b2835 in _int_free () from /lib64/libc.so.6
#5  0x7f3047c5bbbd in CRYPTO_free () from /lib64/libcrypto.so.10
#6  0x7f3047d07582 in BIO_free () from /lib64/libcrypto.so.10
#7  0x7f3043f9ba4b in __socket_reset (this=0x7f303c1ae710) at socket.c:1032
#8  0x7f3043f9c4aa in socket_event_poll_err (this=0x7f303c1ae710, gen=1, 
idx=17) at socket.c:1232
#9  0x7f3043fa1b7d in socket_event_handler (fd=26, idx=17, gen=1, 
data=0x7f303c1ae710, poll_in=1, poll_out=0, poll_err=0) at socket.c:2669
#10 0x7f3049307984 in event_dispatch_epoll_handler (event_pool=0x1035610, 
event=0x7f3043b14e84) at event-epoll.c:587
#11 0x7f3049307c5b in event_dispatch_epoll_worker (data=0x107e3e0) at 
event-epoll.c:663
#12 0x7f30480535da in start_thread () from /lib64/libpthread.so.0
#13 0x7f3047929eaf in clone () from /lib64/libc.so.6

@@ -1019,7 +1019,20 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+gf_log(this->name, GF_LOG_INFO,"priv->ssl_sbio of socket(%d)is %p 
",priv->sock,priv->ssl_sbio);
+ if(priv->ssl_sbio != NULL)
+ BIO_free(priv->ssl_sbio);
+priv->ssl_ssl = NULL;
+ priv->ssl_sbio = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4251,20 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_INFO,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+ gf_log(this->name, GF_LOG_INFO,"priv->ssl_sbio of socket(%d)is %p 
",priv->sock,priv->ssl_sbio);
+if(priv->ssl_sbio != NULL)
+BIO_free(priv->ssl_sbio);
+priv->ssl_ssl = NULL;
+     priv->ssl_sbio = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);


From: Milind Changire 
Sent: Monday, April 22, 2019 1:35 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

This probably went unnoticed until now.



On Mon, Apr 22, 2019 at 10:45 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Why there is no bio_free called in ssl_teardown_connection then?

cynthia

From: Milind Changire mailto:mchan...@redhat.com>>
Sent: Monday, April 22, 2019 10:21 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Atin Mukherjee mailto:amukh...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

After patch 22334<https://review.gluster.org/c/glusterfs/+/22334>, the 
priv->ssl_ctx is now maintained per socket connection and is no longer shared.
So you might want to SSL_free(priv->ssl_ctx) as well and set priv->ssl_ctx to 
NULL.

There might be some strings that are duplicated (gf_strdup()) via the 
socket_init() code path. Please take a look at those as well.

Sorry about that. I missed it.


On Mon, Apr 22, 2019 at 7:25 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:

Hi,
From my code study it seems priv->ssl_ssl is not properly released, I made a 
patch and the glusterfsd memory leak is alleviated with my patch, but some 
otherwhere is still leaking, I have no clue about the other leak points.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Thanks for your quick responding!
My test env is without patch 22334, so priv->ssl_ctx is shared one. In 
socket_reset there is no need to free it. but if with patch 22334, it is 
absolutely needed to free priv->ssl_ctx as well.
Following is the log captured from glusterfsd side while connection 
establishment, when accept returns, a new  new_trans is allocated, and the 
socket_init input param is this new_trans, because this new_trans has no option 
now, so in socket_init   ssl_setup_connection_params is not called, so there 
should be no malloc done here, as showed from following log, 
ssl_setup_connection_params is called in socket_event_handler, and here the 
ssl_ctx had been assigned to the shared one.
This issue is very easy to reproduce in my env, just “while true; do gluster v 
heal  info;done” and check the memory of the corresponding glusterfsd 
, it is very obvious increase.

One more thing to confirm is that there is no need to free the ssl_sbio right? 
Ssl_free will handle it and just call ssl_free is enough?


[2019-04-21 05:02:17.820346] T [socket.c:2776:socket_server_event_handler] 
0-tcp.ccs-server: XXX server:192.168.1.13:53952, client:192.168.1.13:63683
[2019-04-21 05:02:17.820370] T [socket.c:2820:socket_server_event_handler] 
0-tcp.ccs-server: ### use non-blocking IO
[2019-04-21 05:02:17.820410] T [socket.c:2603:socket_event_handler] 
0-tcp.ccs-server: server (sock:126) in:1, out:0, err:0
[2019-04-21 05:02:17.820431] T [socket.c:2610:socket_event_handler] 
0-tcp.ccs-server: server (sock:126) socket is not connected, completing 
connection
[2019-04-21 05:02:17.820442] T [socket.c:3829:ssl_setup_connection_params] 
0-tcp.ccs-server: found old SSL context!   // context is shared between 
listening socket and accepted socket
[2019-04-21 05:02:17.820451] T [socket.c:310:ssl_setup_connection_prefix] 
0-tcp.ccs-server: + ssl_setup_connection_params() done!
[2019-04-21 05:02:17.822559] T [socket.c:2617:socket_event_handler] 
0-tcp.ccs-server: (sock:126) socket_complete_connection() returned 1
[2019-04-21 05:02:17.822585] T [socket.c:2621:socket_event_handler] 
0-tcp.ccs-server: (sock:126) returning to wait on socket
[2019-04-21 05:02:17.828455] T [socket.c:2603:socket_event_handler] 
0-tcp.ccs-server: server (sock:126) in:1, out:0, err:0
[2019-04-21 05:02:17.828483] T [socket.c:2610:socket_event_handler] 
0-tcp.ccs-server: server (sock:126) socket is not connected, completing 
connection
[2019-04-21 05:02:17.829130] D [socket.c:366:ssl_setup_connection_postfix] 
0-tcp.ccs-server: peer CN = example ee certificate
[2019-04-21 05:02:17.829157] D [socket.c:369:ssl_setup_connection_postfix] 
0-tcp.ccs-server: SSL verification succeeded (client: 192.168.1.13:63683) 
(server: 192.168.1.13:53952)
[2019-04-21 05:02:17.829171] T [socket.c:423:ssl_complete_connection] 
0-tcp.ccs-server: ssl_accepted!
[2019-04-21 05:02:17.829183] T [socket.c:2617:socket_event_handler] 
0-tcp.ccs-server: (sock:126) socket_complete_connection() returned 1
[2019-04-21 05:02:17.829192] T [socket.c:2621:socket_event_handler] 
0-tcp.ccs-server: (sock:126) returning to wait on socket
[2019-04-21 05:02:17.829261] T [socket.c:2603:socket_event_handler] 
0-tcp.ccs-server: server (sock:126) in:1, out:0, err:0
[2019-04-21 05:02:17.829282] T [socket.c:2628:socket_event_handler] 
0-tcp.ccs-server: Server socket (126) is already connected
[2019-04-21 05:02:17.829294] T [socket.c:493:__socket_ssl_readv] 
0-tcp.ccs-server: * reading over SSL
[2019-04-21 05:02:17.829311] T [socket.c:493:__socket_ssl_readv] 
0-tcp.ccs-server: * reading over SSL
[2019-04-21 05:02:17.829337] T [socket.c:493:__socket_ssl_readv] 
0-tcp.ccs-server: * reading over SSL


cynthia
From: Milind Changire 
Sent: Monday, April 22, 2019 10:21 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

After patch 22334<https://review.gluster.org/c/glusterfs/+/22334>, the 
priv->ssl_ctx is now maintained per socket connection and is no longer shared.
So you might want to SSL_free(priv->ssl_ctx) as well and set priv->ssl_ctx to 
NULL.

There might be some strings that are duplicated (gf_strdup()) via the 
socket_init() code path. Please take a look at those as well.

Sorry about that. I missed it.


On Mon, Apr 22, 2019 at 7:25 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:

Hi,
From my code study it seems priv->ssl_ssl is not properly released, I made a 
patch and the glusterfsd memory leak is alleviated with my patch, but some 
otherwhere is still leaking, I have no clue about the other leak points.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->s

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok, I will post it later.

cynthia

From: Raghavendra Gowdappa 
Sent: Monday, April 22, 2019 10:09 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Atin Mukherjee ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Mon, Apr 22, 2019 at 7:18 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:

Hi,
From my code study it seems priv->ssl_ssl is not properly released, I made a 
patch and the glusterfsd memory leak is alleviated with my patch,

This is a legitimate leak. Can you post a patch to gerrit?

but some otherwhere is still leaking, I have no clue about the other leak 
points.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4250,16 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);
 }


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:31 PM
To: 'Atin Mukherjee' mailto:amukh...@redhat.com>>
Cc: 'Raghavendra Gowdappa' mailto:rgowd...@redhat.com>>; 
'gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>' 
mailto:gluster-devel@gluster.org>>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

We scan it use memory-leak tool, there are following prints. We doubt some open 
ssl lib malloc is is not properly freed by glusterfs code.
er+0x2af [libglusterfs.so.0.0.1]\n\t\tstart_thread+0xda 
[libpthread-2.27.so<http://libpthread-2.27.so>]'
13580 bytes in 175 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]'
232904 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
[15:41:56] Top 10 stacks with outstanding allocations:
8792 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
9408 bytes in 42 allocations from stack
b'CRYPTO_realloc+0x4d [libcrypto.so.1.0.2p]'
9723 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
10696 bytes in 21 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11319 bytes in 602 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11431 bytes in 518 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11704 bytes in 371 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'


cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:25 PM
To: 'Atin Mukherjee' mailto:amukh...@redhat.com>>
Cc: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

I’ve test on glusterfs3.12.15 and glusterfs5.5 all have this issue, after 
enable tls ssl socket, when execute gluster v heal  info, will 
trigger glfshel to connect glusterfsd process, and cause glusterfsd process 
memory leak. Could you please try in your env?

cynthia


From: Atin Mukherjee mailto:amukh...@redhat.com>>
Sent: Thursday, April 18, 2019 1:19 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, 17 Apr 2019 at 10:53, Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
In my recent test, I found 

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
From my code study it seems priv->ssl_ssl is not properly released, I made a 
patch and the glusterfsd memory leak is alleviated with my patch, but some 
otherwhere is still leaking, I have no clue about the other leak points.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -1019,7 +1019,16 @@ static void __socket_reset(rpc_transport_t *this) {
   memset(>incoming, 0, sizeof(priv->incoming));
   event_unregister_close(this->ctx->event_pool, priv->sock, priv->idx);
-
+  if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+priv->ssl_ssl = NULL;
+  }
   priv->sock = -1;
   priv->idx = -1;
   priv->connected = -1;
@@ -4238,6 +4250,16 @@ void fini(rpc_transport_t *this) {
 pthread_mutex_destroy(>out_lock);
 pthread_mutex_destroy(>cond_lock);
 pthread_cond_destroy(>cond);
+ if(priv->use_ssl&& priv->ssl_ssl)
+  {
+gf_log(this->name, GF_LOG_TRACE,
+   "clear and reset for socket(%d), free ssl ",
+   priv->sock);
+SSL_shutdown(priv->ssl_ssl);
+SSL_clear(priv->ssl_ssl);
+SSL_free(priv->ssl_ssl);
+    priv->ssl_ssl = NULL;
+  }
 if (priv->ssl_private_key) {
   GF_FREE(priv->ssl_private_key);
 }


From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:31 PM
To: 'Atin Mukherjee' 
Cc: 'Raghavendra Gowdappa' ; 'gluster-devel@gluster.org' 

Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

We scan it use memory-leak tool, there are following prints. We doubt some open 
ssl lib malloc is is not properly freed by glusterfs code.
er+0x2af [libglusterfs.so.0.0.1]\n\t\tstart_thread+0xda [libpthread-2.27.so]'
13580 bytes in 175 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]'
232904 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
[15:41:56] Top 10 stacks with outstanding allocations:
8792 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
9408 bytes in 42 allocations from stack
b'CRYPTO_realloc+0x4d [libcrypto.so.1.0.2p]'
9723 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
10696 bytes in 21 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11319 bytes in 602 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11431 bytes in 518 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11704 bytes in 371 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'


cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:25 PM
To: 'Atin Mukherjee' mailto:amukh...@redhat.com>>
Cc: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

I’ve test on glusterfs3.12.15 and glusterfs5.5 all have this issue, after 
enable tls ssl socket, when execute gluster v heal  info, will 
trigger glfshel to connect glusterfsd process, and cause glusterfsd process 
memory leak. Could you please try in your env?

cynthia


From: Atin Mukherjee mailto:amukh...@redhat.com>>
Sent: Thursday, April 18, 2019 1:19 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, 17 Apr 2019 at 10:53, Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
In my recent test, I found that there are very severe glusterfsd memory leak 
when enable socket ssl option

What gluster version are you testing? Would you be able to continue your 
investigation and share the root cause?

--
- Atin (atinm)
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

We scan it use memory-leak tool, there are following prints. We doubt some open 
ssl lib malloc is is not properly freed by glusterfs code.
er+0x2af [libglusterfs.so.0.0.1]\n\t\tstart_thread+0xda [libpthread-2.27.so]'
13580 bytes in 175 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]'
232904 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
[15:41:56] Top 10 stacks with outstanding allocations:
8792 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
9408 bytes in 42 allocations from stack
b'CRYPTO_realloc+0x4d [libcrypto.so.1.0.2p]'
9723 bytes in 14 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
10696 bytes in 21 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11319 bytes in 602 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11431 bytes in 518 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'
11704 bytes in 371 allocations from stack
b'CRYPTO_malloc+0x58 [libcrypto.so.1.0.2p]\n\t\t[unknown]'


cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, April 18, 2019 5:25 PM
To: 'Atin Mukherjee' 
Cc: Raghavendra Gowdappa ; gluster-devel@gluster.org
Subject: RE: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

I’ve test on glusterfs3.12.15 and glusterfs5.5 all have this issue, after 
enable tls ssl socket, when execute gluster v heal  info, will 
trigger glfshel to connect glusterfsd process, and cause glusterfsd process 
memory leak. Could you please try in your env?

cynthia


From: Atin Mukherjee mailto:amukh...@redhat.com>>
Sent: Thursday, April 18, 2019 1:19 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, 17 Apr 2019 at 10:53, Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
In my recent test, I found that there are very severe glusterfsd memory leak 
when enable socket ssl option

What gluster version are you testing? Would you be able to continue your 
investigation and share the root cause?

--
- Atin (atinm)
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

I’ve test on glusterfs3.12.15 and glusterfs5.5 all have this issue, after 
enable tls ssl socket, when execute gluster v heal  info, will 
trigger glfshel to connect glusterfsd process, and cause glusterfsd process 
memory leak. Could you please try in your env?

cynthia


From: Atin Mukherjee 
Sent: Thursday, April 18, 2019 1:19 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: Raghavendra Gowdappa ; gluster-devel@gluster.org
Subject: Re: [Gluster-devel] glusterfsd memory leak issue found after enable ssl



On Wed, 17 Apr 2019 at 10:53, Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
In my recent test, I found that there are very severe glusterfsd memory leak 
when enable socket ssl option

What gluster version are you testing? Would you be able to continue your 
investigation and share the root cause?

--
- Atin (atinm)
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

[Gluster-devel] glusterfsd memory leak issue found after enable ssl

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
In my recent test, I found that there are very severe glusterfsd memory leak 
when enable socket ssl option.
If I monitor glusterfsd process RSS with command:  pidstat -r -p  1
And at the same tme, execute command: gluster v heal  info, i find that 
the RSS keep increasing until system Out of memory.
I have tried even with latest glusterfs5.5 version, this issue still exists,
Have you any idea about this issue?

The config in my env:
[root@mn-0:/var/lib/glusterd]
# gluster v info ccs
Volume Name: ccs
Type: Replicate
Volume ID: b565c958-2fef-4a39-811b-adce67aab20b
Status: Started
Snapshot Count: 0
Number of Bricks: 1 x 3 = 3
Transport-type: tcp
Bricks:
Brick1: mn-0.local:/mnt/bricks/ccs/brick
Brick2: mn-1.local:/mnt/bricks/ccs/brick
Brick3: dbm-0.local:/mnt/bricks/ccs/brick
Options Reconfigured:
nfs.disable: on
transport.address-family: inet
cluster.server-quorum-type: none
cluster.quorum-reads: no
ssl.private-key: /var/opt/nokia/certs/glusterfs/glusterfs.key
cluster.favorite-child-policy: mtime
cluster.consistent-metadata: on
network.ping-timeout: 42
cluster.quorum-type: auto
server.allow-insecure: on
server.ssl: on
ssl.own-cert: /var/opt/nokia/certs/glusterfs/glusterfs.pem
ssl.ca-list: /var/opt/nokia/certs/glusterfs/glusterfs.ca
client.ssl: on
performance.client-io-threads: off
cluster.server-quorum-ratio: 51%
[root@mn-0:/var/lib/glusterd]
#
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok, I got your point, thanks for responding!

cynthia

From: Raghavendra Gowdappa 
Sent: Monday, April 15, 2019 4:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: gluster-devel@gluster.org
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 15, 2019 at 12:52 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
The reason why I move event_handled to the end of socket_event_poll_in is 
because if event_handled is called before rpc_transport_pollin_destroy, it 
allowed another round of event_dispatch_epoll_handler happen before  
rpc_transport_pollin_destroy, in this way, when the latter poll in goes to 
rpc_transport_pollin_destroy , there is a chance that the pollin->iobref has 
already been destroyed by the first one(there is no lock destroy for 
iobref->lock in iobref_destroy by the way). That may cause stuck in “LOCK 
(>lock);”
I find the one of recent patch
SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket

I think the point is to avoid the concurrent handling of the same socket at the 
same time, but after my test with this patch this problem also exists, so I 
think event_handled is still called too early to allow concurrent handling of 
the same socket happen,

But concurrent handling is required for performance. So, we cannot serialize it.

and after move it to the end of socket_event_poll this glusterd stuck issue 
disappeared.

Ideally there shouldn't be a single instance of datastructure that should be 
shared between two instances of pollin handling. My initial code-reading didn't 
find any issues with the way iobref is handled even when there is concurrent 
reading when the previous message was still not notified. I'll continue to 
investigate how objects are shared across two instances of pollin. Will post if 
I find anything interesting.

cynthia
From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Monday, April 15, 2019 2:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 15, 2019 at 11:08 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, thanks for your comment!

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Monday, April 15, 2019 11:52 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15

Cynthia,

On Mon, Apr 15, 2019 at 8:10 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
I made a patch and according to my test, this glusterd stuck issue disappear 
with my patch. Only need to move  event_handled to the end of 
socket_event_poll_in function.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -2305,9 +2305,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }

-if (notify_handled && (ret != -1))
-event_handled (ctx->event_pool, priv->sock, priv->idx,
-   priv->gen);
@@ -2330,6 +2327,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }
 pthread_mutex_unlock (>notify.lock);
 }
+if (notify_handled && (ret != -1))
+event_handled (ctx->event_pool, priv->sock, priv->idx,
+   priv->gen);

Thanks for this tip. Though this helps in fixing the hang, this change has 
performance impact. Moving event_handled to end of poll_in means, socket will 
be added back for polling of new events only _after_ the rpc is msg is 
processed by higher layers (like EC) and higher layers can have significant 
latency  for processing the msg. Which means, socket will be out of polling for 
longer periods of time which decreases the throughput (number of msgs read per 
second) affecting performance. However, this experiment definitely indicates 
there is a codepath where event_handled is not called (and hence causing the 
hang). I'll go through this codepath again.

Can you check whether patch [1] fixes the issue you are seeing?

[1] https://review.gluster.org/#/c/glusterfs/+/22566


Thanks for that experiment :).

 return ret;
}

cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Tuesday, April 09, 2019 3:57 PM
To: 'Raghavendra Gowdappa' mailto:rgowd...@redhat.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: RE: glusterd stuck for glusterfs with version 3.12.15

Can you figure out some possible reason why iobref is corrupted, is it possible 
that thread 8 has called poll in an

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
The reason why I move event_handled to the end of socket_event_poll_in is 
because if event_handled is called before rpc_transport_pollin_destroy, it 
allowed another round of event_dispatch_epoll_handler happen before  
rpc_transport_pollin_destroy, in this way, when the latter poll in goes to 
rpc_transport_pollin_destroy , there is a chance that the pollin->iobref has 
already been destroyed by the first one(there is no lock destroy for 
iobref->lock in iobref_destroy by the way). That may cause stuck in “LOCK 
(>lock);”
I find the one of recent patch
SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket

I think the point is to avoid the concurrent handling of the same socket at the 
same time, but after my test with this patch this problem also exists, so I 
think event_handled is still called too early to allow concurrent handling of 
the same socket happen, and after move it to the end of socket_event_poll this 
glusterd stuck issue disappeared.
cynthia
From: Raghavendra Gowdappa 
Sent: Monday, April 15, 2019 2:36 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: gluster-devel@gluster.org
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 15, 2019 at 11:08 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Ok, thanks for your comment!

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Monday, April 15, 2019 11:52 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15

Cynthia,

On Mon, Apr 15, 2019 at 8:10 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
I made a patch and according to my test, this glusterd stuck issue disappear 
with my patch. Only need to move  event_handled to the end of 
socket_event_poll_in function.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -2305,9 +2305,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }

-if (notify_handled && (ret != -1))
-event_handled (ctx->event_pool, priv->sock, priv->idx,
-   priv->gen);
@@ -2330,6 +2327,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }
 pthread_mutex_unlock (>notify.lock);
 }
+if (notify_handled && (ret != -1))
+event_handled (ctx->event_pool, priv->sock, priv->idx,
+   priv->gen);

Thanks for this tip. Though this helps in fixing the hang, this change has 
performance impact. Moving event_handled to end of poll_in means, socket will 
be added back for polling of new events only _after_ the rpc is msg is 
processed by higher layers (like EC) and higher layers can have significant 
latency  for processing the msg. Which means, socket will be out of polling for 
longer periods of time which decreases the throughput (number of msgs read per 
second) affecting performance. However, this experiment definitely indicates 
there is a codepath where event_handled is not called (and hence causing the 
hang). I'll go through this codepath again.

Can you check whether patch [1] fixes the issue you are seeing?

[1] https://review.gluster.org/#/c/glusterfs/+/22566


Thanks for that experiment :).

 return ret;
}

cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Tuesday, April 09, 2019 3:57 PM
To: 'Raghavendra Gowdappa' mailto:rgowd...@redhat.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: RE: glusterd stuck for glusterfs with version 3.12.15

Can you figure out some possible reason why iobref is corrupted, is it possible 
that thread 8 has called poll in and iobref has been relased, but the lock 
within it is not properly released (as I can not find any free lock operation 
in iobref_destroy), then thread 9 called rpc_transport_pollin_destroy again, 
and so stuck on this lock
Also, there should not be two thread handling the same socket at the same time, 
although there has been a patch claimed to tackle this issue.

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Tuesday, April 09, 2019 3:52 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 8, 2019 at 7:42 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs experts,
Good day!
In my test env, sometimes glusterd stuck issue happened, and it is not 
responding to any gluster commands, when I checked this issue I find that 
gluster

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Ok, thanks for your comment!

cynthia

From: Raghavendra Gowdappa 
Sent: Monday, April 15, 2019 11:52 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: gluster-devel@gluster.org
Subject: Re: glusterd stuck for glusterfs with version 3.12.15

Cynthia,

On Mon, Apr 15, 2019 at 8:10 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
I made a patch and according to my test, this glusterd stuck issue disappear 
with my patch. Only need to move  event_handled to the end of 
socket_event_poll_in function.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -2305,9 +2305,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }

-if (notify_handled && (ret != -1))
-event_handled (ctx->event_pool, priv->sock, priv->idx,
-   priv->gen);
@@ -2330,6 +2327,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }
 pthread_mutex_unlock (>notify.lock);
 }
+if (notify_handled && (ret != -1))
+event_handled (ctx->event_pool, priv->sock, priv->idx,
+   priv->gen);

Thanks for this tip. Though this helps in fixing the hang, this change has 
performance impact. Moving event_handled to end of poll_in means, socket will 
be added back for polling of new events only _after_ the rpc is msg is 
processed by higher layers (like EC) and higher layers can have significant 
latency  for processing the msg. Which means, socket will be out of polling for 
longer periods of time which decreases the throughput (number of msgs read per 
second) affecting performance. However, this experiment definitely indicates 
there is a codepath where event_handled is not called (and hence causing the 
hang). I'll go through this codepath again.

Thanks for that experiment :).

         return ret;
}

cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Tuesday, April 09, 2019 3:57 PM
To: 'Raghavendra Gowdappa' mailto:rgowd...@redhat.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: RE: glusterd stuck for glusterfs with version 3.12.15

Can you figure out some possible reason why iobref is corrupted, is it possible 
that thread 8 has called poll in and iobref has been relased, but the lock 
within it is not properly released (as I can not find any free lock operation 
in iobref_destroy), then thread 9 called rpc_transport_pollin_destroy again, 
and so stuck on this lock
Also, there should not be two thread handling the same socket at the same time, 
although there has been a patch claimed to tackle this issue.

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Tuesday, April 09, 2019 3:52 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 8, 2019 at 7:42 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs experts,
Good day!
In my test env, sometimes glusterd stuck issue happened, and it is not 
responding to any gluster commands, when I checked this issue I find that 
glusterd thread 9 and thread 8 is dealing with the same socket, I thought 
following patch should be able to solve this issue, however after I merged this 
patch this issue still exist. When I looked into this code, it seems 
socket_event_poll_in called event_handled before rpc_transport_pollin_destroy, 
I think this gives the chance for another poll for the exactly the same socket. 
And caused this glusterd stuck issue, also, I find there is no   
LOCK_DESTROY(>lock)
In iobref_destroy, I think it is better to add destroy lock.
Following is the gdb info when this issue happened, I would like to know your 
opinion on this issue, thanks!

SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket



GDB INFO:
Thread 8 is blocked on pthread_cond_wait, and thread 9 is blocked in 
iobref_unref, I think
Thread 9 (Thread 0x7f9edf7fe700 (LWP 1933)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epol

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
I made a patch and according to my test, this glusterd stuck issue disappear 
with my patch. Only need to move  event_handled to the end of 
socket_event_poll_in function.

--- a/rpc/rpc-transport/socket/src/socket.c
+++ b/rpc/rpc-transport/socket/src/socket.c
@@ -2305,9 +2305,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }

-if (notify_handled && (ret != -1))
-event_handled (ctx->event_pool, priv->sock, priv->idx,
-   priv->gen);
@@ -2330,6 +2327,9 @@ socket_event_poll_in (rpc_transport_t *this, gf_boolean_t 
notify_handled)
 }
 pthread_mutex_unlock (>notify.lock);
 }
+if (notify_handled && (ret != -1))
+event_handled (ctx->event_pool, priv->sock, priv->idx,
+   priv->gen);
     return ret;
}

cynthia
From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Tuesday, April 09, 2019 3:57 PM
To: 'Raghavendra Gowdappa' 
Cc: gluster-devel@gluster.org
Subject: RE: glusterd stuck for glusterfs with version 3.12.15

Can you figure out some possible reason why iobref is corrupted, is it possible 
that thread 8 has called poll in and iobref has been relased, but the lock 
within it is not properly released (as I can not find any free lock operation 
in iobref_destroy), then thread 9 called rpc_transport_pollin_destroy again, 
and so stuck on this lock
Also, there should not be two thread handling the same socket at the same time, 
although there has been a patch claimed to tackle this issue.

cynthia

From: Raghavendra Gowdappa mailto:rgowd...@redhat.com>>
Sent: Tuesday, April 09, 2019 3:52 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 8, 2019 at 7:42 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs experts,
Good day!
In my test env, sometimes glusterd stuck issue happened, and it is not 
responding to any gluster commands, when I checked this issue I find that 
glusterd thread 9 and thread 8 is dealing with the same socket, I thought 
following patch should be able to solve this issue, however after I merged this 
patch this issue still exist. When I looked into this code, it seems 
socket_event_poll_in called event_handled before rpc_transport_pollin_destroy, 
I think this gives the chance for another poll for the exactly the same socket. 
And caused this glusterd stuck issue, also, I find there is no   
LOCK_DESTROY(>lock)
In iobref_destroy, I think it is better to add destroy lock.
Following is the gdb info when this issue happened, I would like to know your 
opinion on this issue, thanks!

SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket



GDB INFO:
Thread 8 is blocked on pthread_cond_wait, and thread 9 is blocked in 
iobref_unref, I think
Thread 9 (Thread 0x7f9edf7fe700 (LWP 1933)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 8 (Thread 0x7f9ed700 (LWP 1932)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fd2b42 in __pthread_mutex_cond_lock () from 
/lib64/libpthread.so.0
#2  0x7f9ee9fd44a8 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#3  0x7f9ee4fbadab in socket_event_poll_err (this=0x7f9ed0049cc0, gen=4, 
idx=27) at socket.c:1201
#4  0x7f9ee4fbf99c in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2480
#5  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edfffee84) at event-epoll.c:583
#6  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180cf20) at 
event-epoll.c:659
#7  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#8  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

(gdb) thread 9
[Switching 

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Can you figure out some possible reason why iobref is corrupted, is it possible 
that thread 8 has called poll in and iobref has been relased, but the lock 
within it is not properly released (as I can not find any free lock operation 
in iobref_destroy), then thread 9 called rpc_transport_pollin_destroy again, 
and so stuck on this lock
Also, there should not be two thread handling the same socket at the same time, 
although there has been a patch claimed to tackle this issue.

cynthia

From: Raghavendra Gowdappa 
Sent: Tuesday, April 09, 2019 3:52 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Cc: gluster-devel@gluster.org
Subject: Re: glusterd stuck for glusterfs with version 3.12.15



On Mon, Apr 8, 2019 at 7:42 AM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs experts,
Good day!
In my test env, sometimes glusterd stuck issue happened, and it is not 
responding to any gluster commands, when I checked this issue I find that 
glusterd thread 9 and thread 8 is dealing with the same socket, I thought 
following patch should be able to solve this issue, however after I merged this 
patch this issue still exist. When I looked into this code, it seems 
socket_event_poll_in called event_handled before rpc_transport_pollin_destroy, 
I think this gives the chance for another poll for the exactly the same socket. 
And caused this glusterd stuck issue, also, I find there is no   
LOCK_DESTROY(>lock)
In iobref_destroy, I think it is better to add destroy lock.
Following is the gdb info when this issue happened, I would like to know your 
opinion on this issue, thanks!

SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket



GDB INFO:
Thread 8 is blocked on pthread_cond_wait, and thread 9 is blocked in 
iobref_unref, I think
Thread 9 (Thread 0x7f9edf7fe700 (LWP 1933)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 8 (Thread 0x7f9ed700 (LWP 1932)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fd2b42 in __pthread_mutex_cond_lock () from 
/lib64/libpthread.so.0
#2  0x7f9ee9fd44a8 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#3  0x7f9ee4fbadab in socket_event_poll_err (this=0x7f9ed0049cc0, gen=4, 
idx=27) at socket.c:1201
#4  0x7f9ee4fbf99c in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2480
#5  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edfffee84) at event-epoll.c:583
#6  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180cf20) at 
event-epoll.c:659
#7  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#8  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

(gdb) thread 9
[Switching to thread 9 (Thread 0x7f9edf7fe700 (LWP 1933))]
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) bt
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6
(gdb) frame 2
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
944 iobuf.c: No such file or directory.
(gdb) print *iobref
$1 = {lock = {spinlock = 2, mutex = {__data = {__lock = 2

Re: [Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
The env is not there anymore, but I have collected the thread stack trace of 
glusterd with command “thread apply all bt”
Using host libthread_db library "/lib64/libthread_db.so.1".
0x7f9ee9fcfa3d in __pthread_timedjoin_ex () from /lib64/libpthread.so.0
Missing separate debuginfos, use: dnf debuginfo-install 
rcp-pack-glusterfs-1.12.0_1_gc999db1-RCP2.wf29.x86_64
(gdb) thread apply all bt

Thread 9 (Thread 0x7f9edf7fe700 (LWP 1933)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 8 (Thread 0x7f9ed700 (LWP 1932)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fd2b42 in __pthread_mutex_cond_lock () from 
/lib64/libpthread.so.0
#2  0x7f9ee9fd44a8 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#3  0x7f9ee4fbadab in socket_event_poll_err (this=0x7f9ed0049cc0, gen=4, 
idx=27) at socket.c:1201
#4  0x7f9ee4fbf99c in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2480
#5  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edfffee84) at event-epoll.c:583
#6  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180cf20) at 
event-epoll.c:659
#7  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#8  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 7 (Thread 0x7f9ee49b3700 (LWP 1931)):
#0  0x7f9ee9fd45bc in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#1  0x7f9ee5e651b9 in hooks_worker (args=0x1813000) at glusterd-hooks.c:529
#2  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#3  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 6 (Thread 0x7f9ee692e700 (LWP 1762)):
#0  0x7f9ee9fd497a in pthread_cond_timedwait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#1  0x7f9eeb25d904 in syncenv_task (proc=0x1808e00) at syncop.c:603
#2  0x7f9eeb25db9f in syncenv_processor (thdata=0x1808e00) at syncop.c:695
#3  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#4  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 5 (Thread 0x7f9ee712f700 (LWP 1761)):
---Type  to continue, or q  to quit---
#0  0x7f9ee9fd497a in pthread_cond_timedwait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#1  0x7f9eeb25d904 in syncenv_task (proc=0x1808a40) at syncop.c:603
#2  0x7f9eeb25db9f in syncenv_processor (thdata=0x1808a40) at syncop.c:695
#3  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#4  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 4 (Thread 0x7f9ee7930700 (LWP 1760)):
#0  0x7f9ee98725d0 in nanosleep () from /lib64/libc.so.6
#1  0x7f9ee98724aa in sleep () from /lib64/libc.so.6
#2  0x7f9eeb247fdf in pool_sweeper (arg=0x0) at mem-pool.c:481
#3  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#4  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 3 (Thread 0x7f9ee8131700 (LWP 1759)):
#0  0x7f9ee97e3d7c in sigtimedwait () from /lib64/libc.so.6
#1  0x7f9ee9fd8bac in sigwait () from /lib64/libpthread.so.0
#2  0x00409ed7 in glusterfs_sigwaiter ()
#3  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#4  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 2 (Thread 0x7f9ee8932700 (LWP 1758)):
#0  0x7f9ee9fd83b0 in nanosleep () from /lib64/libpthread.so.0
#1  0x7f9eeb224545 in gf_timer_proc (data=0x1808580) at timer.c:164
#2  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#3  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 1 (Thread 0x7f9eeb707780 (LWP 1757)):
#0  0x7f9ee9fcfa3d in __pthread_timedjoin_ex () from /lib64/libpthread.so.0
#1  0x7f9eeb282b09 in event_dispatch_epoll (event_pool=0x17feb00) at 
event-epoll.c:746
#2  0x7f9eeb246786 in event_dispatch (event_pool=0x17feb00) at event.c:124
#3  0x0040ab95 in main ()
(gdb)
(gdb)
(gdb) q!
A syntax error in expression, near `'.
(gdb) quit

From: Sanju Rakonde 
Sent: Monday, April 08, 2019 4:58 PM
To: Zhou, Cynthia (NSB - CN/Han

[Gluster-devel] glusterd stuck for glusterfs with version 3.12.15

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs experts,
Good day!
In my test env, sometimes glusterd stuck issue happened, and it is not 
responding to any gluster commands, when I checked this issue I find that 
glusterd thread 9 and thread 8 is dealing with the same socket, I thought 
following patch should be able to solve this issue, however after I merged this 
patch this issue still exist. When I looked into this code, it seems 
socket_event_poll_in called event_handled before rpc_transport_pollin_destroy, 
I think this gives the chance for another poll for the exactly the same socket. 
And caused this glusterd stuck issue, also, I find there is no   
LOCK_DESTROY(>lock)
In iobref_destroy, I think it is better to add destroy lock.
Following is the gdb info when this issue happened, I would like to know your 
opinion on this issue, thanks!

SHA-1: f747d55a7fd364e2b9a74fe40360ab3cb7b11537

* socket: fix issue on concurrent handle of a socket



GDB INFO:
Thread 8 is blocked on pthread_cond_wait, and thread 9 is blocked in 
iobref_unref, I think
Thread 9 (Thread 0x7f9edf7fe700 (LWP 1933)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

Thread 8 (Thread 0x7f9ed700 (LWP 1932)):
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fd2b42 in __pthread_mutex_cond_lock () from 
/lib64/libpthread.so.0
#2  0x7f9ee9fd44a8 in pthread_cond_wait@@GLIBC_2.3.2 () from 
/lib64/libpthread.so.0
#3  0x7f9ee4fbadab in socket_event_poll_err (this=0x7f9ed0049cc0, gen=4, 
idx=27) at socket.c:1201
#4  0x7f9ee4fbf99c in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2480
#5  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edfffee84) at event-epoll.c:583
#6  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180cf20) at 
event-epoll.c:659
#7  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#8  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6

(gdb) thread 9
[Switching to thread 9 (Thread 0x7f9edf7fe700 (LWP 1933))]
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
(gdb) bt
#0  0x7f9ee9fd785c in __lll_lock_wait () from /lib64/libpthread.so.0
#1  0x7f9ee9fda657 in __lll_lock_elision () from /lib64/libpthread.so.0
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
#3  0x7f9eeafd2f29 in rpc_transport_pollin_destroy (pollin=0x7f9ed00452d0) 
at rpc-transport.c:123
#4  0x7f9ee4fbf319 in socket_event_poll_in (this=0x7f9ed0049cc0, 
notify_handled=_gf_true) at socket.c:2322
#5  0x7f9ee4fbf932 in socket_event_handler (fd=36, idx=27, gen=4, 
data=0x7f9ed0049cc0, poll_in=1, poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f9eeb2825d4 in event_dispatch_epoll_handler (event_pool=0x17feb00, 
event=0x7f9edf7fde84) at event-epoll.c:583
#7  0x7f9eeb2828ab in event_dispatch_epoll_worker (data=0x180d0c0) at 
event-epoll.c:659
#8  0x7f9ee9fce5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f9ee98a4eaf in clone () from /lib64/libc.so.6
(gdb) frame 2
#2  0x7f9eeb24cae6 in iobref_unref (iobref=0x7f9ed00063b0) at iobuf.c:944
944 iobuf.c: No such file or directory.
(gdb) print *iobref
$1 = {lock = {spinlock = 2, mutex = {__data = {__lock = 2, __count = 222, 
__owner = -2120437760, __nusers = 1, __kind = 8960, __spins = 512,
__elision = 0, __list = {__prev = 0x4000, __next = 0x7f9ed00063b000}},
  __size = 
"\002\000\000\000\336\000\000\000\000\260\234\201\001\000\000\000\000#\000\000\000\002\000\000\000@\000\000\000\000\000\000\000\260c\000О\177",
 __align = 953482739714}}, ref = -256, iobrefs = 0x, alloced = 
-1, used = -1}
(gdb) quit
A debugging session is active.
___
Gluster-devel mailing list
Gluster-devel@gluster.org
https://lists.gluster.org/mailman/listinfo/gluster-devel

[Gluster-devel] when there are dangling entry(without gfid) in only one brick dir, the glusterfs heal info will keep showing the entry, glustershd can not really remove this entry from brick .

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs expert,
I meet one problem in my test bed (3 brick on 3 sn nodes), the "/" is always in 
glusterfs v heal info output. In my ftest+reboot-sn-nodes-randomly test, the 
gluster v heal info output keeps showing entry "/" even for hours, and even you 
do some touch or ls of /mnt/mstate , it will not help to solve this issue.

[root@sn-0:/mnt/bricks/mstate/brick]
# gluster v heal mstate info
Brick sn-0.local:/mnt/bricks/mstate/brick
/
Status: Connected
Number of entries: 1

Brick sn-2.local:/mnt/bricks/mstate/brick
/
Status: Connected
Number of entries: 1

Brick sn-1.local:/mnt/bricks/mstate/brick
/
Status: Connected
Number of entries: 1


>From sn glustershd.log I find following prints
[2018-10-10 08:13:00.005250] I [MSGID: 108026] 
[afr-self-heald.c:432:afr_shd_index_heal] 0-mstate-replicate-0: got entry: 
----0001 from mstate-client-0
[2018-10-10 08:13:00.006077] I [MSGID: 108026] 
[afr-self-heald.c:341:afr_shd_selfheal] 0-mstate-replicate-0: entry: path /, 
gfid: ----0001
[2018-10-10 08:13:00.011599] I [MSGID: 108026] 
[afr-self-heal-entry.c:887:afr_selfheal_entry_do] 0-mstate-replicate-0: 
performing entry selfheal on ----0001
[2018-10-10 08:16:28.722059] W [MSGID: 108015] 
[afr-self-heal-entry.c:47:afr_selfheal_entry_delete] 0-mstate-replicate-0: 
expunging dir 
----0001/fstest_76f272545249be5d71359f06962e069b 
(----) on mstate-client-0
[2018-10-10 08:16:28.722975] W [MSGID: 114031] 
[client-rpc-fops.c:670:client3_3_rmdir_cbk] 0-mstate-client-0: remote operation 
failed [No such file or directory]


When I check the env I find that fstest_76f272545249be5d71359f06962e069b only 
exists on sn-0 node brick only and the getfattr of this is empty!

[root@sn-0:/mnt/bricks/mstate/brick]
# getfattr -m . -d -e hex fstest_76f272545249be5d71359f06962e069b//return 
is empty output
[root@sn-0:/mnt/bricks/mstate/brick]
# getfattr -m . -d -e hex .
# file: .
trusted.afr.dirty=0x
trusted.afr.mstate-client-1=0x
trusted.afr.mstate-client-2=0x02a7
trusted.gfid=0x0001
trusted.glusterfs.dht=0x0001
trusted.glusterfs.volume-id=0xbf7aad0e4ce44196aa9b0a33928ea2ff

[root@sn-1:/root]
# stat /mnt/bricks/mstate/brick/fstest_76f272545249be5d71359f06962e069b
stat: cannot stat 
'/mnt/bricks/mstate/brick/fstest_76f272545249be5d71359f06962e069b': No such 
file or directory
[root@sn-1:/root]
[root@sn-1:/mnt/bricks/mstate/brick]
# getfattr -m . -d -e hex .
# file: .
trusted.afr.dirty=0x
trusted.afr.mstate-client-0=0x0006
trusted.afr.mstate-client-1=0x
trusted.gfid=0x0001
trusted.glusterfs.dht=0x0001
trusted.glusterfs.volume-id=0xbf7aad0e4ce44196aa9b0a33928ea2ff

[root@sn-2:/mnt/bricks/mstate/brick]
# stat /mnt/bricks/mstate/brick/fstest_76f272545249be5d71359f06962e069b
stat: cannot stat 
'/mnt/bricks/mstate/brick/fstest_76f272545249be5d71359f06962e069b': No such 
file or directory
[root@sn-2:/mnt/bricks/mstate/brick]

[root@sn-2:/mnt/bricks/mstate/brick]
# getfattr -m . -d -e hex .
# file: .
trusted.afr.dirty=0x
trusted.afr.mstate-client-0=0x0006
trusted.afr.mstate-client-2=0x
trusted.gfid=0x0001
trusted.glusterfs.dht=0x0001
trusted.glusterfs.volume-id=0xbf7aad0e4ce44196aa9b0a33928ea2ff


I think the entry fstest_76f272545249be5d71359f06962e069b should either be 
assigned gfid or be removed, from the glustershd.log it shows clearly that 
glustershd on sn-0 try to remove this dangling entry but meet some error. And 
when I do some gdb I find that in this case the entry is not assigned to gfid, 
because the __afr_selfheal_heal_dirent input param source is 1, so  
replies[source].op_ret == -1, and can not assign gfid to it. my question is in 
this case there is no fstest_76f272545249be5d71359f06962e069b on sn-1 and sn-2, 
so if want to remove this dangling entry on sn-0 can not use syncop_rmdir, I 
would like your opinion on this issue, thanks!

Thread 12 "glustershdheal" hit Breakpoint 1, __afr_selfheal_heal_dirent 
(frame=0x7f5aec009350, this=0x7f5b1001d8d0, fd=0x7f5b0800c8a0,
name=0x7f5b08059db0 "fstest_76f272545249be5d71359f06962e069b", 
inode=0x7f5aec001e80, source=1, sources=0x7f5af8fefb20 "",
healed_sinks=0x7f5af8fefae0 "\001", locked_on=0x7f5af8fefac0 
"\001\001\001\370Z\177", replies=0x7f5af8fef190) at afr-self-heal-entry.c:172
172 afr-self-heal-entry.c: No such file or directory.
(gdb) print name
$17 = 0x7f5b08059db0 "fstest_76f272545249be5d71359f06962e069b"
(gdb) print source
$18 = 1
(gdb) print replies[0].op_ret
$19 = 0
(gdb) print replies[1].op_ret
$20 = -1
(gdb) print replies[2].op_ret
$21 = -1
(gdb) 

Re: [Gluster-devel] query about one glustershd coredump issue

[Zhou, Cynthia (NSB - CN/Hangzhou)]

From: Ravishankar N 
Sent: Thursday, September 27, 2018 6:04 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
Subject: Re: query about one glustershd coredump issue


Hi,

I think it is better to send it on gluster-users mailing list to get more 
attention.
Regards,
Ravi
On 09/27/2018 01:10 PM, Zhou, Cynthia (NSB - CN/Hangzhou) wrote:
Hi,
In my test env(glusterfs 3.12.3 3brick config) when restart sn-0 sn-1 and sn-2 
at the same time, occasionally, I met glustershd on sn-0 coredump.
Could you help to shed some light on this issue? Thanks!


My gdb result of the coredump file

[root@sn-0:/root]
# gdb /usr/sbin/glusterfs 
core.glusterfs.0.c5f0c5547fbd4e5aa8f350b748e5675e.1812.153796707500
GNU gdb (GDB) Fedora 8.1-14.wf29
Copyright (C) 2018 Free Software Foundation, Inc.
License GPLv3+: GNU GPL version 3 or later 
<http://gnu.org/licenses/gpl.html><http://gnu.org/licenses/gpl.html>
This is free software: you are free to change and redistribute it.
There is NO WARRANTY, to the extent permitted by law.  Type "show copying"
and "show warranty" for details.
This GDB was configured as "x86_64-redhat-linux-gnu".
Type "show configuration" for configuration details.
For bug reporting instructions, please see:
<http://www.gnu.org/software/gdb/bugs/><http://www.gnu.org/software/gdb/bugs/>.
Find the GDB manual and other documentation resources online at:
<http://www.gnu.org/software/gdb/documentation/><http://www.gnu.org/software/gdb/documentation/>.
For help, type "help".
Type "apropos word" to search for commands related to "word"...
Reading symbols from /usr/sbin/glusterfs...(no debugging symbols found)...done.

warning: core file may not match specified executable file.
[New LWP 1818]
[New LWP 1812]
[New LWP 1813]
[New LWP 1817]
[New LWP 1966]
[New LWP 1968]
[New LWP 1970]
[New LWP 1974]
[New LWP 1976]
[New LWP 1814]
[New LWP 1815]
[New LWP 1816]
[New LWP 1828]
[Thread debugging using libthread_db enabled]
Using host libthread_db library "/lib64/libthread_db.so.1".
Core was generated by `/usr/sbin/glusterfs -s sn-0.local --volfile-id 
gluster/glustershd -p /var/run/g'.
Program terminated with signal SIGSEGV, Segmentation fault.
#0  0x7f1b5e5d7d24 in client3_3_lookup_cbk (req=0x7f1b44002300, 
iov=0x7f1b44002340, count=1,
myframe=0x7f1b4401c850) at client-rpc-fops.c:2802
2802  client-rpc-fops.c: No such file or directory.
[Current thread is 1 (Thread 0x7f1b5f00c700 (LWP 1818))]
Missing separate debuginfos, use: dnf debuginfo-install 
rcp-pack-glusterfs-1.2.0-RCP2.wf29.x86_64
(gdb) bt
#0  0x7f1b5e5d7d24 in client3_3_lookup_cbk (req=0x7f1b44002300, 
iov=0x7f1b44002340, count=1,
myframe=0x7f1b4401c850) at client-rpc-fops.c:2802
#1  0x7f1b64553d47 in rpc_clnt_handle_reply (clnt=0x7f1b5808bbb0, 
pollin=0x7f1b580c6620)
at rpc-clnt.c:778
#2  0x7f1b645542e5 in rpc_clnt_notify (trans=0x7f1b5808bde0, 
mydata=0x7f1b5808bbe0,
event=RPC_TRANSPORT_MSG_RECEIVED, data=0x7f1b580c6620) at rpc-clnt.c:971
#3  0x7f1b64550319 in rpc_transport_notify (this=0x7f1b5808bde0, 
event=RPC_TRANSPORT_MSG_RECEIVED,
data=0x7f1b580c6620) at rpc-transport.c:538
#4  0x7f1b5f49734d in socket_event_poll_in (this=0x7f1b5808bde0, 
notify_handled=_gf_true)
at socket.c:2315
#5  0x7f1b5f497992 in socket_event_handler (fd=25, idx=15, gen=7, 
data=0x7f1b5808bde0, poll_in=1,
poll_out=0, poll_err=0) at socket.c:2471
#6  0x7f1b647fe5ac in event_dispatch_epoll_handler (event_pool=0x230cb00, 
event=0x7f1b5f00be84)
at event-epoll.c:583
#7  0x7f1b647fe883 in event_dispatch_epoll_worker (data=0x23543d0) at 
event-epoll.c:659
#8  0x7f1b6354a5da in start_thread () from /lib64/libpthread.so.0
#9  0x7f1b62e20cbf in clone () from /lib64/libc.so.6
(gdb) info thread
  Id   Target Id Frame
* 1Thread 0x7f1b5f00c700 (LWP 1818) 0x7f1b5e5d7d24 in 
client3_3_lookup_cbk (req=0x7f1b44002300,
iov=0x7f1b44002340, count=1, myframe=0x7f1b4401c850) at 
client-rpc-fops.c:2802
  2Thread 0x7f1b64c83780 (LWP 1812) 0x7f1b6354ba3d in 
__pthread_timedjoin_ex ()
   from /lib64/libpthread.so.0
  3Thread 0x7f1b61eae700 (LWP 1813) 0x7f1b63554300 in nanosleep () from 
/lib64/libpthread.so.0
  4Thread 0x7f1b5feaa700 (LWP 1817) 0x7f1b635508ca in 
pthread_cond_timedwait@@GLIBC_2.3.2<mailto:pthread_cond_timedwait@@GLIBC_2.3.2> 
()
   from /lib64/libpthread.so.0
  5Thread 0x7f1b5ca2b700 (LWP 1966) 0x7f1b62dee4b0 in nanosleep () from 
/lib64/libc.so.6
  6Thread 0x7f1b4f7fe700 (LWP 1968) 0x7f1b6355050c in 
pthread_cond_wait@@GLIBC_2.3.2<mailto:pthread_cond_wait@@GLIBC_2.3.2> ()
   from /lib64/libpthread.so.0
  7Thread 0x7f1b4e7fc700 (LWP 1970) 0x7f1b6355050c in 
pthread_cond_wait@@GLIBC_2.3.2<mailto:pthread_cond_wait@@GLIBC_2.3.2> ()
   from /lib64/libpthread.so.0
  8Thread 0x7f1b4d7fa700 (LWP 1974) 0x7f1b62dee4b0 in nano

Re: [Gluster-devel] remaining entry in gluster volume heal info command even after reboot

[Zhou, Cynthia (NSB - CN/Hangzhou)]

In real world this also happened, and when this happened, I notice that the 
getfattr result of the remaining entry(from gluster v heal info command) of 
sn-0 blame sn-2(trusted.afr.mstate-client-2=0x001c) and 
sn-2 blame sn-0(trusted.afr.mstate-client-0=0x00010003), sn-1 
does not blame anyone. But the file within the remaining entry does not have 
any changelog blaming others on 3 sn nodes.!
Since this issue just appear occasionally, So my test step is to simulate this 
situation in real world, I think it is better that glusterfs could also 
consider this situation. Do you have any comments?

From: Zhou, Cynthia (NSB - CN/Hangzhou)
Sent: Thursday, September 06, 2018 9:08 AM
To: 'Pranith Kumar Karampuri' 
Cc: Gluster Devel ; Ravishankar N 

Subject: RE: remaining entry in gluster volume heal info command even after 
reboot

This test steps is only to simulate the real test case(reboot+ftest), in real 
case it also happened occasionally.

From: Pranith Kumar Karampuri mailto:pkara...@redhat.com>>
Sent: Wednesday, September 05, 2018 5:32 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel 
mailto:gluster-devel@gluster.org>>; Ravishankar N 
mailto:ravishan...@redhat.com>>
Subject: Re: remaining entry in gluster volume heal info command even after 
reboot

Looks like the test case is a bit involved and also has modifications directly 
on the brick. Could you let us know if there is any reason to touch the brick 
directly?

On Wed, Sep 5, 2018 at 2:53 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
I will try to reproduce (reboot + ftest)and tell you later, but in following 
steps you can also simulate this issue locally, at least the remaining entry 
happened and the entry heal quit also because of all thee empty 
heald_sinks.(not sure if this is exactly the same from reboot+ftest reproduced 
one but I guess it should be the same)



1>   Stop client quorum by command “gluster v set  cluster.quorum-type 
none”

2>   Isolate sn-0 from sn-1 and sn-2

iptables -I OUTPUT -d sn-1.local -j DROP

iptables -I OUTPUT -d sn-2.local -j DROP

iptables -I INPUT -s sn-2.local -j DROP

iptables -I INPUT -s sn-1.local -j DROP

3>   Touch /mnt/export/testdir/common.txt on sn-0

4>   Touch /mnt/export/testidir/common.txt on sn-1

5>   On sn-1 node,Delete all  /mnt/bricks/export/brick/testdir/common.txt 
metadata until getfattr returns empty,

setfattr -x  trusted.afr.dirty /mnt/bricks/export/brick/testdir/common.txt

setfattr -x  trusted.afr.export-client-0  
/mnt/bricks/export/brick/testdir/common.txt

setfattr -x  trusted.gfid  /mnt/bricks/export/brick/testdir/common.txt

setfattr -x  trusted.gfid2path.53be37be7f01389d 
/mnt/bricks/export/brick/testdir/common.txt

then getfattr returns empty

[root@sn-1:/home/robot]

# getfattr -m . -d -e hex  /mnt/bricks/export/brick/testdir/common.txt

[root@sn-1:/home/robot]

6>   then delete the corresponding entry(common.txt) in 
/mnt/bricks/export/brick/.glusterfs/indices/xattrop/

[root@sn-1:/home/robot]

# rm -rf 
/mnt/bricks/export/brick/.glusterfs/indices/xattrop/d0d237f7-0c43-4828-8720-dfb3792fe5fb
7>Restore network on sn-0 node.

iptables -D OUTPUT -d  sn-1.local  -j DROP
  iptables -D OUTPUT -d sn-2.local  -j DROP

   iptables -D INPUT -s sn-1.local -j DROP
iptables -D INPUT -s sn-2.local  -j DROP

7>   Do touch /mnt/export/testdir/common.txt on sn-0 node

8>   Gluster v heal export info will show following and keep for long time
# gluster v heal export info
Brick sn-0.local:/mnt/bricks/export/brick
/testdir
Status: Connected
Number of entries: 1

Brick sn-1.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-2.local:/mnt/bricks/export/brick
/testdir
Status: Connected
Number of entries: 1



From: Pranith Kumar Karampuri mailto:pkara...@redhat.com>>
Sent: Wednesday, September 05, 2018 4:56 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>>
Cc: Gluster Devel 
mailto:gluster-devel@gluster.org>>; Ravishankar N 
mailto:ravishan...@redhat.com>>
Subject: Re: remaining entry in gluster volume heal info command even after 
reboot


On Wed, Sep 5, 2018 at 1:27 PM Zhou, Cynthia (NSB - CN/Hangzhou) 
mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi glusterfs experts:
   Good day!
   Recently when I do some test on my gluster env, I found that there are 
some remaining entries in command “gluster v heal mstate info” even after 
reboot.
fstest_035ffc492ec43551a64087f9280ffe3e is a folder in /mnt/mstate and in 
this folder only one file(fstest_458bb82d8884ed5c9dadec4ed93bec4e) exists.
When I dbg by gdb on sn-0 I found that:
Parent dir changelog(fstest_035ffc492ec43551a64087f9280ffe3e) says need to heal 
entry, but the changelog/gfid/filetype of the only entry in parent dir shows 
there is nothing to be healed, so

Re: [Gluster-devel] query about a split-brain problem found in glusterfs3.12.3

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
I check the link you provided. It does not mention the the "dirty" attribute, 
if I try to fix this split-brain by manually setfattr command, should I only 
set the "trusted.afr.export-client-0" command?
By the way, I feel it is quite strange that the output of "gluster volume heal 
export info" command there is two entries with the same name, how does this 
happen?
gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

/testdir - Possibly undergoing heal

Status: Connected
Number of entries: 2

I also do some other test, when sn-0 side file/dir does not has "dirty" and 
"trusted.afr.export-client-*" attribute and sn-1 side file/dir has both "dirty" 
and "trusted.afr.export-client-*" non-zero. The gluster could self heal such 
scenario. But in this case the it could never self heal.

From: Ravishankar N [mailto:ravishan...@redhat.com]
Sent: Thursday, February 08, 2018 11:56 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) <cynthia.z...@nokia-sbell.com>; 
Gluster-devel@gluster.org
Subject: Re: query about a split-brain problem found in glusterfs3.12.3




On 02/08/2018 07:16 AM, Zhou, Cynthia (NSB - CN/Hangzhou) wrote:
Hi,
Thanks for responding?
If split-brain happen in such kind of test is reasonable, how to fix this 
split-brain situation?

If you are using replica 2, then there is no prevention. Once they occur, you 
can resolve them using 
http://docs.gluster.org/en/latest/Troubleshooting/resolving-splitbrain/

If you want to prevent split-brain, you would need to use replica 3 or arbiter 
volume.

Regards,
Ravi

From: Ravishankar N [mailto:ravishan...@redhat.com]
Sent: Thursday, February 08, 2018 12:12 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
<cynthia.z...@nokia-sbell.com><mailto:cynthia.z...@nokia-sbell.com>; 
Gluster-devel@gluster.org<mailto:Gluster-devel@gluster.org>
Subject: Re: query about a split-brain problem found in glusterfs3.12.3




On 02/07/2018 10:39 AM, Zhou, Cynthia (NSB - CN/Hangzhou) wrote:

Hi glusterfs expert:
   Good day.
   Lately, we meet a glusterfs split brain problem in our env in 
/mnt/export/testdir. We start 3 ior process (IOR tool) from non-sn nodes, which 
is creating/removing files repeatedly in testdir. then we reboot sn nodes(sn0 
and sn1) by sequence. Then we meet following problem.
Do you have some comments on how this could happen? And how to fix it in 
this situation? Thanks!

Is the problem that split-brain is happening? Is this a replica 2 volume? If 
yes, then it looks like it is expected behavior?
Regards
Ravi




gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

/testdir - Possibly undergoing heal

Status: Connected
Number of entries: 2

wait for a while .

gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Possibly undergoing heal

/testdir - Possibly undergoing heal

and finally:

[root@sn-0:/root<http://sn-0/root>]
# gluster v heal export info
Brick sn-0.local:/mnt/bricks/export/brick<http://local/mnt/bricks/export/brick>
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick<http://local/mnt/bricks/export/brick>
/testdir - Is in split-brain

Status: Connected
Number of entries: 1



[root@sn-0:/root<http://sn-0/root>]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001



[root@sn-1:/root<http://sn-1/root>]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.afr.dirty=0x0001

trusted.afr.export-client-0=0x0038

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001




___
Gluster-devel mailing list
Gluster-devel@gluster.org
http://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] query about a split-brain problem found in glusterfs3.12.3

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Thanks for responding?
If split-brain happen in such kind of test is reasonable, how to fix this 
split-brain situation?

From: Ravishankar N [mailto:ravishan...@redhat.com]
Sent: Thursday, February 08, 2018 12:12 AM
To: Zhou, Cynthia (NSB - CN/Hangzhou) <cynthia.z...@nokia-sbell.com>; 
Gluster-devel@gluster.org
Subject: Re: query about a split-brain problem found in glusterfs3.12.3




On 02/07/2018 10:39 AM, Zhou, Cynthia (NSB - CN/Hangzhou) wrote:

Hi glusterfs expert:
   Good day.
   Lately, we meet a glusterfs split brain problem in our env in 
/mnt/export/testdir. We start 3 ior process (IOR tool) from non-sn nodes, which 
is creating/removing files repeatedly in testdir. then we reboot sn nodes(sn0 
and sn1) by sequence. Then we meet following problem.
Do you have some comments on how this could happen? And how to fix it in 
this situation? Thanks!

Is the problem that split-brain is happening? Is this a replica 2 volume? If 
yes, then it looks like it is expected behavior?
Regards
Ravi



gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

/testdir - Possibly undergoing heal

Status: Connected
Number of entries: 2

wait for a while .

gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Possibly undergoing heal

/testdir - Possibly undergoing heal

and finally:

[root@sn-0:/root<http://sn-0/root>]
# gluster v heal export info
Brick sn-0.local:/mnt/bricks/export/brick<http://local/mnt/bricks/export/brick>
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick<http://local/mnt/bricks/export/brick>
/testdir - Is in split-brain

Status: Connected
Number of entries: 1



[root@sn-0:/root<http://sn-0/root>]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001



[root@sn-1:/root<http://sn-1/root>]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.afr.dirty=0x0001

trusted.afr.export-client-0=0x0038

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001



___
Gluster-devel mailing list
Gluster-devel@gluster.org
http://lists.gluster.org/mailman/listinfo/gluster-devel

[Gluster-devel] query about a split-brain problem found in glusterfs3.12.3

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs expert:
   Good day.
   Lately, we meet a glusterfs split brain problem in our env in 
/mnt/export/testdir. We start 3 ior process (IOR tool) from non-sn nodes, which 
is creating/removing files repeatedly in testdir. then we reboot sn nodes(sn0 
and sn1) by sequence. Then we meet following problem.
Do you have some comments on how this could happen? And how to fix it in 
this situation? Thanks!


gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

/testdir - Possibly undergoing heal

Status: Connected
Number of entries: 2

wait for a while .

gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Possibly undergoing heal

/testdir - Possibly undergoing heal

and finally:

[root@sn-0:/root]
# gluster v heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

Status: Connected
Number of entries: 1



[root@sn-0:/root]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001



[root@sn-1:/root]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.afr.dirty=0x0001

trusted.afr.export-client-0=0x0038

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001


___
Gluster-devel mailing list
Gluster-devel@gluster.org
http://lists.gluster.org/mailman/listinfo/gluster-devel

[Gluster-devel] query about a split-brain problem found in glusterfs3.12.3

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi glusterfs expert:
   Good day.
   Lately, we meet a glusterfs split brain problem in our env in 
/mnt/export/testdir. We start 3 ior process (IOR tool) from non-sn nodes, which 
is creating/removing files repeatedly in testdir. then we reboot sn nodes(sn0 
and sn1) by sequence. Then we meet following problem.
Do you have some comments on how this could happen? And how to fix it in 
this situation? Thanks!


gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

/testdir - Possibly undergoing heal

Status: Connected
Number of entries: 2

wait for a while …..

gluster volume heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Possibly undergoing heal

/testdir - Possibly undergoing heal
and finally:

[root@sn-0:/root]
# gluster v heal export info
Brick sn-0.local:/mnt/bricks/export/brick
Status: Connected
Number of entries: 0

Brick sn-1.local:/mnt/bricks/export/brick
/testdir - Is in split-brain

Status: Connected
Number of entries: 1



[root@sn-0:/root]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001



[root@sn-1:/root]

# getfattr -m .* -d -e  hex /mnt/bricks/export/brick/testdir

getfattr: Removing leading '/' from absolute path names

# file: mnt/bricks/export/brick/testdir

trusted.afr.dirty=0x0001

trusted.afr.export-client-0=0x0038

trusted.gfid=0x5622cff893b3484dbdb6a20a0edb0e77

trusted.glusterfs.dht=0x0001

___
Gluster-devel mailing list
Gluster-devel@gluster.org
http://lists.gluster.org/mailman/listinfo/gluster-devel

Re: [Gluster-devel] [Gluster-users] after hard reboot, split-brain happened, but nothing showed in gluster voluem heal info command !

[Zhou, Cynthia (NSB - CN/Hangzhou)]

Hi,
Thanks for reply!
I’ve checked [1]. But the problem is that there is nothing shown in command 
“gluster volume heal  info”. So these split-entry files could only 
be detected when app try to visit them.
I can find gfid mismatch for those in-split-brain entries from mount log, 
however, nothing show in shd log, the shd log does not know those split-brain 
entries. Because there is nothing in indices/xattrop directory.

The log is not available right now, when it reproduced, I will provide it to 
your, Thanks!

Best regards,
Cynthia （周琳）
MBB SM HETRAN SW3 MATRIX
Storage
Mobile: +86 (0)18657188311

From: Karthik Subrahmanya [mailto:ksubr...@redhat.com]
Sent: Thursday, September 28, 2017 2:02 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) <cynthia.z...@nokia-sbell.com>
Cc: gluster-us...@gluster.org; gluster-devel@gluster.org
Subject: Re: [Gluster-users] after hard reboot, split-brain happened, but 
nothing showed in gluster voluem heal info command !

Hi,
To resolve the gfid split-brain you can follow the steps at [1].
Since we don't have the pending markers set on the files, it is not showing in 
the heal info.
To debug this issue, need some more data from you. Could you provide these 
things?
1. volume info
2. mount log
3. brick logs
4. shd log

May I also know which version of gluster you are running. From the info you 
have provided it looks like an old version.
If it is, then it would be great if you can upgarde to one of the latest 
supported release.

[1] 
http://docs.gluster.org/en/latest/Troubleshooting/split-brain/#fixing-directory-entry-split-brain

Thanks & Regards,
Karthik
On Wed, Sep 27, 2017 at 9:42 AM, Zhou, Cynthia (NSB - CN/Hangzhou) 
<cynthia.z...@nokia-sbell.com<mailto:cynthia.z...@nokia-sbell.com>> wrote:

HI gluster experts,

I meet a tough problem about “split-brain” issue. Sometimes, after hard reboot, 
we will find some files in split-brain, however its parent directory or 
anything could be shown in command “gluster volume heal  info”, 
also, no entry in .glusterfs/indices/xattrop directory, can you help to shed 
some lights on this issue? Thanks!



Following is some info from our env,

Checking from sn-0 cliet, nothing is shown in-split-brain!

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# gluster v heal services info
Brick sn-0:/mnt/bricks/services/brick/
Number of entries: 0

Brick sn-1:/mnt/bricks/services/brick/
Number of entries: 0

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# gluster v heal services info split-brain
Gathering list of split brain entries on volume services has been successful

Brick sn-0.local:/mnt/bricks/services/brick
Number of entries: 0

Brick sn-1.local:/mnt/bricks/services/brick
Number of entries: 0

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# ls -l /mnt/services/netserv/ethip/
ls: cannot access '/mnt/services/netserv/ethip/sn-2': Input/output error
ls: cannot access '/mnt/services/netserv/ethip/mn-1': Input/output error
total 3
-rw-r--r-- 1 root root 144 Sep 26 20:35 as-0
-rw-r--r-- 1 root root 144 Sep 26 20:35 as-1
-rw-r--r-- 1 root root 145 Sep 26 20:35 as-2
-rw-r--r-- 1 root root 237 Sep 26 20:36 mn-0
-? ? ??  ?? mn-1
-rw-r--r-- 1 root root  73 Sep 26 20:35 sn-0
-rw-r--r-- 1 root root  73 Sep 26 20:35 sn-1
-? ? ??  ?? sn-2
[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]

Checking from glusterfs server side, the gfid of mn-1 on sn-0 and sn-1 is 
different

[SN-0]
[root@sn-0:/mnt/bricks/services/brick/.glusterfs/53/a3]
# getfattr -m . -d -e hex /mnt/bricks/services/brick/netserv/ethip
getfattr: Removing leading '/' from absolute path names
# file: mnt/bricks/services/brick/netserv/ethip
trusted.gfid=0xee71d19ac0f84f60b11eb42a083644e4
trusted.glusterfs.dht=0x0001

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# getfattr -m . -d -e hex mn-1
# file: mn-1
trusted.afr.dirty=0x
trusted.afr.services-client-0=0x
trusted.afr.services-client-1=0x
trusted.gfid=0x53a33f437464475486f31c4e44d83afd
[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# stat mn-1
  File: mn-1
  Size: 237  Blocks: 16 IO Block: 4096   regular file
Device: fd51h/64849dInode: 2536Links: 2
Access: (0644/-rw-r--r--)  Uid: (0/root)   Gid: (0/root)
Access: 2017-09-26 20:30:25.67900 +0300
Modify: 2017-09-26 20:30:24.60400 +0300
Change: 2017-09-26 20:30:24.61000 +0300
Birth: -
[root@sn-0:/mnt/bricks/services/brick/.glusterfs/indices/xattrop]
# ls
xattrop-63f8bbcb-7fa6-4fc8-b721-675a05de0ab3
[root@sn-0:/mnt/bricks/services/brick/.glusterfs/indices/xattrop]

[root@sn-0:/mnt/bricks/services/brick/.glusterfs/53/a3]
# ls
53a33f43-7464-4754-86f3-1c4e44d83afd
[root@sn-0:/mnt/bricks/services/brick/.glusterfs/53/a3]
# stat 53a33f43-7464-4754-86f3-1c4e44d83afd
  File: 5

Re: [Gluster-devel] [Gluster-users] after hard reboot, split-brain happened, but nothing showed in gluster voluem heal info command !

[Zhou, Cynthia (NSB - CN/Hangzhou)]

The version I am using is glusterfs 3.6.9
Best regards,
Cynthia （周琳）
MBB SM HETRAN SW3 MATRIX
Storage
Mobile: +86 (0)18657188311

From: Karthik Subrahmanya [mailto:ksubr...@redhat.com]
Sent: Thursday, September 28, 2017 2:37 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) <cynthia.z...@nokia-sbell.com>
Cc: gluster-us...@gluster.org; gluster-devel@gluster.org
Subject: Re: [Gluster-users] after hard reboot, split-brain happened, but 
nothing showed in gluster voluem heal info command !



On Thu, Sep 28, 2017 at 11:41 AM, Zhou, Cynthia (NSB - CN/Hangzhou) 
<cynthia.z...@nokia-sbell.com<mailto:cynthia.z...@nokia-sbell.com>> wrote:
Hi,
Thanks for reply!
I’ve checked [1]. But the problem is that there is nothing shown in command 
“gluster volume heal  info”. So these split-entry files could only 
be detected when app try to visit them.
I can find gfid mismatch for those in-split-brain entries from mount log, 
however, nothing show in shd log, the shd log does not know those split-brain 
entries. Because there is nothing in indices/xattrop directory.
I guess it was there before, and then it got cleared by one of the heal process 
either client side or server side. I wanted to check that by examining the logs.
Which version of gluster you are running by the way?

The log is not available right now, when it reproduced, I will provide it to 
your, Thanks!
Ok.

Best regards,
Cynthia （周琳）
MBB SM HETRAN SW3 MATRIX
Storage
Mobile: +86 (0)18657188311

From: Karthik Subrahmanya 
[mailto:ksubr...@redhat.com<mailto:ksubr...@redhat.com>]
Sent: Thursday, September 28, 2017 2:02 PM
To: Zhou, Cynthia (NSB - CN/Hangzhou) 
<cynthia.z...@nokia-sbell.com<mailto:cynthia.z...@nokia-sbell.com>>
Cc: gluster-us...@gluster.org<mailto:gluster-us...@gluster.org>; 
gluster-devel@gluster.org<mailto:gluster-devel@gluster.org>
Subject: Re: [Gluster-users] after hard reboot, split-brain happened, but 
nothing showed in gluster voluem heal info command !

Hi,
To resolve the gfid split-brain you can follow the steps at [1].
Since we don't have the pending markers set on the files, it is not showing in 
the heal info.
To debug this issue, need some more data from you. Could you provide these 
things?
1. volume info
2. mount log
3. brick logs
4. shd log

May I also know which version of gluster you are running. From the info you 
have provided it looks like an old version.
If it is, then it would be great if you can upgarde to one of the latest 
supported release.

[1] 
http://docs.gluster.org/en/latest/Troubleshooting/split-brain/#fixing-directory-entry-split-brain

Thanks & Regards,
Karthik
On Wed, Sep 27, 2017 at 9:42 AM, Zhou, Cynthia (NSB - CN/Hangzhou) 
<cynthia.z...@nokia-sbell.com<mailto:cynthia.z...@nokia-sbell.com>> wrote:

HI gluster experts,

I meet a tough problem about “split-brain” issue. Sometimes, after hard reboot, 
we will find some files in split-brain, however its parent directory or 
anything could be shown in command “gluster volume heal  info”, 
also, no entry in .glusterfs/indices/xattrop directory, can you help to shed 
some lights on this issue? Thanks!



Following is some info from our env,

Checking from sn-0 cliet, nothing is shown in-split-brain!

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# gluster v heal services info
Brick sn-0:/mnt/bricks/services/brick/
Number of entries: 0

Brick sn-1:/mnt/bricks/services/brick/
Number of entries: 0

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# gluster v heal services info split-brain
Gathering list of split brain entries on volume services has been successful

Brick sn-0.local:/mnt/bricks/services/brick
Number of entries: 0

Brick sn-1.local:/mnt/bricks/services/brick
Number of entries: 0

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# ls -l /mnt/services/netserv/ethip/
ls: cannot access '/mnt/services/netserv/ethip/sn-2': Input/output error
ls: cannot access '/mnt/services/netserv/ethip/mn-1': Input/output error
total 3
-rw-r--r-- 1 root root 144 Sep 26 20:35 as-0
-rw-r--r-- 1 root root 144 Sep 26 20:35 as-1
-rw-r--r-- 1 root root 145 Sep 26 20:35 as-2
-rw-r--r-- 1 root root 237 Sep 26 20:36 mn-0
-? ? ??  ?? mn-1
-rw-r--r-- 1 root root  73 Sep 26 20:35 sn-0
-rw-r--r-- 1 root root  73 Sep 26 20:35 sn-1
-? ? ??  ?? sn-2
[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]

Checking from glusterfs server side, the gfid of mn-1 on sn-0 and sn-1 is 
different

[SN-0]
[root@sn-0:/mnt/bricks/services/brick/.glusterfs/53/a3]
# getfattr -m . -d -e hex /mnt/bricks/services/brick/netserv/ethip
getfattr: Removing leading '/' from absolute path names
# file: mnt/bricks/services/brick/netserv/ethip
trusted.gfid=0xee71d19ac0f84f60b11eb42a083644e4
trusted.glusterfs.dht=0x0001

[root@sn-0:/mnt/bricks/services/brick/netserv/ethip]
# getfattr -m . -d -e he