From owner-freebsd-bugs@FreeBSD.ORG Mon Jun 30 05:23:52 2014 Return-Path: Delivered-To: freebsd-bugs@FreeBSD.org Received: from mx1.freebsd.org (mx1.freebsd.org [8.8.178.115]) (using TLSv1 with cipher ADH-AES256-SHA (256/256 bits)) (No client certificate requested) by hub.freebsd.org (Postfix) with ESMTPS id 41959771 for ; Mon, 30 Jun 2014 05:23:52 +0000 (UTC) Received: from kenobi.freebsd.org (kenobi.freebsd.org [IPv6:2001:1900:2254:206a::16:76]) (using TLSv1 with cipher DHE-RSA-AES256-SHA (256/256 bits)) (Client did not present a certificate) by mx1.freebsd.org (Postfix) with ESMTPS id 22BDE2D37 for ; Mon, 30 Jun 2014 05:23:52 +0000 (UTC) Received: from bugs.freebsd.org ([127.0.1.118]) by kenobi.freebsd.org (8.14.8/8.14.8) with ESMTP id s5U5NpAE057251 for ; Mon, 30 Jun 2014 06:23:51 +0100 (BST) (envelope-from bugzilla-noreply@freebsd.org) From: bugzilla-noreply@freebsd.org To: freebsd-bugs@FreeBSD.org Subject: [Bug 191506] New: [dtrace] [dtruss] dtruss doesn't seem to work on -HEAD Date: Mon, 30 Jun 2014 05:23:52 +0000 X-Bugzilla-Reason: AssignedTo X-Bugzilla-Type: new X-Bugzilla-Watch-Reason: None X-Bugzilla-Product: Base System X-Bugzilla-Component: bin X-Bugzilla-Version: 11.0-CURRENT X-Bugzilla-Keywords: X-Bugzilla-Severity: Affects Only Me X-Bugzilla-Who: adrian@freebsd.org X-Bugzilla-Status: Needs Triage X-Bugzilla-Priority: --- X-Bugzilla-Assigned-To: freebsd-bugs@FreeBSD.org X-Bugzilla-Target-Milestone: --- X-Bugzilla-Flags: X-Bugzilla-Changed-Fields: bug_id short_desc product version rep_platform op_sys bug_status bug_severity priority component assigned_to reporter Message-ID: Content-Type: text/plain; charset="UTF-8" Content-Transfer-Encoding: 7bit X-Bugzilla-URL: https://bugs.freebsd.org/bugzilla/ Auto-Submitted: auto-generated MIME-Version: 1.0 X-BeenThere: freebsd-bugs@freebsd.org X-Mailman-Version: 2.1.18 Precedence: list List-Id: Bug reports List-Unsubscribe: , List-Archive: List-Post: List-Help: List-Subscribe: , X-List-Received-Date: Mon, 30 Jun 2014 05:23:52 -0000 https://bugs.freebsd.org/bugzilla/show_bug.cgi?id=191506 Bug ID: 191506 Summary: [dtrace] [dtruss] dtruss doesn't seem to work on -HEAD Product: Base System Version: 11.0-CURRENT Hardware: Any OS: Any Status: Needs Triage Severity: Affects Only Me Priority: --- Component: bin Assignee: freebsd-bugs@FreeBSD.org Reporter: adrian@freebsd.org Compiled up a fresh -HEAD as of the timestamp: FreeBSD adrian-hackbox 11.0-CURRENT FreeBSD 11.0-CURRENT #1 b01e1c9(local/rss)-dirty: Mon Jun 30 04:51:05 UTC 2014 adrian@adrian-hackbox:/usr/home/adrian/git/github/erikarn/freebsd-obj/usr/home/adrian/git/github/erikarn/freebsd/sys/RSS amd64 .. and then looked at using the userland dtrace bits. The first example i found from: https://wiki.freebsd.org/DTrace/userland was to use dtruss, so I tried it. It didn't work. root@adrian-hackbox:/home/adrian/git/github/erikarn/freebsd-rss/rss-http # dtruss -c date dtrace: invalid probe specifier #pragma D option quiet #pragma D option switchrate=10 /* * Command line arguments */ inline int OPT_command = 1; inline int OPT_follow = 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 = 1; inline int OPT_pid = 0; inline int OPT_name = 0; inline int OPT_trace = 0; inline int OPT_stack = 0; inline string NAME = "."; inline string TRACE = "."; dtrace:::BEGIN { /* 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 = return\n"); } /* * Save syscall entry info */ syscall:::entry /((OPT_command || OPT_pid) && pid == $target) || (OPT_name && execname == NAME) || (OPT_follow && progenyof($target))/ { /* set start details */ self->start = timestamp; self->vstart = vtimestamp; self->arg0 = arg0; self->arg1 = arg1; self->arg2 = arg2; /* count occurances */ OPT_counts == 1 ? @Counts[probefunc] = count() : 1; } /* * Follow children */ syscall::fork*:return /(OPT_follow && progenyof($target)) && (!OPT_trace || (TRACE == probefunc))/ { /* print output */ self->code = errno == 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 = %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 != TRACE/ { /* drop info */ self->start = 0; self->vstart = 0; self->arg0 = 0; self->arg1 = 0; self->arg2 = 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 has * shown in benchmarks to be the fastest (fewest probes fired, fewest actions). */ /* print 3 args, return as hex */ syscall::sigprocmask:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = 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 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 3 args, arg0 as a string */ syscall::access*:return, syscall::stat*:return, syscall::lstat*:return, syscall::readlink*:return, syscall::open*:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %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 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 3 args, arg1 as a string */ syscall::write:return, syscall::pwrite:return, syscall::*read*:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %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 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 0 arg output */ syscall::*fork*:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %d %s%d\n", probefunc, (int)arg0, self->code, (int)errno); OPT_stack ? ustack() : 1; OPT_stack ? trace("\n") : 1; self->arg0 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 1 arg output */ syscall::close:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %d %s%d\n", probefunc, self->arg0, (int)arg0, self->code, (int)errno); OPT_stack ? ustack() : 1; OPT_stack ? trace("\n") : 1; self->arg0 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 2 arg output */ syscall::utimes:return, syscall::munmap:return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %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 = 0; self->arg1 = 0; self->arg2 = 0; } /* print 3 arg output - default */ syscall:::return /self->start/ { /* calculate elapsed time */ this->elapsed = timestamp - self->start; self->start = 0; this->cpu = vtimestamp - self->vstart; self->vstart = 0; self->code = errno == 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 = %d %s%d\n", probefunc, self->arg0, self->arg1, self->arg2, (int)arg0, self->code, (int)errno); OPT_stack ? ustack() : 1; OPT_stack ? trace("\n") : 1; self->arg0 = 0; self->arg1 = 0; self->arg2 = 0; } /* program exited */ proc:::exit /(OPT_command || OPT_pid) && pid == $target/ { exit(0); } /* print counts */ dtrace:::END { OPT_counts == 1 ? printf("\n%-32s %16s\n", "CALL", "COUNT") : 1; OPT_counts == 1 ? printa("%-32s %@16d\n", @Counts) : 1; } : "/usr/lib/dtrace/errno.d", line 150: failed to resolve INP_IPV4: Unknown variable name -- You are receiving this mail because: You are the assignee for the bug.