aboutsummaryrefslogtreecommitdiffstats
path: root/litmus/sched_trace.c
blob: f4171fddbbb12e5d722b1567149013f5a90437ec (plain) (blame)
1
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
18
19
20
21
22
23
24
25
26
27
28
29
30
31
32
33
34
35
36
37
38
39
40
41
42
43
44
45
46
47
48
49
50
51
52
53
54
55
56
57
58
59
60
61
62
63
64
65
66
67
68
69
70
71
72
73
74
75
76
77
78
79
80
81
82
83
84
85
86
87
88
89
90
91
92
93
94
95
96
97
98
99
100
101
102
103
104
105
106
107
108
109
110
111
112
113
114
115
116
117
118
119
120
121
122
123
124
125
126
127
128
129
130
131
132
133
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
152
153
154
155
156
157
158
159
160
161
162
163
164
165
166
167
168
169
170
171
172
173
174
175
176
177
178
179
180
181
182
183
184
185
186
187
188
189
190
191
192
193
194
195
196
197
198
199
200
201
202
203
204
205
206
207
208
209
210
211
212
213
214
215
216
217
218
219
220
221
222
223
224
225
226
227
228
229
230
231
232
233
234
235
236
237
238
239
240
241
242
243
244
245
246
247
248
249
250
251
252
/*
 * sched_trace.c -- record scheduling events to a byte stream.
 */
#include <linux/spinlock.h>
#include <linux/mutex.h>

#include <linux/fs.h>
#include <linux/slab.h>
#include <linux/miscdevice.h>
#include <asm/uaccess.h>
#include <linux/module.h>
#include <linux/sysrq.h>

#include <linux/kfifo.h>

#include <litmus/sched_trace.h>
#include <litmus/litmus.h>

#define SCHED_TRACE_NAME "litmus/log"

/* Compute size of TRACE() buffer */
#define LITMUS_TRACE_BUF_SIZE (1 << CONFIG_SCHED_DEBUG_TRACE_SHIFT)

/* Max length of one read from the buffer */
#define MAX_READ_LEN (64 * 1024)

/* Max length for one write --- by TRACE() --- to the buffer. This is used to
 * allocate a per-cpu buffer for printf() formatting. */
#define MSG_SIZE 255


static DEFINE_MUTEX(reader_mutex);
static atomic_t reader_cnt = ATOMIC_INIT(0);
static DEFINE_KFIFO(debug_buffer, char, LITMUS_TRACE_BUF_SIZE);


static DEFINE_RAW_SPINLOCK(log_buffer_lock);
static DEFINE_PER_CPU(char[MSG_SIZE], fmt_buffer);

/*
 * sched_trace_log_message - Write to the trace buffer (log_buffer)
 *
 * This is the only function accessing the log_buffer from inside the
 * kernel for writing.
 * Concurrent access to sched_trace_log_message must be serialized using
 * log_buffer_lock
 * The maximum length of a formatted message is 255
 */
void sched_trace_log_message(const char* fmt, ...)
{
	unsigned long 	flags;
	va_list 	args;
	size_t		len;
	char*		buf;

	if (!atomic_read(&reader_cnt))
		/* early exit if nobody is listening */
		return;

	va_start(args, fmt);
	local_irq_save(flags);

	/* format message */
	buf = __get_cpu_var(fmt_buffer);
	len = vscnprintf(buf, MSG_SIZE, fmt, args);

	raw_spin_lock(&log_buffer_lock);
	/* Don't copy the trailing null byte, we don't want null bytes in a
	 * text file.
	 */
	kfifo_in(&debug_buffer, buf, len);
	raw_spin_unlock(&log_buffer_lock);

	local_irq_restore(flags);
	va_end(args);
}


/*
 * log_read - Read the trace buffer
 *
 * This function is called as a file operation from userspace.
 * Readers can sleep. Access is serialized through reader_mutex
 */
