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