Date: Wed, 29 Dec 2021 23:06:23 GMT From: Colin Percival <cperciva@FreeBSD.org> To: src-committers@FreeBSD.org, dev-commits-src-all@FreeBSD.org, dev-commits-src-branches@FreeBSD.org Subject: git: 89a9852f327a - stable/13 - MFC loader+userland TSLOG support Message-ID: <202112292306.1BTN6NrL090209@gitrepo.freebsd.org>
next in thread | raw e-mail | index | archive | help
The branch stable/13 has been updated by cperciva: URL: https://cgit.FreeBSD.org/src/commit/?id=89a9852f327abbbd5f7ac29fa9150a1f012449b4 commit 89a9852f327abbbd5f7ac29fa9150a1f012449b4 Author: Colin Percival <cperciva@FreeBSD.org> AuthorDate: 2021-05-30 20:17:11 +0000 Commit: Colin Percival <cperciva@FreeBSD.org> CommitDate: 2021-12-29 22:53:18 +0000 MFC loader+userland TSLOG support stand/common: Add file_addbuf() libsa: Add support for timestamp logging (tslog) stand/common: Add support for timestamp logging (tslog) i386/loader: Call tslog_init efi/loader: Call tslog_init (+ bugfix) stand/common command_boot: Pass tslog to kernel kern_tslog: Include tslog data from loader loader: Use tslog to instrument some functions Add userland boot profiling to TSLOG (+ bugfix) Sponsored by: https://www.patreon.com/cperciva (cherry picked from commit 60a978bec9123fcb9c74bd925e06dd3f4faddac6) (cherry picked from commit e193d3ba337757a27148a38494d3df106b826d1c) (cherry picked from commit c8dfc327db2373c721a35efe857cf07262fd7dd0) (cherry picked from commit c4b65e954f0f4754941f5b37436231f611b76d67) (cherry picked from commit f49381ccb6bc8a5733f1aa505e716eddae299986) (cherry picked from commit 537a44bf281559d304850b5e28b6f8b8e44fd593) (cherry picked from commit fe51b5a76de38d20cddc05a4c6cb1103d1a0547e) (cherry picked from commit 313724bab940c1844fda3d797cf88cd46780e62a) (cherry picked from commit 46dd801acb2318c8464b185893bb111f09b71138) (cherry picked from commit 52e125c2bd302982c179ecc920cc9a6e166033d6) (cherry picked from commit 19e4f2f289fb8d2b14576a65ca9e6f931dbb6a02) --- stand/common/boot.c | 3 ++ stand/common/bootstrap.h | 3 ++ stand/common/console.c | 4 ++ stand/common/gfx_fb.c | 14 ++++++ stand/common/interp.c | 2 + stand/common/interp_lua.c | 6 +++ stand/common/module.c | 51 +++++++++++++++++++++ stand/common/tslog.c | 81 +++++++++++++++++++++++++++++++++ stand/efi/libefi/efipart.c | 3 ++ stand/efi/loader/efi_main.c | 4 ++ stand/i386/libi386/biosdisk.c | 17 +++++++ stand/i386/loader/main.c | 6 +++ stand/libsa/Makefile | 2 +- stand/libsa/open.c | 5 +++ stand/libsa/read.c | 11 ++++- stand/libsa/stand.h | 9 ++++ stand/libsa/tslog.c | 78 ++++++++++++++++++++++++++++++++ stand/libsa/twiddle.c | 11 ++++- stand/loader.mk | 2 +- sys/kern/kern_exec.c | 1 + sys/kern/kern_exit.c | 1 + sys/kern/kern_fork.c | 1 + sys/kern/kern_tslog.c | 101 ++++++++++++++++++++++++++++++++++++++++++ sys/kern/vfs_lookup.c | 1 + sys/sys/tslog.h | 7 +++ 25 files changed, 418 insertions(+), 6 deletions(-) diff --git a/stand/common/boot.c b/stand/common/boot.c index 2103f6dc240c..5ce6fe8a6760 100644 --- a/stand/common/boot.c +++ b/stand/common/boot.c @@ -113,6 +113,9 @@ command_boot(int argc, char *argv[]) #endif #endif + /* Pass the tslog buffer to the kernel as a preloaded module. */ + tslog_publish(); + /* Call the exec handler from the loader matching the kernel */ file_formats[fp->f_loader]->l_exec(fp); return(CMD_ERROR); diff --git a/stand/common/bootstrap.h b/stand/common/bootstrap.h index 80a306f1d3e7..eb4e50203133 100644 --- a/stand/common/bootstrap.h +++ b/stand/common/bootstrap.h @@ -263,6 +263,9 @@ void file_addmetadata(struct preloaded_file *, int, size_t, void *); int file_addmodule(struct preloaded_file *, char *, int, struct kernel_module **); void file_removemetadata(struct preloaded_file *fp); +int file_addbuf(const char *name, const char *type, size_t len, void *buf); +int tslog_init(void); +int tslog_publish(void); vm_offset_t build_font_module(vm_offset_t); diff --git a/stand/common/console.c b/stand/common/console.c index 5b2ddfb10f69..7886f9386c14 100644 --- a/stand/common/console.c +++ b/stand/common/console.c @@ -53,6 +53,8 @@ cons_probe(void) int active; char *prefconsole; + TSENTER(); + /* We want a callback to install the new value when this var changes. */ env_setenv("twiddle_divisor", EV_VOLATILE, "1", twiddle_set, env_nounset); @@ -98,6 +100,8 @@ cons_probe(void) env_nounset); free(prefconsole); } + + TSEXIT(); } int diff --git a/stand/common/gfx_fb.c b/stand/common/gfx_fb.c index a9fcec9942f5..f14242b70170 100644 --- a/stand/common/gfx_fb.c +++ b/stand/common/gfx_fb.c @@ -2432,6 +2432,8 @@ read_list(char *fonts) char buf[PATH_MAX]; int fd, len; + TSENTER(); + dir = strdup(fonts); if (dir == NULL) return (NULL); @@ -2479,6 +2481,7 @@ read_list(char *fonts) SLIST_INSERT_HEAD(nl, np, n_entry); } close(fd); + TSEXIT(); return (nl); } @@ -2496,6 +2499,8 @@ insert_font(char *name, FONT_FLAGS flags) int fd; char *font_name; + TSENTER(); + font_name = NULL; if (flags == FONT_BUILTIN) { /* @@ -2542,6 +2547,7 @@ insert_font(char *name, FONT_FLAGS flags) free(entry->font_name); entry->font_name = font_name; entry->font_flags = FONT_RELOAD; + TSEXIT(); return (true); } } @@ -2565,6 +2571,7 @@ insert_font(char *name, FONT_FLAGS flags) if (STAILQ_EMPTY(&fonts)) { STAILQ_INSERT_HEAD(&fonts, fp, font_next); + TSEXIT(); return (true); } @@ -2583,6 +2590,7 @@ insert_font(char *name, FONT_FLAGS flags) STAILQ_INSERT_AFTER(&fonts, previous, fp, font_next); } + TSEXIT(); return (true); } next = STAILQ_NEXT(entry, font_next); @@ -2590,10 +2598,12 @@ insert_font(char *name, FONT_FLAGS flags) size > next->font_data->vfbd_width * next->font_data->vfbd_height) { STAILQ_INSERT_AFTER(&fonts, entry, fp, font_next); + TSEXIT(); return (true); } previous = entry; } + TSEXIT(); return (true); } @@ -2652,6 +2662,8 @@ autoload_font(bool bios) struct name_list *nl; struct name_entry *np; + TSENTER(); + nl = read_list("/boot/fonts/INDEX.fonts"); if (nl == NULL) return; @@ -2673,6 +2685,8 @@ autoload_font(bool bios) } (void) cons_update_mode(gfx_state.tg_fb_type != FB_TEXT); + + TSEXIT(); } COMMAND_SET(load_font, "loadfont", "load console font from file", command_font); diff --git a/stand/common/interp.c b/stand/common/interp.c index a0a6bd486614..ab68694d61b7 100644 --- a/stand/common/interp.c +++ b/stand/common/interp.c @@ -48,6 +48,8 @@ interact(void) static char input[256]; /* big enough? */ const char * volatile interp_identifier; + TSENTER(); + /* * Because interp_identifier is volatile, it cannot be optimized out by * the compiler as it's considered an externally observable event. This diff --git a/stand/common/interp_lua.c b/stand/common/interp_lua.c index 94001918e151..8a420660683e 100644 --- a/stand/common/interp_lua.c +++ b/stand/common/interp_lua.c @@ -107,6 +107,8 @@ interp_init(void) const char *filename; const luaL_Reg *lib; + TSENTER(); + setenv("script.lang", "lua", 1); LDBG("creating context"); @@ -131,6 +133,8 @@ interp_init(void) lua_pop(luap, 1); setenv("autoboot_delay", "NO", 1); } + + TSEXIT(); } int @@ -142,6 +146,7 @@ interp_run(const char *line) struct interp_lua_softc *softc = &lua_softc; int status, ret; + TSENTER(); luap = softc->luap; LDBG("executing line..."); if ((status = luaL_dostring(luap, line)) != 0) { @@ -186,6 +191,7 @@ interp_run(const char *line) } } + TSEXIT(); return (status == 0 ? CMD_OK : CMD_ERROR); } diff --git a/stand/common/module.c b/stand/common/module.c index 34ffc10cded3..8bddd9f56f52 100644 --- a/stand/common/module.c +++ b/stand/common/module.c @@ -1042,6 +1042,57 @@ file_removemetadata(struct preloaded_file *fp) fp->f_metadata = NULL; } +/* + * Add a buffer to the list of preloaded "files". + */ +int +file_addbuf(const char *name, const char *type, size_t len, void *buf) +{ + struct preloaded_file *fp; + vm_offset_t dest; + + /* We can't load first */ + if ((file_findfile(NULL, NULL)) == NULL) { + command_errmsg = "can't load file before kernel"; + return (-1); + } + + /* Figure out where to load the data. */ + dest = loadaddr; + if (archsw.arch_loadaddr != NULL) + dest = archsw.arch_loadaddr(LOAD_RAW, (void *)name, dest); + + /* Create & populate control structure */ + fp = file_alloc(); + if (fp == NULL) { + snprintf(command_errbuf, sizeof (command_errbuf), + "no memory to load %s", name); + return (-1); + } + fp->f_name = strdup(name); + fp->f_type = strdup(type); + fp->f_args = NULL; + fp->f_metadata = NULL; + fp->f_loader = -1; + fp->f_addr = dest; + fp->f_size = len; + if ((fp->f_name == NULL) || (fp->f_type == NULL)) { + snprintf(command_errbuf, sizeof (command_errbuf), + "no memory to load %s", name); + free(fp->f_name); + free(fp->f_type); + return (-1); + } + + /* Copy the data in. */ + archsw.arch_copyin(buf, fp->f_addr, len); + loadaddr = fp->f_addr + len; + + /* Add to the list of loaded files */ + file_insert_tail(fp); + return(0); +} + struct file_metadata * metadata_next(struct file_metadata *md, int type) { diff --git a/stand/common/tslog.c b/stand/common/tslog.c new file mode 100644 index 000000000000..3851e760daf1 --- /dev/null +++ b/stand/common/tslog.c @@ -0,0 +1,81 @@ +/*- + * Copyright (c) 2021 Colin Percival + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#include <sys/cdefs.h> +__FBSDID("$FreeBSD$"); + +#include <sys/types.h> + +#include <stand.h> + +#include "bootstrap.h" + +/* Buffer for holding tslog data in string format. */ +#ifndef LOADER_TSLOGSIZE +#define LOADER_TSLOGSIZE (2 * 1024 * 1024) +#endif + +int +tslog_init(void) +{ + void * tslog_buf; + + /* Allocate buffer and pass to libsa tslog code. */ + if ((tslog_buf = malloc(LOADER_TSLOGSIZE)) == NULL) + return (-1); + tslog_setbuf(tslog_buf, LOADER_TSLOGSIZE); + + /* Record this as when we entered the loader. */ + TSRAW("ENTER", "loader", NULL); + + return (0); +} + +/* + * Pass our tslog buffer as a preloaded "module" to the kernel. This should + * be called as late as possible prior to the kernel being executed, since + * any timestamps logged after this is called will not be visible to the + * kernel. + */ +int +tslog_publish(void) +{ + void * tslog_buf; + size_t tslog_bufpos; + + /* Record a log entry for ending logging. */ + TSRAW("EXIT", "loader", NULL); + + /* Get the buffer and its current length. */ + tslog_getbuf(&tslog_buf, &tslog_bufpos); + + /* If we never allocated a buffer, return an error. */ + if (tslog_buf == NULL) + return (-1); + + /* Store the buffer where the kernel can read it. */ + return (file_addbuf("TSLOG", "TSLOG data", tslog_bufpos, tslog_buf)); +} diff --git a/stand/efi/libefi/efipart.c b/stand/efi/libefi/efipart.c index 424df7d2e423..aede28ef40c3 100644 --- a/stand/efi/libefi/efipart.c +++ b/stand/efi/libefi/efipart.c @@ -1006,6 +1006,8 @@ efipart_readwrite(EFI_BLOCK_IO *blkio, int rw, daddr_t blk, daddr_t nblks, { EFI_STATUS status; + TSENTER(); + if (blkio == NULL) return (ENXIO); if (blk < 0 || blk > blkio->Media->LastBlock) @@ -1032,6 +1034,7 @@ efipart_readwrite(EFI_BLOCK_IO *blkio, int rw, daddr_t blk, daddr_t nblks, printf("%s: rw=%d, blk=%ju size=%ju status=%lu\n", __func__, rw, blk, nblks, EFI_ERROR_CODE(status)); } + TSEXIT(); return (efi_status_to_errno(status)); } diff --git a/stand/efi/loader/efi_main.c b/stand/efi/loader/efi_main.c index fa3c765c36ab..736c1aa56c99 100644 --- a/stand/efi/loader/efi_main.c +++ b/stand/efi/loader/efi_main.c @@ -27,6 +27,7 @@ #include <sys/cdefs.h> __FBSDID("$FreeBSD$"); +#include <bootstrap.h> #include <efi.h> #include <eficonsctl.h> #include <efilib.h> @@ -101,6 +102,9 @@ efi_main(EFI_HANDLE image_handle, EFI_SYSTEM_TABLE *system_table) setheap((void *)(uintptr_t)heap, (void *)(uintptr_t)(heap + heapsize)); + /* Start tslog now that we have a heap.*/ + tslog_init(); + /* Use efi_exit() from here on... */ status = OpenProtocolByHandle(IH, &image_protocol, (void**)&img); diff --git a/stand/i386/libi386/biosdisk.c b/stand/i386/libi386/biosdisk.c index 00d2de5de418..2c52617f255d 100644 --- a/stand/i386/libi386/biosdisk.c +++ b/stand/i386/libi386/biosdisk.c @@ -339,6 +339,8 @@ bd_init(void) int base, unit; bdinfo_t *bd; + TSENTER(); + base = 0x80; for (unit = 0; unit < *(unsigned char *)PTOV(BIOS_NUMDRIVES); unit++) { /* @@ -358,6 +360,7 @@ bd_init(void) STAILQ_INSERT_TAIL(&hdinfo, bd, bd_link); } bcache_add_dev(unit); + TSEXIT(); return (0); } @@ -840,6 +843,8 @@ bd_open(struct open_file *f, ...) va_list ap; int rc; + TSENTER(); + va_start(ap, f); dev = va_arg(ap, struct disk_devdesc *); va_end(ap); @@ -873,6 +878,7 @@ bd_open(struct open_file *f, ...) } } } + TSEXIT(); return (rc); } @@ -1135,6 +1141,8 @@ bd_edd_io(bdinfo_t *bd, daddr_t dblk, int blks, caddr_t dest, { static struct edd_packet packet; + TSENTER(); + packet.len = sizeof(struct edd_packet); packet.count = blks; packet.off = VTOPOFF(dest); @@ -1152,6 +1160,8 @@ bd_edd_io(bdinfo_t *bd, daddr_t dblk, int blks, caddr_t dest, v86int(); if (V86_CY(v86.efl)) return (v86.eax >> 8); + + TSEXIT(); return (0); } @@ -1161,6 +1171,8 @@ bd_chs_io(bdinfo_t *bd, daddr_t dblk, int blks, caddr_t dest, { uint32_t x, bpc, cyl, hd, sec; + TSENTER(); + bpc = bd->bd_sec * bd->bd_hds; /* blocks per cylinder */ x = dblk; cyl = x / bpc; /* block # / blocks per cylinder */ @@ -1189,6 +1201,7 @@ bd_chs_io(bdinfo_t *bd, daddr_t dblk, int blks, caddr_t dest, v86int(); if (V86_CY(v86.efl)) return (v86.eax >> 8); + TSEXIT(); return (0); } @@ -1206,6 +1219,8 @@ bd_io(struct disk_devdesc *dev, bdinfo_t *bd, daddr_t dblk, int blks, { int result, retry; + TSENTER(); + /* Just in case some idiot actually tries to read/write -1 blocks... */ if (blks < 0) return (-1); @@ -1264,6 +1279,8 @@ bd_io(struct disk_devdesc *dev, bdinfo_t *bd, daddr_t dblk, int blks, } } + TSEXIT(); + return (result); } diff --git a/stand/i386/loader/main.c b/stand/i386/loader/main.c index a595340d3a13..6b81ef411f7f 100644 --- a/stand/i386/loader/main.c +++ b/stand/i386/loader/main.c @@ -130,6 +130,12 @@ main(void) } setheap(heap_bottom, heap_top); + /* + * Now that malloc is usable, allocate a buffer for tslog and start + * logging timestamps during the boot process. + */ + tslog_init(); + /* * detect ACPI for future reference. This may set console to comconsole * if we do have ACPI SPCR table. diff --git a/stand/libsa/Makefile b/stand/libsa/Makefile index 838fefb260a8..815f479b5a0a 100644 --- a/stand/libsa/Makefile +++ b/stand/libsa/Makefile @@ -16,7 +16,7 @@ LIB?= sa SRCS+= gzguts.h zutil.h __main.c abort.c assert.c bcd.c environment.c \ getopt.c gets.c globals.c \ hexdump.c pager.c panic.c printf.c strdup.c strerror.c \ - random.c sbrk.c twiddle.c zalloc.c zalloc_malloc.c + random.c sbrk.c tslog.c twiddle.c zalloc.c zalloc_malloc.c # private (pruned) versions of libc string functions SRCS+= strcasecmp.c diff --git a/stand/libsa/open.c b/stand/libsa/open.c index e2591b680319..c62e48f0e1d8 100644 --- a/stand/libsa/open.c +++ b/stand/libsa/open.c @@ -145,6 +145,8 @@ open(const char *fname, int mode) int fd, i, error, besterror; const char *file; + TSENTER(); + if ((fd = o_gethandle(&f)) == -1) { errno = EMFILE; return (-1); @@ -174,6 +176,7 @@ open(const char *fname, int mode) if (file == NULL || *file == '\0') { f->f_flags |= F_RAW; f->f_rabuf = NULL; + TSEXIT(); return (fd); } @@ -197,10 +200,12 @@ open(const char *fname, int mode) err: f->f_flags = 0; errno = error; + TSEXIT(); return (-1); ok: f->f_ops = fs; o_rainit(f); + TSEXIT(); return (fd); } diff --git a/stand/libsa/read.c b/stand/libsa/read.c index 7d19dae0670d..084bca2522f3 100644 --- a/stand/libsa/read.c +++ b/stand/libsa/read.c @@ -72,6 +72,7 @@ read(int fd, void *dest, size_t bcount) struct open_file *f; size_t resid; + TSENTER(); f = fd2open_file(fd); if (f == NULL || !(f->f_flags & F_READ)) { errno = EBADF; @@ -84,6 +85,7 @@ read(int fd, void *dest, size_t bcount) if (errno) return (-1); f->f_offset += resid; + TSEXIT(); return (resid); } @@ -103,8 +105,10 @@ read(int fd, void *dest, size_t bcount) f->f_raoffset += ccount; f->f_ralen -= ccount; resid -= ccount; - if (resid == 0) + if (resid == 0) { + TSEXIT(); return (bcount); + } dest = (char *)dest + ccount; } @@ -117,6 +121,7 @@ read(int fd, void *dest, size_t bcount) errno = (f->f_ops->fo_read)(f, dest, resid, &cresid); if (errno != 0) return (-1); + TSEXIT(); return (bcount - cresid); } @@ -128,7 +133,9 @@ read(int fd, void *dest, size_t bcount) f->f_raoffset = 0; f->f_ralen = SOPEN_RASIZE - cresid; /* no more data, return what we had */ - if (f->f_ralen == 0) + if (f->f_ralen == 0) { + TSEXIT(); return (bcount - resid); + } } } diff --git a/stand/libsa/stand.h b/stand/libsa/stand.h index e49b8c50619d..535fee31d586 100644 --- a/stand/libsa/stand.h +++ b/stand/libsa/stand.h @@ -477,4 +477,13 @@ caddr_t ptov(uintptr_t); /* hexdump.c */ void hexdump(caddr_t region, size_t len); +/* tslog.c */ +#define TSRAW(a, b, c) tslog(a, b, c) +#define TSENTER() TSRAW("ENTER", __func__, NULL) +#define TSEXIT() TSRAW("EXIT", __func__, NULL) +#define TSLINE() TSRAW("EVENT", __FILE__, __XSTRING(__LINE__)) +void tslog(const char *, const char *, const char *); +void tslog_setbuf(void * buf, size_t len); +void tslog_getbuf(void ** buf, size_t * len); + #endif /* STAND_H */ diff --git a/stand/libsa/tslog.c b/stand/libsa/tslog.c new file mode 100644 index 000000000000..7ea18e0bb8f8 --- /dev/null +++ b/stand/libsa/tslog.c @@ -0,0 +1,78 @@ +/*- + * Copyright (c) 2021 Colin Percival + * All rights reserved. + * + * Redistribution and use in source and binary forms, with or without + * modification, are permitted provided that the following conditions + * are met: + * 1. Redistributions of source code must retain the above copyright + * notice, this list of conditions and the following disclaimer. + * 2. Redistributions in binary form must reproduce the above copyright + * notice, this list of conditions and the following disclaimer in the + * documentation and/or other materials provided with the distribution. + * + * THIS SOFTWARE IS PROVIDED BY THE AUTHOR AND CONTRIBUTORS ``AS IS'' AND + * ANY EXPRESS OR IMPLIED WARRANTIES, INCLUDING, BUT NOT LIMITED TO, THE + * IMPLIED WARRANTIES OF MERCHANTABILITY AND FITNESS FOR A PARTICULAR PURPOSE + * ARE DISCLAIMED. IN NO EVENT SHALL THE AUTHOR OR CONTRIBUTORS BE LIABLE + * FOR ANY DIRECT, INDIRECT, INCIDENTAL, SPECIAL, EXEMPLARY, OR CONSEQUENTIAL + * DAMAGES (INCLUDING, BUT NOT LIMITED TO, PROCUREMENT OF SUBSTITUTE GOODS + * OR SERVICES; LOSS OF USE, DATA, OR PROFITS; OR BUSINESS INTERRUPTION) + * HOWEVER CAUSED AND ON ANY THEORY OF LIABILITY, WHETHER IN CONTRACT, STRICT + * LIABILITY, OR TORT (INCLUDING NEGLIGENCE OR OTHERWISE) ARISING IN ANY WAY + * OUT OF THE USE OF THIS SOFTWARE, EVEN IF ADVISED OF THE POSSIBILITY OF + * SUCH DAMAGE. + */ + +#include <sys/cdefs.h> +__FBSDID("$FreeBSD$"); + +#include <sys/types.h> + +#include <machine/cpufunc.h> + +#include <stand.h> + +/* Buffer for holding tslog data in string format. */ +static char * tslog_buf = NULL; +static size_t tslog_buflen = 0; +static size_t tslog_bufpos = 0; + +void +tslog_setbuf(void * buf, size_t len) +{ + + tslog_buf = (char *)buf; + tslog_buflen = len; + tslog_bufpos = 0; +} + +void +tslog_getbuf(void ** buf, size_t * len) +{ + + *buf = (void *)tslog_buf; + *len = tslog_bufpos; +} + +void +tslog(const char * type, const char * f, const char * s) +{ +#if defined(__amd64__) || defined(__i386__) + uint64_t tsc = rdtsc(); +#else + uint64_t tsc = 0; +#endif + int len; + + /* If we have no buffer, do nothing. */ + if (tslog_buf == NULL) + return; + + /* Append to existing buffer, if we have enough space. */ + len = snprintf(&tslog_buf[tslog_bufpos], + tslog_buflen - tslog_bufpos, "0x0 %llu %s %s%s%s\n", + (unsigned long long)tsc, type, f, s ? " " : "", s ? s : ""); + if ((len > 0) && (tslog_bufpos + len <= tslog_buflen)) + tslog_bufpos += len; +} diff --git a/stand/libsa/twiddle.c b/stand/libsa/twiddle.c index 31828542f7f3..7565295fa1a3 100644 --- a/stand/libsa/twiddle.c +++ b/stand/libsa/twiddle.c @@ -49,16 +49,23 @@ twiddle(u_int callerdiv) { static u_int callercnt, globalcnt, pos; + TSENTER(); + callercnt++; - if (callerdiv > 1 && (callercnt % callerdiv) != 0) + if (callerdiv > 1 && (callercnt % callerdiv) != 0) { + TSEXIT(); return; + } globalcnt++; - if (globaldiv > 1 && (globalcnt % globaldiv) != 0) + if (globaldiv > 1 && (globalcnt % globaldiv) != 0) { + TSEXIT(); return; + } putchar("|/-\\"[pos++ & 3]); putchar('\b'); + TSEXIT(); } void diff --git a/stand/loader.mk b/stand/loader.mk index 3a38a9bc9e63..85d3aad326de 100644 --- a/stand/loader.mk +++ b/stand/loader.mk @@ -6,7 +6,7 @@ CFLAGS+=-I${LDRSRC} SRCS+= boot.c commands.c console.c devopen.c interp.c SRCS+= interp_backslash.c interp_parse.c ls.c misc.c -SRCS+= module.c nvstore.c pnglite.c +SRCS+= module.c nvstore.c pnglite.c tslog.c CFLAGS.module.c += -I$(SRCTOP)/sys/teken -I${SRCTOP}/contrib/pnglite diff --git a/sys/kern/kern_exec.c b/sys/kern/kern_exec.c index 7b27e5b8a885..246d72234a29 100644 --- a/sys/kern/kern_exec.c +++ b/sys/kern/kern_exec.c @@ -352,6 +352,7 @@ kern_execve(struct thread *td, struct image_args *args, struct mac *mac_p, struct vmspace *oldvmspace) { + TSEXEC(td->td_proc->p_pid, args->begin_argv); AUDIT_ARG_ARGV(args->begin_argv, args->argc, exec_args_get_begin_envv(args) - args->begin_argv); AUDIT_ARG_ENVV(exec_args_get_begin_envv(args), args->envc, diff --git a/sys/kern/kern_exit.c b/sys/kern/kern_exit.c index 0b3265cac6f1..226cd5991261 100644 --- a/sys/kern/kern_exit.c +++ b/sys/kern/kern_exit.c @@ -228,6 +228,7 @@ exit1(struct thread *td, int rval, int signo) mtx_assert(&Giant, MA_NOTOWNED); KASSERT(rval == 0 || signo == 0, ("exit1 rv %d sig %d", rval, signo)); + TSPROCEXIT(td->td_proc->p_pid); p = td->td_proc; /* diff --git a/sys/kern/kern_fork.c b/sys/kern/kern_fork.c index 74b415a838ee..16af36635db2 100644 --- a/sys/kern/kern_fork.c +++ b/sys/kern/kern_fork.c @@ -391,6 +391,7 @@ do_fork(struct thread *td, struct fork_req *fr, struct proc *p2, struct thread * p2->p_state = PRS_NEW; /* protect against others */ p2->p_pid = fork_findpid(fr->fr_flags); AUDIT_ARG_PID(p2->p_pid); + TSFORK(p2->p_pid, p1->p_pid); sx_xlock(&allproc_lock); LIST_INSERT_HEAD(&allproc, p2, p_list); diff --git a/sys/kern/kern_tslog.c b/sys/kern/kern_tslog.c index a0cb230f191c..0e7ad3c9ff23 100644 --- a/sys/kern/kern_tslog.c +++ b/sys/kern/kern_tslog.c @@ -28,6 +28,10 @@ __FBSDID("$FreeBSD$"); #include <sys/param.h> +#include <sys/kernel.h> +#include <sys/linker.h> +#include <sys/malloc.h> +#include <sys/proc.h> #include <sys/sbuf.h> #include <sys/sysctl.h> #include <sys/systm.h> @@ -74,6 +78,9 @@ sysctl_debug_tslog(SYSCTL_HANDLER_ARGS) int error; struct sbuf *sb; size_t i, limit; + caddr_t loader_tslog; + void * loader_tslog_buf; + size_t loader_tslog_len; /* * This code can race against the code in tslog() which stores @@ -84,6 +91,16 @@ sysctl_debug_tslog(SYSCTL_HANDLER_ARGS) * anyone will ever experience this race. */ sb = sbuf_new_for_sysctl(NULL, NULL, 1024, req); + + /* Get data from the boot loader, if it provided any. */ + loader_tslog = preload_search_by_type("TSLOG data"); + if (loader_tslog != NULL) { + loader_tslog_buf = preload_fetch_addr(loader_tslog); + loader_tslog_len = preload_fetch_size(loader_tslog); + sbuf_bcat(sb, loader_tslog_buf, loader_tslog_len); + } + + /* Add data logged within the kernel. */ limit = MIN(nrecs, nitems(timestamps)); for (i = 0; i < limit; i++) { sbuf_printf(sb, "%p", timestamps[i].td); @@ -116,3 +133,87 @@ sysctl_debug_tslog(SYSCTL_HANDLER_ARGS) SYSCTL_PROC(_debug, OID_AUTO, tslog, CTLTYPE_STRING|CTLFLAG_RD|CTLFLAG_MPSAFE, 0, 0, sysctl_debug_tslog, "", "Dump recorded event timestamps"); + +MALLOC_DEFINE(M_TSLOGUSER, "tsloguser", "Strings used by userland tslog"); +static struct procdata { + pid_t ppid; + uint64_t tsc_forked; + uint64_t tsc_exited; + char * execname; + char * namei; + int reused; +} procs[PID_MAX + 1]; + +void +tslog_user(pid_t pid, pid_t ppid, const char * execname, const char * namei) +{ + uint64_t tsc = get_cyclecount(); + + /* If we wrapped, do nothing. */ + if (procs[pid].reused) + return; + + /* If we have a ppid, we're recording a fork. */ + if (ppid != (pid_t)(-1)) { + /* If we have a ppid already, we wrapped. */ + if (procs[pid].ppid) { + procs[pid].reused = 1; + return; + } + + /* Fill in some fields. */ + procs[pid].ppid = ppid; + procs[pid].tsc_forked = tsc; + return; + } + + /* If we have an execname, record it. */ + if (execname != NULL) { + if (procs[pid].execname != NULL) + free(procs[pid].execname, M_TSLOGUSER); + procs[pid].execname = strdup(execname, M_TSLOGUSER); + return; + } + + /* Record the first namei for the process. */ + if (namei != NULL) { + if (procs[pid].namei == NULL) + procs[pid].namei = strdup(namei, M_TSLOGUSER); + return; + } + + /* Otherwise we're recording an exit. */ + procs[pid].tsc_exited = tsc; +} + +static int +sysctl_debug_tslog_user(SYSCTL_HANDLER_ARGS) +{ + int error; + struct sbuf *sb; + pid_t pid; + + sb = sbuf_new_for_sysctl(NULL, NULL, 1024, req); + + /* Export the data we logged. */ + for (pid = 0; pid <= PID_MAX; pid++) { + sbuf_printf(sb, "%zu", (size_t)pid); + sbuf_printf(sb, " %zu", (size_t)procs[pid].ppid); + sbuf_printf(sb, " %llu", + (unsigned long long)procs[pid].tsc_forked); + sbuf_printf(sb, " %llu", + (unsigned long long)procs[pid].tsc_exited); + sbuf_printf(sb, " \"%s\"", procs[pid].execname ? + procs[pid].execname : ""); + sbuf_printf(sb, " \"%s\"", procs[pid].namei ? + procs[pid].namei : ""); + sbuf_printf(sb, "\n"); + } + error = sbuf_finish(sb); + sbuf_delete(sb); + return (error); +} + +SYSCTL_PROC(_debug, OID_AUTO, tslog_user, + CTLTYPE_STRING|CTLFLAG_RD|CTLFLAG_MPSAFE, 0, 0, sysctl_debug_tslog_user, + "", "Dump recorded userland event timestamps"); diff --git a/sys/kern/vfs_lookup.c b/sys/kern/vfs_lookup.c index 454a10175e1b..f4faf0c77210 100644 --- a/sys/kern/vfs_lookup.c +++ b/sys/kern/vfs_lookup.c @@ -615,6 +615,7 @@ namei(struct nameidata *ndp) ktrnamei(cnp->cn_pnbuf); } #endif + TSNAMEI(curthread->td_proc->p_pid, cnp->cn_pnbuf); /* * First try looking up the target without locking any vnodes. diff --git a/sys/sys/tslog.h b/sys/sys/tslog.h index 4b2971e4e643..af3c0931cac8 100644 --- a/sys/sys/tslog.h +++ b/sys/sys/tslog.h @@ -51,12 +51,19 @@ #define TSUNWAIT(x) TSEVENT2("UNWAIT", x); #define TSHOLD(x) TSEVENT2("HOLD", x); #define TSRELEASE(x) TSEVENT2("RELEASE", x); +#define TSFORK(p, pp) TSRAW_USER(p, pp, NULL, NULL) +#define TSEXEC(p, name) TSRAW_USER(p, (pid_t)(-1), name, NULL) +#define TSNAMEI(p, name) TSRAW_USER(p, (pid_t)(-1), NULL, name) +#define TSPROCEXIT(p) TSRAW_USER(p, (pid_t)(-1), NULL, NULL) #ifdef TSLOG #define TSRAW(a, b, c, d) tslog(a, b, c, d) void tslog(void *, int, const char *, const char *); +#define TSRAW_USER(a, b, c, d) tslog_user(a, b, c, d) *** 7 LINES SKIPPED ***
Want to link to this message? Use this URL: <https://mail-archive.FreeBSD.org/cgi/mid.cgi?202112292306.1BTN6NrL090209>