NetBSD Problem Report #43611
From Wolfgang.Stukenbrock@nagler-company.com Tue Jul 13 12:34:03 2010
Return-Path: <Wolfgang.Stukenbrock@nagler-company.com>
Received: from mail.netbsd.org (mail.netbsd.org [204.152.190.11])
by www.NetBSD.org (Postfix) with ESMTP id EF3E663BACE
for <gnats-bugs@gnats.NetBSD.org>; Tue, 13 Jul 2010 12:34:02 +0000 (UTC)
Message-Id: <20100713123353.B94102E478F@s013.nagler-company.com>
Date: Tue, 13 Jul 2010 14:33:53 +0200 (CEST)
From: Wolfgang.Stukenbrock@nagler-company.com
Reply-To: Wolfgang.Stukenbrock@nagler-company.com
To: gnats-bugs@gnats.NetBSD.org
Subject: kernel-trace (via ktruss) reports wrong parameter/result values
X-Send-Pr-Version: 3.95
>Number: 43611
>Notify-List: gson@gson.org
>Category: kern
>Synopsis: kernel-trace (via ktruss) reports wrong parameter/result values
>Confidential: no
>Severity: serious
>Priority: high
>Responsible: kern-bug-people
>State: open
>Class: sw-bug
>Submitter-Id: net
>Arrival-Date: Tue Jul 13 12:35:00 +0000 2010
>Last-Modified: Sat Jan 17 14:27:57 +0000 2015
>Originator: W. Stukenbrock
>Release: NetBSD 5.0.2
>Organization:
Dr. Nagler & Company GmbH
>Environment:
System: NetBSD s013 5.0.2 NetBSD 5.0.2 (NSW-S013) #2: Fri Jul 9 11:02:34 CEST 2010 root@s013:/usr/src/sys/arch/amd64/compile/NSW-S013 amd64
Architecture: x86_64
Machine: amd64
>Description:
While debugging a tape-device problem we have traced the dd(1) command in order to validate the correct system calls.
Accedently this was not possible due to the fact that "ktruss -T dd if=/dev/zero of=/dev/nrst1 bs=32k count=10" does not
report all system calls and - even worse - reports wrong data for the open(2) call!
We've added some printouts of the internal variables to the dd.c (e.g. the fd-numbers).
The output of command above follows:
s013# ktruss -T ./dd-tst if=/dev/zero of=$TAPE bs=32k count=20
in.fd = 3
out.fd = 5
io-buffer: in 0x7f7ffd801000 out 0x7f7ffd801000 - offsets 0/0
file-cnt loop ...
i-loop start cpy-cnt 20 in-full 0 in_part 0
21158 1 ktruss 1279024020.645948480 emul(netbsd)
21158 1 ktruss 1279024020.645947153 fktrace = 0
21158 1 ktruss 1279024020.645956442 fcntl(0x4, 0x3, 0) = 1
21158 1 ktruss 1279024020.645957978 fcntl(0x4, 0x4, 0x1) = 0
21158 1 dd-tst 1279024020.646061899 emul(netbsd)
21158 1 dd-tst 1279024020.646062877 execve("./dd-tst", 0x7f7fffffdc60, 0x7f7fffffdc90) JUSTRETURN
21158 1 dd-tst 1279024020.646078730 mmap(0, 0x8000, 0x3, 0x1002, 0xffffffff, 0, 0) = 0x7f7ffdff8000
21158 1 dd-tst 1279024020.646088787 open("/usr/libexec/ld.elf_so", 0, 0) Err#2 ENOENT
21158 1 dd-tst 1279024020.646107644 open("/etc/ld.so.conf", 0, 0xfefeff362d6e722d) = 3
21158 1 dd-tst 1279024020.646109460 __fstat30(0x3, 0x7f7fffffd3c0) = 0
21158 1 dd-tst 1279024020.646112812 mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0) = 0x7f7ffdff7000
21158 1 dd-tst 1279024020.646117771 munmap(0x7f7ffdff7000, 0x1000) = 0
21158 1 dd-tst 1279024020.646120285 mmap(0, 0x116000, 0x5, 0x14000002, 0x3, 0, 0) = 0x7f7ffdc00000
21158 1 dd-tst 1279024020.646123707 mmap(0x7f7ffdd12000, 0x2000, 0x3, 0x12, 0x3, 0, 0x12000) = 0x7f7ffdd12000
21158 1 dd-tst 1279024020.646126012 mmap(0x7f7ffdd14000, 0x2000, 0x3, 0x1012, 0xffffffff, 0, 0) = 0x7f7ffdd14000
21158 1 dd-tst 1279024020.646128037 mprotect(0x7f7ffdc12000, 0x100000, 0) = 0
21158 1 dd-tst 1279024020.646136976 close(0x3) = 0
21158 1 dd-tst 1279024020.646154716 open("/usr/lib/libutil.so.7", 0, 0xfefeff35ff31302d) = 3
21158 1 dd-tst 1279024020.646156950 __fstat30(0x3, 0x7f7fffffd3c0) = 0
21158 1 dd-tst 1279024020.646160023 mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0) = 0x7f7ffdff7000
21158 1 dd-tst 1279024020.646164353 munmap(0x7f7ffdff7000, 0x1000) = 0
21158 1 dd-tst 1279024020.646167007 mmap(0, 0x218000, 0x5, 0x14000002, 0x3, 0, 0) = 0x7f7ffd900000
21158 1 dd-tst 1279024020.646170569 mmap(0x7f7ffdafa000, 0xc000, 0x3, 0x12, 0x3, 0, 0xfa000) = 0x7f7ffdafa000
21158 1 dd-tst 1279024020.646172804 mmap(0x7f7ffdb06000, 0x12000, 0x3, 0x1012, 0xffffffff, 0, 0) = 0x7f7ffdb06000
21158 1 dd-tst 1279024020.646175248 mprotect(0x7f7ffd9fa000, 0x100000, 0) = 0
21158 1 dd-tst 1279024020.646183769 close(0x3) = 0
21158 1 dd-tst 1279024020.646201019 open("/usr/lib/libc.so.12", 0, 0xff31302d6e722d62) = 3
21158 1 dd-tst 1279024020.646203044 __fstat30(0x3, 0x7f7fffffd3c0) = 0
21158 1 dd-tst 1279024020.646204651 close(0x3) = 0
21158 1 dd-tst 1279024020.646396150 __sysctl(0x7f7fffffdb50, 0x2, 0x7f7ffdb159c0, 0x7f7fffffdb48, 0, 0) = 0
21158 1 dd-tst 1279024020.646429882 issetugid() = 0
21158 1 dd-tst 1279024020.646472065 open("/lib/libc.so.12", 0, 0) = 3
21158 1 dd-tst 1279024020.646496579 write(0x2, 0x7f7fffffd290, 0xa) = 10
"in.fd = 3\n"
21158 1 dd-tst 1279024020.646499791 __fstat30(0x3, 0x7f7fffffdaf0) = 0
21158 1 dd-tst 1279024020.646502166 ioctl(0x3, MTIOCGET, 0x7f7fffffdb80) Err#45 EOPNOTSUPP
21158 1 dd-tst 1279024020.652129884 open("/dev/zero", 0x602, 0x1b6) = 5
21158 1 dd-tst 1279024020.652135820 write(0x2, 0x7f7fffffd290, 0xb) = 11
"out.fd = 5\n"
21158 1 dd-tst 1279024020.652138544 __fstat30(0x5, 0x7f7fffffdaf0) = 0
21158 1 dd-tst 1279024020.655394311 ioctl(0x5, MTIOCGET, 0x7f7fffffdb80) = 0
"\a\0\^C\0\0\0\0\0\0\0\0\0\r\0\0\0\0\0\0\0\M^B\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.655398920 __sysctl(0x7f7fffffd730, 0x2, 0x7f7ffdb0e090, 0x7f7fffffd728, 0, 0) = 0
21158 1 dd-tst 1279024020.655409466 __sysctl(0x7f7fffffd650, 0x2, 0x7f7ffdb15e40, 0x7f7fffffd648, 0, 0) = 0
21158 1 dd-tst 1279024020.655414704 readlink("/dev/nrst1", 0x7f7fffffd740, 0x400) Err#2 ENOENT
21158 1 dd-tst 1279024020.655420989 mmap(0, 0x1000, 0x3, 0x1002, 0xffffffff, 0, 0) = 0x7f7ffdff7000
21158 1 dd-tst 1279024020.655440894 mmap(0, 0x1000, 0x3, 0x1002, 0xffffffff, 0, 0) = 0x7f7ffdff6000
21158 1 dd-tst 1279024020.655455420 mmap(0, 0x100000, 0x3, 0x14001002, 0xffffffff, 0, 0) = 0x7f7ffd800000
21158 1 dd-tst 1279024020.655469528 write(0x2, 0x7f7fffffd290, 0x3e) = 62
"io-buffer: in 0x7f7ffd801000 out 0x7f7ffd801000 - offsets 0/0\n"
21158 1 dd-tst 1279024020.655473648 gettimeofday(0x505820, 0) = 0
21158 1 dd-tst 1279024020.655478258 __sigaction_sigtramp(0x1d, 0x7f7fffffdbd0, 0x7f7fffffdbb0, 0x7f7ffd981710, 0x2) = 0
21158 1 dd-tst 1279024020.655481261 __sigaction_sigtramp(0x2, 0x7f7fffffdbd0, 0x7f7fffffdbb0, 0x7f7ffd981710, 0x2) = 0
21158 1 dd-tst 1279024020.655506054 write(0x2, 0x404779, 0x12) = 18
"file-cnt loop ...\n"
21158 1 dd-tst 1279024020.655511222 write(0x2, 0x7f7fffffd2a0, 0x2c) = 44
"i-loop start cpy-cnt 20 in-full 0 in_part 0\n"
i-loop read on 3 - req 32768 - result 32768
calling dd_out(1) ...
write on 5 - req 32768 - res 0
dd-tst: /dev/nrst1: end of device
1+0 records in
0+0 records out
0 bytes transferred in 0.004 secs (0 bytes/sec)
21158 1 dd-tst 1279024020.655587975 read(0x3, 0x7f7ffd801000, 0x8000) = 32768
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.655994021 write(0x2, 0x7f7fffffd2a0, 0x2c) = 44
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.655997024 write(0x2, 0x4048b0, 0x16) = 22
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.656000306 __sigprocmask14(0x1, 0x5057b0, 0x7f7fffffdb50) = 0
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659109690 write(0x5, 0x7f7ffd801000, 0x8000) = 0
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659116185 write(0x2, 0x7f7fffffd1f0, 0x1f) = 31
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659118979 __sigprocmask14(0x3, 0x7f7fffffdb50, 0) = 0
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659138604 write(0x2, 0x7f7fffffd130, 0x8) = 8
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659143143 write(0x2, 0x7f7fffffd210, 0x19) = 25
"\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0\0"
21158 1 dd-tst 1279024020.659155505 write(0x2, 0x505517, 0x1) = 1
"i-loop read on 3 - req 32768 - result 32768\n"
21158 1 dd-tst 1279024020.659159206 gettimeofday(0x7f7fffffd980, 0) = 0
"calling dd_out(1) ...\n"
21158 1 dd-tst 1279024020.659166679 write(0x2, 0x7f7fffffd990, 0x1f) = 31
""
21158 1 dd-tst 1279024020.659172755 write(0x2, 0x7f7fffffd990, 0x30) = 48
"write on 5 - req 32768 - res 0\n"
21158 1 dd-tst 1279024020.659177085 exit(0x1)
s013#
Our prints addedto dd reports that fd = 3 is the input and fd = 5 is the output.
This corresponds to the read(2) and write(2) calles done later.
But ktruss reports ' 21158 1 dd-tst 1279024020.652129884 open("/dev/zero", 0x602, 0x1b6) = 5', and that is
simply nonsence!
The call to open("/dev/zero", ...) has returned 3 as stated by our print outs and due to the fact that read(2) is done from 3
and the open("/dev/nrst1", ...) that is missing in the output has returned 5.
It looks like the ktruss command has combined theese two calls to open into one line of output.
>How-To-Repeat:
e.g. try to trace the dd command - at least on our machine the problem is reproducable.
>Fix:
not known up to now - sorry
>Release-Note:
>Audit-Trail:
From: David Laight <david@l8s.co.uk>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Tue, 13 Jul 2010 18:40:14 +0100
On Tue, Jul 13, 2010 at 12:35:00PM +0000, Wolfgang.Stukenbrock@nagler-company.com wrote:
> >Synopsis: kernel-trace (via ktruss) reports wrong parameter/result values
...
> While debugging a tape-device problem we have traced the dd(1) command in order to validate the correct system calls.
ktrace+kdump tends to work much better than ktruss.
ktruss tries to convert the ktrace data to system call parameters and
fails when the data is unexpected (due to extra traces).
ktruss probably should be rewritten to use system call entry/exit
breakpoints and then userspace controlled reads of the traced programs
memory (which is how truss works on SYSV).
David
--
David Laight: david@l8s.co.uk
From: christos@zoulas.com (Christos Zoulas)
To: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org,
gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
Wolfgang.Stukenbrock@nagler-company.com
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Tue, 13 Jul 2010 13:42:06 -0400
On Jul 13, 5:40pm, david@l8s.co.uk (David Laight) wrote:
-- Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter
| The following reply was made to PR kern/43611; it has been noted by GNATS.
|
| From: David Laight <david@l8s.co.uk>
| To: gnats-bugs@NetBSD.org
| Cc:
| Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
| Date: Tue, 13 Jul 2010 18:40:14 +0100
|
| On Tue, Jul 13, 2010 at 12:35:00PM +0000, Wolfgang.Stukenbrock@nagler-company.com wrote:
| > >Synopsis: kernel-trace (via ktruss) reports wrong parameter/result values
| ...
| > While debugging a tape-device problem we have traced the dd(1) command in order to validate the correct system calls.
|
| ktrace+kdump tends to work much better than ktruss.
|
| ktruss tries to convert the ktrace data to system call parameters and
| fails when the data is unexpected (due to extra traces).
|
| ktruss probably should be rewritten to use system call entry/exit
| breakpoints and then userspace controlled reads of the traced programs
| memory (which is how truss works on SYSV).
Well, this is PT_SYSCALL and /usr/pkg/bin/strace :-)
christos
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong
parameter/result values
Date: Wed, 14 Jul 2010 01:45:23 +0000
On Tue, Jul 13, 2010 at 05:40:04PM +0000, David Laight wrote:
> ktruss probably should be rewritten to use system call entry/exit
> breakpoints and then userspace controlled reads of the traced programs
> memory (which is how truss works on SYSV).
Using ptrace for this purpose is not desirable because it monkeys with
the parent/child process relationships and tends to break things,
particularly shell scripts.
(I'm not particularly clear on exactly what ktruss does that's
different from running kdump afterwards, but then I've never been
particularly clear on why ktruss is desirable relative to running
kdump afterwards, either.)
--
David A. Holland
dholland@netbsd.org
From: christos@zoulas.com (Christos Zoulas)
To: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org,
gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
Wolfgang.Stukenbrock@nagler-company.com
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Wed, 14 Jul 2010 08:36:07 -0400
On Jul 14, 1:50am, dholland-bugs@netbsd.org (David Holland) wrote:
-- Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter
| On Tue, Jul 13, 2010 at 05:40:04PM +0000, David Laight wrote:
| > ktruss probably should be rewritten to use system call entry/exit
| > breakpoints and then userspace controlled reads of the traced programs
| > memory (which is how truss works on SYSV).
|
| Using ptrace for this purpose is not desirable because it monkeys with
| the parent/child process relationships and tends to break things,
| particularly shell scripts.
It is desirable because it stops the process and lets you examine the
syscall arguments in detail.
| (I'm not particularly clear on exactly what ktruss does that's
| different from running kdump afterwards, but then I've never been
| particularly clear on why ktruss is desirable relative to running
| kdump afterwards, either.)
Interactivity; you can watch processes that stop and wait for events
and see what they do as you supply the different events.
christos
From: David Laight <david@l8s.co.uk>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Wed, 14 Jul 2010 22:18:51 +0100
On Wed, Jul 14, 2010 at 12:40:03PM +0000, Christos Zoulas wrote:
> On Jul 14, 1:50am, dholland-bugs@netbsd.org (David Holland) wrote:
> | On Tue, Jul 13, 2010 at 05:40:04PM +0000, David Laight wrote:
> | > ktruss probably should be rewritten to use system call entry/exit
> | > breakpoints and then userspace controlled reads of the traced programs
> | > memory (which is how truss works on SYSV).
> |
> | Using ptrace for this purpose is not desirable because it monkeys with
> | the parent/child process relationships and tends to break things,
> | particularly shell scripts.
>
> It is desirable because it stops the process and lets you examine the
> syscall arguments in detail.
Actually the systrace code would have let you do this, except that
someone decided to use to try to implement security not tracing.
IIRC that didn't mess with lineage of processes.
David
--
David Laight: david@l8s.co.uk
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong
parameter/result values
Date: Thu, 15 Jul 2010 20:13:45 +0000
On Wed, Jul 14, 2010 at 12:40:03PM +0000, Christos Zoulas wrote:
>|> ktruss probably should be rewritten to use system call entry/exit
>|> breakpoints and then userspace controlled reads of the traced programs
>|> memory (which is how truss works on SYSV).
>|
>| Using ptrace for this purpose is not desirable because it monkeys with
>| the parent/child process relationships and tends to break things,
>| particularly shell scripts.
>
> It is desirable because it stops the process and lets you examine the
> syscall arguments in detail.
Mm, point. Maybe we ought to invent a new kind of tracing for this
purpose (since supervised execution was trendy in research for a while
and it's getting to the point of moving to production...)
I'm not sure if it makes sense for that to be different from a
debugger interface or not.
> | (I'm not particularly clear on exactly what ktruss does that's
> | different from running kdump afterwards, but then I've never been
> | particularly clear on why ktruss is desirable relative to running
> | kdump afterwards, either.)
>
> Interactivity; you can watch processes that stop and wait for events
> and see what they do as you supply the different events.
Ah. Yeah, I guess that can be useful. The main problem I've always had
with strace and truss and whatnot is that the trace output gets mixed
with the program's output; when I first found ktrace years ago it was
a big step forward.
--
David A. Holland
dholland@netbsd.org
From: christos@zoulas.com (Christos Zoulas)
To: gnats-bugs@NetBSD.org, kern-bug-people@netbsd.org,
gnats-admin@netbsd.org, netbsd-bugs@netbsd.org,
Wolfgang.Stukenbrock@nagler-company.com
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Thu, 15 Jul 2010 17:57:18 -0400
On Jul 15, 8:15pm, dholland-bugs@netbsd.org (David Holland) wrote:
-- Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter
| Mm, point. Maybe we ought to invent a new kind of tracing for this
| purpose (since supervised execution was trendy in research for a while
| and it's getting to the point of moving to production...)
|
| I'm not sure if it makes sense for that to be different from a
| debugger interface or not.
We already support PT_SYSCALL, although it might be broken in current.
|
| > | (I'm not particularly clear on exactly what ktruss does that's
| > | different from running kdump afterwards, but then I've never been
| > | particularly clear on why ktruss is desirable relative to running
| > | kdump afterwards, either.)
| >
| > Interactivity; you can watch processes that stop and wait for events
| > and see what they do as you supply the different events.
|
| Ah. Yeah, I guess that can be useful. The main problem I've always had
| with strace and truss and whatnot is that the trace output gets mixed
| with the program's output; when I first found ktrace years ago it was
| a big step forward.
For that you can use -o fname and tail -f fname in another pty.
christos
From: David Holland <dholland-bugs@netbsd.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong
parameter/result values
Date: Thu, 15 Jul 2010 23:17:17 +0000
On Thu, Jul 15, 2010 at 10:00:07PM +0000, Christos Zoulas wrote:
> | Mm, point. Maybe we ought to invent a new kind of tracing for this
> | purpose (since supervised execution was trendy in research for a while
> | and it's getting to the point of moving to production...)
> |
> | I'm not sure if it makes sense for that to be different from a
> | debugger interface or not.
>
> We already support PT_SYSCALL, although it might be broken in current.
Well, a new kind of tracing that doesn't get entangled with wait() and
mess up parent process ids.
> | Ah. Yeah, I guess that can be useful. The main problem I've always had
> | with strace and truss and whatnot is that the trace output gets mixed
> | with the program's output; when I first found ktrace years ago it was
> | a big step forward.
>
> For that you can use -o fname and tail -f fname in another pty.
I have no idea why I didn't do that at the time, but it was a long
time ago and may have involved HPUX.
--
David A. Holland
dholland@netbsd.org
From: matthew sporleder <msporleder@gmail.com>
To: gnats-bugs@netbsd.org, gnats-admin@netbsd.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong
parameter/result values
Date: Wed, 3 Aug 2011 20:49:40 -0400
See how ktruss claims to open /usr/local/lib/libm but kdump
(correctly) reports "No such file or directory".
NetBSD vc136-15.vc.panix.com 5.1 NetBSD 5.1 (PANIX-VC) #0: Thu Mar 10
01:49:14 EST 2011
root@juggler.panix.com:/misc/obj/misc/devel/netbsd/5.1/src/sys/arch/amd64/compile/PANIX-VC
amd64
ktrace/kdump - correct:
22799 1 perl NAMI "/etc/ld.so.conf"
22799 1 perl RET open -1 errno 2 No such file or directory
22799 1 perl CALL open(0x7f7fffffcfb0,0,0xfeff2f2d6e722d6c)
22799 1 perl NAMI "/usr/pkg/lib/libm.so.0"
22799 1 perl RET open -1 errno 2 No such file or directory
22799 1 perl CALL open(0x7f7fffffcfb0,0,0xfefefefefefefeff)
22799 1 perl NAMI "/usr/local/lib/libm.so.0"
22799 1 perl RET open -1 errno 2 No such file or directory
22799 1 perl CALL open(0x7f7fffffcfb0,0,0x2f2d6e722cff2f2d)
22799 1 perl NAMI "/usr/lib/libm.so.0"
22799 1 perl RET open 3
ktruss - incorrect:
11347 1 perl open("/usr/libexec/ld.elf_so", 0, 0) Err#2 ENOENT
11347 1 perl open("/etc/ld.so.conf", 0, 0xfeff2f2d6e722d6c)
Err#2 ENOENT
11347 1 perl open("/usr/pkg/lib/libm.so.0", 0,
0xfefefefefefefeff) Err#2 ENOENT
11347 1 perl open("/usr/local/lib/libm.so.0", 0,
0x2f2d6e722cff2f2d) = 3
11347 1 perl __fstat30(0x3, 0x7f7fffffcee0) = 0
11347 1 perl mmap(0, 0x1000, 0x1, 0x1, 0x3, 0, 0) = 0x7f7ffdff7000
11347 1 perl munmap(0x7f7ffdff7000, 0x1000) = 0
11347 1 perl mmap(0, 0x11c000, 0x5, 0x14000002, 0x3, 0, 0) =
0x7f7ffdc00000
11347 1 perl mmap(0x7f7ffdd1b000, 0x1000, 0x3, 0x12, 0x3, 0,
0x1b000) = 0x7f7ffdd1b000
11347 1 perl mmap(0x7f7ffdd1c000, 0, 0x3, 0x1012,
0xffffffff, 0, 0) = 0x7f7ffdd1c000
11347 1 perl mprotect(0x7f7ffdc1b000, 0x100000, 0) = 0
11347 1 perl close(0x3) = 0
11347 1 perl open("/usr/lib/libm.so.0", 0,
0xfefefefefeff2f2d) Err#2 ENOENT
From: Andreas Gustafsson <gson@gson.org>
To: gnats-bugs@NetBSD.org
Cc:
Subject: Re: kern/43611: kernel-trace (via ktruss) reports wrong parameter/result values
Date: Wed, 10 Aug 2011 23:03:30 +0300
I also ran into problems with ktruss recently, on NetBSD 5.0.1/i386.
For example, an open() system call which ktrace + kdump reported like
this:
15159 1 testprog CALL open(0xbb80208c,0,0xbfbfe7e8)
15159 1 testprog NAMI "/dev/rwd0a"
15159 1 testprog RET open 3
ktruss reported like this:
11230 1 testprog open("/etc/malloc.conf", 0, 0xbfbfe7e8) = 3
Note how the argument "/dev/rwd0a" has turned into "/etc/malloc.conf".
--
Andreas Gustafsson, gson@gson.org
>Unformatted:
(Contact us)
$NetBSD: query-full-pr,v 1.39 2013/11/01 18:47:49 spz Exp $
$NetBSD: gnats_config.sh,v 1.8 2006/05/07 09:23:38 tsutsui Exp $
Copyright © 1994-2007
The NetBSD Foundation, Inc. ALL RIGHTS RESERVED.