Whamcloud - gitweb
f5aff7fe8176b6caed1ba16846e4b74b39feae91
[fs/lustre-release.git] / lnet / libcfs / debug.c
1 /* -*- mode: c; c-basic-offset: 8; indent-tabs-mode: nil; -*-
2  * vim:expandtab:shiftwidth=8:tabstop=8:
3  *
4  * Copyright (C) 2002 Cluster File Systems, Inc.
5  *   Author: Phil Schwan <phil@clusterfs.com>
6  *
7  *   This file is part of Lustre, http://www.lustre.org.
8  *
9  *   Lustre is free software; you can redistribute it and/or
10  *   modify it under the terms of version 2 of the GNU General Public
11  *   License as published by the Free Software Foundation.
12  *
13  *   Lustre is distributed in the hope that it will be useful,
14  *   but WITHOUT ANY WARRANTY; without even the implied warranty of
15  *   MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
16  *   GNU General Public License for more details.
17  *
18  *   You should have received a copy of the GNU General Public License
19  *   along with Lustre; if not, write to the Free Software
20  *   Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
21  */
22
23 #ifndef EXPORT_SYMTAB
24 # define EXPORT_SYMTAB
25 #endif
26
27 # define DEBUG_SUBSYSTEM S_LNET
28
29 #include <libcfs/kp30.h>
30 #include <libcfs/libcfs.h>
31 #include "tracefile.h"
32
33 static char debug_file_name[1024];
34
35 #ifdef __KERNEL__
36 unsigned int libcfs_subsystem_debug = ~0;
37 EXPORT_SYMBOL(libcfs_subsystem_debug);
38
39 unsigned int libcfs_debug = (D_EMERG | D_ERROR | D_WARNING | D_CONSOLE |
40                              D_NETERROR | D_HA | D_CONFIG | D_IOCTL |
41                              D_DLMTRACE | D_RPCTRACE | D_VFSTRACE);
42 EXPORT_SYMBOL(libcfs_debug);
43
44 unsigned int libcfs_printk;
45 EXPORT_SYMBOL(libcfs_printk);
46
47 unsigned int libcfs_console_ratelimit = 1;
48 EXPORT_SYMBOL(libcfs_console_ratelimit);
49
50 unsigned int libcfs_debug_binary = 1;
51 EXPORT_SYMBOL(libcfs_debug_binary);
52
53 unsigned int libcfs_stack;
54 EXPORT_SYMBOL(libcfs_stack);
55
56 unsigned int portal_enter_debugger;
57 EXPORT_SYMBOL(portal_enter_debugger);
58
59 unsigned int libcfs_catastrophe;
60 EXPORT_SYMBOL(libcfs_catastrophe);
61
62 unsigned int libcfs_panic_on_lbug = 0;
63 EXPORT_SYMBOL(libcfs_panic_on_lbug);
64
65 atomic_t libcfs_kmemory = ATOMIC_INIT(0);
66 EXPORT_SYMBOL(libcfs_kmemory);
67
68 static cfs_waitq_t debug_ctlwq;
69
70 char debug_file_path[1024] = "/tmp/lustre-log";
71
72 int libcfs_panic_in_progress;
73
74 /* libcfs_debug_token2mask() expects the returned
75  * string in lower-case */
76 const char *
77 libcfs_debug_subsys2str(int subsys)
78 {
79         switch (subsys) {
80         default:
81                 return NULL;
82         case S_UNDEFINED:
83                 return "undefined";
84         case S_MDC:
85                 return "mdc";
86         case S_MDS:
87                 return "mds";
88         case S_OSC:
89                 return "osc";
90         case S_OST:
91                 return "ost";
92         case S_CLASS:
93                 return "class";
94         case S_LOG:
95                 return "log";
96         case S_LLITE:
97                 return "llite";
98         case S_RPC:
99                 return "rpc";
100         case S_LNET:
101                 return "lnet";
102         case S_LND:
103                 return "lnd";
104         case S_PINGER:
105                 return "pinger";
106         case S_FILTER:
107                 return "filter";
108         case S_ECHO:
109                 return "echo";
110         case S_LDLM:
111                 return "ldlm";
112         case S_LOV:
113                 return "lov";
114         case S_LMV:
115                 return "lmv";
116         case S_SEC:
117                 return "sec";
118         case S_GSS:
119                 return "gss";
120         case S_MGC:
121                 return "mgc";
122         case S_MGS:
123                 return "mgs";
124         case S_FID:
125                 return "fid";
126         case S_FLD:
127                 return "fld";
128         }
129 }
130
131 /* libcfs_debug_token2mask() expects the returned
132  * string in lower-case */
133 const char *
134 libcfs_debug_dbg2str(int debug)
135 {
136         switch (debug) {
137         default:
138                 return NULL;
139         case D_TRACE:
140                 return "trace";
141         case D_INODE:
142                 return "inode";
143         case D_SUPER:
144                 return "super";
145         case D_EXT2:
146                 return "ext2";
147         case D_MALLOC:
148                 return "malloc";
149         case D_CACHE:
150                 return "cache";
151         case D_INFO:
152                 return "info";
153         case D_IOCTL:
154                 return "ioctl";
155         case D_NETERROR:
156                 return "neterror";
157         case D_NET:
158                 return "net";
159         case D_WARNING:
160                 return "warning";
161         case D_BUFFS:
162                 return "buffs";
163         case D_OTHER:
164                 return "other";
165         case D_DENTRY:
166                 return "dentry";
167         case D_NETTRACE:
168                 return "nettrace";
169         case D_PAGE:
170                 return "page";
171         case D_DLMTRACE:
172                 return "dlmtrace";
173         case D_ERROR:
174                 return "error";
175         case D_EMERG:
176                 return "emerg";
177         case D_HA:
178                 return "ha";
179         case D_RPCTRACE:
180                 return "rpctrace";
181         case D_VFSTRACE:
182                 return "vfstrace";
183         case D_READA:
184                 return "reada";
185         case D_MMAP:
186                 return "mmap";
187         case D_CONFIG:
188                 return "config";
189         case D_CONSOLE:
190                 return "console";
191         case D_QUOTA:
192                 return "quota";
193         case D_SEC:
194                 return "sec";
195         }
196 }
197
198 int
199 libcfs_debug_mask2str(char *str, int size, int mask, int is_subsys)
200 {
201         const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
202                                                  libcfs_debug_dbg2str;
203         int           len = 0;
204         const char   *token;
205         int           bit;
206         int           i;
207
208         if (mask == 0) {                        /* "0" */
209                 if (size > 0)
210                         str[0] = '0';
211                 len = 1;
212         } else {                                /* space-separated tokens */
213                 for (i = 0; i < 32; i++) {
214                         bit = 1 << i;
215
216                         if ((mask & bit) == 0)
217                                 continue;
218
219                         token = fn(bit);
220                         if (token == NULL)              /* unused bit */
221                                 continue;
222
223                         if (len > 0) {                  /* separator? */
224                                 if (len < size)
225                                         str[len] = ' ';
226                                 len++;
227                         }
228                 
229                         while (*token != 0) {
230                                 if (len < size)
231                                         str[len] = *token;
232                                 token++;
233                                 len++;
234                         }
235                 }
236         }
237
238         /* terminate 'str' */
239         if (len < size)
240                 str[len] = 0;
241         else
242                 str[size - 1] = 0;
243
244         return len;
245 }
246
247 int
248 libcfs_debug_token2mask(int *mask, const char *str, int len, int is_subsys)
249 {
250         const char *(*fn)(int bit) = is_subsys ? libcfs_debug_subsys2str :
251                                                  libcfs_debug_dbg2str;
252         int           i;
253         int           j;
254         int           bit;
255         const char   *token;
256
257         /* match against known tokens */
258         for (i = 0; i < 32; i++) {
259                 bit = 1 << i;
260
261                 token = fn(bit);
262                 if (token == NULL)              /* unused? */
263                         continue;
264                 
265                 /* strcasecmp */
266                 for (j = 0; ; j++) {
267                         if (j == len) {         /* end of token */
268                                 if (token[j] == 0) {
269                                         *mask = bit;
270                                         return 0;
271                                 }
272                                 break;
273                         }
274                         
275                         if (token[j] == 0)
276                                 break;
277                                 
278                         if (str[j] == token[j])
279                                 continue;
280                         
281                         if (str[j] < 'A' || 'Z' < str[j])
282                                 break;
283
284                         if (str[j] - 'A' + 'a' != token[j])
285                                 break;
286                 }
287         }
288         
289         return -EINVAL;                         /* no match */
290 }
291
292 int
293 libcfs_debug_str2mask(int *mask, const char *str, int is_subsys)
294 {
295         int         m = 0;
296         int         matched = 0;
297         char        op = 0;
298         int         n;
299         int         t;
300
301         /* <str> must be a list of debug tokens or numbers separated by
302          * whitespace and optionally an operator ('+' or '-').  If an operator
303          * appears first in <str>, '*mask' is used as the starting point
304          * (relative), otherwise 0 is used (absolute).  An operator applies to
305          * all following tokens up to the next operator. */
306         
307         while (*str != 0) {
308                 while (isspace(*str)) /* skip whitespace */
309                         str++;
310
311                 if (*str == 0)
312                         break;
313
314                 if (*str == '+' || *str == '-') {
315                         op = *str++;
316
317                         /* op on first token == relative */
318                         if (!matched)
319                                 m = *mask;
320
321                         while (isspace(*str)) /* skip whitespace */
322                                 str++;
323
324                         if (*str == 0)          /* trailing op */
325                                 return -EINVAL;
326                 }
327
328                 /* find token length */
329                 for (n = 0; str[n] != 0 && !isspace(str[n]); n++);
330
331                 /* match token */
332                 if (libcfs_debug_token2mask(&t, str, n, is_subsys) != 0)
333                         return -EINVAL;
334                 
335                 matched = 1;
336                 if (op == '-')
337                         m &= ~t;
338                 else
339                         m |= t;
340                 
341                 str += n;
342         }
343
344         if (!matched)
345                 return -EINVAL;
346
347         *mask = m;
348         return 0;
349 }
350
351 void libcfs_debug_dumplog_internal(void *arg)
352 {
353         CFS_DECL_JOURNAL_DATA;
354
355         CFS_PUSH_JOURNAL;
356
357         snprintf(debug_file_name, sizeof(debug_file_path) - 1, "%s.%ld.%ld",
358                  debug_file_path, cfs_time_current_sec(), (long)arg);
359         printk(KERN_ALERT "LustreError: dumping log to %s\n", debug_file_name);
360         tracefile_dump_all_pages(debug_file_name);
361
362         CFS_POP_JOURNAL;
363 }
364
365 int libcfs_debug_dumplog_thread(void *arg)
366 {
367         cfs_daemonize("");
368         libcfs_debug_dumplog_internal(arg);
369         cfs_waitq_signal(&debug_ctlwq);
370         return 0;
371 }
372
373 void libcfs_debug_dumplog(void)
374 {
375         int            rc;
376         cfs_waitlink_t wait;
377         ENTRY;
378
379         /* we're being careful to ensure that the kernel thread is
380          * able to set our state to running as it exits before we
381          * get to schedule() */
382         cfs_waitlink_init(&wait);
383         set_current_state(TASK_INTERRUPTIBLE);
384         cfs_waitq_add(&debug_ctlwq, &wait);
385
386         rc = cfs_kernel_thread(libcfs_debug_dumplog_thread,
387                                (void *)(long)cfs_curproc_pid(),
388                                CLONE_VM | CLONE_FS | CLONE_FILES);
389         if (rc < 0)
390                 printk(KERN_ERR "LustreError: cannot start log dump thread: "
391                        "%d\n", rc);
392         else
393                 cfs_waitq_wait(&wait, CFS_TASK_INTERRUPTIBLE);
394
395         /* be sure to teardown if kernel_thread() failed */
396         cfs_waitq_del(&debug_ctlwq, &wait);
397         set_current_state(TASK_RUNNING);
398 }
399
400 int libcfs_debug_init(unsigned long bufsize)
401 {
402         int    rc;
403
404         cfs_waitq_init(&debug_ctlwq);
405         rc = tracefile_init();
406
407         if (rc == 0)
408                 libcfs_register_panic_notifier();
409
410         return rc;
411 }
412
413 int libcfs_debug_cleanup(void)
414 {
415         libcfs_unregister_panic_notifier();
416         tracefile_exit();
417         return 0;
418 }
419
420 int libcfs_debug_clear_buffer(void)
421 {
422         trace_flush_pages();
423         return 0;
424 }
425
426 /* Debug markers, although printed by S_LNET
427  * should not be be marked as such. */
428 #undef DEBUG_SUBSYSTEM
429 #define DEBUG_SUBSYSTEM S_UNDEFINED
430 int libcfs_debug_mark_buffer(char *text)
431 {
432         CDEBUG(D_TRACE,"***************************************************\n");
433         CDEBUG(D_WARNING, "DEBUG MARKER: %s\n", text);
434         CDEBUG(D_TRACE,"***************************************************\n");
435
436         return 0;
437 }
438 #undef DEBUG_SUBSYSTEM
439 #define DEBUG_SUBSYSTEM S_LNET
440
441 void libcfs_debug_set_level(unsigned int debug_level)
442 {
443         printk(KERN_WARNING "Lustre: Setting portals debug level to %08x\n",
444                debug_level);
445         libcfs_debug = debug_level;
446 }
447
448 EXPORT_SYMBOL(libcfs_debug_dumplog);
449 EXPORT_SYMBOL(libcfs_debug_set_level);
450
451
452 #else /* !__KERNEL__ */
453
454 #include <libcfs/libcfs.h>
455
456 #ifdef HAVE_SYS_USER_H
457 # include <sys/user.h>
458 #endif
459
460 #ifdef HAVE_CATAMOUNT_DATA_H
461 #include <catamount/data.h>
462 #include <catamount/lputs.h>
463
464 static char source_nid[16];
465 /* 0 indicates no messages to console, 1 is errors, > 1 is all debug messages */
466 static int toconsole = 1;
467 unsigned int libcfs_console_ratelimit = 1;
468 #else /* !HAVE_CATAMOUNT_DATA_H */
469 #ifdef HAVE_NETDB_H
470 #include <sys/utsname.h>
471 #endif /* HAVE_CATAMOUNT_DATA_H */
472 struct utsname *tmp_utsname;
473 static char source_nid[sizeof(tmp_utsname->nodename)];
474 #endif /* __KERNEL__ */
475
476 static int source_pid;
477 int smp_processor_id = 1;
478 char debug_file_path[1024];
479 FILE *debug_file_fd;
480
481 int portals_do_debug_dumplog(void *arg)
482 {
483         printf("Look in %s\n", debug_file_name);
484         return 0;
485 }
486
487
488 void portals_debug_print(void)
489 {
490         return;
491 }
492
493
494 void libcfs_debug_dumplog(void)
495 {
496         printf("Look in %s\n", debug_file_name);
497         return;
498 }
499
500 int libcfs_debug_init(unsigned long bufsize)
501 {
502         char *debug_mask = NULL;
503         char *debug_subsys = NULL;
504         char *debug_filename;
505
506 #ifdef HAVE_CATAMOUNT_DATA_H
507         char *debug_console = NULL;
508         char *debug_ratelimit = NULL;
509
510         snprintf(source_nid, sizeof(source_nid) - 1, "%u", _my_pnid);
511         source_pid = _my_pid;
512
513         debug_console = getenv("LIBLUSTRE_DEBUG_CONSOLE");
514         if (debug_console != NULL) {
515                 toconsole = strtoul(debug_console, NULL, 0);
516                 CDEBUG(D_INFO, "set liblustre toconsole to %u\n", toconsole);
517         }
518         debug_ratelimit = getenv("LIBLUSTRE_DEBUG_CONSOLE_RATELIMIT");
519         if (debug_ratelimit != NULL) {
520                 libcfs_console_ratelimit = strtoul(debug_ratelimit, NULL, 0);
521                 CDEBUG(D_INFO, "set liblustre console ratelimit to %u\n", libcfs_console_ratelimit);
522         }
523 #else
524         struct utsname myname;
525
526         if (uname(&myname) == 0)
527                 strcpy(source_nid, myname.nodename);
528         source_pid = getpid();
529 #endif
530         /* debug masks */
531         debug_mask = getenv("LIBLUSTRE_DEBUG_MASK");
532         if (debug_mask)
533                 libcfs_debug = (unsigned int) strtol(debug_mask, NULL, 0);
534
535         debug_subsys = getenv("LIBLUSTRE_DEBUG_SUBSYS");
536         if (debug_subsys)
537                 libcfs_subsystem_debug =
538                                 (unsigned int) strtol(debug_subsys, NULL, 0);
539
540         debug_filename = getenv("LIBLUSTRE_DEBUG_BASE");
541         if (debug_filename)
542                 strncpy(debug_file_path,debug_filename,sizeof(debug_file_path));
543
544         debug_filename = getenv("LIBLUSTRE_DEBUG_FILE");
545         if (debug_filename)
546                 strncpy(debug_file_name,debug_filename,sizeof(debug_file_path));
547
548         if (debug_file_name[0] == '\0' && debug_file_path[0] != '\0')
549                 snprintf(debug_file_name, sizeof(debug_file_name) - 1,
550                          "%s-%s-%lu.log", debug_file_path, source_nid, time(0));
551
552         if (strcmp(debug_file_name, "stdout") == 0 ||
553             strcmp(debug_file_name, "-") == 0) {
554                 debug_file_fd = stdout;
555         } else if (strcmp(debug_file_name, "stderr") == 0) {
556                 debug_file_fd = stderr;
557         } else if (debug_file_name[0] != '\0') {
558                 debug_file_fd = fopen(debug_file_name, "w");
559                 if (debug_file_fd == NULL)
560                         fprintf(stderr, "%s: unable to open '%s': %s\n",
561                                 source_nid, debug_file_name, strerror(errno));
562         }
563
564         if (debug_file_fd == NULL)
565                 debug_file_fd = stdout;
566
567         return 0;
568 }
569
570 int libcfs_debug_cleanup(void)
571 {
572         if (debug_file_fd != stdout && debug_file_fd != stderr)
573                 fclose(debug_file_fd);
574         return 0;
575 }
576
577 int libcfs_debug_clear_buffer(void)
578 {
579         return 0;
580 }
581
582 int libcfs_debug_mark_buffer(char *text)
583 {
584
585         fprintf(debug_file_fd, "*******************************************************************************\n");
586         fprintf(debug_file_fd, "DEBUG MARKER: %s\n", text);
587         fprintf(debug_file_fd, "*******************************************************************************\n");
588
589         return 0;
590 }
591
592 #ifdef HAVE_CATAMOUNT_DATA_H
593 #define CATAMOUNT_MAXLINE (256-4)
594 void catamount_printline(char *buf, size_t size)
595 {
596     char *pos = buf;
597     int prsize = size;
598
599     while (prsize > 0){
600         lputs(pos);
601         pos += CATAMOUNT_MAXLINE;
602         prsize -= CATAMOUNT_MAXLINE;
603     }
604 }
605 #endif
606
607 int
608 libcfs_debug_vmsg2(cfs_debug_limit_state_t *cdls,
609                    int subsys, int mask,
610                    const char *file, const char *fn, const int line,
611                    const char *format1, va_list args,
612                    const char *format2, ...)
613 {
614         struct timeval tv;
615         int            nob;
616         int            remain;
617         va_list        ap;
618         char           buf[PAGE_SIZE]; /* size 4096 used for compatimble with linux,
619                                         * where message can`t be exceed PAGE_SIZE */
620         int            console = 0;
621         char *prefix = "Lustre";
622
623 #ifdef HAVE_CATAMOUNT_DATA_H
624         /* toconsole == 0 - all messages to debug_file_fd
625          * toconsole == 1 - warnings to console, all to debug_file_fd
626          * toconsole >  1 - all debug to console */
627         if ( ((mask & D_CANTMASK) &&
628              (toconsole == 1)) || (toconsole > 1)) {
629                 console = 1;
630         }
631 #endif
632
633         if ((!console) && (!debug_file_fd)) {
634                 return 0;
635         }
636
637         if (mask & (D_EMERG | D_ERROR))
638                prefix = "LustreError";
639
640         nob = snprintf(buf, sizeof(buf), "%s: %u-%s:(%s:%d:%s()): ", prefix,
641                        source_pid, source_nid, file, line, fn);
642
643         remain = sizeof(buf) - nob;
644         if (format1) {
645                 nob += vsnprintf(&buf[nob], remain, format1, args);
646         }
647
648         remain = sizeof(buf) - nob;
649         if ((format2) && (remain > 0)) {
650                 va_start(ap, format2);
651                 nob += vsnprintf(&buf[nob], remain, format2, ap);
652                 va_end(ap);
653         }
654
655 #ifdef HAVE_CATAMOUNT_DATA_H
656         if (console) {
657                 /* check rate limit for console */
658                 if (cdls != NULL) {
659                         cfs_time_t t = cdls->cdls_next +
660                                        cfs_time_seconds(CDEBUG_MAX_LIMIT + 10);
661                         cfs_duration_t  dmax = cfs_time_seconds(CDEBUG_MAX_LIMIT);
662
663                         if (libcfs_console_ratelimit &&
664                                 cdls->cdls_next != 0 &&     /* not first time ever */
665                                 !cfs_time_after(cfs_time_current(), cdls->cdls_next)) {
666
667                                 /* skipping a console message */
668                                 cdls->cdls_count++;
669                                 goto out_file;
670                         }
671
672                         if (cfs_time_after(cfs_time_current(), t)) {
673                                 /* last timeout was a long time ago */
674                                 cdls->cdls_delay /= 8;
675                         } else {
676                                 cdls->cdls_delay *= 2;
677
678                                 if (cdls->cdls_delay < CFS_TICK)
679                                         cdls->cdls_delay = CFS_TICK;
680                                 else if (cdls->cdls_delay > dmax)
681                                         cdls->cdls_delay = dmax;
682                         }
683
684                         /* ensure cdls_next is never zero after it's been seen */
685                         cdls->cdls_next = (cfs_time_current() + cdls->cdls_delay) | 1;
686                 }
687
688                 if (cdls != NULL && cdls->cdls_count != 0) {
689                         char buf2[100];
690
691                         nob = snprintf(buf2, sizeof(buf2),
692                                        "Skipped %d previous similar message%s\n",
693                                        cdls->cdls_count, (cdls->cdls_count > 1) ? "s" : "");
694
695                         catamount_printline(buf2, nob);
696                         cdls->cdls_count = 0;
697                         goto out_file;
698                 }
699                 catamount_printline(buf, nob);
700        }
701 out_file:
702         /* return on toconsole > 1, as we don't want the user getting
703         * spammed by the debug data */
704         if (toconsole > 1)
705                 return 0;
706 #endif
707         if (debug_file_fd == NULL)
708                 return 0;
709
710         gettimeofday(&tv, NULL);
711
712         fprintf(debug_file_fd, "%lu.%06lu:%u:%s:(%s:%d:%s()): %s",
713                 tv.tv_sec, tv.tv_usec, source_pid, source_nid,
714                 file, line, fn, buf);
715
716         return 0;
717 }
718
719 void
720 libcfs_assertion_failed(const char *expr, const char *file, const char *func,
721                         const int line)
722 {
723         libcfs_debug_msg(NULL, 0, D_EMERG, file, func, line,
724                          "ASSERTION(%s) failed\n", expr);
725         abort();
726 }
727
728 #endif /* __KERNEL__ */