brendangregg

[root@smartos18 ~/utils/libMicro-0.4.1/bin]# ./mprotect -N "mprot_tw128k" -l 128k -I 2000 -w -t -f /dev/zero
             prc thr   usecs/call      samples   errors cnt/samp     size flags
mprot_tw128k   1   1      1.63200          219        0        1   131072 --w-t
[root@smartos18 ~/utils/libMicro-0.4.1/bin]# ./mprotect -N "mprot_tw128k" -l 128k -I 2000 -w -t -f /dev/zero
             prc thr   usecs/call      samples   errors cnt/samp     size flags
mprot_tw128k   1   1     67.25900          205        0        1   131072 --w-t
[root@smartos18 ~/utils/libMicro-0.4.1/bin]# ./mprotect -N "mprot_tw128k" -l 128k -I 2000 -w -t -f /dev/zero
             prc thr   usecs/call      samples   errors cnt/samp     size flags
mprot_tw128k   1   1    106.88600          135        0        1   131072 --w-t

brendangregg

#!/usr/sbin/dtrace -s
/*
 * tcpretranssnoop.d	Trace TCP retransmitted segments with details.
 *
 * CDDL HEADER START
 *
 * The contents of this file are subject to the terms of the
 * Common Development and Distribution License, Version 1.0 only
 * (the "License").  You may not use this file except in compliance
 * with the License.

brendangregg

run time (ms):

  searchd                                           
           value  ------------- Distribution ------------- count    
             < 0 |                                         0        
               0 |@@@@@@@@@@@@@@@@@                        1745     
             100 |@@@@                                     363      
             200 |@@@                                      287      
             300 |@@                                       175      
             400 |@                                        106      

brendangregg

[root@fedora1 admin]# stap -e 'global s, last; probe begin { last = gettimeofday_ns(); } probe timer.profile { now = gettimeofday_ns(); s <<< now - last; last = now; } probe timer.s(10) { printf("ns\n"); print(@hist_linear(s, 900000, 1100000, 10000)); exit(); }'
ns
   value |-------------------------------------------------- count
 <900000 |                                                     80
  900000 |                                                     17
  910000 |                                                     15
  920000 |                                                      7
  930000 |                                                      8
  940000 |                                                     17
  950000 |                                                     15

brendangregg

root@macbook:~> dtrace -n 'io:::start /!(args[0]->b_flags & B_READ) && execname == "launchd"/ { trace(execname); stack(); }'
dtrace: description 'io:::start ' matched 1 probe
CPU     ID                    FUNCTION:NAME
  0  19368               buf_strategy:start   launchd                          
              mach_kernel`buf_strategy+0x5e
              mach_kernel`hfs_vnop_strategy+0x34
              mach_kernel`VNOP_STRATEGY+0x2f
              mach_kernel`buf_bwrite+0x257
              mach_kernel`hfs_vnop_bwrite+0x12a
              mach_kernel`VNOP_BWRITE+0x2f

brendangregg

Here's some more perf analysis: what was the limiter for node.js in the original fs.readFile benchmark,
causing large performance difference?

Examining thread microstates using prstat (SmartOS):

# prstat -mLcp 92432 1
Please wait...
[...]
   PID USERNAME USR SYS TRP TFL DFL LCK SLP LAT VCX ICX SCL SIG PROCESS/LWPID 
 92432 root      90  10 0.0 0.0 0.0 0.0 0.0 0.0   7   9 42K   0 node/1

brendangregg

#!/usr/bin/sh
#
# intelcpi - measure CPI and utilization on Intel processors.
#
# USAGE: intelcpi [interval]
#   eg,
#        intelcpi 0.1		# for 0.1 second intervals
#
# CPI shows how memory intensive CPU workloads are.
#

brendangregg

2 problems:

1. ignores runtime
2. doesn't output actual measurements (other than issued total)

[~/fio-2.0.13]# time ./fio --name=randread --rw=randread --random_distribution=pareto:0.5 --size=1g --bs=8k --runtime=10 --time_based --filename=fio.tmp 
randread: (g=0): rw=randread, bs=8K-8K/8K-8K/8K-8K, ioengine=sync, iodepth=1
fio-2.0.13
Starting 1 process
^C

brendangregg

[root@headnode /var/tmp/brendan]# cat rxstacklat.d 
#!/usr/sbin/dtrace -s

fbt::mac_rx:entry
{
	ts[arg2] = timestamp;
}

fbt::freemsg:entry,
fbt::freeb:entry

brendangregg

# dtrace -Fn 'fbt::mac_tx_send:entry /execname == "ping"/ { self->in = 1; } fbt::mac_tx_send:return { exit(0); } fbt:mac:: { trace(timestamp); }'
dtrace: description 'fbt::mac_tx_send:entry ' matched 1410 probes
CPU FUNCTION                                 
  8  -> mac_tx                                 13822389790096059
  8    -> mac_protect_check                    13822389790102650
  8      -> mac_protect_check_one              13822389790104778
  8        -> mac_vlan_header_info             13822389790106716
  8          -> mac_header_info                13822389790107876
  8          <- mac_header_info                13822389790108803
  8        <- mac_vlan_header_info             13822389790110092