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