2011/10/31 Christian Brunner <c...@muc.de>: > 2011/10/31 Christian Brunner <c...@muc.de>: >> >> The patch didn't hurt, but I've to tell you that I'm still seeing the >> same old problems. Load is going up again: >> >> PID USER PR NI VIRT RES SHR S %CPU %MEM TIME+ COMMAND >> 5502 root 20 0 0 0 0 S 52.5 0.0 106:29.97 btrfs-endio-wri >> 1976 root 20 0 601m 211m 1464 S 28.3 0.9 115:10.62 ceph-osd >> >> And I have hit our warning again: >> >> [223560.970713] ------------[ cut here ]------------ >> [223560.976043] WARNING: at fs/btrfs/inode.c:2118 >> btrfs_orphan_commit_root+0xb0/0xc0 [btrfs]() >> [223560.985411] Hardware name: ProLiant DL180 G6 >> [223560.990491] Modules linked in: btrfs zlib_deflate libcrc32c sunrpc >> bonding ipv6 sg serio_raw pcspkr ghes hed iTCO_wdt iTCO_vendor_support >> i7core_edac edac_core ixgbe dca mdio iomemory_vsl(P) hpsa squashfs >> [last unloaded: scsi_wait_scan] >> [223561.014748] Pid: 2079, comm: ceph-osd Tainted: P >> 3.0.6-1.fits.9.el6.x86_64 #1 >> [223561.023874] Call Trace: >> [223561.026738] [<ffffffff8106344f>] warn_slowpath_common+0x7f/0xc0 >> [223561.033564] [<ffffffff810634aa>] warn_slowpath_null+0x1a/0x20 >> [223561.040272] [<ffffffffa0282120>] btrfs_orphan_commit_root+0xb0/0xc0 >> [btrfs] >> [223561.048278] [<ffffffffa027ce55>] commit_fs_roots+0xc5/0x1b0 [btrfs] >> [223561.055534] [<ffffffff8154c231>] ? mutex_lock+0x31/0x60 >> [223561.061666] [<ffffffffa027ddbe>] >> btrfs_commit_transaction+0x3ce/0x820 [btrfs] >> [223561.069876] [<ffffffffa027d1b8>] ? wait_current_trans+0x28/0x110 [btrfs] >> [223561.077582] [<ffffffffa027e325>] ? join_transaction+0x25/0x250 [btrfs] >> [223561.085065] [<ffffffff81086410>] ? wake_up_bit+0x40/0x40 >> [223561.091251] [<ffffffffa025a329>] btrfs_sync_fs+0x59/0xd0 [btrfs] >> [223561.098187] [<ffffffffa02abc65>] btrfs_ioctl+0x495/0xd50 [btrfs] >> [223561.105120] [<ffffffff8125ed20>] ? inode_has_perm+0x30/0x40 >> [223561.111575] [<ffffffff81261a2c>] ? file_has_perm+0xdc/0xf0 >> [223561.117924] [<ffffffff8117086a>] do_vfs_ioctl+0x9a/0x5a0 >> [223561.124072] [<ffffffff81170e11>] sys_ioctl+0xa1/0xb0 >> [223561.129842] [<ffffffff81555702>] system_call_fastpath+0x16/0x1b >> [223561.136699] ---[ end trace 176e8be8996f25f6 ]--- > > [ Not sending this to the lists, as the attachment is large ]. > > I've spent a little time to do some tracing with ftrace. Its output > seems to be right (at least as far as I can tell). I hope that its > output can give you an insight on whats going on. > > The interesting PIDs in the trace are: > > 5502 root 20 0 0 0 0 S 33.6 0.0 118:28.37 btrfs-endio-wri > 5518 root 20 0 0 0 0 S 29.3 0.0 41:23.58 btrfs-endio-wri > 8059 root 20 0 400m 48m 2756 S 8.0 0.2 8:31.56 ceph-osd > 7993 root 20 0 401m 41m 2808 S 13.6 0.2 7:58.38 ceph-osd >
[ adding linux-btrfs again ] I've been digging into this a bit further: Attached is another ftrace report that I've filtered for "btrfs_*" calls and limited to CPU0 (this is where PID 5502 was running). >From what I can see there is a lot of time consumed in btrfs_reserve_extent(). I this normal? Thanks, Christian
ftrace_btrfs_cpu0.bz2
Description: BZip2 compressed data