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