From: Scott Cheloha <scottcheloha@gmail.com>
Subject: btrace(8): cache ELF .symtab, .strtab in sorted array
To: tech@openbsd.org
Cc: mpi@openbsd.org
Date: Sun, 18 Feb 2024 18:07:28 -0600

When btrace(8) runs a profiling probe, the most expensive thing it
does is call kelf_snprintf().  kelf_snprintf() walks through the ELF
.symtab to find a function matching the PC and then looks up the
function's name in the ELF .strtab.

This patch consolidates the .symtab parsing and searching logic into
kelf_open().  We store each function found in the .symtab in an array
sorted by st_value alongside its size and name.  Then, at runtime,
kelf_snprintf() calls bsearch(3) to match the given PC to a function.

On my laptop this patch reduces the average cost of kelf_snprintf()
at idle by about 325x:

# -current
$ doas btrace /usr/share/btrace/kprofile.bt >/dev/null
btrace: kelf_snprintf: cputime 5.250057903 calls 13082 avg 0.000401319

# Patched
$ doas ./obj/btrace /usr/share/btrace/kprofile.bt >/dev/null
btrace: kelf_snprintf: cputime 0.017177200 calls 13896 avg 0.000001236

This could be further optimized by deferring symbol lookup until a
given stacktrace is printed.  That would require typed maps, though.

One thing is missing: I need help working the "best offset" logic for
unsized symbols into this scheme.

Index: ksyms.c
===================================================================
RCS file: /cvs/src/usr.sbin/btrace/ksyms.c,v
diff -u -p -r1.6 ksyms.c
--- ksyms.c	10 Nov 2023 18:56:21 -0000	1.6
+++ ksyms.c	18 Feb 2024 23:43:48 -0000
@@ -30,60 +30,147 @@
 
 #include "btrace.h"
 
+struct sym {
+	const char *sym_name;
+	unsigned long sym_addr;
+	unsigned long sym_size;
+};
+
 struct syms {
-	int		 fd;
-	Elf		*elf;
-	Elf_Scn		*symtab;
-	size_t		 strtabndx, nsymb;
+	struct sym *table;
+	size_t nsymb;
 };
 
