lustre/portals/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 wait_queue_head_t 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 ... writing ...\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         ENTRY;
 420
 421         init_waitqueue_head(&debug_ctlwq);
 422
 423         rc = kernel_thread(portals_do_debug_dumplog,
 424                            NULL, CLONE_VM | CLONE_FS | CLONE_FILES);
 425         if (rc < 0) {
 426                 printk(KERN_ERR "LustreError: cannot start log dump thread: "
 427                        "%d\n", rc);
 428                 return;
 429         }
 430         sleep_on(&debug_ctlwq);
 431 }
 432
 433 int portals_debug_daemon_start(char *file, unsigned int size)
 434 {
 435         int rc;
 436
 437         if (!debug_daemon_state.stopped)
 438                 return -EALREADY;
 439
 440         if (file != NULL)
 441                 strncpy(debug_daemon_file_path, file, 1024);
 442
 443         init_waitqueue_head(&debug_daemon_state.lctl);
 444         init_waitqueue_head(&debug_daemon_state.daemon);
 445
 446         daemon_file_size_limit = size << 20;
 447
 448         debug_daemon_state.lctl_event = 0;
 449         rc = kernel_thread(portals_debug_daemon, NULL, 0);
 450         if (rc < 0) {
 451                 printk(KERN_ERR "LustreError: cannot start debug daemon thread\n");
 452                 strncpy(debug_daemon_file_path, "\0", 1);
 453                 return rc;
 454         }
 455         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 456         return 0;
 457 }
 458
 459 int portals_debug_daemon_pause(void)
 460 {
 461         if (atomic_read(&debug_daemon_state.paused))
 462                 return -EALREADY;
 463
 464         atomic_set(&debug_daemon_state.paused, 1);
 465         debug_daemon_state.lctl_event = 0;
 466         debug_daemon_state.daemon_event = 1;
 467         wake_up(&debug_daemon_state.daemon);
 468         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 469         return 0;
 470 }
 471
 472 int portals_debug_daemon_continue(void)
 473 {
 474         if (!atomic_read(&debug_daemon_state.paused))
 475                 return -EINVAL;
 476         if (debug_daemon_state.stopped)
 477                 return -EINVAL;
 478
 479         debug_daemon_state.overlapped = 0;
 480         atomic_set(&debug_daemon_next_write, atomic_read(&debug_off_a));
 481         atomic_set(&debug_daemon_state.paused, 0);
 482         return 0;
 483 }
 484
 485 int portals_debug_daemon_stop(void)
 486 {
 487         if (debug_daemon_state.stopped)
 488                 return -EALREADY;
 489
 490         if (!atomic_read(&debug_daemon_state.paused))
 491                 portals_debug_daemon_pause();
 492
 493         debug_daemon_state.lctl_event = 0;
 494         debug_daemon_state.stopped = 1;
 495
 496         debug_daemon_state.daemon_event = 1;
 497         wake_up(&debug_daemon_state.daemon);
 498         wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
 499
 500         debug_daemon_file_path[0] = '\0';
 501         return 0;
 502 }
 503
 504 int portals_debug_set_daemon(unsigned int cmd, unsigned int length,
 505                              char *filename, unsigned int size)
 506 {
 507         int rc = -EINVAL;
 508
 509         down(&debug_daemon_semaphore);
 510         switch (cmd) {
 511                 case DEBUG_DAEMON_START:
 512                         if (length && (filename[length -1] != '\0')) {
 513                                 CERROR("Invalid filename for debug_daemon\n");
 514                                 rc = -EINVAL;
 515                                 break;
 516                         }
 517                         rc = portals_debug_daemon_start(filename, size);
 518                         break;
 519                 case DEBUG_DAEMON_STOP:
 520                         rc = portals_debug_daemon_stop();
 521                         break;
 522                 case DEBUG_DAEMON_PAUSE:
 523                         rc = portals_debug_daemon_pause();
 524                         break;
 525                 case DEBUG_DAEMON_CONTINUE:
 526                         rc = portals_debug_daemon_continue();
 527                         break;
 528                 default:
 529                         CERROR("unknown set_daemon cmd\n");
 530         }
 531         up(&debug_daemon_semaphore);
 532         return rc;
 533 }
 534
 535 static int panic_dumplog(struct notifier_block *self, unsigned long unused1,
 536                          void *unused2)
 537 {
 538         if (handled_panic)
 539                 return 0;
 540         else
 541                 handled_panic = 1;
 542
 543         if (in_interrupt()) {
 544                 portals_debug_print();
 545                 return 0;
 546         }
 547
 548         while (current->lock_depth >= 0)
 549                 unlock_kernel();
 550         portals_debug_dumplog();
 551         return 0;
 552 }
 553
 554 static struct notifier_block lustre_panic_notifier = {
 555         notifier_call :     panic_dumplog,
 556         next :              NULL,
 557         priority :          10000
 558 };
 559
 560 int portals_debug_init(unsigned long bufsize)
 561 {
 562         unsigned long debug_off = atomic_read(&debug_off_a);
 563         if (debug_buf != NULL)
 564                 return -EALREADY;
 565
 566         atomic_set(&debug_daemon_state.paused, 1);
 567         debug_daemon_state.stopped = 1;
 568
 569         debug_buf = vmalloc(bufsize + DEBUG_OVERFLOW);
 570         if (debug_buf == NULL)
 571                 return -ENOMEM;
 572         memset(debug_buf, 0, debug_size);
 573         debug_wrapped = 0;
 574
 575         //printk(KERN_INFO "Portals: allocated %lu byte debug buffer at %p.\n",
 576                //bufsize, debug_buf);
 577         atomic_set(&debug_off_a, debug_off);
 578         notifier_chain_register(&panic_notifier_list, &lustre_panic_notifier);
 579         debug_size = bufsize;
 580
 581         return 0;
 582 }
 583
 584 int portals_debug_cleanup(void)
 585 {
 586         notifier_chain_unregister(&panic_notifier_list, &lustre_panic_notifier);
 587         if (debug_buf == NULL)
 588                 return -EINVAL;
 589
 590         down(&debug_daemon_semaphore);
 591         portals_debug_daemon_stop();
 592
 593         vfree(debug_buf);
 594         atomic_set(&debug_off_a, 0);
 595         up(&debug_daemon_semaphore);
 596
 597         return 0;
 598 }
 599
 600 int portals_debug_clear_buffer(void)
 601 {
 602         unsigned long flags;
 603         unsigned long state;
 604
 605         if (debug_buf == NULL)
 606                 return -EINVAL;
 607
 608         down(&debug_daemon_semaphore);
 609         state = atomic_read(&debug_daemon_state.paused);
 610         if (!state)
 611                 portals_debug_daemon_pause();
 612         spin_lock_irqsave(&portals_debug_lock, flags);
 613         atomic_set(&debug_off_a, 0);
 614         debug_wrapped = 0;
 615         atomic_set(&debug_daemon_next_write, 0);
 616         debug_daemon_state.overlapped = 0;
 617         spin_unlock_irqrestore(&portals_debug_lock, flags);
 618
 619         if (!state)
 620                 atomic_set(&debug_daemon_state.paused, 0);
 621         up(&debug_daemon_semaphore);
 622
 623         return 0;
 624 }
 625
 626 /* Debug markers, although printed by S_PORTALS
 627  * should not be be marked as such.
 628  */
 629 #undef DEBUG_SUBSYSTEM
 630 #define DEBUG_SUBSYSTEM S_UNDEFINED
 631 int portals_debug_mark_buffer(char *text)
 632 {
 633         if (debug_buf == NULL)
 634                 return -EINVAL;
 635
 636         CDEBUG(0, "********************************************************\n");
 637         CWARN("DEBUG MARKER: %s\n", text);
 638         CDEBUG(0, "********************************************************\n");
 639
 640         return 0;
 641 }
 642 #undef DEBUG_SUBSYSTEM
 643 #define DEBUG_SUBSYSTEM S_PORTALS
 644
 645 /* this copies a snapshot of the debug buffer into an array of pages
 646  * before doing the potentially blocking copy into userspace. it could
 647  * be warning userspace if things wrap heavily while its off copying. */
 648 __s32 portals_debug_copy_to_user(char *buf, unsigned long len)
 649 {
 650         int rc;
 651         unsigned long total, debug_off, i, off, copied;
 652         unsigned long flags;
 653         struct page *page;
 654         LIST_HEAD(my_pages);
 655         struct list_head *pos, *n;
 656
 657         if (len < debug_size)
 658                 return -ENOSPC;
 659
 660         for (i = 0 ; i < debug_size; i += PAGE_SIZE) {
 661                 page = alloc_page(GFP_NOFS);
 662                 if (page == NULL) {
 663                         rc = -ENOMEM;
 664                         goto cleanup;
 665                 }
 666                 list_add(&page->list, &my_pages);
 667         }
 668
 669         spin_lock_irqsave(&portals_debug_lock, flags);
 670         debug_off = atomic_read(&debug_off_a);
 671
 672         /* Sigh. If the buffer is empty, then skip to the end. */
 673         if (debug_off == 0 && !debug_wrapped) {
 674                 spin_unlock_irqrestore(&portals_debug_lock, flags);
 675                 rc = 0;
 676                 goto cleanup;
 677         }
 678
 679         if (debug_wrapped) {
 680                 off = debug_off + 1;
 681                 total = debug_size;
 682         } else {
 683                 off = 0;
 684                 total = debug_off;
 685         }
 686         copied = 0;
 687         list_for_each(pos, &my_pages) {
 688                 unsigned long to_copy;
 689                 void *addr;
 690
 691                 page = list_entry(pos, struct page, list);
 692                 to_copy = min(total - off, PAGE_SIZE);
 693                 if (to_copy == 0) {
 694                         off = 0;
 695                         to_copy = min(debug_size - off, PAGE_SIZE);
 696                 }
 697 finish_partial:
 698                 addr = kmap_atomic(page, KM_USER0);
 699                 memcpy(addr, debug_buf + off, to_copy);
 700                 kunmap_atomic(addr, KM_USER0);
 701                 copied += to_copy;
 702                 if (copied >= total)
 703                         break;
 704
 705                 off += to_copy;
 706                 if (off >= debug_size) {
 707                         off = 0;
 708                         if (to_copy != PAGE_SIZE) {
 709                                 to_copy = PAGE_SIZE - to_copy;
 710                                 goto finish_partial;
 711                         }
 712                 }
 713         }
 714
 715         spin_unlock_irqrestore(&portals_debug_lock, flags);
 716
 717         off = 0;
 718         list_for_each(pos, &my_pages) {
 719                 unsigned long to_copy;
 720                 page = list_entry(pos, struct page, list);
 721
 722                 to_copy = min(copied - off, PAGE_SIZE);
 723                 rc = copy_to_user(buf + off, kmap(page), to_copy);
 724                 kunmap(page);
 725                 if (rc) {
 726                         rc = -EFAULT;
 727                         goto cleanup;
 728                 }
 729                 off += to_copy;
 730                 if (off >= copied)
 731                         break;
 732         }
 733         rc = copied;
 734
 735 cleanup:
 736         list_for_each_safe(pos, n, &my_pages) {
 737                 page = list_entry(pos, struct page, list);
 738                 list_del(&page->list);
 739                 __free_page(page);
 740         }
 741         return rc;
 742 }
 743
 744 /* FIXME: I'm not very smart; someone smarter should make this better. */
 745 void
 746 portals_debug_msg(int subsys, int mask, char *file, const char *fn,
 747                   const int line, unsigned long stack, char *format, ...)
 748 {
 749         va_list       ap;
 750         unsigned long flags;
 751         int           max_nob;
 752         int           prefix_nob;
 753         int           msg_nob;
 754         struct timeval tv;
 755         unsigned long base_offset;
 756         unsigned long debug_off;
 757
 758         if (debug_buf == NULL) {
 759                 printk("LustreError: portals_debug_msg: debug_buf is NULL!\n");
 760                 return;
 761         }
 762
 763         spin_lock_irqsave(&portals_debug_lock, flags);
 764         debug_off = atomic_read(&debug_off_a);
 765         if (!atomic_read(&debug_daemon_state.paused)) {
 766                 unsigned long available;
 767                 long delta;
 768                 long v = atomic_read(&debug_daemon_next_write);
 769
 770                 delta = debug_off - v;
 771                 available = (delta>=0) ? debug_size-delta : -delta;
 772                 // Check if we still have enough debug buffer for CDEBUG
 773                 if (available < DAEMON_SND_SIZE) {
 774                         /* Drop CDEBUG packets until enough debug_buffer is
 775                          * available */
 776                         if (debug_daemon_state.overlapped)
 777                                  goto out;
 778                         /* If this is the first time, leave a marker in the
 779                          * output */
 780                         debug_daemon_state.overlapped = 1;
 781                         format = "DEBUG MARKER: Debug buffer overlapped\n";
 782                         printk(KERN_ERR "LustreError: debug daemon buffer "
 783                                "overlapped\n");
 784                 } else  /* More space just became available */
 785                         debug_daemon_state.overlapped = 0;
 786         }
 787
 788         max_nob = debug_size - debug_off + DEBUG_OVERFLOW;
 789         if (max_nob <= 0) {
 790                 spin_unlock_irqrestore(&portals_debug_lock, flags);
 791                 printk("LustreError: logic error in portals_debug_msg: "
 792                        "< 0 bytes to write\n");
 793                 return;
 794         }
 795
 796         /* NB since we pass a non-zero sized buffer (at least) on the first
 797          * print, we can be assured that by the end of all the snprinting,
 798          * we _do_ have a terminated buffer, even if our message got truncated.
 799          */
 800
 801         do_gettimeofday(&tv);
 802
 803         prefix_nob = snprintf(debug_buf + debug_off, max_nob,
 804                               "%06x:%06x:%d:%lu.%06lu:%lu:%d:",
 805                               subsys, mask, smp_processor_id(),
 806                               tv.tv_sec, tv.tv_usec, stack, current->pid);
 807         max_nob -= prefix_nob;
 808
 809         if(*(format + strlen(format) - 1) != '\n')
 810                 printk(KERN_INFO "format at %s:%d:%s doesn't end in newline\n",
 811                        file, line, fn);
 812
 813 #if defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,4,20))
 814         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 815                            "%d:(%s:%d:%s()) ",
 816                            current->thread.extern_pid, file, line, fn);
 817 #elif defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,5,0))
 818         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 819                            "%d:(%s:%d:%s()) ",
 820                            current->thread.mode.tt.extern_pid, file, line, fn);
 821 #else
 822         msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
 823                            "%d:(%s:%d:%s()) ",
 824                            current->pid, file, line, fn);
 825 #endif
 826
 827         va_start(ap, format);
 828         msg_nob += vsnprintf(debug_buf + debug_off + prefix_nob + msg_nob,
 829                              max_nob, format, ap);
 830         max_nob -= msg_nob;
 831         va_end(ap);
 832
 833         /* Print to console, while msg is contiguous in debug_buf */
 834         /* NB safely terminated see above */
 835         if ((mask & D_EMERG) != 0)
 836                 printk(KERN_EMERG "LustreError: %s",
 837                        debug_buf + debug_off + prefix_nob);
 838         else if ((mask & D_ERROR) != 0)
 839                 printk(KERN_ERR "LustreError: %s",
 840                        debug_buf + debug_off + prefix_nob);
 841         else if ((mask & D_WARNING) != 0)
 842                 printk(KERN_WARNING "Lustre: %s",
 843                        debug_buf + debug_off + prefix_nob);
 844         else if (portal_printk)
 845                 printk("<%d>Lustre: %s", portal_printk,
 846                        debug_buf+debug_off+prefix_nob);
 847         base_offset = debug_off & 0xFFFF;
 848
 849         debug_off += prefix_nob + msg_nob;
 850         if (debug_off > debug_size) {
 851                 memcpy(debug_buf, debug_buf + debug_size,
 852                        debug_off - debug_size + 1);
 853                 debug_off -= debug_size;
 854                 debug_wrapped = 1;
 855         }
 856
 857         atomic_set(&debug_off_a, debug_off);
 858         if (!atomic_read(&debug_daemon_state.paused) &&
 859             ((base_offset+prefix_nob+msg_nob) >= DAEMON_SND_SIZE)) {
 860                 debug_daemon_state.daemon_event = 1;
 861                 wake_up(&debug_daemon_state.daemon);
 862         }
 863 out:
 864         spin_unlock_irqrestore(&portals_debug_lock, flags);
 865 }
 866
 867 void portals_debug_set_level(unsigned int debug_level)
 868 {
 869         printk("Lustre: Setting portals debug level to %08x\n", debug_level);
 870         portal_debug = debug_level;
 871 }
 872
 873 void portals_run_upcall(char **argv)
 874 {
 875         int   rc;
 876         int   argc;
 877         char *envp[] = {
 878                 "HOME=/",
 879                 "PATH=/sbin:/bin:/usr/sbin:/usr/bin",
 880                 NULL};
 881         ENTRY;
 882
 883         argv[0] = portals_upcall;
 884         argc = 1;
 885         while (argv[argc] != NULL)
 886                 argc++;
 887
 888         LASSERT(argc >= 2);
 889
 890         rc = USERMODEHELPER(argv[0], argv, envp);
 891         if (rc < 0) {
 892                 CERROR("Error %d invoking portals upcall %s %s%s%s%s%s%s%s%s; "
 893                        "check /proc/sys/portals/upcall\n",
 894                        rc, argv[0], argv[1],
 895                        argc < 3 ? "" : ",", argc < 3 ? "" : argv[2],
 896                        argc < 4 ? "" : ",", argc < 4 ? "" : argv[3],
 897                        argc < 5 ? "" : ",", argc < 5 ? "" : argv[4],
 898                        argc < 6 ? "" : ",...");
 899         } else {
 900                 CERROR("Invoked portals upcall %s %s%s%s%s%s%s%s%s\n",
 901                        argv[0], argv[1],
 902                        argc < 3 ? "" : ",", argc < 3 ? "" : argv[2],
 903                        argc < 4 ? "" : ",", argc < 4 ? "" : argv[3],
 904                        argc < 5 ? "" : ",", argc < 5 ? "" : argv[4],
 905                        argc < 6 ? "" : ",...");
 906         }
 907 }
 908
 909 void portals_run_lbug_upcall(char *file, const char *fn, const int line)
 910 {
 911         char *argv[6];
 912         char buf[32];
 913
 914         ENTRY;
 915         snprintf (buf, sizeof buf, "%d", line);
 916
 917         argv[1] = "LBUG";
 918         argv[2] = file;
 919         argv[3] = (char *)fn;
 920         argv[4] = buf;
 921         argv[5] = NULL;
 922
 923         portals_run_upcall (argv);
 924 }
 925
 926 char *portals_nid2str(int nal, ptl_nid_t nid, char *str)
 927 {
 928         switch(nal){
 929         case TCPNAL:
 930                 /* userspace NAL */
 931         case SOCKNAL:
 932                 sprintf(str, "%u:%d.%d.%d.%d", (__u32)(nid >> 32),
 933                         HIPQUAD(nid));
 934                 break;
 935         case QSWNAL:
 936         case GMNAL:
 937         case IBNAL:
 938         case SCIMACNAL:
 939                 sprintf(str, "%u:%u", (__u32)(nid >> 32), (__u32)nid);
 940                 break;
 941         default:
 942                 return NULL;
 943         }
 944         return str;
 945 }
 946
 947 #ifdef __KERNEL__
 948 #include <linux/lustre_version.h>
 949 #if (LUSTRE_KERNEL_VERSION >= 30)
 950 #warning "FIXME: remove workaround when l30 is widely used"
 951 char stack_backtrace[LUSTRE_TRACE_SIZE];
 952 spinlock_t stack_backtrace_lock = SPIN_LOCK_UNLOCKED;
 953
 954 #if defined(__arch_um__)
 955
 956 extern int is_kernel_text_address(unsigned long addr);
 957
 958 char *portals_debug_dumpstack(void)
 959 {
 960         asm("int $3");
 961         return "dump stack";
 962 }
 963
 964 #elif defined(__i386__)
 965
 966 extern int is_kernel_text_address(unsigned long addr);
 967 extern int lookup_symbol(unsigned long address, char *buf, int buflen);
 968
 969 char *portals_debug_dumpstack(void)
 970 {
 971         unsigned long esp = current->thread.esp;
 972         unsigned long *stack = (unsigned long *)&esp;
 973         int size;
 974         unsigned long addr;
 975         char *buf = stack_backtrace;
 976         char *pbuf = buf;
 977         static char buffer[512];
 978         int rc = 0;
 979
 980         /* User space on another CPU? */
 981         if ((esp ^ (unsigned long)current) & (PAGE_MASK<<1)){
 982                 buf[0] = '\0';
 983                 goto out;
 984         }
 985
 986         size = sprintf(pbuf, " Call Trace: ");
 987         pbuf += size;
 988         while (((long) stack & (THREAD_SIZE-1)) != 0) {
 989                 addr = *stack++;
 990                 if (is_kernel_text_address(addr)) {
 991                         rc = lookup_symbol(addr, buffer, 512);
 992                         if (rc == -ENOSYS) {
 993                                 if (buf + LUSTRE_TRACE_SIZE <= pbuf + 12)
 994                                         break;
 995                                 size = sprintf(pbuf, "[<%08lx>] ", addr);
 996                         } else {
 997                                 if (buf + LUSTRE_TRACE_SIZE
 998                                             /* fix length + sizeof('\0') */
 999                                     <= pbuf + strlen(buffer) + 28 + 1)
1000                                         break;
1001                                 size = sprintf(pbuf, "([<%08lx>] %s (0x%p)) ",
1002                                                addr, buffer, stack-1);
1003                         }
1004                         pbuf += size;
1005                 }
1006         }
1007 out:
1008         return buf;
1009 }
1010
1011 #else /* !__arch_um__ && !__i386__ */
1012
1013 char *portals_debug_dumpstack(void)
1014 {
1015         char *buf = stack_backtrace;
1016         buf[0] = '\0';
1017         return buf;
1018 }
1019
1020 #endif /* __arch_um__ */
1021 EXPORT_SYMBOL(stack_backtrace_lock);
1022 EXPORT_SYMBOL(portals_debug_dumpstack);
1023 #endif /* LUSTRE_KERNEL_VERSION < 30 */
1024 #endif /* __KERNEL__ */
1025
1026 EXPORT_SYMBOL(portals_debug_dumplog);
1027 EXPORT_SYMBOL(portals_debug_msg);
1028 EXPORT_SYMBOL(portals_debug_set_level);
1029 EXPORT_SYMBOL(portals_run_upcall);
1030 EXPORT_SYMBOL(portals_run_lbug_upcall);
1031 EXPORT_SYMBOL(portals_nid2str);