<div dir="ltr"><div><div><div>Hi Brain,<br></div>Here is the file:<br>find . -inum 539274<br>./crashtest/.glusterfs/indices/xattrop<br>[<a href="mailto:root@10.23.72.94">root@10.23.72.94</a> xfsd]# ls -lih ./crashtest/.glusterfs/indices/xattrop<br>
total 0<br>539275 ---------- 2 root root 0 Apr 20 17:17 132ef294-71d1-4435-8daa-aa002e67cb6e<br>539275 ---------- 2 root root 0 Apr 20 17:17 xattrop-f3ad589a-b8dc-4416-ab84-fc9ad4033540<br>find . -inum 539275<br>./crashtest/.glusterfs/indices/xattrop/xattrop-f3ad589a-b8dc-4416-ab84-fc9ad4033540<br>
./crashtest/.glusterfs/indices/xattrop/132ef294-71d1-4435-8daa-aa002e67cb6e<br></div>I'm not sure if it is normal or glusterfs fall in infinite loop. Is there a change that the kernel fall into dead loop?<br></div><div>
I'll study it.<br></div></div><div class="gmail_extra"><br><br><div class="gmail_quote">2013/4/20 Brian Foster <span dir="ltr"><<a href="mailto:bfoster@redhat.com" target="_blank">bfoster@redhat.com</a>></span><br>
<blockquote class="gmail_quote" style="margin:0 0 0 .8ex;border-left:1px #ccc solid;padding-left:1ex"><div class="im">On 04/20/2013 06:10 AM, ·ûÓÀÌÎ wrote:<br>
> Dear Eric,<br>
> I have applied your latest patch and collected the following log:<br>
><br>
> /var/log/message<br>
> Apr 20 17:28:23 10 kernel: XFS (sdb): xfs_iunlink_remove: xfs_inotobp()<br>
> returned error 22 for inode 0x1b20b ag 0 agino 1b20b<br>
> Apr 20 17:28:23 10 kernel:<br>
> Apr 20 17:28:23 10 kernel: XFS (sdb): xfs_inactive: xfs_ifree returned<br>
> error 22<br>
> Apr 20 17:28:23 10 kernel: XFS (sdb): xfs_do_force_shutdown(0x1) called<br>
> from line 1184 of file fs/xfs/xfs_vnodeops.c. Return address =<br>
> 0xffffffffa02d4d0a<br>
> Apr 20 17:28:23 10 kernel: XFS (sdb): I/O Error Detected. Shutting down<br>
> filesystem<br>
> Apr 20 17:28:23 10 kernel: XFS (sdb): Please umount the filesystem and<br>
> rectify the problem(s)<br>
> Apr 20 17:28:37 10 kernel: XFS (sdb): xfs_log_force: error 5 returned.<br>
> Apr 20 17:29:07 10 kernel: XFS (sdb): xfs_log_force: error 5 returned.<br>
> Apr 20 17:29:37 10 kernel: XFS (sdb): xfs_log_force: error 5 returned.<br>
> Apr 20 17:30:07 10 kernel: XFS (sdb): xfs_log_force: error 5 returned.<br>
><br>
> debugfs trace:<br>
> <a href="https://docs.google.com/file/d/0B7n2C4T5tfNCTlZGUVpnZENrZ3M/edit?usp=sharing" target="_blank">https://docs.google.com/file/d/0B7n2C4T5tfNCTlZGUVpnZENrZ3M/edit?usp=sharing</a><br>
><br>
<br>
</div>FWIW...<br>
<br>
<...>-6908 [001] 8739.967623: xfs_iunlink: dev 8:16 ino 0x83a8b mode<br>
0100000, flags 0x0<br>
<...>-6909 [001] 8739.970252: xfs_iunlink: dev 8:16 ino 0x83a8b mode<br>
0100000, flags 0x0<br>
<br>
0x83a8b and 0x1b20b both hash to unlinked list bucket 11.<br>
<br>
As to the rest of the trace, there appears to be a significant amount of<br>
link activity on (directory) inode 0x83a8a (the immediately prior inode<br>
to the inode involved in the race). The name data in the trace suggests<br>
activity somewhere under .glusterfs. A couple questions:<br>
<br>
1.) Any idea what entries point to this inode right now (e.g., how many<br>
links on this inode) and where it resides in the fs (path)?<br>
<br>
2.) Can you associate this kind of heavy remove/link pattern on a single<br>
inode to a higher level activity? For example, if you were to watch the<br>
trace data live, is this a normal pattern you observe? Does it only<br>
occur when a rebalance is in progress? Or when a rebalance finishes? Any<br>
detailed observations you can make in that regard could be helpful.<br>
<br>
Brian<br>
<br>
> Thank you.<br>
><br>
><br>
> 2013/4/20 ·ûÓÀÌÎ <<a href="mailto:yongtaofu@gmail.com">yongtaofu@gmail.com</a> <mailto:<a href="mailto:yongtaofu@gmail.com">yongtaofu@gmail.com</a>>><br>
<div class="im">><br>
> Hi Eric,<br>
> The xfs module is loaded from system kernel, it happens on our<br>
> production server too (I did not touch that till now) and if the xfs<br>
> module is mess up the systemstap may also not working but now it<br>
> works. As you have mentioned, strange thing is xfs shutdown always<br>
> happens when glusterfs rebalance completes.<br>
><br>
><br>
> 2013/4/20 Eric Sandeen <<a href="mailto:sandeen@sandeen.net">sandeen@sandeen.net</a><br>
</div>> <mailto:<a href="mailto:sandeen@sandeen.net">sandeen@sandeen.net</a>>><br>
<div class="HOEnZb"><div class="h5">><br>
> On 4/19/13 9:03 PM, ·ûÓÀÌÎ wrote:<br>
> > Hi Eric,<br>
> > I will enable them and run test again. I can only reproduce it<br>
> with<br>
> > glusterfs rebalance. Glusterfs uses a mechanism it called<br>
> syncop to<br>
> > unlink file. For rebalance it uses<br>
> > syncop_unlink(glusterfs/libglusterfs/src/syncop.c). In the<br>
> glusterfs<br>
> > sync_task framework(glusterfs/libglusterfs/src/syncop.c) it uses<br>
> > "makecontext/swapcontext"<br>
> ><br>
> <<a href="http://www.opengroup.org/onlinepubs/009695399/functions/makecontext.html" target="_blank">http://www.opengroup.org/onlinepubs/009695399/functions/makecontext.html</a>>.<br>
> > Does it leads to racing unlink from different CPU core?<br>
><br>
> Yep, I understand that it's rebalance. It dies when rebalance<br>
> finishes because an<br>
> open but unlinked file trips over the corrupted list from<br>
> earlier, it seems.<br>
><br>
> I don't know why makecontext would matter...<br>
><br>
> Just to be sure, you are definitely loading the xfs module from<br>
> the kernel you built, right, and you don't have a "priority"<br>
> module getting loaded from elsewhere? Seems unlikely, but just<br>
> to be sure.<br>
><br>
> > Thank you.<br>
><br>
> You could also add this patch to the xfs tracepoints to print<br>
> more information about the inodes - the mode & flags.<br>
><br>
> -Eric<br>
><br>
><br>
> diff --git a/fs/xfs/linux-2.6/xfs_trace.h<br>
> b/fs/xfs/linux-2.6/xfs_trace.h<br>
> index e8ce644..c314b87 100644<br>
> --- a/fs/xfs/linux-2.6/xfs_trace.h<br>
> +++ b/fs/xfs/linux-2.6/xfs_trace.h<br>
> @@ -544,14 +544,18 @@ DECLARE_EVENT_CLASS(xfs_inode_class,<br>
> TP_STRUCT__entry(<br>
> __field(dev_t, dev)<br>
> __field(xfs_ino_t, ino)<br>
> + __field(__u16, mode)<br>
> + __field(unsigned long, flags)<br>
> ),<br>
> TP_fast_assign(<br>
> __entry->dev = VFS_I(ip)->i_sb->s_dev;<br>
> __entry->ino = ip->i_ino;<br>
> + __entry->mode = VFS_I(ip)->i_mode;<br>
> + __entry->flags = ip->i_flags;<br>
> ),<br>
> - TP_printk("dev %d:%d ino 0x%llx",<br>
> + TP_printk("dev %d:%d ino 0x%llx mode 0%o, flags 0x%lx",<br>
> MAJOR(__entry->dev), MINOR(__entry->dev),<br>
> - __entry->ino)<br>
> + __entry->ino, __entry->mode, __entry->flags)<br>
> )<br>
><br>
> #define DEFINE_INODE_EVENT(name) \<br>
><br>
><br>
><br>
><br>
><br>
><br>
> --<br>
> ·ûÓÀÌÎ<br>
><br>
><br>
><br>
><br>
> --<br>
> ·ûÓÀÌÎ<br>
<br>
</div></div></blockquote></div><br><br clear="all"><br>-- <br>·ûÓÀÌÎ
</div>