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

Anand Avati anand.avati at gmail.com
Tue Jun 14 06:50:32 UTC 2011


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://supercolony.gluster.org/pipermail/gluster-users/attachments/20110614/415ca30a/attachment.html>


More information about the Gluster-users mailing list