Re: [PATCH 1/2] Add some basic resume trace facilities

[Nigel Cunningham <ncunningham@linuxmail.org>]

[-- Attachment #1.1: Type: text/plain, Size: 11611 bytes --]

Hi.

On Wednesday 14 June 2006 07:35, Linus Torvalds wrote:
> Considering that there isn't a lot of hw we can depend on during
> resume, this is about as good as it gets.
>
> Use "#include <linux/resume-trace.h>", and then sprinkle TRACE_RESUME(0)
> commands liberally over the driver that you're trying to figure out why
> and where it hangs. Expect to waste a _lot_ of time, but at least this
> gives you _some_ chance to actually debug it, instead of just staring at a
> dead machine.
>
> Signed-off-by: Linus Torvalds <torvalds@osdl.org>

s/On laptop per child/One bdi2000 per computer/? I'll give it a try.

Regards,

Nigel

> ---
>
> Not a lot of space in the RTC, but it's the only piece of hardware that is
> (a) reachable at all times, regardless of any other setup and (b) doesn't
> lose it state or have firmware reset the memory of at boot.
>
> Side note: you really don't want to do this unless you have an external
> time-source like NTP that resets the clock to the right value after the
> boot is done ;)
>
> diff --git a/arch/i386/kernel/vmlinux.lds.S
> b/arch/i386/kernel/vmlinux.lds.S index 8831303..509af98 100644
> --- a/arch/i386/kernel/vmlinux.lds.S
> +++ b/arch/i386/kernel/vmlinux.lds.S
> @@ -37,6 +37,13 @@ SECTIONS
>
>    RODATA
>
> +  . = ALIGN(4);
> +  __tracedata_start = .;
> +  .tracedata : AT(ADDR(.tracedata) - LOAD_OFFSET) {
> +	*(.tracedata)
> +  }
> +  __tracedata_end = .;
> +
>    /* writeable */
>    .data : AT(ADDR(.data) - LOAD_OFFSET) {	/* Data */
>  	*(.data)
> diff --git a/drivers/base/power/Makefile b/drivers/base/power/Makefile
> index c0219ad..adc4250 100644
> --- a/drivers/base/power/Makefile
> +++ b/drivers/base/power/Makefile
> @@ -1,5 +1,5 @@
>  obj-y			:= shutdown.o
> -obj-$(CONFIG_PM)	+= main.o suspend.o resume.o runtime.o sysfs.o
> +obj-$(CONFIG_PM)	+= main.o suspend.o resume.o runtime.o sysfs.o trace.o
>
>  ifeq ($(CONFIG_DEBUG_DRIVER),y)
>  EXTRA_CFLAGS += -DDEBUG
> diff --git a/drivers/base/power/trace.c b/drivers/base/power/trace.c
> new file mode 100644
> index 0000000..bcc5f12
> --- /dev/null
> +++ b/drivers/base/power/trace.c
> @@ -0,0 +1,228 @@
> +/*
> + * drivers/base/power/trace.c
> + *
> + * Copyright (C) 2006 Linus Torvalds
> + *
> + * Trace facility for suspend/resume problems, when none of the
> + * devices may be working.
> + */
> +
> +#include <linux/resume-trace.h>
> +#include <linux/rtc.h>
> +
> +#include <asm/rtc.h>
> +
> +#include "power.h"
> +
> +/*
> + * Horrid, horrid, horrid.
> + *
> + * It turns out that the _only_ piece of hardware that actually
> + * keeps its value across a hard boot (and, more importantly, the
> + * POST init sequence) is literally the realtime clock.
> + *
> + * Never mind that an RTC chip has 114 bytes (and often a whole
> + * other bank of an additional 128 bytes) of nice SRAM that is
> + * _designed_ to keep data - the POST will clear it. So we literally
> + * can just use the few bytes of actual time data, which means that
> + * we're really limited.
> + *
> + * It means, for example, that we can't use the seconds at all
> + * (since the time between the hang and the boot might be more
> + * than a minute), and we'd better not depend on the low bits of
> + * the minutes either.
> + *
> + * There are the wday fields etc, but I wouldn't guarantee those
> + * are dependable either. And if the date isn't valid, either the
> + * hw or POST will do strange things.
> + *
> + * So we're left with:
> + *  - year: 0-99
> + *  - month: 0-11
> + *  - day-of-month: 1-28
> + *  - hour: 0-23
> + *  - min: (0-30)*2
> + *
> + * Giving us a total range of 0-16128000 (0xf61800), ie less
> + * than 24 bits of actual data we can save across reboots.
> + *
> + * And if your box can't boot in less than three minutes,
> + * you're screwed.
> + *
> + * Now, almost 24 bits of data is pitifully small, so we need
> + * to be pretty dense if we want to use it for anything nice.
> + * What we do is that instead of saving off nice readable info,
> + * we save off _hashes_ of information that we can hopefully
> + * regenerate after the reboot.
> + *
> + * In particular, this means that we might be unlucky, and hit
> + * a case where we have a hash collision, and we end up not
> + * being able to tell for certain exactly which case happened.
> + * But that's hopefully unlikely.
> + *
> + * What we do is to take the bits we can fit, and split them
> + * into three parts (16*997*1009 = 16095568), and use the values
> + * for:
> + *  - 0-15: user-settable
> + *  - 0-996: file + line number
> + *  - 0-1008: device
> + */
> +#define USERHASH (16)
> +#define FILEHASH (997)
> +#define DEVHASH (1009)
> +
> +#define DEVSEED (7919)
> +
> +static unsigned int dev_hash_value;
> +
> +static int set_magic_time(unsigned int user, unsigned int file, unsigned
> int device) +{
> +	unsigned int n = user + USERHASH*(file + FILEHASH*device);
> +
> +	// June 7th, 2006
> +	static struct rtc_time time = {
> +		.tm_sec = 0,
> +		.tm_min = 0,
> +		.tm_hour = 0,
> +		.tm_mday = 7,
> +		.tm_mon = 5,	// June - counting from zero
> +		.tm_year = 106,
> +		.tm_wday = 3,
> +		.tm_yday = 160,
> +		.tm_isdst = 1
> +	};
> +
> +	time.tm_year = (n % 100);
> +	n /= 100;
> +	time.tm_mon = (n % 12);
> +	n /= 12;
> +	time.tm_mday = (n % 28) + 1;
> +	n /= 28;
> +	time.tm_hour = (n % 24);
> +	n /= 24;
> +	time.tm_min = (n % 20) * 3;
> +	n /= 20;
> +	set_rtc_time(&time);
> +	return n ? -1 : 0;
> +}
> +
> +static unsigned int read_magic_time(void)
> +{
> +	struct rtc_time time;
> +	unsigned int val;
> +
> +	get_rtc_time(&time);
> +	printk("Time: %2d:%02d:%02d  Date: %02d/%02d/%02d\n",
> +		time.tm_hour, time.tm_min, time.tm_sec,
> +		time.tm_mon, time.tm_mday, time.tm_year);
> +	val = time.tm_year;				/* 100 years */
> +	if (val > 100)
> +		val -= 100;
> +	val += time.tm_mon * 100;			/* 12 months */
> +	val += (time.tm_mday-1) * 100 * 12;		/* 28 month-days */
> +	val += time.tm_hour * 100 * 12 * 28;		/* 24 hours */
> +	val += (time.tm_min / 3) * 100 * 12 * 28 * 24;	/* 20 3-minute intervals
> */ +	return val;
> +}
> +
> +/*
> + * This is just the sdbm hash function with a user-supplied
> + * seed and final size parameter.
> + */
> +static unsigned int hash_string(unsigned int seed, const char *data,
> unsigned int mod) +{
> +	unsigned char c;
> +	while ((c = *data++) != 0) {
> +		seed = (seed << 16) + (seed << 6) - seed + c;
> +	}
> +	return seed % mod;
> +}
> +
> +void set_trace_device(struct device *dev)
> +{
> +	dev_hash_value = hash_string(DEVSEED, dev->bus_id, DEVHASH);
> +}
> +
> +/*
> + * We could just take the "tracedata" index into the .tracedata
> + * section instead. Generating a hash of the data gives us a
> + * chance to work across kernel versions, and perhaps more
> + * importantly it also gives us valid/invalid check (ie we will
> + * likely not give totally bogus reports - if the hash matches,
> + * it's not any guarantee, but it's a high _likelihood_ that
> + * the match is valid).
> + */
> +void generate_resume_trace(void *tracedata, unsigned int user)
> +{
> +	unsigned short lineno = *(unsigned short *)tracedata;
> +	const char *file = *(const char **)(tracedata + 2);
> +	unsigned int user_hash_value, file_hash_value;
> +
> +	user_hash_value = user % USERHASH;
> +	file_hash_value = hash_string(lineno, file, FILEHASH);
> +	set_magic_time(user_hash_value, file_hash_value, dev_hash_value);
> +}
> +
> +extern char __tracedata_start, __tracedata_end;
> +static int show_file_hash(unsigned int value)
> +{
> +	int match;
> +	char *tracedata;
> +
> +	match = 0;
> +	for (tracedata = &__tracedata_start ; tracedata < &__tracedata_end ;
> tracedata += 6) { +		unsigned short lineno = *(unsigned short *)tracedata;
> +		const char *file = *(const char **)(tracedata + 2);
> +		unsigned int hash = hash_string(lineno, file, FILEHASH);
> +		if (hash != value)
> +			continue;
> +		printk("  hash matches %s:%u\n", file, lineno);
> +		match++;
> +	}
> +	return match;
> +}
> +
> +static int show_dev_hash(unsigned int value)
> +{
> +	int match = 0;
> +	struct list_head * entry = dpm_active.prev;
> +
> +	while (entry != &dpm_active) {
> +		struct device * dev = to_device(entry);
> +		unsigned int hash = hash_string(DEVSEED, dev->bus_id, DEVHASH);
> +		if (hash == value) {
> +			printk("  hash matches device %s\n", dev->bus_id);
> +			match++;
> +		}
> +		entry = entry->prev;
> +	}
> +	return match;
> +}
> +
> +static unsigned int hash_value_early_read;
> +
> +static int early_resume_init(void)
> +{
> +	hash_value_early_read = read_magic_time();
> +	return 0;
> +}
> +
> +static int late_resume_init(void)
> +{
> +	unsigned int val = hash_value_early_read;
> +	unsigned int user, file, dev;
> +
> +	user = val % USERHASH;
> +	val = val / USERHASH;
> +	file = val % FILEHASH;
> +	val = val / FILEHASH;
> +	dev = val /* % DEVHASH */;
> +
> +	printk("  Magic number: %d:%d:%d\n", user, file, dev);
> +	show_file_hash(file);
> +	show_dev_hash(dev);
> +	return 0;
> +}
> +
> +core_initcall(early_resume_init);
> +late_initcall(late_resume_init);
> diff --git a/include/asm-generic/rtc.h b/include/asm-generic/rtc.h
> index cef08db..4087037 100644
> --- a/include/asm-generic/rtc.h
> +++ b/include/asm-generic/rtc.h
> @@ -114,6 +114,7 @@ #endif
>  /* Set the current date and time in the real time clock. */
>  static inline int set_rtc_time(struct rtc_time *time)
>  {
> +	unsigned long flags;
>  	unsigned char mon, day, hrs, min, sec;
>  	unsigned char save_control, save_freq_select;
>  	unsigned int yrs;
> @@ -131,7 +132,7 @@ #endif
>  	if (yrs > 255)	/* They are unsigned */
>  		return -EINVAL;
>
> -	spin_lock_irq(&rtc_lock);
> +	spin_lock_irqsave(&rtc_lock, flags);
>  #ifdef CONFIG_MACH_DECSTATION
>  	real_yrs = yrs;
>  	leap_yr = ((!((yrs + 1900) % 4) && ((yrs + 1900) % 100)) ||
> @@ -152,7 +153,7 @@ #endif
>  	 * whether the chip is in binary mode or not.
>  	 */
>  	if (yrs > 169) {
> -		spin_unlock_irq(&rtc_lock);
> +		spin_unlock_irqrestore(&rtc_lock, flags);
>  		return -EINVAL;
>  	}
>
> @@ -187,7 +188,7 @@ #endif
>  	CMOS_WRITE(save_control, RTC_CONTROL);
>  	CMOS_WRITE(save_freq_select, RTC_FREQ_SELECT);
>
> -	spin_unlock_irq(&rtc_lock);
> +	spin_unlock_irqrestore(&rtc_lock, flags);
>
>  	return 0;
>  }
> diff --git a/include/linux/resume-trace.h b/include/linux/resume-trace.h
> new file mode 100644
> index 0000000..e2e1e14
> --- /dev/null
> +++ b/include/linux/resume-trace.h
> @@ -0,0 +1,21 @@
> +#ifndef RESUME_TRACE_H
> +#define RESUME_TRACE_H
> +
> +struct device;
> +extern void set_trace_device(struct device *);
> +extern void generate_resume_trace(void *tracedata, unsigned int user);
> +
> +#define TRACE_DEVICE(dev) set_trace_device(dev)
> +#define TRACE_RESUME(user) do {				\
> +	void *tracedata;				\
> +	asm volatile("movl $1f,%0\n"			\
> +		".section .tracedata,\"a\"\n"		\
> +		"1:\t.word %c1\n"			\
> +		"\t.long %c2\n"				\
> +		".previous"				\
> +		:"=r" (tracedata)			\
> +		: "i" (__LINE__), "i" (__FILE__));	\
> +	generate_resume_trace(tracedata, user);		\
> +} while (0)
> +
> +#endif
> _______________________________________________
> linux-pm mailing list
> linux-pm@lists.osdl.org
> https://lists.osdl.org/mailman/listinfo/linux-pm

-- 
Nigel, Michelle and Alisdair Cunningham
5 Mitchell Street
Cobden 3266
Victoria, Australia

[-- Attachment #1.2: Type: application/pgp-signature, Size: 189 bytes --]

[-- Attachment #2: Type: text/plain, Size: 0 bytes --]