debug.c 16.9 KB
Newer Older
1
/*
2
3
4
5
6
7
8
9
10
11
12
13
14
15
16
17
 * Copyright (C) 2010 Philippe Gerum <rpm@xenomai.org>.
 *
 * Xenomai is free software; you can redistribute it and/or modify
 * it under the terms of the GNU General Public License as published
 * by the Free Software Foundation; either version 2 of the License,
 * or (at your option) any later version.
 *
 * Xenomai is distributed in the hope that it will be useful, but
 * WITHOUT ANY WARRANTY; without even the implied warranty of
 * MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the GNU
 * General Public License for more details.
 *
 * You should have received a copy of the GNU General Public License
 * along with Xenomai; if not, write to the Free Software
 * Foundation, Inc., 59 Temple Place - Suite 330, Boston, MA
 * 02111-1307, USA.
18
 */
19
20
21
22
23
#include <linux/types.h>
#include <linux/limits.h>
#include <linux/ctype.h>
#include <linux/jhash.h>
#include <linux/mm.h>
24
#include <linux/signal.h>
25
#include <linux/vmalloc.h>
26
#include <cobalt/kernel/sched.h>
27
28
29
#include <cobalt/kernel/heap.h>
#include <cobalt/kernel/clock.h>
#include <cobalt/kernel/ppd.h>
30
31
32
#include <cobalt/uapi/signal.h>
#include <asm/xenomai/syscall.h>
#include "posix/process.h"
33
#include "debug.h"
34

35
/**
36
37
 * @ingroup cobalt_core
 * @defgroup cobalt_core_debug Debugging services
38
39
 * @{
 */
40
41
struct xnvfile_directory cobalt_debug_vfroot;
EXPORT_SYMBOL_GPL(cobalt_debug_vfroot);
42

43
44
#ifdef CONFIG_XENO_OPT_DEBUG_TRACE_RELAX

45
46
47
48
49
50
51
52
53
#define SYMBOL_HSLOTS	(1 << 8)

struct hashed_symbol {
	struct hashed_symbol *next;
	char symbol[0];
};

static struct hashed_symbol *symbol_jhash[SYMBOL_HSLOTS];

54
55
static struct xnheap memory_pool;

56
57
58
59
60
61
62
63
64
65
66
/*
 * This is a permanent storage for ASCII strings which comes handy to
 * get a unique and constant reference to a symbol while preserving
 * storage space. Hashed symbols have infinite lifetime and are never
 * flushed.
 */
DEFINE_PRIVATE_XNLOCK(symbol_lock);

static const char *hash_symbol(const char *symbol)
{
	struct hashed_symbol *p, **h;
Jan Kiszka's avatar
Jan Kiszka committed
67
	const char *str;
68
69
	size_t len;
	u32 hash;
Jan Kiszka's avatar
Jan Kiszka committed
70
	spl_t s;
71
72
73
74

	len = strlen(symbol);
	hash = jhash(symbol, len, 0);

Jan Kiszka's avatar
Jan Kiszka committed
75
	xnlock_get_irqsave(&symbol_lock, s);
76
77
78
79
80
81
82
83
84
85
86

	h = &symbol_jhash[hash & (SYMBOL_HSLOTS - 1)];
	p = *h;
	while (p &&
	       (*p->symbol != *symbol ||
		strcmp(p->symbol + 1, symbol + 1)))
	       p = p->next;

	if (p)
		goto done;

87
	p = xnheap_alloc(&memory_pool, sizeof(*p) + len + 1);
88
	if (p == NULL) {
Jan Kiszka's avatar
Jan Kiszka committed
89
		str = NULL;
90
91
92
93
94
95
96
		goto out;
	}

	strcpy(p->symbol, symbol);
	p->next = *h;
	*h = p;
done:
Jan Kiszka's avatar
Jan Kiszka committed
97
	str = p->symbol;
98
out:
Jan Kiszka's avatar
Jan Kiszka committed
99
	xnlock_put_irqrestore(&symbol_lock, s);
100

Jan Kiszka's avatar
Jan Kiszka committed
101
	return str;
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
}

