Skip to content
New issue

Have a question about this project? Sign up for a free GitHub account to open an issue and contact its maintainers and the community.

Sign up for GitHub

By clicking “Sign up for GitHub”, you agree to our terms of service and privacy statement. We’ll occasionally send you account related emails.

Already on GitHub? Sign in to your account

Jump to bottom

dtrace: processing aborted: Invalid argument #50

Open
ryao opened this issue Feb 6, 2013 · 5 comments
Open

dtrace: processing aborted: Invalid argument #50

ryao opened this issue Feb 6, 2013 · 5 comments

Comments

@ryao
Copy link
Contributor

ryao commented Feb 6, 2013

I am running Linux 3.8-r3. Running a basic dtrace command from Illumos' dtrace documentation fails:

#  ./build-3.8.0-rc3/dtrace -n BEGIN
dtrace: description 'BEGIN' matched 1 probe
CPU     ID                    FUNCTION:NAME
  3      1                           :BEGIN 
dtrace: processing aborted: Invalid argument

http://dtrace.org/guide/chapter.html#chp-intro
@dtrace4linux
Copy link
Owner

if this happen,s, look at /var/log/messages, dmesg and /proc/dtrace/trace
to see what is happening.

tx

On 6 February 2013 23:40, Richard Yao [email protected] wrote:

I am running Linux 3.8-r3. Running a basic dtrace command from Illumos'
dtrace documentation fails:

./build-3.8.0-rc3/dtrace -n BEGIN

dtrace: description 'BEGIN' matched 1 probe
CPU ID FUNCTION:NAME
3 1 :BEGIN
dtrace: processing aborted: Invalid argument

http://dtrace.org/guide/chapter.html#chp-intro

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/50.

@ryao
Copy link
Contributor Author

ryao commented Feb 7, 2013

Here is /proc/dtrace/trace:

#3 8901:�4dtracedrv loaded: /dev/dtrace available, dtrace_here=0 nr_cpus=4
#3 8901:vmem_create(dtrace) ffff88003f9abcc0
#3 8901:vmem_create(dtrace_minor) ffff88003f9abd80
#3 8901:__alloc_workqueue_key_ptr=ffffffff8105ef00
#1 8901:dtrace_linux.c:get_proc_addr: Failed to find 'lockdep_init_map' (warn=1)
#1 8901:queue_delayed_work_ptr=ffffffff8105caa0
#1 8901:destroy_workqueue_ptr=ffffffff8105d640
#1 8901:flush_workqueue_ptr=ffffffff8105cfe0
#1 8901:delayed_work_timer_fn_ptr=ffffffff8105c7c0
#1 8901:ctf loaded: /dev/ctf now available
#1 8879:dtrace_linux.c:get_proc_addr: Failed to find 'sysrq_showregs_othercpus' (warn=2)
#1 8879:dtrace_linux.c:get_proc_addr: Failed to find 'profile_event_register' (warn=3)
#1 8879:dtrace_linux.c:get_proc_addr: Failed to find 'profile_event_unregister' (warn=4)
#1 8879:dtrace_linux.c:get_proc_addr: Failed to find 'xtime_cache' (warn=5)
#1 8879:profile loaded: /dev/dtrace_profile available
#1 8879:dtrace_linux.c:get_proc_addr: Failed to find 'tcp_event_data_sent' (warn=6)
#1 8879:prcom_add_function: cannot locate 'tcp_event_data_sent'
#1 8879:dcpc.c:dcpc_attach:1326: TODO:please fill me in
#1 8879:dcpc initialised.
#1 8879:sdt loaded: /dev/sdt now available
#1 8879:ctl loaded: /dev/dtrace_ctl now available
#1 8879:dtrace_function_size: do_sync_read ffffffff8114ef00 size=224
#1 8879:io_prov_entry called io:start
#1 8879:io_prov_return called io:start ffffffff8114efcb  sz=1
#1 8879:dtrace_function_size: do_sync_write ffffffff8114ee20 size=224
#1 8879:io_prov_entry called io:start
#1 8879:io_prov_return called io:start ffffffff8114eeeb  sz=1
#3 8917:fbt:dup patch: ffffffff813c00f1 error_sti
#3 8917:fbt:dup patch: ffffffff813c6e80 __fentry__
#3 8917:fbt:dup patch: ffffffff813c6f2f ftrace_stub
#3 8917:initting a mutex
#3 8917:instr:dup patch: ffffffffa09496a3 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0922886 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa075077f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa062b234 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa08b4f0f cleanup_module-je
#3 8917:instr:dup patch: ffffffffa078ad73 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa07802ae cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa073f034 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa07e5ce9 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0762430 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa06b669f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0703364 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa067e90c cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0529d31 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0624a67 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa061a0dd cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04d8a8f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0505853 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa05ffd32 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa05a32f1 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa05493f9 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa050deb4 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa051acf0 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04fdd9f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04a402e cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04f0457 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa049d557 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04d3b94 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04c8a10 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04b3708 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04615e0 cleanup_module-je
#3 8917:instr:dup patch: ffffffffa04358a7 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0487f72 cleanup_module-jne
#3 8917:instr:dup patch: ffffffffa0471e90 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa045b2fb cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0442063 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0427d37 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa043aa0b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa04210eb cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa040d6b7 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa041818d cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0406b59 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa03fd72f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa03f377b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa03ed5df cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa03e8104 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa01db4c7 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa02163a1 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0257d6c cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa01f69fb cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa01cfd64 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0197f48 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa028e3f6 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0148c0a cleanup_module-je
#3 8917:instr:dup patch: ffffffffa00dce85 cleanup_module-je
#3 8917:instr:dup patch: ffffffffa00cbec7 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00c617f cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00c156b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00bc32b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00b6127 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00b12ab cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00ac403 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00a7137 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00a21f7 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa00996c3 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa009432b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa001200b cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0081ef3 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa008f607 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0064f07 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa0077b76 cleanup_module-lock
#3 8917:instr:dup patch: ffffffffa004c5fc cleanup_module-jne
#3 8917:instr:dup patch: ffffffffa0029683 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa001cc21 cleanup_module-callr
#3 8917:instr:dup patch: ffffffffa000c982 cleanup_module-je
#3 8917:instr:dup patch: ffffffffa00001a3 cleanup_module-callr
#3 8917:fbt:dup patch: ffffffffa09496dc cleanup_module
#3 8917:fbt:dup patch: ffffffffa0922938 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0750791 cleanup_module
#3 8917:fbt:dup patch: ffffffffa062b23a cleanup_module
#3 8917:fbt:dup patch: ffffffffa08b4f2a cleanup_module
#3 8917:fbt:dup patch: ffffffffa078ad79 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0780327 cleanup_module
#3 8917:fbt:dup patch: ffffffffa073f0af cleanup_module
#3 8917:fbt:dup patch: ffffffffa07e5d30 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0762475 cleanup_module
#3 8917:fbt:dup patch: ffffffffa06b66a5 cleanup_module
#3 8917:fbt:dup patch: ffffffffa05374e9 cleanup_module
#3 8917:fbt:dup patch: ffffffffa070336a cleanup_module
#3 8917:fbt:dup patch: ffffffffa067e921 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0529d5b cleanup_module
#3 8917:fbt:dup patch: ffffffffa0624a6d cleanup_module
#3 8917:fbt:dup patch: ffffffffa061a0e3 cleanup_module
#3 8917:fbt:dup patch: ffffffffa04d8aa3 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0505859 cleanup_module
#3 8917:fbt:dup patch: ffffffffa05ffd5c cleanup_module
#3 8917:fbt:dup patch: ffffffffa05a332a cleanup_module
#3 8917:fbt:dup patch: ffffffffa05493ff cleanup_module
#3 8917:fbt:dup patch: ffffffffa050df3c cleanup_module
#3 8917:fbt:dup patch: ffffffffa051acf6 cleanup_module
#3 8917:fbt:dup patch: ffffffffa04fddbd cleanup_module
#3 8917:fbt:dup patch: ffffffffa04a4072 cleanup_module
#3 8917:fbt:dup patch: ffffffffa04f0475 cleanup_module
#3 8917:fbt:dup patch: ffffffffa049d55d cleanup_module
#3 8917:fbt:dup patch: ffffffffa0452145 cleanup_module
#3 8917:fbt:dup patch: ffffffffa04d3b9a cleanup_module
#3 8917:fbt:dup patch: ffffffffa04c8a5d cleanup_module
#3 8917:fbt:dup patch: ffffffffa04b3820 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0461604 cleanup_module
#3 8917:fbt:dup patch: ffffffffa04358ad cleanup_module
#3 8917:fbt:dup patch: ffffffffa0487fc2 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0471eb4 cleanup_module
#3 8917:fbt:dup patch: ffffffffa045b31b cleanup_module
#3 8917:fbt:dup patch: ffffffffa04420a5 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0427d3d cleanup_module
#3 8917:fbt:dup patch: ffffffffa043aa1d cleanup_module
#3 8917:fbt:dup patch: ffffffffa04210f1 cleanup_module
#3 8917:fbt:dup patch: ffffffffa040d6bd cleanup_module
#3 8917:fbt:dup patch: ffffffffa04181b2 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0406b77 cleanup_module
#3 8917:fbt:dup patch: ffffffffa03fd735 cleanup_module
#3 8917:fbt:dup patch: ffffffffa03f3781 cleanup_module
#3 8917:fbt:dup patch: ffffffffa03ed5e5 cleanup_module
#3 8917:fbt:dup patch: ffffffffa03e810a cleanup_module
#3 8917:fbt:dup patch: ffffffffa01db4cd cleanup_module
#3 8917:fbt:dup patch: ffffffffa02163fb cleanup_module
#3 8917:fbt:dup patch: ffffffffa0257d86 cleanup_module
#3 8917:fbt:dup patch: ffffffffa01f6a4f cleanup_module
#3 8917:fbt:dup patch: ffffffffa01cfd82 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0197f73 cleanup_module
#3 8917:fbt:dup patch: ffffffffa028e419 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0148c86 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00dce9b cleanup_module
#3 8917:fbt:dup patch: ffffffffa00cbecd cleanup_module
#3 8917:fbt:dup patch: ffffffffa00c6185 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00c1571 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00bc331 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00b612d cleanup_module
#3 8917:fbt:dup patch: ffffffffa00b12b1 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00ac409 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00a713d cleanup_module
#3 8917:fbt:dup patch: ffffffffa00a21fd cleanup_module
#3 8917:fbt:dup patch: ffffffffa00996c9 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0094331 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0012011 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0081efe cleanup_module
#3 8917:fbt:dup patch: ffffffffa008f639 cleanup_module
#3 8917:fbt:dup patch: ffffffffa0064f0d cleanup_module
#3 8917:fbt:dup patch: ffffffffa0077b7f cleanup_module
#3 8917:fbt:dup patch: ffffffffa004c64f cleanup_module
#3 8917:fbt:dup patch: ffffffffa002969a cleanup_module
#3 8917:fbt:dup patch: ffffffffa001cc38 cleanup_module
#3 8917:fbt:dup patch: ffffffffa000c9f2 cleanup_module
#3 8917:fbt:dup patch: ffffffffa00001a9 cleanup_module
#3 8917:dtrace_linux.c:get_proc_addr: Failed to find 'sys32_clone' (warn=7)
#3 8917:dtrace_linux.c:get_proc_addr: Failed to find 'sys32_execve' (warn=8)
#3 8917:vmem_create(dtrace_aggid_0) ffff8800c393ba80
#0 8917:teardown start xcalls=19 probes=0
#0 8917:teardown done 0.000000000 xcalls=20 probes=0
#0 8922:vmem_create(dtrace_aggid_0) ffff88013ee93e40
#0 8922:teardown start xcalls=28 probes=1
#0 8922:teardown done 0.000000000 xcalls=33 probes=0

