fmsg: implement suspend in writer

This removes the requirement to call fmsg.Exit on every exit path, and enables direct use of the "log" package. However, fmsg.BeforeExit is still encouraged when possible to catch exit on suspended output.

Signed-off-by: Ophestra <cat@gensokyo.uk>

internal/app/init/early.go

@@ -4,7 +4,7 @@ import (
 	"os"
 	"path"
 
-	"git.gensokyo.uk/security/fortify/internal/fmsg"
+	"git.gensokyo.uk/security/fortify/internal"
 )
 
 // used by the parent process
@@ -13,6 +13,6 @@ import (
 func TryArgv0() {
 	if len(os.Args) > 0 && path.Base(os.Args[0]) == "init" {
 		Main()
-		fmsg.Exit(0)
+		internal.Exit(0)
 	}
 }

internal/app/init/main.go

@@ -2,6 +2,7 @@ package init0
 
 import (
 	"errors"
+	"log"
 	"os"
 	"os/exec"
 	"os/signal"
@@ -24,17 +25,15 @@ const (
 func Main() {
 	// sharing stdout with shim
 	// USE WITH CAUTION
-	fmsg.SetPrefix("init")
+	fmsg.Prepare("init")
 
 	// setting this prevents ptrace
 	if err := internal.PR_SET_DUMPABLE__SUID_DUMP_DISABLE(); err != nil {
-		fmsg.Fatalf("cannot set SUID_DUMP_DISABLE: %s", err)
-		panic("unreachable")
+		log.Fatalf("cannot set SUID_DUMP_DISABLE: %s", err)
 	}
 
 	if os.Getpid() != 1 {
-		fmsg.Fatal("this process must run as pid 1")
-		panic("unreachable")
+		log.Fatal("this process must run as pid 1")
 	}
 
 	// receive setup payload
@@ -44,30 +43,29 @@ func Main() {
 	)
 	if f, err := proc.Receive(Env, &payload); err != nil {
 		if errors.Is(err, proc.ErrInvalid) {
-			fmsg.Fatal("invalid config descriptor")
+			log.Fatal("invalid config descriptor")
 		}
 		if errors.Is(err, proc.ErrNotSet) {
-			fmsg.Fatal("FORTIFY_INIT not set")
+			log.Fatal("FORTIFY_INIT not set")
 		}
 
-		fmsg.Fatalf("cannot decode init setup payload: %v", err)
-		panic("unreachable")
+		log.Fatalf("cannot decode init setup payload: %v", err)
 	} else {
-		fmsg.SetVerbose(payload.Verbose)
+		fmsg.Store(payload.Verbose)
 		closeSetup = f
 
 		// child does not need to see this
 		if err = os.Unsetenv(Env); err != nil {
-			fmsg.Printf("cannot unset %s: %v", Env, err)
+			log.Printf("cannot unset %s: %v", Env, err)
 			// not fatal
 		} else {
-			fmsg.VPrintln("received configuration")
+			fmsg.Verbose("received configuration")
 		}
 	}
 
 	// die with parent
 	if err := internal.PR_SET_PDEATHSIG__SIGKILL(); err != nil {
-		fmsg.Fatalf("prctl(PR_SET_PDEATHSIG, SIGKILL): %v", err)
+		log.Fatalf("prctl(PR_SET_PDEATHSIG, SIGKILL): %v", err)
 	}
 
 	cmd := exec.Command(payload.Argv0)
@@ -76,13 +74,13 @@ func Main() {
 	cmd.Env = os.Environ()
 
 	if err := cmd.Start(); err != nil {
-		fmsg.Fatalf("cannot start %q: %v", payload.Argv0, err)
+		log.Fatalf("cannot start %q: %v", payload.Argv0, err)
 	}
 	fmsg.Suspend()
 
 	// close setup pipe as setup is now complete
 	if err := closeSetup(); err != nil {
-		fmsg.Println("cannot close setup pipe:", err)
+		log.Println("cannot close setup pipe:", err)
 		// not fatal
 	}
 
@@ -119,7 +117,7 @@ func Main() {
 			}
 		}
 		if !errors.Is(err, syscall.ECHILD) {
-			fmsg.Println("unexpected wait4 response:", err)
+			log.Println("unexpected wait4 response:", err)
 		}
 
 		close(done)
@@ -132,9 +130,12 @@ func Main() {
 	for {
 		select {
 		case s := <-sig:
-			fmsg.VPrintln("received", s.String())
-			fmsg.Resume() // output could still be withheld at this point, so resume is called
-			fmsg.Exit(0)
+			if fmsg.Resume() {
+				fmsg.Verbosef("terminating on %s after process start", s.String())
+			} else {
+				fmsg.Verbosef("terminating on %s", s.String())
+			}
+			internal.Exit(0)
 		case w := <-info:
 			if w.wpid == cmd.Process.Pid {
 				// initial process exited, output is most likely available again
@@ -155,10 +156,10 @@ func Main() {
 				}()
 			}
 		case <-done:
-			fmsg.Exit(r)
+			internal.Exit(r)
 		case <-timeout:
-			fmsg.Println("timeout exceeded waiting for lingering processes")
-			fmsg.Exit(r)
+			log.Println("timeout exceeded waiting for lingering processes")
+			internal.Exit(r)
 		}
 	}
 }

internal/app/seal.go

@@ -191,7 +191,7 @@ func (a *app) Seal(config *fst.Config) error {
 
 	// map sandbox config to bwrap
 	if config.Confinement.Sandbox == nil {
-		fmsg.VPrintln("sandbox configuration not supplied, PROCEED WITH CAUTION")
+		fmsg.Verbose("sandbox configuration not supplied, PROCEED WITH CAUTION")
 
 		// permissive defaults
 		conf := &fst.SandboxConfig{
@@ -264,7 +264,7 @@ func (a *app) Seal(config *fst.Config) error {
 	}
 
 	// verbose log seal information
-	fmsg.VPrintf("created application seal for uid %s (%s) groups: %v, command: %s",
+	fmsg.Verbosef("created application seal for uid %s (%s) groups: %v, command: %s",
 		seal.sys.user.us, seal.sys.user.username, config.Confinement.Groups, config.Command)
 
 	// seal app and release lock

internal/app/share.go

@@ -143,7 +143,7 @@ func (seal *appSeal) setupShares(bus [2]*dbus.Config, os linux.System) error {
 	if seal.et.Has(system.EWayland) {
 		var socketPath string
 		if name, ok := os.LookupEnv(wl.WaylandDisplay); !ok {
-			fmsg.VPrintln(wl.WaylandDisplay + " is not set, assuming " + wl.FallbackName)
+			fmsg.Verbose(wl.WaylandDisplay + " is not set, assuming " + wl.FallbackName)
 			socketPath = path.Join(seal.RuntimePath, wl.FallbackName)
 		} else if !path.IsAbs(name) {
 			socketPath = path.Join(seal.RuntimePath, name)
@@ -166,7 +166,7 @@ func (seal *appSeal) setupShares(bus [2]*dbus.Config, os linux.System) error {
 			seal.sys.Wayland(outerPath, socketPath, appID, seal.id)
 			seal.sys.bwrap.Bind(outerPath, innerPath)
 		} else { // bind mount wayland socket (insecure)
-			fmsg.VPrintln("direct wayland access, PROCEED WITH CAUTION")
+			fmsg.Verbose("direct wayland access, PROCEED WITH CAUTION")
 			seal.sys.bwrap.Bind(socketPath, innerPath)
 
 			// ensure Wayland socket ACL (e.g. `/run/user/%d/wayland-%d`)
@@ -229,7 +229,7 @@ func (seal *appSeal) setupShares(bus [2]*dbus.Config, os linux.System) error {
 		// publish current user's pulse cookie for target user
 		if src, err := discoverPulseCookie(os); err != nil {
 			// not fatal
-			fmsg.VPrintln(strings.TrimSpace(err.(*fmsg.BaseError).Message()))
+			fmsg.Verbose(strings.TrimSpace(err.(*fmsg.BaseError).Message()))
 		} else {
 			dst := path.Join(seal.share, "pulse-cookie")
 			innerDst := fst.Tmp + "/pulse-cookie"

internal/app/shim/main.go

@@ -3,6 +3,7 @@ package shim
 import (
 	"context"
 	"errors"
+	"log"
 	"os"
 	"os/exec"
 	"os/signal"
@@ -25,12 +26,11 @@ import (
 func Main() {
 	// sharing stdout with fortify
 	// USE WITH CAUTION
-	fmsg.SetPrefix("shim")
+	fmsg.Prepare("shim")
 
 	// setting this prevents ptrace
 	if err := internal.PR_SET_DUMPABLE__SUID_DUMP_DISABLE(); err != nil {
-		fmsg.Fatalf("cannot set SUID_DUMP_DISABLE: %s", err)
-		panic("unreachable")
+		log.Fatalf("cannot set SUID_DUMP_DISABLE: %s", err)
 	}
 
 	// receive setup payload
@@ -40,21 +40,20 @@ func Main() {
 	)
 	if f, err := proc.Receive(Env, &payload); err != nil {
 		if errors.Is(err, proc.ErrInvalid) {
-			fmsg.Fatal("invalid config descriptor")
+			log.Fatal("invalid config descriptor")
 		}
 		if errors.Is(err, proc.ErrNotSet) {
-			fmsg.Fatal("FORTIFY_SHIM not set")
+			log.Fatal("FORTIFY_SHIM not set")
 		}
 
-		fmsg.Fatalf("cannot decode shim setup payload: %v", err)
-		panic("unreachable")
+		log.Fatalf("cannot decode shim setup payload: %v", err)
 	} else {
-		fmsg.SetVerbose(payload.Verbose)
+		fmsg.Store(payload.Verbose)
 		closeSetup = f
 	}
 
 	if payload.Bwrap == nil {
-		fmsg.Fatal("bwrap config not supplied")
+		log.Fatal("bwrap config not supplied")
 	}
 
 	// restore bwrap sync fd
@@ -65,7 +64,7 @@ func Main() {
 
 	// close setup socket
 	if err := closeSetup(); err != nil {
-		fmsg.Println("cannot close setup pipe:", err)
+		log.Println("cannot close setup pipe:", err)
 		// not fatal
 	}
 
@@ -73,15 +72,15 @@ func Main() {
 	if s, err := os.Stat(payload.Home); err != nil {
 		if os.IsNotExist(err) {
 			if err = os.Mkdir(payload.Home, 0700); err != nil {
-				fmsg.Fatalf("cannot create home directory: %v", err)
+				log.Fatalf("cannot create home directory: %v", err)
 			}
 		} else {
-			fmsg.Fatalf("cannot access home directory: %v", err)
+			log.Fatalf("cannot access home directory: %v", err)
 		}
 
 		// home directory is created, proceed
 	} else if !s.IsDir() {
-		fmsg.Fatalf("data path %q is not a directory", payload.Home)
+		log.Fatalf("data path %q is not a directory", payload.Home)
 	}
 
 	var ic init0.Payload
@@ -95,10 +94,10 @@ func Main() {
 		// no argv, look up shell instead
 		var ok bool
 		if payload.Bwrap.SetEnv == nil {
-			fmsg.Fatal("no command was specified and environment is unset")
+			log.Fatal("no command was specified and environment is unset")
 		}
 		if ic.Argv0, ok = payload.Bwrap.SetEnv["SHELL"]; !ok {
-			fmsg.Fatal("no command was specified and $SHELL was unset")
+			log.Fatal("no command was specified and $SHELL was unset")
 		}
 
 		ic.Argv = []string{ic.Argv0}
@@ -110,20 +109,20 @@ func Main() {
 
 	// serve setup payload
 	if fd, encoder, err := proc.Setup(&extraFiles); err != nil {
-		fmsg.Fatalf("cannot pipe: %v", err)
+		log.Fatalf("cannot pipe: %v", err)
 	} else {
 		conf.SetEnv[init0.Env] = strconv.Itoa(fd)
 		go func() {
-			fmsg.VPrintln("transmitting config to init")
+			fmsg.Verbose("transmitting config to init")
 			if err = encoder.Encode(&ic); err != nil {
-				fmsg.Fatalf("cannot transmit init config: %v", err)
+				log.Fatalf("cannot transmit init config: %v", err)
 			}
 		}()
 	}
 
 	helper.BubblewrapName = payload.Exec[0] // resolved bwrap path by parent
-	if fmsg.Verbose() {
-		seccomp.CPrintln = fmsg.Println
+	if fmsg.Load() {
+		seccomp.CPrintln = log.Println
 	}
 	if b, err := helper.NewBwrap(
 		conf, path.Join(fst.Tmp, "sbin/init"),
@@ -131,7 +130,7 @@ func Main() {
 		extraFiles,
 		syncFd,
 	); err != nil {
-		fmsg.Fatalf("malformed sandbox config: %v", err)
+		log.Fatalf("malformed sandbox config: %v", err)
 	} else {
 		b.Stdin(os.Stdin).Stdout(os.Stdout).Stderr(os.Stderr)
 		ctx, stop := signal.NotifyContext(context.Background(), os.Interrupt, syscall.SIGTERM)
@@ -139,15 +138,15 @@ func Main() {
 
 		// run and pass through exit code
 		if err = b.Start(ctx, false); err != nil {
-			fmsg.Fatalf("cannot start target process: %v", err)
+			log.Fatalf("cannot start target process: %v", err)
 		} else if err = b.Wait(); err != nil {
 			var exitError *exec.ExitError
 			if !errors.As(err, &exitError) {
-				fmsg.Println("wait:", err)
-				fmsg.Exit(127)
+				log.Printf("wait: %v", err)
+				internal.Exit(127)
 				panic("unreachable")
 			}
-			fmsg.Exit(exitError.ExitCode())
+			internal.Exit(exitError.ExitCode())
 			panic("unreachable")
 		}
 	}

internal/app/shim/manager.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"encoding/gob"
 	"errors"
+	"log"
 	"os"
 	"os/exec"
 	"strconv"
@@ -54,8 +55,7 @@ func (s *Shim) Start(
 	// prepare user switcher invocation
 	var fsu string
 	if p, ok := internal.Path(internal.Fsu); !ok {
-		fmsg.Fatal("invalid fsu path, this copy of fortify is not compiled correctly")
-		panic("unreachable")
+		log.Fatal("invalid fsu path, this copy of fortify is not compiled correctly")
 	} else {
 		fsu = p
 	}
@@ -75,7 +75,7 @@ func (s *Shim) Start(
 
 	// format fsu supplementary groups
 	if len(supp) > 0 {
-		fmsg.VPrintf("attaching supplementary group ids %s", supp)
+		fmsg.Verbosef("attaching supplementary group ids %s", supp)
 		s.cmd.Env = append(s.cmd.Env, "FORTIFY_GROUPS="+strings.Join(supp, " "))
 	}
 	s.cmd.Stdin, s.cmd.Stdout, s.cmd.Stderr = os.Stdin, os.Stdout, os.Stderr
@@ -87,7 +87,7 @@ func (s *Shim) Start(
 		s.sync = &fd
 	}
 
-	fmsg.VPrintln("starting shim via fsu:", s.cmd)
+	fmsg.Verbose("starting shim via fsu:", s.cmd)
 	// withhold messages to stderr
 	fmsg.Suspend()
 	if err := s.cmd.Start(); err != nil {

internal/app/start.go

@@ -4,6 +4,7 @@ import (
 	"context"
 	"errors"
 	"fmt"
+	"log"
 	"os/exec"
 	"path/filepath"
 	"strings"
@@ -81,7 +82,7 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 			Bwrap: a.seal.sys.bwrap,
 			Home:  a.seal.sys.user.data,
 
-			Verbose: fmsg.Verbose(),
+			Verbose: fmsg.Load(),
 		}); err != nil {
 			return err
 		}
@@ -119,8 +120,8 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 		} else {
 			rs.ExitCode = a.shim.Unwrap().ProcessState.ExitCode()
 		}
-		if fmsg.Verbose() {
-			fmsg.VPrintf("process %d exited with exit code %d", a.shim.Unwrap().Process.Pid, rs.ExitCode)
+		if fmsg.Load() {
+			fmsg.Verbosef("process %d exited with exit code %d", a.shim.Unwrap().Process.Pid, rs.ExitCode)
 		}
 
 	// this is reached when a fault makes an already running shim impossible to continue execution
@@ -128,11 +129,11 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 	// the effects of this is similar to the alternative exit path and ensures shim death
 	case err := <-a.shim.WaitFallback():
 		rs.ExitCode = 255
-		fmsg.Printf("cannot terminate shim on faulted setup: %v", err)
+		log.Printf("cannot terminate shim on faulted setup: %v", err)
 
 	// alternative exit path relying on shim behaviour on monitor process exit
 	case <-ctx.Done():
-		fmsg.VPrintln("alternative exit path selected")
+		fmsg.Verbose("alternative exit path selected")
 	}
 
 	// child process exited, resume output
@@ -163,10 +164,10 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 			} else {
 				if l := len(states); l == 0 {
 					// cleanup globals as the final launcher
-					fmsg.VPrintln("no other launchers active, will clean up globals")
+					fmsg.Verbose("no other launchers active, will clean up globals")
 					ec.Set(system.User)
 				} else {
-					fmsg.VPrintf("found %d active launchers, cleaning up without globals", l)
+					fmsg.Verbosef("found %d active launchers, cleaning up without globals", l)
 				}
 
 				// accumulate capabilities of other launchers
@@ -174,7 +175,7 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 					if s.Config != nil {
 						*rt |= s.Config.Confinement.Enablements
 					} else {
-						fmsg.Printf("state entry %d does not contain config", i)
+						log.Printf("state entry %d does not contain config", i)
 					}
 				}
 			}
@@ -184,7 +185,7 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 					ec.Set(i)
 				}
 			}
-			if fmsg.Verbose() {
+			if fmsg.Load() {
 				labels := make([]string, 0, system.ELen+1)
 				for i := system.Enablement(0); i < system.Enablement(system.ELen+2); i++ {
 					if ec.Has(i) {
@@ -192,7 +193,7 @@ func (a *app) Run(ctx context.Context, rs *RunState) error {
 					}
 				}
 				if len(labels) > 0 {
-					fmsg.VPrintln("reverting operations labelled", strings.Join(labels, ", "))
+					fmsg.Verbose("reverting operations labelled", strings.Join(labels, ", "))
 				}
 			}