/*
 * We define a static limit (RELAX_SPOTNR) for spot records to limit
 * the memory consumption (we pull record memory from the system
 * heap). The current value should be reasonable enough unless the
 * application is extremely unsane, given that we only keep unique
 * spots. Said differently, if the application has more than
 * RELAX_SPOTNR distinct code locations doing spurious relaxes, then
 * the first issue to address is likely PEBKAC.
 */
#define RELAX_SPOTNR	128
#define RELAX_HSLOTS	(1 << 8)

struct relax_record {
	/* Number of hits for this location */
	u32 hits;
	struct relax_spot {
		/* Faulty thread name. */
		char thread[XNOBJECT_NAME_LEN];
		/* call stack the relax originates from. */
		int depth;
		struct backtrace {
			unsigned long pc;
			const char *mapname;
127
		} backtrace[SIGSHADOW_BACKTRACE_DEPTH];
128
129
130
131
		/* Program hash value of the caller. */
		u32 proghash;
		/* Pid of the caller. */
		pid_t pid;
132
133
		/* Reason for relaxing. */
		int reason;
134
135
136
137
138
139
140
141
142
143
144
145
146
147
148
149
150
151
	} spot;
	struct relax_record *r_next;
	struct relax_record *h_next;
	const char *exe_path;
};

static struct relax_record *relax_jhash[RELAX_HSLOTS];

static struct relax_record *relax_record_list;

static int relax_overall, relax_queued;

DEFINE_PRIVATE_XNLOCK(relax_lock);

/*
 * The motivation to centralize tracing information about relaxes
 * directly into kernel space is fourfold:
 *
152
153
 * - this allows to gather all the trace data into a single location
 * and keep it safe there, with no external log file involved.
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
 *
 * - enabling the tracing does not impose any requirement on the
 * application (aside of being compiled with debug symbols for best
 * interpreting that information). We only need a kernel config switch
 * for this (i.e. CONFIG_XENO_OPT_DEBUG_TRACE_RELAX).
 *
 * - the data is collected and can be made available exactly the same
 * way regardless of the application emitting the relax requests, or
 * whether it is still alive when the trace data are displayed.
 *
 * - the kernel is able to provide accurate and detailed trace
 * information, such as the relative offset of instructions causing
 * relax requests within dynamic shared objects, without having to
 * guess it roughly from /proc/pid/maps, or relying on ldd's
 * --function-relocs feature, which both require to run on the target
 * system to get the needed information. Instead, we allow a build
 * host to use a cross-compilation toolchain later to extract the
 * source location, from the raw data the kernel has provided on the
 * target system.
 *
 * However, collecting the call frames within the application to
 * determine the full context of a relax spot is not something we can
 * do purely from kernel space, notably because it depends on build
 * options we just don't know about (e.g. frame pointers availability
 * for the app, or other nitty-gritty details depending on the
 * toolchain). To solve this, we ask the application to send us a
 * complete backtrace taken from the context of a specific signal
 * handler, which we know is stacked over the relax spot. That
 * information is then stored by the kernel after some
 * post-processing, along with other data identifying the caller, and
 * made available through the /proc/xenomai/debug/relax vfile.
 *
 * Implementation-wise, xndebug_notify_relax and xndebug_trace_relax
 * routines are paired: first, xndebug_notify_relax sends a SIGSHADOW
 * request to userland when a relax spot is detected from
189
 * xnthread_relax, which should then trigger a call back to
190
 * xndebug_trace_relax with the complete backtrace information, as
191
 * seen from userland (via the internal sc_cobalt_backtrace
192
193
194
 * syscall). All this runs on behalf of the relaxing thread, so we can
 * make a number of convenient assumptions (such as being able to scan
 * the current vma list to get detailed information about the
195
196
197
 * executable mappings that could be involved).
 */

198
void xndebug_notify_relax(struct xnthread *thread, int reason)
199
{
200
	xnthread_signal(thread, SIGSHADOW,
201
			  sigshadow_int(SIGSHADOW_ACTION_BACKTRACE, reason));
202
203
}

204
void xndebug_trace_relax(int nr, unsigned long *backtrace,
205
			 int reason)
