Solved dwatch output format

Y

yjqg6666

From the dwatch(1)(1) man page,
Output format without options is:

date/time uid.gid execname[pid]: psargs

For example, the command `dwatch BEGIN' produces:

INFO Watching 'dtrace:::BEGIN' ...
2017 May 29 08:23:20 0.0 dtrace[60671]: dtrace -s /dev/stdin
Click to expand...
But dwatch -x exec have the following output:
<2><3>2025 Apr 1 09:17:14 1001.1001 bash[96920]: /usr/local/bin/bash
<2><3>2025 Apr 1 09:17:14 1001.1001 bash[97022]: /usr/local/bin/bash
Click to expand...

What are the "<2><3>" here?
 
First... when trying to debug something always keep your tests consistent. In your first example you're adding a new variable by exchanging BEGIN with exec which - theoretically - could also be a cause for the generation of different output:

Code: 
peter@bsd:/home/peter $ doas dwatch BEGIN
INFO Watching 'dtrace:::BEGIN' ...
2025 Apr  2 05:21:31 0.0 dtrace[1624]: dtrace -s /dev/stdin
peter@bsd:/home/peter $ doas dwatch -x BEGIN
INFO Watching 'dtrace:::BEGIN' ...
INFO Setting trace: 1
<2><3>2025 Apr  2 05:21:35 0.0 dtrace[1648]: dtrace -s /dev/stdin
I know this may seem like nitpicking, fair enough, but it's the only way to get to the right conclusions.

Anyway, I got curious and ... you are aware that /usr/sbin/dwatch is basically a shell script? Bit of an annoying one too IMVHO because it insists on automagically using things like sudo which I'm not really a fan of. But anyway.... now would be a good time for less `which dwatch` I'd say.

When doing so -x leads me to TRACE and that led me to:

Code: 
*:execve:entry|execve:entry)
        ACTIONS=$( awk 'gsub(/\\\t/, "\t") || 1' <<-EOF
                $PROBE /* probe ID $ID */
                {${TRACE:+
                \       printf("<$ID>");}
                \       this->caller_execname = execname;
                }
                EOF
As well as:
Code: 
exec 9<<EOF
$PROBE /* probe ID 2 */
{${TRACE:+
        printf("<2>");
}
In other words: this particular (undocumented?) output format fully traces back to this particular script and not dtrace necessarily. Making me wonder why even use this script instead of using dtrace(1) directly, optionally with sysutils/dtrace-toolkit? This may be a good read.

Hope this can help!
 
yjqg6666 said:
@ShelLuser Thanks for the detailed explanation. Just knew that the dwatch() is a script after posting the first three posts. I treat dwatch() as an alternative to strace in Linux.
Click to expand...
Aha! Then I have a much better solution for you: truss(1) as well as ktrace(1), I would suggest forgetting about DTrace for now and instead rely on these.

Here's the thing: truss can trace all kinds of system calls "just like that" whereas DTrace only reacts to probes. See, the catch is that those probes need to be either provided by the developers in order to get the most out of this setup, or you build your own trace scripts to check for specific aspects.

truss doesn't have this problem, and thus it's also much closer to strace (basically: both allow you to trace system calls).

But wait, there's more! (pardon the pun).

More seriously though: sometimes there's only so much you can get out of truss, and in those situations you'll want ktrace: this critter can specifically trace kernel operations. Now, that's obviously a broad term, so allow me:
ktrace(1) said:
The following trace points are supported:

c trace system calls
f trace page faults
i trace I/O
n trace namei(9) translations
p trace capability check failures
s trace signal processing
t trace various structures
u userland traces generated by utrace(2)
w context switches
y trace sysctl(3) requests
+ trace the default set of trace points - c, i, n, s, t, u, y
Click to expand...
See what I mean? It can do the same as truss (the +c; system call tracing?), and a whole lot more! And the best part? You don't have to do a thing. One catch: it dumps its data in a binary format, so you'll need kdump to actually display that.

Allow me:
Code: 
peter@bsd:/home/peter $ truss -o ls.truss ls > /dev/null
peter@bsd:/home/peter $ ktrace ls > /dev/null
peter@bsd:/home/peter $ head -7 ls.truss
mmap(0x0,135168,PROT_READ|PROT_WRITE,MAP_PRIVATE|MAP_ANON,-1,0x0) = 53157382062080 (0x3058aae00000)
mprotect(0x4fada9523000,8192,PROT_READ)          = 0 (0x0)
issetugid()                                      = 0 (0x0)
sigfastblock(0x1,0x4fada9525ea0)                 = 0 (0x0)
open("/etc/libmap.conf",O_RDONLY|O_CLOEXEC,025270030030) = 3 (0x3)
fstat(3,{ mode=-rw-r--r-- ,inode=1054,size=35,blksize=4096 }) = 0 (0x0)
read(3,"includedir /usr/local/etc/libmap"...,35) = 35 (0x23)
peter@bsd:/home/peter $ kdump | head -7
  1561 ktrace   RET   ktrace 0
  1561 ktrace   CALL  execve(0x2b14f91cd1a0,0x2b14f91cd7c0,0x2b14f91cd7d0)
  1561 ktrace   NAMI  "/sbin/ls"
  1561 ktrace   RET   execve -1 errno 2 No such file or directory
  1561 ktrace   CALL  execve(0x2b14f91cd1a0,0x2b14f91cd7c0,0x2b14f91cd7d0)
  1561 ktrace   NAMI  "/bin/ls"
  1561 ktrace   NAMI  "/libexec/ld-elf.so.1"
peter@bsd:/home/peter $
See what I mean?
 
You must log in or register to reply here.
Back
Top