-int		 kelf_parse(struct syms *);
+int sym_compare_search(const void *, const void *);
+int sym_compare_sort(const void *, const void *);
 
 struct syms *
 kelf_open(const char *path)
 {
+	char *name;
+	Elf *elf;
+	Elf_Data *data = NULL;
+	Elf_Scn	*scn = NULL, *symtab;
+	GElf_Sym sym;
+	GElf_Shdr shdr;
+	size_t i, shstrndx, strtabndx = -1, symtab_size;
+	struct sym *tmp;
 	struct syms *syms;
-	int error;
+	int fd;
 
 	if (elf_version(EV_CURRENT) == EV_NONE)
 		errx(1, "elf_version: %s", elf_errmsg(-1));
 
-	if ((syms = calloc(1, sizeof(*syms))) == NULL)
-		err(1, NULL);
-
-	syms->fd = open(path, O_RDONLY);
-	if (syms->fd == -1) {
+	fd = open(path, O_RDONLY);
+	if (fd == -1) {
 		warn("open: %s", path);
-		free(syms);
 		return NULL;
 	}
 
-	if ((syms->elf = elf_begin(syms->fd, ELF_C_READ, NULL)) == NULL) {
+	if ((elf = elf_begin(fd, ELF_C_READ, NULL)) == NULL) {
 		warnx("elf_begin: %s", elf_errmsg(-1));
 		goto bad;
 	}
 
-	if (elf_kind(syms->elf) != ELF_K_ELF)
+	if (elf_kind(elf) != ELF_K_ELF)
+		goto bad;
+
+	if (elf_getshdrstrndx(elf, &shstrndx) != 0) {
+		warnx("elf_getshdrstrndx: %s", elf_errmsg(-1));
+		goto bad;
+	}
+
+	while ((scn = elf_nextscn(elf, scn)) != NULL) {
+		if (gelf_getshdr(scn, &shdr) != &shdr) {
+			warnx("elf_getshdr: %s", elf_errmsg(-1));
+			goto bad;
+		}
+
+		if ((name = elf_strptr(elf, shstrndx, shdr.sh_name)) == NULL) {
+			warnx("elf_strptr: %s", elf_errmsg(-1));
+			goto bad;
+		}
+
+		if (strcmp(name, ELF_SYMTAB) == 0 &&
+		    shdr.sh_type == SHT_SYMTAB && shdr.sh_entsize != 0) {
+			symtab = scn;
+			symtab_size = shdr.sh_size / shdr.sh_entsize;
+		}
+
+		if (strcmp(name, ELF_STRTAB) == 0 &&
+		    shdr.sh_type == SHT_STRTAB) {
+			strtabndx = elf_ndxscn(scn);
+		}
+	}
+	if (symtab == NULL) {
+		warnx("%s: %s: section not found", path, ELF_SYMTAB);
+		goto bad;
+	}
+	if (strtabndx == (size_t)-1) {
+		warnx("%s: %s: section not found", path, ELF_STRTAB);
 		goto bad;
+	}
 
-	error = kelf_parse(syms);
-	if (error)
+	data = elf_rawdata(symtab, data);
+	if (data == NULL)
 		goto bad;
 
+	/*
+	 * All errors after this point are allocation failures.
+	 * From here on, don't jump to "bad", just call err(3).
+	 */
+
+	if ((syms = calloc(1, sizeof(*syms))) == NULL)
+		err(1, NULL);
+	syms->table = calloc(symtab_size, sizeof *syms->table);
+	if (syms->table == NULL)
+		err(1, NULL);
+	for (i = 0; i < symtab_size; i++) {
+		if (gelf_getsym(data, i, &sym) == NULL)
+			continue;
+		if (GELF_ST_TYPE(sym.st_info) != STT_FUNC)
+			continue;
+		name = elf_strptr(elf, strtabndx, sym.st_name);
+		if (name == NULL)
+			continue;
+		syms->table[syms->nsymb].sym_name = strdup(name);
+		if (syms->table[syms->nsymb].sym_name == NULL)
+			err(1, NULL);
+		syms->table[syms->nsymb].sym_addr = sym.st_value;
+		syms->table[syms->nsymb].sym_size = sym.st_size;
+		syms->nsymb++;
+	}
+	tmp = reallocarray(syms->table, syms->nsymb, sizeof *syms->table);
+	if (tmp == NULL)
+		err(1, NULL);
+	syms->table = tmp;
+	warnx("%s: %zu symbols %zu functions", path, symtab_size, syms->nsymb);
+
+	/* Sort symbols in ascending order by address. */
+	qsort(syms->table, syms->nsymb, sizeof *syms->table, sym_compare_sort);
+
+	elf_end(elf);
+	close(fd);
+
 	return syms;
 
 bad:
-	kelf_close(syms);
+	elf_end(elf);
+	close(fd);
 	return NULL;
 }
 
 void
 kelf_close(struct syms *syms)
 {
+	size_t i;
+
 	if (syms == NULL)
 		return;
-	elf_end(syms->elf);
-	close(syms->fd);
+
+	for (i = 0; i < syms->nsymb; i++)
+		free(syms->table[i].sym_name);
+	free(syms->table);
 	free(syms);
 }
 
@@ -91,106 +178,46 @@ int
 kelf_snprintsym(struct syms *syms, char *str, size_t size, unsigned long pc,
     unsigned long off)
 {
-	GElf_Sym	 sym;
-	Elf_Data	*data = NULL;
-	Elf_Addr	 offset, bestoff = 0;
-	size_t		 i, bestidx = 0;
-	char		*name;
-	int		 cnt;
+	struct sym key = { .sym_addr = pc + off };
+	struct sym *entry;
+	Elf_Addr offset;
 
 	if (syms == NULL)
 		goto fallback;
 
-	data = elf_rawdata(syms->symtab, data);
-	if (data == NULL)
+	entry = bsearch(&key, syms->table, syms->nsymb, sizeof *syms->table,
+	    sym_compare_search);
+	if (entry == NULL)
 		goto fallback;
 
-	for (i = 0; i < syms->nsymb; i++) {
-		if (gelf_getsym(data, i, &sym) == NULL)
-			continue;
-		if (GELF_ST_TYPE(sym.st_info) != STT_FUNC)
-			continue;
-		if (pc >= sym.st_value + off) {
-			if (pc < (sym.st_value + off + sym.st_size))
-				break;
-			/* Workaround for symbols w/o size, usually asm ones. */
-			if (sym.st_size == 0 && sym.st_value + off > bestoff) {
-				bestidx = i;
-				bestoff = sym.st_value + off;
-			}
-		}
-	}
-
-	if (i == syms->nsymb) {
-		if (bestidx == 0 || gelf_getsym(data, bestidx, &sym) == NULL)
-			goto fallback;
-	}
-
-	name = elf_strptr(syms->elf, syms->strtabndx, sym.st_name);
-	if (name != NULL)
-		cnt = snprintf(str, size, "\n%s", name);
-	else
-		cnt = snprintf(str, size, "\n0x%llx", sym.st_value);
-	if (cnt < 0)
-		return cnt;
-
-	offset = pc - (sym.st_value + off);
+	offset = pc - (entry->sym_addr + off);
 	if (offset != 0) {
-		int l;
-
-		l = snprintf(str + cnt, size > (size_t)cnt ? size - cnt : 0,
-		    "+0x%llx", (unsigned long long)offset);
-		if (l < 0)
-			return l;
-		cnt += l;
+		return snprintf(str, size, "\n%s+0x%llx",
+		    entry->sym_name, (unsigned long long)offset);
 	}
 
-	return cnt;
+	return snprintf(str, size, "\n%s", entry->sym_name);
 
-fallback:
+ fallback:
 	return snprintf(str, size, "\n0x%lx", pc);
 }
 
 int
-kelf_parse(struct syms *syms)
+sym_compare_sort(const void *ap, const void *bp)
 {
-	GElf_Shdr	 shdr;
-	Elf_Scn		*scn, *scnctf;
-	char		*name;
-	size_t		 shstrndx;
+	const struct sym *a = ap, *b = bp;
 
-	if (elf_getshdrstrndx(syms->elf, &shstrndx) != 0) {
-		warnx("elf_getshdrstrndx: %s", elf_errmsg(-1));
-		return 1;
-	}
-
-	scn = scnctf = NULL;
-	while ((scn = elf_nextscn(syms->elf, scn)) != NULL) {
-		if (gelf_getshdr(scn, &shdr) != &shdr) {
-			warnx("elf_getshdr: %s", elf_errmsg(-1));
-			return 1;
-		}
-
-		if ((name = elf_strptr(syms->elf, shstrndx,
-		    shdr.sh_name)) == NULL) {
-			warnx("elf_strptr: %s", elf_errmsg(-1));
-			return 1;
-		}
-
-		if (strcmp(name, ELF_SYMTAB) == 0 &&
-		    shdr.sh_type == SHT_SYMTAB && shdr.sh_entsize != 0) {
-			syms->symtab = scn;
-			syms->nsymb = shdr.sh_size / shdr.sh_entsize;
-		}
-
-		if (strcmp(name, ELF_STRTAB) == 0 &&
-		    shdr.sh_type == SHT_STRTAB) {
-			syms->strtabndx = elf_ndxscn(scn);
-		}
-	}
+	if (a->sym_addr < b->sym_addr)
+		return -1;
+	return a->sym_addr > b->sym_addr;
+}
 
-	if (syms->symtab == NULL)
-		warnx("symbol table not found");
+int
+sym_compare_search(const void *keyp, const void *entryp)
+{
+	const struct sym *entry = entryp, *key = keyp;
 
-	return 0;
+	if (key->sym_addr < entry->sym_addr)
+		return -1;
+	return key->sym_addr >= entry->sym_addr + entry->sym_size;
 }