206
207
208
209
210
211
212
213
214
215
216
217
{
	struct relax_record *p, **h;
	struct vm_area_struct *vma;
	struct xnthread *thread;
	struct relax_spot spot;
	struct mm_struct *mm;
	struct file *file;
	unsigned long pc;
	char *mapname;
	int n, depth;
	char *tmp;
	u32 hash;
Jan Kiszka's avatar
Jan Kiszka committed
218
	spl_t s;
219

220
	thread = xnthread_current();
221
222
	if (thread == NULL)
		return;		/* Can't be, right? What a mess. */
223

224
225
226
227
228
	/*
	 * We compute PC values relative to the base of the shared
	 * executable mappings we find in the backtrace, which makes
	 * it possible for the slackspot utility to match the
	 * corresponding source code locations from unrelocated file
Philippe Gerum's avatar
Philippe Gerum committed
229
	 * offsets.
230
231
	 */

232
	tmp = (char *)__get_free_page(GFP_KERNEL);
233
234
235
236
237
238
239
240
241
	if (tmp == NULL)
		/*
		 * The situation looks really bad, but we can't do
		 * anything about it. Just bail out.
		 */
		return;

	memset(&spot, 0, sizeof(spot));
	mm = get_task_mm(current);
242
	mmap_read_lock(mm);
243
244
245
246
247
248
249
250

	for (n = 0, depth = 0; n < nr; n++) {
		pc = backtrace[n];

		vma = find_vma(mm, pc);
		if (vma == NULL)
			continue;

251
252
253
254
255
256
257
258
259
260
261
		/*
		 * Hack. Unlike DSOs, executables and interpreters
		 * (e.g. dynamic linkers) are protected against write
		 * attempts. Use this to determine when $pc should be
		 * fixed up by subtracting the mapping base address in
		 * the DSO case.
		 */
		if (!(vma->vm_flags & VM_DENYWRITE))
			pc -= vma->vm_start;

		spot.backtrace[depth].pc = pc;
262
263
264
265
266
267
268
269
270
271
272
273
274
275
276
277
278
279
280

		/*
		 * Even in case we can't fetch the map name, we still
		 * record the PC value, which may still give some hint
		 * downstream.
		 */
		file = vma->vm_file;
		if (file == NULL)
			goto next_frame;

		mapname = d_path(&file->f_path, tmp, PAGE_SIZE);
		if (IS_ERR(mapname))
			goto next_frame;

		spot.backtrace[depth].mapname = hash_symbol(mapname);
	next_frame:
		depth++;
	}

281
	mmap_read_unlock(mm);
282
283
284
285
286
287
288
289
290
291
292
293
294
	mmput(mm);
	free_page((unsigned long)tmp);

	/*
	 * Most of the time we will be sent duplicates, since the odds
	 * of seeing the same thread running the same code doing the
	 * same mistake all over again are high. So we probe the hash
	 * table for an identical spot first, before going for a
	 * complete record allocation from the system heap if no match
	 * was found. Otherwise, we just take the fast exit path.
	 */
	spot.depth = depth;
	spot.proghash = thread->proghash;
295
	spot.pid = xnthread_host_pid(thread);
296
	spot.reason = reason;
297
298
299
	strcpy(spot.thread, thread->name);
	hash = jhash2((u32 *)&spot, sizeof(spot) / sizeof(u32), 0);

Jan Kiszka's avatar
Jan Kiszka committed
300
	xnlock_get_irqsave(&relax_lock, s);
301
302
303
304
305
306
307
308
309
310
311
312
313
314
315
316
317
318
319
320
321
322
323
324
325

	h = &relax_jhash[hash & (RELAX_HSLOTS - 1)];
	p = *h;
	while (p &&
	       /* Try quick guesses first, then memcmp */
	       (p->spot.depth != spot.depth ||
		p->spot.pid != spot.pid ||
		memcmp(&p->spot, &spot, sizeof(spot))))
	       p = p->h_next;

	if (p) {
		p->hits++;
		goto out;	/* Spot already recorded. */
	}

	if (relax_queued >= RELAX_SPOTNR)
		goto out;	/* No more space -- ignore. */
	/*
	 * We can only compete with other shadows which have just
	 * switched to secondary mode like us. So holding the
	 * relax_lock a bit more without disabling interrupts is not
	 * an issue. This allows us to postpone the record memory
	 * allocation while probing and updating the hash table in a
	 * single move.
	 */
326
	p = xnheap_alloc(&memory_pool, sizeof(*p));
327
328
329
330
331
332
333
334
335
336
337
338
339
340
	if (p == NULL)
		goto out;      /* Something is about to go wrong... */

	memcpy(&p->spot, &spot, sizeof(p->spot));
	p->exe_path = hash_symbol(thread->exe_path);
	p->hits = 1;
	p->h_next = *h;
	*h = p;
	p->r_next = relax_record_list;
	relax_record_list = p;
	relax_queued++;
out:
	relax_overall++;

Jan Kiszka's avatar
Jan Kiszka committed
341
	xnlock_put_irqrestore(&relax_lock, s);
342
343
344
345
346
347
348
349
350
351
352
353
354
355
356
357
}

