Latch, mutex and beyond

spin.d

#!/usr/sbin/dtrace -ZCs 
#pragma D option quiet

/*
     This file is part of demos for "Contemporary Latch Internals" seminar v.18.01.2011
     Copyright:   (c) Andrey S. Nikolaev (Andrey.Nikolaev@rdtex.ru) RDTEX 
     http://AndreyNikolaev.wordpress.com
*/

/* latch# offset inside latch structure */
#ifdef  _LP64
#define KSLLT_KSLLTNUM 12
#else
#define KSLLT_KSLLTNUM 8
#endif

#include <sys/sem.h>
#include <sys/time.h>


BEGIN {
 printf("\nLatch spin trace for pid: %d\n", $target);
 spins=0;
}

pid$target::kslgetl:entry	/* KSL GET exclusive Latch */
{
 in_latch= 1;	
 depth=0;
 this->lnum= * (unsigned short int *) copyin((uintptr_t) (arg0+KSLLT_KSLLTNUM),2);
 printf("\n%s(0x%X,%d,%d,%d)\t\t - KSL GET exclusive Latch# %d\n",probefunc,arg0,arg1,arg2,arg3, this->lnum);
}

pid$target::kslgetsl:entry	/* KSL GET Shared Latch */
{
 in_latch= 1;	
 depth=0;
 this->lnum= * (unsigned short int *) copyin((uintptr_t) (arg0+KSLLT_KSLLTNUM),2);
 printf("%s(0x%X,%d,%d,%d,%d)\t\t - KSL GET Shared Latch# %d\n",probefunc,arg0,arg1,arg2,arg3,arg4, this->lnum);
}

pid$target::sskgslspin:entry,	/* X86   spinning function */
pid$target::skgsltst:entry	/* SPARC spinning function */
/ in_latch /
{
 actual_spin_count++;
 spin_routine=probefunc;	/* name of spinning function */
}

pid$target::sskgslgf:entry,	/* X86 8i-10g immediate latch get */
pid$target::skgslsgf:entry,	/* SPARC 8i-10g */
pid$target::skgslcas:entry	/* SPARC 11g */
/ in_latch /
{
  depth+=2;
  printf("%*s%s(0x%X)\t\t\t - immediate latch get\n",depth,"",probefunc,arg0);
}

pid$target::sskgslgf:return,
pid$target::skgslsgf:return,
pid$target::skgslcas:return
/ in_latch /
{
  depth-=2;
}

pid$target::kslges:entry	/* wait get of exclusive latch*/
/ in_latch /
{
  depth+=2;
  printf("%*s%s(0x%X, ...)\t\t - wait get of exclusive latch\n",depth,"",probefunc,arg0);
  yields=0;
  sleeps=0;
}

pid$target::kslgess:entry	/* wait get of shared latch*/
/ in_latch /
{
  depth+=2;
  printf("%*s%s(0x%X, ...)\t\t - wait get of shared latch\n",depth,"",probefunc,arg0);
}
pid$target::kslges:return,
pid$target::kslgess:return
/ in_latch /
{
  depth-=2;
}

pid$target::kslskgs:entry 	/* spin get of shared latch*/      
/ in_latch /
{
  actual_spin_count=0;
  laddress=arg0;
  spin_routine=" ";		
  depth+=2;
/*  printf("%*s%s(0x%X, ...)\t\t - spin get of shared latch\n",depth,"",probefunc,arg0); */
}
pid$target::skgslsgts:entry,	/* 8i-10g spin get of exclusive latch */
pid$target::ksl_skgslgts:entry	/* 11g */
/ in_latch /
{
  actual_spin_count=0;
  laddress=arg1;
  spin_routine=" ";		
  depth+=2;
/*  printf("%*s%s(...,0x%X, ...)\t - spin get of exclusive latch\n",depth,"",probefunc,arg1); */
}
pid$target::skgslsgts:entry,	/* end of tracing */
pid$target::ksl_skgslgts:entry	
/ in_latch&&(sleeps>8) /
{
   printf("...\n");
   exit(0);
}
pid$target::skgslsgts:return,
pid$target::ksl_skgslgts:return,
pid$target::kslskgs:return
/ in_latch /
{
  printf("%*s  %s(0x%X)\n",depth,"",spin_routine,laddress);
  printf("%*s    ... previous call repeated %d times. \n",depth,"",actual_spin_count); 
  depth-= 2;
  spins+=actual_spin_count;
  actual_spin_count=0;
}

pid$target::kslwlmod:entry	/* KSL latch Wait List MODification */
/ in_latch /
{
  in_latch=0;
  in_wlmod=1;
  depth+=2;
  printf("%*s%s(...)\t\t\t - KSL Wait List MODification\n",depth,"",probefunc);
}

pid$target::kslwlmod:return
/ in_wlmod /
{
  in_latch=1;
  in_wlmod=0;
  depth-=2;
}

syscall::semsys:entry		/* semop syscall -  wait until posted */
/(pid == $target) && in_latch&& ((int)arg0 == 2)/
{
  printf("%*s  semop(%d,...)\t\t\t -     until posted\n",depth+2,"",(int) arg1);
  exit(0);
}

/* int poll(struct pollfd fds[], nfds_t nfds, int timeout); */


syscall::pollsys:entry
/(pid == $target) &&in_latch/
{
 this->timespec=(timestruc_t *)copyin((uintptr_t) arg2 ,sizeof(timestruc_t));
 printf("%*s",depth,"");
 yields=0;
 sleeps++;
 printf("  %s(...,timeout=%d ms,...)\t - Sleep %d\n",probefunc,
	(long) this->timespec->tv_sec*100
	+(long) this->timespec->tv_nsec/1000000, sleeps);
}

syscall::yield:entry
/(pid == $target) &&in_latch/
{
  yields++;
  printf("%*s%s()\t\t\t\t -    Yield %d\n",depth+2,"",probefunc,yields);
}

pid$target::kslfre:entry
{
  exit(0);
}

END {
 printf("Disconnected\n");
}

1 Comment »

  1. […] several DTrace scripts to trace various aspects of latch acquisition. This final version of spin.d enables probes (triggers) to trace latch acquisition functions and system calls. The script also […]

    Pingback by Spin tales: Part 3. Non-standard latch classes in Oracle 9.2-11g « Latch, mutex and beyond — January 18, 2011 @ 8:20 pm | Reply


RSS feed for comments on this post. TrackBack URI

Leave a comment

Blog at WordPress.com.