dtrace sdt problem: my fault or a generic problem (SYSINIT not
working as expected for modules)?
Alexander Leidinger
Alexander at Leidinger.net
Fri Mar 25 09:52:28 UTC 2011
Hi,
I'm in the process of adding some SDT probes to the linuxulator.
Unfortunately I get a kernel panic while doing a "dtrace -l -P
linuxulator". What I see in kgdb puzzles me. Maybe someone can help out?
The id of the provider is 0x0, I would expect this is a little
problem. Debugging session follows with some discussion inline and
afterwards.
Fatal trap 12: page fault while in kernel mode
fault virtual address = 0x48
fault code = supervisor read, page not present
instruction pointer = 0x20:0x80db03db
stack pointer = 0x28:0xafb4d7f8
frame pointer = 0x28:0xafb4d83c
code segment = base 0x0, limit 0xfffff, type 0x1b
= DPL 0, pres 1, def32 1, gran 1
processor eflags = interrupt enabled, resume, IOPL = 0
current process = 1415 (initial thread)
trap number = 12
panic: page fault
Uptime: 10m4s
#5 0x8071e9c6 in trap (frame=0xafb4d7b8) at ../../../i386/i386/trap.c:553
#6 0x8070aa4c in calltrap () at ../../../i386/i386/exception.s:168
#7 0x80db03db in dtrace_probe_lookup (prid=0, mod=0xafb4d8e0 "emul",
func=0xafb4d8a0 "linux_schedtail", name=0xafb4d860 "return")
at
/usr/src/sys/modules/dtrace/dtrace/../../../cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c:7807
#8 0x80ee0955 in sdt_probe_callback (probe=0x859daca0, arg=0x0)
at /usr/src/sys/modules/dtrace/sdt/../../../cddl/dev/sdt/sdt.c:131
(kgdb) up 7
During symbol reading, Incomplete CFI data; unspecified registers at
0x80560633.
#7 0x80db03db in dtrace_probe_lookup (prid=0x0, mod=0xafb4d8e0
"emul", func=0xafb4d8a0 "linux_schedtail",
name=0xafb4d860 "return")
at
/usr/src/sys/modules/dtrace/dtrace/../../../cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c:7807
7807 pkey.dtpk_mmatch = mod ? &dtrace_match_string :
&dtrace_match_nul;
prid is zero...?
(kgdb) list
7802 int match;
7803
7804 pkey.dtpk_prov = ((dtrace_provider_t *)prid)->dtpv_name;
7805 pkey.dtpk_pmatch = &dtrace_match_string;
7806 pkey.dtpk_mod = mod;
7807 pkey.dtpk_mmatch = mod ? &dtrace_match_string :
&dtrace_match_nul;
7808 pkey.dtpk_func = func;
7809 pkey.dtpk_fmatch = func ? &dtrace_match_string :
&dtrace_match_nul;
7810 pkey.dtpk_name = name;
7811 pkey.dtpk_nmatch = name ? &dtrace_match_string :
&dtrace_match_nul;
(kgdb) print pkey
$1 = {
dtpk_prov = 0x1e58 <Address 0x1e58 out of bounds>,
dtpk_pmatch = 0xafb4d83c,
dtpk_mod = 0x80db1143 "\213E203034[^_]\220 ,S200d\213\025",
dtpk_mmatch = 0x80ed531c <dtrace_lock>,
dtpk_func = 0x80dc68d8
"/usr/src/sys/modules/dtrace/dtrace/../../../cddl/contrib/opensolaris/uts/common/dtrace/dtrace.c",
dtpk_fmatch = 0x1e58,
dtpk_name = 0x1e18 <Address 0x1e18 out of bounds>,
dtpk_nmatch = 0x72e,
dtpk_id = 0x72f
}
(kgdb) print ((dtrace_provider_t *)prid)->dtpv_name
Cannot access memory at address 0x48
Ok, prid is NULL, so this is not a surprise, but why is it NULL?
(kgdb) print prid
$2 = 0x0
(kgdb) print mod
$3 = 0xafb4d8e0 "emul"
(kgdb) up 1
#8 0x80ee0955 in sdt_probe_callback (probe=0x859daca0, arg=0x0)
at /usr/src/sys/modules/dtrace/sdt/../../../cddl/dev/sdt/sdt.c:131
131 if (dtrace_probe_lookup(prov->id, mod, func, name) != 0)
(kgdb) list
126 */
127 strlcpy(mod, probe->mod, sizeof(mod));
128 strlcpy(func, probe->func, sizeof(func));
129 strlcpy(name, probe->name, sizeof(name));
130
131 if (dtrace_probe_lookup(prov->id, mod, func, name) != 0)
132 return (0);
133
134 (void) dtrace_probe_create(prov->id, probe->mod, probe->func,
135 probe->name, 0, probe);
(kgdb) print prov
$4 = (struct sdt_provider *) 0x859da520
(kgdb) print *prov
$5 = {
name = 0x859d719d "linuxulator",
prov_entry = {
tqe_next = 0x0,
tqe_prev = 0x807bbac4
},
probe_list = {
tqh_first = 0x859daca0,
tqh_last = 0x859e442c
},
id = 0x0
}
(kgdb) print probe
$6 = (struct sdt_probe *) 0x859daca0
(kgdb) print *probe
$7 = {
version = 0x34,
state = SDT_INIT,
prov = 0x859da520,
probe_entry = {
tqe_next = 0x859dac40,
tqe_prev = 0x859da52c
},
argtype_list = {
tqh_first = 0x0,
tqh_last = 0x859dacb4
},
mod = 0x859d7204 "emul",
func = 0x859d72af "linux_schedtail",
name = 0x859d721f "return",
id = 0x0,
n_args = 0x0
}
It looks suspicious to mee that the id is NULL. Here is what I do:
kernel with KDTRACE_HOOKS, makeoptions WITH_CTF=yes, DDB_CTF. The SDT
probes are in linux.ko which is loaded after the dtrace, cyclic, sdt,
profile, fbt, systrace and lockstat modules. My patches are at
http://www.Leidinger.net/FreeBSD/current-patches/linuxulator-dtrace.diff
linux_emul.c contains LIN_SDT_PROVIDER_DEFINE(LINUX_DTRACE); which is
just a mapping of SDT_PROVIDE_DEFINE. All other files contain the
corresponding DECLARE.
Actually the kernel crashed at another place which uses automatically
generated probes via a macro, and I removed those probes to see if I
made a mistake in this macro. Now it crashes for this probe which I
added directly in this place by hand. I do not know if this is the
first of my probes which is causing the crash, or if this is somewhere
after already processing some of my probes. Is there a way to find
this out with kgdb?
Without linux.ko loaded, "dtrace -l | head" works as expected. As I am
forward porting my SDT probes from a -current from 2008, and my probes
worked back then, the probes themself should not be a big problem. I
assume my use of the SDT_PROBE_DEFINE[1-5] macros is OK
(sys/compat/linux/linux_dtrace.h), reviews welcome.
As I read it, it looks a little bit like the SYSINIT of the SDT probes
didn't work as expected for my new probes (does this work in modules?
fxr.watson.org AFAICS only lists SDT probes in kernel-code, not in
module-code), a hit with the clue-bat is welcome.
Any hints how to debug this further are welcome.
Bye,
Alexander.
--
Foolproof Operation:
No provision for adjustment.
http://www.Leidinger.net Alexander @ Leidinger.net: PGP ID = B0063FE7
http://www.FreeBSD.org netchild @ FreeBSD.org : PGP ID = 72077137
More information about the freebsd-hackers
mailing list