static DEFINE_VFILE_HOSTLOCK(relax_mutex);

struct relax_vfile_priv {
	int queued;
	int overall;
	int ncurr;
	struct relax_record *head;
	struct relax_record *curr;
};

static void *relax_vfile_begin(struct xnvfile_regular_iterator *it)
{
	struct relax_vfile_priv *priv = xnvfile_iterator_priv(it);
	struct relax_record *p;
Jan Kiszka's avatar
Jan Kiszka committed
358
	spl_t s;
359
360
361
362
363
364
365
366
367
	int n;

	/*
	 * Snapshot the counters under lock, to make sure they remain
	 * mutually consistent despite we dump the record list in a
	 * lock-less manner. Additionally, the vfile layer already
	 * holds the relax_mutex lock for us, so that we can't race
	 * with ->store().
	 */
Jan Kiszka's avatar
Jan Kiszka committed
368
	xnlock_get_irqsave(&relax_lock, s);
369

370
	if (relax_queued == 0 || it->pos > relax_queued) {
371
		xnlock_put_irqrestore(&relax_lock, s);
372
373
374
375
376
377
		return NULL;
	}
	priv->overall = relax_overall;
	priv->queued = relax_queued;
	priv->head = relax_record_list;

Jan Kiszka's avatar
Jan Kiszka committed
378
	xnlock_put_irqrestore(&relax_lock, s);
379
380
381
382
383
384
385
386
387
388
389
390
391
392
393
394
395
396
397
398
399
400
401
402
403
404
405
406
407
408
409
410
411
412
413
414
415
416

	if (it->pos == 0) {
		priv->curr = NULL;
		priv->ncurr = -1;
		return VFILE_SEQ_START;
	}

	for (n = 1, p = priv->head; n < it->pos; n++)
		p = p->r_next;

	priv->curr = p;
	priv->ncurr = n;

	return p;
}

static void *relax_vfile_next(struct xnvfile_regular_iterator *it)
{
	struct relax_vfile_priv *priv = xnvfile_iterator_priv(it);
	struct relax_record *p;
	int n;

	if (it->pos > priv->queued)
		return NULL;

	if (it->pos == priv->ncurr + 1)
		p = priv->curr->r_next;
	else {
		for (n = 1, p = priv->head; n < it->pos; n++)
			p = p->r_next;
	}

	priv->curr = p;
	priv->ncurr = it->pos;

	return p;
}

417
418
419
420
421
422
423
424
static const char *reason_str[] = {
    [SIGDEBUG_UNDEFINED] = "undefined",
    [SIGDEBUG_MIGRATE_SIGNAL] = "signal",
    [SIGDEBUG_MIGRATE_SYSCALL] = "syscall",
    [SIGDEBUG_MIGRATE_FAULT] = "fault",
    [SIGDEBUG_MIGRATE_PRIOINV] = "pi-error",
    [SIGDEBUG_NOMLOCK] = "mlock-check",
    [SIGDEBUG_WATCHDOG] = "runaway-break",
425
    [SIGDEBUG_RESCNT_IMBALANCE] = "resource-count-imbalance",
426
    [SIGDEBUG_MUTEX_SLEEP] = "sleep-holding-mutex",
427
    [SIGDEBUG_LOCK_BREAK] = "scheduler-lock-break",
428
429
};

