#!/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"); }
spin.d
1 Comment »
RSS feed for comments on this post. TrackBack URI
[…] 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 |