1 /* -*- mode: c; c-basic-offset: 8; indent-tabs-mode: nil; -*-
2 * vim:expandtab:shiftwidth=8:tabstop=8:
4 * Copyright (C) 2002 Cluster File Systems, Inc.
5 * Author: Phil Schwan <phil@clusterfs.com>
7 * This file is part of Portals, http://www.sf.net/projects/sandiaportals/
9 * Portals is free software; you can redistribute it and/or
10 * modify it under the terms of version 2.1 of the GNU Lesser General
11 * Public License as published by the Free Software Foundation.
13 * Portals 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 Lesser General Public License for more details.
18 * You should have received a copy of the GNU Lesser General Public
19 * License along with Portals; if not, write to the Free Software
20 * Foundation, Inc., 675 Mass Ave, Cambridge, MA 02139, USA.
25 #include <linux/config.h>
26 #include <linux/module.h>
27 #include <linux/kmod.h>
28 #include <linux/notifier.h>
29 #include <linux/kernel.h>
30 #include <linux/kernel.h>
32 #include <linux/string.h>
33 #include <linux/stat.h>
34 #include <linux/errno.h>
35 #include <linux/smp_lock.h>
36 #include <linux/unistd.h>
37 #include <linux/interrupt.h>
38 #include <asm/system.h>
39 #include <asm/uaccess.h>
40 #include <linux/completion.h>
43 #include <linux/stat.h>
44 #include <asm/uaccess.h>
45 #include <asm/segment.h>
46 #include <linux/miscdevice.h>
48 # define DEBUG_SUBSYSTEM S_PORTALS
50 #include <linux/kp30.h>
52 #define DEBUG_OVERFLOW 1024
53 static char *debug_buf = NULL;
54 static unsigned long debug_size = 0;
55 static atomic_t debug_off_a = ATOMIC_INIT(0);
56 static int debug_wrapped;
57 wait_queue_head_t debug_ctlwq;
58 #define DAEMON_SND_SIZE (64 << 10)
61 * used by the daemon to keep track the offset into debug_buffer for the next
62 * write to the file. Usually, the daemon is to write out buffer
63 * from debug_daemon_next_write upto debug_off
65 * Reader - portals_debug_msg()
66 * Writer - portals_debug_daemon()
67 * portals_debug_daemon_start() during daemon init time
68 * portals_debug_daemon_continue() to reset to debug_off
69 * portals_debug_clear_buffer() reset to debug_off for clear
70 * Note that *_start(), *_continue() & *clear_buffer() should serialized;
72 static atomic_t debug_daemon_next_write;
75 * A debug_daemon can be in following states
76 * stopped - stopped state means there is no debug_daemon running.
77 * accordingly, it must be in paused state
78 * a daemon is in !stopped && !paused state after
79 * "lctl debug_daemon start" creates debug_daemon successfully
81 * Reader - portals_debug_daemon()
82 * portals_debug_set_daemon() routines
83 * Writer - portals_debug_set_daemon() routines
84 * portals_debug_daemon() on IO error
85 * paused - a debug_daemon state is changed from !paused into paused
86 * when "lctl debug_daemon paused" is issued
87 * "lctl debug_daemon continue" gets a daemon into !paused mode
88 * Reader - portals_debug_set_daemon() routines
90 * Writer - portals_debug_set_daemon() on init
91 * portals_debug_daemon()
93 * Daemon state diagram.
95 * | <-- debug_daemon start
98 * | <-- debug_daemon pause
101 * | <-- debug_daemon continue
103 * (!stopped, !paused)
104 * | <-- debug_daemon stop
107 * Overlapped - this is a state when CDEBUG is too fast for the daemon to
108 * write out the debug_bufferr. That is, debug_off is to
109 * overlap debug_daemon_next_write;
110 * Reader - portals_debug_msg()
111 * Writer - portals_debug_msg()
115 * Description on Trace Daemon Synchronization
117 * Three categories of code are synchronizing between each other
118 * 1. lctl, portals_debug_set_daemon(), the user debug control code,
119 * as well as portals_debug_clear_buffer()
120 * 2. CDEBUG, portals_debug_msg(), the debug put messages routine
121 * 3. Daemon, portals_debug_daemon(), to write out debug log file
124 * Three different controls for synchronizations
126 * 1. debug_daemon_semaphore
127 * The usage of this semaphore is to serialize multiple lctl controls
128 * in manipulating debug daemon state. The semaphore serves as the
129 * gatekeeper to allow only one user control thread, at any giving time,
130 * to access debug daemon state and keeps the other user control requests
131 * in wait state until the current control request is serviced.
133 * 2. wait_queue_head_t lctl (paired with lctl_event flag)
134 * Lctl event is the event between portals_debug_set_daemon() and
135 * portals_debug_daemon(). Lctl is an indicator for portals_debug_daemon()
136 * to flush data out to file. portals_debug_daemon() is to use lctl event
137 * as signal channel to wakeup portals_debug_set_daemon() upon flush
141 * portals_debug_daemon() uses to wake up
142 * portals_debug_set_daemon(), pause and stop, routines
144 * portals_debug_set_daemon(), stop and pause operations,
145 * wait and sleep on the event
147 * 3. wait_queue_head_t daemon (paired with daemon_event flag)
148 * This is an event channel to wakeup portals_debug_daemon. Daemon
149 * wakes up to run whenever there is an event posted. Daemon handles
150 * 2 types of operations . 1. Writes data out to debug file, 2. Flushes
151 * file and terminates base on lctl event.
153 * Daemon is normally in a sleep state.
154 * Daemon is woken up through daemon event whenever CDEBUG is
155 * putting data over any 64K boundary.
156 * File flush and termination -
157 * On portals_debug_daemon_stop/pause() operations, lctl control
158 * is to wake up daemon through daemon event.
160 * We can't use sleep_on() and wake_up() to replace daemon event because
161 * portals_debug_daemon() must catch the wakeup operation posted by
162 * portals_debug_daemon_stop/pause(). Otherwise, stop and pause may
163 * stuck in lctl wait event.
166 * a. portals_debug_daemon_pause() and portals_debug_daemon_stop()
167 * uses the event to wake up portals_debug_daemon()
168 * b. portals_debug_msg() uses the event to wake up
169 * portals_debug_daemon() whenever the data output is acrossing
170 * a 64K bytes boundary.
172 * portals_debug_daemon() wakes up upon daemon event.
174 * Sequence for portals_debug_daemon_stop() operation
176 * _Portals_debug_daemon_stop()_ _Daemon_
177 * Wait_event(daemon) or running
179 * Wakeup_event (daemon)
181 * Set force_flush flag if lctlevnt
183 * Wakeup_event (lctl)
186 * Wakeup_event (daemon)
188 * Exit daemon loop if (Stopped)
189 * Wakeup_event (lctl)
191 * Return to user application
194 * _Portals_debug_msg()_ _Daemon_
195 * Wait_event(daemon) or running
196 * If (WriteStart<64K<WriteEnd)
197 * Wakeup_event(daemon)
201 struct debug_daemon_state {
202 unsigned long overlapped;
203 unsigned long stopped;
205 unsigned long lctl_event; /* event for lctl */
206 wait_queue_head_t lctl;
207 unsigned long daemon_event; /* event for daemon */
208 wait_queue_head_t daemon;
210 static struct debug_daemon_state debug_daemon_state;
211 static DECLARE_MUTEX(debug_daemon_semaphore);
213 static loff_t daemon_file_size_limit;
214 char debug_daemon_file_path[1024] = "";
216 spinlock_t portals_debug_lock = SPIN_LOCK_UNLOCKED;
217 char debug_file_path[1024] = "/tmp/lustre-log";
218 char debug_file_name[1024];
219 int handled_panic; /* to avoid recursive calls to notifiers */
220 char portals_upcall[1024] = "/usr/lib/lustre/portals_upcall";
223 int portals_do_debug_dumplog(void *arg)
229 unsigned long debug_off;
231 kportal_daemonize("");
234 journal_info = current->journal_info;
235 current->journal_info = NULL;
236 sprintf(debug_file_name, "%s.%ld", debug_file_path, CURRENT_TIME);
237 file = filp_open(debug_file_name, O_CREAT|O_TRUNC|O_RDWR, 0644);
239 if (!file || IS_ERR(file)) {
240 CERROR("cannot open %s for dumping: %ld\n", debug_file_name,
242 GOTO(out, PTR_ERR(file));
244 printk(KERN_ALERT "dumping log to %s ... writing ...\n",
248 debug_off = atomic_read(&debug_off_a);
252 rc = file->f_op->write(file, debug_buf + debug_off + 1,
253 debug_size-debug_off-1, &file->f_pos);
254 rc += file->f_op->write(file, debug_buf, debug_off + 1,
257 rc = file->f_op->write(file, debug_buf, debug_off,&file->f_pos);
259 printk("wrote %d bytes\n", rc);
262 rc = file->f_op->fsync(file, file->f_dentry, 1);
264 CERROR("sync returns %d\n", rc);
267 current->journal_info = journal_info;
268 wake_up(&debug_ctlwq);
272 int portals_debug_daemon(void *arg)
277 unsigned long force_flush = 0;
278 unsigned long size, off, flags;
281 kportal_daemonize("ldebug_daemon");
283 journal_info = current->journal_info;
284 current->journal_info = NULL;
286 file = filp_open(debug_daemon_file_path,
287 O_CREAT|O_TRUNC|O_RDWR|O_LARGEFILE, 0644);
289 if (!file || IS_ERR(file)) {
290 CERROR("cannot open %s for logging", debug_daemon_file_path);
291 GOTO(out1, PTR_ERR(file));
293 printk(KERN_ALERT "daemon dumping log to %s ... writing ...\n",
294 debug_daemon_file_path);
297 debug_daemon_state.overlapped = 0;
298 debug_daemon_state.stopped = 0;
300 spin_lock_irqsave(&portals_debug_lock, flags);
301 off = atomic_read(&debug_off_a) + 1;
303 off = (off >= debug_size)? 0 : off;
306 atomic_set(&debug_daemon_next_write, off);
307 atomic_set(&debug_daemon_state.paused, 0);
308 spin_unlock_irqrestore(&portals_debug_lock, flags);
313 unsigned long ending;
314 unsigned long start, tail;
317 debug_daemon_state.daemon_event = 0;
319 ending = atomic_read(&debug_off_a);
320 start = atomic_read(&debug_daemon_next_write);
322 /* check if paused is imposed by lctl ? */
323 force_flush = !debug_daemon_state.lctl_event;
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;
336 rc = file->f_op->write(file, debug_buf+start,
340 "Debug_daemon write error %d\n", rc);
344 delta = ending - start;
345 tail = debug_size - start;
351 size = (tail == 0) ? ending : tail;
352 if (daemon_file_size_limit == file->f_pos) {
353 // file wrapped around
357 atomic_set(&debug_daemon_next_write, start);
359 rc = file->f_op->fsync(file, file->f_dentry, 1);
362 "Debug_daemon sync error %d\n", rc);
365 if (debug_daemon_state.stopped)
367 debug_daemon_state.lctl_event = 1;
368 wake_up(&debug_daemon_state.lctl);
370 wait_event(debug_daemon_state.daemon,
371 debug_daemon_state.daemon_event);
374 atomic_set(&debug_daemon_state.paused, 1);
375 debug_daemon_state.stopped = 1;
378 current->journal_info = journal_info;
380 debug_daemon_state.lctl_event = 1;
381 wake_up(&debug_daemon_state.lctl);
385 void portals_debug_print(void)
387 unsigned long dumplen = 64 * 1024;
388 char *start1, *start2;
390 unsigned long debug_off = atomic_read(&debug_off_a);
392 start1 = debug_buf + debug_off - dumplen;
393 if (start1 < debug_buf) {
394 start1 += debug_size;
395 end1 = debug_buf + debug_size - 1;
397 end2 = debug_buf + debug_off;
399 end1 = debug_buf + debug_off;
400 start2 = debug_buf + debug_off;
401 end2 = debug_buf + debug_off;
404 while (start1 < end1) {
405 int count = MIN(1024, end1 - start1);
406 printk("%*s", count, start1);
409 while (start2 < end2) {
410 int count = MIN(1024, end2 - start2);
411 printk("%*s", count, start2);
416 void portals_debug_dumplog(void)
421 init_waitqueue_head(&debug_ctlwq);
423 rc = kernel_thread(portals_do_debug_dumplog,
424 NULL, CLONE_VM | CLONE_FS | CLONE_FILES);
426 printk(KERN_ERR "cannot start dump thread\n");
429 sleep_on(&debug_ctlwq);
432 int portals_debug_daemon_start(char *file, unsigned int size)
436 if (!debug_daemon_state.stopped)
440 strncpy(debug_daemon_file_path, file, 1024);
442 init_waitqueue_head(&debug_daemon_state.lctl);
443 init_waitqueue_head(&debug_daemon_state.daemon);
445 daemon_file_size_limit = size << 20;
447 debug_daemon_state.lctl_event = 0;
448 rc = kernel_thread(portals_debug_daemon, NULL, 0);
450 printk(KERN_ERR "cannot start debug daemon thread\n");
451 strncpy(debug_daemon_file_path, "\0", 1);
454 wait_event(debug_daemon_state.lctl, debug_daemon_state.lctl_event);
458 int portals_debug_daemon_pause(void)
460 if (atomic_read(&debug_daemon_state.paused))
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);
471 int portals_debug_daemon_continue(void)
473 if (!atomic_read(&debug_daemon_state.paused))
475 if (debug_daemon_state.stopped)
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);
484 int portals_debug_daemon_stop(void)
486 if (debug_daemon_state.stopped)
489 if (!atomic_read(&debug_daemon_state.paused))
490 portals_debug_daemon_pause();
492 debug_daemon_state.lctl_event = 0;
493 debug_daemon_state.stopped = 1;
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);
499 debug_daemon_file_path[0] = '\0';
503 int portals_debug_set_daemon(unsigned int cmd, unsigned int length,
504 char *filename, unsigned int size)
508 down(&debug_daemon_semaphore);
510 case DEBUG_DAEMON_START:
511 if (length && (filename[length -1] != '\0')) {
512 CERROR("Invalid filename for debug_daemon\n");
516 rc = portals_debug_daemon_start(filename, size);
518 case DEBUG_DAEMON_STOP:
519 rc = portals_debug_daemon_stop();
521 case DEBUG_DAEMON_PAUSE:
522 rc = portals_debug_daemon_pause();
524 case DEBUG_DAEMON_CONTINUE:
525 rc = portals_debug_daemon_continue();
528 CERROR("unknown set_daemon cmd\n");
530 up(&debug_daemon_semaphore);
534 static int panic_dumplog(struct notifier_block *self, unsigned long unused1,
542 if (in_interrupt()) {
543 portals_debug_print();
547 while (current->lock_depth >= 0)
549 portals_debug_dumplog();
553 static struct notifier_block lustre_panic_notifier = {
554 notifier_call : panic_dumplog,
559 int portals_debug_init(unsigned long bufsize)
561 unsigned long debug_off = atomic_read(&debug_off_a);
562 if (debug_buf != NULL)
565 atomic_set(&debug_daemon_state.paused, 1);
566 debug_daemon_state.stopped = 1;
568 debug_buf = vmalloc(bufsize + DEBUG_OVERFLOW);
569 if (debug_buf == NULL)
571 memset(debug_buf, 0, debug_size);
574 printk(KERN_INFO "Portals: allocated %lu byte debug buffer at %p.\n",
576 atomic_set(&debug_off_a, debug_off);
577 notifier_chain_register(&panic_notifier_list, &lustre_panic_notifier);
578 debug_size = bufsize;
583 int portals_debug_cleanup(void)
585 notifier_chain_unregister(&panic_notifier_list, &lustre_panic_notifier);
586 if (debug_buf == NULL)
589 down(&debug_daemon_semaphore);
590 portals_debug_daemon_stop();
593 atomic_set(&debug_off_a, 0);
594 up(&debug_daemon_semaphore);
599 int portals_debug_clear_buffer(void)
604 if (debug_buf == NULL)
607 down(&debug_daemon_semaphore);
608 state = atomic_read(&debug_daemon_state.paused);
610 portals_debug_daemon_pause();
611 spin_lock_irqsave(&portals_debug_lock, flags);
612 atomic_set(&debug_off_a, 0);
614 atomic_set(&debug_daemon_next_write, 0);
615 debug_daemon_state.overlapped = 0;
616 spin_unlock_irqrestore(&portals_debug_lock, flags);
619 atomic_set(&debug_daemon_state.paused, 0);
620 up(&debug_daemon_semaphore);
625 /* Debug markers, although printed by S_PORTALS
626 * should not be be marked as such.
628 #undef DEBUG_SUBSYSTEM
629 #define DEBUG_SUBSYSTEM S_UNDEFINED
630 int portals_debug_mark_buffer(char *text)
632 if (debug_buf == NULL)
635 CDEBUG(0, "*******************************************************************************\n");
636 CDEBUG(0, "DEBUG MARKER: %s\n", text);
637 CDEBUG(0, "*******************************************************************************\n");
641 #undef DEBUG_SUBSYSTEM
642 #define DEBUG_SUBSYSTEM S_PORTALS
644 __s32 portals_debug_copy_to_user(char *buf, unsigned long len)
647 unsigned long debug_off;
650 if (len < debug_size)
653 debug_off = atomic_read(&debug_off_a);
654 spin_lock_irqsave(&portals_debug_lock, flags);
656 /* All of this juggling with the 1s is to keep the trailing nul
657 * (which falls at debug_buf + debug_off) at the end of what we
658 * copy into user space */
659 copy_to_user(buf, debug_buf + debug_off + 1,
660 debug_size - debug_off - 1);
661 copy_to_user(buf + debug_size - debug_off - 1,
662 debug_buf, debug_off + 1);
665 copy_to_user(buf, debug_buf, debug_off);
668 spin_unlock_irqrestore(&portals_debug_lock, flags);
673 /* FIXME: I'm not very smart; someone smarter should make this better. */
675 portals_debug_msg (int subsys, int mask, char *file, char *fn, int line,
676 unsigned long stack, const char *format, ...)
684 unsigned long base_offset;
685 unsigned long debug_off;
687 if (debug_buf == NULL) {
688 printk("portals_debug_msg: debug_buf is NULL!\n");
692 spin_lock_irqsave(&portals_debug_lock, flags);
693 debug_off = atomic_read(&debug_off_a);
694 if (!atomic_read(&debug_daemon_state.paused)) {
695 unsigned long available;
697 long v = atomic_read(&debug_daemon_next_write);
699 delta = debug_off - v;
700 available = (delta>=0) ? debug_size-delta : -delta;
701 // Check if we still have enough debug buffer for CDEBUG
702 if (available < DAEMON_SND_SIZE) {
703 /* Drop CDEBUG packets until enough debug_buffer is
705 if (debug_daemon_state.overlapped)
707 /* If this is the first time, leave a marker in the
709 debug_daemon_state.overlapped = 1;
711 format = "DEBUG MARKER: Debug buffer overlapped\n";
712 } else /* More space just became available */
713 debug_daemon_state.overlapped = 0;
716 max_nob = debug_size - debug_off + DEBUG_OVERFLOW;
718 spin_unlock_irqrestore(&portals_debug_lock, flags);
719 printk("logic error in portals_debug_msg: <0 bytes to write\n");
723 /* NB since we pass a non-zero sized buffer (at least) on the first
724 * print, we can be assured that by the end of all the snprinting,
725 * we _do_ have a terminated buffer, even if our message got truncated.
728 do_gettimeofday(&tv);
730 prefix_nob = snprintf(debug_buf + debug_off, max_nob,
731 "%02x:%06x:%d:%lu.%06lu ",
732 subsys >> 24, mask, smp_processor_id(),
733 tv.tv_sec, tv.tv_usec);
734 max_nob -= prefix_nob;
736 #if defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,4,20))
737 msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
738 "(%s:%d:%s() %d | %d+%lu): ",
739 file, line, fn, current->pid,
740 current->thread.extern_pid, stack);
741 #elif defined(__arch_um__) && (LINUX_VERSION_CODE < KERNEL_VERSION(2,5,0))
742 msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
743 "(%s:%d:%s() %d | %d+%lu): ",
744 file, line, fn, current->pid,
745 current->thread.mode.tt.extern_pid, stack);
747 msg_nob = snprintf(debug_buf + debug_off + prefix_nob, max_nob,
748 "(%s:%d:%s() %d+%lu): ",
749 file, line, fn, current->pid, stack);
753 va_start(ap, format);
754 msg_nob += vsnprintf(debug_buf + debug_off + prefix_nob + msg_nob,
755 max_nob, format, ap);
759 /* Print to console, while msg is contiguous in debug_buf */
760 /* NB safely terminated see above */
761 if ((mask & D_EMERG) != 0)
762 printk(KERN_EMERG "%s", debug_buf + debug_off + prefix_nob);
763 if ((mask & D_ERROR) != 0)
764 printk(KERN_ERR "%s", debug_buf + debug_off + prefix_nob);
765 else if (portal_printk)
766 printk("<%d>%s", portal_printk, debug_buf+debug_off+prefix_nob);
767 base_offset = debug_off & 0xFFFF;
769 debug_off += prefix_nob + msg_nob;
770 if (debug_off > debug_size) {
771 memcpy(debug_buf, debug_buf + debug_size,
772 debug_off - debug_size + 1);
773 debug_off -= debug_size;
777 atomic_set(&debug_off_a, debug_off);
778 if (!atomic_read(&debug_daemon_state.paused) &&
779 ((base_offset+prefix_nob+msg_nob) >= DAEMON_SND_SIZE)) {
780 debug_daemon_state.daemon_event = 1;
781 wake_up(&debug_daemon_state.daemon);
784 spin_unlock_irqrestore(&portals_debug_lock, flags);
787 void portals_debug_set_level(unsigned int debug_level)
789 printk("Setting portals debug level to %08x\n", debug_level);
790 portal_debug = debug_level;
793 void portals_run_lbug_upcall(char * file, char *fn, int line)
801 snprintf (buf, sizeof buf, "%d", line);
803 argv[0] = portals_upcall;
811 envp[1] = "PATH=/sbin:/bin:/usr/sbin:/usr/bin";
814 rc = call_usermodehelper(argv[0], argv, envp);
816 CERROR("Error invoking lbug upcall %s %s %s %s %s: %d; check "
817 "/proc/sys/portals/upcall\n",
818 argv[0], argv[1], argv[2], argv[3], argv[4], rc);
821 CERROR("Invoked upcall %s %s %s %s %s\n",
822 argv[0], argv[1], argv[2], argv[3], argv[4]);
827 EXPORT_SYMBOL(portals_debug_dumplog);
828 EXPORT_SYMBOL(portals_debug_msg);
829 EXPORT_SYMBOL(portals_debug_set_level);
830 EXPORT_SYMBOL(portals_run_lbug_upcall);