[Level 3] Solaris 10 Technical Conference ( 2009/10/25,11/13,12/4 ) -- Advanced DTrace hands-on lab
The following is my lab file, please refer to it.
Wish this helps.
regards,
Stanley Huang
Wish this helps.
regards,
Stanley Huang
****************************************************************************************************
The purpose of this lab is to let you have advanced DTrace skill. And then you will have the following capabilities.
Lab 1:
* well known about D-script.
Lab 2:
* use DTrace to debug your own program.
Lab 1:
1. D-script arguments.
# cd /temp;
# cat ./testArgs.d;
------------------------------------
#!/usr/sbin/dtrace -qs
/*
* $ is for digital argument,
* $$ is for quated string argument.
*/
BEGIN {
printf("args1=%d\n",$1);
printf("args2=%s\n",$$2);
}
------------------------------------
# chmod u+x ./testArgs.d;
# ./testArgs.d 1 "a";
-------
args1=1
args2=a
-------
^C
2. D-script control
# cd /temp;
# cat ./0-60.d;
----------------------------------------------------------------------
#!/usr/sbin/dtrace -qs
dtrace:::BEGIN
{
msecond = 0;
speed = 0;
}
profile:::tick-1msec
/speed < 60/
{
speed = 10 *msecond/1000;
msecond++;
}
profile:::tick-1msec
/speed>=60/
{
printf("0 to %d m/s in %d milli seconds\n", speed, msecond-1);
exit(0);
}
----------------------------------------------------------------------
# chmod u+x ./0-60.d
# ./0-60.d
---------------------------------
0 to 60 m/s in 6000 milli seconds
---------------------------------
3. aggregation funcion.
aggregation function format:
@name[keys] = aggfunc(args);
'@' -- notice that "name" is a aggregation set.
keys -- index
aggregation function has:
sum(expr) -- summary
count() -- count
avg(expr) -- average
min(expr)/max(expr) -- minimus/maxima
quantize()/lquantize() -- quantize/linear quantize
# cd /temp
# cat ./aggr1.d
------------------------------
#!/usr/sbin/dtrace -s
sysinfo:::pswitch
{
@[execname] = count();
}
------------------------------
# chmod u+x ./aggr1.d
# ./aggr1.d
---------------------------------------------------------------------
dtrace: script './aggr1.d' matched 3 probes
---------------------------------------------------------------------
^C
---------------------------------------------------------------------
devfsadm 1
dhcpagent 1
gnome-power-mana 1
gnome-volume-man 1
iiimd 1
inetd 1
mdnsd 1
nscd 2
fsflush 3
dtrace 4
httpd 4
metacity 4
updatemanagernot 4
xscreensaver 4
...
---------------------------------------------------------------------
# cat ./aggr2.d
---------------------------------------------------------
#!/usr/sbin/dtrace -s
pid$target:libc:malloc:entry
{
@[execname, "Malloc Distribution"]=quantize(arg0);
}
---------------------------------------------------------
# chmod u+x ./aggr2.d
# ./aggr2.d -c ls
--------------------------------------------------------------------------
dtrace: script './aggr2.d' matched 1 probe
0-60.d f8
aggr1.d f9
badopen.d h.d
Developer001.zip myProg
f1 myProg.c
f2 myProg.d
f3 myProg.sh
f4 MySQLDeveloper5.1Exam
f5 mysqldeveloper5_1exam.zip
f6 testArgs.d
f7 test.txt
dtrace: pid 1470 has exited
ls Malloc Distribution
value ------------- Distribution ------------- count
4 | 0
8 |@@@@@@@@@@@@@@@@@@@@ 4
16 |@@@@@ 1
32 |@@@@@ 1
64 | 0
128 | 0
256 |@@@@@ 1
512 | 0
1024 | 0
2048 | 0
4096 | 0
8192 | 0
16384 | 0
32768 |@@@@@ 1
65536 | 0
--------------------------------------------------------------------------
# cat ./aggr3.d
---------------------------------------------------------
#!/usr/sbin/dtrace -s
syscall::mmap:entry
{
@a["number of mmaps"] = count();
@b["average size of mmaps"] = avg(arg1);
@c["size distribution"] = quantize(arg1);
}
profile:::tick-10sec
{
printa(@a);
printa(@b);
printa(@c);
clear(@a);
clear(@b);
clear(@c);
}
---------------------------------------------------------
# chmod u+x aggr3.d
# ./aggr3.d
---------------------------------------------------------------------
dtrace: script './aggr3.d' matched 2 probes
---------------------------------------------------------------------
^C
---------------------------------------------------------------------
number of mmaps 1
average size of mmaps 131072
size distribution
value ------------- Distribution ------------- count
65536 | 0
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
262144 | 0
---------------------------------------------------------------------
# cat ./timespent.d
-------------------------------------------------------------------------------
#!/usr/sbin/dtrace -qs
syscall::open*:entry,
syscall::close*:entry
{
self->ts=timestamp;
}
syscall::open*:return,
syscall::close*:return
{
self->timespent = timestamp - self->ts;
printf("Process %s with ThreadID %d spent %d nsecs in %s\n", execname, tid, self->timespent, probefunc);
self->ts=0; /*allow DTrace to reclaim the storage */
self->timespent = 0;
}
-------------------------------------------------------------------------------
# chmod u+x ./timespent.d
# ./timespent.d
-------------------------------------------------------------------
Process gnome-netstatus- with ThreadID 1 spent 57534 nsecs in open
Process multiload-applet with ThreadID 1 spent 67725 nsecs in open
Process multiload-applet with ThreadID 1 spent 5744 nsecs in close
Process multiload-applet with ThreadID 1 spent 8165 nsecs in close
Process multiload-applet with ThreadID 1 spent 2762 nsecs in close
Process multiload-applet with ThreadID 1 spent 2441 nsecs in close
Process multiload-applet with ThreadID 1 spent 2406 nsecs in close
Process multiload-applet with ThreadID 1 spent 2381 nsecs in close
Process multiload-applet with ThreadID 1 spent 2366 nsecs in close
...
-------------------------------------------------------------------
Lab 2:
1. create new C program (myProg.c).
# cd /temp
# cat ./myProg.c
----------------------------------------
#include
int f1(int n) {
int r=f3(n*2);
return r;
}
int f2(int n) {
int r=n+3;
return r;
}
int f3(int n) {
int r=f2(n*5);
return r;
}
int main(int argc, char** argv) {
int r=f1(1);
printf("%d\n",r); // f1 call f2, f2 call f3 => (1*2+3)*5=15
}
----------------------------------------
# gcc -o ./myProg ./myProg.c
# ./myProg
----------------------------------------
13 ## not 15
----------------------------------------
2. debug your program
# cat ./myProg.d
----------------------------------------
#!/usr/sbin/dtrace -s
pid$1:myProg:$$2:entry
{
self->trace=1;
}
pid$1:myProg:$$2:return
{
self->trace=0;
}
pid$1:myProg::entry,
pid$1:myProg::return
/self->trace/
{
}
----------------------------------------
[termianl 1]# mdb ./myProg
[terminal 1]> _start:b
[terminal 1]> :r
mdb: stop at _start
mdb: target stopped at:
_start: pushl $0x0
[terminal 1]> !ps
PID TTY TIME CMD
1959 pts/4 0:00 mdb
1961 pts/4 0:00 ps
1662 pts/4 0:00 bash
1960 pts/4 0:00 myProg
[terminal 2]# dtrace -F -s ./myProg.d 1960 f1
dtrace: script './myProg.d' matched 26 probes
[terminal 1]> :c
13
mdb: target has terminated
[terminal 1]> $q
[terminal 1]#
[terminal 2]
CPU FUNCTION
0 -> f1
0 -> f3
0 -> f2
0 <- f2
0 <- f3
[terminal 2]
^C
[terminal 2]#
3. result::
The program (myProg) main call f1, but f1 call f3, not call f2
so wrong function called in f1, modify the program...done!
The purpose of this lab is to let you have advanced DTrace skill. And then you will have the following capabilities.
Lab 1:
* well known about D-script.
Lab 2:
* use DTrace to debug your own program.
Lab 1:
1. D-script arguments.
# cd /temp;
# cat ./testArgs.d;
------------------------------------
#!/usr/sbin/dtrace -qs
/*
* $ is for digital argument,
* $$ is for quated string argument.
*/
BEGIN {
printf("args1=%d\n",$1);
printf("args2=%s\n",$$2);
}
------------------------------------
# chmod u+x ./testArgs.d;
# ./testArgs.d 1 "a";
-------
args1=1
args2=a
-------
^C
2. D-script control
# cd /temp;
# cat ./0-60.d;
----------------------------------------------------------------------
#!/usr/sbin/dtrace -qs
dtrace:::BEGIN
{
msecond = 0;
speed = 0;
}
profile:::tick-1msec
/speed < 60/
{
speed = 10 *msecond/1000;
msecond++;
}
profile:::tick-1msec
/speed>=60/
{
printf("0 to %d m/s in %d milli seconds\n", speed, msecond-1);
exit(0);
}
----------------------------------------------------------------------
# chmod u+x ./0-60.d
# ./0-60.d
---------------------------------
0 to 60 m/s in 6000 milli seconds
---------------------------------
3. aggregation funcion.
aggregation function format:
@name[keys] = aggfunc(args);
'@' -- notice that "name" is a aggregation set.
keys -- index
aggregation function has:
sum(expr) -- summary
count() -- count
avg(expr) -- average
min(expr)/max(expr) -- minimus/maxima
quantize()/lquantize() -- quantize/linear quantize
# cd /temp
# cat ./aggr1.d
------------------------------
#!/usr/sbin/dtrace -s
sysinfo:::pswitch
{
@[execname] = count();
}
------------------------------
# chmod u+x ./aggr1.d
# ./aggr1.d
---------------------------------------------------------------------
dtrace: script './aggr1.d' matched 3 probes
---------------------------------------------------------------------
^C
---------------------------------------------------------------------
devfsadm 1
dhcpagent 1
gnome-power-mana 1
gnome-volume-man 1
iiimd 1
inetd 1
mdnsd 1
nscd 2
fsflush 3
dtrace 4
httpd 4
metacity 4
updatemanagernot 4
xscreensaver 4
...
---------------------------------------------------------------------
# cat ./aggr2.d
---------------------------------------------------------
#!/usr/sbin/dtrace -s
pid$target:libc:malloc:entry
{
@[execname, "Malloc Distribution"]=quantize(arg0);
}
---------------------------------------------------------
# chmod u+x ./aggr2.d
# ./aggr2.d -c ls
--------------------------------------------------------------------------
dtrace: script './aggr2.d' matched 1 probe
0-60.d f8
aggr1.d f9
badopen.d h.d
Developer001.zip myProg
f1 myProg.c
f2 myProg.d
f3 myProg.sh
f4 MySQLDeveloper5.1Exam
f5 mysqldeveloper5_1exam.zip
f6 testArgs.d
f7 test.txt
dtrace: pid 1470 has exited
ls Malloc Distribution
value ------------- Distribution ------------- count
4 | 0
8 |@@@@@@@@@@@@@@@@@@@@ 4
16 |@@@@@ 1
32 |@@@@@ 1
64 | 0
128 | 0
256 |@@@@@ 1
512 | 0
1024 | 0
2048 | 0
4096 | 0
8192 | 0
16384 | 0
32768 |@@@@@ 1
65536 | 0
--------------------------------------------------------------------------
# cat ./aggr3.d
---------------------------------------------------------
#!/usr/sbin/dtrace -s
syscall::mmap:entry
{
@a["number of mmaps"] = count();
@b["average size of mmaps"] = avg(arg1);
@c["size distribution"] = quantize(arg1);
}
profile:::tick-10sec
{
printa(@a);
printa(@b);
printa(@c);
clear(@a);
clear(@b);
clear(@c);
}
---------------------------------------------------------
# chmod u+x aggr3.d
# ./aggr3.d
---------------------------------------------------------------------
dtrace: script './aggr3.d' matched 2 probes
---------------------------------------------------------------------
^C
---------------------------------------------------------------------
number of mmaps 1
average size of mmaps 131072
size distribution
value ------------- Distribution ------------- count
65536 | 0
131072 |@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@@ 1
262144 | 0
---------------------------------------------------------------------
# cat ./timespent.d
-------------------------------------------------------------------------------
#!/usr/sbin/dtrace -qs
syscall::open*:entry,
syscall::close*:entry
{
self->ts=timestamp;
}
syscall::open*:return,
syscall::close*:return
{
self->timespent = timestamp - self->ts;
printf("Process %s with ThreadID %d spent %d nsecs in %s\n", execname, tid, self->timespent, probefunc);
self->ts=0; /*allow DTrace to reclaim the storage */
self->timespent = 0;
}
-------------------------------------------------------------------------------
# chmod u+x ./timespent.d
# ./timespent.d
-------------------------------------------------------------------
Process gnome-netstatus- with ThreadID 1 spent 57534 nsecs in open
Process multiload-applet with ThreadID 1 spent 67725 nsecs in open
Process multiload-applet with ThreadID 1 spent 5744 nsecs in close
Process multiload-applet with ThreadID 1 spent 8165 nsecs in close
Process multiload-applet with ThreadID 1 spent 2762 nsecs in close
Process multiload-applet with ThreadID 1 spent 2441 nsecs in close
Process multiload-applet with ThreadID 1 spent 2406 nsecs in close
Process multiload-applet with ThreadID 1 spent 2381 nsecs in close
Process multiload-applet with ThreadID 1 spent 2366 nsecs in close
...
-------------------------------------------------------------------
Lab 2:
1. create new C program (myProg.c).
# cd /temp
# cat ./myProg.c
----------------------------------------
#include
int f1(int n) {
int r=f3(n*2);
return r;
}
int f2(int n) {
int r=n+3;
return r;
}
int f3(int n) {
int r=f2(n*5);
return r;
}
int main(int argc, char** argv) {
int r=f1(1);
printf("%d\n",r); // f1 call f2, f2 call f3 => (1*2+3)*5=15
}
----------------------------------------
# gcc -o ./myProg ./myProg.c
# ./myProg
----------------------------------------
13 ## not 15
----------------------------------------
2. debug your program
# cat ./myProg.d
----------------------------------------
#!/usr/sbin/dtrace -s
pid$1:myProg:$$2:entry
{
self->trace=1;
}
pid$1:myProg:$$2:return
{
self->trace=0;
}
pid$1:myProg::entry,
pid$1:myProg::return
/self->trace/
{
}
----------------------------------------
[termianl 1]# mdb ./myProg
[terminal 1]> _start:b
[terminal 1]> :r
mdb: stop at _start
mdb: target stopped at:
_start: pushl $0x0
[terminal 1]> !ps
PID TTY TIME CMD
1959 pts/4 0:00 mdb
1961 pts/4 0:00 ps
1662 pts/4 0:00 bash
1960 pts/4 0:00 myProg
[terminal 2]# dtrace -F -s ./myProg.d 1960 f1
dtrace: script './myProg.d' matched 26 probes
[terminal 1]> :c
13
mdb: target has terminated
[terminal 1]> $q
[terminal 1]#
[terminal 2]
CPU FUNCTION
0 -> f1
0 -> f3
0 -> f2
0 <- f2
0 <- f3
[terminal 2]
^C
[terminal 2]#
3. result::
The program (myProg) main call f1, but f1 call f3, not call f2
so wrong function called in f1, modify the program...done!
Comments
Post a Comment