static ssize_t log_read(struct file *filp,
			char __user *to, size_t len,
			loff_t *f_pos)
{
	/* we ignore f_pos, this is strictly sequential */

	ssize_t error = -EINVAL;
	char* mem;

	if (mutex_lock_interruptible(&reader_mutex)) {
		error = -ERESTARTSYS;
		goto out;
	}

	if (len > MAX_READ_LEN)
		len = MAX_READ_LEN;

	mem = kmalloc(len, GFP_KERNEL);
	if (!mem) {
		error = -ENOMEM;
		goto out_unlock;
	}

	error = kfifo_out(&debug_buffer, mem, len);
	while (!error) {
		set_current_state(TASK_INTERRUPTIBLE);
		schedule_timeout(110);
		if (signal_pending(current))
			error = -ERESTARTSYS;
		else
			error = kfifo_out(&debug_buffer, mem, len);
	}

	if (error > 0 && copy_to_user(to, mem, error))
		error = -EFAULT;

	kfree(mem);
 out_unlock:
	mutex_unlock(&reader_mutex);
 out:
	return error;
}

/*
 * Enable redirection of printk() messages to the trace buffer.
 * Defined in kernel/printk.c
 */
extern int trace_override;
extern int trace_recurse;

/*
 * log_open - open the global log message ring buffer.
 */
static int log_open(struct inode *in, struct file *filp)
{
	int error = -EINVAL;

	if (mutex_lock_interruptible(&reader_mutex)) {
		error = -ERESTARTSYS;
		goto out;
	}

	atomic_inc(&reader_cnt);
	error = 0;

	printk(KERN_DEBUG
	       "sched_trace kfifo with buffer starting at: 0x%p\n",
	       debug_buffer.buf);

	/* override printk() */
	trace_override++;

	mutex_unlock(&reader_mutex);
 out:
	return error;
}

static int log_release(struct inode *in, struct file *filp)
{
	int error = -EINVAL;

	if (mutex_lock_interruptible(&reader_mutex)) {
		error = -ERESTARTSYS;
		goto out;
	}

	atomic_dec(&reader_cnt);

	/* release printk() overriding */
	trace_override--;

	printk(KERN_DEBUG "sched_trace kfifo released\n");

	mutex_unlock(&reader_mutex);
 out:
	return error;
}

/*
 * log_fops  - The file operations for accessing the global LITMUS log message
 *             buffer.
 *
 * Except for opening the device file it uses the same operations as trace_fops.
 */
static struct file_operations log_fops = {
	.owner   = THIS_MODULE,
	.open    = log_open,
	.release = log_release,
	.read    = log_read,
};

static struct miscdevice litmus_log_dev = {
	.name    = SCHED_TRACE_NAME,
	.minor   = MISC_DYNAMIC_MINOR,
	.fops    = &log_fops,
};

#ifdef CONFIG_MAGIC_SYSRQ
void dump_trace_buffer(int max)
{
	char line[80];
	int len;
	int count = 0;

	/* potential, but very unlikely, race... */
	trace_recurse = 1;
	while ((max == 0 || count++ < max) &&
	       (len = kfifo_out(&debug_buffer, line, sizeof(line - 1))) > 0) {
		line[len] = '\0';
		printk("%s", line);
	}
	trace_recurse = 0;
}

static void sysrq_dump_trace_buffer(int key)
{
	dump_trace_buffer(100);
}

static struct sysrq_key_op sysrq_dump_trace_buffer_op = {
	.handler	= sysrq_dump_trace_buffer,
	.help_msg	= "dump-trace-buffer(Y)",
	.action_msg	= "writing content of TRACE() buffer",
};
#endif

static int __init init_sched_trace(void)
{
	printk("Initializing TRACE() device\n");

#ifdef CONFIG_MAGIC_SYSRQ
	/* offer some debugging help */
	if (!register_sysrq_key('y', &sysrq_dump_trace_buffer_op))
		printk("Registered dump-trace-buffer(Y) magic sysrq.\n");
	else
		printk("Could not register dump-trace-buffer(Y) magic sysrq.\n");
#endif

	return misc_register(&litmus_log_dev);
}

static void __exit exit_sched_trace(void)
{
	misc_deregister(&litmus_log_dev);
}

module_init(init_sched_trace);
module_exit(exit_sched_trace);