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