latch_times.d

#!/usr/sbin/dtrace -s
#pragma D option quiet
/*
     This file is part of demos for "Contemporary Latch Internals" 
        presentation at Hotsos Symposium 2011  v.21.02.2011
     Copyright: (c)  Andrey S. Nikolaev (Andrey.Nikolaev@rdtex.ru) 
     http://AndreyNikolaev.wordpress.com

     Measure latch acquisition times and distributions
*/
BEGIN {
 printf("latch_time  pid: %d\n", $target);
 n=0;
 in_latch_acquisition=0;
 ts=0;
 tget=0;
}
pid$target::kslgetl:entry, 
pid$target::kslgetsl:entry 
/ arg0 == $1 /
{
 ts=timestamp;
 in_latch_acquisition=1;
 n++;
}
pid$target::kslgetl:return,
pid$target::kslgetsl:return
/ in_latch_acquisition /
{
 tget = timestamp;
 this->t = tget - ts;
 @time["Acquisition"] = quantize(this->t);
 @timeavg["acquisition"] = avg(this->t);
 in_latch_acquisition=0;
}
pid$target::kslfre:entry
/ (arg0 == $1) /
{
 this->t = timestamp - tget;
 @time["Holding"] = quantize(this->t);
 @timeavg["holding"] = avg(this->t);
}
tick-10s
{
  normalize(@timeavg,1000);
  printf("\nlatch gets traced: %d\n",n);
  printf("latch acquisition time histogramm for laddress=%p\n",$1);
  printa("%s time:\t%@d\n",@time);
  printa("average %s time =%@d mus\n",@timeavg);
}