[Gluster-users] Apache hung tasks still occur with glusterfs 3.2.1

Jiri Lunacek jiri.lunacek at hosting90.cz
Mon Jun 13 17:14:09 UTC 2011


Thanks for the tip. I disabled io-cache and stat-prefetch, increased io-thread-count to 64 and rebooted the server to clean off the hung apache processes. We'll see tomorrow.

On 13.6.2011, at 15:58, Justice London wrote:

> Disable io-cache and up the threads to 64 and your problems should disappear. They did for me when I made both of these changes.
>  
> Justice London
>  
> From: gluster-users-bounces at gluster.org [mailto:gluster-users-bounces at gluster.org] On Behalf Of Jiri Lunacek
> Sent: Monday, June 13, 2011 1:49 AM
> To: gluster-users at gluster.org
> Subject: [Gluster-users] Apache hung tasks still occur with glusterfs 3.2.1
>  
> Hi all.
>  
> We have been having problems with hung tasks of apache reading from glusterfs 2-replica volume ever since upgrading to 3.2.0. The problems were identical to those described here: http://gluster.org/pipermail/gluster-users/2011-May/007697.html
>  
> Yesterday we updated to 3.2.1.
>  
> A good thing is that the hung tasks stopped appearing when gluster is in "intact" operation, i.e. when there are no modifications to the gluster configs at all.
> Today we modified some other volume exported by the same cluster (but not sharing anything with the volume used by the apache process). And, once again, two requests of apache reading from glusterfs volume are stuck.
>  
> Any help with this issue would be very appreciated as right now we have to nightly-reboot the machine as the processes re stuck in iowait -> unkillable.
>  
> I really do not want to go through the downgrade to 3.1.4 since it seems from the mailing list that it may not go exactly smooth. We are exporting millions of files and any large operation on the exported filesystem takes days.
>  
> I am attaching tech info on the problem.
>  
> client:
> Centos 5.6
> 2.6.18-238.9.1.el5
> fuse-2.7.4-8.el5
> glusterfs-fuse-3.2.1-1
> glusterfs-core-3.2.1-1
>  
> servers:
> Centos 5.6
> 2.6.18-194.32.1.el5
> fuse-2.7.4-8.el5
> glusterfs-fuse-3.2.1-1
> glusterfs-core-3.2.1-1
>  
> dmesg:
> INFO: task httpd:1246 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> httpd         D ffff81000101d7a0     0  1246   2394          1247  1191 (NOTLB)
>  ffff81013ee7dc38 0000000000000082 0000000000000092 ffff81013ee7dcd8
>  ffff81013ee7dd04 000000000000000a ffff810144d0f7e0 ffff81019fc28100
>  0000308f8b444727 00000000000014ee ffff810144d0f9c8 000000038006e608
> Call Trace:
>  [<ffffffff8006ec4e>] do_gettimeofday+0x40/0x90
>  [<ffffffff80028c5a>] sync_page+0x0/0x43
>  [<ffffffff800637ca>] io_schedule+0x3f/0x67
>  [<ffffffff80028c98>] sync_page+0x3e/0x43
>  [<ffffffff8006390e>] __wait_on_bit_lock+0x36/0x66
>  [<ffffffff8003ff27>] __lock_page+0x5e/0x64
>  [<ffffffff800a2921>] wake_bit_function+0x0/0x23
>  [<ffffffff8003fd85>] pagevec_lookup+0x17/0x1e
>  [<ffffffff800cc666>] invalidate_inode_pages2_range+0x73/0x1bd
>  [<ffffffff8004fc94>] finish_wait+0x32/0x5d
>  [<ffffffff884b9798>] :fuse:wait_answer_interruptible+0xb6/0xbd
>  [<ffffffff800a28f3>] autoremove_wake_function+0x0/0x2e
>  [<ffffffff8009a485>] recalc_sigpending+0xe/0x25
>  [<ffffffff8001decc>] sigprocmask+0xb7/0xdb
>  [<ffffffff884bd456>] :fuse:fuse_finish_open+0x36/0x62
>  [<ffffffff884bda11>] :fuse:fuse_open_common+0x147/0x158
>  [<ffffffff884bda22>] :fuse:fuse_open+0x0/0x7
>  [<ffffffff8001eb99>] __dentry_open+0xd9/0x1dc
>  [<ffffffff8002766e>] do_filp_open+0x2a/0x38
>  [<ffffffff8001a061>] do_sys_open+0x44/0xbe
>  [<ffffffff8005d28d>] tracesys+0xd5/0xe0
>  
> INFO: task httpd:1837 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> httpd         D ffff810001004420     0  1837   2394          1856  1289 (NOTLB)
>  ffff81013c6f9c38 0000000000000086 ffff81013c6f9bf8 00000000fffffffe
>  ffff810170ce7000 000000000000000a ffff81019c0ae7a0 ffffffff80311b60
>  0000308c0f83d792 0000000000000ec4 ffff81019c0ae988 000000008006e608
> Call Trace:
>  [<ffffffff8006ec4e>] do_gettimeofday+0x40/0x90
>  [<ffffffff80028c5a>] sync_page+0x0/0x43
>  [<ffffffff800637ca>] io_schedule+0x3f/0x67
>  [<ffffffff80028c98>] sync_page+0x3e/0x43
>  [<ffffffff8006390e>] __wait_on_bit_lock+0x36/0x66
>  [<ffffffff8003ff27>] __lock_page+0x5e/0x64
>  [<ffffffff800a2921>] wake_bit_function+0x0/0x23
>  [<ffffffff8003fd85>] pagevec_lookup+0x17/0x1e
>  [<ffffffff800cc666>] invalidate_inode_pages2_range+0x73/0x1bd
>  [<ffffffff8004fc94>] finish_wait+0x32/0x5d
>  [<ffffffff884b9798>] :fuse:wait_answer_interruptible+0xb6/0xbd
>  [<ffffffff800a28f3>] autoremove_wake_function+0x0/0x2e
>  [<ffffffff8009a485>] recalc_sigpending+0xe/0x25
>  [<ffffffff8001decc>] sigprocmask+0xb7/0xdb
>  [<ffffffff884bd456>] :fuse:fuse_finish_open+0x36/0x62
>  [<ffffffff884bda11>] :fuse:fuse_open_common+0x147/0x158
>  [<ffffffff884bda22>] :fuse:fuse_open+0x0/0x7
>  [<ffffffff8001eb99>] __dentry_open+0xd9/0x1dc
>  [<ffffffff8002766e>] do_filp_open+0x2a/0x38
>  [<ffffffff8001a061>] do_sys_open+0x44/0xbe
>  [<ffffffff8005d28d>] tracesys+0xd5/0xe0
>  
> INFO: task httpd:383 blocked for more than 120 seconds.
> "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> httpd         D ffff81019fa21100     0   383   2394           534       (NOTLB)
>  ffff81013e497c08 0000000000000082 ffff810183eb8910 ffffffff884b9219
>  ffff81019e41c600 0000000000000009 ffff81019b1e2100 ffff81019fa21100
>  0000308c0e2c2bfb 0000000000016477 ffff81019b1e22e8 000000038006e608
> Call Trace:
>  [<ffffffff884b9219>] :fuse:flush_bg_queue+0x2b/0x48
>  [<ffffffff8006ec4e>] do_gettimeofday+0x40/0x90
>  [<ffffffff8005a9f9>] getnstimeofday+0x10/0x28
>  [<ffffffff80028c5a>] sync_page+0x0/0x43
>  [<ffffffff800637ca>] io_schedule+0x3f/0x67
>  [<ffffffff80028c98>] sync_page+0x3e/0x43
>  [<ffffffff8006390e>] __wait_on_bit_lock+0x36/0x66
>  [<ffffffff8003ff27>] __lock_page+0x5e/0x64
>  [<ffffffff800a2921>] wake_bit_function+0x0/0x23
>  [<ffffffff8000c48d>] do_generic_mapping_read+0x1df/0x359
>  [<ffffffff8000d279>] file_read_actor+0x0/0x159
>  [<ffffffff8000c753>] __generic_file_aio_read+0x14c/0x198
>  [<ffffffff800c8c45>] generic_file_read+0xac/0xc5
>  [<ffffffff800a28f3>] autoremove_wake_function+0x0/0x2e
>  [<ffffffff80130778>] selinux_file_permission+0x9f/0xb4
>  [<ffffffff8000b78d>] vfs_read+0xcb/0x171
>  [<ffffffff80011d34>] sys_read+0x45/0x6e
>  [<ffffffff8005d28d>] tracesys+0xd5/0xe0
>  
> possibly relevant log messages:
> [2011-06-13 09:09:14.985576] W [socket.c:1494:__socket_proto_state_machine] 0-glusterfs: reading from socket failed. Error (Transport endpoint is not connected), peer (81.0.225.122:24007)
> [2011-06-13 09:09:25.741055] I [glusterfsd-mgmt.c:637:mgmt_getspec_cbk] 0-: No change in volfile, continuing
> [2011-06-13 09:59:00.644130] I [afr-common.c:639:afr_lookup_self_heal_check] 0-isifa1-replicate-0: size differs for /data/foto/thumbs/3140/31409780.jpg 
> [2011-06-13 09:59:00.644269] I [afr-common.c:801:afr_lookup_done] 0-isifa1-replicate-0: background  meta-data data self-heal triggered. path: /data/foto/thumbs/3140/31409780.jpg
> [2011-06-13 09:59:00.822524] W [dict.c:437:dict_ref] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/protocol/client.so(client3_1_fstat_cbk+0x2cb) [0x2aaaab1afa0b] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/cluster/replicate.so(afr_sh_data_fstat_cbk+0x17d) [0x2aaaab3e4c9d] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/cluster/replicate.so(afr_sh_data_fix+0x1fc) [0x2aaaab3e493c]))) 0-dict: dict is NULL
> [2011-06-13 09:59:00.824323] I [afr-common.c:639:afr_lookup_self_heal_check] 0-isifa1-replicate-0: size differs for /data/foto/thumbs/3140/31409781.jpg 
> [2011-06-13 09:59:00.824356] I [afr-common.c:801:afr_lookup_done] 0-isifa1-replicate-0: background  meta-data data self-heal triggered. path: /data/foto/thumbs/3140/31409781.jpg
> [2011-06-13 09:59:00.826494] I [afr-self-heal-common.c:1557:afr_self_heal_completion_cbk] 0-isifa1-replicate-0: background  meta-data data self-heal completed on /data/foto/thumbs/3140/31409780.jpg
> [2011-06-13 09:59:00.830902] W [dict.c:437:dict_ref] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/protocol/client.so(client3_1_fstat_cbk+0x2cb) [0x2aaaab1afa0b] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/cluster/replicate.so(afr_sh_data_fstat_cbk+0x17d) [0x2aaaab3e4c9d] (-->/opt/glusterfs/3.2.1/lib64/glusterfs/3.2.1/xlator/cluster/replicate.so(afr_sh_data_fix+0x1fc) [0x2aaaab3e493c]))) 0-dict: dict is NULL
>  
>  
> gluster-server volume config:
> volume isifa1-posix
>     type storage/posix
>     option directory /mnt/data/isifa1
> end-volume
>  
> volume isifa1-access-control
>     type features/access-control
>     subvolumes isifa1-posix
> end-volume
>  
> volume isifa1-locks
>     type features/locks
>     subvolumes isifa1-access-control
> end-volume
>  
> volume isifa1-io-threads
>     type performance/io-threads
>     subvolumes isifa1-locks
> end-volume
>  
> volume isifa1-marker
>     type features/marker
>     option volume-uuid 39d5c509-ad39-4b24-a272-c33e212cf912
>     option timestamp-file /etc/glusterd/vols/isifa1/marker.tstamp
>     option xtime off
>     option quota off
>     subvolumes isifa1-io-threads
> end-volume
>  
> volume /mnt/data/isifa1
>     type debug/io-stats
>     option latency-measurement off
>     option count-fop-hits off
>     subvolumes isifa1-marker
> end-volume
>  
> volume isifa1-server
>     type protocol/server
>     option transport-type tcp
>     option auth.addr./mnt/data/isifa1.allow 81.0.225.120,81.0.225.121,81.0.225.90,81.0.225.117,81.0.225.118,82.208.17.113
>     subvolumes /mnt/data/isifa1
> end-volume
>  
> gluster-fuse config:
> volume isifa1-client-0
>     type protocol/client
>     option remote-host isifa-data1
>     option remote-subvolume /mnt/data/isifa1
>     option transport-type tcp
> end-volume
>  
> volume isifa1-client-1
>     type protocol/client
>     option remote-host isifa-data2
>     option remote-subvolume /mnt/data/isifa1
>     option transport-type tcp
> end-volume
>  
> volume isifa1-replicate-0
>     type cluster/replicate
>     subvolumes isifa1-client-0 isifa1-client-1
> end-volume
>  
> volume isifa1-write-behind
>     type performance/write-behind
>     subvolumes isifa1-replicate-0
> end-volume
>  
> volume isifa1-read-ahead
>     type performance/read-ahead
>     subvolumes isifa1-write-behind
> end-volume
>  
> volume isifa1-io-cache
>     type performance/io-cache
>     subvolumes isifa1-read-ahead
> end-volume
>  
> volume isifa1-quick-read
>     type performance/quick-read
>     subvolumes isifa1-io-cache
> end-volume
>  
> volume isifa1-stat-prefetch
>     type performance/stat-prefetch
>     subvolumes isifa1-quick-read
> end-volume
>  
> volume isifa1
>     type debug/io-stats
>     option latency-measurement off
>     option count-fop-hits off
>     subvolumes isifa1-stat-prefetch
> end-volume
>  
>  

-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://supercolony.gluster.org/pipermail/gluster-users/attachments/20110613/0e23824a/attachment.html>


More information about the Gluster-users mailing list