xfs_iunlink_remove: xfs_inotobp() returned error 22 -- debugging

符永涛 yongtaofu at gmail.com
Thu Apr 18 03:25:38 CDT 2013


Hi Brian and Eric,
Can I change as following to bypass it?
--- a/xfs_inode.c
+++ b/xfs_inode.c
@@ -1764,7 +1764,7 @@ xfs_iunlink_remove(
                 */
                next_agino = be32_to_cpu(agi->agi_unlinked[bucket_index]);
                last_ibp = NULL;
-               while (next_agino != agino) {
+               while (next_agino != agino && next_agino != NULLAGINO) {
                        /*
                         * If the last inode wasn't the one pointing to
                         * us, then release its buffer since we're not
@@ -1786,6 +1786,14 @@ xfs_iunlink_remove(
                        ASSERT(next_agino != NULLAGINO);
                        ASSERT(next_agino != 0);
                }
+               if (next_agino == NULLAGINO) {
+                       /*
+                        *After search the list for the inode being free
+                        *we still can't find it.
+                        */
+                       xfs_err(mp, "%s ino %lld not found in unlinked
list.",
+                                    __func__, (unsigned long
long)ip->i_ino);
+               }
                /*
                 * Now last_ibp points to the buffer previous to us on
                 * the unlinked list.  Pull us from the list.
@@ -1810,16 +1818,20 @@ xfs_iunlink_remove(
                } else {
                        xfs_trans_brelse(tp, ibp);
                }
-               /*
-                * Point the previous inode on the list to the next inode.
-                */
-               last_dip->di_next_unlinked = cpu_to_be32(next_agino);
-               ASSERT(next_agino != 0);
-               offset = last_offset + offsetof(xfs_dinode_t,
di_next_unlinked);
-               xfs_trans_inode_buf(tp, last_ibp);
-               xfs_trans_log_buf(tp, last_ibp, offset,
-                                 (offset + sizeof(xfs_agino_t) - 1));
-               xfs_inobp_check(mp, last_ibp);
+               if (next_agino != NULLAGINO) {
+                       /*
+                       * If only find the inode being free then we modify
+                       * the unlinked list.
+                       * Point the previous inode on the list to the next
inode.
+                       */
+                       last_dip->di_next_unlinked =
cpu_to_be32(next_agino);
+                       ASSERT(next_agino != 0);
+                       offset = last_offset + offsetof(xfs_dinode_t,
di_next_unlinked);
+                       xfs_trans_inode_buf(tp, last_ibp);
+                       xfs_trans_log_buf(tp, last_ibp, offset,
+                                         (offset + sizeof(xfs_agino_t) -
1));
+                       xfs_inobp_check(mp, last_ibp);
+               }
        }
        return 0;
 }

Thank you.


2013/4/18 符永涛 <yongtaofu at gmail.com>

