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