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 #include <linux/config.h>
  28 #include <linux/module.h>
  29 #include <linux/kmod.h>
  30 #include <linux/notifier.h>
  31 #include <linux/kernel.h>
  32 #include <linux/mm.h>
  33 #include <linux/string.h>
  34 #include <linux/stat.h>
  35 #include <linux/errno.h>
  36 #include <linux/smp_lock.h>
  37 #include <linux/unistd.h>
  38 #include <linux/interrupt.h>
  39 #include <asm/system.h>
  40 #include <asm/uaccess.h>
  41 #include <linux/completion.h>
  42
  43 #include <linux/fs.h>
  44 #include <linux/stat.h>
  45 #include <asm/uaccess.h>
  46 #include <asm/segment.h>
  47 #include <linux/miscdevice.h>
  48 #include <linux/version.h>
  49
  50 # define DEBUG_SUBSYSTEM S_PORTALS
  51
  52 #include <linux/kp30.h>
  53 #include <linux/portals_compat25.h>
  54 #include <linux/libcfs.h>
  55
  56 #if (LINUX_VERSION_CODE > KERNEL_VERSION(2,5,0))
  57 #include <linux/kallsyms.h>
  58 #endif
  59
  60 unsigned int portal_subsystem_debug = ~0 - (S_PORTALS | S_QSWNAL | S_SOCKNAL |
  61                                             S_GMNAL | S_IBNAL);
  62 EXPORT_SYMBOL(portal_subsystem_debug);
  63
  64 unsigned int portal_debug = (D_WARNING | D_DLMTRACE | D_ERROR | D_EMERG | D_HA |
  65                              D_RPCTRACE | D_VFSTRACE | 0xffffffff);
  66 EXPORT_SYMBOL(portal_debug);
  67
  68 unsigned int portal_cerror = 1;
  69 EXPORT_SYMBOL(portal_cerror);
  70
  71 unsigned int portal_printk;
  72 EXPORT_SYMBOL(portal_printk);
  73
  74 unsigned int portal_stack;
  75 EXPORT_SYMBOL(portal_stack);
  76
  77 #ifdef __KERNEL__
  78 atomic_t portal_kmemory = ATOMIC_INIT(0);
  79 EXPORT_SYMBOL(portal_kmemory);
  80 #endif
  81
  82 #define DEBUG_OVERFLOW 1024
  83 static char *debug_buf = NULL;
  84 static unsigned long debug_size = 0;
  85 static atomic_t debug_off_a = ATOMIC_INIT(0);
  86 static int debug_wrapped;
  87 static DECLARE_WAIT_QUEUE_HEAD(debug_ctlwq);
  88 #define DAEMON_SND_SIZE      (64 << 10)
  89
  90 /*
  91  * used by the daemon to keep track the offset into debug_buffer for the next
  92  * write to the file.  Usually, the daemon is to write out buffer
  93  * from debug_daemon_next_write upto debug_off
  94  *  variable usage
  95  *      Reader - portals_debug_msg()
  96  *      Writer - portals_debug_daemon()
  97  *               portals_debug_daemon_start() during daemon init time
  98  *               portals_debug_daemon_continue() to reset to debug_off
  99  *               portals_debug_clear_buffer() reset to debug_off for clear
 100  *      Note that *_start(), *_continue() & *clear_buffer() should serialized;
 101  */
 102 static atomic_t   debug_daemon_next_write;
 103
 104 /*
 105  * A debug_daemon can be in following states
 106  *      stopped - stopped state means there is no debug_daemon running.
 107  *                accordingly, it must be in paused state
 108  *                a daemon is in !stopped && !paused state after
 109  *                "lctl debug_daemon start" creates debug_daemon successfully
 110  *                Variable Usage
 111  *                      Reader - portals_debug_daemon()
 112  *                               portals_debug_set_daemon() routines
 113  *                      Writer - portals_debug_set_daemon() routines
 114  *                              portals_debug_daemon() on IO error
 115  *      paused -  a debug_daemon state is changed from !paused into paused
 116  *                when "lctl debug_daemon paused" is issued
 117  *                "lctl debug_daemon continue" gets a daemon into !paused mode
 118  *                      Reader - portals_debug_set_daemon() routines
 119  *                               portals_debug_msg()
 120  *                      Writer - portals_debug_set_daemon() on init
 121  *                               portals_debug_daemon()
 122  *
 123  *        Daemon  state diagram.
 124  *                      (stopped, paused)
 125  *                              |  <-- debug_daemon start
 126  *                              V
 127  *                      (!stopped, !paused)
 128  *                              |  <-- debug_daemon pause
 129  *                              V
 130  *                      (!stopped, paused)
 131  *                              |  <-- debug_daemon continue
 132  *                              V
 133  *                      (!stopped, !paused)
 134  *                              |  <-- debug_daemon stop
 135  *                              V
 136  *                      (stopped, paused)
 137  *      Overlapped - this is a state when CDEBUG is too fast for the daemon to
 138  *                   write out the debug_bufferr.  That is, debug_off is to
 139  *                   overlap debug_daemon_next_write;
 140  *                     Reader - portals_debug_msg()
 141  *                     Writer - portals_debug_msg()
 142  */
 143
 144 /*
 145  * Description on Trace Daemon Synchronization
 146  *
 147  * Three categories of code are synchronizing between each other
 148  * 1.   lctl, portals_debug_set_daemon(), the user debug control code,
 149  *      as well as portals_debug_clear_buffer()
 150  * 2.   CDEBUG, portals_debug_msg(), the debug put messages routine
 151  * 3.   Daemon, portals_debug_daemon(), to write out debug log file
 152  *
 153  *
 154  * Three different controls for synchronizations
 155  *
 156  * 1.   debug_daemon_semaphore
 157  *      The usage of this semaphore is to serialize multiple lctl controls
 158  *      in manipulating debug daemon state.  The semaphore serves as the
 159  *      gatekeeper to allow only one user control thread, at any giving time,
 160  *      to access debug daemon state and keeps the other user control requests
 161  *      in wait state until the current control request is serviced.
 162  *
 163  * 2.   wait_queue_head_t lctl (paired with lctl_event flag)
 164  *      Lctl event is the event between portals_debug_set_daemon() and
 165  *      portals_debug_daemon().  Lctl is an indicator for portals_debug_daemon()
 166  *      to flush data out to file.  portals_debug_daemon() is to use lctl event
 167  *      as signal channel to wakeup portals_debug_set_daemon() upon flush
 168  *      operation is done.
 169  *
 170  *      Producer :
 171  *              portals_debug_daemon() uses to wake up
 172  *              portals_debug_set_daemon(), pause and stop, routines
 173  *      Consumer :
 174  *              portals_debug_set_daemon(), stop and pause operations,
 175  *              wait and sleep on the event
 176  *
 177  * 3.   wait_queue_head_t daemon (paired with daemon_event flag)
 178  *      This is an event channel to wakeup portals_debug_daemon.  Daemon
 179  *      wakes up to run whenever there is an event posted.   Daemon handles
 180  *      2 types of operations . 1. Writes data out to debug file, 2. Flushes
 181  *      file and terminates base on lctl event.
 182  *      File operation -
 183  *              Daemon is normally in a sleep state.
 184  *              Daemon is woken up through daemon event whenever CDEBUG is
 185  *              putting data over any 64K boundary.
 186  *      File flush and termination -
 187  *              On portals_debug_daemon_stop/pause() operations, lctl control
 188  *              is to wake up daemon through daemon event.
 189  *
 190  *      We can't use sleep_on() and wake_up() to replace daemon event because
 191  *      portals_debug_daemon() must catch the wakeup operation posted by
 192  *      portals_debug_daemon_stop/pause().  Otherwise, stop and pause may
 193  *      stuck in lctl wait event.
 194  *
 195  *      Producer :
 196  *           a. portals_debug_daemon_pause() and portals_debug_daemon_stop()
 197  *              uses the event to wake up portals_debug_daemon()
 198  *           b. portals_debug_msg() uses the event to wake up
 199  *              portals_debug_daemon() whenever the data output is acrossing
 200  *              a 64K bytes boundary.
 201  *      Consumer :
 202  *              portals_debug_daemon() wakes up upon daemon event.
 203  *
 204  * Sequence for portals_debug_daemon_stop() operation
 205  *
 206  * _Portals_debug_daemon_stop()_          _Daemon_
 207  *                                      Wait_event(daemon) or running
 208  *      Paused = 1;
 209  *      Wakeup_event (daemon)
 210  *      Wait_event(lctl)
 211  *                                      Set force_flush flag if lctlevnt
 212  *                                      Flush data
 213  *                                      Wakeup_event (lctl)
 214  *                                      Wait_event(daemon)
 215  *      Stopped = 1;
 216  *      Wakeup_event (daemon)
 217  *      Wait_event(lctl)
 218  *                                      Exit daemon loop if (Stopped)
 219  *                                      Wakeup_event (lctl)
 220  *                                      Exit
 221  *      Return to user application
 222  *
 223  *
 224  * _Portals_debug_msg()_                  _Daemon_
 225  *                                      Wait_event(daemon) or running
 226  *      If (WriteStart<64K<WriteEnd)
 227  *         Wakeup_event(daemon)
 228  *                                      Do file IO
 229  *                                      Wait_event(daemon)
 230  */
 231 struct debug_daemon_state {
 232         unsigned long overlapped;
 233         unsigned long stopped;
 234         atomic_t paused;
 235         unsigned long   lctl_event;     /* event for lctl */
 236         wait_queue_head_t lctl;
 237         unsigned long   daemon_event;   /* event for daemon */
 238         wait_queue_head_t daemon;
 239 };
 240 static struct debug_daemon_state debug_daemon_state;
 241 static DECLARE_MUTEX(debug_daemon_semaphore);
 242
 243 static loff_t daemon_file_size_limit;
 244 char debug_daemon_file_path[1024] = "";
 245
 246 spinlock_t portals_debug_lock = SPIN_LOCK_UNLOCKED;
 247 char debug_file_path[1024] = "/tmp/lustre-log";
 248 char debug_file_name[1024];
 249 int handled_panic; /* to avoid recursive calls to notifiers */
 250 char portals_upcall[1024] = "/usr/lib/lustre/portals_upcall";
 251
 252
 253 int portals_do_debug_dumplog(void *arg)
 254 {
 255         struct file *file;
 256         void *journal_info;
 257         int rc;
 258         mm_segment_t oldfs;
 259         unsigned long debug_off;
 260
 261         kportal_daemonize("");
 262
 263         reparent_to_init();
 264         journal_info = current->journal_info;
 265         current->journal_info = NULL;
 266         sprintf(debug_file_name, "%s.%ld", debug_file_path, CURRENT_SECONDS);
 267         file = filp_open(debug_file_name, O_CREAT|O_EXCL|O_RDWR, 0644);
 268
 269         if (!file || IS_ERR(file)) {
 270                 CERROR("cannot open %s for dumping: %ld\n", debug_file_name,
 271                        PTR_ERR(file));
 272                 GOTO(out, PTR_ERR(file));
 273         } else {
 274                 printk(KERN_ALERT "LustreError: dumping log to %s ...\n",
 275                        debug_file_name);
 276         }
 277
 278         debug_off = atomic_read(&debug_off_a);
 279         oldfs = get_fs();
 280         set_fs(get_ds());
 281         if (debug_wrapped) {
 282                 rc = file->f_op->write(file, debug_buf + debug_off + 1,
 283                                        debug_size-debug_off-1, &file->f_pos);
 284                 rc += file->f_op->write(file, debug_buf, debug_off + 1,
 285                                         &file->f_pos);
 286         } else {
 287                 rc = file->f_op->write(file, debug_buf, debug_off,&file->f_pos);
 288         }
 289         printk("LustreError: wrote %d bytes\n", rc);
 290         set_fs(oldfs);
 291
 292         rc = file->f_op->fsync(file, file->f_dentry, 1);
 293         if (rc)
 294                 CERROR("sync returns %d\n", rc);
 295         filp_close(file, 0);
 296 out:
 297         current->journal_info = journal_info;
 298         wake_up(&debug_ctlwq);
 299         return 0;
 300 }
 301
 302 int portals_debug_daemon(void *arg)
 303 {
 304         struct file *file;
 305         void *journal_info;
 306         mm_segment_t oldfs;
 307         unsigned long force_flush = 0;
 308         unsigned long size, off, flags;
 309         int rc;
 310
 311         kportal_daemonize("ldebug_daemon");
 312         reparent_to_init();
 313         journal_info = current->journal_info;
 314         current->journal_info = NULL;
 315
 316         file = filp_open(debug_daemon_file_path,
 317                          O_CREAT|O_TRUNC|O_RDWR|O_LARGEFILE, 0644);
 318
 319         if (!file || IS_ERR(file)) {
 320                 CERROR("cannot open %s for logging", debug_daemon_file_path);
 321                 GOTO(out1, PTR_ERR(file));
 322         }
 323         printk(KERN_INFO "daemon dumping log to %s\n", debug_daemon_file_path);
 324
 325         debug_daemon_state.overlapped = 0;
 326         debug_daemon_state.stopped = 0;
 327
 328         spin_lock_irqsave(&portals_debug_lock, flags);
 329         off = atomic_read(&debug_off_a) + 1;
 330         if (debug_wrapped)
 331                 off = (off >= debug_size)? 0 : off;
 332         else
 333                 off = 0;
 334         atomic_set(&debug_daemon_next_write, off);
 335         atomic_set(&debug_daemon_state.paused, 0);
 336         spin_unlock_irqrestore(&portals_debug_lock, flags);
 337
 338         oldfs = get_fs();
 339         set_fs(KERNEL_DS);
 340         while (1) {
 341                 unsigned long ending;
 342                 unsigned long start, tail;
 343                 long delta;
 344
 345                 debug_daemon_state.daemon_event = 0;
 346
 347                 ending = atomic_read(&debug_off_a);
 348                 start = atomic_read(&debug_daemon_next_write);
 349
 350                 /* check if paused is imposed by lctl ? */
 351                 force_flush = !debug_daemon_state.lctl_event;
 352
 353                 delta = ending - start;
 354                 tail = debug_size - start;
 355                 size = (delta >= 0) ? delta : tail;
 356                 while (size && (force_flush || (delta < 0) ||
 357                                 (size >= DAEMON_SND_SIZE))) {
 358                         if (daemon_file_size_limit) {
 359                                int ssize = daemon_file_size_limit - file->f_pos;
 360                                if (size > ssize)
 361                                         size = ssize;
 362                         }
 363
 364                         rc = file->f_op->write(file, debug_buf+start,
 365                                                size, &file->f_pos);
 366                         if (rc < 0) {
 367                                 printk(KERN_ALERT "LustreError: Debug_daemon "
 368                                        "write error %d\n", rc);
 369                                 goto out;
 370                         }
 371                         start += rc;
 372                         delta = ending - start;
 373                         tail = debug_size - start;
 374                         if (tail == 0)
 375                                 start = 0;
 376                         if (delta >= 0)
 377                                 size = delta;
 378                         else
 379                                 size = (tail == 0) ? ending : tail;
 380                         if (daemon_file_size_limit == file->f_pos) {
 381                                 // file wrapped around
 382                                 file->f_pos = 0;
 383                         }
 384                 }
 385                 atomic_set(&debug_daemon_next_write, start);
 386                 if (force_flush) {
 387                         rc = file->f_op->fsync(file, file->f_dentry, 1);
 388                         if (rc < 0) {
 389                                 printk(KERN_ALERT "LustreError: Debug_daemon "
 390                                        "sync error %d\n", rc);
 391                                 goto out;
 392                         }
 393                         if (debug_daemon_state.stopped)
 394                                break;
 395                         debug_daemon_state.lctl_event = 1;
 396                         wake_up(&debug_daemon_state.lctl);
 397                 }
 398                 wait_event(debug_daemon_state.daemon,
 399                            debug_daemon_state.daemon_event);
 400                 }
 401 out:
 402         atomic_set(&debug_daemon_state.paused, 1);
 403         debug_daemon_state.stopped = 1;
 404         set_fs(oldfs);
 405         filp_close(file, 0);
 406         current->journal_info = journal_info;
 407 out1:
 408         debug_daemon_state.lctl_event = 1;
 409         wake_up(&debug_daemon_state.lctl);
 410         return 0;
 411 }
 412
 413 void portals_debug_print(void)
 414 {
 415         unsigned long dumplen = 64 * 1024;
 416         char *start1, *start2;
 417         char *end1, *end2;
 418         unsigned long debug_off = atomic_read(&debug_off_a);
 419
 420         start1 = debug_buf + debug_off - dumplen;
 421         if (start1 < debug_buf) {
 422                 start1 += debug_size;
 423                 end1 = debug_buf + debug_size - 1;
 424                 start2 = debug_buf;
 425                 end2 = debug_buf + debug_off;
 426         } else {
 427                 end1 = debug_buf + debug_off;
 428                 start2 = debug_buf + debug_off;
 429                 end2 = debug_buf + debug_off;
 430         }
 431
 432         while (start1 < end1) {
 433                 int count = MIN(1024, end1 - start1);
 434                 printk("LustreError: %*s", count, start1);
 435                 start1 += 1024;
 436         }
 437         while (start2 < end2) {
 438                 int count = MIN(1024, end2 - start2);
 439                 printk("LustreError: %*s", count, start2);
 440                 start2 += 1024;
 441         }
 442 }
 443
 444 void portals_debug_dumplog(void)
 445 {
 446         int rc;
 447         DECLARE_WAITQUEUE(wait, current);
 448         ENTRY;
 449
 450         /* we're being careful to ensure that the kernel thread is
 451          * able to set our state to running as it exits before we
 452          * get to schedule() */
 453         set_current_state(TASK_INTERRUPTIBLE);
 454         add_wait_queue(&debug_ctlwq, &wait);
 455
 456         rc = kernel_thread(portals_do_debug_dumplog,
 457                            NULL, CLONE_VM | CLONE_FS | CLONE_FILES);
 458         if (rc < 0)
 459                 printk(KERN_ERR "LustreError: cannot start log dump thread: "
 460                        "%d\n", rc);
 461         else
 462                 schedule();
 463
 464         /* be sure to teardown if kernel_thread() failed */
 465         remove_wait_queue(&debug_ctlwq, &wait);
 466         set_current_state(TASK_RUNNING);
 467 }
 468
 469 int portals_debug_daemon_start(char *file, unsigned int size)
 470 {
 471         int rc;
 472
 473         if (!debug_daemon_state.stopped)
 474                 return -EALREADY;
 475
 476         if (file != NULL)
 477                 strncpy(debug_daemon_file_path, file, 1024);
 478
 479         init_waitqueue_head(&debug_daemon_state.lctl);
 480         init_waitqueue_head(&debug_daemon_state.daemon);
 481
 482         daemon_file_size_limit = size << 20;
 483
 484         debug_daemon_state.lctl_event = 0;
 485         rc = kernel_thread(portals_debug_daemon, NULL, 0);
 486         if (rc < 0) {
 487                 printk(KERN_ERR "LustreError: cannot start debug daemon thread\n");
 488                 strncpy(debug_daemon_file_path, "\0", 1);
 489                 return rc;
 490         }
 491         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 492         return 0;
 493 }
 494
 495 int portals_debug_daemon_pause(void)
 496 {
 497         if (atomic_read(&debug_daemon_state.paused))
 498                 return -EALREADY;
 499
 500         atomic_set(&debug_daemon_state.paused, 1);
 501         debug_daemon_state.lctl_event = 0;
 502         debug_daemon_state.daemon_event = 1;
 503         wake_up(&debug_daemon_state.daemon);
 504         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 505         return 0;
 506 }
 507
 508 int portals_debug_daemon_continue(void)
 509 {
 510         if (!atomic_read(&debug_daemon_state.paused))
 511                 return -EINVAL;
 512         if (debug_daemon_state.stopped)
 513                 return -EINVAL;
 514
 515         debug_daemon_state.overlapped = 0;
 516         atomic_set(&debug_daemon_next_write, atomic_read(&debug_off_a));
 517         atomic_set(&debug_daemon_state.paused, 0);
 518         return 0;
 519 }
 520
 521 int portals_debug_daemon_stop(void)
 522 {
 523         if (debug_daemon_state.stopped)
 524                 return -EALREADY;
 525
 526         if (!atomic_read(&debug_daemon_state.paused))
 527                 portals_debug_daemon_pause();
 528
 529         debug_daemon_state.lctl_event = 0;
 530         debug_daemon_state.stopped = 1;
 531
 532         debug_daemon_state.daemon_event = 1;
 533         wake_up(&debug_daemon_state.daemon);
 534         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 535
 536         debug_daemon_file_path[0] = '\0';
 537         return 0;
 538 }
 539
 540 int portals_debug_set_daemon(unsigned int cmd, unsigned int length,
 541                              char *filename, unsigned int size)
 542 {
 543         int rc = -EINVAL;
 544
 545         down(&debug_daemon_semaphore);
 546         switch (cmd) {
 547                 case DEBUG_DAEMON_START:
 548                         if (length && (filename[length -1] != '\0')) {
 549                                 CERROR("Invalid filename for debug_daemon\n");
 550                                 rc = -EINVAL;
 551                                 break;
 552                         }
 553                         rc = portals_debug_daemon_start(filename, size);
 554                         break;
 555                 case DEBUG_DAEMON_STOP:
 556                         rc = portals_debug_daemon_stop();
 557                         break;
 558                 case DEBUG_DAEMON_PAUSE:
 559                         rc = portals_debug_daemon_pause();
 560                         break;
 561                 case DEBUG_DAEMON_CONTINUE:
 562                         rc = portals_debug_daemon_continue();
 563                         break;
 564                 default:
 565                         CERROR("unknown set_daemon cmd\n");
 566         }
 567         up(&debug_daemon_semaphore);
 568         return rc;
 569 }
 570
 571 static int panic_dumplog(struct notifier_block *self, unsigned long unused1,
 572                          void *unused2)
 573 {
 574         if (handled_panic)
 575                 return 0;
 576         else
 577                 handled_panic = 1;
 578
 579         if (in_interrupt()) {
 580                 portals_debug_print();
 581                 return 0;
 582         }
 583
 584         while (current->lock_depth >= 0)
 585                 unlock_kernel();
 586         portals_debug_dumplog();
 587         return 0;
 588 }
 589
 590 static struct notifier_block lustre_panic_notifier = {
 591         notifier_call :     panic_dumplog,
 592         next :              NULL,
 593         priority :          10000
 594 };
 595
 596 int portals_debug_init(unsigned long bufsize)
 597 {
 598         unsigned long debug_off = atomic_read(&debug_off_a);
 599         if (debug_buf != NULL)
 600                 return -EALREADY;
 601
 602         atomic_set(&debug_daemon_state.paused, 1);
 603         debug_daemon_state.stopped = 1;
 604
 605         debug_buf = vmalloc(bufsize + DEBUG_OVERFLOW);
 606         if (debug_buf == NULL)
 607                 return -ENOMEM;
 608         memset(debug_buf, 0, bufsize + DEBUG_OVERFLOW);
 609         debug_wrapped = 0;
 610
 611         //printk(KERN_INFO "Portals: allocated %lu byte debug buffer at %p.\n",
 612                //bufsize, debug_buf);
 613         atomic_set(&debug_off_a, debug_off);
 614         notifier_chain_register(&panic_notifier_list, &lustre_panic_notifier);
 615         debug_size = bufsize;
 616
 617         return 0;
 618 }
 619
 620 int portals_debug_cleanup(void)
 621 {
 622         notifier_chain_unregister(&panic_notifier_list, &lustre_panic_notifier);
 623         if (debug_buf == NULL)
 624                 return -EINVAL;
 625
 626         down(&debug_daemon_semaphore);
 627         portals_debug_daemon_stop();
 628
 629         vfree(debug_buf);
 630         atomic_set(&debug_off_a, 0);
 631         up(&debug_daemon_semaphore);
 632
 633         return 0;
 634 }
 635
 636 int portals_debug_clear_buffer(void)
 637 {
 638         unsigned long flags;
 639         unsigned long state;
 640
 641         if (debug_buf == NULL)
 642                 return -EINVAL;
 643
 644         down(&debug_daemon_semaphore);
 645         state = atomic_read(&debug_daemon_state.paused);
 646         if (!state)
 647                 portals_debug_daemon_pause();
 648         spin_lock_irqsave(&portals_debug_lock, flags);
 649         atomic_set(&debug_off_a, 0);
 650         debug_wrapped = 0;
 651         atomic_set(&debug_daemon_next_write, 0);
 652         debug_daemon_state.overlapped = 0;
 653         spin_unlock_irqrestore(&portals_debug_lock, flags);
 654
 655         if (!state)
 656                 atomic_set(&debug_daemon_state.paused, 0);
 657         up(&debug_daemon_semaphore);
 658
 659         return 0;
 660 }
 661
 662 /* Debug markers, although printed by S_PORTALS
 663  * should not be be marked as such.
 664  */
 665 #undef DEBUG_SUBSYSTEM
 666 #define DEBUG_SUBSYSTEM S_UNDEFINED
 667 int portals_debug_mark_buffer(char *text)
 668 {
 669         if (debug_buf == NULL)
 670                 return -EINVAL;
 671
 672         CDEBUG(D_TRACE,"***************************************************\n");
 673         CWARN("DEBUG MARKER: %s\n", text);
 674         CDEBUG(D_TRACE,"***************************************************\n");
 675
 676         return 0;
 677 }
 678 #undef DEBUG_SUBSYSTEM
 679 #define DEBUG_SUBSYSTEM S_PORTALS
 680
 681 /* this copies a snapshot of the debug buffer into an array of pages
 682  * before doing the potentially blocking copy into userspace. it could
 683  * be warning userspace if things wrap heavily while its off copying. */
 684 __s32 portals_debug_copy_to_user(char *buf, unsigned long len)
 685 {
 686         int rc;
 687         unsigned long total, debug_off, i, off, copied;
 688         unsigned long flags;
 689         struct page *page;
 690         LIST_HEAD(my_pages);
 691         struct list_head *pos, *n;
 692
 693         if (len < debug_size)
 694                 return -ENOSPC;
 695
 696         for (i = 0 ; i < debug_size; i += PAGE_SIZE) {
 697                 page = alloc_page(GFP_NOFS);
 698                 if (page == NULL) {
 699                         rc = -ENOMEM;
 700                         goto cleanup;
 701                 }
 702                 list_add(&PAGE_LIST(page), &my_pages);
 703         }
 704
 705         spin_lock_irqsave(&portals_debug_lock, flags);
 706         debug_off = atomic_read(&debug_off_a);
 707
 708         /* Sigh. If the buffer is empty, then skip to the end. */
 709         if (debug_off == 0 && !debug_wrapped) {
 710                 spin_unlock_irqrestore(&portals_debug_lock, flags);
 711                 rc = 0;
 712                 goto cleanup;
 713         }
 714
 715         if (debug_wrapped) {
 716                 off = debug_off + 1;
 717                 total = debug_size;
 718         } else {
 719                 off = 0;
 720                 total = debug_off;
 721         }
 722         copied = 0;
 723         list_for_each(pos, &my_pages) {
 724                 unsigned long to_copy;
 725                 void *addr;
 726
 727                 page = list_entry(pos, struct page, PAGE_LIST_ENTRY);
 728                 to_copy = min(total - off, PAGE_SIZE);
 729                 if (to_copy == 0) {
 730                         off = 0;
 731                         to_copy = min(debug_size - off, PAGE_SIZE);
 732                 }
 733 finish_partial:
 734                 addr = kmap_atomic(page, KM_USER0);
 735                 memcpy(addr, debug_buf + off, to_copy);
 736                 kunmap_atomic(addr, KM_USER0);
 737                 copied += to_copy;
 738                 if (copied >= total)
 739                         break;
 740
 741                 off += to_copy;
 742                 if (off >= debug_size) {
 743                         off = 0;
 744                         if (to_copy != PAGE_SIZE) {
 745                                 to_copy = PAGE_SIZE - to_copy;
 746                                 goto finish_partial;
 747                         }
 748                 }
 749         }
 750
 751         spin_unlock_irqrestore(&portals_debug_lock, flags);
 752
 753         off = 0;
 754         list_for_each(pos, &my_pages) {
 755                 unsigned long to_copy;
 756                 page = list_entry(pos, struct page, PAGE_LIST_ENTRY);
 757
 758                 to_copy = min(copied - off, PAGE_SIZE);
 759                 rc = copy_to_user(buf + off, kmap(page), to_copy);
 760                 kunmap(page);
 761                 if (rc) {
 762                         rc = -EFAULT;
 763                         goto cleanup;
 764                 }
 765                 off += to_copy;
 766                 if (off >= copied)
 767                         break;
 768         }
 769         rc = copied;
 770
 771 cleanup:
 772         list_for_each_safe(pos, n, &my_pages) {
 773                 page = list_entry(pos, struct page, PAGE_LIST_ENTRY);
 774                 list_del(&PAGE_LIST(page));
 775                 __free_page(page);
 776         }
 777         return rc;
 778 }
 779
 780 /* FIXME: I'm not very smart; someone smarter should make this better. */
 781 void
 782 portals_debug_msg(int subsys, int mask, char *file, const char *fn,
 783                   const int line, unsigned long stack, char *format, ...)
 784 {
 785         va_list       ap;
 786         unsigned long flags;
 787         int           max_nob;
 788         int           prefix_nob;
 789         int           msg_nob;
 790         struct timeval tv;
 791         unsigned long base_offset;
 792         unsigned long debug_off;
 793
 794         if (debug_buf == NULL) {
 795                 printk("LustreError: portals_debug_msg: debug_buf is NULL!\n");
 796                 return;
 797         }
 798
 799         spin_lock_irqsave(&portals_debug_lock, flags);
 800         debug_off = atomic_read(&debug_off_a);
 801         if (!atomic_read(&debug_daemon_state.paused)) {
 802                 unsigned long available;
 803                 long delta;
 804                 long v = atomic_read(&debug_daemon_next_write);
 805
 806                 delta = debug_off - v;
 807                 available = (delta>=0) ? debug_size-delta : -delta;
 808                 // Check if we still have enough debug buffer for CDEBUG
 809                 if (available < DAEMON_SND_SIZE) {
 810                         /* Drop CDEBUG packets until enough debug_buffer is
 811                          * available */
 812                         if (debug_daemon_state.overlapped)
 813                                  goto out;
 814                         /* If this is the first time, leave a marker in the
 815                          * output */
 816                         debug_daemon_state.overlapped = 1;
 817                         format = "DEBUG MARKER: Debug buffer overlapped\n";
 818                         printk(KERN_ERR "LustreError: debug daemon buffer "
 819                                "overlapped\n");
 820                 } else  /* More space just became available */
 821                         debug_daemon_state.overlapped = 0;
 822         }
 823
 824         max_nob = debug_size - debug_off + DEBUG_OVERFLOW;
 825         if (max_nob <= 0) {
 826                 spin_unlock_irqrestore(&portals_debug_lock, flags);
 827                 printk("LustreError: logic error in portals_debug_msg: "
 828                        "< 0 bytes to write\n");
 829                 return;
 830         }
 831
 832         /* NB since we pass a non-zero sized buffer (at least) on the first
 833          * print, we can be assured that by the end of all the snprinting,
 834          * we _do_ have a terminated buffer, even if our message got truncated.
 835          */
 836
 837         do_gettimeofday(&tv);
 838
 839         prefix_nob = snprintf(debug_buf + debug_off, max_nob,
 840                               "%06x:%06x:%d:%lu.%06lu:%lu:%d:",
 841                               subsys, mask, smp_processor_id(),
 842                               tv.tv_sec, tv.tv_usec, stack, current->pid);
 843         max_nob -= prefix_nob;
 844
 845         if(*(format + strlen(format) - 1) != '\n')
 846                 printk(KERN_INFO "format at %s:%d:%s doesn't end in newline\n",
 847                        file, line, fn);
 848
 849 #if defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,4,20))
 850         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 851                            "%d:(%s:%d:%s()) ",
 852                            current->thread.extern_pid, file, line, fn);
 853 #elif defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,5,0))
 854         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 855                            "%d:(%s:%d:%s()) ",
 856                            current->thread.mode.tt.extern_pid, file, line, fn);
 857 #else
 858         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 859                            "%d:(%s:%d:%s()) ",
 860                            current->pid, file, line, fn);
 861 #endif
 862
 863         va_start(ap, format);
 864         msg_nob += vsnprintf(debug_buf + debug_off + prefix_nob + msg_nob,
 865                              max_nob, format, ap);
 866         max_nob -= msg_nob;
 867         va_end(ap);
 868
 869         /* Print to console, while msg is contiguous in debug_buf */
 870         /* NB safely terminated see above */
 871         if ((mask & D_EMERG) != 0)
 872                 printk(KERN_EMERG "LustreError: %s",
 873                        debug_buf + debug_off + prefix_nob);
 874         else if ((mask & D_ERROR) != 0)
 875                 printk(KERN_ERR "LustreError: %s",
 876                        debug_buf + debug_off + prefix_nob);
 877         else if ((mask & D_WARNING) != 0)
 878                 printk(KERN_WARNING "Lustre: %s",
 879                        debug_buf + debug_off + prefix_nob);
 880         else if (portal_printk)
 881                 printk("<%d>Lustre: %s", portal_printk,
 882                        debug_buf+debug_off+prefix_nob);
 883         base_offset = debug_off & 0xFFFF;
 884
 885         debug_off += prefix_nob + msg_nob;
 886         if (debug_off > debug_size) {
 887                 memcpy(debug_buf, debug_buf + debug_size,
 888                        debug_off - debug_size + 1);
 889                 debug_off -= debug_size;
 890                 debug_wrapped = 1;
 891         }
 892
 893         atomic_set(&debug_off_a, debug_off);
 894         if (!atomic_read(&debug_daemon_state.paused) &&
 895             ((base_offset+prefix_nob+msg_nob) >= DAEMON_SND_SIZE)) {
 896                 debug_daemon_state.daemon_event = 1;
 897                 wake_up(&debug_daemon_state.daemon);
 898         }
 899 out:
 900         spin_unlock_irqrestore(&portals_debug_lock, flags);
 901 }
 902
 903 void portals_debug_set_level(unsigned int debug_level)
 904 {
 905         printk("Lustre: Setting portals debug level to %08x\n", debug_level);
 906         portal_debug = debug_level;
 907 }
 908
 909 void portals_run_upcall(char **argv)
 910 {
 911         int   rc;
 912         int   argc;
 913         char *envp[] = {
 914                 "HOME=/",
 915                 "PATH=/sbin:/bin:/usr/sbin:/usr/bin",
 916                 NULL};
 917         ENTRY;
 918
 919         argv[0] = portals_upcall;
 920         argc = 1;
 921         while (argv[argc] != NULL)
 922                 argc++;
 923
 924         LASSERT(argc >= 2);
 925
 926         rc = USERMODEHELPER(argv[0], argv, envp);
 927         if (rc < 0) {
 928                 CERROR("Error %d invoking portals upcall %s %s%s%s%s%s%s%s%s; "
 929                        "check /proc/sys/portals/upcall\n",
 930                        rc, argv[0], argv[1],
 931                        argc < 3 ? "" : ",", argc < 3 ? "" : argv[2],
 932                        argc < 4 ? "" : ",", argc < 4 ? "" : argv[3],
 933                        argc < 5 ? "" : ",", argc < 5 ? "" : argv[4],
 934                        argc < 6 ? "" : ",...");
 935         } else {
 936                 CERROR("Invoked portals upcall %s %s%s%s%s%s%s%s%s\n",
 937                        argv[0], argv[1],
 938                        argc < 3 ? "" : ",", argc < 3 ? "" : argv[2],
 939                        argc < 4 ? "" : ",", argc < 4 ? "" : argv[3],
 940                        argc < 5 ? "" : ",", argc < 5 ? "" : argv[4],
 941                        argc < 6 ? "" : ",...");
 942         }
 943 }
 944
 945 void portals_run_lbug_upcall(char *file, const char *fn, const int line)
 946 {
 947         char *argv[6];
 948         char buf[32];
 949
 950         ENTRY;
 951         snprintf (buf, sizeof buf, "%d", line);
 952
 953         argv[1] = "LBUG";
 954         argv[2] = file;
 955         argv[3] = (char *)fn;
 956         argv[4] = buf;
 957         argv[5] = NULL;
 958
 959         portals_run_upcall (argv);
 960 }
 961
 962 char *portals_nid2str(int nal, ptl_nid_t nid, char *str)
 963 {
 964         switch(nal){
 965 /* XXX this could be a nal method of some sort, 'cept it's config
 966  * dependent whether (say) socknal NIDs are actually IP addresses... */
 967 #ifndef CRAY_PORTALS
 968         case TCPNAL:
 969                 /* userspace NAL */
 970         case SOCKNAL:
 971                 snprintf(str, PTL_NALFMT_SIZE - 1, "%u:%u.%u.%u.%u",
 972                          (__u32)(nid >> 32), HIPQUAD(nid));
 973                 break;
 974         case QSWNAL:
 975         case GMNAL:
 976         case IBNAL:
 977                 snprintf(str, PTL_NALFMT_SIZE - 1, "%u:%u",
 978                          (__u32)(nid >> 32), (__u32)nid);
 979                 break;
 980 #endif
 981         default:
 982                 snprintf(str, PTL_NALFMT_SIZE - 1, "?%d? %llx",
 983                          nal, (long long)nid);
 984                 break;
 985         }
 986         return str;
 987 }
 988
 989 #ifdef __KERNEL__
 990 char stack_backtrace[LUSTRE_TRACE_SIZE];
 991 spinlock_t stack_backtrace_lock = SPIN_LOCK_UNLOCKED;
 992
 993 #if defined(__arch_um__)
 994
 995 char *portals_debug_dumpstack(void)
 996 {
 997         asm("int $3");
 998         return "dump stack\n";
 999 }
