* possible memory allocation deadlock in xfs_buf_allocate_memory @ 2012-10-11 18:13 Christian Kujau 2012-10-11 21:33 ` Dave Chinner 0 siblings, 1 reply; 3+ messages in thread From: Christian Kujau @ 2012-10-11 18:13 UTC (permalink / raw) To: xfs Hi, since Linux 3.5 I'm seeing these "inconsistent lock state" lockdep warnings [0]. They show up in 3.6 as well [1]. I was being told[2] that I may have run out of inode attributes. This may well be the case, but I cannot reformat the disk right now and will have to live with that warning a while longer. I got the warning again today, but 8h later the system hung and eventually shutdown. The last message from the box was received via netconsole: XFS: possible memory allocation deadlock in xfs_buf_allocate_memory (mode:0x250) This has been reported[3] for 3.2.1, but when the message was printed I was not around and could not watch /proc/slabinfo. The last -MARK- message (some kind of heartbeat message from syslog, printing "MARK" every 5min) has been received 07:55 local time, the netconsole message above was received 08:09, so two -MARK- messages were lost. sar(1) stopped recording at 08:05. These two incidents (the lockdep warning and the final lockup) may be unrelated (and timestamp-wise, they seem to be), but I thought I'd better report it. Full dmesg and .config: http://nerdbynature.de/bits/3.6.0/xfs/ Thanks, Christian. [0] http://oss.sgi.com/archives/xfs/2012-07/msg00113.html [1] http://oss.sgi.com/archives/xfs/2012-09/msg00305.html [2] http://oss.sgi.com/archives/xfs/2012-07/msg00116.html [3] http://oss.sgi.com/archives/xfs/2012-06/msg00362.html -- BOFH excuse #75: There isn't any problem _______________________________________________ xfs mailing list xfs@oss.sgi.com http://oss.sgi.com/mailman/listinfo/xfs ^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: possible memory allocation deadlock in xfs_buf_allocate_memory 2012-10-11 18:13 possible memory allocation deadlock in xfs_buf_allocate_memory Christian Kujau @ 2012-10-11 21:33 ` Dave Chinner 2012-10-11 22:06 ` Christian Kujau 0 siblings, 1 reply; 3+ messages in thread From: Dave Chinner @ 2012-10-11 21:33 UTC (permalink / raw) To: Christian Kujau; +Cc: xfs On Thu, Oct 11, 2012 at 11:13:14AM -0700, Christian Kujau wrote: > Hi, > > since Linux 3.5 I'm seeing these "inconsistent lock state" lockdep > warnings [0]. They show up in 3.6 as well [1]. I was being told[2] that I > may have run out of inode attributes. This may well be the case, but I > cannot reformat the disk right now and will have to live with that warning > a while longer. > > I got the warning again today, but 8h later the system hung and eventually > shutdown. The last message from the box was received via netconsole: > > XFS: possible memory allocation deadlock in xfs_buf_allocate_memory (mode:0x250) > > This has been reported[3] for 3.2.1, but when the message was printed I > was not around and could not watch /proc/slabinfo. > > The last -MARK- message (some kind of heartbeat message from syslog, > printing "MARK" every 5min) has been received 07:55 local time, the > netconsole message above was received 08:09, so two -MARK- messages were > lost. sar(1) stopped recording at 08:05. > > These two incidents (the lockdep warning and the final lockup) may be > unrelated (and timestamp-wise, they seem to be), but I thought I'd > better report it. > > Full dmesg and .config: http://nerdbynature.de/bits/3.6.0/xfs/o The inconsistent lock state is this path: Oct 11 00:18:27 alice kernel: [261506.767190] [e5e2fc70] [c00b5d44] vm_map_ram+0x228/0x5a0 Oct 11 00:18:27 alice kernel: [261506.768354] [e5e2fcf0] [c01a6f9c] _xfs_buf_map_pages+0x44/0x104 Oct 11 00:18:27 alice kernel: [261506.769522] [e5e2fd10] [c01a8090] xfs_buf_get_map+0x74/0x11c Oct 11 00:18:27 alice kernel: [261506.770698] [e5e2fd30] [c01ffad8] xfs_trans_get_buf_map+0xc0/0xdc Oct 11 00:18:27 alice kernel: [261506.772106] [e5e2fd50] [c01e9504] xfs_ifree_cluster+0x3f4/0x5b0 Oct 11 00:18:27 alice kernel: [261506.773309] [e5e2fde0] [c01eabc0] xfs_ifree+0xec/0xf0 Oct 11 00:18:27 alice kernel: [261506.774493] [e5e2fe20] [c01bd5c0] xfs_inactive+0x274/0x448 Oct 11 00:18:27 alice kernel: [261506.775672] [e5e2fe60] [c01b8450] xfs_fs_evict_inode+0x60/0x74 Oct 11 00:18:27 alice kernel: [261506.776863] [e5e2fe70] [c00dfa88] evict+0xc0/0x1b4 Oct 11 00:18:27 alice kernel: [261506.778046] [e5e2fe90] [c00db968] d_delete+0x1b0/0x1ec Oct 11 00:18:27 alice kernel: [261506.779235] [e5e2feb0] [c00d2e24] vfs_rmdir+0x124/0x128 Oct 11 00:18:27 alice kernel: [261506.780425] [e5e2fed0] [c00d2f10] do_rmdir+0xe8/0x110 Oct 11 00:18:27 alice kernel: [261506.781619] [e5e2ff40] [c0010aac] ret_from_syscall+0x0/0x38 Which indicates that it is this: > [1] http://oss.sgi.com/archives/xfs/2012-09/msg00305.html which is a real bug in the VM code that the VM developers refuse to fix even though it is simple to do and patches have been posted several times to fix it. /me points to his recent rant rather than repeating it: https://lkml.org/lkml/2012/6/13/628 However, that is unrelated to this message: XFS: possible memory allocation deadlock in xfs_buf_allocate_memory (mode:0x250) which triggers when memory cannot be allocated. mode 0x250 is ___GFP_NOWARN | ___GFP_IO | ___GFP_WAIT or more commonly known as: GFP_NOFS with warnings turned off. Basically the warning is saying "we're trying really hard to allocate memory, but we're not making progress". If it was only emitted once, however, it means that progress was made, as the message is emitted every 100 times through the loop and so only one message means it looped less than 200 times... What it does imply, however, is that vm_map_ram() is being called from GFP_NOFS context quite regularly and might be blocking there, and so the lockdep warning is more than just a nuisance - your system may indeed have hung there, but I don't have enough information to say for sure. When it hangs next time, can you get a blocked task dump from sysrq (i.e. sysrq-w, or "echo w > /proc/sysrq-trigger")? That's the only way we're going to know where the system hung. You might also want to ensure the hung task functionality is built into you kernel, so it automatically dumps stack traces for tasks hung longer than 120s... Cheers, Dave. -- Dave Chinner david@fromorbit.com _______________________________________________ xfs mailing list xfs@oss.sgi.com http://oss.sgi.com/mailman/listinfo/xfs ^ permalink raw reply [flat|nested] 3+ messages in thread
* Re: possible memory allocation deadlock in xfs_buf_allocate_memory 2012-10-11 21:33 ` Dave Chinner @ 2012-10-11 22:06 ` Christian Kujau 0 siblings, 0 replies; 3+ messages in thread From: Christian Kujau @ 2012-10-11 22:06 UTC (permalink / raw) To: Dave Chinner; +Cc: LKML, xfs [Cc'ed lkml, hence the full-quote] On Fri, 12 Oct 2012 at 08:33, Dave Chinner wrote: > On Thu, Oct 11, 2012 at 11:13:14AM -0700, Christian Kujau wrote: > > Hi, > > > > since Linux 3.5 I'm seeing these "inconsistent lock state" lockdep > > warnings [0]. They show up in 3.6 as well [1]. I was being told[2] that I > > may have run out of inode attributes. This may well be the case, but I > > cannot reformat the disk right now and will have to live with that warning > > a while longer. > > > > I got the warning again today, but 8h later the system hung and eventually > > shutdown. The last message from the box was received via netconsole: > > > > XFS: possible memory allocation deadlock in xfs_buf_allocate_memory (mode:0x250) > > > > This has been reported[3] for 3.2.1, but when the message was printed I > > was not around and could not watch /proc/slabinfo. > > > > The last -MARK- message (some kind of heartbeat message from syslog, > > printing "MARK" every 5min) has been received 07:55 local time, the > > netconsole message above was received 08:09, so two -MARK- messages were > > lost. sar(1) stopped recording at 08:05. > > > > These two incidents (the lockdep warning and the final lockup) may be > > unrelated (and timestamp-wise, they seem to be), but I thought I'd > > better report it. > > > > Full dmesg and .config: http://nerdbynature.de/bits/3.6.0/xfs/o > > The inconsistent lock state is this path: > > Oct 11 00:18:27 alice kernel: [261506.767190] [e5e2fc70] [c00b5d44] vm_map_ram+0x228/0x5a0 > Oct 11 00:18:27 alice kernel: [261506.768354] [e5e2fcf0] [c01a6f9c] _xfs_buf_map_pages+0x44/0x104 > Oct 11 00:18:27 alice kernel: [261506.769522] [e5e2fd10] [c01a8090] xfs_buf_get_map+0x74/0x11c > Oct 11 00:18:27 alice kernel: [261506.770698] [e5e2fd30] [c01ffad8] xfs_trans_get_buf_map+0xc0/0xdc > Oct 11 00:18:27 alice kernel: [261506.772106] [e5e2fd50] [c01e9504] xfs_ifree_cluster+0x3f4/0x5b0 > Oct 11 00:18:27 alice kernel: [261506.773309] [e5e2fde0] [c01eabc0] xfs_ifree+0xec/0xf0 > Oct 11 00:18:27 alice kernel: [261506.774493] [e5e2fe20] [c01bd5c0] xfs_inactive+0x274/0x448 > Oct 11 00:18:27 alice kernel: [261506.775672] [e5e2fe60] [c01b8450] xfs_fs_evict_inode+0x60/0x74 > Oct 11 00:18:27 alice kernel: [261506.776863] [e5e2fe70] [c00dfa88] evict+0xc0/0x1b4 > Oct 11 00:18:27 alice kernel: [261506.778046] [e5e2fe90] [c00db968] d_delete+0x1b0/0x1ec > Oct 11 00:18:27 alice kernel: [261506.779235] [e5e2feb0] [c00d2e24] vfs_rmdir+0x124/0x128 > Oct 11 00:18:27 alice kernel: [261506.780425] [e5e2fed0] [c00d2f10] do_rmdir+0xe8/0x110 > Oct 11 00:18:27 alice kernel: [261506.781619] [e5e2ff40] [c0010aac] ret_from_syscall+0x0/0x38 > > > Which indicates that it is this: > > > [1] http://oss.sgi.com/archives/xfs/2012-09/msg00305.html > > which is a real bug in the VM code that the VM developers refuse to > fix even though it is simple to do and patches have been posted > several times to fix it. > > /me points to his recent rant rather than repeating it: > > https://lkml.org/lkml/2012/6/13/628 Read through it, only understood the half of it. But interesting to see that there seems to be a real issue. > However, that is unrelated to this message: > > XFS: possible memory allocation deadlock in xfs_buf_allocate_memory (mode:0x250) > > which triggers when memory cannot be allocated. mode 0x250 is > > ___GFP_NOWARN | ___GFP_IO | ___GFP_WAIT > > or more commonly known as: > > GFP_NOFS > > with warnings turned off. Basically the warning is saying "we're > trying really hard to allocate memory, but we're not making > progress". If it was only emitted once, however, it means that > progress was made, as the message is emitted every 100 times through > the loop and so only one message means it looped less than 200 > times... Memory usage at that time was not different than on other days, so I don't know why it had a hard time allocating memory. But I don't have any numbers. > What it does imply, however, is that vm_map_ram() is being called > from GFP_NOFS context quite regularly and might be blocking there, > and so the lockdep warning is more than just a nuisance - your > system may indeed have hung there, but I don't have enough > information to say for sure. > > When it hangs next time, can you get a blocked task dump from sysrq > (i.e. sysrq-w, or "echo w > /proc/sysrq-trigger")? That's the only OK, will try to get this information the next time this happens. > way we're going to know where the system hung. You might also want > to ensure the hung task functionality is built into you kernel, so > it automatically dumps stack traces for tasks hung longer than > 120s... Yes, the option was already set: CONFIG_DETECT_HUNG_TASK=y CONFIG_DEFAULT_HUNG_TASK_TIMEOUT=120 # CONFIG_BOOTPARAM_HUNG_TASK_PANIC is not set CONFIG_BOOTPARAM_HUNG_TASK_PANIC_VALUE=0 Thanks for digging through this and for the explanation! Christian. -- BOFH excuse #398: Data for intranet got routed through the extranet and landed on the internet. _______________________________________________ xfs mailing list xfs@oss.sgi.com http://oss.sgi.com/mailman/listinfo/xfs ^ permalink raw reply [flat|nested] 3+ messages in thread
end of thread, other threads:[~2012-10-11 22:05 UTC | newest] Thread overview: 3+ messages (download: mbox.gz follow: Atom feed -- links below jump to the message on this page -- 2012-10-11 18:13 possible memory allocation deadlock in xfs_buf_allocate_memory Christian Kujau 2012-10-11 21:33 ` Dave Chinner 2012-10-11 22:06 ` Christian Kujau
This is a public inbox, see mirroring instructions for how to clone and mirror all data and code used for this inbox