dtrace discuss - Jun 2007 - kcopy() untraceble on X4500/b65 ?

I am trying to run a benchmark on an X4500 and see the system 75%  
busy in kernel mode, lockstat output
shows:
# lockstat -Ikw sleep 10

Profiling interrupt: 4276 events in 11.017 seconds (388 events/sec)

Count indv cuml rcnt     nsec CPU+PIL                Hottest Caller
------------------------------------------------------------------------ 
-------
1010  24%  24% 0.00     3419 cpu[3]                 kcopy
1009  24%  47% 0.00     3926 cpu[1]                 kcopy
   974  23%  70% 0.00     4006 cpu[0]                 kcopy
   907  21%  91% 0.00     4001 cpu[2]                 (usermode)
    85   2%  93% 0.00     3762 cpu[2]+11              setbackdq
    84   2%  95% 0.00     3831 cpu[0]+11              setbackdq
    60   1%  97% 0.00     3614 cpu[1]+11              splr
    59   1%  98% 0.00     3382 cpu[3]+11              restorectx
    44   1%  99% 0.00     3923 cpu[2]+5               ddi_io_get32
    33   1% 100% 0.00     3920 cpu[2]+4               sdintr
    11   0% 100% 0.00     1684 cpu[0]+10              set_anoninfo
------------------------------------------------------------------------ 
-------


Trying the figure out who is calling kcopy() I tried:
#  dtrace -n ''fbt::kcopy:entry { @[stack(2)] = count()}''
But the only output I got was:

dtrace: description ''fbt::kcopy:entry '' matched 1 probe

And ^C after a while gave no output....


Any tips on how to figure out why kcopy() is saturating 3 opteron  
cores ??

	Paul

Hi Paul,
> Trying the figure out who is calling kcopy() I tried:
> #  dtrace -n ''fbt::kcopy:entry { @[stack(2)] = count()}''
> But the only output I got was:
>
> dtrace: description ''fbt::kcopy:entry '' matched 1 probe
>
> And ^C after a while gave no output....
>
>
> Any tips on how to figure out why kcopy() is saturating 3 opteron 
> cores ??
The reason you don''t see kcopy:entry firing is because we often
enter kcopy() by jumping in part way through (for performance
reasons I think). For example, your system is seeing a lot
of kcopy() activity eminating from uiomove() (For the viewers at
home I verified this by having a quick look at the system in
question). If we look at uiomove() we can see it actually calls
kcopy_nta():

 > uiomove::dis ! grep kcopy
uiomove+0x89:                   call   -0x17dbae        <kcopy_nta>
uiomove+0xa1:                   call   -0x17dbc6        <kcopy_nta>

The kcopy_nta() function uses kcopy() but it doesn''t call it
directly but simply jumps part way into it:

 > kcopy_nta::dis ! grep kcopy+
kcopy_nta+0x18:                 jne    -0x56    <kcopy+0x14>
kcopy_nta+0x21:                 jb     -0x5f    <kcopy+0x14>
kcopy_nta+0x34:                 jne    -0x72    <kcopy+0x14>


Therefore you never actually hit the kcopy:entry probe you have enabled.
If you instrument kcopy:return then you should see the actual call
sites as we do always exit via that route.

Jon.