430
431
432
433
434
435
436
437
438
439
440
441
442
443
444
445
446
static int relax_vfile_show(struct xnvfile_regular_iterator *it, void *data)
{
	struct relax_vfile_priv *priv = xnvfile_iterator_priv(it);
	struct relax_record *p = data;
	int n;

	/*
	 * No need to grab any lock to read a record from a previously
	 * validated index: the data must be there and won't be
	 * touched anymore.
	 */
	if (p == NULL) {
		xnvfile_printf(it, "%d\n", priv->overall);
		return 0;
	}

	xnvfile_printf(it, "%s\n", p->exe_path ?: "?");
447
448
	xnvfile_printf(it, "%d %d %s %s\n", p->spot.pid, p->hits,
		       reason_str[p->spot.reason], p->spot.thread);
449
450
451
452
453
454
455

	for (n = 0; n < p->spot.depth; n++)
		xnvfile_printf(it, "0x%lx %s\n",
			       p->spot.backtrace[n].pc,
			       p->spot.backtrace[n].mapname ?: "?");

	xnvfile_printf(it, ".\n");
Gilles Chanteperdrix's avatar
Gilles Chanteperdrix committed
456

457
458
459
460
461
462
	return 0;
}

static ssize_t relax_vfile_store(struct xnvfile_input *input)
{
	struct relax_record *p, *np;
Jan Kiszka's avatar
Jan Kiszka committed
463
	spl_t s;
464
465
466
467
468
469

	/*
	 * Flush out all records. Races with ->show() are prevented
	 * using the relax_mutex lock. The vfile layer takes care of
	 * this internally.
	 */
Jan Kiszka's avatar
Jan Kiszka committed
470
	xnlock_get_irqsave(&relax_lock, s);
471
472
473
474
	p = relax_record_list;
	relax_record_list = NULL;
	relax_overall = 0;
	relax_queued = 0;
475
	memset(relax_jhash, 0, sizeof(relax_jhash));
Jan Kiszka's avatar
Jan Kiszka committed
476
	xnlock_put_irqrestore(&relax_lock, s);
477
478
479

	while (p) {
		np = p->r_next;
480
		xnheap_free(&memory_pool, p);
481
482
483
484
485
486
487
488
489
490
491
492
493
494
495
496
497
498
499
500
501
		p = np;
	}

	return input->size;
}

static struct xnvfile_regular_ops relax_vfile_ops = {
	.begin = relax_vfile_begin,
	.next = relax_vfile_next,
	.show = relax_vfile_show,
	.store = relax_vfile_store,
};

static struct xnvfile_regular relax_vfile = {
	.privsz = sizeof(struct relax_vfile_priv),
	.ops = &relax_vfile_ops,
	.entry = { .lockops = &relax_mutex.ops },
};

static inline int init_trace_relax(void)
{
502
503
504
505
506
507
508
509
510
511
512
513
514
515
	u32 size = CONFIG_XENO_OPT_DEBUG_TRACE_LOGSZ * 1024;
	void *p;
	int ret;

	p = vmalloc(size);
	if (p == NULL)
		return -ENOMEM;

	ret = xnheap_init(&memory_pool, p, size);
	if (ret)
		return ret;

	xnheap_set_name(&memory_pool, "debug log");

516
	ret = xnvfile_init_regular("relax", &relax_vfile, &cobalt_debug_vfroot);
517
518
519
520
521
522
	if (ret) {
		xnheap_destroy(&memory_pool);
		vfree(p);
	}

	return ret;
523
524
525
526
}

static inline void cleanup_trace_relax(void)
{
527
528
	void *p;

529
	xnvfile_destroy_regular(&relax_vfile);
530
531
532
	p = xnheap_get_membase(&memory_pool);
	xnheap_destroy(&memory_pool);
	vfree(p);
533
534
535
536
537
538
539
540
541
542
543
544
545
546
547
548
549
550
551
}