> Hi Brain and Eric,
> If the problem is the agno can't be found in the unlinked list. Can we
> just bypass it instead of passing ino=0xffffffff to xfs_inotobp?
> Thank you.
>
>
> 2013/4/18 符永涛 <yongtaofu at gmail.com>
>
>> Hi Eric,
>> The shutdown issue is still not reproduced yet. But I get the following
>> error today during test.
>>
>> Apr 18 07:42:51 10 kernel: Call Trace:
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d91ef>] ?
>> xfs_buf_cond_lock+0x2f/0xc0 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff814fe6a5>]
>> schedule_timeout+0x215/0x2e0
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d5f07>] ?
>> kmem_zone_alloc+0x77/0xf0 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff814ff5c2>] __down+0x72/0xb0
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02da652>] ?
>> _xfs_buf_find+0x102/0x280 [xfs]
>> Apr 18 07:42:51 10 kernel: "echo 0 >
>> /proc/sys/kernel/hung_task_timeout_secs" disables this message.
>> Apr 18 07:42:51 10 kernel: glusterfsd    D ffffffff8160b3c0     0
>> 14522      1 0x00000083
>> Apr 18 07:42:51 10 kernel: ffff882015a63a28 0000000000000082
>> 0000000000000000 0000000000000000
>> Apr 18 07:42:51 10 kernel: ffff882015a639b8 ffffffffa02d91ef
>> ffff882015a639d8 0000000000000246
>> Apr 18 07:42:51 10 kernel: ffff880e70491af8 ffff882015a63fd8
>> 000000000000fb88 ffff880e70491af8
>> Apr 18 07:42:51 10 kernel: Call Trace:
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d91ef>] ?
>> xfs_buf_cond_lock+0x2f/0xc0 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff814fe6a5>]
>> schedule_timeout+0x215/0x2e0
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d5f07>] ?
>> kmem_zone_alloc+0x77/0xf0 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff814ff5c2>] __down+0x72/0xb0
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02da652>] ?
>> _xfs_buf_find+0x102/0x280 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff81097ef1>] down+0x41/0x50
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02da493>] xfs_buf_lock+0x53/0x110
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02da652>] _xfs_buf_find+0x102/0x280
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02da83b>] xfs_buf_get+0x6b/0x1a0
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02daeac>] xfs_buf_read+0x2c/0x100
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d0af8>]
>> xfs_trans_read_buf+0x1f8/0x400 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02b3444>] xfs_read_agi+0x74/0x100
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02b967b>] xfs_iunlink+0x5b/0x180
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff810724c7>] ?
>> current_fs_time+0x27/0x30
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d12a7>] ?
>> xfs_trans_ichgtime+0x27/0xa0 [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d15fb>] xfs_droplink+0x5b/0x70
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02d2f9e>] xfs_remove+0x27e/0x3a0
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff81186fd3>] ?
>> generic_permission+0x23/0xb0
>> Apr 18 07:42:51 10 kernel: [<ffffffffa02e0968>] xfs_vn_unlink+0x48/0x90
>> [xfs]
>> Apr 18 07:42:51 10 kernel: [<ffffffff81188c0f>] vfs_unlink+0x9f/0xe0
>> Apr 18 07:42:51 10 kernel: [<ffffffff8118795a>] ? lookup_hash+0x3a/0x50
>> Apr 18 07:42:51 10 kernel: [<ffffffff8118b143>] do_unlinkat+0x183/0x1c0
>> Apr 18 07:42:51 10 kernel: [<ffffffff81017938>] ?
>> syscall_trace_enter+0x1d8/0x1e0
>> Apr 18 07:42:51 10 kernel: [<ffffffff8118b196>] sys_unlink+0x16/0x20
>> Apr 18 07:42:51 10 kernel: [<ffffffff8100b308>] tracesys+0xd9/0xde
>>
>> Thank you.
>>
>>
>> 2013/4/17 Eric Sandeen <sandeen at sandeen.net>
>>
>>> On Apr 16, 2013, at 8:48 PM, 符永涛 <yongtaofu at gmail.com> wrote:
>>>
>>> Hi Brain,
>>> Can I change as following?
>>>
>>>
>>> ASSERTS are no-ops in a non-debug kernel, so this won't change any
>>> behavior.  I hope we'll know more if we get new traces from your patched
>>> kernel....
>>>
>>> Eric
>>>
>>> --- a/xfs_inode.c
>>> +++ b/xfs_inode.c
>>> @@ -1773,6 +1773,8 @@ xfs_iunlink_remove(
>>>                         if (last_ibp != NULL) {
>>>                                 xfs_trans_brelse(tp, last_ibp);
>>>                         }
>>> +                        ASSERT(next_agino != NULLAGINO);
>>> +                        ASSERT(next_agino != 0);
>>>                         next_ino = XFS_AGINO_TO_INO(mp, agno,
>>> next_agino);
>>>                         error = xfs_inotobp(mp, tp, next_ino, &last_dip,
>>>                                             &last_ibp, &last_offset, 0);
>>> @@ -1783,8 +1785,6 @@ xfs_iunlink_remove(
>>>                                 return error;
>>>                         }
>>>                         next_agino =
>>> be32_to_cpu(last_dip->di_next_unlinked);
>>> -                       ASSERT(next_agino != NULLAGINO);
>>> -                       ASSERT(next_agino != 0);
>>>                 }
>>>                 /*
>>>                  * Now last_ibp points to the buffer previous to us on
>>>
>>> Thank you.
>>>
>>>
>>> 2013/4/17 符永涛 <yongtaofu at gmail.com>
>>>
>>>> Hi Brain,
>>>> If it is because NULLAGINO is passed in  to xfs_inotobp().
>>>> Can I move the following two lines before xfs_inotobp?
>>>>
>>>> For example:
>>>>
>>>> 1767                 while (next_agino != agino) {
>>>> 1768                         /*
>>>> 1769                          * If the last inode wasn't the one
>>>> pointing to
>>>> 1770                          * us, then release its buffer since we're
>>>> not
>>>> 1771                          * going to do anything with it.
>>>> 1772                          */
>>>> 1773                         if (last_ibp != NULL) {
>>>> 1774                                 xfs_trans_brelse(tp, last_ibp);
>>>> 1775                         }
>>>> 1776                         next_ino = XFS_AGINO_TO_INO(mp, agno,
>>>> next_agino);
>>>> +                               ASSERT(next_agino != NULLAGINO);
>>>> +                               ASSERT(next_agino != 0);
>>>> 1777                         error = xfs_inotobp(mp, tp, next_ino,
>>>> &last_dip,
>>>> 1778                                             &last_ibp,
>>>> &last_offset, 0);
>>>> 1779                         if (error) {
>>>> 1780                                 xfs_warn(mp,
>>>> 1781                                         "%s: xfs_inotobp()
>>>> returned error %d.",
>>>> 1782                                         __func__, error);
>>>> 1783                                 return error;
>>>> 1784                         }
>>>> 1785                         next_agino =
>>>> be32_to_cpu(last_dip->di_next_unlinked);
>>>> -                               //ASSERT(next_agino != NULLAGINO);
>>>> -                               //ASSERT(next_agino != 0);
>>>> 1788                 }
>>>> I don't understand xfs well and correct me if I'm totally wrong.
>>>> Thank you very much.
>>>>
>>>>
>>>> 2013/4/17 符永涛 <yongtaofu at gmail.com>
>>>>
>>>>> Hi Brain,
>>>>> I want to ask a question, according to the shutdown trace. The ino in
>>>>>  xfs_iunlink_remove is 0x113, why xfs_imap got ino=0xffffffff ?
>>>>>
>>>>> --- xfs_imap -- module("xfs").function("xfs_imap at fs
>>>>> /xfs/xfs_ialloc.c:1257").return -- return=0x16
>>>>> vars: mp=0xffff882017a50800 tp=0xffff881c81797c70 ino=0xffffffff
>>>>>
>>>>> --- xfs_iunlink_remove -- module("xfs").function("xfs_
>>>>> iunlink_remove at fs/xfs/xfs_inode.c:1680").return -- return=0x16
>>>>> vars: tp=0xffff881c81797c70 ip=0xffff881003c13c00 next_ino=? mp=?
>>>>> agi=? dip=? agibp=0xffff880109b47e20 ibp=? agno=? agino=? next_agino=?
>>>>> last_ibp=? last_dip=0xffff882000000000 bucket_index=? offset=?
>>>>> last_offset=0xffffffffffff8810 error=? __func__=[...]
>>>>> ip: i_ino = 0x113, i_flags = 0x0
>>>>>
>>>>> Thank you.
>>>>>
>>>>>
>>>>>
>>>>> 2013/4/17 符永涛 <yongtaofu at gmail.com>
>>>>>
>>>>>> Hi Brain,
>>>>>> Thank you for your update, and I have applied your last kernel patch.
>>>>>> However it is not easy to reproduce especially in out test environment.
>>>>>> Till now is not happens again. I'll update the kernel patch now. BTW is
>>>>>> there any findings in the logs of previous thread?
>>>>>> http://oss.sgi.com/archives/xfs/2013-04/msg00327.html
>>>>>> I guess it tend to happen during glusterfs rebalance because
>>>>>> glusterfs moves a lot of file from one server to another and then unlink it.
>>>>>>
>>>>>> Thank you.
>>>>>>
>>>>>>
>>>>>> 2013/4/17 Brian Foster <bfoster at redhat.com>
>>>>>>
>>>>>>> On 04/16/2013 12:24 PM, Dave Chinner wrote:
>>>>>>> > On Mon, Apr 15, 2013 at 07:14:39PM -0400, Brian Foster wrote:
>>>>>>> >> Hi,
>>>>>>> >>
>>>>>>> >> Thanks for the data in the previous thread:
>>>>>>> >>
>>>>>>> >> http://oss.sgi.com/archives/xfs/2013-04/msg00327.html
>>>>>>> >>
>>>>>>> ...
>>>>>>> >>
>>>>>>> >>      echo 1 >
>>>>>>> /sys/kernel/debug/tracing/events/xfs/xfs_iunlink/enable
>>>>>>> >>      echo 1 >
>>>>>>> /sys/kernel/debug/tracing/events/xfs/xfs_iunlink_remove/enable
>>>>>>> >>      ... reproduce ...
>>>>>>> >>      cat /sys/kernel/debug/tracing/trace > trace.output
>>>>>>> >
>>>>>>> > It's better to use trace-cmd for this. it will result in less
>>>>>>> > dropped events. i.e.:
>>>>>>> >
>>>>>>> >       $ trace-cmd record -e xfs_iunlink\*
>>>>>>> >       ... reproduce ...
>>>>>>> >       ^C
>>>>>>> >       $ trace-cmd report > trace.output
>>>>>>> >
>>>>>>> >> --- a/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> >> +++ b/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> >> @@ -581,6 +581,8 @@ DEFINE_INODE_EVENT(xfs_file_fsync);
>>>>>>> ...
>>>>>>> >
>>>>>>> > I would suggest that the the tracing shoul dbe at entry of the
>>>>>>> > function, otherwise we won't get a tracepoint for the operation
>>>>>>> that
>>>>>>> > triggers the shutdown. (That's the reason most tracepoints in XFS
>>>>>>> > are at function entry...)
>>>>>>> >
>>>>>>>
>>>>>>> Good points, thanks Dave. A v2 that pulls up the tracepoints towards
>>>>>>> function entry is appended.
>>>>>>>
>>>>>>> Brian
>>>>>>>
>>>>>>> From 280943e78ebe0b97a774cba51e7815c42f044b55 Mon Sep 17 00:00:00
>>>>>>> 2001
>>>>>>> From: Brian Foster <bfoster at redhat.com>
>>>>>>> Date: Mon, 15 Apr 2013 18:16:24 -0400
>>>>>>> Subject: [PATCH v2] xfs: add tracepoints for xfs_iunlink and
>>>>>>> xfs_iunlink_remove
>>>>>>>
>>>>>>> ---
>>>>>>>  fs/xfs/linux-2.6/xfs_trace.h |    2 ++
>>>>>>>  fs/xfs/xfs_inode.c           |    4 ++++
>>>>>>>  2 files changed, 6 insertions(+), 0 deletions(-)
>>>>>>>
>>>>>>> diff --git a/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> b/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> index adc6ec4..338a0f9 100644
>>>>>>> --- a/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> +++ b/fs/xfs/linux-2.6/xfs_trace.h
>>>>>>> @@ -583,6 +583,8 @@ DEFINE_INODE_EVENT(xfs_file_fsync);
>>>>>>>  DEFINE_INODE_EVENT(xfs_destroy_inode);
>>>>>>>  DEFINE_INODE_EVENT(xfs_dirty_inode);
>>>>>>>  DEFINE_INODE_EVENT(xfs_clear_inode);
>>>>>>> +DEFINE_INODE_EVENT(xfs_iunlink);
>>>>>>> +DEFINE_INODE_EVENT(xfs_iunlink_remove);
>>>>>>>
>>>>>>>  DEFINE_INODE_EVENT(xfs_dquot_dqalloc);
>>>>>>>  DEFINE_INODE_EVENT(xfs_dquot_dqdetach);
>>>>>>> diff --git a/fs/xfs/xfs_inode.c b/fs/xfs/xfs_inode.c
>>>>>>> index 19900f0..d705c77 100644
>>>>>>> --- a/fs/xfs/xfs_inode.c
>>>>>>> +++ b/fs/xfs/xfs_inode.c
>>>>>>> @@ -1615,6 +1615,8 @@ xfs_iunlink(
>>>>>>>
>>>>>>>         mp = tp->t_mountp;
>>>>>>>
>>>>>>> +       trace_xfs_iunlink(ip);
>>>>>>> +
>>>>>>>         /*
>>>>>>>          * Get the agi buffer first.  It ensures lock ordering
>>>>>>>          * on the list.
>>>>>>> @@ -1694,6 +1696,8 @@ xfs_iunlink_remove(
>>>>>>>         mp = tp->t_mountp;
>>>>>>>         agno = XFS_INO_TO_AGNO(mp, ip->i_ino);
>>>>>>>
>>>>>>> +       trace_xfs_iunlink_remove(ip);
>>>>>>> +
>>>>>>>         /*
>>>>>>>          * Get the agi buffer first.  It ensures lock ordering
>>>>>>>          * on the list.
>>>>>>> --
>>>>>>> 1.7.7.6
>>>>>>>
>>>>>>>
>>>>>>
>>>>>>
>>>>>> --
>>>>>> 符永涛
>>>>>>
>>>>>
>>>>>
>>>>>
>>>>> --
>>>>> 符永涛
>>>>>
>>>>
>>>>
>>>>
>>>> --
>>>> 符永涛
>>>>
>>>
>>>
>>>
>>> --
>>> 符永涛
>>>
>>> _______________________________________________
>>> xfs mailing list
>>> xfs at oss.sgi.com
>>> http://oss.sgi.com/mailman/listinfo/xfs
>>>
>>>
>>
>>
>> --
>> 符永涛
>>
>
>
>
> --
> 符永涛
>



-- 
符永涛
-------------- next part --------------
An HTML attachment was scrubbed...
URL: <http://oss.sgi.com/pipermail/xfs/attachments/20130418/86b9fcf9/attachment-0001.html>


More information about the xfs mailing list