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