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