libcfs/libcfs/posix/posix-debug.c

   1 /* -*- mode: c; c-basic-offset: 8; indent-tabs-mode: nil; -*-
   2  * vim:expandtab:shiftwidth=8:tabstop=8:
   3  *
   4  * GPL HEADER START
   5  *
   6  * DO NOT ALTER OR REMOVE COPYRIGHT NOTICES OR THIS FILE HEADER.
   7  *
   8  * This program is free software; you can redistribute it and/or modify
   9  * it under the terms of the GNU General Public License version 2 only,
  10  * as published by the Free Software Foundation.
  11  *
  12  * This program is distributed in the hope that it will be useful, but
  13  * WITHOUT ANY WARRANTY; without even the implied warranty of
  14  * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
  15  * General Public License version 2 for more details (a copy is included
  16  * in the LICENSE file that accompanied this code).
  17  *
  18  * You should have received a copy of the GNU General Public License
  19  * version 2 along with this program; If not, see
  20  * http://www.sun.com/software/products/lustre/docs/GPLv2.pdf
  21  *
  22  * Please contact Sun Microsystems, Inc., 4150 Network Circle, Santa Clara,
  23  * CA 95054 USA or visit www.sun.com if you need additional information or
  24  * have any questions.
  25  *
  26  * GPL HEADER END
  27  */
  28 /*
  29  * Copyright (c) 2008, 2010, Oracle and/or its affiliates. All rights reserved.
  30  * Use is subject to license terms.
  31  */
  32 /*
  33  * This file is part of Lustre, http://www.lustre.org/
  34  * Lustre is a trademark of Sun Microsystems, Inc.
  35  *
  36  * libcfs/libcfs/posix/posix_debug.c
  37  *
  38  * Userspace debugging.
  39  *
  40  */
  41
  42 # define DEBUG_SUBSYSTEM S_LNET
  43
  44 #include <libcfs/libcfs.h>
  45
  46 static char debug_file_name[1024];
  47
  48 #ifdef HAVE_CATAMOUNT_DATA_H
  49 #include <catamount/data.h>
  50 #include <catamount/lputs.h>
  51
  52 static char source_nid[16];
  53 /* 0 indicates no messages to console, 1 is errors, > 1 is all debug messages */
  54 static int toconsole = 1;
  55 unsigned int libcfs_console_ratelimit = 1;
  56 unsigned int libcfs_console_max_delay;
  57 unsigned int libcfs_console_min_delay;
  58 unsigned int libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
  59 #else /* !HAVE_CATAMOUNT_DATA_H */
  60 #ifdef HAVE_NETDB_H
  61 #include <sys/utsname.h>
  62 #endif /* HAVE_NETDB_H */
  63 struct utsname *tmp_utsname;
  64 static char source_nid[sizeof(tmp_utsname->nodename)];
  65 #endif /* HAVE_CATAMOUNT_DATA_H */
  66
  67 static int source_pid;
  68 int cfs_smp_processor_id = 1;
  69 char libcfs_debug_file_path[1024];
  70 FILE *debug_file_fd;
  71
  72 int portals_do_debug_dumplog(void *arg)
  73 {
  74         printf("Look in %s\n", debug_file_name);
  75         return 0;
  76 }
  77
  78
  79 void portals_debug_print(void)
  80 {
  81         return;
  82 }
  83
  84
  85 void libcfs_debug_dumplog(void)
  86 {
  87         printf("Look in %s\n", debug_file_name);
  88         return;
  89 }
  90
  91 int libcfs_debug_init(unsigned long bufsize)
  92 {
  93         char *debug_mask = NULL;
  94         char *debug_subsys = NULL;
  95         char *debug_filename;
  96
  97 #ifdef HAVE_CATAMOUNT_DATA_H
  98         char *debug_console = NULL;
  99         char *debug_ratelimit = NULL;
 100         char *debug_max_delay = NULL;
 101         char *debug_min_delay = NULL;
 102         char *debug_backoff = NULL;
 103
 104         libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
 105         libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
 106
 107         snprintf(source_nid, sizeof(source_nid) - 1, "%u", _my_pnid);
 108         source_pid = _my_pid;
 109
 110         debug_console = getenv("LIBLUSTRE_DEBUG_CONSOLE");
 111         if (debug_console != NULL) {
 112                 toconsole = strtoul(debug_console, NULL, 0);
 113                 CDEBUG(D_INFO, "set liblustre toconsole to %u\n", toconsole);
 114         }
 115         debug_ratelimit = getenv("LIBLUSTRE_DEBUG_CONSOLE_RATELIMIT");
 116         if (debug_ratelimit != NULL) {
 117                 libcfs_console_ratelimit = strtoul(debug_ratelimit, NULL, 0);
 118                 CDEBUG(D_INFO, "set liblustre console ratelimit to %u\n",
 119                                 libcfs_console_ratelimit);
 120         }
 121         debug_max_delay = getenv("LIBLUSTRE_DEBUG_CONSOLE_MAX_DELAY");
 122         if (debug_max_delay != NULL)
 123                 libcfs_console_max_delay =
 124                             cfs_time_seconds(strtoul(debug_max_delay, NULL, 0));
 125         debug_min_delay = getenv("LIBLUSTRE_DEBUG_CONSOLE_MIN_DELAY");
 126         if (debug_min_delay != NULL)
 127                 libcfs_console_min_delay =
 128                             cfs_time_seconds(strtoul(debug_min_delay, NULL, 0));
 129         if (debug_min_delay || debug_max_delay) {
 130                 if (!libcfs_console_max_delay || !libcfs_console_min_delay ||
 131                     libcfs_console_max_delay < libcfs_console_min_delay) {
 132                         libcfs_console_max_delay = CDEBUG_DEFAULT_MAX_DELAY;
 133                         libcfs_console_min_delay = CDEBUG_DEFAULT_MIN_DELAY;
 134                         CDEBUG(D_INFO, "LIBLUSTRE_DEBUG_CONSOLE_MAX_DELAY "
 135                                        "should be greater than "
 136                                        "LIBLUSTRE_DEBUG_CONSOLE_MIN_DELAY "
 137                                        "and both parameters should be non-null"
 138                                        ": restore default values\n");
 139                 } else {
 140                         CDEBUG(D_INFO, "set liblustre console max delay to %lus"
 141                                        " and min delay to %lus\n",
 142                                (cfs_duration_t)
 143                                      cfs_duration_sec(libcfs_console_max_delay),
 144                                (cfs_duration_t)
 145                                     cfs_duration_sec(libcfs_console_min_delay));
 146                 }
 147         }
 148         debug_backoff = getenv("LIBLUSTRE_DEBUG_CONSOLE_BACKOFF");
 149         if (debug_backoff != NULL) {
 150                 libcfs_console_backoff = strtoul(debug_backoff, NULL, 0);
 151                 if (libcfs_console_backoff <= 0) {
 152                         libcfs_console_backoff = CDEBUG_DEFAULT_BACKOFF;
 153                         CDEBUG(D_INFO, "LIBLUSTRE_DEBUG_CONSOLE_BACKOFF <= 0: "
 154                                        "restore default value\n");
 155                 } else {
 156                         CDEBUG(D_INFO, "set liblustre console backoff to %u\n",
 157                                libcfs_console_backoff);
 158                 }
 159         }
 160 #else
 161         struct utsname myname;
 162
 163         if (uname(&myname) == 0)
 164                 strcpy(source_nid, myname.nodename);
 165         source_pid = getpid();
 166 #endif
 167         /* debug masks */
 168         debug_mask = getenv("LIBLUSTRE_DEBUG_MASK");
 169         if (debug_mask)
 170                 libcfs_debug = (unsigned int) strtol(debug_mask, NULL, 0);
 171
 172         debug_subsys = getenv("LIBLUSTRE_DEBUG_SUBSYS");
 173         if (debug_subsys)
 174                 libcfs_subsystem_debug =
 175                                 (unsigned int) strtol(debug_subsys, NULL, 0);
 176
 177         debug_filename = getenv("LIBLUSTRE_DEBUG_BASE");
 178         if (debug_filename)
 179                 strncpy(libcfs_debug_file_path, debug_filename,
 180                         sizeof(libcfs_debug_file_path));
 181
 182         debug_filename = getenv("LIBLUSTRE_DEBUG_FILE");
 183         if (debug_filename)
 184                 strncpy(debug_file_name,debug_filename,sizeof(debug_file_name));
 185
 186         if (debug_file_name[0] == '\0' && libcfs_debug_file_path[0] != '\0')
 187                 snprintf(debug_file_name, sizeof(debug_file_name) - 1,
 188                          "%s-%s-"CFS_TIME_T".log", libcfs_debug_file_path,
 189                          source_nid, time(0));
 190
 191         if (strcmp(debug_file_name, "stdout") == 0 ||
 192             strcmp(debug_file_name, "-") == 0) {
 193                 debug_file_fd = stdout;
 194         } else if (strcmp(debug_file_name, "stderr") == 0) {
 195                 debug_file_fd = stderr;
 196         } else if (debug_file_name[0] != '\0') {
 197                 debug_file_fd = fopen(debug_file_name, "w");
 198                 if (debug_file_fd == NULL)
 199                         fprintf(stderr, "%s: unable to open '%s': %s\n",
 200                                 source_nid, debug_file_name, strerror(errno));
 201         }
 202
 203         if (debug_file_fd == NULL)
 204                 debug_file_fd = stdout;
 205
 206         return 0;
 207 }
 208
 209 int libcfs_debug_cleanup(void)
 210 {
 211         if (debug_file_fd != stdout && debug_file_fd != stderr)
 212                 fclose(debug_file_fd);
 213         return 0;
 214 }
 215
 216 int libcfs_debug_clear_buffer(void)
 217 {
 218         return 0;
 219 }
 220
 221 int libcfs_debug_mark_buffer(const char *text)
 222 {
 223
 224         fprintf(debug_file_fd, "*******************************************************************************\n");
 225         fprintf(debug_file_fd, "DEBUG MARKER: %s\n", text);
 226         fprintf(debug_file_fd, "*******************************************************************************\n");
 227
 228         return 0;
 229 }
 230
 231 #ifdef HAVE_CATAMOUNT_DATA_H
 232 #define CATAMOUNT_MAXLINE (256-4)
 233 void catamount_printline(char *buf, size_t size)
 234 {
 235     char *pos = buf;
 236     int prsize = size;
 237
 238     while (prsize > 0){
 239         lputs(pos);
 240         pos += CATAMOUNT_MAXLINE;
 241         prsize -= CATAMOUNT_MAXLINE;
 242     }
 243 }
 244 #endif
 245
 246 int libcfs_debug_msg(struct libcfs_debug_msg_data *msgdata,
 247                      const char *format, ...)
 248 {
 249         va_list args;
 250         int     rc;
 251
 252         va_start(args, format);
 253         rc = libcfs_debug_vmsg2(msgdata, format, args, NULL);
 254         va_end(args);
 255
 256         return rc;
 257 }
 258
 259 int
 260 libcfs_debug_vmsg2(struct libcfs_debug_msg_data *msgdata,
 261                    const char *format1, va_list args,
 262                    const char *format2, ...)
 263 {
 264         struct timeval tv;
 265         int            nob;
 266         int            remain;
 267         va_list        ap;
 268         char           buf[CFS_PAGE_SIZE]; /* size 4096 used for compatimble
 269                                             * with linux, where message can`t
 270                                             * be exceed PAGE_SIZE */
 271         int            console = 0;
 272         char *prefix = "Lustre";
 273
 274 #ifdef HAVE_CATAMOUNT_DATA_H
 275         /* toconsole == 0 - all messages to debug_file_fd
 276          * toconsole == 1 - warnings to console, all to debug_file_fd
 277          * toconsole >  1 - all debug to console */
 278         if (((msgdata->msg_mask & libcfs_printk) && toconsole == 1) || toconsole > 1)
 279                 console = 1;
 280 #endif
 281
 282         if ((!console) && (!debug_file_fd)) {
 283                 return 0;
 284         }
 285
 286         if (msgdata->msg_mask & (D_EMERG | D_ERROR))
 287                prefix = "LustreError";
 288
 289         nob = snprintf(buf, sizeof(buf), "%s: %u-%s:(%s:%d:%s()): ", prefix,
 290                        source_pid, source_nid, msgdata->msg_file,
 291                        msgdata->msg_line, msgdata->msg_fn);
 292
 293         remain = sizeof(buf) - nob;
 294         if (format1) {
 295                 nob += vsnprintf(&buf[nob], remain, format1, args);
 296         }
 297
 298         remain = sizeof(buf) - nob;
 299         if ((format2) && (remain > 0)) {
 300                 va_start(ap, format2);
 301                 nob += vsnprintf(&buf[nob], remain, format2, ap);
 302                 va_end(ap);
 303         }
 304
 305 #ifdef HAVE_CATAMOUNT_DATA_H
 306         if (console) {
 307                 cfs_debug_limit_state_t *cdls = msgdata->msg_cdls;
 308
 309                 /* check rate limit for console */
 310                 if (cdls != NULL) {
 311                         if (libcfs_console_ratelimit &&
 312                                 cdls->cdls_next != 0 &&     /* not first time ever */
 313                                 !cfs_time_after(cfs_time_current(), cdls->cdls_next)) {
 314
 315                                 /* skipping a console message */
 316                                 cdls->cdls_count++;
 317                                 goto out_file;
 318                         }
 319
 320                         if (cfs_time_after(cfs_time_current(), cdls->cdls_next +
 321                                            libcfs_console_max_delay +
 322                                            cfs_time_seconds(10))) {
 323                                 /* last timeout was a long time ago */
 324                                 cdls->cdls_delay /= libcfs_console_backoff * 4;
 325                         } else {
 326                                 cdls->cdls_delay *= libcfs_console_backoff;
 327
 328                                 if (cdls->cdls_delay <
 329                                                 libcfs_console_min_delay)
 330                                         cdls->cdls_delay =
 331                                                 libcfs_console_min_delay;
 332                                 else if (cdls->cdls_delay >
 333                                                 libcfs_console_max_delay)
 334                                         cdls->cdls_delay =
 335                                                 libcfs_console_max_delay;
 336                         }
 337
 338                         /* ensure cdls_next is never zero after it's been seen */
 339                         cdls->cdls_next = (cfs_time_current() + cdls->cdls_delay) | 1;
 340                 }
 341
 342                 if (cdls != NULL && cdls->cdls_count != 0) {
 343                         char buf2[100];
 344
 345                         nob = snprintf(buf2, sizeof(buf2),
 346                                        "Skipped %d previous similar message%s\n",
 347                                        cdls->cdls_count, (cdls->cdls_count > 1) ? "s" : "");
 348
 349                         catamount_printline(buf2, nob);
 350                         cdls->cdls_count = 0;
 351                         goto out_file;
 352                 }
 353                 catamount_printline(buf, nob);
 354        }
 355 out_file:
 356         /* return on toconsole > 1, as we don't want the user getting
 357         * spammed by the debug data */
 358         if (toconsole > 1)
 359                 return 0;
 360 #endif
 361         if (debug_file_fd == NULL)
 362                 return 0;
 363
 364         gettimeofday(&tv, NULL);
 365
 366         fprintf(debug_file_fd, CFS_TIME_T".%06lu:%u:%s:(%s:%d:%s()): %s",
 367                 tv.tv_sec, tv.tv_usec, source_pid, source_nid,
 368                 msgdata->msg_file, msgdata->msg_line, msgdata->msg_fn, buf);
 369
 370         return 0;
 371 }
 372
 373 void
 374 libcfs_assertion_failed(const char *expr, struct libcfs_debug_msg_data *msgdata)
 375 {
 376         libcfs_debug_msg(msgdata, "ASSERTION(%s) failed\n", expr);
 377         abort();
 378 }
 379
 380 /*
 381  * a helper function for RETURN(): the sole purpose is to save 8-16 bytes
 382  * on the stack - function calling RETURN() doesn't need to allocate two
 383  * additional 'rc' on the stack
 384  */
 385 long libcfs_log_return(struct libcfs_debug_msg_data *msgdata, long rc)
 386 {
 387         libcfs_debug_msg(msgdata, "Process leaving (rc=%lu : %ld : %lx)\n",
 388                          rc, rc, rc);
 389         return rc;
 390 }
 391
 392 /*
 393  * a helper function for GOTO(): the sole purpose is to save 8-16 bytes
 394  * on the stack - function calling GOTO() doesn't need to allocate two
 395  * additional 'rc' on the stack
 396  */
 397 void libcfs_log_goto(struct libcfs_debug_msg_data *msgdata, const char *l,
 398                      long_ptr_t rc)
 399 {
 400         libcfs_debug_msg(msgdata, "Process leaving via %s (rc=" LPLU " : "
 401                          LPLD " : " LPLX ")\n", l, (ulong_ptr_t) rc, rc, rc);
 402 }