Can you get us the process state dump of the glusterfs client where httpd is hung? kill -USR1 <glusterfs pid> will generate /tmp/glusterdump.pid which is the dumpfile. Avati On Mon, Jun 13, 2011 at 2:18 PM, Jiri Lunacek <jiri.lunacek at hosting90.cz>wrote: > 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 > > > > _______________________________________________ > Gluster-users mailing list > Gluster-users at gluster.org > http://gluster.org/cgi-bin/mailman/listinfo/gluster-users > > -------------- next part -------------- An HTML attachment was scrubbed... URL: <http://gluster.org/pipermail/gluster-users/attachments/20110614/415ca30a/attachment-0001.htm>
