+soumyak, +rtalur.
On Fri, Jan 29, 2016 at 2:34 PM, Pranith Kumar Karampuri <pkarampu@xxxxxxxxxx> wrote:
On 01/28/2016 05:05 PM, Pranith Kumar Karampuri wrote:
With baul jianguo's help I am able to see that FLUSH fops are hanging for some reason.+Raghavendra G
pk1@localhost - ~/Downloads
17:02:13 :) ⚡ grep "unique=" client-dump1.txt
unique=3160758373
unique=2073075682
unique=1455047665
unique=0
pk1@localhost - ~/Downloads
17:02:21 :) ⚡ grep "unique=" client-dump-0.txt
unique=3160758373
unique=2073075682
unique=1455047665
unique=0
I will be debugging a bit more and post my findings.
All the stubs are hung in write-behind. I checked that the statedumps doesn't have any writes in progress. May be because of some race, flush fop is not resumed after write calls are complete? It seems this issue happens only when io-threads is enabled on the client.
Pranith
Pranith
On 01/28/2016 03:18 PM, baul jianguo wrote:
the client glusterfs gdb info， main thread id is 70800。
In the top output，70800 thread time 1263:30，70810 thread time
1321:10，other thread time too small。
(gdb) thread apply all bt
Thread 9 (Thread 0x7fc21acaf700 (LWP 70801)):
#0 0x00007fc21cc0c535 in sigwait () from /lib64/libpthread.so.0
#1 0x000000000040539b in glusterfs_sigwaiter (arg=<value optimized
out>) at glusterfsd.c:1653
#2 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#3 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 8 (Thread 0x7fc21a2ae700 (LWP 70802)):
#0 0x00007fc21cc08a0e in pthread_cond_timedwait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007fc21ded02bf in syncenv_task (proc=0x121ee60) at syncop.c:493
#2 0x00007fc21ded6300 in syncenv_processor (thdata=0x121ee60) at syncop.c:571
#3 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#4 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 7 (Thread 0x7fc2198ad700 (LWP 70803)):
#0 0x00007fc21cc08a0e in pthread_cond_timedwait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007fc21ded02bf in syncenv_task (proc=0x121f220) at syncop.c:493
#2 0x00007fc21ded6300 in syncenv_processor (thdata=0x121f220) at syncop.c:571
#3 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#4 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 6 (Thread 0x7fc21767d700 (LWP 70805)):
#0 0x00007fc21cc0bfbd in nanosleep () from /lib64/libpthread.so.0
#1 0x00007fc21deb16bc in gf_timer_proc (ctx=0x11f2010) at timer.c:170
#2 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#3 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 5 (Thread 0x7fc20fb1e700 (LWP 70810)):
#0 0x00007fc21c566987 in readv () from /lib64/libc.so.6
#1 0x00007fc21accbc55 in fuse_thread_proc (data="" at
fuse-bridge.c:4752
#2 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#3 0x00007fc21c56e93d in clone () from /lib64/libc.so.6 时间最多
Thread 4 (Thread 0x7fc20f11d700 (LWP 70811)): 少点
#0 0x00007fc21cc0b7dd in read () from /lib64/libpthread.so.0
#1 0x00007fc21acc0e73 in read (data="" optimized out>) at
/usr/include/bits/unistd.h:45
#2 notify_kernel_loop (data="" optimized out>) at fuse-bridge.c:3786
#3 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#4 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 3 (Thread 0x7fc1b16fe700 (LWP 206224)):
---Type <return> to continue, or q <return> to quit---
#0 0x00007fc21cc08a0e in pthread_cond_timedwait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007fc20e515e60 in iot_worker (data="" at io-threads.c:157
#2 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#3 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 2 (Thread 0x7fc1b0bfb700 (LWP 214361)):
#0 0x00007fc21cc08a0e in pthread_cond_timedwait@@GLIBC_2.3.2 () from
/lib64/libpthread.so.0
#1 0x00007fc20e515e60 in iot_worker (data="" at io-threads.c:157
#2 0x00007fc21cc04a51 in start_thread () from /lib64/libpthread.so.0
#3 0x00007fc21c56e93d in clone () from /lib64/libc.so.6
Thread 1 (Thread 0x7fc21e31e700 (LWP 70800)):
#0 0x00007fc21c56ef33 in epoll_wait () from /lib64/libc.so.6
#1 0x00007fc21deea3e7 in event_dispatch_epoll (event_pool=0x120dec0)
at event-epoll.c:428
#2 0x00000000004075e4 in main (argc=4, argv=0x7fff3dc93698) at
glusterfsd.c:1983
On Thu, Jan 28, 2016 at 5:29 PM, baul jianguo <roidinev@xxxxxxxxx> wrote:
http://pastebin.centos.org/38941/
client statedump,only the pid 27419,168030,208655 hang，you can search
this pid in the statedump file。
On Wed, Jan 27, 2016 at 4:35 PM, Pranith Kumar Karampuri
<pkarampu@xxxxxxxxxx> wrote:
Hi,
If the hang appears on enabling client side io-threads then it could
be because of some race that is seen when io-threads is enabled on the
client side. 2 things will help us debug this issue:
1) thread apply all bt inside gdb (with debuginfo rpms/debs installed )
2) Complete statedump of the mount at two intervals preferably 10 seconds
apart. It becomes difficult to find out which ones are stuck vs the ones
that are on-going when we have just one statedump. If we have two, we can
find which frames are common in both of the statedumps and then take a
closer look there.
Feel free to ping me on #gluster-dev, nick: pranithk if you have the process
hung in that state and you guys don't mind me do a live debugging with you
guys. This option is the best of the lot!
Thanks a lot baul, Oleksandr for the debugging so far!
Pranith
On 01/25/2016 01:03 PM, baul jianguo wrote:
3.5.7 also hangs.only the flush op hung. Yes,off the
performance.client-io-threads ,no hang.
The hang does not relate the client kernel version.
One client statdump about flush op,any abnormal?
[global.callpool.stack.12]
uid=0
gid=0
pid=14432
unique=16336007098
lk-owner=77cb199aa36f3641
op=FLUSH
type=1
cnt=6
[global.callpool.stack.12.frame.1]
ref_count=1
translator=fuse
complete=0
[global.callpool.stack.12.frame.2]
ref_count=0
translator=datavolume-write-behind
complete=0
parent=datavolume-read-ahead
wind_from=ra_flush
wind_to=FIRST_CHILD (this)->fops->flush
unwind_to=ra_flush_cbk
[global.callpool.stack.12.frame.3]
ref_count=1
translator=datavolume-read-ahead
complete=0
parent=datavolume-open-behind
wind_from=default_flush_resume
wind_to=FIRST_CHILD(this)->fops->flush
unwind_to=default_flush_cbk
[global.callpool.stack.12.frame.4]
ref_count=1
translator=datavolume-open-behind
complete=0
parent=datavolume-io-threads
wind_from=iot_flush_wrapper
wind_to=FIRST_CHILD(this)->fops->flush
unwind_to=iot_flush_cbk
[global.callpool.stack.12.frame.5]
ref_count=1
translator=datavolume-io-threads
complete=0
parent=datavolume
wind_from=io_stats_flush
wind_to=FIRST_CHILD(this)->fops->flush
unwind_to=io_stats_flush_cbk
[global.callpool.stack.12.frame.6]
ref_count=1
translator=datavolume
complete=0
parent=fuse
wind_from=fuse_flush_resume
wind_to=xl->fops->flush
unwind_to=fuse_err_cbk
On Sun, Jan 24, 2016 at 5:35 AM, Oleksandr Natalenko
<oleksandr@xxxxxxxxxxxxxx> wrote:
With "performance.client-io-threads" set to "off" no hangs occurred in 3
rsync/rm rounds. Could that be some fuse-bridge lock race? Will bring
that
option to "on" back again and try to get full statedump.
On четвер, 21 січня 2016 р. 14:54:47 EET Raghavendra G wrote:
On Thu, Jan 21, 2016 at 10:49 AM, Pranith Kumar Karampuri <
pkarampu@xxxxxxxxxx> wrote:
On 01/18/2016 02:28 PM, Oleksandr Natalenko wrote:We also need to dump inode information. To do that you've to add
XFS. Server side works OK, I'm able to mount volume again. Brick isOleksandr,
30%
full.
Will it be possible to get the statedump of the client, bricks
output next time it happens?
https://github.com/gluster/glusterfs/blob/master/doc/debugging/statedump.m
d#how-to-generate-statedump
"all=yes"
to /var/run/gluster/glusterdump.options before you issue commands to get
statedump.
Pranith
On понеділок, 18 січня 2016 р. 15:07:18 EET baul jianguo wrote:_______________________________________________
What is your brick file system? and the glusterfsd process and all_______________________________________________
thread status?
I met same issue when client app such as rsync stay in D status,and
the brick process and relate thread also be in the D status.
And the brick dev disk util is 100% .
On Sun, Jan 17, 2016 at 6:13 AM, Oleksandr Natalenko
<oleksandr@xxxxxxxxxxxxxx> wrote:
Wrong assumption, rsync hung again.
On субота, 16 січня 2016 р. 22:53:04 EET Oleksandr Natalenko wrote:
One possible reason:_______________________________________________
cluster.lookup-optimize: on
cluster.readdir-optimize: on
I've disabled both optimizations, and at least as of now rsync
still
does
its job with no issues. I would like to find out what option causes
such
a
behavior and why. Will test more.
On пʼятниця, 15 січня 2016 р. 16:09:51 EET Oleksandr Natalenko
wrote:
Another observation: if rsyncing is resumed after hang, rsync_______________________________________________
itself
hangs a lot faster because it does stat of already copied files.
So,
the
reason may be not writing itself, but massive stat on GlusterFS
volume
as well.
15.01.2016 09:40, Oleksandr Natalenko написав:
While doing rsync over millions of files from ordinary partition_______________________________________________
to
GlusterFS volume, just after approx. first 2 million rsync hang
happens, and the following info appears in dmesg:
===
[17075038.924481] INFO: task rsync:10310 blocked for more than
120
seconds.
[17075038.931948] "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs"
disables this message.
[17075038.940748] rsync D ffff88207fc13680 0 10310
10309 0x00000080
[17075038.940752] ffff8809c578be18 0000000000000086
ffff8809c578bfd8
0000000000013680
[17075038.940756] ffff8809c578bfd8 0000000000013680
ffff880310cbe660
ffff881159d16a30
[17075038.940759] ffff881e3aa25800 ffff8809c578be48
ffff881159d16b10
ffff88087d553980
[17075038.940762] Call Trace:
[17075038.940770] [<ffffffff8160a1d9>] schedule+0x29/0x70
[17075038.940797] [<ffffffffa023a53d>]
__fuse_request_send+0x13d/0x2c0
[fuse]
[17075038.940801] [<ffffffffa023db30>] ?
fuse_get_req_nofail_nopages+0xc0/0x1e0 [fuse]
[17075038.940805] [<ffffffff81098350>] ? wake_up_bit+0x30/0x30
[17075038.940809] [<ffffffffa023a6d2>]
fuse_request_send+0x12/0x20
[fuse]
[17075038.940813] [<ffffffffa024382f>] fuse_flush+0xff/0x150
[fuse]
[17075038.940817] [<ffffffff811c45c4>] filp_close+0x34/0x80
[17075038.940821] [<ffffffff811e4ed8>] __close_fd+0x78/0xa0
[17075038.940824] [<ffffffff811c6103>] SyS_close+0x23/0x50
[17075038.940828] [<ffffffff81614de9>]
system_call_fastpath+0x16/0x1b
===
rsync blocks in D state, and to kill it, I have to do umount
--lazy
on
GlusterFS mountpoint, and then kill corresponding client
glusterfs
process. Then rsync exits.
Here is GlusterFS volume info:
===
Volume Name: asterisk_records
Type: Distributed-Replicate
Volume ID: dc1fe561-fa3a-4f2e-8330-ec7e52c75ba4
Status: Started
Number of Bricks: 3 x 2 = 6
Transport-type: tcp
Bricks:
Brick1:
server1:/bricks/10_megaraid_0_3_9_x_0_4_3_hdd_r1_nolvm_hdd_storage_0
1
/as
te
risk/records Brick2:
server2:/bricks/10_megaraid_8_5_14_x_8_6_16_hdd_r1_nolvm_hdd_storage
_
01/
as
terisk/records Brick3:
server1:/bricks/11_megaraid_0_5_4_x_0_6_5_hdd_r1_nolvm_hdd_storage_0
2
/as
te
risk/records Brick4:
server2:/bricks/11_megaraid_8_7_15_x_8_8_20_hdd_r1_nolvm_hdd_storage
_
02/
as
terisk/records Brick5:
server1:/bricks/12_megaraid_0_7_6_x_0_13_14_hdd_r1_nolvm_hdd_storage
_
03/
as
terisk/records Brick6:
server2:/bricks/12_megaraid_8_9_19_x_8_13_24_hdd_r1_nolvm_hdd_storag
e
_03
/a
sterisk/records Options Reconfigured:
cluster.lookup-optimize: on
cluster.readdir-optimize: on
client.event-threads: 2
network.inode-lru-limit: 4096
server.event-threads: 4
performance.client-io-threads: on
storage.linux-aio: on
performance.write-behind-window-size: 4194304
performance.stat-prefetch: on
performance.quick-read: on
performance.read-ahead: on
performance.flush-behind: on
performance.write-behind: on
performance.io-thread-count: 2
performance.cache-max-file-size: 1048576
performance.cache-size: 33554432
features.cache-invalidation: on
performance.readdir-ahead: on
===
The issue reproduces each time I rsync such an amount of files.
How could I debug this issue better?
_______________________________________________
Gluster-users mailing list
Gluster-users@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-users
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
Gluster-users mailing list
Gluster-users@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-users
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
_______________________________________________
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
_______________________________________________
Gluster-devel mailing list
Gluster-devel@xxxxxxxxxxx
http://www.gluster.org/mailman/listinfo/gluster-devel
Raghavendra G
_______________________________________________ Gluster-users mailing list Gluster-users@xxxxxxxxxxx http://www.gluster.org/mailman/listinfo/gluster-users