#else /* !CONFIG_XENO_OPT_DEBUG_TRACE_RELAX */

static inline int init_trace_relax(void)
{
	return 0;
}

static inline void cleanup_trace_relax(void)
{
}

static inline void init_thread_relax_trace(struct xnthread *thread)
{
}

#endif /* !XENO_OPT_DEBUG_TRACE_RELAX */

552
#ifdef CONFIG_XENO_OPT_DEBUG_LOCKING
553
554
555

void xnlock_dbg_prepare_acquire(unsigned long long *start)
{
556
	*start = xnclock_read_raw(&nkclock);
557
}
Philippe Gerum's avatar
Philippe Gerum committed
558
EXPORT_SYMBOL_GPL(xnlock_dbg_prepare_acquire);
559
560
561
562
563

void xnlock_dbg_acquired(struct xnlock *lock, int cpu, unsigned long long *start,
			 const char *file, int line, const char *function)
{
	lock->lock_date = *start;
564
	lock->spin_time = xnclock_read_raw(&nkclock) - *start;
565
566
567
568
569
570
571
	lock->file = file;
	lock->function = function;
	lock->line = line;
	lock->cpu = cpu;
}
EXPORT_SYMBOL_GPL(xnlock_dbg_acquired);

572
573
int xnlock_dbg_release(struct xnlock *lock,
		       const char *file, int line, const char *function)
574
575
576
577
578
{
	unsigned long long lock_time;
	struct xnlockinfo *stats;
	int cpu;

579
	lock_time = xnclock_read_raw(&nkclock) - lock->lock_date;
580
	cpu = raw_smp_processor_id();
581
	stats = &per_cpu(xnlock_stats, cpu);
582

583
584
585
586
587
588
	if (lock->file == NULL) {
		lock->file = "??";
		lock->line = 0;
		lock->function = "invalid";
	}

589
	if (unlikely(lock->owner != cpu)) {
590
		pipeline_prepare_panic();
591
592
		printk(XENO_ERR "lock %p already unlocked on CPU #%d\n"
				"          last owner = %s:%u (%s(), CPU #%d)\n",
593
594
		       lock, cpu, lock->file, lock->line, lock->function,
		       lock->cpu);
595
		dump_stack();
596
597
598
		return 1;
	}

599
600
601
602
603
	/* File that we released it. */
	lock->cpu = -lock->cpu;
	lock->file = file;
	lock->line = line;
	lock->function = function;
604
605
606
607
608
609
610
611
612
613
614
615
616

	if (lock_time > stats->lock_time) {
		stats->lock_time = lock_time;
		stats->spin_time = lock->spin_time;
		stats->file = lock->file;
		stats->function = lock->function;
		stats->line = lock->line;
	}

	return 0;
}
EXPORT_SYMBOL_GPL(xnlock_dbg_release);

617
#endif /* CONFIG_XENO_OPT_DEBUG_LOCKING */
618

619
620
void xndebug_shadow_init(struct xnthread *thread)
{
621
	struct cobalt_ppd *sys_ppd;
622
623
	size_t len;

624
	sys_ppd = cobalt_ppd_get(0);
625
626
627
	/*
	 * The caller is current, so we know for sure that sys_ppd
	 * will still be valid after we dropped the lock.
628
629
630
	 *
	 * NOTE: Kernel shadows all share the system global ppd
	 * descriptor with no refcounting.
631
632
633
634
635
636
637
638
639
640
641
642
643
644
645
646
647
648
649
650
651
652
653
654
655
656
657
658
	 */
	thread->exe_path = sys_ppd->exe_path ?: "(unknown)";
	/*
	 * The program hash value is a unique token debug features may
	 * use to identify all threads which belong to a given
	 * executable file. Using this value for quick probes is often
	 * handier and more efficient than testing the whole exe_path.
	 */
	len = strlen(thread->exe_path);
	thread->proghash = jhash(thread->exe_path, len, 0);
}

int xndebug_init(void)
{
	int ret;

	ret = init_trace_relax();
	if (ret)
		return ret;

	return 0;
}

void xndebug_cleanup(void)
{
	cleanup_trace_relax();
}

659
/** @} */