| 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 | * $DragonFly: src/sys/kern/kern_ktr.c,v 1.23 2008/02/12 23:33:23 corecode Exp $ |
| 66 | */ |
| 67 | /* |
| 68 | * Kernel tracepoint facility. |
| 69 | */ |
| 70 | |
| 71 | #include "opt_ddb.h" |
| 72 | #include "opt_ktr.h" |
| 73 | |
| 74 | #include <sys/param.h> |
| 75 | #include <sys/cons.h> |
| 76 | #include <sys/kernel.h> |
| 77 | #include <sys/libkern.h> |
| 78 | #include <sys/proc.h> |
| 79 | #include <sys/sysctl.h> |
| 80 | #include <sys/ktr.h> |
| 81 | #include <sys/systm.h> |
| 82 | #include <sys/time.h> |
| 83 | #include <sys/malloc.h> |
| 84 | #include <sys/spinlock.h> |
| 85 | #include <sys/thread2.h> |
| 86 | #include <sys/spinlock2.h> |
| 87 | #include <sys/ctype.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 | #endif |
| 99 | #define KTR_ENTRIES_MASK (KTR_ENTRIES - 1) |
| 100 | |
| 101 | /* |
| 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. |
| 105 | */ |
| 106 | #if !defined(KTR_TESTLOG) |
| 107 | #define KTR_TESTLOG KTR_ALL |
| 108 | #endif |
| 109 | KTR_INFO_MASTER(testlog); |
| 110 | #if KTR_TESTLOG |
| 111 | KTR_INFO(KTR_TESTLOG, testlog, test1, 0, "test1", sizeof(void *) * 4); |
| 112 | KTR_INFO(KTR_TESTLOG, testlog, test2, 1, "test2", sizeof(void *) * 4); |
| 113 | KTR_INFO(KTR_TESTLOG, testlog, test3, 2, "test3", sizeof(void *) * 4); |
| 114 | KTR_INFO(KTR_TESTLOG, testlog, test4, 3, "test4", 0); |
| 115 | KTR_INFO(KTR_TESTLOG, testlog, test5, 4, "test5", 0); |
| 116 | KTR_INFO(KTR_TESTLOG, testlog, test6, 5, "test6", 0); |
| 117 | #ifdef SMP |
| 118 | KTR_INFO(KTR_TESTLOG, testlog, pingpong, 6, "pingpong", 0); |
| 119 | KTR_INFO(KTR_TESTLOG, testlog, pipeline, 7, "pipeline", 0); |
| 120 | KTR_INFO(KTR_TESTLOG, testlog, crit_beg, 8, "crit_beg", 0); |
| 121 | KTR_INFO(KTR_TESTLOG, testlog, crit_end, 9, "crit_end", 0); |
| 122 | KTR_INFO(KTR_TESTLOG, testlog, spin_beg, 10, "spin_beg", 0); |
| 123 | KTR_INFO(KTR_TESTLOG, testlog, spin_end, 11, "spin_end", 0); |
| 124 | #endif |
| 125 | #define logtest(name) KTR_LOG(testlog_ ## name, 0, 0, 0, 0) |
| 126 | #define logtest_noargs(name) KTR_LOG(testlog_ ## name) |
| 127 | #endif |
| 128 | |
| 129 | MALLOC_DEFINE(M_KTR, "ktr", "ktr buffers"); |
| 130 | |
| 131 | SYSCTL_NODE(_debug, OID_AUTO, ktr, CTLFLAG_RW, 0, "ktr"); |
| 132 | |
| 133 | int ktr_entries = KTR_ENTRIES; |
| 134 | SYSCTL_INT(_debug_ktr, OID_AUTO, entries, CTLFLAG_RD, &ktr_entries, 0, ""); |
| 135 | |
| 136 | int ktr_version = KTR_VERSION; |
| 137 | SYSCTL_INT(_debug_ktr, OID_AUTO, version, CTLFLAG_RD, &ktr_version, 0, ""); |
| 138 | |
| 139 | static int ktr_stacktrace = 1; |
| 140 | SYSCTL_INT(_debug_ktr, OID_AUTO, stacktrace, CTLFLAG_RD, &ktr_stacktrace, 0, ""); |
| 141 | |
| 142 | static int ktr_resynchronize = 0; |
| 143 | SYSCTL_INT(_debug_ktr, OID_AUTO, resynchronize, CTLFLAG_RW, &ktr_resynchronize, 0, ""); |
| 144 | |
| 145 | #if KTR_TESTLOG |
| 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 | #ifdef SMP |
| 150 | static int ktr_testipicnt_remainder; |
| 151 | #endif |
| 152 | SYSCTL_INT(_debug_ktr, OID_AUTO, testipicnt, CTLFLAG_RW, &ktr_testipicnt, 0, ""); |
| 153 | static int ktr_testcritcnt = 0; |
| 154 | SYSCTL_INT(_debug_ktr, OID_AUTO, testcritcnt, CTLFLAG_RW, &ktr_testcritcnt, 0, ""); |
| 155 | static int ktr_testspincnt = 0; |
| 156 | SYSCTL_INT(_debug_ktr, OID_AUTO, testspincnt, CTLFLAG_RW, &ktr_testspincnt, 0, ""); |
| 157 | #endif |
| 158 | |
| 159 | /* |
| 160 | * Give cpu0 a static buffer so the tracepoint facility can be used during |
| 161 | * early boot (note however that we still use a critical section, XXX). |
| 162 | */ |
| 163 | static struct ktr_entry ktr_buf0[KTR_ENTRIES]; |
| 164 | |
| 165 | __cachealign struct ktr_cpu ktr_cpu[MAXCPU] = { |
| 166 | { .core.ktr_buf = &ktr_buf0[0] } |
| 167 | }; |
| 168 | |
| 169 | #ifdef SMP |
| 170 | static int ktr_sync_state = 0; |
| 171 | static int ktr_sync_count; |
| 172 | static int64_t ktr_sync_tsc; |
| 173 | #endif |
| 174 | struct callout ktr_resync_callout; |
| 175 | |
| 176 | #ifdef KTR_VERBOSE |
| 177 | int ktr_verbose = KTR_VERBOSE; |
| 178 | TUNABLE_INT("debug.ktr.verbose", &ktr_verbose); |
| 179 | SYSCTL_INT(_debug_ktr, OID_AUTO, verbose, CTLFLAG_RW, &ktr_verbose, 0, ""); |
| 180 | #endif |
| 181 | |
| 182 | static void ktr_resync_callback(void *dummy __unused); |
| 183 | |
| 184 | extern int64_t tsc_offsets[]; |
| 185 | |
| 186 | static void |
| 187 | ktr_sysinit(void *dummy) |
| 188 | { |
| 189 | struct ktr_cpu_core *kcpu; |
| 190 | int i; |
| 191 | |
| 192 | for(i = 1; i < ncpus; ++i) { |
| 193 | kcpu = &ktr_cpu[i].core; |
| 194 | kcpu->ktr_buf = kmalloc(KTR_ENTRIES * sizeof(struct ktr_entry), |
| 195 | M_KTR, M_WAITOK | M_ZERO); |
| 196 | } |
| 197 | callout_init(&ktr_resync_callout); |
| 198 | callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL); |
| 199 | } |
| 200 | SYSINIT(ktr_sysinit, SI_BOOT2_KLD, SI_ORDER_ANY, ktr_sysinit, NULL); |
| 201 | |
| 202 | /* |
| 203 | * Try to resynchronize the TSC's for all cpus. This is really, really nasty. |
| 204 | * We have to send an IPIQ message to all remote cpus, wait until they |
| 205 | * get into their IPIQ processing code loop, then do an even stricter hard |
| 206 | * loop to get the cpus as close to synchronized as we can to get the most |
| 207 | * accurate reading. |
| 208 | * |
| 209 | * This callback occurs on cpu0. |
| 210 | */ |
| 211 | #if KTR_TESTLOG |
| 212 | #ifdef SMP |
| 213 | static void ktr_pingpong_remote(void *dummy); |
| 214 | static void ktr_pipeline_remote(void *dummy); |
| 215 | #endif |
| 216 | #endif |
| 217 | |
| 218 | #if defined(SMP) && defined(_RDTSC_SUPPORTED_) |
| 219 | |
| 220 | static void ktr_resync_remote(void *dummy); |
| 221 | extern cpumask_t smp_active_mask; |
| 222 | |
| 223 | /* |
| 224 | * We use a callout callback instead of a systimer because we cannot afford |
| 225 | * to preempt anyone to do this, or we might deadlock a spin-lock or |
| 226 | * serializer between two cpus. |
| 227 | */ |
| 228 | static |
| 229 | void |
| 230 | ktr_resync_callback(void *dummy __unused) |
| 231 | { |
| 232 | int count; |
| 233 | |
| 234 | KKASSERT(mycpu->gd_cpuid == 0); |
| 235 | |
| 236 | #if KTR_TESTLOG |
| 237 | /* |
| 238 | * Test logging |
| 239 | */ |
| 240 | if (ktr_testlogcnt) { |
| 241 | --ktr_testlogcnt; |
| 242 | cpu_disable_intr(); |
| 243 | logtest(test1); |
| 244 | logtest(test2); |
| 245 | logtest(test3); |
| 246 | logtest_noargs(test4); |
| 247 | logtest_noargs(test5); |
| 248 | logtest_noargs(test6); |
| 249 | cpu_enable_intr(); |
| 250 | } |
| 251 | |
| 252 | /* |
| 253 | * Test IPI messaging |
| 254 | */ |
| 255 | if (ktr_testipicnt && ktr_testipicnt_remainder == 0 && ncpus > 1) { |
| 256 | ktr_testipicnt_remainder = ktr_testipicnt; |
| 257 | ktr_testipicnt = 0; |
| 258 | lwkt_send_ipiq_bycpu(1, ktr_pingpong_remote, NULL); |
| 259 | } |
| 260 | |
| 261 | /* |
| 262 | * Test critical sections |
| 263 | */ |
| 264 | if (ktr_testcritcnt) { |
| 265 | crit_enter(); |
| 266 | crit_exit(); |
| 267 | logtest_noargs(crit_beg); |
| 268 | for (count = ktr_testcritcnt; count; --count) { |
| 269 | crit_enter(); |
| 270 | crit_exit(); |
| 271 | } |
| 272 | logtest_noargs(crit_end); |
| 273 | ktr_testcritcnt = 0; |
| 274 | } |
| 275 | |
| 276 | /* |
| 277 | * Test spinlock sections |
| 278 | */ |
| 279 | if (ktr_testspincnt) { |
| 280 | struct spinlock spin; |
| 281 | |
| 282 | spin_init(&spin); |
| 283 | spin_lock_wr(&spin); |
| 284 | spin_unlock_wr(&spin); |
| 285 | logtest_noargs(spin_beg); |
| 286 | for (count = ktr_testspincnt; count; --count) { |
| 287 | spin_lock_wr(&spin); |
| 288 | spin_unlock_wr(&spin); |
| 289 | } |
| 290 | logtest_noargs(spin_end); |
| 291 | ktr_testspincnt = 0; |
| 292 | } |
| 293 | #endif |
| 294 | |
| 295 | /* |
| 296 | * Resynchronize the TSC |
| 297 | */ |
| 298 | if (ktr_resynchronize == 0) |
| 299 | goto done; |
| 300 | if ((cpu_feature & CPUID_TSC) == 0) |
| 301 | return; |
| 302 | |
| 303 | /* |
| 304 | * Send the synchronizing IPI and wait for all cpus to get into |
| 305 | * their spin loop. We must process incoming IPIs while waiting |
| 306 | * to avoid a deadlock. |
| 307 | */ |
| 308 | crit_enter(); |
| 309 | ktr_sync_count = 0; |
| 310 | ktr_sync_state = 1; |
| 311 | ktr_sync_tsc = rdtsc(); |
| 312 | count = lwkt_send_ipiq_mask(mycpu->gd_other_cpus & smp_active_mask, |
| 313 | (ipifunc1_t)ktr_resync_remote, NULL); |
| 314 | while (ktr_sync_count != count) |
| 315 | lwkt_process_ipiq(); |
| 316 | |
| 317 | /* |
| 318 | * Continuously update the TSC for cpu 0 while waiting for all other |
| 319 | * cpus to finish stage 2. |
| 320 | */ |
| 321 | cpu_disable_intr(); |
| 322 | ktr_sync_tsc = rdtsc(); |
| 323 | cpu_sfence(); |
| 324 | ktr_sync_state = 2; |
| 325 | cpu_sfence(); |
| 326 | while (ktr_sync_count != 0) { |
| 327 | ktr_sync_tsc = rdtsc(); |
| 328 | cpu_lfence(); |
| 329 | cpu_nop(); |
| 330 | } |
| 331 | cpu_enable_intr(); |
| 332 | crit_exit(); |
| 333 | ktr_sync_state = 0; |
| 334 | done: |
| 335 | callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL); |
| 336 | } |
| 337 | |
| 338 | /* |
| 339 | * The remote-end of the KTR synchronization protocol runs on all cpus except |
| 340 | * cpu 0. Since this is an IPI function, it is entered with the current |
| 341 | * thread in a critical section. |
| 342 | */ |
| 343 | static void |
| 344 | ktr_resync_remote(void *dummy __unused) |
| 345 | { |
| 346 | volatile int64_t tsc1 = ktr_sync_tsc; |
| 347 | volatile int64_t tsc2; |
| 348 | |
| 349 | /* |
| 350 | * Inform the master that we have entered our hard loop. |
| 351 | */ |
| 352 | KKASSERT(ktr_sync_state == 1); |
| 353 | atomic_add_int(&ktr_sync_count, 1); |
| 354 | while (ktr_sync_state == 1) { |
| 355 | lwkt_process_ipiq(); |
| 356 | } |
| 357 | |
| 358 | /* |
| 359 | * Now the master is in a hard loop, synchronize the TSC and |
| 360 | * we are done. |
| 361 | */ |
| 362 | cpu_disable_intr(); |
| 363 | KKASSERT(ktr_sync_state == 2); |
| 364 | tsc2 = ktr_sync_tsc; |
| 365 | if (tsc2 > tsc1) |
| 366 | tsc_offsets[mycpu->gd_cpuid] = rdtsc() - tsc2; |
| 367 | atomic_subtract_int(&ktr_sync_count, 1); |
| 368 | cpu_enable_intr(); |
| 369 | } |
| 370 | |
| 371 | #if KTR_TESTLOG |
| 372 | |
| 373 | static |
| 374 | void |
| 375 | ktr_pingpong_remote(void *dummy __unused) |
| 376 | { |
| 377 | int other_cpu; |
| 378 | |
| 379 | logtest_noargs(pingpong); |
| 380 | other_cpu = 1 - mycpu->gd_cpuid; |
| 381 | if (ktr_testipicnt_remainder) { |
| 382 | --ktr_testipicnt_remainder; |
| 383 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pingpong_remote, NULL); |
| 384 | } else { |
| 385 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL); |
| 386 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL); |
| 387 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL); |
| 388 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL); |
| 389 | lwkt_send_ipiq_bycpu(other_cpu, ktr_pipeline_remote, NULL); |
| 390 | } |
| 391 | } |
| 392 | |
| 393 | static |
| 394 | void |
| 395 | ktr_pipeline_remote(void *dummy __unused) |
| 396 | { |
| 397 | logtest_noargs(pipeline); |
| 398 | } |
| 399 | |
| 400 | #endif |
| 401 | |
| 402 | #else /* !SMP */ |
| 403 | |
| 404 | /* |
| 405 | * The resync callback for UP doesn't do anything other then run the test |
| 406 | * log messages. If test logging is not enabled, don't bother resetting |
| 407 | * the callout. |
| 408 | */ |
| 409 | static |
| 410 | void |
| 411 | ktr_resync_callback(void *dummy __unused) |
| 412 | { |
| 413 | #if KTR_TESTLOG |
| 414 | /* |
| 415 | * Test logging |
| 416 | */ |
| 417 | if (ktr_testlogcnt) { |
| 418 | --ktr_testlogcnt; |
| 419 | cpu_disable_intr(); |
| 420 | logtest(test1); |
| 421 | logtest(test2); |
| 422 | logtest(test3); |
| 423 | logtest_noargs(test4); |
| 424 | logtest_noargs(test5); |
| 425 | logtest_noargs(test6); |
| 426 | cpu_enable_intr(); |
| 427 | } |
| 428 | callout_reset(&ktr_resync_callout, hz / 10, ktr_resync_callback, NULL); |
| 429 | #endif |
| 430 | } |
| 431 | |
| 432 | #endif |
| 433 | |
| 434 | /* |
| 435 | * KTR_WRITE_ENTRY - Primary entry point for kernel trace logging |
| 436 | */ |
| 437 | |
| 438 | static __inline |
| 439 | void |
| 440 | ktr_write_entry(struct ktr_info *info, const char *file, int line, __va_list va) |
| 441 | { |
| 442 | struct ktr_cpu_core *kcpu; |
| 443 | struct ktr_entry *entry; |
| 444 | int cpu; |
| 445 | |
| 446 | cpu = mycpu->gd_cpuid; |
| 447 | kcpu = &ktr_cpu[cpu].core; |
| 448 | if (kcpu->ktr_buf == NULL) |
| 449 | return; |
| 450 | |
| 451 | crit_enter(); |
| 452 | entry = kcpu->ktr_buf + (kcpu->ktr_idx & KTR_ENTRIES_MASK); |
| 453 | ++kcpu->ktr_idx; |
| 454 | #ifdef _RDTSC_SUPPORTED_ |
| 455 | if (cpu_feature & CPUID_TSC) { |
| 456 | #ifdef SMP |
| 457 | entry->ktr_timestamp = rdtsc() - tsc_offsets[cpu]; |
| 458 | #else |
| 459 | entry->ktr_timestamp = rdtsc(); |
| 460 | #endif |
| 461 | } else |
| 462 | #endif |
| 463 | { |
| 464 | entry->ktr_timestamp = get_approximate_time_t(); |
| 465 | } |
| 466 | entry->ktr_info = info; |
| 467 | entry->ktr_file = file; |
| 468 | entry->ktr_line = line; |
| 469 | crit_exit(); |
| 470 | if (info->kf_data_size > KTR_BUFSIZE) |
| 471 | bcopy(va, entry->ktr_data, KTR_BUFSIZE); |
| 472 | else if (info->kf_data_size) |
| 473 | bcopy(va, entry->ktr_data, info->kf_data_size); |
| 474 | if (ktr_stacktrace) |
| 475 | cpu_ktr_caller(entry); |
| 476 | #ifdef KTR_VERBOSE |
| 477 | if (ktr_verbose && info->kf_format) { |
| 478 | #ifdef SMP |
| 479 | kprintf("cpu%d ", cpu); |
| 480 | #endif |
| 481 | if (ktr_verbose > 1) { |
| 482 | kprintf("%s.%d\t", entry->ktr_file, entry->ktr_line); |
| 483 | } |
| 484 | kvprintf(info->kf_format, va); |
| 485 | kprintf("\n"); |
| 486 | } |
| 487 | #endif |
| 488 | } |
| 489 | |
| 490 | void |
| 491 | ktr_log(struct ktr_info *info, const char *file, int line, ...) |
| 492 | { |
| 493 | __va_list va; |
| 494 | |
| 495 | if (panicstr == NULL) { |
| 496 | __va_start(va, line); |
| 497 | ktr_write_entry(info, file, line, va); |
| 498 | __va_end(va); |
| 499 | } |
| 500 | } |
| 501 | |
| 502 | #ifdef DDB |
| 503 | |
| 504 | #define NUM_LINES_PER_PAGE 19 |
| 505 | |
| 506 | struct tstate { |
| 507 | int cur; |
| 508 | int first; |
| 509 | }; |
| 510 | |
| 511 | static int db_ktr_verbose; |
| 512 | static int db_mach_vtrace(int cpu, struct ktr_entry *kp, int idx); |
| 513 | |
| 514 | DB_SHOW_COMMAND(ktr, db_ktr_all) |
| 515 | { |
| 516 | struct ktr_cpu_core *kcpu; |
| 517 | int a_flag = 0; |
| 518 | int c; |
| 519 | int nl = 0; |
| 520 | int i; |
| 521 | struct tstate tstate[MAXCPU]; |
| 522 | int printcpu = -1; |
| 523 | |
| 524 | for(i = 0; i < ncpus; i++) { |
| 525 | kcpu = &ktr_cpu[i].core; |
| 526 | tstate[i].first = -1; |
| 527 | tstate[i].cur = (kcpu->ktr_idx - 1) & KTR_ENTRIES_MASK; |
| 528 | } |
| 529 | db_ktr_verbose = 0; |
| 530 | while ((c = *(modif++)) != '\0') { |
| 531 | if (c == 'v') { |
| 532 | db_ktr_verbose = 1; |
| 533 | } |
| 534 | else if (c == 'a') { |
| 535 | a_flag = 1; |
| 536 | } |
| 537 | else if (c == 'c') { |
| 538 | printcpu = 0; |
| 539 | while ((c = *(modif++)) != '\0') { |
| 540 | if (isdigit(c)) { |
| 541 | printcpu *= 10; |
| 542 | printcpu += c - '0'; |
| 543 | } |
| 544 | else { |
| 545 | modif++; |
| 546 | break; |
| 547 | } |
| 548 | } |
| 549 | modif--; |
| 550 | } |
| 551 | } |
| 552 | if (printcpu > ncpus - 1) { |
| 553 | db_printf("Invalid cpu number\n"); |
| 554 | return; |
| 555 | } |
| 556 | /* |
| 557 | * Lopp throug all the buffers and print the content of them, sorted |
| 558 | * by the timestamp. |
| 559 | */ |
| 560 | while (1) { |
| 561 | int counter; |
| 562 | u_int64_t highest_ts; |
| 563 | int highest_cpu; |
| 564 | struct ktr_entry *kp; |
| 565 | |
| 566 | if (a_flag == 1 && cncheckc() != -1) |
| 567 | return; |
| 568 | highest_ts = 0; |
| 569 | highest_cpu = -1; |
| 570 | /* |
| 571 | * Find the lowest timestamp |
| 572 | */ |
| 573 | for (i = 0, counter = 0; i < ncpus; i++) { |
| 574 | kcpu = &ktr_cpu[i].core; |
| 575 | if (kcpu->ktr_buf == NULL) |
| 576 | continue; |
| 577 | if (printcpu != -1 && printcpu != i) |
| 578 | continue; |
| 579 | if (tstate[i].cur == -1) { |
| 580 | counter++; |
| 581 | if (counter == ncpus) { |
| 582 | db_printf("--- End of trace buffer ---\n"); |
| 583 | return; |
| 584 | } |
| 585 | continue; |
| 586 | } |
| 587 | if (kcpu->ktr_buf[tstate[i].cur].ktr_timestamp > highest_ts) { |
| 588 | highest_ts = kcpu->ktr_buf[tstate[i].cur].ktr_timestamp; |
| 589 | highest_cpu = i; |
| 590 | } |
| 591 | } |
| 592 | if (highest_cpu < 0) { |
| 593 | db_printf("no KTR data available\n"); |
| 594 | break; |
| 595 | } |
| 596 | i = highest_cpu; |
| 597 | kcpu = &ktr_cpu[i].core; |
| 598 | kp = &kcpu->ktr_buf[tstate[i].cur]; |
| 599 | if (tstate[i].first == -1) |
| 600 | tstate[i].first = tstate[i].cur; |
| 601 | if (--tstate[i].cur < 0) |
| 602 | tstate[i].cur = KTR_ENTRIES - 1; |
| 603 | if (tstate[i].first == tstate[i].cur) { |
| 604 | db_mach_vtrace(i, kp, tstate[i].cur + 1); |
| 605 | tstate[i].cur = -1; |
| 606 | continue; |
| 607 | } |
| 608 | if (kcpu->ktr_buf[tstate[i].cur].ktr_info == NULL) |
| 609 | tstate[i].cur = -1; |
| 610 | if (db_more(&nl) == -1) |
| 611 | break; |
| 612 | if (db_mach_vtrace(i, kp, tstate[i].cur + 1) == 0) |
| 613 | tstate[i].cur = -1; |
| 614 | } |
| 615 | } |
| 616 | |
| 617 | static int |
| 618 | db_mach_vtrace(int cpu, struct ktr_entry *kp, int idx) |
| 619 | { |
| 620 | if (kp->ktr_info == NULL) |
| 621 | return(0); |
| 622 | #ifdef SMP |
| 623 | db_printf("cpu%d ", cpu); |
| 624 | #endif |
| 625 | db_printf("%d: ", idx); |
| 626 | if (db_ktr_verbose) { |
| 627 | db_printf("%10.10lld %s.%d\t", (long long)kp->ktr_timestamp, |
| 628 | kp->ktr_file, kp->ktr_line); |
| 629 | } |
| 630 | db_printf("%s\t", kp->ktr_info->kf_name); |
| 631 | db_printf("from(%p,%p) ", kp->ktr_caller1, kp->ktr_caller2); |
| 632 | if (kp->ktr_info->kf_format) |
| 633 | db_vprintf(kp->ktr_info->kf_format, (__va_list)kp->ktr_data); |
| 634 | db_printf("\n"); |
| 635 | |
| 636 | return(1); |
| 637 | } |
| 638 | |
| 639 | #endif /* DDB */ |