Apologies to the ZFSers, this thread really belongs elsewhere.

On Mar 25, 2012, at 10:11 PM, Aubrey Li wrote:

> On Mon, Mar 26, 2012 at 11:34 AM, Richard Elling
> <richard.ell...@gmail.com> wrote:
>> On Mar 25, 2012, at 6:51 PM, Aubrey Li wrote:
>>> On Mon, Mar 26, 2012 at 4:18 AM, Jim Mauro <james.ma...@oracle.com> wrote:
>>>> If you're chasing CPU utilization, specifically %sys (time in the kernel),
>>>> I would start with a time-based kernel profile.
>>>> 
>>>> #dtrace -n 'profile-997hz /arg0/ { @[stack()] = count(); } tick-60sec { 
>>>> trunc(@, 20); printa(@0; }'
>>>> 
>>>> I would be curious to see where the CPU cycles are being consumed first,
>>>> before going down the lock path…
>>>> 
>>>> This assume that most or all of CPU utilization is %sys. If it's %usr, we 
>>>> take
>>>> a different approach.
>>>> 
>>> 
>>> Here is the output, I changed to "tick-5sec" and "trunc(@, 5)".
>>> No.2 and No.3 is what I care about.
>>> 
>>> Thanks,
>>> -Aubrey
>>> 
>>> 21  80536                       :tick-5sec
>>> ========== 1 =====================
>>>              genunix`avl_walk+0x6a
>>>              genunix`as_gap_aligned+0x2b7
>>>              unix`map_addr_proc+0x179
>>>              unix`map_addr+0x8e
>>>              genunix`choose_addr+0x9e
>>>              zfs`zfs_map+0x161
>>>              genunix`fop_map+0xc5
>>>              genunix`smmap_common+0x268
>>>              genunix`smmaplf32+0xa2
>>>              genunix`syscall_ap+0x92
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             1427
>>> 
>>> ========= 2 =================
>>>              unix`mutex_delay_default+0x7
>>>              unix`mutex_vector_enter+0x2ae
>>>              zfs`zfs_zget+0x46
>>>              zfs`zfs_root+0x55
>>>              genunix`fsop_root+0x2d
>>>              genunix`traverse+0x65
>>>              genunix`lookuppnvp+0x446
>>>              genunix`lookuppnatcred+0x119
>>>              genunix`lookupnameatcred+0x97
>>>              genunix`lookupnameat+0x6b
>>>              genunix`vn_openat+0x147
>>>              genunix`copen+0x493
>>>              genunix`openat64+0x2d
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             2645
>>> 
>>> ========== 3 =====================
>>>              unix`mutex_delay_default+0x7
>>>              unix`mutex_vector_enter+0x2ae
>>>              zfs`zfs_zget+0x46
>>>              zfs`zfs_root+0x55
>>>              genunix`fsop_root+0x2d
>>>              genunix`traverse+0x65
>>>              genunix`lookuppnvp+0x446
>>>              genunix`lookuppnatcred+0x119
>>>              genunix`lookupnameatcred+0x97
>>>              genunix`lookupnameat+0x6b
>>>              genunix`cstatat_getvp+0x11e
>>>              genunix`cstatat64_32+0x5d
>>>              genunix`fstatat64_32+0x4c
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             3201
>>> 
>>> ======== 4 ===========
>>>              unix`i86_mwait+0xd
>>>              unix`cpu_idle_mwait+0x154
>>>              unix`idle+0x116
>>>              unix`thread_start+0x8
>>>             3559
>>> 
>>> ========= 5 ==============
>>>              tmpfs`tmp_readdir+0x138
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             4589
>>> 
>>> =========  6 ================
>>>              unix`strlen+0x3
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             5005
>>> 
>>> =========== 7 =================
>>>              tmpfs`tmp_readdir+0xc7
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>             9548
>>> 
>>> 
>>> ========= 8 =======================
>>>              unix`strlen+0x8
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>            11166
>>> 
>>> 
>>> ============= 9 ===================
>>>              unix`strlen+0xe
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>            14491
>>> 
>>> =============  10 ==================
>>>              tmpfs`tmp_readdir+0xbe
>>>              genunix`fop_readdir+0xe8
>>>              genunix`getdents64+0xd5
>>>              unix`_sys_sysenter_post_swapgs+0x149
>>>            39540
>> 
>> 
>> Well, there you go. tmpfs is not zfs.
>>  -- richard
> 
> Let me explain below:
> 
> Root documentation path of apache is in zfs, you see
> it at No.3 at the above dtrace report.

The sort is in reverse order. The large number you see below the 
stack trace is the number of times that stack was seen. By far the 
most frequently seen is tmpfs`tmp_readdir

> 
> tmpfs(/tmp) is the place where PHP place the temporary
> folders and files.

bingo

> 
> If you go back to see my first thread, you'll see the zfs
> root lock contetion as well.
> 
> Hope we are in the same page now.
> 
> Thanks,
> -Aubrey

 -- richard

--
DTrace Conference, April 3, 2012, 
http://wiki.smartos.org/display/DOC/dtrace.conf
ZFS Performance and Training
richard.ell...@richardelling.com
+1-760-896-4422






_______________________________________________
zfs-discuss mailing list
zfs-discuss@opensolaris.org
http://mail.opensolaris.org/mailman/listinfo/zfs-discuss

Reply via email to