Latency Tracer, voluntary-preempt-2.6.8-rc4-O6

Or just stick some cond_sched()s in there. It was designed to be slow, but there are no locking issues.

-Andi

the speedup would be important: even on a 2GHz box reading 10,000 trace entries takes a couple of seconds.

[ the /proc/latency_trace read()ing itself is fully preemptible, i'd be
ashamed if it werent ;) ]

Ingo

That's because you're abusing it - it was never designed to process that much data.

With binary search you would need to backward search to find the stem for the stem compression. It's probably doable, but would be a bit ugly I guess.

-Andi

i'm not abusing it. Linear searching of 20 thousand symbols is a gross first-approximation algorithm no matter what. Yes, most users of the symbols dont care about performance. And i'm not complaining at all, i'm just pointing out the reason why e.g. printing a simple stack backtrace can take milliseconds.

yeah. Maybe someone will find the time to improve the algorithm. But it's not a highprio thing.

Ingo

Well, I found some time and decided to give it a go :)

I first built a small test program that could provide the same symbol data to the lookup function, so that I could test using a user space app.

This way I could benchmark both the original algorithm and any improvement I could make, and do it confortably from user space.

The original algorithm took, on average, 1340us per lookup on my P4 2.8GHz. The compile settings for the test are not the same on the kernel, so this can be only compared against other results from the same setup.

With the attached patch it takes 14us per lookup. This is almost a 100x improvement.

The largest portion of the time it took to do a lookup, was the decompression of the symbol names. It seemed a waste of time to keep strcpy'ing over the result lots of names that would probably not contribute to the final name.

With the strcpy's out, the speed-up was around 5x, but even then, looking sequentially for the symbol name was still slow.

The final algorithm pre-calculates markers on the compressed symbols so that the search time is almost divided by the number of markers.

There are still a few issues with this approach. The biggest issue is that this is clearly a speed/space trade-off, and maybe we don't want to waste the space on a code path that is not supposed to be "hot". If this is the case, I can make a smaller patch, that fixes just the name "decompression" strcpy's.

As always, any comments will be greatly appreciated.

Just one side note: gcc gives a warning about 2 variables that might be used before initialization. I know they are not, and it didn't seem a good idea to put extra code just to shut up gcc. What is the standard way to convince gcc that those vars are ok?

Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

@@ -22,6 +22,13 @@ extern char kallsyms_names[] __attribute
 /* Defined by the linker script. */
 extern char _stext[], _etext[], _sinittext[], _einittext[];
 
