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