xref: /dragonfly/sys/kern/kern_ktr.c (revision 267c04fd)
1 /*
2  * Copyright (c) 2005 The DragonFly Project.  All rights reserved.
3  *
4  * This code is derived from software contributed to The DragonFly Project
5  * by Matthew Dillon <dillon@backplane.com>
6  *
7  * Redistribution and use in source and binary forms, with or without
8  * modification, are permitted provided that the following conditions
9  * are met:
10  *
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
16  *    distribution.
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.
20  *
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
32  * SUCH DAMAGE.
33  */
34 /*
35  * The following copyright applies to the DDB command code:
36  *
37  * Copyright (c) 2000 John Baldwin <jhb@FreeBSD.org>
38  * All rights reserved.
39  *
40  * Redistribution and use in source and binary forms, with or without
41  * modification, are permitted provided that the following conditions
42  * are met:
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.
51  *
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
62  * SUCH DAMAGE.
63  */
64 
65 /*
66  * Kernel tracepoint facility.
67  */
68 
69 #include "opt_ddb.h"
70 #include "opt_ktr.h"
71 
72 #include <sys/param.h>
73 #include <sys/cons.h>
74 #include <sys/kernel.h>
75 #include <sys/libkern.h>
76 #include <sys/proc.h>
77 #include <sys/sysctl.h>
78 #include <sys/ktr.h>
79 #include <sys/systm.h>
80 #include <sys/time.h>
81 #include <sys/malloc.h>
82 #include <sys/spinlock.h>
83 #include <sys/kbio.h>
84 #include <sys/ctype.h>
85 
86 #include <sys/thread2.h>
87 #include <sys/spinlock2.h>
88 
89 #include <machine/cpu.h>
90 #include <machine/cpufunc.h>
91 #include <machine/specialreg.h>
92 #include <machine/md_var.h>
93 
94 #include <ddb/ddb.h>
95 
96 #ifndef KTR_ENTRIES
97 #define	KTR_ENTRIES		2048
98 #elif (KTR_ENTRIES & KTR_ENTRIES - 1)
99 #error KTR_ENTRIES must be a power of two
100 #endif
101 #define KTR_ENTRIES_MASK	(KTR_ENTRIES - 1)
102 
103 /*
104  * Used by earlier boot; default value consumes ~64K BSS.
105  *
106  * NOTE:
107  * We use a small value here; this prevents kernel or module loading
108  * failure due to excessive BSS usage if KTR_ENTRIES is large.
109  */
110 #if (KTR_ENTRIES < 256)
111 #define KTR_ENTRIES_BOOT0	KTR_ENTRIES
112 #else
113 #define KTR_ENTRIES_BOOT0	256
114 #endif
115 #define KTR_ENTRIES_BOOT0_MASK	(KTR_ENTRIES_BOOT0 - 1)
116 
117 /*
118  * test logging support.  When ktr_testlogcnt is non-zero each synchronization
119  * interrupt will issue six back-to-back ktr logging messages on cpu 0
120  * so the user can determine KTR logging overheads.
121  */
122 #if !defined(KTR_TESTLOG)
123 #define KTR_TESTLOG	KTR_ALL
124 #endif
125 KTR_INFO_MASTER(testlog);
126 #if KTR_TESTLOG
127 KTR_INFO(KTR_TESTLOG, testlog, test1, 0, "test1 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4);
128 KTR_INFO(KTR_TESTLOG, testlog, test2, 1, "test2 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4);
129 KTR_INFO(KTR_TESTLOG, testlog, test3, 2, "test3 %d %d %d %d", int dummy1, int dummy2, int dummy3, int dummy4);
130 KTR_INFO(KTR_TESTLOG, testlog, test4, 3, "test4");
131 KTR_INFO(KTR_TESTLOG, testlog, test5, 4, "test5");
132 KTR_INFO(KTR_TESTLOG, testlog, test6, 5, "test6");
133 KTR_INFO(KTR_TESTLOG, testlog, pingpong, 6, "pingpong");
134 KTR_INFO(KTR_TESTLOG, testlog, pipeline, 7, "pipeline");
135 KTR_INFO(KTR_TESTLOG, testlog, crit_beg, 8, "crit_beg");
136 KTR_INFO(KTR_TESTLOG, testlog, crit_end, 9, "crit_end");
137 KTR_INFO(KTR_TESTLOG, testlog, spin_beg, 10, "spin_beg");
138 KTR_INFO(KTR_TESTLOG, testlog, spin_end, 11, "spin_end");
139 #define logtest(name)	KTR_LOG(testlog_ ## name, 0, 0, 0, 0)
140 #define logtest_noargs(name)	KTR_LOG(testlog_ ## name)
141 #endif
142 
143 MALLOC_DEFINE(M_KTR, "ktr", "ktr buffers");
144 
145 SYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RW, 0, "ktr");
146 
147 static int	ktr_entries = KTR_ENTRIES_BOOT0;
148 SYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0,
149     "Size of the event buffer");
150 static int	ktr_entries_mask = KTR_ENTRIES_BOOT0_MASK;
151 
152 static int	ktr_version = KTR_VERSION;
153 SYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, "");
154 
155 static int	ktr_stacktrace = 1;
156 SYSCTL_INT(_debug_ktr, OID_AUTO, stacktrace, CTLFLAG_RD, &ktr_stacktrace, 0, "");
157 
158 static int	ktr_resynchronize = 0;
159 SYSCTL_INT(_debug_ktr, OID_AUTO, resynchronize, CTLFLAG_RW,
160     &ktr_resynchronize, 0, "Resynchronize TSC 10 times a second");
161 
162 #if KTR_TESTLOG
163 static int	ktr_testlogcnt = 0;
164 SYSCTL_INT(_debug_ktr, OID_AUTO, testlogcnt, CTLFLAG_RW, &ktr_testlogcnt, 0, "");
165 static int	ktr_testipicnt = 0;
166 static int	ktr_testipicnt_remainder;
167 SYSCTL_INT(_debug_ktr, OID_AUTO, testipicnt, CTLFLAG_RW, &ktr_testipicnt, 0, "");
168 static int	ktr_testcritcnt = 0;
169 SYSCTL_INT(_debug_ktr, OID_AUTO, testcritcnt, CTLFLAG_RW, &ktr_testcritcnt, 0, "");
170 static int	ktr_testspincnt = 0;
171 SYSCTL_INT(_debug_ktr, OID_AUTO, testspincnt, CTLFLAG_RW, &ktr_testspincnt, 0, "");
172 #endif
173 
174 /*
175  * Give cpu0 a static buffer so the tracepoint facility can be used during
176  * early boot (note however that we still use a critical section, XXX).
177  */
178 static struct	ktr_entry ktr_buf0[KTR_ENTRIES_BOOT0];
179 
180 struct ktr_cpu ktr_cpu[MAXCPU] = {
181 	{ .core.ktr_buf = &ktr_buf0[0] }
182 };
183 
184 static int64_t	ktr_sync_tsc;
185 struct callout	ktr_resync_callout;
186 
187 #ifdef KTR_VERBOSE
188 int	ktr_verbose = KTR_VERBOSE;
189 TUNABLE_INT("debug.ktr.verbose", &ktr_verbose);
190 SYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0,
191     "Log events to the console as well");
192 #endif
193 
194 static void ktr_resync_callback(void *dummy __unused);
195 
196 extern int64_t tsc_offsets[];
197 
198 static void
199 ktr_sysinit(void *dummy)
200 {
201 	struct ktr_cpu_core *kcpu;
202 	int i;
203 
204 	for (i = 0; i < ncpus; ++i) {
205 		kcpu = &ktr_cpu[i].core;
206 		kcpu->ktr_buf = kmalloc(KTR_ENTRIES * sizeof(struct ktr_entry),
207 					M_KTR, M_WAITOK | M_ZERO);
208 		if (i == 0) {
209 			/* Migrate ktrs on CPU0 to the new location */
210 			memcpy(kcpu->ktr_buf, ktr_buf0, sizeof(ktr_buf0));
211 		}
212 	}
213 	cpu_sfence();
214 	ktr_entries = KTR_ENTRIES;
215 	ktr_entries_mask = KTR_ENTRIES_MASK;
216 
217 	callout_init_mp(&ktr_resync_callout);
218 	callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL);
219 }
220 SYSINIT(ktr_sysinit, SI_BOOT2_KLD, SI_ORDER_ANY, ktr_sysinit, NULL);
221 
222 /*
223  * Try to resynchronize the TSC's for all cpus.  This is really, really nasty.
224  * We have to send an IPIQ message to all remote cpus, wait until they
225  * get into their IPIQ processing code loop, then do an even stricter hard
226  * loop to get the cpus as close to synchronized as we can to get the most
227  * accurate reading.
228  *
229  * This callback occurs on cpu0.
230  */
231 #if KTR_TESTLOG
232 static void ktr_pingpong_remote(void *dummy);
233 static void ktr_pipeline_remote(void *dummy);
234 #endif
235 
236 #ifdef _RDTSC_SUPPORTED_
237 
238 static void ktr_resync_remote(void *dummy);
239 
240 /*
241  * We use a callout callback instead of a systimer because we cannot afford
242  * to preempt anyone to do this, or we might deadlock a spin-lock or
243  * serializer between two cpus.
244  */
245 static
246 void
247 ktr_resync_callback(void *dummy __unused)
248 {
249 	struct lwkt_cpusync cs;
250 #if KTR_TESTLOG
251 	int count;
252 #endif
253 
254 	KKASSERT(mycpu->gd_cpuid == 0);
255 
256 #if KTR_TESTLOG
257 	/*
258 	 * Test logging
259 	 */
260 	if (ktr_testlogcnt) {
261 		--ktr_testlogcnt;
262 		cpu_disable_intr();
263 		logtest(test1);
264 		logtest(test2);
265 		logtest(test3);
266 		logtest_noargs(test4);
267 		logtest_noargs(test5);
268 		logtest_noargs(test6);
269 		cpu_enable_intr();
270 	}
271 
272 	/*
273 	 * Test IPI messaging
274 	 */
275 	if (ktr_testipicnt && ktr_testipicnt_remainder == 0 && ncpus > 1) {
276 		ktr_testipicnt_remainder = ktr_testipicnt;
277 		ktr_testipicnt = 0;
278 		lwkt_send_ipiq_bycpu(1, ktr_pingpong_remote, NULL);
279 	}
280 
281 	/*
282 	 * Test critical sections
283 	 */
284 	if (ktr_testcritcnt) {
285 		crit_enter();
286 		crit_exit();
287 		logtest_noargs(crit_beg);
288 		for (count = ktr_testcritcnt; count; --count) {
289 			crit_enter();
290 			crit_exit();
291 		}
292 		logtest_noargs(crit_end);
293 		ktr_testcritcnt = 0;
294 	}
295 
296 	/*
297 	 * Test spinlock sections
298 	 */
299 	if (ktr_testspincnt) {
300 		struct spinlock spin;
301 
302 		spin_init(&spin, "ktrresync");
303 		spin_lock(&spin);
304 		spin_unlock(&spin);
305 		logtest_noargs(spin_beg);
306 		for (count = ktr_testspincnt; count; --count) {
307 			spin_lock(&spin);
308 			spin_unlock(&spin);
309 		}
310 		logtest_noargs(spin_end);
311 		ktr_testspincnt = 0;
312 	}
313 #endif
314 
315 	/*
316 	 * Resynchronize the TSC
317 	 */
318 	if (ktr_resynchronize == 0)
319 		goto done;
320 	if ((cpu_feature & CPUID_TSC) == 0)
321 		return;
322 
323 	crit_enter();
324 	lwkt_cpusync_init(&cs, smp_active_mask, ktr_resync_remote,
325 			  (void *)(intptr_t)mycpu->gd_cpuid);
326 	lwkt_cpusync_interlock(&cs);
327 	ktr_sync_tsc = rdtsc();
328 	lwkt_cpusync_deinterlock(&cs);
329 	crit_exit();
330 done:
331 	callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL);
332 }
333 
334 /*
335  * The remote-end of the KTR synchronization protocol runs on all cpus.
336  * The one we run on the controlling cpu updates its tsc continuously
337  * until the others have finished syncing (theoretically), but we don't
338  * loop forever.
339  *
340  * This is a bit ad-hoc but we need to avoid livelocking inside an IPI
341  * callback.  rdtsc() is a synchronizing instruction (I think).
342  */
343 static void
344 ktr_resync_remote(void *arg)
345 {
346 	globaldata_t gd = mycpu;
347 	int64_t delta;
348 	int i;
349 
350 	if (gd->gd_cpuid == (int)(intptr_t)arg) {
351 		for (i = 0; i < 2000; ++i)
352 			ktr_sync_tsc = rdtsc();
353 	} else {
354 		delta = rdtsc() - ktr_sync_tsc;
355 		if (tsc_offsets[gd->gd_cpuid] == 0)
356 			tsc_offsets[gd->gd_cpuid] = delta;
357 		tsc_offsets[gd->gd_cpuid] =
358 			(tsc_offsets[gd->gd_cpuid] * 7 + delta) / 8;
359 	}
360 }
361 
362 #if KTR_TESTLOG
363 
364 static
365 void
366 ktr_pingpong_remote(void *dummy __unused)
367 {
368 	int other_cpu;
369 
370 	logtest_noargs(pingpong);
371 	other_cpu = 1 - mycpu->gd_cpuid;
372 	if (ktr_testipicnt_remainder) {
373 		--ktr_testipicnt_remainder;
374 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pingpong_remote, NULL);
375 	} else {
376 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL);
377 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL);
378 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL);
379 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL);
380 		lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL);
381 	}
382 }
383 
384 static
385 void
386 ktr_pipeline_remote(void *dummy __unused)
387 {
388 	logtest_noargs(pipeline);
389 }
390 
391 #endif
392 
393 #else	/* !_RDTSC_SUPPORTED_ */
394 
395 /*
396  * The resync callback for UP doesn't do anything other then run the test
397  * log messages.  If test logging is not enabled, don't bother resetting
398  * the callout.
399  */
400 static
401 void
402 ktr_resync_callback(void *dummy __unused)
403 {
404 #if KTR_TESTLOG
405 	/*
406 	 * Test logging
407 	 */
408 	if (ktr_testlogcnt) {
409 		--ktr_testlogcnt;
410 		cpu_disable_intr();
411 		logtest(test1);
412 		logtest(test2);
413 		logtest(test3);
414 		logtest_noargs(test4);
415 		logtest_noargs(test5);
416 		logtest_noargs(test6);
417 		cpu_enable_intr();
418 	}
419 	callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL);
420 #endif
421 }
422 
423 #endif
424 
425 /*
426  * Setup the next empty slot and return it to the caller to store the data
427  * directly.
428  */
429 struct ktr_entry *
430 ktr_begin_write_entry(struct ktr_info *info, const char *file, int line)
431 {
432 	struct ktr_cpu_core *kcpu;
433 	struct ktr_entry *entry;
434 	int cpu;
435 
436 	cpu = mycpu->gd_cpuid;
437 	kcpu = &ktr_cpu[cpu].core;
438 	if (panicstr)			/* stop logging during panic */
439 		return NULL;
440 	if (kcpu->ktr_buf == NULL)	/* too early in boot */
441 		return NULL;
442 
443 	crit_enter();
444 	entry = kcpu->ktr_buf + (kcpu->ktr_idx & ktr_entries_mask);
445 	++kcpu->ktr_idx;
446 #ifdef _RDTSC_SUPPORTED_
447 	if (cpu_feature & CPUID_TSC) {
448 		entry->ktr_timestamp = rdtsc() - tsc_offsets[cpu];
449 	} else
450 #endif
451 	{
452 		entry->ktr_timestamp = get_approximate_time_t();
453 	}
454 	entry->ktr_info = info;
455 	entry->ktr_file = file;
456 	entry->ktr_line = line;
457 	crit_exit();
458 	return entry;
459 }
460 
461 int
462 ktr_finish_write_entry(struct ktr_info *info, struct ktr_entry *entry)
463 {
464 	if (ktr_stacktrace)
465 		cpu_ktr_caller(entry);
466 #ifdef KTR_VERBOSE
467 	if (ktr_verbose && info->kf_format) {
468 		kprintf("cpu%d ", mycpu->gd_cpuid);
469 		if (ktr_verbose > 1) {
470 			kprintf("%s.%d\t", entry->ktr_file, entry->ktr_line);
471 		}
472 		return !0;
473 	}
474 #endif
475 	return 0;
476 }
477 
478 #ifdef DDB
479 
480 #define	NUM_LINES_PER_PAGE	19
481 
482 struct tstate {
483 	int	cur;
484 	int	first;
485 };
486 
487 static	int db_ktr_verbose;
488 static	int db_mach_vtrace(int cpu, struct ktr_entry *kp, int idx);
489 
490 DB_SHOW_COMMAND(ktr, db_ktr_all)
491 {
492 	struct ktr_cpu_core *kcpu;
493 	int a_flag = 0;
494 	int c;
495 	int nl = 0;
496 	int i;
497 	struct tstate tstate[MAXCPU];
498 	int printcpu = -1;
499 
500 	for(i = 0; i < ncpus; i++) {
501 		kcpu = &ktr_cpu[i].core;
502 		tstate[i].first = -1;
503 		tstate[i].cur = (kcpu->ktr_idx - 1) & ktr_entries_mask;
504 	}
505 	db_ktr_verbose = 0;
506 	while ((c = *(modif++)) != '\0') {
507 		if (c == 'v') {
508 			db_ktr_verbose = 1;
509 		}
510 		else if (c == 'a') {
511 			a_flag = 1;
512 		}
513 		else if (c == 'c') {
514 			printcpu = 0;
515 			while ((c = *(modif++)) != '\0') {
516 				if (isdigit(c)) {
517 					printcpu *= 10;
518 					printcpu += c - '0';
519 				}
520 				else {
521 					modif++;
522 					break;
523 				}
524 			}
525 			modif--;
526 		}
527 	}
528 	if (printcpu > ncpus - 1) {
529 		db_printf("Invalid cpu number\n");
530 		return;
531 	}
532 	/*
533 	 * Loop throug all the buffers and print the content of them, sorted
534 	 * by the timestamp.
535 	 */
536 	while (1) {
537 		int counter;
538 		u_int64_t highest_ts;
539 		struct ktr_entry *kp;
540 		int highest_cpu;
541 		int c;
542 
543 		if (a_flag == 1) {
544 			c = cncheckc();
545 			if (c != -1 && c != NOKEY)
546 				return;
547 		}
548 		highest_ts = 0;
549 		highest_cpu = -1;
550 		/*
551 		 * Find the lowest timestamp
552 		 */
553 		for (i = 0, counter = 0; i < ncpus; i++) {
554 			kcpu = &ktr_cpu[i].core;
555 			if (kcpu->ktr_buf == NULL)
556 				continue;
557 			if (printcpu != -1 && printcpu != i)
558 				continue;
559 			if (tstate[i].cur == -1) {
560 				counter++;
561 				if (counter == ncpus) {
562 					db_printf("--- End of trace buffer ---\n");
563 					return;
564 				}
565 				continue;
566 			}
567 			if (kcpu->ktr_buf[tstate[i].cur].ktr_timestamp > highest_ts) {
568 				highest_ts = kcpu->ktr_buf[tstate[i].cur].ktr_timestamp;
569 				highest_cpu = i;
570 			}
571 		}
572 		if (highest_cpu < 0) {
573 			db_printf("no KTR data available\n");
574 			break;
575 		}
576 		i = highest_cpu;
577 		kcpu = &ktr_cpu[i].core;
578 		kp = &kcpu->ktr_buf[tstate[i].cur];
579 		if (tstate[i].first == -1)
580 			tstate[i].first = tstate[i].cur;
581 		if (--tstate[i].cur < 0)
582 			tstate[i].cur = ktr_entries - 1;
583 		if (tstate[i].first == tstate[i].cur) {
584 			db_mach_vtrace(i, kp, tstate[i].cur + 1);
585 			tstate[i].cur = -1;
586 			continue;
587 		}
588 		if (kcpu->ktr_buf[tstate[i].cur].ktr_info == NULL)
589 			tstate[i].cur = -1;
590 		if (db_more(&nl) == -1)
591 			break;
592 		if (db_mach_vtrace(i, kp, tstate[i].cur + 1) == 0)
593 			tstate[i].cur = -1;
594 	}
595 }
596 
597 static int
598 db_mach_vtrace(int cpu, struct ktr_entry *kp, int idx)
599 {
600 	if (kp->ktr_info == NULL)
601 		return(0);
602 	db_printf("cpu%d ", cpu);
603 	db_printf("%d: ", idx);
604 	if (db_ktr_verbose) {
605 		db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp,
606 		    kp->ktr_file, kp->ktr_line);
607 	}
608 	db_printf("%s\t", kp->ktr_info->kf_name);
609 	db_printf("from(%p,%p) ", kp->ktr_caller1, kp->ktr_caller2);
610 #ifdef __i386__
611 	if (kp->ktr_info->kf_format)
612 		db_vprintf(kp->ktr_info->kf_format, (__va_list)kp->ktr_data);
613 #endif
614 	db_printf("\n");
615 
616 	return(1);
617 }
618 
619 #endif	/* DDB */
620