]> git.proxmox.com Git - mirror_zfs.git/blob - module/spl/spl-debug.c
4bcc34a8ef62ebce56706c64d83077b93ce3400a
[mirror_zfs.git] / module / spl / spl-debug.c
1 /*****************************************************************************\
2 * Copyright (C) 2007-2010 Lawrence Livermore National Security, LLC.
3 * Copyright (C) 2007 The Regents of the University of California.
4 * Produced at Lawrence Livermore National Laboratory (cf, DISCLAIMER).
5 * Written by Brian Behlendorf <behlendorf1@llnl.gov>.
6 * UCRL-CODE-235197
7 *
8 * This file is part of the SPL, Solaris Porting Layer.
9 * For details, see <http://github.com/behlendorf/spl/>.
10 *
11 * The SPL is free software; you can redistribute it and/or modify it
12 * under the terms of the GNU General Public License as published by the
13 * Free Software Foundation; either version 2 of the License, or (at your
14 * option) any later version.
15 *
16 * The SPL is distributed in the hope that it will be useful, but WITHOUT
17 * ANY WARRANTY; without even the implied warranty of MERCHANTABILITY or
18 * FITNESS FOR A PARTICULAR PURPOSE. See the GNU General Public License
19 * for more details.
20 *
21 * You should have received a copy of the GNU General Public License along
22 * with the SPL. If not, see <http://www.gnu.org/licenses/>.
23 *****************************************************************************
24 * Solaris Porting Layer (SPL) Debug Implementation.
25 \*****************************************************************************/
26
27 #include <linux/kmod.h>
28 #include <linux/mm.h>
29 #include <linux/vmalloc.h>
30 #include <linux/pagemap.h>
31 #include <linux/slab.h>
32 #include <linux/ctype.h>
33 #include <linux/kthread.h>
34 #include <linux/hardirq.h>
35 #include <linux/interrupt.h>
36 #include <linux/spinlock.h>
37 #include <linux/proc_compat.h>
38 #include <linux/file_compat.h>
39 #include <sys/sysmacros.h>
40 #include <spl-debug.h>
41 #include <spl-trace.h>
42 #include <spl-ctl.h>
43
44 #ifdef SS_DEBUG_SUBSYS
45 #undef SS_DEBUG_SUBSYS
46 #endif
47
48 #define SS_DEBUG_SUBSYS SS_DEBUG
49
50 /* Debug log support enabled */
51 #ifdef DEBUG_LOG
52
53 unsigned long spl_debug_subsys = ~0;
54 EXPORT_SYMBOL(spl_debug_subsys);
55 module_param(spl_debug_subsys, ulong, 0644);
56 MODULE_PARM_DESC(spl_debug_subsys, "Subsystem debugging level mask.");
57
58 unsigned long spl_debug_mask = SD_CANTMASK;
59 EXPORT_SYMBOL(spl_debug_mask);
60 module_param(spl_debug_mask, ulong, 0644);
61 MODULE_PARM_DESC(spl_debug_mask, "Debugging level mask.");
62
63 unsigned long spl_debug_printk = SD_CANTMASK;
64 EXPORT_SYMBOL(spl_debug_printk);
65 module_param(spl_debug_printk, ulong, 0644);
66 MODULE_PARM_DESC(spl_debug_printk, "Console printk level mask.");
67
68 int spl_debug_mb = -1;
69 EXPORT_SYMBOL(spl_debug_mb);
70 module_param(spl_debug_mb, int, 0644);
71 MODULE_PARM_DESC(spl_debug_mb, "Total debug buffer size.");
72
73 unsigned int spl_debug_binary = 1;
74 EXPORT_SYMBOL(spl_debug_binary);
75
76 unsigned int spl_debug_catastrophe;
77 EXPORT_SYMBOL(spl_debug_catastrophe);
78
79 unsigned int spl_debug_panic_on_bug = 0;
80 EXPORT_SYMBOL(spl_debug_panic_on_bug);
81 module_param(spl_debug_panic_on_bug, uint, 0644);
82 MODULE_PARM_DESC(spl_debug_panic_on_bug, "Panic on BUG");
83
84 static char spl_debug_file_name[PATH_MAX];
85 char spl_debug_file_path[PATH_MAX] = "/tmp/spl-log";
86
87 unsigned int spl_console_ratelimit = 1;
88 EXPORT_SYMBOL(spl_console_ratelimit);
89
90 long spl_console_max_delay;
91 EXPORT_SYMBOL(spl_console_max_delay);
92
93 long spl_console_min_delay;
94 EXPORT_SYMBOL(spl_console_min_delay);
95
96 unsigned int spl_console_backoff = SPL_DEFAULT_BACKOFF;
97 EXPORT_SYMBOL(spl_console_backoff);
98
99 unsigned int spl_debug_stack;
100 EXPORT_SYMBOL(spl_debug_stack);
101
102 static int spl_panic_in_progress;
103
104 union trace_data_union (*trace_data[TCD_TYPE_MAX])[NR_CPUS] __cacheline_aligned;
105 char *trace_console_buffers[NR_CPUS][3];
106 struct rw_semaphore trace_sem;
107 atomic_t trace_tage_allocated = ATOMIC_INIT(0);
108
109 static int spl_debug_dump_all_pages(dumplog_priv_t *dp, char *);
110 static void trace_fini(void);
111
112
113 /* Memory percentage breakdown by type */
114 static unsigned int pages_factor[TCD_TYPE_MAX] = {
115 80, /* 80% pages for TCD_TYPE_PROC */
116 10, /* 10% pages for TCD_TYPE_SOFTIRQ */
117 10 /* 10% pages for TCD_TYPE_IRQ */
118 };
119
120 const char *
121 spl_debug_subsys2str(int subsys)
122 {
123 switch (subsys) {
124 default:
125 return NULL;
126 case SS_UNDEFINED:
127 return "undefined";
128 case SS_ATOMIC:
129 return "atomic";
130 case SS_KOBJ:
131 return "kobj";
132 case SS_VNODE:
133 return "vnode";
134 case SS_TIME:
135 return "time";
136 case SS_RWLOCK:
137 return "rwlock";
138 case SS_THREAD:
139 return "thread";
140 case SS_CONDVAR:
141 return "condvar";
142 case SS_MUTEX:
143 return "mutex";
144 case SS_RNG:
145 return "rng";
146 case SS_TASKQ:
147 return "taskq";
148 case SS_KMEM:
149 return "kmem";
150 case SS_DEBUG:
151 return "debug";
152 case SS_GENERIC:
153 return "generic";
154 case SS_PROC:
155 return "proc";
156 case SS_MODULE:
157 return "module";
158 case SS_CRED:
159 return "cred";
160 case SS_KSTAT:
161 return "kstat";
162 case SS_XDR:
163 return "xdr";
164 case SS_TSD:
165 return "tsd";
166 case SS_ZLIB:
167 return "zlib";
168 case SS_USER1:
169 return "user1";
170 case SS_USER2:
171 return "user2";
172 case SS_USER3:
173 return "user3";
174 case SS_USER4:
175 return "user4";
176 case SS_USER5:
177 return "user5";
178 case SS_USER6:
179 return "user6";
180 case SS_USER7:
181 return "user7";
182 case SS_USER8:
183 return "user8";
184 }
185 }
186
187 const char *
188 spl_debug_dbg2str(int debug)
189 {
190 switch (debug) {
191 default:
192 return NULL;
193 case SD_TRACE:
194 return "trace";
195 case SD_INFO:
196 return "info";
197 case SD_WARNING:
198 return "warning";
199 case SD_ERROR:
200 return "error";
201 case SD_EMERG:
202 return "emerg";
203 case SD_CONSOLE:
204 return "console";
205 case SD_IOCTL:
206 return "ioctl";
207 case SD_DPRINTF:
208 return "dprintf";
209 case SD_OTHER:
210 return "other";
211 }
212 }
213
214 int
215 spl_debug_mask2str(char *str, int size, unsigned long mask, int is_subsys)
216 {
217 const char *(*fn)(int bit) = is_subsys ? spl_debug_subsys2str :
218 spl_debug_dbg2str;
219 const char *token;
220 int i, bit, len = 0;
221
222 if (mask == 0) { /* "0" */
223 if (size > 0)
224 str[0] = '0';
225 len = 1;
226 } else { /* space-separated tokens */
227 for (i = 0; i < 32; i++) {
228 bit = 1 << i;
229
230 if ((mask & bit) == 0)
231 continue;
232
233 token = fn(bit);
234 if (token == NULL) /* unused bit */
235 continue;
236
237 if (len > 0) { /* separator? */
238 if (len < size)
239 str[len] = ' ';
240 len++;
241 }
242
243 while (*token != 0) {
244 if (len < size)
245 str[len] = *token;
246 token++;
247 len++;
248 }
249 }
250 }
251
252 /* terminate 'str' */
253 if (len < size)
254 str[len] = 0;
255 else
256 str[size - 1] = 0;
257
258 return len;
259 }
260
261 static int
262 spl_debug_token2mask(int *mask, const char *str, int len, int is_subsys)
263 {
264 const char *(*fn)(int bit) = is_subsys ? spl_debug_subsys2str :
265 spl_debug_dbg2str;
266 const char *token;
267 int i, j, bit;
268
269 /* match against known tokens */
270 for (i = 0; i < 32; i++) {
271 bit = 1 << i;
272
273 token = fn(bit);
274 if (token == NULL) /* unused? */
275 continue;
276
277 /* strcasecmp */
278 for (j = 0; ; j++) {
279 if (j == len) { /* end of token */
280 if (token[j] == 0) {
281 *mask = bit;
282 return 0;
283 }
284 break;
285 }
286
287 if (token[j] == 0)
288 break;
289
290 if (str[j] == token[j])
291 continue;
292
293 if (str[j] < 'A' || 'Z' < str[j])
294 break;
295
296 if (str[j] - 'A' + 'a' != token[j])
297 break;
298 }
299 }
300
301 return -EINVAL; /* no match */
302 }
303
304 int
305 spl_debug_str2mask(unsigned long *mask, const char *str, int is_subsys)
306 {
307 char op = 0;
308 int m = 0, matched, n, t;
309
310 /* Allow a number for backwards compatibility */
311 for (n = strlen(str); n > 0; n--)
312 if (!isspace(str[n-1]))
313 break;
314 matched = n;
315
316 if ((t = sscanf(str, "%i%n", &m, &matched)) >= 1 && matched == n) {
317 *mask = m;
318 return 0;
319 }
320
321 /* <str> must be a list of debug tokens or numbers separated by
322 * whitespace and optionally an operator ('+' or '-'). If an operator
323 * appears first in <str>, '*mask' is used as the starting point
324 * (relative), otherwise 0 is used (absolute). An operator applies to
325 * all following tokens up to the next operator. */
326 matched = 0;
327 while (*str != 0) {
328 while (isspace(*str)) /* skip whitespace */
329 str++;
330
331 if (*str == 0)
332 break;
333
334 if (*str == '+' || *str == '-') {
335 op = *str++;
336
337 /* op on first token == relative */
338 if (!matched)
339 m = *mask;
340
341 while (isspace(*str)) /* skip whitespace */
342 str++;
343
344 if (*str == 0) /* trailing op */
345 return -EINVAL;
346 }
347
348 /* find token length */
349 for (n = 0; str[n] != 0 && !isspace(str[n]); n++);
350
351 /* match token */
352 if (spl_debug_token2mask(&t, str, n, is_subsys) != 0)
353 return -EINVAL;
354
355 matched = 1;
356 if (op == '-')
357 m &= ~t;
358 else
359 m |= t;
360
361 str += n;
362 }
363
364 if (!matched)
365 return -EINVAL;
366
367 *mask = m;
368 return 0;
369 }
370
371 static void
372 spl_debug_dumplog_internal(dumplog_priv_t *dp)
373 {
374 void *journal_info;
375
376 journal_info = current->journal_info;
377 current->journal_info = NULL;
378
379 snprintf(spl_debug_file_name, sizeof(spl_debug_file_path) - 1,
380 "%s.%ld.%ld", spl_debug_file_path,
381 get_seconds(), (long)dp->dp_pid);
382 printk("SPL: Dumping log to %s\n", spl_debug_file_name);
383 spl_debug_dump_all_pages(dp, spl_debug_file_name);
384
385 current->journal_info = journal_info;
386 }
387
388 static int
389 spl_debug_dumplog_thread(void *arg)
390 {
391 dumplog_priv_t *dp = (dumplog_priv_t *)arg;
392
393 spl_debug_dumplog_internal(dp);
394 atomic_set(&dp->dp_done, 1);
395 wake_up(&dp->dp_waitq);
396 complete_and_exit(NULL, 0);
397
398 return 0; /* Unreachable */
399 }
400
401 /* When flag is set do not use a new thread for the debug dump */
402 int
403 spl_debug_dumplog(int flags)
404 {
405 struct task_struct *tsk;
406 dumplog_priv_t dp;
407
408 init_waitqueue_head(&dp.dp_waitq);
409 dp.dp_pid = current->pid;
410 dp.dp_flags = flags;
411 atomic_set(&dp.dp_done, 0);
412
413 if (dp.dp_flags & DL_NOTHREAD) {
414 spl_debug_dumplog_internal(&dp);
415 } else {
416
417 tsk = kthread_create(spl_debug_dumplog_thread,(void *)&dp,"spl_debug");
418 if (tsk == NULL)
419 return -ENOMEM;
420
421 wake_up_process(tsk);
422 wait_event(dp.dp_waitq, atomic_read(&dp.dp_done));
423 }
424
425 return 0;
426 }
427 EXPORT_SYMBOL(spl_debug_dumplog);
428
429 static char *
430 trace_get_console_buffer(void)
431 {
432 int cpu = get_cpu();
433 int idx;
434
435 if (in_irq()) {
436 idx = 0;
437 } else if (in_softirq()) {
438 idx = 1;
439 } else {
440 idx = 2;
441 }
442
443 return trace_console_buffers[cpu][idx];
444 }
445
446 static void
447 trace_put_console_buffer(char *buffer)
448 {
449 put_cpu();
450 }
451
452 static int
453 trace_lock_tcd(struct trace_cpu_data *tcd)
454 {
455 __ASSERT(tcd->tcd_type < TCD_TYPE_MAX);
456
457 spin_lock_irqsave(&tcd->tcd_lock, tcd->tcd_lock_flags);
458
459 return 1;
460 }
461
462 static void
463 trace_unlock_tcd(struct trace_cpu_data *tcd)
464 {
465 __ASSERT(tcd->tcd_type < TCD_TYPE_MAX);
466
467 spin_unlock_irqrestore(&tcd->tcd_lock, tcd->tcd_lock_flags);
468 }
469
470 static struct trace_cpu_data *
471 trace_get_tcd(void)
472 {
473 int cpu;
474 struct trace_cpu_data *tcd;
475
476 cpu = get_cpu();
477 if (in_irq())
478 tcd = &(*trace_data[TCD_TYPE_IRQ])[cpu].tcd;
479 else if (in_softirq())
480 tcd = &(*trace_data[TCD_TYPE_SOFTIRQ])[cpu].tcd;
481 else
482 tcd = &(*trace_data[TCD_TYPE_PROC])[cpu].tcd;
483
484 trace_lock_tcd(tcd);
485
486 return tcd;
487 }
488
489 static void
490 trace_put_tcd (struct trace_cpu_data *tcd)
491 {
492 trace_unlock_tcd(tcd);
493
494 put_cpu();
495 }
496
497 static void
498 trace_set_debug_header(struct spl_debug_header *header, int subsys,
499 int mask, const int line, unsigned long stack)
500 {
501 struct timeval tv;
502
503 do_gettimeofday(&tv);
504
505 header->ph_subsys = subsys;
506 header->ph_mask = mask;
507 header->ph_cpu_id = smp_processor_id();
508 header->ph_sec = (__u32)tv.tv_sec;
509 header->ph_usec = tv.tv_usec;
510 header->ph_stack = stack;
511 header->ph_pid = current->pid;
512 header->ph_line_num = line;
513
514 return;
515 }
516
517 static void
518 trace_print_to_console(struct spl_debug_header *hdr, int mask, const char *buf,
519 int len, const char *file, const char *fn)
520 {
521 char *prefix = "SPL", *ptype = NULL;
522
523 if ((mask & SD_EMERG) != 0) {
524 prefix = "SPLError";
525 ptype = KERN_EMERG;
526 } else if ((mask & SD_ERROR) != 0) {
527 prefix = "SPLError";
528 ptype = KERN_ERR;
529 } else if ((mask & SD_WARNING) != 0) {
530 prefix = "SPL";
531 ptype = KERN_WARNING;
532 } else if ((mask & (SD_CONSOLE | spl_debug_printk)) != 0) {
533 prefix = "SPL";
534 ptype = KERN_INFO;
535 }
536
537 if ((mask & SD_CONSOLE) != 0) {
538 printk("%s%s: %.*s", ptype, prefix, len, buf);
539 } else {
540 printk("%s%s: %d:%d:(%s:%d:%s()) %.*s", ptype, prefix,
541 hdr->ph_pid, hdr->ph_stack, file,
542 hdr->ph_line_num, fn, len, buf);
543 }
544
545 return;
546 }
547
548 static int
549 trace_max_debug_mb(void)
550 {
551 return MAX(512, ((num_physpages >> (20 - PAGE_SHIFT)) * 80) / 100);
552 }
553
554 static struct trace_page *
555 tage_alloc(int gfp)
556 {
557 struct page *page;
558 struct trace_page *tage;
559
560 page = alloc_pages(gfp | __GFP_NOWARN, 0);
561 if (page == NULL)
562 return NULL;
563
564 tage = kmalloc(sizeof(*tage), gfp);
565 if (tage == NULL) {
566 __free_pages(page, 0);
567 return NULL;
568 }
569
570 tage->page = page;
571 atomic_inc(&trace_tage_allocated);
572
573 return tage;
574 }
575
576 static void
577 tage_free(struct trace_page *tage)
578 {
579 __ASSERT(tage != NULL);
580 __ASSERT(tage->page != NULL);
581
582 __free_pages(tage->page, 0);
583 kfree(tage);
584 atomic_dec(&trace_tage_allocated);
585 }
586
587 static struct trace_page *
588 tage_from_list(struct list_head *list)
589 {
590 return list_entry(list, struct trace_page, linkage);
591 }
592
593 static void
594 tage_to_tail(struct trace_page *tage, struct list_head *queue)
595 {
596 __ASSERT(tage != NULL);
597 __ASSERT(queue != NULL);
598
599 list_move_tail(&tage->linkage, queue);
600 }
601
602 /* try to return a page that has 'len' bytes left at the end */
603 static struct trace_page *
604 trace_get_tage_try(struct trace_cpu_data *tcd, unsigned long len)
605 {
606 struct trace_page *tage;
607
608 if (tcd->tcd_cur_pages > 0) {
609 __ASSERT(!list_empty(&tcd->tcd_pages));
610 tage = tage_from_list(tcd->tcd_pages.prev);
611 if (tage->used + len <= PAGE_SIZE)
612 return tage;
613 }
614
615 if (tcd->tcd_cur_pages < tcd->tcd_max_pages) {
616 if (tcd->tcd_cur_stock_pages > 0) {
617 tage = tage_from_list(tcd->tcd_stock_pages.prev);
618 tcd->tcd_cur_stock_pages--;
619 list_del_init(&tage->linkage);
620 } else {
621 tage = tage_alloc(GFP_ATOMIC);
622 if (tage == NULL) {
623 printk(KERN_WARNING
624 "failure to allocate a tage (%ld)\n",
625 tcd->tcd_cur_pages);
626 return NULL;
627 }
628 }
629
630 tage->used = 0;
631 tage->cpu = smp_processor_id();
632 tage->type = tcd->tcd_type;
633 list_add_tail(&tage->linkage, &tcd->tcd_pages);
634 tcd->tcd_cur_pages++;
635
636 return tage;
637 }
638
639 return NULL;
640 }
641
642 /* return a page that has 'len' bytes left at the end */
643 static struct trace_page *
644 trace_get_tage(struct trace_cpu_data *tcd, unsigned long len)
645 {
646 struct trace_page *tage;
647
648 __ASSERT(len <= PAGE_SIZE);
649
650 tage = trace_get_tage_try(tcd, len);
651 if (tage)
652 return tage;
653
654 if (tcd->tcd_cur_pages > 0) {
655 tage = tage_from_list(tcd->tcd_pages.next);
656 tage->used = 0;
657 tage_to_tail(tage, &tcd->tcd_pages);
658 }
659
660 return tage;
661 }
662
663 int
664 spl_debug_msg(void *arg, int subsys, int mask, const char *file,
665 const char *fn, const int line, const char *format, ...)
666 {
667 spl_debug_limit_state_t *cdls = arg;
668 struct trace_cpu_data *tcd = NULL;
669 struct spl_debug_header header = { 0, };
670 struct trace_page *tage;
671 /* string_buf is used only if tcd != NULL, and is always set then */
672 char *string_buf = NULL;
673 char *debug_buf;
674 int known_size;
675 int needed = 85; /* average message length */
676 int max_nob;
677 va_list ap;
678 int i;
679
680 if (subsys == 0)
681 subsys = SS_DEBUG_SUBSYS;
682
683 if (mask == 0)
684 mask = SD_EMERG;
685
686 if (strchr(file, '/'))
687 file = strrchr(file, '/') + 1;
688
689 trace_set_debug_header(&header, subsys, mask, line, 0);
690
691 tcd = trace_get_tcd();
692 if (tcd == NULL)
693 goto console;
694
695 if (tcd->tcd_shutting_down) {
696 trace_put_tcd(tcd);
697 tcd = NULL;
698 goto console;
699 }
700
701 known_size = strlen(file) + 1;
702 if (fn)
703 known_size += strlen(fn) + 1;
704
705 if (spl_debug_binary)
706 known_size += sizeof(header);
707
708 /* '2' used because vsnprintf returns real size required for output
709 * _without_ terminating NULL. */
710 for (i = 0; i < 2; i++) {
711 tage = trace_get_tage(tcd, needed + known_size + 1);
712 if (tage == NULL) {
713 if (needed + known_size > PAGE_SIZE)
714 mask |= SD_ERROR;
715
716 trace_put_tcd(tcd);
717 tcd = NULL;
718 goto console;
719 }
720
721 string_buf = (char *)page_address(tage->page) +
722 tage->used + known_size;
723
724 max_nob = PAGE_SIZE - tage->used - known_size;
725 if (max_nob <= 0) {
726 printk(KERN_EMERG "negative max_nob: %i\n", max_nob);
727 mask |= SD_ERROR;
728 trace_put_tcd(tcd);
729 tcd = NULL;
730 goto console;
731 }
732
733 needed = 0;
734 if (format) {
735 va_start(ap, format);
736 needed += vsnprintf(string_buf, max_nob, format, ap);
737 va_end(ap);
738 }
739
740 if (needed < max_nob)
741 break;
742 }
743
744 header.ph_len = known_size + needed;
745 debug_buf = (char *)page_address(tage->page) + tage->used;
746
747 if (spl_debug_binary) {
748 memcpy(debug_buf, &header, sizeof(header));
749 tage->used += sizeof(header);
750 debug_buf += sizeof(header);
751 }
752
753 strcpy(debug_buf, file);
754 tage->used += strlen(file) + 1;
755 debug_buf += strlen(file) + 1;
756
757 if (fn) {
758 strcpy(debug_buf, fn);
759 tage->used += strlen(fn) + 1;
760 debug_buf += strlen(fn) + 1;
761 }
762
763 __ASSERT(debug_buf == string_buf);
764
765 tage->used += needed;
766 __ASSERT (tage->used <= PAGE_SIZE);
767
768 console:
769 if ((mask & spl_debug_printk) == 0) {
770 /* no console output requested */
771 if (tcd != NULL)
772 trace_put_tcd(tcd);
773 return 1;
774 }
775
776 if (cdls != NULL) {
777 if (spl_console_ratelimit && cdls->cdls_next != 0 &&
778 !time_before(cdls->cdls_next, jiffies)) {
779 /* skipping a console message */
780 cdls->cdls_count++;
781 if (tcd != NULL)
782 trace_put_tcd(tcd);
783 return 1;
784 }
785
786 if (time_before(cdls->cdls_next + spl_console_max_delay +
787 (10 * HZ), jiffies)) {
788 /* last timeout was a long time ago */
789 cdls->cdls_delay /= spl_console_backoff * 4;
790 } else {
791 cdls->cdls_delay *= spl_console_backoff;
792
793 if (cdls->cdls_delay < spl_console_min_delay)
794 cdls->cdls_delay = spl_console_min_delay;
795 else if (cdls->cdls_delay > spl_console_max_delay)
796 cdls->cdls_delay = spl_console_max_delay;
797 }
798
799 /* ensure cdls_next is never zero after it's been seen */
800 cdls->cdls_next = (jiffies + cdls->cdls_delay) | 1;
801 }
802
803 if (tcd != NULL) {
804 trace_print_to_console(&header, mask, string_buf, needed, file, fn);
805 trace_put_tcd(tcd);
806 } else {
807 string_buf = trace_get_console_buffer();
808
809 needed = 0;
810 if (format != NULL) {
811 va_start(ap, format);
812 needed += vsnprintf(string_buf,
813 TRACE_CONSOLE_BUFFER_SIZE, format, ap);
814 va_end(ap);
815 }
816 trace_print_to_console(&header, mask,
817 string_buf, needed, file, fn);
818
819 trace_put_console_buffer(string_buf);
820 }
821
822 if (cdls != NULL && cdls->cdls_count != 0) {
823 string_buf = trace_get_console_buffer();
824
825 needed = snprintf(string_buf, TRACE_CONSOLE_BUFFER_SIZE,
826 "Skipped %d previous similar message%s\n",
827 cdls->cdls_count, (cdls->cdls_count > 1) ? "s" : "");
828
829 trace_print_to_console(&header, mask,
830 string_buf, needed, file, fn);
831
832 trace_put_console_buffer(string_buf);
833 cdls->cdls_count = 0;
834 }
835
836 return 0;
837 }
838 EXPORT_SYMBOL(spl_debug_msg);
839
840 /* Do the collect_pages job on a single CPU: assumes that all other
841 * CPUs have been stopped during a panic. If this isn't true for
842 * some arch, this will have to be implemented separately in each arch.
843 */
844 static void
845 collect_pages_from_single_cpu(struct page_collection *pc)
846 {
847 struct trace_cpu_data *tcd;
848 int i, j;
849
850 tcd_for_each(tcd, i, j) {
851 list_splice_init(&tcd->tcd_pages, &pc->pc_pages);
852 tcd->tcd_cur_pages = 0;
853 }
854 }
855
856 static void
857 collect_pages_on_all_cpus(struct page_collection *pc)
858 {
859 struct trace_cpu_data *tcd;
860 int i, cpu;
861
862 spin_lock(&pc->pc_lock);
863 for_each_possible_cpu(cpu) {
864 tcd_for_each_type_lock(tcd, i, cpu) {
865 list_splice_init(&tcd->tcd_pages, &pc->pc_pages);
866 tcd->tcd_cur_pages = 0;
867 }
868 }
869 spin_unlock(&pc->pc_lock);
870 }
871
872 static void
873 collect_pages(dumplog_priv_t *dp, struct page_collection *pc)
874 {
875 INIT_LIST_HEAD(&pc->pc_pages);
876
877 if (spl_panic_in_progress || dp->dp_flags & DL_SINGLE_CPU)
878 collect_pages_from_single_cpu(pc);
879 else
880 collect_pages_on_all_cpus(pc);
881 }
882
883 static void
884 put_pages_back_on_all_cpus(struct page_collection *pc)
885 {
886 struct trace_cpu_data *tcd;
887 struct list_head *cur_head;
888 struct trace_page *tage;
889 struct trace_page *tmp;
890 int i, cpu;
891
892 spin_lock(&pc->pc_lock);
893
894 for_each_possible_cpu(cpu) {
895 tcd_for_each_type_lock(tcd, i, cpu) {
896 cur_head = tcd->tcd_pages.next;
897
898 list_for_each_entry_safe(tage, tmp, &pc->pc_pages,
899 linkage) {
900 if (tage->cpu != cpu || tage->type != i)
901 continue;
902
903 tage_to_tail(tage, cur_head);
904 tcd->tcd_cur_pages++;
905 }
906 }
907 }
908
909 spin_unlock(&pc->pc_lock);
910 }
911
912 static void
913 put_pages_back(struct page_collection *pc)
914 {
915 if (!spl_panic_in_progress)
916 put_pages_back_on_all_cpus(pc);
917 }
918
919 static int
920 spl_debug_dump_all_pages(dumplog_priv_t *dp, char *filename)
921 {
922 struct page_collection pc;
923 struct file *filp;
924 struct trace_page *tage;
925 struct trace_page *tmp;
926 mm_segment_t oldfs;
927 int rc = 0;
928
929 down_write(&trace_sem);
930
931 filp = spl_filp_open(filename, O_CREAT|O_EXCL|O_WRONLY|O_LARGEFILE,
932 0600, &rc);
933 if (filp == NULL) {
934 if (rc != -EEXIST)
935 printk(KERN_ERR "SPL: Can't open %s for dump: %d\n",
936 filename, rc);
937 goto out;
938 }
939
940 spin_lock_init(&pc.pc_lock);
941 collect_pages(dp, &pc);
942 if (list_empty(&pc.pc_pages)) {
943 rc = 0;
944 goto close;
945 }
946
947 oldfs = get_fs();
948 set_fs(get_ds());
949
950 list_for_each_entry_safe(tage, tmp, &pc.pc_pages, linkage) {
951 rc = spl_filp_write(filp, page_address(tage->page),
952 tage->used, spl_filp_poff(filp));
953 if (rc != (int)tage->used) {
954 printk(KERN_WARNING "SPL: Wanted to write %u "
955 "but wrote %d\n", tage->used, rc);
956 put_pages_back(&pc);
957 __ASSERT(list_empty(&pc.pc_pages));
958 break;
959 }
960 list_del(&tage->linkage);
961 tage_free(tage);
962 }
963
964 set_fs(oldfs);
965
966 rc = spl_filp_fsync(filp, 1);
967 if (rc)
968 printk(KERN_ERR "SPL: Unable to sync: %d\n", rc);
969 close:
970 spl_filp_close(filp);
971 out:
972 up_write(&trace_sem);
973
974 return rc;
975 }
976
977 static void
978 spl_debug_flush_pages(void)
979 {
980 dumplog_priv_t dp;
981 struct page_collection pc;
982 struct trace_page *tage;
983 struct trace_page *tmp;
984
985 spin_lock_init(&pc.pc_lock);
986 init_waitqueue_head(&dp.dp_waitq);
987 dp.dp_pid = current->pid;
988 dp.dp_flags = 0;
989 atomic_set(&dp.dp_done, 0);
990
991 collect_pages(&dp, &pc);
992 list_for_each_entry_safe(tage, tmp, &pc.pc_pages, linkage) {
993 list_del(&tage->linkage);
994 tage_free(tage);
995 }
996 }
997
998 unsigned long
999 spl_debug_set_mask(unsigned long mask) {
1000 spl_debug_mask = mask;
1001 return 0;
1002 }
1003 EXPORT_SYMBOL(spl_debug_set_mask);
1004
1005 unsigned long
1006 spl_debug_get_mask(void) {
1007 return spl_debug_mask;
1008 }
1009 EXPORT_SYMBOL(spl_debug_get_mask);
1010
1011 unsigned long
1012 spl_debug_set_subsys(unsigned long subsys) {
1013 spl_debug_subsys = subsys;
1014 return 0;
1015 }
1016 EXPORT_SYMBOL(spl_debug_set_subsys);
1017
1018 unsigned long
1019 spl_debug_get_subsys(void) {
1020 return spl_debug_subsys;
1021 }
1022 EXPORT_SYMBOL(spl_debug_get_subsys);
1023
1024 int
1025 spl_debug_set_mb(int mb)
1026 {
1027 int i, j, pages;
1028 int limit = trace_max_debug_mb();
1029 struct trace_cpu_data *tcd;
1030
1031 if (mb < num_possible_cpus()) {
1032 printk(KERN_ERR "SPL: Refusing to set debug buffer size to "
1033 "%dMB - lower limit is %d\n", mb, num_possible_cpus());
1034 return -EINVAL;
1035 }
1036
1037 if (mb > limit) {
1038 printk(KERN_ERR "SPL: Refusing to set debug buffer size to "
1039 "%dMB - upper limit is %d\n", mb, limit);
1040 return -EINVAL;
1041 }
1042
1043 mb /= num_possible_cpus();
1044 pages = mb << (20 - PAGE_SHIFT);
1045
1046 down_write(&trace_sem);
1047
1048 tcd_for_each(tcd, i, j)
1049 tcd->tcd_max_pages = (pages * tcd->tcd_pages_factor) / 100;
1050
1051 up_write(&trace_sem);
1052
1053 return 0;
1054 }
1055 EXPORT_SYMBOL(spl_debug_set_mb);
1056
1057 int
1058 spl_debug_get_mb(void)
1059 {
1060 int i, j;
1061 struct trace_cpu_data *tcd;
1062 int total_pages = 0;
1063
1064 down_read(&trace_sem);
1065
1066 tcd_for_each(tcd, i, j)
1067 total_pages += tcd->tcd_max_pages;
1068
1069 up_read(&trace_sem);
1070
1071 return (total_pages >> (20 - PAGE_SHIFT)) + 1;
1072 }
1073 EXPORT_SYMBOL(spl_debug_get_mb);
1074
1075 void spl_debug_dumpstack(struct task_struct *tsk)
1076 {
1077 extern void show_task(struct task_struct *);
1078
1079 if (tsk == NULL)
1080 tsk = current;
1081
1082 printk("SPL: Showing stack for process %d\n", tsk->pid);
1083 dump_stack();
1084 }
1085 EXPORT_SYMBOL(spl_debug_dumpstack);
1086
1087 void spl_debug_bug(char *file, const char *func, const int line, int flags)
1088 {
1089 spl_debug_catastrophe = 1;
1090 spl_debug_msg(NULL, 0, SD_EMERG, file, func, line, "SPL PANIC\n");
1091
1092 if (in_interrupt())
1093 panic("SPL PANIC in interrupt.\n");
1094
1095 if (in_atomic() || irqs_disabled())
1096 flags |= DL_NOTHREAD;
1097
1098 /* Ensure all debug pages and dumped by current cpu */
1099 if (spl_debug_panic_on_bug)
1100 spl_panic_in_progress = 1;
1101
1102 spl_debug_dumpstack(NULL);
1103 spl_debug_dumplog(flags);
1104
1105 if (spl_debug_panic_on_bug)
1106 panic("SPL PANIC");
1107
1108 set_task_state(current, TASK_UNINTERRUPTIBLE);
1109 while (1)
1110 schedule();
1111 }
1112 EXPORT_SYMBOL(spl_debug_bug);
1113
1114 int
1115 spl_debug_clear_buffer(void)
1116 {
1117 spl_debug_flush_pages();
1118 return 0;
1119 }
1120 EXPORT_SYMBOL(spl_debug_clear_buffer);
1121
1122 int
1123 spl_debug_mark_buffer(char *text)
1124 {
1125 SDEBUG(SD_WARNING, "*************************************\n");
1126 SDEBUG(SD_WARNING, "DEBUG MARKER: %s\n", text);
1127 SDEBUG(SD_WARNING, "*************************************\n");
1128
1129 return 0;
1130 }
1131 EXPORT_SYMBOL(spl_debug_mark_buffer);
1132
1133 static int
1134 trace_init(int max_pages)
1135 {
1136 struct trace_cpu_data *tcd;
1137 int i, j;
1138
1139 init_rwsem(&trace_sem);
1140
1141 /* initialize trace_data */
1142 memset(trace_data, 0, sizeof(trace_data));
1143 for (i = 0; i < TCD_TYPE_MAX; i++) {
1144 trace_data[i] = kmalloc(sizeof(union trace_data_union) *
1145 NR_CPUS, GFP_KERNEL);
1146 if (trace_data[i] == NULL)
1147 goto out;
1148 }
1149
1150 tcd_for_each(tcd, i, j) {
1151 spin_lock_init(&tcd->tcd_lock);
1152 tcd->tcd_pages_factor = pages_factor[i];
1153 tcd->tcd_type = i;
1154 tcd->tcd_cpu = j;
1155 INIT_LIST_HEAD(&tcd->tcd_pages);
1156 INIT_LIST_HEAD(&tcd->tcd_stock_pages);
1157 tcd->tcd_cur_pages = 0;
1158 tcd->tcd_cur_stock_pages = 0;
1159 tcd->tcd_max_pages = (max_pages * pages_factor[i]) / 100;
1160 tcd->tcd_shutting_down = 0;
1161 }
1162
1163 for (i = 0; i < num_possible_cpus(); i++) {
1164 for (j = 0; j < 3; j++) {
1165 trace_console_buffers[i][j] =
1166 kmalloc(TRACE_CONSOLE_BUFFER_SIZE,
1167 GFP_KERNEL);
1168
1169 if (trace_console_buffers[i][j] == NULL)
1170 goto out;
1171 }
1172 }
1173
1174 return 0;
1175 out:
1176 trace_fini();
1177 printk(KERN_ERR "SPL: Insufficient memory for debug logs\n");
1178 return -ENOMEM;
1179 }
1180
1181 int
1182 spl_debug_init(void)
1183 {
1184 int rc, max = spl_debug_mb;
1185
1186 spl_console_max_delay = SPL_DEFAULT_MAX_DELAY;
1187 spl_console_min_delay = SPL_DEFAULT_MIN_DELAY;
1188
1189 /* If spl_debug_mb is set to an invalid value or uninitialized
1190 * then just make the total buffers smp_num_cpus TCD_MAX_PAGES */
1191 if (max > (num_physpages >> (20 - 2 - PAGE_SHIFT)) / 5 ||
1192 max >= 512 || max < 0) {
1193 max = TCD_MAX_PAGES;
1194 } else {
1195 max = (max / num_online_cpus()) << (20 - PAGE_SHIFT);
1196 }
1197
1198 rc = trace_init(max);
1199 if (rc)
1200 return rc;
1201
1202 return rc;
1203 }
1204
1205 static void
1206 trace_cleanup_on_all_cpus(void)
1207 {
1208 struct trace_cpu_data *tcd;
1209 struct trace_page *tage;
1210 struct trace_page *tmp;
1211 int i, cpu;
1212
1213 for_each_possible_cpu(cpu) {
1214 tcd_for_each_type_lock(tcd, i, cpu) {
1215 tcd->tcd_shutting_down = 1;
1216
1217 list_for_each_entry_safe(tage, tmp, &tcd->tcd_pages,
1218 linkage) {
1219 list_del(&tage->linkage);
1220 tage_free(tage);
1221 }
1222 tcd->tcd_cur_pages = 0;
1223 }
1224 }
1225 }
1226
1227 static void
1228 trace_fini(void)
1229 {
1230 int i, j;
1231
1232 trace_cleanup_on_all_cpus();
1233
1234 for (i = 0; i < num_possible_cpus(); i++) {
1235 for (j = 0; j < 3; j++) {
1236 if (trace_console_buffers[i][j] != NULL) {
1237 kfree(trace_console_buffers[i][j]);
1238 trace_console_buffers[i][j] = NULL;
1239 }
1240 }
1241 }
1242
1243 for (i = 0; i < TCD_TYPE_MAX && trace_data[i] != NULL; i++) {
1244 kfree(trace_data[i]);
1245 trace_data[i] = NULL;
1246 }
1247 }
1248
1249 void
1250 spl_debug_fini(void)
1251 {
1252 trace_fini();
1253 }
1254
1255 #endif /* DEBUG_LOG */