From mboxrd@z Thu Jan 1 00:00:00 1970 Return-Path: Received: from mx5-phx2.redhat.com ([209.132.183.37]:54247 "EHLO mx5-phx2.redhat.com" rhost-flags-OK-OK-OK-OK) by vger.kernel.org with ESMTP id S1756713AbcJGP2N (ORCPT ); Fri, 7 Oct 2016 11:28:13 -0400 Date: Fri, 7 Oct 2016 11:27:55 -0400 (EDT) From: CAI Qian To: Jan Kara , Miklos Szeredi , tj , Al Viro , Linus Torvalds , Dave Chinner Cc: linux-xfs , Jens Axboe , Nick Piggin , linux-fsdevel@vger.kernel.org, Dave Jones Message-ID: <1267347639.1072505.1475854075552.JavaMail.zimbra@redhat.com> In-Reply-To: <1720038662.1062048.1475851398433.JavaMail.zimbra@redhat.com> References: <270577901.647921.1475682888765.JavaMail.zimbra@redhat.com> <874538236.682217.1475693824077.JavaMail.zimbra@redhat.com> <20161005200522.GE19539@ZenIV.linux.org.uk> <119370333.805584.1475756417736.JavaMail.zimbra@redhat.com> <1860793605.807021.1475756759147.JavaMail.zimbra@redhat.com> <20161007070838.GA16260@quack2.suse.cz> <1720038662.1062048.1475851398433.JavaMail.zimbra@redhat.com> Subject: Re: local DoS - systemd hang or timeout (WAS: Re: [RFC][CFT] splice_read reworked) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8BIT Sender: linux-fsdevel-owner@vger.kernel.org List-ID: > Hmm, this round of trinity triggered a different hang. This hang is reproducible so far with the command below on a overlayfs/xfs, $ trinity -g vfs --arch 64 --disable-fds=sockets --disable-fds=perf --disable-fds=epoll   --disable-fds=eventfd --disable-fds=pseudo --disable-fds=timerfd --disable-fds=memfd   --disable-fds=drm > > [ 2094.403119] INFO: task trinity-c0:3126 blocked for more than 120 seconds. > [ 2094.410705]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2094.417027] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2094.425770] trinity-c0      D ffff88044efc3d10 13472  3126   3124 > 0x00000084 > [ 2094.433659]  ffff88044efc3d10 ffffffff00000000 ffff880400000000 > ffff880822b5e000 > [ 2094.441965]  ffff88044c8b8000 ffff88044efc4000 ffff880443755670 > ffff880443755658 > [ 2094.450272]  ffffffff00000000 ffff88044c8b8000 ffff88044efc3d28 > ffffffff817cdaaf > [ 2094.458572] Call Trace: > [ 2094.461312]  [] schedule+0x3f/0xa0 > [ 2094.466858]  [] rwsem_down_write_failed+0x242/0x4b0 > [ 2094.474049]  [] ? rwsem_down_write_failed+0x6c/0x4b0 > [ 2094.481352]  [] ? __lock_acquire+0x472/0x1990 > [ 2094.487964]  [] call_rwsem_down_write_failed+0x17/0x30 > [ 2094.495450]  [] down_write+0x5f/0x80 > [ 2094.501190]  [] ? chown_common.isra.12+0x131/0x1e0 > [ 2094.508284]  [] chown_common.isra.12+0x131/0x1e0 > [ 2094.515177]  [] ? __sb_start_write+0xd1/0xf0 > [ 2094.521692]  [] ? preempt_count_add+0x47/0xc0 > [ 2094.528304]  [] ? mnt_clone_write+0x3f/0x70 > [ 2094.534723]  [] SyS_fchown+0x8f/0xa0 > [ 2094.540463]  [] do_syscall_64+0x6c/0x1e0 > [ 2094.546588]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2094.553784] 2 locks held by trinity-c0/3126: > [ 2094.558552]  #0:  (sb_writers#14){.+.+.+}, at: [] > __sb_start_write+0xd1/0xf0 > [ 2094.568240]  #1:  (&sb->s_type->i_mutex_key#17){++++++}, at: > [] chown_common.isra.12+0x131/0x1e0 > [ 2094.579864] INFO: task trinity-c1:3127 blocked for more than 120 seconds. > [ 2094.587442]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2094.593761] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2094.602503] trinity-c1      D ffff88045a1bbd10 13312  3127   3124 > 0x00000084 > [ 2094.610402]  ffff88045a1bbd10 ffff880443769fe8 ffff880400000000 > ffff88046cefe000 > [ 2094.618710]  ffff88044c8ba000 ffff88045a1bc000 ffff880443769fd0 > ffff88045a1bbd40 > [ 2094.627015]  ffff880443769fe8 ffff88044376a158 ffff88045a1bbd28 > ffffffff817cdaaf > [ 2094.635321] Call Trace: > [ 2094.638053]  [] schedule+0x3f/0xa0 > [ 2094.643597]  [] rwsem_down_read_failed+0x107/0x190 > [ 2094.650726]  [] ? xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2094.657727]  [] call_rwsem_down_read_failed+0x18/0x30 > [ 2094.665119]  [] down_read_nested+0x5b/0x80 > [ 2094.671457]  [] ? xfs_ilock+0xfa/0x260 [xfs] > [ 2094.677987]  [] xfs_ilock+0xfa/0x260 [xfs] > [ 2094.684324]  [] xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2094.691133]  [] vfs_fsync_range+0x3d/0xb0 > [ 2094.697354]  [] do_fsync+0x3d/0x70 > [ 2094.702896]  [] SyS_fsync+0x10/0x20 > [ 2094.708528]  [] do_syscall_64+0x6c/0x1e0 > [ 2094.714652]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2094.721844] 1 lock held by trinity-c1/3127: > [ 2094.726515]  #0:  (&xfs_nondir_ilock_class){++++..}, at: > [] xfs_ilock+0xfa/0x260 [xfs] > [ 2094.737181] INFO: task trinity-c2:3128 blocked for more than 120 seconds. > [ 2094.744751]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2094.751068] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2094.759810] trinity-c2      D ffff8804574f3df8 13472  3128   3124 > 0x00000084 > [ 2094.767692]  ffff8804574f3df8 0000000000000006 0000000000000000 > ffff8804569a4000 > [ 2094.776002]  ffff88044c8bc000 ffff8804574f4000 ffff8804622eb338 > ffff88044c8bc000 > [ 2094.784307]  0000000000000246 00000000ffffffff ffff8804574f3e10 > ffffffff817cdaaf > [ 2094.792605] Call Trace: > [ 2094.795340]  [] schedule+0x3f/0xa0 > [ 2094.800886]  [] schedule_preempt_disabled+0x18/0x30 > [ 2094.808078]  [] mutex_lock_nested+0x19f/0x450 > [ 2094.814688]  [] ? __fdget_pos+0x43/0x50 > [ 2094.820715]  [] __fdget_pos+0x43/0x50 > [ 2094.826544]  [] SyS_getdents+0x83/0x140 > [ 2094.832573]  [] ? fillonedir+0x100/0x100 > [ 2094.838699]  [] do_syscall_64+0x6c/0x1e0 > [ 2094.844822]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2094.852013] 1 lock held by trinity-c2/3128: > [ 2094.856682]  #0:  (&f->f_pos_lock){+.+.+.}, at: [] > __fdget_pos+0x43/0x50 > [ 2094.865969] INFO: task trinity-c3:3129 blocked for more than 120 seconds. > [ 2094.873547]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2094.879864] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2094.888606] trinity-c3      D ffff880455ce3e08 13440  3129   3124 > 0x00000084 > [ 2094.896495]  ffff880455ce3e08 0000000000000006 0000000000000000 > ffff88045144e000 > [ 2094.904803]  ffff88044c8be000 ffff880455ce4000 ffff8804622eb338 > ffff88044c8be000 > [ 2094.913111]  0000000000000246 00000000ffffffff ffff880455ce3e20 > ffffffff817cdaaf > [ 2094.921418] Call Trace: > [ 2094.924152]  [] schedule+0x3f/0xa0 > [ 2094.929695]  [] schedule_preempt_disabled+0x18/0x30 > [ 2094.936885]  [] mutex_lock_nested+0x19f/0x450 > [ 2094.943496]  [] ? __fdget_pos+0x43/0x50 > [ 2094.949526]  [] ? __audit_syscall_entry+0xaf/0x100 > [ 2094.956620]  [] __fdget_pos+0x43/0x50 > [ 2094.962454]  [] SyS_getdents64+0x81/0x130 > [ 2094.968675]  [] ? iterate_dir+0x190/0x190 > [ 2094.974895]  [] do_syscall_64+0x6c/0x1e0 > [ 2094.981019]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2094.988204] 1 lock held by trinity-c3/3129: > [ 2094.992872]  #0:  (&f->f_pos_lock){+.+.+.}, at: [] > __fdget_pos+0x43/0x50 > [ 2095.002158] INFO: task trinity-c4:3130 blocked for more than 120 seconds. > [ 2095.009734]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.016052] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.024793] trinity-c4      D ffff880458997e28 13392  3130   3124 > 0x00000084 > [ 2095.032690]  ffff880458997e28 0000000000000006 0000000000000000 > ffff88046ca18000 > [ 2095.040995]  ffff880458998000 ffff880458998000 ffff8804622eb338 > ffff880458998000 > [ 2095.049342]  0000000000000246 00000000ffffffff ffff880458997e40 > ffffffff817cdaaf > [ 2095.057650] Call Trace: > [ 2095.060382]  [] schedule+0x3f/0xa0 > [ 2095.065926]  [] schedule_preempt_disabled+0x18/0x30 > [ 2095.073118]  [] mutex_lock_nested+0x19f/0x450 > [ 2095.079728]  [] ? __fdget_pos+0x43/0x50 > [ 2095.085757]  [] __fdget_pos+0x43/0x50 > [ 2095.091589]  [] SyS_lseek+0x1d/0xb0 > [ 2095.097229]  [] do_syscall_64+0x6c/0x1e0 > [ 2095.103355]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2095.110547] 1 lock held by trinity-c4/3130: > [ 2095.115216]  #0:  (&f->f_pos_lock){+.+.+.}, at: [] > __fdget_pos+0x43/0x50 > [ 2095.124507] INFO: task trinity-c5:3131 blocked for more than 120 seconds. > [ 2095.132083]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.138402] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.147135] trinity-c5      D ffff88045a12bae0 13472  3131   3124 > 0x00000084 > [ 2095.155034]  ffff88045a12bae0 ffff880443769fe8 ffff880400000000 > ffff88046ca1a000 > [ 2095.163339]  ffff88045899a000 ffff88045a12c000 ffff880443769fd0 > ffff88045a12bb10 > [ 2095.171645]  ffff880443769fe8 0000000000000000 ffff88045a12baf8 > ffffffff817cdaaf > [ 2095.179952] Call Trace: > [ 2095.182684]  [] schedule+0x3f/0xa0 > [ 2095.188230]  [] rwsem_down_read_failed+0x107/0x190 > [ 2095.195341]  [] ? xfs_ilock_attr_map_shared+0x34/0x40 > [xfs] > [ 2095.203310]  [] call_rwsem_down_read_failed+0x18/0x30 > [ 2095.210696]  [] down_read_nested+0x5b/0x80 > [ 2095.217029]  [] ? xfs_ilock+0xfa/0x260 [xfs] > [ 2095.223558]  [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.229894]  [] xfs_ilock_attr_map_shared+0x34/0x40 > [xfs] > [ 2095.237682]  [] xfs_attr_get+0xdf/0x1b0 [xfs] > [ 2095.244312]  [] xfs_xattr_get+0x4c/0x70 [xfs] > [ 2095.250924]  [] generic_getxattr+0x59/0x70 > [ 2095.257244]  [] vfs_getxattr+0x8b/0xb0 > [ 2095.263177]  [] ovl_xattr_get+0x46/0x60 [overlay] > [ 2095.270176]  [] ovl_other_xattr_get+0x1a/0x20 [overlay] > [ 2095.277756]  [] generic_getxattr+0x59/0x70 > [ 2095.284079]  [] cap_inode_need_killpriv+0x2e/0x40 > [ 2095.291078]  [] security_inode_need_killpriv+0x33/0x50 > [ 2095.298560]  [] dentry_needs_remove_privs+0x30/0x50 > [ 2095.305743]  [] do_truncate+0x51/0xc0 > [ 2095.311581]  [] ? __sb_start_write+0xd1/0xf0 > [ 2095.318094]  [] ? __sb_start_write+0xd1/0xf0 > [ 2095.324609]  [] do_sys_ftruncate.constprop.15+0xfe/0x160 > [ 2095.332286]  [] SyS_ftruncate+0xe/0x10 > [ 2095.338225]  [] do_syscall_64+0x6c/0x1e0 > [ 2095.344339]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2095.351531] 2 locks held by trinity-c5/3131: > [ 2095.356297]  #0:  (sb_writers#14){.+.+.+}, at: [] > __sb_start_write+0xd1/0xf0 > [ 2095.365983]  #1:  (&xfs_nondir_ilock_class){++++..}, at: > [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.376647] INFO: task trinity-c6:3132 blocked for more than 120 seconds. > [ 2095.384216]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.390535] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.399275] trinity-c6      D ffff88044da5fd30 13312  3132   3124 > 0x00000084 > [ 2095.407177]  ffff88044da5fd30 ffffffff00000000 ffff880400000000 > ffff880459858000 > [ 2095.415485]  ffff88045899c000 ffff88044da60000 ffff880443755670 > ffff880443755658 > [ 2095.423789]  ffffffff00000000 ffff88045899c000 ffff88044da5fd48 > ffffffff817cdaaf > [ 2095.432094] Call Trace: > [ 2095.434825]  [] schedule+0x3f/0xa0 > [ 2095.440372]  [] rwsem_down_write_failed+0x242/0x4b0 > [ 2095.447565]  [] ? rwsem_down_write_failed+0x6c/0x4b0 > [ 2095.454854]  [] call_rwsem_down_write_failed+0x17/0x30 > [ 2095.462337]  [] down_write+0x5f/0x80 > [ 2095.468077]  [] ? chmod_common+0x63/0x150 > [ 2095.474300]  [] chmod_common+0x63/0x150 > [ 2095.480327]  [] ? __audit_syscall_entry+0xaf/0x100 > [ 2095.487421]  [] ? syscall_trace_enter+0x1dc/0x390 > [ 2095.494418]  [] SyS_fchmod+0x52/0x80 > [ 2095.500155]  [] do_syscall_64+0x6c/0x1e0 > [ 2095.506270]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2095.513452] 2 locks held by trinity-c6/3132: > [ 2095.518217]  #0:  (sb_writers#14){.+.+.+}, at: [] > __sb_start_write+0xd1/0xf0 > [ 2095.527895]  #1:  (&sb->s_type->i_mutex_key#17){++++++}, at: > [] chmod_common+0x63/0x150 > [ 2095.538648] INFO: task trinity-c7:3133 blocked for more than 120 seconds. > [ 2095.546227]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.552544] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.561288] trinity-c7      D ffff88044d393d10 13472  3133   3124 > 0x00000084 > [ 2095.569188]  ffff88044d393d10 ffff880443769fe8 ffff880400000000 > ffff88086ce68000 > [ 2095.577491]  ffff88045899e000 ffff88044d394000 ffff880443769fd0 > ffff88044d393d40 > [ 2095.585796]  ffff880443769fe8 ffff88044376a158 ffff88044d393d28 > ffffffff817cdaaf > [ 2095.594103] Call Trace: > [ 2095.596836]  [] schedule+0x3f/0xa0 > [ 2095.602379]  [] rwsem_down_read_failed+0x107/0x190 > [ 2095.609491]  [] ? xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2095.616490]  [] call_rwsem_down_read_failed+0x18/0x30 > [ 2095.623877]  [] down_read_nested+0x5b/0x80 > [ 2095.630212]  [] ? xfs_ilock+0xfa/0x260 [xfs] > [ 2095.636740]  [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.643076]  [] xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2095.649889]  [] vfs_fsync_range+0x3d/0xb0 > [ 2095.656109]  [] do_fsync+0x3d/0x70 > [ 2095.661653]  [] SyS_fsync+0x10/0x20 > [ 2095.667291]  [] do_syscall_64+0x6c/0x1e0 > [ 2095.673417]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2095.680610] 1 lock held by trinity-c7/3133: > [ 2095.685281]  #0:  (&xfs_nondir_ilock_class){++++..}, at: > [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.695947] INFO: task trinity-c8:3135 blocked for more than 120 seconds. > [ 2095.703530]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.709848] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.718590] trinity-c8      D ffff88044d3b3d10 12912  3135   3124 > 0x00000084 > [ 2095.726470]  ffff88044d3b3d10 ffff880443769fe8 ffff880400000000 > ffff88046ca30000 > [ 2095.734775]  ffff88044d3a8000 ffff88044d3b4000 ffff880443769fd0 > ffff88044d3b3d40 > [ 2095.743083]  ffff880443769fe8 ffff88044376a158 ffff88044d3b3d28 > ffffffff817cdaaf > [ 2095.751387] Call Trace: > [ 2095.754119]  [] schedule+0x3f/0xa0 > [ 2095.759662]  [] rwsem_down_read_failed+0x107/0x190 > [ 2095.766772]  [] ? xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2095.773763]  [] call_rwsem_down_read_failed+0x18/0x30 > [ 2095.781148]  [] down_read_nested+0x5b/0x80 > [ 2095.787482]  [] ? xfs_ilock+0xfa/0x260 [xfs] > [ 2095.794013]  [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.800347]  [] xfs_file_fsync+0xea/0x2e0 [xfs] > [ 2095.807155]  [] vfs_fsync_range+0x3d/0xb0 > [ 2095.813377]  [] do_fsync+0x3d/0x70 > [ 2095.818921]  [] SyS_fdatasync+0x13/0x20 > [ 2095.824949]  [] do_syscall_64+0x6c/0x1e0 > [ 2095.831074]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2095.838261] 1 lock held by trinity-c8/3135: > [ 2095.842930]  #0:  (&xfs_nondir_ilock_class){++++..}, at: > [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.853588] INFO: task trinity-c9:3136 blocked for more than 120 seconds. > [ 2095.861167]       Not tainted 4.8.0-rc8-splice-fixw-proc+ #4 > [ 2095.867485] "echo 0 > /proc/sys/kernel/hung_task_timeout_secs" disables > this message. > [ 2095.876228] trinity-c9      D ffff88045b3679e0 13328  3136   3124 > 0x00000084 > [ 2095.884111]  ffff88045b3679e0 ffff880443769fe8 ffff880400000000 > ffff88086ce56000 > [ 2095.892417]  ffff88044d3aa000 ffff88045b368000 ffff880443769fd0 > ffff88045b367a10 > [ 2095.900721]  ffff880443769fe8 ffff88044376a1e8 ffff88045b3679f8 > ffffffff817cdaaf > [ 2095.909024] Call Trace: > [ 2095.911761]  [] schedule+0x3f/0xa0 > [ 2095.917305]  [] rwsem_down_read_failed+0x107/0x190 > [ 2095.924414]  [] ? xfs_ilock_data_map_shared+0x30/0x40 > [xfs] > [ 2095.932383]  [] call_rwsem_down_read_failed+0x18/0x30 > [ 2095.939768]  [] down_read_nested+0x5b/0x80 > [ 2095.946104]  [] ? xfs_ilock+0xfa/0x260 [xfs] > [ 2095.952632]  [] xfs_ilock+0xfa/0x260 [xfs] > [ 2095.958968]  [] xfs_ilock_data_map_shared+0x30/0x40 > [xfs] > [ 2095.966752]  [] __xfs_get_blocks+0x96/0x9d0 [xfs] > [ 2095.973753]  [] ? > mem_cgroup_event_ratelimit.isra.39+0x3e/0xb0 > [ 2095.982012]  [] ? mem_cgroup_commit_charge+0x95/0x110 > [ 2095.989413]  [] xfs_get_blocks+0x14/0x20 [xfs] > [ 2095.996122]  [] do_mpage_readpage+0x474/0x800 > [ 2096.002745]  [] ? __xfs_get_blocks+0x9d0/0x9d0 [xfs] > [ 2096.010037]  [] ? debug_smp_processor_id+0x17/0x20 > [ 2096.017136]  [] ? __lru_cache_add+0x75/0xb0 > [ 2096.023551]  [] ? lru_cache_add+0xe/0x10 > [ 2096.029678]  [] mpage_readpages+0x13d/0x1b0 > [ 2096.036109]  [] ? __xfs_get_blocks+0x9d0/0x9d0 [xfs] > [ 2096.043420]  [] ? __xfs_get_blocks+0x9d0/0x9d0 [xfs] > [ 2096.050724]  [] xfs_vm_readpages+0x54/0x170 [xfs] > [ 2096.057724]  [] __do_page_cache_readahead+0x2ad/0x370 > [ 2096.065113]  [] ? __do_page_cache_readahead+0x17c/0x370 > [ 2096.072693]  [] ? __audit_syscall_entry+0xaf/0x100 > [ 2096.079787]  [] force_page_cache_readahead+0x94/0xf0 > [ 2096.087077]  [] SyS_readahead+0xa8/0xc0 > [ 2096.093106]  [] do_syscall_64+0x6c/0x1e0 > [ 2096.099234]  [] entry_SYSCALL64_slow_path+0x25/0x25 > [ 2096.106427] 1 lock held by trinity-c9/3136: > [ 2096.111097]  #0:  (&xfs_nondir_ilock_class){++++..}, at: > [] xfs_ilock+0xfa/0x260 [xfs] >