1000
1001 #elif defined(__i386__)
1002
1003 #if (LINUX_VERSION_CODE < KERNEL_VERSION(2,5,0))
1004 extern int lookup_symbol(unsigned long address, char *buf, int buflen);
1005 const char *kallsyms_lookup(unsigned long addr,
1006                             unsigned long *symbolsize,
1007                             unsigned long *offset,
1008                             char **modname, char *namebuf)
1009 {
1010         int rc = lookup_symbol(addr, namebuf, 128);
1011         if (rc == -ENOSYS)
1012                 return NULL;
1013         return namebuf;
1014 }
1015 #endif
1016
1017 char *portals_debug_dumpstack(void)
1018 {
1019         unsigned long esp = current->thread.esp, addr;
1020         unsigned long *stack = (unsigned long *)&esp;
1021         char *buf = stack_backtrace, *pbuf = buf;
1022         int size;
1023
1024         /* User space on another CPU? */
1025         if ((esp ^ (unsigned long)current) & (PAGE_MASK << 1)){
1026                 buf[0] = '\0';
1027                 goto out;
1028         }
1029
1030         size = sprintf(pbuf, " Call Trace: ");
1031         pbuf += size;
1032         while (((long) stack & (THREAD_SIZE - 1)) != 0) {
1033                 addr = *stack++;
1034                 if (kernel_text_address(addr)) {
1035                         const char *sym_name;
1036                         char *modname, buffer[128];
1037                         unsigned long junk, offset;
1038
1039                         sym_name = kallsyms_lookup(addr, &junk, &offset,
1040                                                    &modname, buffer);
1041                         if (sym_name == NULL) {
1042                                 if (buf + LUSTRE_TRACE_SIZE <= pbuf + 12)
1043                                         break;
1044                                 size = sprintf(pbuf, "[<%08lx>] ", addr);
1045                         } else {
1046                                 if (buf + LUSTRE_TRACE_SIZE
1047                                             /* fix length + sizeof('\0') */
1048                                     <= pbuf + strlen(buffer) + 28 + 1)
1049                                         break;
1050                                 size = sprintf(pbuf, "([<%08lx>] %s (0x%p)) ",
1051                                                addr, buffer, stack - 1);
1052                         }
1053                         pbuf += size;
1054                 }
1055         }
1056 out:
1057         return buf;
1058 }
1059
1060 #else /* !__arch_um__ && !__i386__ */
1061
1062 char *portals_debug_dumpstack(void)
1063 {
1064         char *buf = stack_backtrace;
1065         buf[0] = '\0';
1066         return buf;
1067 }
1068
1069 #endif /* __arch_um__ */
1070 EXPORT_SYMBOL(stack_backtrace_lock);
1071 EXPORT_SYMBOL(portals_debug_dumpstack);
1072 #endif /* __KERNEL__ */
1073
1074 EXPORT_SYMBOL(portals_debug_dumplog);
1075 EXPORT_SYMBOL(portals_debug_msg);
1076 EXPORT_SYMBOL(portals_debug_set_level);
1077 EXPORT_SYMBOL(portals_run_upcall);
1078 EXPORT_SYMBOL(portals_run_lbug_upcall);
1079 EXPORT_SYMBOL(portals_nid2str);