+/* auxiliary markers to speed up symbol lookup */
+#define KALLSYMS_STEM_MARKS	8
+
+static int kallsyms_stem_mark_idx[KALLSYMS_STEM_MARKS];
+static char *kallsyms_stem_mark[KALLSYMS_STEM_MARKS];
+
+
 static inline int is_kernel_inittext(unsigned long addr)
 {
 	if (addr >= (unsigned long)_sinittext

@@ -56,13 +63,42 @@ unsigned long kallsyms_lookup_name(const
 	return module_kallsyms_lookup_name(name);
 }
 
+/* build markers into the compressed symbol table, so that lookups can be faster */
+static void build_stem_marks(void)
+{
+	char *name = kallsyms_names;
+	int i, mark_cnt;
+
+	unsigned prefix;
+
+	mark_cnt = 0;
+	for (i = 0 ; i < kallsyms_num_syms; i++) { 
+		prefix=*name;
+		if (prefix == 0) {
+			/* if this is the first 0-prefix stem in the desired interval */
+			if(i > (mark_cnt + 1) * (kallsyms_num_syms / (KALLSYMS_STEM_MARKS + 1)) && 
+			   kallsyms_stem_mark_idx[mark_cnt]==0) {
+				kallsyms_stem_mark[mark_cnt] = name;
+				kallsyms_stem_mark_idx[mark_cnt] = i;
+				mark_cnt++;
+				if(mark_cnt >= KALLSYMS_STEM_MARKS) break;
+			}
+		}
+		do {
+			name++;
+		} while(*name);
+		name ++;
+	}
+}
 /* Lookup an address.  modname is set to NULL if it's in the kernel. */
 const char *kallsyms_lookup(unsigned long addr,
 			    unsigned long *symbolsize,
 			    unsigned long *offset,
 			    char **modname, char *namebuf)
 {
-	unsigned long i, best = 0;
+	unsigned long i, last_0idx;
+	unsigned long mark, low, high, mid;
+	char *last_0prefix;
 
 	/* This kernel should never had been booted. */
 	BUG_ON(!kallsyms_addresses);

@@ -72,39 +108,67 @@ const char *kallsyms_lookup(unsigned lon
 
 	if (is_kernel_text(addr) || is_kernel_inittext(addr)) {
 		unsigned long symbol_end;
-		char *name = kallsyms_names;
+		char *name;
 
-		/* They're sorted, we could be clever here, but who cares? */
-		for (i = 0; i < kallsyms_num_syms; i++) {
-			if (kallsyms_addresses[i] > kallsyms_addresses[best] &&
-			    kallsyms_addresses[i] <= addr)
-				best = i;
+		/* do a binary search on the sorted kallsyms_addresses array */
+		low = 0;
+		high = kallsyms_num_syms;
+		while( high-low > 1 ) { 
+			mid = (low + high) / 2;
+			if( kallsyms_addresses[mid] <= addr ) low = mid;
+			else high = mid;
 		}
 
 		/* Grab name */
-		for (i = 0; i <= best; i++) { 
-			unsigned prefix = *name++;
-			strncpy(namebuf + prefix, name, KSYM_NAME_LEN - prefix);
-			name += strlen(name) + 1;
-		}
+		i = 0;
+		name = kallsyms_names;
 
-		/* At worst, symbol ends at end of section. */
-		if (is_kernel_inittext(addr))
-			symbol_end = (unsigned long)_einittext;
-		else
-			symbol_end = (unsigned long)_etext;
+		if(kallsyms_stem_mark_idx[0]==0)
+			build_stem_marks();
+
+		for(mark = 0; mark < KALLSYMS_STEM_MARKS; mark++) {
+			if( low >= kallsyms_stem_mark_idx[mark] ) {
+				i = kallsyms_stem_mark_idx[mark];
+				name = kallsyms_stem_mark[mark];
+			}
+			else break;
+		}
 
-		/* Search for next non-aliased symbol */
-		for (i = best+1; i < kallsyms_num_syms; i++) {
-			if (kallsyms_addresses[i] > kallsyms_addresses[best]) {
-				symbol_end = kallsyms_addresses[i];
-				break;
+		/* find the last stem before the actual symbol that as 0 prefix */
+		unsigned prefix;
+		for (; i <= low; i++) { 
+			prefix=*name;
+			if (prefix == 0) {
+				last_0prefix = name;
+				last_0idx = i;
 			}
+			do {
+				name++;
+			} while(*name);
+			name ++;
 		}
 
-		*symbolsize = symbol_end - kallsyms_addresses[best];
+		/* build the name from there */
+		name = last_0prefix;
+		for (i = last_0idx; i <= low; i++) { 
+			prefix = *name++;
+			strncpy(namebuf + prefix, name, KSYM_NAME_LEN - prefix);
+			name += strlen(name) + 1;
+		}
+
+		if(low == kallsyms_num_syms - 1) {
+			/* At worst, symbol ends at end of section. */
+			if (is_kernel_inittext(addr))
+				symbol_end = (unsigned long)_einittext;
+			else
+				symbol_end = (unsigned long)_etext;
+		}
+		else
+			symbol_end = kallsyms_addresses[low + 1];
+		
+		*symbolsize = symbol_end - kallsyms_addresses[low];
 		*modname = NULL;
-		*offset = addr - kallsyms_addresses[best];
+		*offset = addr - kallsyms_addresses[low];
 		return namebuf;
 	}
 

I get a few warnings:

CC kernel/kallsyms.o
kernel/kallsyms.c: In function `kallsyms_lookup':
kernel/kallsyms.c:99: warning: last_0idx' might be used uninitialized in this function kernel/kallsyms.c:101: warning: last_0prefix' might be used uninitialized in this function

rlrevell@mindpipe:~/cvs/alsa/alsa-driver$ gcc --version
gcc (GCC) 3.3.4 (Debian 1:3.3.4-7)
Copyright (C) 2003 Free Software Foundation, Inc.
This is free software; see the source for copying conditions.  There is NO
warranty; not even for MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.

Lee

My original email explained this problem. These warning are harmless (although not pretty, for sure), and Ingo corrected them for the O8 patch (this was only 2 hours after your email :)

Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

Oops, should have read the whole thing...

Lee

great, your patch is looking really good!

ouch. I consider fixing this a quality of implementation issue.

wow! I have tried your patch and /proc/latency_trace now produces instantaneous output.

your patch doesnt add all that much of code. It adds 288 bytes to .text and 64 bytes to .data. A typical .config generates 180K of compressed kallsyms data (with !KALLSYMS_ALL), so your patch increases the kallsyms overhead by a mere 0.2%. So it's really not an issue - especially since kallsyms can be disabled in .config.

i've put your patch into the -O8 patch:

http://redhat.com/~mingo/voluntary-preempt/voluntary-preempt-2.6.8-rc4-O8

i'd strongly recommend merging this patch upstream as well.

the standard way is to add the extra initializers. The gcc folks feel that those rare cases where gcc gets it wrong justify the benefit of catching lots of real bugs. I've added the extra initialization to -O8.

Ingo

Thanks :)

Good to ear

The 64 bytes of data can be further tuned using the KALLSYMS_STEM_MARKS define.

Setting it to 16 instead of 8 will speed up the algorithm by _almost_ twice the speed. As the number grows higher, the speed up is less noticeable.

Ok, now that I know how it should be done, next time I'll add them myself :)

Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

This patch regresses some recent changes to kallsyms which handle aliased symbols, IOW symbols with the same address. The speed up is very good, but it has two problems with repeated addresses.

The binary chop will give different results on different configs. Depending on the chop, it will pick any one of the aliased symbols, the previous kallsyms would always pick the first name. For consistent bug reports, always report the first symbol from an aliased set.

When calculating the size of a symbol, you must skip the aliased entries.

Patch over kallsyms-speedup, to handle aliased symbols again. Also removes a warning about mixing code and declarations.

Index: linux/kernel/kallsyms.c
===================================================================
@@ -107,7 +107,8 @@ const char *kallsyms_lookup(unsigned lon
 	namebuf[0] = 0;
 
 	if (is_kernel_text(addr) || is_kernel_inittext(addr)) {
-		unsigned long symbol_end;
+		unsigned long symbol_end = 0;
+		unsigned prefix;
 		char *name;
 
 		/* do a binary search on the sorted kallsyms_addresses array */

@@ -118,6 +119,7 @@ const char *kallsyms_lookup(unsigned lon
 			if( kallsyms_addresses[mid] <= addr ) low = mid;
 			else high = mid;
 		}
+		while (low && kallsyms_addresses[low-1] == kallsyms_addresses[low]) --low;
 
 		/* Grab name */
 		i = 0;

@@ -135,7 +137,6 @@ const char *kallsyms_lookup(unsigned lon
 		}
 
 		/* find the last stem before the actual symbol that as 0 prefix */
-		unsigned prefix;
 		for (; i <= low; i++) { 
 			prefix=*name;
 			if (prefix == 0) {

@@ -156,15 +157,20 @@ const char *kallsyms_lookup(unsigned lon
 			name += strlen(name) + 1;
 		}
 
-		if(low == kallsyms_num_syms - 1) {
+		/* Search for next non-aliased symbol */
+		for (i = low + 1; i < kallsyms_num_syms; i++) {
+			if (kallsyms_addresses[i] > kallsyms_addresses[low]) {
+				symbol_end = kallsyms_addresses[i];
+				break;
+			}
+		}
+		if (!symbol_end) {
 			/* At worst, symbol ends at end of section. */
 			if (is_kernel_inittext(addr))
 				symbol_end = (unsigned long)_einittext;
 			else
 				symbol_end = (unsigned long)_etext;
 		}
-		else
-			symbol_end = kallsyms_addresses[low + 1];
 		
 		*symbolsize = symbol_end - kallsyms_addresses[low];
 		*modname = NULL;

Oops, I didn't realize that there could be repeated addresses :(

I did a test running 500000 lookups with the original function and my own and compared the results from both functions looking for any differences. The test program was fed from /proc/kallsyms from my machine. Because there were no aliases there, the result was ok and I felt confident about the algorithm.

Anyway, at first glance your patch looks right, and I don't think there will be any performance implications from it, unless there can be thousands of aliases for the same address :)

Paulo Marques - www.grupopie.com

Hi,

I've been messing with scripts/kallsyms.c to try to follow Andi Kleen's suggestion of calculating the markers at compile time. This would make the code in kernel/kallsyms.c much simpler.

In the process I could get rid of the aliased symbols at compile time also. There are only 2 places where they might matter:

- the kallsyms_lookup_name function. GREP'ing through the code shows
that this function is only used in arch/ppc64/xmon/xmon.c. Does xmon need to know about aliased symbols?

- /proc/kallsyms. Of course this is a problem, because since this is
available in user space we can break applications that rely on having aliased symbols there. Are there any?

I have no problem in keeping the aliased symbols as the code to handle them is not that big anyway. Is just that it hurts my programmer instincts to leave completely useless code hanging around. If it is not completely useless, then it's another story :)

Any comments will be greatly appreciated,

Paulo Marques - www.grupopie.com

kdb uses aliased symbols as well. The user can enter any kernel symbol name and have it converted to an address.

Ok, I'll leave them alone, then.

Just another quick question: is kallsyms_names only used by the functions in kallsyms.c and everyone else simply uses those functions, or are there direct users of kallsyms_names?

This is because another thing I was pondering was to change the stem compression scheme into a different one, changing all the stuff in kallsyms.c accordingly. If there are direct users of kallsyms_names, this would break them. There are none in the vanilla kernel as far as I can grep, but there might be outside (like in kdb).

I've done some tests with a different scheme and my uncompressed 170kb symbol table goes to about 134kb with stem compression and to about 90kb with the new scheme. This is not usable right now because compression still takes a long time (although the decompression inside kernel/kallsyms.c is even simpler than it is now). I'm now trying to speed up compression.

As always, comments will be greatly appreciated :)

Paulo Marques - www.grupopie.com

Hi Paulo.

kallsyms_names should only be used by kallsyms, so there are no issue changing this interface.
That said do not put too much effort moving kode from the kernel to kallsyms.c. kallsyms support can be deselected, and users will not care about the little extra overhead (down in noise compared with the symbols).
Keeping the data passed in from the build tools as simple as possible is the better goal here. Then the kernel can implement the extra code to optimize speed.

kallsyms parses the output of objdump as does other tools in the kernel. Would you be willing to look into an elf-tool for the kernel?

A consistent output from an Elf-tool is preferred as replacement for the hacking needed to use output from objdump and nm. See arch/sparc/boot/btfixup as a horrid example.

objdump and nm has been optimised for human readable output, and is not easy to parse up for various tricky usage.

Rusty Russell's module-init-tools has some good starting stuff.

PS. Please cc: me on future patches in this area - thanks.

Sam

distributions tend to enable it though, so saving 64K of kernel RAM is good indeed. Good compression of the symbols increases the applicability of kallsyms.

Ingo

I know I'm probably putting to much effort on a low priority task (understatement of the year), but I was having fun doing it, so I saw no reason to stop :)

The new algorithm that I was thinking about is quite simple from the kernel point of view. It takes advantage of the fact that not all characters are allowed on symbols.

It uses these extra chars to feed a table that maps "special unused char"->"small string". For instance, it can say char \x85 is in fact "write_". Interesting enough the best string on my test data is "acpi_", and saves about 3kb of data to map it to just one char :)

So the work in the kernel is quite easy, and I believe it will in fact be faster than now, using less code.

The real problem is that the algorithm has to give the best strings to use in the table fast enough as to not be noticed in the total kernel compile time. Selecting the best strings is a really interesting problem from a mathematical point of view, and I was trying to solve it just for the fun of doing it :)

I'm glad you also found this scheme to be useful.

The code might be useful on other situations where we need to compress english text (or something like that) in a way that uncompressing a small string is quite fast. (I remember a thread a long time ago about compressing all the printk texts in the kernel, so maybe this could be useful there too)

Paulo Marques - www.grupopie.com

You could do that at compile time (in scripts/kallsyms.c)

I'm surprised that using 8 markers helps anything. There should be many many more 0 stems than that in a not so big kernel.
Did you actually measure the hit rate of the cache? I bet it is pretty low.

-Andi

You're right! I'll see if I can come up with a patch.

If this is done in scripts/kallsyms.c, there is less code needed in the actual kernel, and there is no time penalty on the first lookup. This is a true win-win scenario :)

Thanks a lot for your suggestion.

Well, I only left in the resulting source code the pieces that I actually measured to be a significant improvment.

The thing is, this is not exactly a cache.

The problem that the markers address is that the decompression must be done sequentially.

If I have 20000 symbols and already figured out from the binary search that I need symbol 11201 (for instance), I would have to go through 11201 symbols to get to the symbol I need.

The algorithm I wrote keeps markers in the middle of the stream, so that when I try to fetch symbol 11201, I already know where symbol 10000 is because of the marker and only have to go through 1201 symbols.

With N markers you get N times the speed on the name search. (actually this is not exactly right for high values of N, because you can only use a marker that is a 0 stem, but for N<~32 this is a good approximation)

Paulo Marques - www.grupopie.com
"In a world without walls and fences who needs windows and gates?"

binary searching should be doable without much extra code, the kallsym entries are already sorted.

Ingo