misc/141452: DTrace stops tracing because of struct thread
Andrei Lavreniyuk
andy.lavr at reactor-xg.kiev.ua
Mon Dec 14 10:30:01 UTC 2009
>Number: 141452
>Category: misc
>Synopsis: DTrace stops tracing because of struct thread
>Confidential: no
>Severity: serious
>Priority: medium
>Responsible: freebsd-bugs
>State: open
>Quarter:
>Keywords:
>Date-Required:
>Class: sw-bug
>Submitter-Id: current-users
>Arrival-Date: Mon Dec 14 10:30:00 UTC 2009
>Closed-Date:
>Last-Modified:
>Originator: Andrei Lavreniyuk
>Release: FreeBSD 8.0-STABLE
>Organization:
Technica-03, Inc.
>Environment:
FreeBSD datacenter.technica-03.local 8.0-STABLE FreeBSD 8.0-STABLE #0: Sat Dec 12 21:41:15 EET 2009 root at datacenter.technica-03.local:/usr/obj/usr/src/sys/SMP64 amd64
>Description:
DTrace support was enabled referring to http://www.freebsd.org/doc/en_US.ISO8859-1/books/handbook/dtrace-enable.html
However, various DTraceToolkit applications stop tracing as follows.
# dtrace -l | wc -l
28647
# ./hotkernel
Sampling... Hit Ctrl-C to end.
dtrace: invalid probe specifier
#pragma D option quiet
profile:::profile-1001hz
/arg0/
{
@pc[arg0] = count();
}
dtrace:::END
{
printa("%a %@d\n", @pc);
}
: "/usr/lib/dtrace/psinfo.d", line 88: failed to resolve type kernel`struct thread * for identifier curthread: Unknown type name
FUNCTION COUNT PCNT
# ./procsystime -n ksh
dtrace: invalid probe specifier
#pragma D option quiet
/*
* Command line arguments
*/
inline int OPT_elapsed = 1;
inline int OPT_cpu = 0;
inline int OPT_counts = 0;
inline int OPT_filter = 1;
inline int OPT_pid = 0;
inline int OPT_name = 1;
inline int OPT_totals = 0;
inline int OPT_command = 0;
inline int PID = 0;
inline string NAME = "ksh";
inline string COMMAND = "";
dtrace:::BEGIN
{
self->start = 0;
self->vstart = 0;
}
dtrace:::BEGIN
/! OPT_command/
{
printf("Tracing... Hit Ctrl-C to end...\n");
}
/*
* Set start timestamp and counts
*/
syscall:::entry
/(! OPT_filter) ||
(OPT_pid && pid == PID) ||
(OPT_name && execname == NAME) ||
(OPT_command && pid == $target)/
{
self->ok = 1;
}
syscall:::entry
/self->ok/
{
OPT_counts ? @Counts[probefunc] = count() : 1;
(OPT_counts && OPT_totals) ? @Counts["TOTAL:"] = count() : 1;
OPT_elapsed ? self->start = timestamp : 1;
OPT_cpu ? self->vstart = vtimestamp : 1;
self->ok = 0;
}
/*
* Calculate time deltas
*/
syscall:::return
/self->start/
{
this->elapsed = timestamp - self->start;
@Elapsed[probefunc] = sum(this->elapsed);
OPT_totals ? @Elapsed["TOTAL:"] = sum(this->elapsed) : 1;
self->start = 0;
}
syscall:::return
/self->vstart/
{
this->cpu = vtimestamp - self->vstart;
@CPU[probefunc] = sum(this->cpu);
OPT_totals ? @CPU["TOTAL:"] = sum(this->cpu) : 1;
self->vstart = 0;
}
/*
* Elapsed time report
*/
dtrace:::END
/OPT_elapsed/
{
printf("\nElapsed Times for ");
OPT_pid ? printf("PID %d,\n\n",PID) : 1;
OPT_name ? printf("processes %s,\n\n",NAME) : 1;
OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
(! OPT_filter) ? printf("all processes,\n\n") : 1;
printf("%16s %18s\n","SYSCALL","TIME (ns)");
printa("%16s %@18d\n", at Elapsed);
}
/*
* CPU time report
*/
dtrace:::END
/OPT_cpu/
{
printf("\nCPU Times for ");
OPT_pid ? printf("PID %d,\n\n",PID) : 1;
OPT_name ? printf("processes %s,\n\n",NAME) : 1;
OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
(! OPT_filter) ? printf("all processes,\n\n") : 1;
printf("%16s %18s\n","SYSCALL","TIME (ns)");
printa("%16s %@18d\n", at CPU);
}
/*
* Syscall count report
*/
dtrace:::END
/OPT_counts/
{
printf("\nSyscall Counts for ");
OPT_pid ? printf("PID %d,\n\n",PID) : 1;
OPT_name ? printf("processes %s,\n\n",NAME) : 1;
OPT_command ? printf("command %s,\n\n",COMMAND) : 1;
(! OPT_filter) ? printf("all processes,\n\n") : 1;
printf("%16s %18s\n","SYSCALL","COUNT");
OPT_counts ? printa("%16s %@18d\n", at Counts) : 1;
}
: "/usr/lib/dtrace/psinfo.d", line 88: failed to resolve type kernel`struct thread * for identifier curthread: Unknown type name
# cd Proc
# ./dapptrace /bin/pwd
/root/DTraceToolkit/Proc
dtrace: invalid probe specifier
#pragma D option quiet
/*
* Command line arguments
*/
inline int OPT_command = 1;
inline int OPT_liball = 0;
inline int OPT_indent = 0;
inline int OPT_printid = 0;
inline int OPT_relative = 0;
inline int OPT_elapsed = 0;
inline int OPT_cpu = 0;
inline int OPT_counts = 0;
inline int OPT_pid = 0;
inline int PID = 0;
inline string NAME = "";
dtrace:::BEGIN
{
/* print header */
OPT_printid ? printf("%-8s ","PID/LWP") : 1;
OPT_relative ? printf("%8s ","RELATIVE") : 1;
OPT_elapsed ? printf("%7s ","ELAPSD") : 1;
OPT_cpu ? printf("%6s ","CPU") : 1;
printf("CALL(args) \t\t = return\n");
/* indent depth */
depth = 0;
}
/*
* Save syscall entry info
*/
pid$target:a.out::entry
{
/* set function depth */
this->fdepth = ++fdepth[probefunc];
depth += 2;
/* set start details */
self->start[probefunc,this->fdepth] = timestamp;
self->vstart[probefunc,this->fdepth] = vtimestamp;
/* count occurances */
OPT_counts && OPT_liball ? @Counts[probemod,probefunc] = count() : 1;
OPT_counts && ! OPT_liball ? @Counts[probefunc] = count() : 1;
/* print optional fields */
OPT_printid ? printf("%5d/%d: ",pid,tid) : 1;
OPT_relative ? printf("%8d ",vtimestamp/1000) : 1;
OPT_elapsed ? printf(" . ") : 1;
OPT_cpu ? printf(" . ") : 1;
OPT_indent ? printf("%*s",depth,"") : 1;
/* print main data */
printf("-> ");
OPT_liball ? printf("%s:",probemod) : 1;
printf("%s(0x%X, 0x%X, 0x%X)\t\t\n",probefunc,arg0,arg1,arg2);
}
/*
* Print return data
*/
/* print 3 arg output - default */
pid$target:a.out::return
/self->start[probefunc,fdepth[probefunc]]/
{
/* fetch function depth */
this->fdepth = fdepth[probefunc];
/* calculate elapsed time */
this->elapsed = timestamp - self->start[probefunc,this->fdepth];
self->start[probefunc,this->fdepth] = 0;
this->cpu = vtimestamp - self->vstart[probefunc,this->fdepth];
self->vstart[probefunc,this->fdepth] = 0;
/* print optional fields */
OPT_printid ? printf("%5d/%d: ",pid,tid) : 1;
OPT_relative ? printf("%8d ",vtimestamp/1000) : 1;
OPT_elapsed ? printf("%7d ",this->elapsed/1000) : 1;
OPT_cpu ? printf("%6d ",this->cpu/1000) : 1;
OPT_indent ? printf("%*s",depth,"") : 1;
/* print main data */
printf("<- ");
OPT_liball ? printf("%s:",probemod) : 1;
printf("%s = %d\n",probefunc,(int)arg0);
depth -= 2;
fdepth[probefunc]--;
}
/* reset indent depth */
profile:::tick-1sec
{
/*
* some probes generated by the pid provider have entries
* but not returns. this is a klude to fix that problem. this
* also explains fdepth[probefunc] rather than a single depth.
*/
depth = 0;
}
/* print counts */
dtrace:::END
{
OPT_counts ? printf("\n%-49s %16s\n","CALL","COUNT") : 1;
OPT_counts && OPT_liball ? printa("%-16s %-32s %@16d\n", at Counts) : 1;
OPT_counts && ! OPT_liball ? printa("%-49s %@16d\n", at Counts) : 1;
}
: "/usr/lib/dtrace/psinfo.d", line 88: failed to resolve type kernel`struct thread * for identifier curthread: Unknown type name
>How-To-Repeat:
See http://www.freebsd.org/doc/en_US.ISO8859-1/books/handbook/dtrace-enable.html
and run DTraceToolkit applications on FreeBSD 8.0-STABLE.
>Fix:
>Release-Note:
>Audit-Trail:
>Unformatted:
More information about the freebsd-bugs
mailing list