Download raw body.
btrace(8): cache ELF .symtab, .strtab in sorted array
On Tue, Feb 27, 2024 at 06:22:18PM -0600, Scott Cheloha wrote:
> On Sun, Feb 18, 2024 at 06:07:28PM -0600, Scott Cheloha wrote:
> > 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.
>
> Ping.
>
> Here's a tidier patch.
>
> This is a very nice speedup. The patch dramatically reduces the drop
> rate.
(whoops, wrong patch, my bad. this is what I meant to send.)
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 28 Feb 2024 03:04:20 -0000
@@ -23,6 +23,7 @@
#include <err.h>
#include <fcntl.h>
#include <gelf.h>
+#include <stdint.h>
#include <stdio.h>
#include <stdlib.h>
#include <string.h>
@@ -30,60 +31,143 @@
#include "btrace.h"
+struct sym {
+ 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)
{
- struct syms *syms;
- int error;
+ char *name;
+ Elf *elf;
+ Elf_Data *data = NULL;
+ Elf_Scn *scn = NULL, *symtab;
+ GElf_Sym sym;
+ GElf_Shdr shdr;
+ size_t i, shstrndx, strtabndx = SIZE_MAX, symtab_size;
+ struct sym *tmp;
+ struct syms *syms = NULL;
+ 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;
- error = kelf_parse(syms);
- if (error)
+ if (elf_getshdrstrndx(elf, &shstrndx) != 0) {
+ warnx("elf_getshdrstrndx: %s", elf_errmsg(-1));
goto bad;
+ }
- return syms;
+ 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_MAX) {
+ warnx("%s: %s: section not found", path, ELF_STRTAB);
+ goto bad;
+ }
+
+ 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;
+ debug("%s: %zu symbols %zu functions\n",
+ path, symtab_size, syms->nsymb);
+
+ /* Sort symbols in ascending order by address. */
+ qsort(syms->table, syms->nsymb, sizeof *syms->table, sym_compare_sort);
bad:
- kelf_close(syms);
- return NULL;
+ elf_end(elf);
+ close(fd);
+ return syms;
}
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 +175,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:
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;
}
Index: btrace.c
===================================================================
RCS file: /cvs/src/usr.sbin/btrace/btrace.c,v
diff -u -p -r1.89 btrace.c
--- btrace.c 27 Feb 2024 12:38:12 -0000 1.89
+++ btrace.c 28 Feb 2024 03:04:38 -0000
@@ -105,7 +105,6 @@ int ba2dtflags(struct bt_arg *);
* Debug routines.
*/
__dead void xabort(const char *, ...);
-void debug(const char *, ...);
void debugx(const char *, ...);
const char *debug_probe_name(struct bt_probe *);
void debug_dump_term(struct bt_arg *);
Index: btrace.h
===================================================================
RCS file: /cvs/src/usr.sbin/btrace/btrace.h,v
diff -u -p -r1.14 btrace.h
--- btrace.h 27 Feb 2024 12:50:33 -0000 1.14
+++ btrace.h 28 Feb 2024 03:04:38 -0000
@@ -33,6 +33,7 @@ const char * ba_name(struct bt_arg *);
long ba2long(struct bt_arg *, struct dt_evt *);
const char *ba2str(struct bt_arg *, struct dt_evt *);
long bacmp(struct bt_arg *, struct bt_arg *);
+void debug(const char *, ...);
unsigned long dt_get_offset(pid_t);
/* ksyms.c */
btrace(8): cache ELF .symtab, .strtab in sorted array