2 * Copyright (c) 2005 The DragonFly Project. All rights reserved.
4 * This code is derived from software contributed to The DragonFly Project
5 * by Matthew Dillon <dillon@backplane.com>
7 * Redistribution and use in source and binary forms, with or without
8 * modification, are permitted provided that the following conditions
11 * 1. Redistributions of source code must retain the above copyright
12 * notice, this list of conditions and the following disclaimer.
13 * 2. Redistributions in binary form must reproduce the above copyright
14 * notice, this list of conditions and the following disclaimer in
15 * the documentation and/or other materials provided with the
17 * 3. Neither the name of The DragonFly Project nor the names of its
18 * contributors may be used to endorse or promote products derived
19 * from this software without specific, prior written permission.
21 * THIS SOFTWARE IS PROVIDED BY THE COPYRIGHT HOLDERS AND CONTRIBUTORS
22 * ``AS IS'' AND ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT
23 * LIMITED TO, THE IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS
24 * FOR A PARTICULAR PURPOSE ARE DISCLAIMED. IN NO EVENT SHALL THE
25 * COPYRIGHT HOLDERS OR CONTRIBUTORS BE LIABLE FOR ANY DIRECT, INDIRECT,
26 * INCIDENTAL, SPECIAL, EXEMPLARY OR CONSEQUENTIAL DAMAGES (INCLUDING,
27 * BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS OR SERVICES;
28 * LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) HOWEVER CAUSED
29 * AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT LIABILITY,
30 * OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY OUT
31 * OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
35 * The following copyright applies to the DDB command code:
37 * Copyright (c) 2000 John Baldwin <jhb@FreeBSD.org>
38 * All rights reserved.
40 * Redistribution and use in source and binary forms, with or without
41 * modification, are permitted provided that the following conditions
43 * 1. Redistributions of source code must retain the above copyright
44 * notice, this list of conditions and the following disclaimer.
45 * 2. Redistributions in binary form must reproduce the above copyright
46 * notice, this list of conditions and the following disclaimer in the
47 * documentation and/or other materials provided with the distribution.
48 * 3. Neither the name of the author nor the names of any co-contributors
49 * may be used to endorse or promote products derived from this software
50 * without specific prior written permission.
52 * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND
53 * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE
54 * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE
55 * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE
56 * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL
57 * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS
58 * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION)
59 * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT
60 * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY
61 * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF
66 * Kernel tracepoint facility.
72 #include <sys/param.h>
74 #include <sys/kernel.h>
75 #include <sys/libkern.h>
77 #include <sys/sysctl.h>
79 #include <sys/systm.h>
81 #include <sys/malloc.h>
82 #include <sys/spinlock.h>
83 #include <sys/thread2.h>
84 #include <sys/spinlock2.h>
85 #include <sys/ctype.h>
87 #include <machine/cpu.h>
88 #include <machine/cpufunc.h>
89 #include <machine/specialreg.h>
90 #include <machine/md_var.h>
95 #define KTR_ENTRIES 2048
96 #elif (KTR_ENTRIES & KTR_ENTRIES - 1)
97 #error KTR_ENTRIES must be a power of two
99 #define KTR_ENTRIES_MASK (KTR_ENTRIES - 1)
102 * test logging support. When ktr_testlogcnt is non-zero each synchronization
103 * interrupt will issue six back-to-back ktr logging messages on cpu 0
104 * so the user can determine KTR logging overheads.
106 #if !defined(KTR_TESTLOG)
107 #define KTR_TESTLOG KTR_ALL
109 KTR_INFO_MASTER(testlog
);
111 KTR_INFO(KTR_TESTLOG
, testlog
, test1
, 0, "test1 %d %d %d %d", int dummy1
, int dummy2
, int dummy3
, int dummy4
);
112 KTR_INFO(KTR_TESTLOG
, testlog
, test2
, 1, "test2 %d %d %d %d", int dummy1
, int dummy2
, int dummy3
, int dummy4
);
113 KTR_INFO(KTR_TESTLOG
, testlog
, test3
, 2, "test3 %d %d %d %d", int dummy1
, int dummy2
, int dummy3
, int dummy4
);
114 KTR_INFO(KTR_TESTLOG
, testlog
, test4
, 3, "test4");
115 KTR_INFO(KTR_TESTLOG
, testlog
, test5
, 4, "test5");
116 KTR_INFO(KTR_TESTLOG
, testlog
, test6
, 5, "test6");
117 KTR_INFO(KTR_TESTLOG
, testlog
, pingpong
, 6, "pingpong");
118 KTR_INFO(KTR_TESTLOG
, testlog
, pipeline
, 7, "pipeline");
119 KTR_INFO(KTR_TESTLOG
, testlog
, crit_beg
, 8, "crit_beg");
120 KTR_INFO(KTR_TESTLOG
, testlog
, crit_end
, 9, "crit_end");
121 KTR_INFO(KTR_TESTLOG
, testlog
, spin_beg
, 10, "spin_beg");
122 KTR_INFO(KTR_TESTLOG
, testlog
, spin_end
, 11, "spin_end");
123 #define logtest(name) KTR_LOG(testlog_ ## name, 0, 0, 0, 0)
124 #define logtest_noargs(name) KTR_LOG(testlog_ ## name)
127 MALLOC_DEFINE(M_KTR
, "ktr", "ktr buffers");
129 SYSCTL_NODE(_debug
, OID_AUTO
, ktr
, CTLFLAG_RW
, 0, "ktr");
131 int ktr_entries
= KTR_ENTRIES
;
132 SYSCTL_INT(_debug_ktr
, OID_AUTO
, entries
, CTLFLAG_RD
, &ktr_entries
, 0,
133 "Size of the event buffer");
135 int ktr_version
= KTR_VERSION
;
136 SYSCTL_INT(_debug_ktr
, OID_AUTO
, version
, CTLFLAG_RD
, &ktr_version
, 0, "");
138 static int ktr_stacktrace
= 1;
139 SYSCTL_INT(_debug_ktr
, OID_AUTO
, stacktrace
, CTLFLAG_RD
, &ktr_stacktrace
, 0, "");
141 static int ktr_resynchronize
= 0;
142 SYSCTL_INT(_debug_ktr
, OID_AUTO
, resynchronize
, CTLFLAG_RW
,
143 &ktr_resynchronize
, 0, "Resynchronize TSC 10 times a second");
146 static int ktr_testlogcnt
= 0;
147 SYSCTL_INT(_debug_ktr
, OID_AUTO
, testlogcnt
, CTLFLAG_RW
, &ktr_testlogcnt
, 0, "");
148 static int ktr_testipicnt
= 0;
149 static int ktr_testipicnt_remainder
;
150 SYSCTL_INT(_debug_ktr
, OID_AUTO
, testipicnt
, CTLFLAG_RW
, &ktr_testipicnt
, 0, "");
151 static int ktr_testcritcnt
= 0;
152 SYSCTL_INT(_debug_ktr
, OID_AUTO
, testcritcnt
, CTLFLAG_RW
, &ktr_testcritcnt
, 0, "");
153 static int ktr_testspincnt
= 0;
154 SYSCTL_INT(_debug_ktr
, OID_AUTO
, testspincnt
, CTLFLAG_RW
, &ktr_testspincnt
, 0, "");
158 * Give cpu0 a static buffer so the tracepoint facility can be used during
159 * early boot (note however that we still use a critical section, XXX).
161 static struct ktr_entry ktr_buf0
[KTR_ENTRIES
];
163 struct ktr_cpu ktr_cpu
[MAXCPU
] = {
164 { .core
.ktr_buf
= &ktr_buf0
[0] }
167 static int64_t ktr_sync_tsc
;
168 struct callout ktr_resync_callout
;
171 int ktr_verbose
= KTR_VERBOSE
;
172 TUNABLE_INT("debug.ktr.verbose", &ktr_verbose
);
173 SYSCTL_INT(_debug_ktr
, OID_AUTO
, verbose
, CTLFLAG_RW
, &ktr_verbose
, 0,
174 "Log events to the console as well");
177 static void ktr_resync_callback(void *dummy __unused
);
179 extern int64_t tsc_offsets
[];
182 ktr_sysinit(void *dummy
)
184 struct ktr_cpu_core
*kcpu
;
187 for(i
= 1; i
< ncpus
; ++i
) {
188 kcpu
= &ktr_cpu
[i
].core
;
189 kcpu
->ktr_buf
= kmalloc(KTR_ENTRIES
* sizeof(struct ktr_entry
),
190 M_KTR
, M_WAITOK
| M_ZERO
);
192 callout_init_mp(&ktr_resync_callout
);
193 callout_reset(&ktr_resync_callout
, hz
/ 10, ktr_resync_callback
, NULL
);
195 SYSINIT(ktr_sysinit
, SI_BOOT2_KLD
, SI_ORDER_ANY
, ktr_sysinit
, NULL
);
198 * Try to resynchronize the TSC's for all cpus. This is really, really nasty.
199 * We have to send an IPIQ message to all remote cpus, wait until they
200 * get into their IPIQ processing code loop, then do an even stricter hard
201 * loop to get the cpus as close to synchronized as we can to get the most
204 * This callback occurs on cpu0.
207 static void ktr_pingpong_remote(void *dummy
);
208 static void ktr_pipeline_remote(void *dummy
);
211 #ifdef _RDTSC_SUPPORTED_
213 static void ktr_resync_remote(void *dummy
);
216 * We use a callout callback instead of a systimer because we cannot afford
217 * to preempt anyone to do this, or we might deadlock a spin-lock or
218 * serializer between two cpus.
222 ktr_resync_callback(void *dummy __unused
)
224 struct lwkt_cpusync cs
;
229 KKASSERT(mycpu
->gd_cpuid
== 0);
235 if (ktr_testlogcnt
) {
241 logtest_noargs(test4
);
242 logtest_noargs(test5
);
243 logtest_noargs(test6
);
250 if (ktr_testipicnt
&& ktr_testipicnt_remainder
== 0 && ncpus
> 1) {
251 ktr_testipicnt_remainder
= ktr_testipicnt
;
253 lwkt_send_ipiq_bycpu(1, ktr_pingpong_remote
, NULL
);
257 * Test critical sections
259 if (ktr_testcritcnt
) {
262 logtest_noargs(crit_beg
);
263 for (count
= ktr_testcritcnt
; count
; --count
) {
267 logtest_noargs(crit_end
);
272 * Test spinlock sections
274 if (ktr_testspincnt
) {
275 struct spinlock spin
;
280 logtest_noargs(spin_beg
);
281 for (count
= ktr_testspincnt
; count
; --count
) {
285 logtest_noargs(spin_end
);
291 * Resynchronize the TSC
293 if (ktr_resynchronize
== 0)
295 if ((cpu_feature
& CPUID_TSC
) == 0)
299 lwkt_cpusync_init(&cs
, smp_active_mask
, ktr_resync_remote
,
300 (void *)(intptr_t)mycpu
->gd_cpuid
);
301 lwkt_cpusync_interlock(&cs
);
302 ktr_sync_tsc
= rdtsc();
303 lwkt_cpusync_deinterlock(&cs
);
306 callout_reset(&ktr_resync_callout
, hz
/ 10, ktr_resync_callback
, NULL
);
310 * The remote-end of the KTR synchronization protocol runs on all cpus.
311 * The one we run on the controlling cpu updates its tsc continuously
312 * until the others have finished syncing (theoretically), but we don't
315 * This is a bit ad-hoc but we need to avoid livelocking inside an IPI
316 * callback. rdtsc() is a synchronizing instruction (I think).
319 ktr_resync_remote(void *arg
)
321 globaldata_t gd
= mycpu
;
325 if (gd
->gd_cpuid
== (int)(intptr_t)arg
) {
326 for (i
= 0; i
< 2000; ++i
)
327 ktr_sync_tsc
= rdtsc();
329 delta
= rdtsc() - ktr_sync_tsc
;
330 if (tsc_offsets
[gd
->gd_cpuid
] == 0)
331 tsc_offsets
[gd
->gd_cpuid
] = delta
;
332 tsc_offsets
[gd
->gd_cpuid
] =
333 (tsc_offsets
[gd
->gd_cpuid
] * 7 + delta
) / 8;
341 ktr_pingpong_remote(void *dummy __unused
)
345 logtest_noargs(pingpong
);
346 other_cpu
= 1 - mycpu
->gd_cpuid
;
347 if (ktr_testipicnt_remainder
) {
348 --ktr_testipicnt_remainder
;
349 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pingpong_remote
, NULL
);
351 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pipeline_remote
, NULL
);
352 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pipeline_remote
, NULL
);
353 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pipeline_remote
, NULL
);
354 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pipeline_remote
, NULL
);
355 lwkt_send_ipiq_bycpu(other_cpu
, ktr_pipeline_remote
, NULL
);
361 ktr_pipeline_remote(void *dummy __unused
)
363 logtest_noargs(pipeline
);
368 #else /* !_RDTSC_SUPPORTED_ */
371 * The resync callback for UP doesn't do anything other then run the test
372 * log messages. If test logging is not enabled, don't bother resetting
377 ktr_resync_callback(void *dummy __unused
)
383 if (ktr_testlogcnt
) {
389 logtest_noargs(test4
);
390 logtest_noargs(test5
);
391 logtest_noargs(test6
);
394 callout_reset(&ktr_resync_callout
, hz
/ 10, ktr_resync_callback
, NULL
);
401 * Setup the next empty slot and return it to the caller to store the data
405 ktr_begin_write_entry(struct ktr_info
*info
, const char *file
, int line
)
407 struct ktr_cpu_core
*kcpu
;
408 struct ktr_entry
*entry
;
411 cpu
= mycpu
->gd_cpuid
;
412 kcpu
= &ktr_cpu
[cpu
].core
;
413 if (panicstr
) /* stop logging during panic */
415 if (kcpu
->ktr_buf
== NULL
) /* too early in boot */
419 entry
= kcpu
->ktr_buf
+ (kcpu
->ktr_idx
& KTR_ENTRIES_MASK
);
421 #ifdef _RDTSC_SUPPORTED_
422 if (cpu_feature
& CPUID_TSC
) {
423 entry
->ktr_timestamp
= rdtsc() - tsc_offsets
[cpu
];
427 entry
->ktr_timestamp
= get_approximate_time_t();
429 entry
->ktr_info
= info
;
430 entry
->ktr_file
= file
;
431 entry
->ktr_line
= line
;
437 ktr_finish_write_entry(struct ktr_info
*info
, struct ktr_entry
*entry
)
440 cpu_ktr_caller(entry
);
442 if (ktr_verbose
&& info
->kf_format
) {
443 kprintf("cpu%d ", mycpu
->gd_cpuid
);
444 if (ktr_verbose
> 1) {
445 kprintf("%s.%d\t", entry
->ktr_file
, entry
->ktr_line
);
455 #define NUM_LINES_PER_PAGE 19
462 static int db_ktr_verbose
;
463 static int db_mach_vtrace(int cpu
, struct ktr_entry
*kp
, int idx
);
465 DB_SHOW_COMMAND(ktr
, db_ktr_all
)
467 struct ktr_cpu_core
*kcpu
;
472 struct tstate tstate
[MAXCPU
];
475 for(i
= 0; i
< ncpus
; i
++) {
476 kcpu
= &ktr_cpu
[i
].core
;
477 tstate
[i
].first
= -1;
478 tstate
[i
].cur
= (kcpu
->ktr_idx
- 1) & KTR_ENTRIES_MASK
;
481 while ((c
= *(modif
++)) != '\0') {
490 while ((c
= *(modif
++)) != '\0') {
503 if (printcpu
> ncpus
- 1) {
504 db_printf("Invalid cpu number\n");
508 * Lopp throug all the buffers and print the content of them, sorted
513 u_int64_t highest_ts
;
515 struct ktr_entry
*kp
;
517 if (a_flag
== 1 && cncheckc() != -1)
522 * Find the lowest timestamp
524 for (i
= 0, counter
= 0; i
< ncpus
; i
++) {
525 kcpu
= &ktr_cpu
[i
].core
;
526 if (kcpu
->ktr_buf
== NULL
)
528 if (printcpu
!= -1 && printcpu
!= i
)
530 if (tstate
[i
].cur
== -1) {
532 if (counter
== ncpus
) {
533 db_printf("--- End of trace buffer ---\n");
538 if (kcpu
->ktr_buf
[tstate
[i
].cur
].ktr_timestamp
> highest_ts
) {
539 highest_ts
= kcpu
->ktr_buf
[tstate
[i
].cur
].ktr_timestamp
;
543 if (highest_cpu
< 0) {
544 db_printf("no KTR data available\n");
548 kcpu
= &ktr_cpu
[i
].core
;
549 kp
= &kcpu
->ktr_buf
[tstate
[i
].cur
];
550 if (tstate
[i
].first
== -1)
551 tstate
[i
].first
= tstate
[i
].cur
;
552 if (--tstate
[i
].cur
< 0)
553 tstate
[i
].cur
= KTR_ENTRIES
- 1;
554 if (tstate
[i
].first
== tstate
[i
].cur
) {
555 db_mach_vtrace(i
, kp
, tstate
[i
].cur
+ 1);
559 if (kcpu
->ktr_buf
[tstate
[i
].cur
].ktr_info
== NULL
)
561 if (db_more(&nl
) == -1)
563 if (db_mach_vtrace(i
, kp
, tstate
[i
].cur
+ 1) == 0)
569 db_mach_vtrace(int cpu
, struct ktr_entry
*kp
, int idx
)
571 if (kp
->ktr_info
== NULL
)
573 db_printf("cpu%d ", cpu
);
574 db_printf("%d: ", idx
);
575 if (db_ktr_verbose
) {
576 db_printf("%10.10lld %s.%d\t", (long long)kp
->ktr_timestamp
,
577 kp
->ktr_file
, kp
->ktr_line
);
579 db_printf("%s\t", kp
->ktr_info
->kf_name
);
580 db_printf("from(%p,%p) ", kp
->ktr_caller1
, kp
->ktr_caller2
);
582 if (kp
->ktr_info
->kf_format
)
583 db_vprintf(kp
->ktr_info
->kf_format
, (__va_list
)kp
->ktr_data
);