Skip site navigation (1)Skip section navigation (2)
Date:      Thu, 16 Nov 2017 12:38:52 +0000
From:      bugzilla-noreply@freebsd.org
To:        freebsd-ports-bugs@FreeBSD.org
Subject:   [Bug 223704] sysutils/DTraceToolkit: dtruss aborts on 12.0-CURRENT
Message-ID:  <bug-223704-13@https.bugs.freebsd.org/bugzilla/>

next in thread | raw e-mail | index | archive | help
https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=3D223704

            Bug ID: 223704
           Summary: sysutils/DTraceToolkit: dtruss aborts on 12.0-CURRENT
           Product: Ports & Packages
           Version: Latest
          Hardware: Any
                OS: Any
            Status: New
          Severity: Affects Only Me
          Priority: ---
         Component: Individual Port(s)
          Assignee: skreuzer@FreeBSD.org
          Reporter: dch@freebsd.org
             Flags: maintainer-feedback?(skreuzer@FreeBSD.org)
          Assignee: skreuzer@FreeBSD.org

I discovered this at BSDCan with gnn@ but never got around to bugzillaing i=
t -
sorry :(

steps:
run some program, like top(1), on another terminal.
in the main terminal, run dtruss top

# sudo /usr/local/share/dtrace-toolkit/dtruss top
dtrace: invalid probe specifier=20

actual results:
dtruss echos the dtrace script back to the console and whines.
dtrace: invalid probe specifier=20
... script ...
: probe description syscall::lstat*:return does not match any probes

expected results:
same as on 11.1R amd 64 - dtracing results spew over console


```
# sudo /usr/local/share/dtrace-toolkit/dtruss top
dtrace: invalid probe specifier=20
#pragma D option quiet
#pragma D option switchrate=3D10

/*
 * Command line arguments
 */
inline int OPT_command   =3D 1;
inline int OPT_follow    =3D 0;
inline int OPT_printid   =3D 0;
inline int OPT_relative  =3D 0;
inline int OPT_elapsed   =3D 0;
inline int OPT_cpu       =3D 0;
inline int OPT_counts    =3D 0;
inline int OPT_pid       =3D 0;
inline int OPT_name      =3D 0;
inline int OPT_trace     =3D 0;
inline int OPT_stack     =3D 0;
inline string NAME       =3D ".";
inline string TRACE      =3D ".";

dtrace:::BEGIN=20
{
        /* print header */
        OPT_printid  ? printf("%-9s  ", "PID/LWP") : 1;
        OPT_relative ? printf("%8s ", "RELATIVE") : 1;
        OPT_elapsed  ? printf("%7s ", "ELAPSD") : 1;
        OPT_cpu      ? printf("%6s ", "CPU") : 1;
        printf("SYSCALL(args) \t\t =3D return\n");
}

/*
 * Save syscall entry info
 */
syscall:::entry
/((OPT_command || OPT_pid) && pid =3D=3D $target) ||=20
 (OPT_name && execname =3D=3D NAME) ||
 (OPT_follow && progenyof($target))/
{
        /* set start details */
        self->start =3D timestamp;
        self->vstart =3D vtimestamp;
        self->arg0 =3D arg0;
        self->arg1 =3D arg1;
        self->arg2 =3D arg2;

        /* count occurances */
        OPT_counts =3D=3D 1 ? @Counts[probefunc] =3D count() : 1;
}

/*
 * Follow children
 */
syscall::fork*:return
/(OPT_follow && progenyof($target)) && (!OPT_trace || (TRACE =3D=3D probefu=
nc))/
{
        /* print output */
        self->code =3D errno =3D=3D 0 ? "" : "Err#";
        OPT_printid  ? printf("%6d/%d:  ", pid, tid) : 1;
        OPT_relative ? printf("%8d:  ", vtimestamp/1000) : 1;
        OPT_elapsed  ? printf("%7d:  ", 0) : 1;
        OPT_cpu      ? printf("%6d ", 0) : 1;
        printf("%s(0x%X, 0x%X, 0x%X)\t\t =3D %d %s%d\n", probefunc,
            self->arg0, self->arg1, self->arg2, (int)arg0, self->code,
            (int)errno);
}

/*
 * Check for syscall tracing
 */
syscall:::entry
/OPT_trace && probefunc !=3D TRACE/
{
        /* drop info */
        self->start =3D 0;
        self->vstart =3D 0;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/*
 * Print return data
 */

/*
 * The following code is written in an intentionally repetative way.
 * The first versions had no code redundancies, but performed badly during
 * benchmarking. The priority here is speed, not cleverness. I know there
 * are many obvious shortcuts to this code, I have tried them. This style h=
as
 * shown in benchmarks to be the fastest (fewest probes fired, fewest actio=
ns).
 */

/* print 3 args, return as hex */
syscall::sigprocmask:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(0x%X, 0x%X, 0x%X)\t\t =3D 0x%X %s%d\n", probefunc,
            (int)self->arg0, self->arg1, self->arg2, (int)arg0,
            self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 3 args, arg0 as a string */
syscall::access*:return,
syscall::stat*:return,=20
syscall::lstat*:return,=20
syscall::readlink*:return,
syscall::open*:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(\"%S\", 0x%X, 0x%X)\t\t =3D %d %s%d\n", probefunc,
            copyinstr(self->arg0), self->arg1, self->arg2, (int)arg0,
            self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 3 args, arg1 as a string */
syscall::write:return,
syscall::pwrite:return,
syscall::*read*:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(0x%X, \"%S\", 0x%X)\t\t =3D %d %s%d\n", probefunc, self-=
>arg0,
            stringof(copyin(self->arg1, self->arg2)), self->arg2, (int)arg0,
            self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 0 arg output */
syscall::*fork*:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s()\t\t =3D %d %s%d\n", probefunc,
            (int)arg0, self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 1 arg output */
syscall::close:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(0x%X)\t\t =3D %d %s%d\n", probefunc, self->arg0,
            (int)arg0, self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 2 arg output */
syscall::utimes:return,
syscall::munmap:return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(0x%X, 0x%X)\t\t =3D %d %s%d\n", probefunc, self->arg0,
            self->arg1, (int)arg0, self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* print 3 arg output - default */
syscall:::return
/self->start/
{
        /* calculate elapsed time */
        this->elapsed =3D timestamp - self->start;
        self->start =3D 0;
        this->cpu =3D vtimestamp - self->vstart;
        self->vstart =3D 0;
        self->code =3D errno =3D=3D 0 ? "" : "Err#";

        /* print optional fields */
        OPT_printid  ? printf("%6d/%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;

        /* print main data */
        printf("%s(0x%X, 0x%X, 0x%X)\t\t =3D %d %s%d\n", probefunc, self->a=
rg0,
            self->arg1, self->arg2, (int)arg0, self->code, (int)errno);
        OPT_stack ? ustack()    : 1;
        OPT_stack ? trace("\n") : 1;
        self->arg0 =3D 0;
        self->arg1 =3D 0;
        self->arg2 =3D 0;
}

/* program exited */
proc:::exit
/(OPT_command || OPT_pid) && pid =3D=3D $target/
{
        exit(0);
}

/* print counts */
dtrace:::END
{
        OPT_counts =3D=3D 1 ? printf("\n%-32s %16s\n", "CALL", "COUNT") : 1;
        OPT_counts =3D=3D 1 ? printa("%-32s %@16d\n", @Counts) : 1;
}
: probe description syscall::lstat*:return does not match any probes

--=20
You are receiving this mail because:
You are the assignee for the bug.=



Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?bug-223704-13>