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