Here is an excerpt from dmesg:

[21500.124199] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124225] caller is dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124228] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124229] Call Trace:
[21500.124237]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124260]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124272]  [<ffffffffa098ac65>] dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124276]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124288]  [<ffffffffa099346d>] printk+0x41/0x45 [dtracedrv]
[21500.124296]  [<ffffffffa07a4293>] dtracedrv_init+0x293/0x1000 [dtracedrv]
[21500.124300]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124304]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124308]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124310]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124314]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124316] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124328] caller is dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.124330] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124331] Call Trace:
[21500.124334]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124338]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124350]  [<ffffffffa098ae3b>] dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.124354]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124368]  [<ffffffffa099346d>] printk+0x41/0x45 [dtracedrv]
[21500.124387]  [<ffffffffa07a4293>] dtracedrv_init+0x293/0x1000 [dtracedrv]
[21500.124390]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124393]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124395]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124399]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124405]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124409] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124421] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124423] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124424] Call Trace:
[21500.124427]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124440]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124443]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124456]  [<ffffffffa098aa18>] mutex_enter+0x38/0x70 [dtracedrv]
[21500.124471]  [<ffffffffa09763fb>] dtrace_attach+0x2b/0x730 [dtracedrv]
[21500.124483]  [<ffffffffa099346d>] ? printk+0x41/0x45 [dtracedrv]
[21500.124492]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124495]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124497]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124500]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124507]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124509]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124512] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124524] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124525] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124526] Call Trace:
[21500.124529]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124542]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124545]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124558]  [<ffffffffa098aa18>] mutex_enter+0x38/0x70 [dtracedrv]
[21500.124569]  [<ffffffffa0976407>] dtrace_attach+0x37/0x730 [dtracedrv]
[21500.124581]  [<ffffffffa099346d>] ? printk+0x41/0x45 [dtracedrv]
[21500.124589]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124592]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124594]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124597]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124600]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124603]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124605] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124617] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124619] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124620] Call Trace:
[21500.124623]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124635]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21500.124639]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124651]  [<ffffffffa098aa18>] mutex_enter+0x38/0x70 [dtracedrv]
[21500.124662]  [<ffffffffa0976413>] dtrace_attach+0x43/0x730 [dtracedrv]
[21500.124674]  [<ffffffffa099346d>] ? printk+0x41/0x45 [dtracedrv]
[21500.124682]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124685]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124688]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124691]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124694]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124696]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124700] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124712] caller is dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124713] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124715] Call Trace:
[21500.124718]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124730]  [<ffffffffa098ac65>] dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124742]  [<ffffffffa098b5a1>] dtrace_printf+0x41/0x50 [dtracedrv]
[21500.124755]  [<ffffffffa097f02a>] vmem_create+0x8a/0xa0 [dtracedrv]
[21500.124758]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124769]  [<ffffffffa097646d>] dtrace_attach+0x9d/0x730 [dtracedrv]
[21500.124779]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124782]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124785]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124788]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124795]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124798]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124800] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124812] caller is dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.124813] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124814] Call Trace:
[21500.124817]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124830]  [<ffffffffa098ae3b>] dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.124842]  [<ffffffffa098b5a1>] dtrace_printf+0x41/0x50 [dtracedrv]
[21500.124854]  [<ffffffffa097f02a>] vmem_create+0x8a/0xa0 [dtracedrv]
[21500.124857]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124868]  [<ffffffffa097646d>] dtrace_attach+0x9d/0x730 [dtracedrv]
[21500.124876]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124884]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124887]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124890]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124893]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124896]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124898] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.124910] caller is dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124912] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.124913] Call Trace:
[21500.124916]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.124929]  [<ffffffffa098ac65>] dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.124941]  [<ffffffffa098b5a1>] dtrace_printf+0x41/0x50 [dtracedrv]
[21500.124952]  [<ffffffffa097f02a>] vmem_create+0x8a/0xa0 [dtracedrv]
[21500.124956]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.124967]  [<ffffffffa09764ae>] dtrace_attach+0xde/0x730 [dtracedrv]
[21500.124975]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.124978]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.124980]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.124983]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.124986]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.124989]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.124991] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.125017] caller is dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.125019] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.125021] Call Trace:
[21500.125024]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.125038]  [<ffffffffa098ae3b>] dtrace_vprintf+0x23b/0x960 [dtracedrv]
[21500.125050]  [<ffffffffa098b5a1>] dtrace_printf+0x41/0x50 [dtracedrv]
[21500.125069]  [<ffffffffa097f02a>] vmem_create+0x8a/0xa0 [dtracedrv]
[21500.125083]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.125095]  [<ffffffffa09764ae>] dtrace_attach+0xde/0x730 [dtracedrv]
[21500.125105]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.125122]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.125147]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.125153]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.125156]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.125159]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21500.125401] BUG: using smp_processor_id() in preemptible [00000000] code: insmod/8901
[21500.125413] caller is dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.125415] Pid: 8901, comm: insmod Tainted: P           O 3.8.0-rc3 #2
[21500.125416] Call Trace:
[21500.125419]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21500.125422]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.125435]  [<ffffffffa098ac65>] dtrace_vprintf+0x65/0x960 [dtracedrv]
[21500.125438]  [<ffffffffa07a4000>] ? 0xffffffffa07a3fff
[21500.125450]  [<ffffffffa099346d>] printk+0x41/0x45 [dtracedrv]
[21500.125454]  [<ffffffff8105ef00>] ? worker_thread+0x3f0/0x3f0
[21500.125466]  [<ffffffffa0990e26>] taskq_create+0x66/0x150 [dtracedrv]
[21500.125481]  [<ffffffffa09764d9>] dtrace_attach+0x109/0x730 [dtracedrv]
[21500.125489]  [<ffffffffa07a429c>] dtracedrv_init+0x29c/0x1000 [dtracedrv]
[21500.125492]  [<ffffffff8100020f>] do_one_initcall+0x3f/0x170
[21500.125495]  [<ffffffff810a14d1>] load_module+0x1671/0x1cd0
[21500.125498]  [<ffffffff8109de30>] ? get_modinfo.isra.37+0xc0/0xc0
[21500.125501]  [<ffffffff810a1c08>] sys_init_module+0xd8/0x110
[21500.125504]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21502.317912] Pid: 8917, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21502.317915] Call Trace:
[21502.317935]  [<ffffffffa098a8c6>] mutex_enter_common+0x36/0x130 [dtracedrv]
[21502.317946]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21502.317956]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21502.317967]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21502.317978]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21502.317987]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21502.317995]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21502.318001]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21502.318024]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21502.318028]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21502.318032]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21502.318035]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21502.318039]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21502.318042]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21502.318045]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21502.318048]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21502.318050]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21502.318053]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21502.318057]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21502.318061]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21502.318088]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21502.318092]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21502.318095]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21502.318097]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21502.318100]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.123924] debug_smp_processor_id: 1351088 callbacks suppressed
[21544.123927] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.123942] caller is CRED+0x1a/0x60 [dtracedrv]
[21544.123944] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.123946] Call Trace:
[21544.123953]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.123962]  [<ffffffffa097d1da>] CRED+0x1a/0x60 [dtracedrv]
[21544.123971]  [<ffffffffa097d236>] dtracedrv_open+0x16/0x30 [dtracedrv]
[21544.123975]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.123979]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.123983]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.123985]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.123988]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.123991]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.123994]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.123997]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124019]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124022]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124026]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124029]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124032]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124036]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124039]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124042]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124045]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124048]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124053] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124064] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124067] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124068] Call Trace:
[21544.124074]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124089]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124103]  [<ffffffffa098aa18>] mutex_enter+0x38/0x70 [dtracedrv]
[21544.124112]  [<ffffffffa0976b5c>] dtrace_open+0x5c/0x140 [dtracedrv]
[21544.124121]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124123]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124126]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124129]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124131]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124134]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124136]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124139]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124141]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124144]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124147]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124149]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124152]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124155]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124157]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124160]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124163]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124165]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124168]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124171] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124181] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124183] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124184] Call Trace:
[21544.124187]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124198]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124209]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124217]  [<ffffffffa096e9c9>] dtrace_probe_provide+0x59/0x140 [dtracedrv]
[21544.124226]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124235]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124237]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124240]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124243]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124245]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124248]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124250]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124253]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124256]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124258]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124261]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124264]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124266]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124269]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124272]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124274]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124277]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124280]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124282]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124319] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124329] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124331] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124332] Call Trace:
[21544.124335]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124346]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124357]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124365]  [<ffffffffa096e9c9>] dtrace_probe_provide+0x59/0x140 [dtracedrv]
[21544.124374]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124383]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124385]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124388]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124391]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124393]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124396]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124398]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124401]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124404]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124406]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124409]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124412]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124414]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124417]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124420]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124422]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124425]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124428]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124430]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124433] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124443] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124445] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124446] Call Trace:
[21544.124449]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124460]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124470]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124480]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.124491]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.124501]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124510]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.124518]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124527]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124530]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124532]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124535]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124537]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124540]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124543]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124545]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124548]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124550]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124553]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124556]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124558]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124561]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124564]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124566]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124569]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124572]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124574]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124597] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124607] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124608] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124609] Call Trace:
[21544.124611]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124621]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124633]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124643]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.124659]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.124669]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124677]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.124685]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124694]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124697]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124700]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124702]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124704]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124705]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124707]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124709]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124713]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124716]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124718]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124719]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124723]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124726]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124728]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124731]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124733]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124735]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124736]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124740] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124749] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124751] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124756] Call Trace:
[21544.124758]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124768]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124780]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124789]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.124800]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.124810]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124819]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.124826]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124839]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124841]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124844]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124845]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124847]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124850]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124853]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.124856]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.124858]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.124861]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.124862]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.124864]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.124865]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.124870]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.124874]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.124876]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.124878]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.124882]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.124883]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.124886] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.124896] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124898] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.124899] Call Trace:
[21544.124902]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.124913]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124924]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.124935]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.124945]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.124956]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.124964]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.124973]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.124981]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.124983]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.124986]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.124988]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.124991]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.124992]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.124994]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.125007]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.125009]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.125010]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.125013]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.125016]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.125024]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.125027]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.125030]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.125032]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.125034]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.125036]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.125037]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.125040] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.125053] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125055] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.125056] Call Trace:
[21544.125059]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.125070]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125081]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.125090]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.125101]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.125111]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125120]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.125128]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.125137]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.125140]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.125142]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.125145]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.125147]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.125150]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.125153]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.125155]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.125158]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.125160]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.125163]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.125166]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.125168]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.125171]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.125173]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.125176]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.125179]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.125182]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.125184]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b
[21544.125188] BUG: using smp_processor_id() in preemptible [00000000] code: dtrace/8922
[21544.125198] caller is mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125200] Pid: 8922, comm: dtrace Tainted: P           O 3.8.0-rc3 #2
[21544.125201] Call Trace:
[21544.125203]  [<ffffffff81215fec>] debug_smp_processor_id+0xdc/0x100
[21544.125214]  [<ffffffffa098a99d>] mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125225]  [<ffffffffa098a9db>] dmutex_enter+0x1b/0x20 [dtracedrv]
[21544.125235]  [<ffffffffa097e54e>] par_alloc+0x2e/0x110 [dtracedrv]
[21544.125245]  [<ffffffffa098897e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[21544.125256]  [<ffffffffa098a99d>] ? mutex_enter_common+0x10d/0x130 [dtracedrv]
[21544.125264]  [<ffffffffa096ea03>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[21544.125273]  [<ffffffffa0976b65>] dtrace_open+0x65/0x140 [dtracedrv]
[21544.125282]  [<ffffffffa097d245>] dtracedrv_open+0x25/0x30 [dtracedrv]
[21544.125284]  [<ffffffff8128b618>] misc_open+0xb8/0x1c0
[21544.125287]  [<ffffffff81153b11>] chrdev_open+0xa1/0x1b0
[21544.125290]  [<ffffffff8106ce3d>] ? lg_local_unlock+0x2d/0x60
[21544.125292]  [<ffffffff81153a70>] ? cdev_put+0x30/0x30
[21544.125295]  [<ffffffff8114d716>] do_dentry_open.isra.16+0x206/0x290
[21544.125297]  [<ffffffff8114d7c2>] finish_open+0x22/0x40
[21544.125300]  [<ffffffff8115ddae>] do_last+0x73e/0xe30
[21544.125302]  [<ffffffff8115a928>] ? inode_permission+0x18/0x50
[21544.125305]  [<ffffffff8115ab8d>] ? link_path_walk+0x22d/0x920
[21544.125308]  [<ffffffff8115e553>] path_openat+0xb3/0x4a0
[21544.125310]  [<ffffffff811283c1>] ? handle_mm_fault+0x241/0x340
[21544.125313]  [<ffffffff8112da65>] ? do_brk+0x295/0x330
[21544.125315]  [<ffffffff8115ed52>] do_filp_open+0x42/0xa0
[21544.125318]  [<ffffffff813bf558>] ? _raw_spin_unlock+0x18/0x40
[21544.125321]  [<ffffffff8116c3f7>] ? __alloc_fd+0xd7/0x120
[21544.125323]  [<ffffffff8114eb6e>] do_sys_open+0xfe/0x1e0
[21544.125326]  [<ffffffff8114ec71>] sys_open+0x21/0x30
[21544.125328]  [<ffffffff813c72d9>] system_call_fastpath+0x16/0x1b

It looks like there are some preemption bugs in the dtrace kernel module. My kernel is built with CONFIG_PREEMPT=y.

@ryao
Copy link
Contributor Author

ryao commented Feb 7, 2013

I rebuilt with CONFIG_PREEMPT_VOLUNTARY=y. The same issue occurs, but now dmesg is noticeably shorter:

[  251.893768] Pid: 7833, comm: dtrace Tainted: P           O 3.8.0-rc3 #3
[  251.893771] Call Trace:
[  251.893791]  [<ffffffffa098c416>] mutex_enter_common+0x36/0x130 [dtracedrv]
[  251.893794]  [<ffffffff813c95e6>] ? bad_from_user+0x6/0x6
[  251.893796]  [<ffffffff813c9c19>] ? bad_to_user+0x633/0x633
[  251.893807]  [<ffffffffa098c52b>] dmutex_enter+0x1b/0x20 [dtracedrv]
[  251.893817]  [<ffffffffa09801fe>] par_alloc+0x2e/0x110 [dtracedrv]
[  251.893827]  [<ffffffffa098a57e>] instr_provide_module+0x3e/0x250 [dtracedrv]
[  251.893838]  [<ffffffffa098c447>] ? mutex_enter_common+0x67/0x130 [dtracedrv]
[  251.893846]  [<ffffffffa0970703>] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[  251.893855]  [<ffffffffa0978875>] dtrace_open+0x65/0x140 [dtracedrv]
[  251.893864]  [<ffffffffa097e295>] dtracedrv_open+0x55/0x60 [dtracedrv]
[  251.893867]  [<ffffffff812893e8>] misc_open+0xb8/0x1c0
[  251.893870]  [<ffffffff81151741>] chrdev_open+0xa1/0x1b0
[  251.893873]  [<ffffffff811516a0>] ? cdev_put+0x30/0x30
[  251.893876]  [<ffffffff8114b316>] do_dentry_open.isra.16+0x206/0x290
[  251.893878]  [<ffffffff8114b3c2>] finish_open+0x22/0x40
[  251.893881]  [<ffffffff8115b9de>] do_last+0x73e/0xe30
[  251.893884]  [<ffffffff81158538>] ? inode_permission+0x18/0x50
[  251.893886]  [<ffffffff8115879d>] ? link_path_walk+0x22d/0x910
[  251.893889]  [<ffffffff81124e30>] ? handle_pte_fault+0x90/0x7a0
[  251.893891]  [<ffffffff8115c183>] path_openat+0xb3/0x4a0
[  251.893894]  [<ffffffff81126721>] ? handle_mm_fault+0x241/0x340
[  251.893896]  [<ffffffff8112bd35>] ? do_brk+0x295/0x330
[  251.893899]  [<ffffffff8115c982>] do_filp_open+0x42/0xa0
[  251.893901]  [<ffffffff813bd4ee>] ? _raw_spin_unlock+0xe/0x20
[  251.893905]  [<ffffffff8116a037>] ? __alloc_fd+0xd7/0x120
[  251.893907]  [<ffffffff8114c76e>] do_sys_open+0xfe/0x1e0
[  251.893909]  [<ffffffff8114c871>] sys_open+0x21/0x30
[  251.893912]  [<ffffffff813c6019>] system_call_fastpath+0x16/0x1b

@dtrace4linux
Copy link
Owner

This error appears because CONFIG_DEBUG_PREEMPT is set in your kernel.
Technically, it is an error - using the cpu id without interrupts disabled
could result in the wrong cpu being returned. I'll have to review where
this is used - one place is in the dtrace debugging, where it really doesnt
matter.

#ifdef CONFIG_DEBUG_PREEMPT
extern unsigned int debug_smp_processor_id(void);

define smp_processor_id() debug_smp_processor_id()

#else

define smp_processor_id() raw_smp_processor_id()

#endif

Thanks for the feedback

On 7 February 2013 06:28, Richard Yao [email protected] wrote:

I rebuilt with CONFIG_PREEMPT_VOLUNTARY=y. The same issue occurs, but now
dmesg is noticeably shorter:

[ 251.893768] Pid: 7833, comm: dtrace Tainted: P O 3.8.0-rc3 #3
[ 251.893771] Call Trace:
[ 251.893791] [] mutex_enter_common+0x36/0x130 [dtracedrv]
[ 251.893794] [] ? bad_from_user+0x6/0x6
[ 251.893796] [] ? bad_to_user+0x633/0x633
[ 251.893807] [] dmutex_enter+0x1b/0x20 [dtracedrv]
[ 251.893817] [] par_alloc+0x2e/0x110 [dtracedrv]
[ 251.893827] [] instr_provide_module+0x3e/0x250 [dtracedrv]
[ 251.893838] [] ? mutex_enter_common+0x67/0x130 [dtracedrv]
[ 251.893846] [] dtrace_probe_provide+0x93/0x140 [dtracedrv]
[ 251.893855] [] dtrace_open+0x65/0x140 [dtracedrv]
[ 251.893864] [] dtracedrv_open+0x55/0x60 [dtracedrv]
[ 251.893867] [] misc_open+0xb8/0x1c0
[ 251.893870] [] chrdev_open+0xa1/0x1b0
[ 251.893873] [] ? cdev_put+0x30/0x30
[ 251.893876] [] do_dentry_open.isra.16+0x206/0x290
[ 251.893878] [] finish_open+0x22/0x40
[ 251.893881] [] do_last+0x73e/0xe30
[ 251.893884] [] ? inode_permission+0x18/0x50
[ 251.893886] [] ? link_path_walk+0x22d/0x910
[ 251.893889] [] ? handle_pte_fault+0x90/0x7a0
[ 251.893891] [] path_openat+0xb3/0x4a0
[ 251.893894] [] ? handle_mm_fault+0x241/0x340
[ 251.893896] [] ? do_brk+0x295/0x330
[ 251.893899] [] do_filp_open+0x42/0xa0
[ 251.893901] [] ? _raw_spin_unlock+0xe/0x20
[ 251.893905] [] ? __alloc_fd+0xd7/0x120
[ 251.893907] [] do_sys_open+0xfe/0x1e0
[ 251.893909] [] sys_open+0x21/0x30
[ 251.893912] [] system_call_fastpath+0x16/0x1b

—
Reply to this email directly or view it on GitHubhttps://github.com//issues/50#issuecomment-13223569.

@dutow dutow mentioned this issue Oct 9, 2012
Open
@ryao
Copy link
Contributor Author

ryao commented Mar 10, 2014

#76 should dramatically improve things for preemptive kernels.

Sign up for free to join this conversation on GitHub. Already have an account? Sign in to comment
Assignees
No one assigned
Labels
None yet
Projects
None yet
Milestone
No milestone
Development

No branches or pull requests
2 participants
@ryao @dtrace4linux