rework log handling slightly

cmd/vinegar/binary.go

@@ -11,7 +11,6 @@ import (
 	"path/filepath"
 	"strings"
 	"syscall"
-	"time"
 
 	bsrpc "github.com/vinegarhq/vinegar/bloxstraprpc"
 	"github.com/vinegarhq/vinegar/internal/config"
@@ -30,8 +29,6 @@ const (
 	DialogInternalBrowserBrokenTitle = "WebView/InternalBrowser is broken"
 	DialogUseBrowserMsg              = "Use the browser for whatever you were doing just now."
 	DialogQuickLoginMsg              = "Use Quick Log In to authenticate ('Log In With Another Device' button)"
-	RobloxLogShutdownEntry           = "[FLog::SingleSurfaceApp] shutDown:"
-	RobloxLogAbsoluteExitEntry       = "[FLog::SingleSurfaceApp] unregisterMemoryPrioritizationCallback"
 )
 
 type Binary struct {
@@ -49,12 +46,10 @@ type Binary struct {
 
 	// Logging
 	Auth     bool
-	Exited   chan bool
 	Activity bsrpc.Activity
-	Output   io.Writer
 }
 
-func NewBinary(bt roblox.BinaryType, out io.Writer, cfg *config.Config, pfx *wine.Prefix) Binary {
+func NewBinary(bt roblox.BinaryType, cfg *config.Config, pfx *wine.Prefix) Binary {
 	var bcfg config.Binary
 
 	switch bt {
@@ -74,13 +69,20 @@ func NewBinary(bt roblox.BinaryType, out io.Writer, cfg *config.Config, pfx *win
 		Name:   bt.BinaryName(),
 		Type:   bt,
 		Prefix: pfx,
-
-		Output: out,
-		Exited: make(chan bool, 1),
 	}
 }
 
 func (b *Binary) Run(args ...string) error {
+	if b.Config.DiscordRPC {
+		if err := bsrpc.Login(); err != nil {
+			log.Printf("Failed to authenticate Discord RPC: %s, disabling RPC", err)
+			b.Config.DiscordRPC = false
+		}
+
+		// NOTE: This will panic if logout fails
+		defer bsrpc.Logout()
+	}
+
 	// REQUIRED for HandleRobloxLog to function.
 	os.Setenv("WINEDEBUG", os.Getenv("WINEDEBUG")+",warn+debugstr")
 
@@ -93,68 +95,27 @@ func (b *Binary) Run(args ...string) error {
 		return err
 	}
 
-	log.Printf("Launching %s", b.Name)
-	b.Splash.Message("Launching " + b.Alias)
-
-	// Launches into foreground
-	if err := cmd.Start(); err != nil {
-		return err
-	}
-
 	// Act as the signal holder, as roblox/wine will not do anything with the INT signal.
 	// Additionally, if Vinegar got TERM, it will also immediately exit, but roblox
 	// continues running.
 	c := make(chan os.Signal, 1)
 	signal.Notify(c, os.Interrupt, syscall.SIGTERM)
-
 	go func() {
 		<-c
 		log.Println("Killing Roblox")
-		// This way, cmd.Wait() will return and the wineprefix killer will be ran.
+		// This way, cmd.Run() will return and the wineprefix killer will be ran.
 		cmd.Process.Kill()
 		// Don't handle INT after it was recieved, this way if another signal was sent,
 		// Vinegar will immediately exit.
 		signal.Stop(c)
 	}()
 
-	// This is for cases where Roblox itself does not exit by itself, which
-	// happens sometimes (#173).
-	go func() {
-		// Gets sent by the log handler
-		<-b.Exited
-		log.Println("Got Roblox shutdown")
-		// Give roblox two seconds to cleanup its garbage
-		time.Sleep(2 * time.Second)
-		// Send a signal to the signal holder to kill the wine process
-		c <- syscall.SIGINT
-	}()
+	go b.HandleOutput(o)
 
-	if b.Config.DiscordRPC {
-		if err := bsrpc.Login(); err != nil {
-			log.Printf("Failed to authenticate Discord RPC: %s, disabling RPC", err)
-			b.Config.DiscordRPC = false
-		}
-
-		// NOTE: This will panic if logout fails
-		defer bsrpc.Logout()
-	}
-
-	// Log handler, this *should* return once the output reader of the
-	// Wine/Roblox process is closed, indicating that it has exited.
-	// r := io.TeeReader(o, b.Output)
-	// This ^ can alternatively be used to achieve both parsing of Wine+Roblox logs
-	// while also sending it to the log output, but debugstr from Wine
-	// should be ignored for a cleaner log output, which by itself should only
-	// be used for HandleRobloxLog(), which is also sent to the log output...
-	// Although, there may be some wine logs AFTER wine exits, which is why
-	// this function only returns once there is nothing to read. Only downside
-	// to that is this the command will take some time to flush and close the
-	// output pipes.
-	if err := b.HandleWineLog(o); err != nil {
-		return err
-	}
+	log.Printf("Launching %s", b.Name)
+	b.Splash.Message("Launching " + b.Alias)
 
-	if err := cmd.Wait(); err != nil {
+	if err := cmd.Run(); err != nil {
 		return fmt.Errorf("roblox process: %w", err)
 	}
 
@@ -170,7 +131,7 @@ func (b *Binary) Run(args ...string) error {
 	return nil
 }
 
-func (b *Binary) HandleWineLog(wr io.Reader) error {
+func (b *Binary) HandleOutput(wr io.Reader) {
 	s := bufio.NewScanner(wr)
 	for s.Scan() {
 		txt := s.Text()
@@ -184,10 +145,8 @@ func (b *Binary) HandleWineLog(wr io.Reader) error {
 			continue
 		}
 
-		fmt.Fprintln(b.Output, txt)
+		fmt.Fprintln(b.Prefix.Output, txt)
 	}
-
-	return s.Err()
 }
 
 func (b *Binary) HandleRobloxLog(line string) {
@@ -196,7 +155,7 @@ func (b *Binary) HandleRobloxLog(line string) {
 		b.Splash.Close()
 	}
 
-	fmt.Fprintln(b.Output, line)
+	fmt.Fprintln(b.Prefix.Output, line)
 
 	if strings.Contains(line, "DID_LOG_IN") {
 		b.Auth = true
@@ -213,11 +172,6 @@ func (b *Binary) HandleRobloxLog(line string) {
 		return
 	}
 
-	if strings.Contains(line, RobloxLogShutdownEntry) {
-		b.Exited <- true
-		return
-	}
-
 	if b.Config.DiscordRPC {
 		if err := b.Activity.HandleRobloxLog(line); err != nil {
 			log.Printf("Failed to handle Discord RPC: %s", err)
@@ -431,7 +385,7 @@ func (b *Binary) Command(args ...string) (*wine.Cmd, error) {
 		mutexer := b.Prefix.Command("wine", filepath.Join(BinPrefix, "robloxmutexer.exe"))
 		err := mutexer.Start()
 		if err != nil {
-			return &wine.Cmd{}, err
+			return &wine.Cmd{}, fmt.Errorf("robloxmutexer: %w")
 		}
 	}
 
@@ -441,6 +395,7 @@ func (b *Binary) Command(args ...string) (*wine.Cmd, error) {
 	if len(launcher) >= 1 {
 		cmd.Args = append(launcher, cmd.Args...)
 
+		// For safety, ensure that the launcher is in PATH
 		launcherPath, err := exec.LookPath(launcher[0])
 		if err != nil {
 			return &wine.Cmd{}, err

cmd/vinegar/vinegar.go

@@ -53,7 +53,7 @@ func main() {
 			log.Fatal(err)
 		}
 
-		pfx := wine.New(dirs.Prefix)
+		pfx := wine.New(dirs.Prefix, os.Stderr)
 		// Always ensure its created, wine will complain if the root
 		// directory doesnt exist
 		if err := os.MkdirAll(dirs.Prefix, 0o755); err != nil {
@@ -84,16 +84,16 @@ func main() {
 
 			logFile := logs.File(cmd)
 			logOutput := io.MultiWriter(logFile, os.Stderr)
-			b.Output = logOutput
+			pfx.Output = logOutput
 			log.SetOutput(logOutput)
 
 			defer logFile.Close()
 
 			switch cmd {
 			case "player":
-				b = NewBinary(roblox.Player, logOutput, &cfg, &pfx)
+				b = NewBinary(roblox.Player, &cfg, &pfx)
 			case "studio":
-				b = NewBinary(roblox.Studio, logOutput, &cfg, &pfx)
+				b = NewBinary(roblox.Studio, &cfg, &pfx)
 			}
 
 			go func() {
@@ -145,7 +145,7 @@ func PrefixInit(pfx *wine.Prefix) error {
 		return err
 	}
 
-	return pfx.RegistryAdd("HKEY_CURRENT_USER\\Control Panel\\Desktop", "LogPixels", wine.REG_DWORD, "97")
+	return pfx.SetDPI(97)
 }
 
 func Uninstall() {

internal/logs/logs.go

@@ -20,8 +20,8 @@ func File(name string) *os.File {
 
 	file, err := os.Create(path)
 	if err != nil {
-		log.Printf("Failed to create %s log file: %s", name, err)
-		return nil
+		log.Printf("Failed to create %s log file: %s, using Stderr", name, err)
+		return os.Stderr
 	}
 
 	log.Printf("Logging to file: %s", path)

wine/exec.go → wine/cmd.go

@@ -2,6 +2,7 @@ package wine
 
 import (
 	"errors"
+	"os"
 	"io"
 	"log"
 	"os/exec"
@@ -11,28 +12,37 @@ type Cmd struct {
 	*exec.Cmd
 }
 
+// Command returns a passthrough Cmd struct to execute the named
+// program with the given arguments.
+// The command's Stderr and Stdout will be set to their os counterparts
+// if the prefix's Output is nil.
 func (p *Prefix) Command(name string, arg ...string) *Cmd {
 	cmd := exec.Command(name, arg...)
+
+	cmd.Stdout = os.Stdout
+	cmd.Stderr = os.Stderr
+	if p.Output != nil {
+		cmd.Stdout = p.Output
+		cmd.Stderr = p.Output
+	}
+
 	cmd.Env = append(cmd.Environ(),
 		"WINEPREFIX="+p.dir,
 	)
 
 	return &Cmd{cmd}
 }
 
-func (c *Cmd) SetOutput(w io.Writer) error {
-	if c.Process != nil {
-		return errors.New("SetOutput after process started")
-	}
-	c.Stderr = w
-	c.Stdout = w
-	return nil
-}
-
+// OutputPipe erturns a pipe that will be a MultiReader
+// of StderrPipe and StdoutPipe, it will set both Stdout
+// and Stderr to nil once ran.
 func (c *Cmd) OutputPipe() (io.Reader, error) {
-	if err := c.SetOutput(nil); err != nil {
-		return nil, err
+	if c.Process != nil {
+		return nil, errors.New("OutputPipe after process started")
 	}
+
+	c.Stdout = nil
+	c.Stderr = nil
 
 	e, err := c.StderrPipe()
 	if err != nil {

wine/prefix.go

@@ -1,15 +1,22 @@
 package wine
 
 import (
+	"io"
 	"log"
 )
 
 type Prefix struct {
+	// Output specifies the descendant prefix commmand's
+	// Stderr and Stdout together.
+	Output io.Writer
+
 	dir string
 }
 
-func New(dir string) Prefix {
+
+func New(dir string, out io.Writer) Prefix {
 	return Prefix{
+		Output: out,
 		dir: dir,
 	}
 }

wine/tricks.go

@@ -2,6 +2,7 @@ package wine
 
 import (
 	"log"
+	"strconv"
 )
 
 func (p *Prefix) DisableCrashDialogs() error {
@@ -15,3 +16,7 @@ func (p *Prefix) Winetricks() error {
 
 	return p.Command("winetricks").Run()
 }
+
+func (p *Prefix) SetDPI(dpi int) error {
+	return p.RegistryAdd("HKEY_CURRENT_USER\\Control Panel\\Desktop", "LogPixels", REG_DWORD, strconv.Itoa(dpi))
+}