is this hang in a rename syscall is known?

is this hang in a rename syscall is known?

[Olga Kornievskaia]

Hi folks,

Getting this hang on a 5.5 kernel, is this a known issue? Thank you.

Apr  7 13:34:53 scspr1865142002 kernel:      Not tainted 5.5.7 #1
Apr  7 13:34:53 scspr1865142002 kernel: "echo 0 >
/proc/sys/kernel/hung_task_timeout_secs" disables this message.
Apr  7 13:34:53 scspr1865142002 kernel: dt              D    0 24788
24323 0x00000080
Apr  7 13:34:53 scspr1865142002 kernel: Call Trace:
Apr  7 13:34:53 scspr1865142002 kernel: ? __schedule+0x2ca/0x6e0
Apr  7 13:34:53 scspr1865142002 kernel: schedule+0x4a/0xb0
Apr  7 13:34:53 scspr1865142002 kernel: schedule_preempt_disabled+0xa/0x10
Apr  7 13:34:53 scspr1865142002 kernel: __mutex_lock.isra.11+0x233/0x4e0
Apr  7 13:34:53 scspr1865142002 kernel: ? strncpy_from_user+0x47/0x160
Apr  7 13:34:53 scspr1865142002 kernel: lock_rename+0x28/0xd0
Apr  7 13:34:53 scspr1865142002 kernel: do_renameat2+0x1e7/0x4f0
Apr  7 13:34:53 scspr1865142002 kernel: __x64_sys_rename+0x1c/0x20
Apr  7 13:34:53 scspr1865142002 kernel: do_syscall_64+0x5b/0x200
Apr  7 13:34:53 scspr1865142002 kernel: entry_SYSCALL_64_after_hwframe+0x44/0xa9
Apr  7 13:34:53 scspr1865142002 kernel: RIP: 0033:0x7f747a10ac77
Apr  7 13:34:53 scspr1865142002 kernel: Code: Bad RIP value.
Apr  7 13:34:53 scspr1865142002 kernel: RSP: 002b:00007f7479f92948
EFLAGS: 00000206 ORIG_RAX: 0000000000000052
Apr  7 13:34:53 scspr1865142002 kernel: RAX: ffffffffffffffda RBX:
00000000023604c0 RCX: 00007f747a10ac77
Apr  7 13:34:53 scspr1865142002 kernel: RDX: 0000000000000000 RSI:
00007f7479f94a80 RDI: 00007f7479f96b80
Apr  7 13:34:53 scspr1865142002 kernel: RBP: 0000000000000005 R08:
00007f7479f9d700 R09: 00007f7479f9d700
Apr  7 13:34:53 scspr1865142002 kernel: R10: 645f72656464616c R11:
0000000000000206 R12: 0000000000000001
Apr  7 13:34:53 scspr1865142002 kernel: R13: 00007f7479f98c80 R14:
00007f7479f9ad80 R15: 00007f7479f94a80

Re: is this hang in a rename syscall is known?

[Matthew Wilcox]

On Thu, Apr 09, 2020 at 12:44:25PM -0400, Olga Kornievskaia wrote:
> Hi folks,
> 
> Getting this hang on a 5.5 kernel, is this a known issue? Thank you.

I haven't seen it reported.

> Apr  7 13:34:53 scspr1865142002 kernel:      Not tainted 5.5.7 #1
> Apr  7 13:34:53 scspr1865142002 kernel: "echo 0 >
> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> Apr  7 13:34:53 scspr1865142002 kernel: dt              D    0 24788
> 24323 0x00000080
> Apr  7 13:34:53 scspr1865142002 kernel: Call Trace:
> Apr  7 13:34:53 scspr1865142002 kernel: ? __schedule+0x2ca/0x6e0
> Apr  7 13:34:53 scspr1865142002 kernel: schedule+0x4a/0xb0
> Apr  7 13:34:53 scspr1865142002 kernel: schedule_preempt_disabled+0xa/0x10
> Apr  7 13:34:53 scspr1865142002 kernel: __mutex_lock.isra.11+0x233/0x4e0
> Apr  7 13:34:53 scspr1865142002 kernel: ? strncpy_from_user+0x47/0x160
> Apr  7 13:34:53 scspr1865142002 kernel: lock_rename+0x28/0xd0

This task is doing a cross-directory rename() operation.  We only allow
one of those in progress per filesystem at any given time (because they're
quite rare and rearranging the tree like that plays merry havoc with the
locking, which you need to prevent a directory becoming its own ancestor).

So the question is, who else is in the middle of a rename operation and
has blocked for a long time while holding the s_vfs_rename_mutex?

As I recall, you work on NFS, so has something weird been going on with
your network?

Re: is this hang in a rename syscall is known?

[Olga Kornievskaia]

On Thu, Apr 9, 2020 at 2:51 PM Matthew Wilcox <willy@infradead.org> wrote:
>
> On Thu, Apr 09, 2020 at 12:44:25PM -0400, Olga Kornievskaia wrote:
> > Hi folks,
> >
> > Getting this hang on a 5.5 kernel, is this a known issue? Thank you.
>
> I haven't seen it reported.
>
> > Apr  7 13:34:53 scspr1865142002 kernel:      Not tainted 5.5.7 #1
> > Apr  7 13:34:53 scspr1865142002 kernel: "echo 0 >
> > /proc/sys/kernel/hung_task_timeout_secs" disables this message.
> > Apr  7 13:34:53 scspr1865142002 kernel: dt              D    0 24788
> > 24323 0x00000080
> > Apr  7 13:34:53 scspr1865142002 kernel: Call Trace:
> > Apr  7 13:34:53 scspr1865142002 kernel: ? __schedule+0x2ca/0x6e0
> > Apr  7 13:34:53 scspr1865142002 kernel: schedule+0x4a/0xb0
> > Apr  7 13:34:53 scspr1865142002 kernel: schedule_preempt_disabled+0xa/0x10
> > Apr  7 13:34:53 scspr1865142002 kernel: __mutex_lock.isra.11+0x233/0x4e0
> > Apr  7 13:34:53 scspr1865142002 kernel: ? strncpy_from_user+0x47/0x160
> > Apr  7 13:34:53 scspr1865142002 kernel: lock_rename+0x28/0xd0
>
> This task is doing a cross-directory rename() operation.  We only allow
> one of those in progress per filesystem at any given time (because they're
> quite rare and rearranging the tree like that plays merry havoc with the
> locking, which you need to prevent a directory becoming its own ancestor).
>
> So the question is, who else is in the middle of a rename operation and
> has blocked for a long time while holding the s_vfs_rename_mutex?
>
> As I recall, you work on NFS, so has something weird been going on with
> your network?

Yes indeed the renames were on NFS. I'll take a look at the network
trace (it didn't look like there was an unanswered renamed that would
have been holding a VFS lock). Thanks for reply so far.