dtrace: processing aborted: Invalid argument

[ryao]

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]

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 notifications@github.com 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]

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]

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]

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 notifications@github.com 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.

[ryao]

#76 should dramatically improve things for preemptive kernels.