libcfs/libcfs/debug.c

   1 /*
   2  * GPL HEADER START
   3  *
   4  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   5  *
   6  * This program is free software; you can redistribute it and/or modify
   7  * it under the terms of the GNU General Public License version 2 only,
   8  * as published by the Free Software Foundation.
   9  *
  10  * This program is distributed in the hope that it will be useful, but
  11  * WITHOUT ANY WARRANTY; without even the implied warranty of
  12  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  13  * General Public License version 2 for more details (a copy is included
  14  * in the LICENSE file that accompanied this code).
  15  *
  16  * You should have received a copy of the GNU General Public License
  17  * version 2 along with this program; If not, see
  18  * http://www.gnu.org/licenses/gpl-2.0.html
  19  *
  20  * GPL HEADER END
  21  */
  22 /*
  23  * Copyright (c) 2008, 2010, Oracle and/or its affiliates. All rights reserved.
  24  * Use is subject to license terms.
  25  *
  26  * Copyright (c) 2011, 2017, Intel Corporation.
  27  */
  28 /*
  29  * This file is part of Lustre, http://www.lustre.org/
  30  * Lustre is a trademark of Sun Microsystems, Inc.
  31  *
  32  * libcfs/libcfs/debug.c
  33  *
  34  * Author: Phil Schwan <phil@clusterfs.com>
  35  *
  36  */
  37
  38 # define DEBUG_SUBSYSTEM S_LNET
  39
  40 #include <linux/kthread.h>
  41 #include <libcfs/libcfs.h>
  42 #include "tracefile.h"
  43
  44 static char debug_file_name[1024];
  45
  46 unsigned int libcfs_subsystem_debug = ~0;
  47 module_param(libcfs_subsystem_debug, int, 0644);
  48 MODULE_PARM_DESC(libcfs_subsystem_debug, "Lustre kernel debug subsystem mask");
  49 EXPORT_SYMBOL(libcfs_subsystem_debug);
  50
  51 unsigned int libcfs_debug = (D_CANTMASK |
  52                              D_NETERROR | D_HA | D_CONFIG | D_IOCTL | D_LFSCK);
  53 module_param(libcfs_debug, int, 0644);
  54 MODULE_PARM_DESC(libcfs_debug, "Lustre kernel debug mask");
  55 EXPORT_SYMBOL(libcfs_debug);
  56
  57 static int libcfs_param_debug_mb_set(const char *val,
  58                                      cfs_kernel_param_arg_t *kp)
  59 {
  60         int rc;
  61         unsigned int num;
  62
  63         rc = kstrtouint(val, 0, &num);
  64         if (rc < 0)
  65                 return rc;
  66
  67 /*
  68  * RHEL6 does not support any kind of locking so we have to provide
  69  * our own
  70  */
  71 #if !defined(HAVE_MODULE_PARAM_LOCKING) && !defined(HAVE_KERNEL_PARAM_LOCK)
  72         kernel_param_lock(THIS_MODULE);
  73 #endif
  74         if (!*((unsigned int *)kp->arg)) {
  75                 *((unsigned int *)kp->arg) = num;
  76
  77 #if !defined(HAVE_MODULE_PARAM_LOCKING) && !defined(HAVE_KERNEL_PARAM_LOCK)
  78                 kernel_param_unlock(THIS_MODULE);
  79 #endif
  80                 return 0;
  81         }
  82
  83         rc = cfs_trace_set_debug_mb(num);
  84
  85         if (!rc)
  86                 *((unsigned int *)kp->arg) = cfs_trace_get_debug_mb();
  87
  88 #if !defined(HAVE_MODULE_PARAM_LOCKING) && !defined(HAVE_KERNEL_PARAM_LOCK)
  89         kernel_param_unlock(THIS_MODULE);
  90 #endif
  91         return rc;
  92 }
  93
  94 /* While debug_mb setting look like unsigned int, in fact
  95  * it needs quite a bunch of extra processing, so we define special
  96  * debug_mb parameter type with corresponding methods to handle this case
  97  */
  98 static struct kernel_param_ops param_ops_debug_mb = {
  99         .set = libcfs_param_debug_mb_set,
 100         .get = param_get_uint,
 101 };
 102
 103 #define param_check_debug_mb(name, p) \
 104                 __param_check(name, p, unsigned int)
 105
 106 static unsigned int libcfs_debug_mb;
 107 #ifdef HAVE_KERNEL_PARAM_OPS
 108 module_param(libcfs_debug_mb, debug_mb, 0644);
 109 #else
 110 module_param_call(libcfs_debug_mb, libcfs_param_debug_mb_set, param_get_uint,
 111                   &param_ops_debug_mb, 0644);
 112 #endif
 113 MODULE_PARM_DESC(libcfs_debug_mb, "Total debug buffer size.");
 114
 115 unsigned int libcfs_printk = D_CANTMASK;
 116 module_param(libcfs_printk, uint, 0644);
 117 MODULE_PARM_DESC(libcfs_printk, "Lustre kernel debug console mask");
 118
 119 unsigned int libcfs_console_ratelimit = 1;
 120 module_param(libcfs_console_ratelimit, uint, 0644);
 121 MODULE_PARM_DESC(libcfs_console_ratelimit, "Lustre kernel debug console ratelimit (0 to disable)");
 122
 123 static int param_set_delay_minmax(const char *val,
 124                                   cfs_kernel_param_arg_t *kp,
 125                                   long min, long max)
 126 {
 127         long d;
 128         int sec;
 129         int rc;
 130
 131         rc = kstrtoint(val, 0, &sec);
 132         if (rc)
 133                 return -EINVAL;
 134
 135         /* The sysfs setting is in centiseconds */
 136         d = cfs_time_seconds(sec) / 100;
 137         if (d < min || d > max)
 138                 return -EINVAL;
 139
 140         *((unsigned int *)kp->arg) = d;
 141
 142         return 0;
 143 }
 144
 145 static int param_get_delay(char *buffer, cfs_kernel_param_arg_t *kp)
 146 {
 147         unsigned int d = *(unsigned int *)kp->arg;
 148
 149         return sprintf(buffer, "%u", (unsigned int)cfs_duration_sec(d * 100));
 150 }
 151
 152 unsigned int libcfs_console_max_delay;
 153 unsigned int libcfs_console_min_delay;
 154
 155 static int param_set_console_max_delay(const char *val,
 156                                        cfs_kernel_param_arg_t *kp)
 157 {
 158         return param_set_delay_minmax(val, kp,
 159                                       libcfs_console_min_delay, INT_MAX);
 160 }
 161
 162 static struct kernel_param_ops param_ops_console_max_delay = {
 163         .set = param_set_console_max_delay,
 164         .get = param_get_delay,
 165 };
 166
 167 #define param_check_console_max_delay(name, p) \
 168                 __param_check(name, p, unsigned int)
 169
 170 #ifdef HAVE_KERNEL_PARAM_OPS
 171 module_param(libcfs_console_max_delay, console_max_delay, 0644);
 172 #else
 173 module_param_call(libcfs_console_max_delay, param_set_console_max_delay,
 174                   param_get_delay, &param_ops_console_max_delay, 0644);
 175 #endif
 176 MODULE_PARM_DESC(libcfs_console_max_delay, "Lustre kernel debug console max delay (jiffies)");
 177
 178 static int param_set_console_min_delay(const char *val,
 179                                        cfs_kernel_param_arg_t *kp)
 180 {
 181         return param_set_delay_minmax(val, kp,
 182                                       1, libcfs_console_max_delay);
 183 }
 184
 185 static struct kernel_param_ops param_ops_console_min_delay = {
 186         .set = param_set_console_min_delay,
 187         .get = param_get_delay,
 188 };
 189
 190 #define param_check_console_min_delay(name, p) \
 191                 __param_check(name, p, unsigned int)
 192
 193 #ifdef HAVE_KERNEL_PARAM_OPS
 194 module_param(libcfs_console_min_delay, console_min_delay, 0644);
 195 #else
 196 module_param_call(libcfs_console_min_delay, param_set_console_min_delay,
 197                   param_get_delay, &param_ops_console_min_delay, 0644);
 198 #endif
 199 MODULE_PARM_DESC(libcfs_console_min_delay, "Lustre kernel debug console min delay (jiffies)");
 200
 201 static int param_set_uint_minmax(const char *val,
 202                                  cfs_kernel_param_arg_t *kp,
 203                                  unsigned int min, unsigned int max)
 204 {
 205         unsigned int num;
 206         int ret;
 207
 208         if (!val)
 209                 return -EINVAL;
 210
 211         ret = kstrtouint(val, 0, &num);
 212         if (ret < 0 || num < min || num > max)
 213                 return -EINVAL;
 214
 215         *((unsigned int *)kp->arg) = num;
 216         return 0;
 217 }
 218
 219 static int param_set_uintpos(const char *val,
 220                              cfs_kernel_param_arg_t *kp)
 221 {
 222         return param_set_uint_minmax(val, kp, 1, -1);
 223 }
 224
 225 static struct kernel_param_ops param_ops_uintpos = {
 226         .set = param_set_uintpos,
 227         .get = param_get_uint,
 228 };
 229
 230 #define param_check_uintpos(name, p) \
 231                 __param_check(name, p, unsigned int)
 232
 233 unsigned int libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
 234 #ifdef HAVE_KERNEL_PARAM_OPS
 235 module_param(libcfs_console_backoff, uintpos, 0644);
 236 #else
 237 module_param_call(libcfs_console_backoff, param_set_uintpos, param_get_uint,
 238                   &param_ops_uintpos, 0644);
 239 #endif
 240 MODULE_PARM_DESC(libcfs_console_backoff, "Lustre kernel debug console backoff factor");
 241
 242 unsigned int libcfs_debug_binary = 1;
 243
 244 unsigned int libcfs_stack = 3 * THREAD_SIZE / 4;
 245 EXPORT_SYMBOL(libcfs_stack);
 246
 247 unsigned int libcfs_catastrophe;
 248 EXPORT_SYMBOL(libcfs_catastrophe);
 249
 250 unsigned int libcfs_watchdog_ratelimit = 300;
 251
 252 unsigned int libcfs_panic_on_lbug = 1;
 253 module_param(libcfs_panic_on_lbug, uint, 0644);
 254 MODULE_PARM_DESC(libcfs_panic_on_lbug, "Lustre kernel panic on LBUG");
 255
 256 atomic_t libcfs_kmemory = ATOMIC_INIT(0);
 257 EXPORT_SYMBOL(libcfs_kmemory);
 258
 259 static wait_queue_head_t debug_ctlwq;
 260
 261 char libcfs_debug_file_path_arr[PATH_MAX] = LIBCFS_DEBUG_FILE_PATH_DEFAULT;
 262 EXPORT_SYMBOL(libcfs_debug_file_path_arr);
 263
 264 /* We need to pass a pointer here, but elsewhere this must be a const */
 265 static char *libcfs_debug_file_path = LIBCFS_DEBUG_FILE_PATH_DEFAULT;
 266 module_param(libcfs_debug_file_path, charp, 0644);
 267 MODULE_PARM_DESC(libcfs_debug_file_path,
 268                  "Path for dumping debug logs, set 'NONE' to prevent log dumping");
 269
 270 int libcfs_panic_in_progress;
 271
 272 /* libcfs_debug_token2mask() expects the returned
 273  * string in lower-case */
 274 static const char *libcfs_debug_subsys2str(int subsys)
 275 {
 276         static const char *libcfs_debug_subsystems[] = LIBCFS_DEBUG_SUBSYS_NAMES;
 277
 278         if (subsys >= ARRAY_SIZE(libcfs_debug_subsystems))
 279                 return NULL;
 280
 281         return libcfs_debug_subsystems[subsys];
 282 }
 283
 284 /* libcfs_debug_token2mask() expects the returned
 285  * string in lower-case */
 286 static const char *libcfs_debug_dbg2str(int debug)
 287 {
 288         static const char *libcfs_debug_masks[] = LIBCFS_DEBUG_MASKS_NAMES;
 289
 290         if (debug >= ARRAY_SIZE(libcfs_debug_masks))
 291                 return NULL;
 292
 293         return libcfs_debug_masks[debug];
 294 }
 295
 296 int
 297 libcfs_debug_mask2str(char *str, int size, int mask, int is_subsys)
 298 {
 299         const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
 300                                                  libcfs_debug_dbg2str;
 301         int           len = 0;
 302         const char   *token;
 303         int           i;
 304
 305         if (mask == 0) {                        /* "0" */
 306                 if (size > 0)
 307                         str[0] = '0';
 308                 len = 1;
 309         } else {                                /* space-separated tokens */
 310                 for (i = 0; i < 32; i++) {
 311                         if ((mask & (1 << i)) == 0)
 312                                 continue;
 313
 314                         token = fn(i);
 315                         if (token == NULL)              /* unused bit */
 316                                 continue;
 317
 318                         if (len > 0) {                  /* separator? */
 319                                 if (len < size)
 320                                         str[len] = ' ';
 321                                 len++;
 322                         }
 323
 324                         while (*token != 0) {
 325                                 if (len < size)
 326                                         str[len] = *token;
 327                                 token++;
 328                                 len++;
 329                         }
 330                 }
 331         }
 332
 333         /* terminate 'str' */
 334         if (len < size)
 335                 str[len] = 0;
 336         else
 337                 str[size - 1] = 0;
 338
 339         return len;
 340 }
 341
 342 int
 343 libcfs_debug_str2mask(int *mask, const char *str, int is_subsys)
 344 {
 345         const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
 346                                                  libcfs_debug_dbg2str;
 347         int         m = 0;
 348         int         matched;
 349         int         n;
 350         int         t;
 351
 352         /* Allow a number for backwards compatibility */
 353
 354         for (n = strlen(str); n > 0; n--)
 355                 if (!isspace(str[n-1]))
 356                         break;
 357         matched = n;
 358
 359         if ((t = sscanf(str, "%i%n", &m, &matched)) >= 1 &&
 360             matched == n) {
 361                 /* don't print warning for lctl set_param debug=0 or -1 */
 362                 if (m != 0 && m != -1)
 363                         CWARN("You are trying to use a numerical value for the "
 364                               "mask - this will be deprecated in a future "
 365                               "release.\n");
 366                 *mask = m;
 367                 return 0;
 368         }
 369
 370         return cfs_str2mask(str, fn, mask, is_subsys ? 0 : D_CANTMASK,
 371                             0xffffffff);
 372 }
 373
 374 /**
 375  * Dump Lustre log to ::debug_file_path by calling tracefile_dump_all_pages()
 376  */
 377 void libcfs_debug_dumplog_internal(void *arg)
 378 {
 379         static time64_t last_dump_time;
 380         time64_t current_time;
 381         void *journal_info;
 382
 383         journal_info = current->journal_info;
 384         current->journal_info = NULL;
 385         current_time = ktime_get_real_seconds();
 386
 387         if (strncmp(libcfs_debug_file_path_arr, "NONE", 4) != 0 &&
 388             current_time > last_dump_time) {
 389                 last_dump_time = current_time;
 390                 snprintf(debug_file_name, sizeof(debug_file_name) - 1,
 391                          "%s.%lld.%ld", libcfs_debug_file_path_arr,
 392                          (s64)current_time, (uintptr_t)arg);
 393                 printk(KERN_ALERT "LustreError: dumping log to %s\n",
 394                        debug_file_name);
 395                 cfs_tracefile_dump_all_pages(debug_file_name);
 396                 libcfs_run_debug_log_upcall(debug_file_name);
 397         }
 398         current->journal_info = journal_info;
 399 }
 400
 401 static int libcfs_debug_dumplog_thread(void *arg)
 402 {
 403         libcfs_debug_dumplog_internal(arg);
 404         wake_up(&debug_ctlwq);
 405         return 0;
 406 }
 407
 408 void libcfs_debug_dumplog(void)
 409 {
 410         wait_queue_t wait;
 411         struct task_struct    *dumper;
 412         ENTRY;
 413
 414         /* we're being careful to ensure that the kernel thread is
 415          * able to set our state to running as it exits before we
 416          * get to schedule() */
 417         init_waitqueue_entry(&wait, current);
 418         set_current_state(TASK_INTERRUPTIBLE);
 419         add_wait_queue(&debug_ctlwq, &wait);
 420
 421         dumper = kthread_run(libcfs_debug_dumplog_thread,
 422                              (void *)(long)current_pid(),
 423                              "libcfs_debug_dumper");
 424         if (IS_ERR(dumper))
 425                 printk(KERN_ERR "LustreError: cannot start log dump thread:"
 426                        " %ld\n", PTR_ERR(dumper));
 427         else
 428                 schedule();
 429
 430         /* be sure to teardown if cfs_create_thread() failed */
 431         remove_wait_queue(&debug_ctlwq, &wait);
 432         set_current_state(TASK_RUNNING);
 433 }
 434 EXPORT_SYMBOL(libcfs_debug_dumplog);
 435
 436 int libcfs_debug_init(unsigned long bufsize)
 437 {
 438         int    rc = 0;
 439         unsigned int max = libcfs_debug_mb;
 440
 441         init_waitqueue_head(&debug_ctlwq);
 442
 443         if (libcfs_console_max_delay <= 0 || /* not set by user or */
 444             libcfs_console_min_delay <= 0 || /* set to invalid values */
 445             libcfs_console_min_delay >= libcfs_console_max_delay) {
 446                 libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
 447                 libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
 448         }
 449
 450         if (libcfs_debug_file_path != NULL) {
 451                 strlcpy(libcfs_debug_file_path_arr,
 452                         libcfs_debug_file_path,
 453                         sizeof(libcfs_debug_file_path_arr));
 454         }
 455
 456         /* If libcfs_debug_mb is set to an invalid value or uninitialized
 457          * then just make the total buffers smp_num_cpus * TCD_MAX_PAGES */
 458         if (max > cfs_trace_max_debug_mb() || max < num_possible_cpus()) {
 459                 max = TCD_MAX_PAGES;
 460         } else {
 461                 max = (max / num_possible_cpus());
 462                 max = (max << (20 - PAGE_SHIFT));
 463         }
 464
 465         rc = cfs_tracefile_init(max);
 466         if (rc)
 467                 return rc;
 468
 469         libcfs_register_panic_notifier();
 470         kernel_param_lock(THIS_MODULE);
 471         libcfs_debug_mb = cfs_trace_get_debug_mb();
 472         kernel_param_unlock(THIS_MODULE);
 473         return rc;
 474 }
 475
 476 int libcfs_debug_cleanup(void)
 477 {
 478         libcfs_unregister_panic_notifier();
 479         kernel_param_lock(THIS_MODULE);
 480         cfs_tracefile_exit();
 481         kernel_param_unlock(THIS_MODULE);
 482         return 0;
 483 }
 484
 485 int libcfs_debug_clear_buffer(void)
 486 {
 487         cfs_trace_flush_pages();
 488         return 0;
 489 }
 490
 491 /* Debug markers, although printed by S_LNET
 492  * should not be be marked as such. */
 493 #undef DEBUG_SUBSYSTEM
 494 #define DEBUG_SUBSYSTEM S_UNDEFINED
 495 int libcfs_debug_mark_buffer(const char *text)
 496 {
 497         CDEBUG(D_TRACE,"***************************************************\n");
 498         LCONSOLE(D_WARNING, "DEBUG MARKER: %s\n", text);
 499         CDEBUG(D_TRACE,"***************************************************\n");
 500
 501         return 0;
 502 }
 503 #undef DEBUG_SUBSYSTEM
 504 #define DEBUG_SUBSYSTEM S_LNET
 505
 506 long libcfs_log_return(struct libcfs_debug_msg_data *msgdata, long rc)
 507 {
 508         libcfs_debug_msg(msgdata, "Process leaving (rc=%lu : %ld : %lx)\n",
 509                          rc, rc, rc);
 510         return rc;
 511 }
 512 EXPORT_SYMBOL(libcfs_log_return);
 513
 514 void libcfs_log_goto(struct libcfs_debug_msg_data *msgdata, const char *label,
 515                      long rc)
 516 {
 517         libcfs_debug_msg(msgdata, "Process leaving via %s (rc=%lu : %ld"
 518                          " : %#lx)\n", label, rc, rc, rc);
 519 }
 520 EXPORT_SYMBOL(libcfs_log_goto);