From nobody Tue Feb 22 00:17:20 2022 X-Original-To: dev-commits-src-main@mlmmj.nyi.freebsd.org Received: from mx1.freebsd.org (mx1.freebsd.org [IPv6:2610:1c1:1:606c::19:1]) by mlmmj.nyi.freebsd.org (Postfix) with ESMTP id ABC8F19DF06B; Tue, 22 Feb 2022 00:17:21 +0000 (UTC) (envelope-from git@FreeBSD.org) Received: from mxrelay.nyi.freebsd.org (mxrelay.nyi.freebsd.org [IPv6:2610:1c1:1:606c::19:3]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256 client-signature RSA-PSS (4096 bits) client-digest SHA256) (Client CN "mxrelay.nyi.freebsd.org", Issuer "R3" (verified OK)) by mx1.freebsd.org (Postfix) with ESMTPS id 4K2fr11GCmz3Ll4; Tue, 22 Feb 2022 00:17:21 +0000 (UTC) (envelope-from git@FreeBSD.org) DKIM-Signature: v=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1645489041; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding; bh=FAdnz36aK8+vyTljgG3qfVZG6HV6YzlAvuxNJ5SnrtM=; b=E7eldY0rRJUr+o9XEe86GBRI0qYvklvJZ/Imk2j+RpV981dOENmqQo2MheqWa5LtC9X8zG 1FLfOzkNz2FwJ7IDMte6YrmOF5wsy22sMeVetw7ed7CysbrOZL9jIBblqIg87rMSQspTcV mY9ptGgd4vrnggbJp/ZSACZdxi/mMtiNqGzYh4xm9k5ZeU0OlzQE/6Ir2ya901weU72Z/C 0Eqni/05h2hqThuVi4RUbKyhW7gAa4cgBXU87wPynTB1+Ndm/I+TJuyRt5RtK5Gkj6bFkt H1P0lD/cGpGGGHQca/hyJZwUcQOiQQE2K+RkOZr6Y06nvKSDjWkEVvzZ2vGNzw== Received: from gitrepo.freebsd.org (gitrepo.freebsd.org [IPv6:2610:1c1:1:6068::e6a:5]) (using TLSv1.3 with cipher TLS_AES_256_GCM_SHA384 (256/256 bits) key-exchange X25519 server-signature RSA-PSS (4096 bits) server-digest SHA256) (Client did not present a certificate) by mxrelay.nyi.freebsd.org (Postfix) with ESMTPS id EF34D19F58; Tue, 22 Feb 2022 00:17:20 +0000 (UTC) (envelope-from git@FreeBSD.org) Received: from gitrepo.freebsd.org ([127.0.1.44]) by gitrepo.freebsd.org (8.16.1/8.16.1) with ESMTP id 21M0HKoB041207; Tue, 22 Feb 2022 00:17:20 GMT (envelope-from git@gitrepo.freebsd.org) Received: (from git@localhost) by gitrepo.freebsd.org (8.16.1/8.16.1/Submit) id 21M0HKUW041206; Tue, 22 Feb 2022 00:17:20 GMT (envelope-from git) Date: Tue, 22 Feb 2022 00:17:20 GMT Message-Id: <202202220017.21M0HKUW041206@gitrepo.freebsd.org> To: src-committers@FreeBSD.org, dev-commits-src-all@FreeBSD.org, dev-commits-src-main@FreeBSD.org From: Mitchell Horne Subject: git: 7b0a665d72c0 - main - boottrace: annotate init and shutdown utilities List-Id: Commit messages for the main branch of the src repository List-Archive: https://lists.freebsd.org/archives/dev-commits-src-main List-Help: List-Post: List-Subscribe: List-Unsubscribe: Sender: owner-dev-commits-src-main@freebsd.org X-BeenThere: dev-commits-src-main@freebsd.org MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit X-Git-Committer: mhorne X-Git-Repository: src X-Git-Refname: refs/heads/main X-Git-Reftype: branch X-Git-Commit: 7b0a665d72c0fdc1bc15b87bb47dff4d895e32a9 Auto-Submitted: auto-generated ARC-Message-Signature: i=1; a=rsa-sha256; c=relaxed/relaxed; d=freebsd.org; s=dkim; t=1645489041; h=from:from:reply-to:subject:subject:date:date:message-id:message-id: to:to:cc:mime-version:mime-version:content-type:content-type: content-transfer-encoding:content-transfer-encoding; bh=FAdnz36aK8+vyTljgG3qfVZG6HV6YzlAvuxNJ5SnrtM=; b=WtcOcmf4d/F+r7CjGfhf2kEM5MAE6w9D+O3Xes055Zbu6NhAGwursFb/hAMDqNkh4dXG1r aJSevEPO33KC1I/5rRy4VXqySbkouxbE4vAdtNpCgXUrN/ZaVjvde6VpRwPaRuiCphQAFf XW39J04OJrZl3fyXpXH1jwOSNq+zYESUWxaF0sBSkoiHwW8QjPIn/PyrH/mS4xmzMgLNgO TsuHfVIKSwIHTNfa9Yyt8+ewRDifVCXtakldgQIef3VvJPu2VvVvIp8bSe7Y+ETBOZtkBB KizntD1nRuuYQmATHSl+9gRA8pwRPr46Cy4S5nQHhcL5x+J6qDHtOgdnZzdgeQ== ARC-Seal: i=1; s=dkim; d=freebsd.org; t=1645489041; a=rsa-sha256; cv=none; b=kJ7EkLIWVc17L17ES7EDSgRP8Mb4eZnMqysVHWd/k1dfuUtuQi2WO7HwjHjCheDNny7vMv hkqvex0k0Jx0d86FoqY+b+gzkxS1asjMof/HOz9GDgwzm+kz00AKkBtQcTIYMG1H0DfTtU dNoM4zvwozvAMs7XAVUN0yJDkBvh6ifcWzP7CozaBmiL0mu3S4XbOyP8Zv0AyKxLuDxDl1 JahKnal0Q9ZTwmQVrzKJzW36j8BOhCX6t0ux0vE/mXhp7UrLNXvygY3MuDNRtifk/O1zZs +FhBfUIjtcAwYsc2Q3r4rt0T8lrTpLD79jsBQEnkicpzbJnHZkHyOGGb/cNT1w== ARC-Authentication-Results: i=1; mx1.freebsd.org; none X-ThisMailContainsUnwantedMimeParts: N The branch main has been updated by mhorne: URL: https://cgit.FreeBSD.org/src/commit/?id=7b0a665d72c0fdc1bc15b87bb47dff4d895e32a9 commit 7b0a665d72c0fdc1bc15b87bb47dff4d895e32a9 Author: Mitchell Horne AuthorDate: 2022-02-22 00:16:07 +0000 Commit: Mitchell Horne CommitDate: 2022-02-22 00:16:07 +0000 boottrace: annotate init and shutdown utilities Add boottrace annotations to record events in init(8), shutdown(8), and reboot(8). Sponsored by: NetApp, Inc. Sponsored by: Klara, Inc. X-NetApp-PR: #23 Differential Revision: https://reviews.freebsd.org/D31928 --- sbin/init/init.c | 84 ++++++++++++++++++++++++++++++++++++++++++++---- sbin/reboot/reboot.c | 10 ++++-- sbin/shutdown/shutdown.c | 19 +++++++++-- sys/sys/boottrace.h | 37 +++++++++++++++++++-- 4 files changed, 137 insertions(+), 13 deletions(-) diff --git a/sbin/init/init.c b/sbin/init/init.c index 230c141bd351..93a525c46427 100644 --- a/sbin/init/init.c +++ b/sbin/init/init.c @@ -47,21 +47,26 @@ static const char rcsid[] = #endif /* not lint */ #include +#include #include #include #include -#include -#include +#include #include +#include #include +#include #include +#include #include #include #include #include #include #include +#include +#include #include #include #include @@ -69,10 +74,6 @@ static const char rcsid[] = #include #include #include -#include -#include - -#include #ifdef SECURE #include @@ -213,6 +214,8 @@ main(int argc, char *argv[]) if (getuid() != 0) errx(1, "%s", strerror(EPERM)); + BOOTTRACE("init(8) starting..."); + /* System V users like to reexec init. */ if (getpid() != 1) { #ifdef COMPAT_SYSV_INIT @@ -876,6 +879,7 @@ single_user(void) if (Reboot) { /* Instead of going single user, let's reboot the machine */ + BOOTTRACE("shutting down the system"); sync(); /* Run scripts after all processes have been terminated. */ runfinal(); @@ -887,6 +891,7 @@ single_user(void) _exit(0); /* panic as well */ } + BOOTTRACE("going to single user mode"); shell = get_shell(); if ((pid = fork()) == 0) { @@ -1028,8 +1033,10 @@ runcom(void) { state_func_t next_transition; + BOOTTRACE("/etc/rc starting..."); if ((next_transition = run_script(_PATH_RUNCOM)) != NULL) return next_transition; + BOOTTRACE("/etc/rc finished"); runcom_mode = AUTOBOOT; /* the default */ return (state_func_t) read_ttys; @@ -1598,6 +1605,59 @@ collect_child(pid_t pid) add_session(sp); } +static const char * +get_current_state(void) +{ + + if (current_state == single_user) + return ("single-user"); + if (current_state == runcom) + return ("runcom"); + if (current_state == read_ttys) + return ("read-ttys"); + if (current_state == multi_user) + return ("multi-user"); + if (current_state == clean_ttys) + return ("clean-ttys"); + if (current_state == catatonia) + return ("catatonia"); + if (current_state == death) + return ("death"); + if (current_state == death_single) + return ("death-single"); + return ("unknown"); +} + +static void +boottrace_transition(int sig) +{ + const char *action; + + switch (sig) { + case SIGUSR2: + action = "halt & poweroff"; + break; + case SIGUSR1: + action = "halt"; + break; + case SIGINT: + action = "reboot"; + break; + case SIGWINCH: + action = "powercycle"; + break; + case SIGTERM: + action = Reboot ? "reboot" : "single-user"; + break; + default: + BOOTTRACE("signal %d from %s", sig, get_current_state()); + return; + } + + /* Trace the shutdown reason. */ + SHUTTRACE("%s from %s", action, get_current_state()); +} + /* * Catch a signal and request a state transition. */ @@ -1605,6 +1665,7 @@ static void transition_handler(int sig) { + boottrace_transition(sig); switch (sig) { case SIGHUP: if (current_state == read_ttys || current_state == multi_user || @@ -1648,6 +1709,7 @@ transition_handler(int sig) static state_func_t multi_user(void) { + static bool inmultiuser = false; pid_t pid; session_t *sp; @@ -1677,6 +1739,11 @@ multi_user(void) add_session(sp); } + if (requested_transition == 0 && !inmultiuser) { + inmultiuser = true; + /* This marks the change from boot-time tracing to run-time. */ + RUNTRACE("multi-user start"); + } while (!requested_transition) if ((pid = waitpid(-1, (int *) 0, 0)) != -1) collect_child(pid); @@ -1843,6 +1910,7 @@ death_single(void) revoke(_PATH_CONSOLE); + BOOTTRACE("start killing user processes"); for (i = 0; i < 2; ++i) { if (kill(-1, death_sigs[i]) == -1 && errno == ESRCH) return (state_func_t) single_user; @@ -1894,6 +1962,8 @@ runshutdown(void) char *argv[4]; struct stat sb; + BOOTTRACE("init(8): start rc.shutdown"); + /* * rc.shutdown is optional, so to prevent any unnecessary * complaints from the shell we simply don't run it if the @@ -1944,6 +2014,8 @@ runshutdown(void) kill(wpid, SIGTERM); warning("timeout expired for %s: %m; going to " "single user mode", _PATH_RUNDOWN); + BOOTTRACE("rc.shutdown's %d sec timeout expired", + shutdowntimeout); return -1; } if (wpid == -1) { diff --git a/sbin/reboot/reboot.c b/sbin/reboot/reboot.c index 4dcade7611c2..118ac304024c 100644 --- a/sbin/reboot/reboot.c +++ b/sbin/reboot/reboot.c @@ -43,10 +43,12 @@ static char sccsid[] = "@(#)reboot.c 8.1 (Berkeley) 6/5/93"; #include __FBSDID("$FreeBSD$"); -#include -#include #include +#include +#include #include +#include + #include #include #include @@ -210,10 +212,12 @@ main(int argc, char *argv[]) } /* Just stop init -- if we fail, we'll restart it. */ + BOOTTRACE("SIGTSTP to init(8)..."); if (kill(1, SIGTSTP) == -1) err(1, "SIGTSTP init"); /* Send a SIGTERM first, a chance to save the buffers. */ + BOOTTRACE("SIGTERM to all other processes..."); if (kill(-1, SIGTERM) == -1 && errno != ESRCH) err(1, "SIGTERM processes"); @@ -235,6 +239,7 @@ main(int argc, char *argv[]) } for (i = 1;; ++i) { + BOOTTRACE("SIGKILL to all other processes(%d)...", i); if (kill(-1, SIGKILL) == -1) { if (errno == ESRCH) break; @@ -252,6 +257,7 @@ main(int argc, char *argv[]) /* FALLTHROUGH */ restart: + BOOTTRACE("SIGHUP to init(8)..."); sverrno = errno; errx(1, "%s%s", kill(1, SIGHUP) == -1 ? "(can't restart init): " : "", strerror(sverrno)); diff --git a/sbin/shutdown/shutdown.c b/sbin/shutdown/shutdown.c index 67a433b8edde..76e02d1fd6b1 100644 --- a/sbin/shutdown/shutdown.c +++ b/sbin/shutdown/shutdown.c @@ -44,9 +44,10 @@ static char sccsid[] = "@(#)shutdown.c 8.4 (Berkeley) 4/28/95"; __FBSDID("$FreeBSD$"); #include -#include +#include #include #include +#include #include #include @@ -221,10 +222,13 @@ poweroff: } mbuflen = strlen(mbuf); - if (offset) + if (offset) { + BOOTTRACE("Shutdown at %s", ctime(&shuttime)); (void)printf("Shutdown at %.24s.\n", ctime(&shuttime)); - else + } else { + BOOTTRACE("Shutdown NOW!"); (void)printf("Shutdown NOW!\n"); + } if (!(whom = getlogin())) whom = (pw = getpwuid(getuid())) ? pw->pw_name : "???"; @@ -360,12 +364,16 @@ die_you_gravy_sucking_pig_dog(void) { char *empty_environ[] = { NULL }; + BOOTTRACE("%s by %s", + doreboot ? "reboot" : dohalt ? "halt" : dopower ? "power-down" : + docycle ? "power-cycle" : "shutdown", whom); syslog(LOG_NOTICE, "%s by %s: %s", doreboot ? "reboot" : dohalt ? "halt" : dopower ? "power-down" : docycle ? "power-cycle" : "shutdown", whom, mbuf); (void)printf("\r\nSystem shutdown time has arrived\007\007\r\n"); if (killflg) { + BOOTTRACE("fake shutdown..."); (void)printf("\rbut you'll have to do it yourself\r\n"); exit(0); } @@ -383,6 +391,7 @@ die_you_gravy_sucking_pig_dog(void) (void)printf("\nkill -HUP 1\n"); #else if (!oflag) { + BOOTTRACE("signal to init(8)..."); (void)kill(1, doreboot ? SIGINT : /* reboot */ dohalt ? SIGUSR1 : /* halt */ dopower ? SIGUSR2 : /* power-down */ @@ -390,6 +399,7 @@ die_you_gravy_sucking_pig_dog(void) SIGTERM); /* single-user */ } else { if (doreboot) { + BOOTTRACE("exec reboot(8) -l..."); execle(_PATH_REBOOT, "reboot", "-l", nosync, (char *)NULL, empty_environ); syslog(LOG_ERR, "shutdown: can't exec %s: %m.", @@ -397,6 +407,7 @@ die_you_gravy_sucking_pig_dog(void) warn(_PATH_REBOOT); } else if (dohalt) { + BOOTTRACE("exec halt(8) -l..."); execle(_PATH_HALT, "halt", "-l", nosync, (char *)NULL, empty_environ); syslog(LOG_ERR, "shutdown: can't exec %s: %m.", @@ -404,6 +415,7 @@ die_you_gravy_sucking_pig_dog(void) warn(_PATH_HALT); } else if (dopower) { + BOOTTRACE("exec halt(8) -l -p..."); execle(_PATH_HALT, "halt", "-l", "-p", nosync, (char *)NULL, empty_environ); syslog(LOG_ERR, "shutdown: can't exec %s: %m.", @@ -417,6 +429,7 @@ die_you_gravy_sucking_pig_dog(void) _PATH_HALT); warn(_PATH_HALT); } + BOOTTRACE("SIGTERM to init(8)..."); (void)kill(1, SIGTERM); /* to single-user */ } #endif diff --git a/sys/sys/boottrace.h b/sys/sys/boottrace.h index b09888bff4ac..2cb17c15ff0f 100644 --- a/sys/sys/boottrace.h +++ b/sys/sys/boottrace.h @@ -36,9 +36,42 @@ #define BT_EVENT_NAMELEN 40 #define BT_MSGLEN (BT_EVENT_NAMELEN + 1 + BT_EVENT_TDNAMELEN) -#ifdef _KERNEL +#ifndef _KERNEL +#include +#include +#include +#include + +/* + * Convenience macros. Userland API. + */ +#define BOOTTRACE(...) _boottrace(_BOOTTRACE_BOOTTRACE, __VA_ARGS__) +#define RUNTRACE(...) _boottrace(_BOOTTRACE_RUNTRACE, __VA_ARGS__) +#define SHUTTRACE(...) _boottrace(_BOOTTRACE_SHUTTRACE, __VA_ARGS__) + +/* + * Call the requested boottrace sysctl with provided va-formatted message. + */ +static __inline void +_boottrace(const char *sysctlname, const char *fmt, ...) +{ + va_list ap; + char msg[BT_MSGLEN]; + int len; + + va_start(ap, fmt); + len = vsnprintf(msg, sizeof(msg), fmt, ap); + va_end(ap); + + /* Log the event, even if truncated. */ + if (len >= 0) + (void)sysctlbyname(sysctlname, NULL, NULL, msg, strlen(msg)); +} + +#else /* _KERNEL */ + /* - * Convenience macros. + * Convenience macros. Kernel API. */ #define _BOOTTRACE(tdname, ...) do { \ if (boottrace_enabled) \