Platform tart:// improve logging / fix tool_cache (#61)

pkg/runner/run_context_darwin.go

@@ -64,7 +64,7 @@ func (rc *RunContext) startTartEnvironment() common.Executor {
 				SSHPassword: "admin",
 				Softnet:     query.Get("softnet") == "1",
 				Headless:    query.Get("headless") != "0",
-				AlwaysPull:  query.Get("pull") != "0",
+				AlwaysPull:  rc.Config.ForcePull,
 			},
 			Env: &tart.Env{
 				JobImage: platURI.Host + platURI.EscapedPath(),
@@ -72,6 +72,9 @@ func (rc *RunContext) startTartEnvironment() common.Executor {
 			},
 			Miscpath: miscpath,
 		}
+		if query.Has("pull") {
+			tenv.Config.AlwaysPull = query.Get("pull") != "0"
+		}
 		rc.JobContainer = tenv
 		if query.Has("sshusername") {
 			tenv.Config.SSHUsername = query.Get("sshusername")
@@ -85,14 +88,6 @@ func (rc *RunContext) startTartEnvironment() common.Executor {
 				rc.Env[fmt.Sprintf("RUNNER_%s", strings.ToUpper(k))] = v
 			}
 		}
-		// for _, env := range os.Environ() {
-		// 	if k, v, ok := strings.Cut(env, "="); ok {
-		// 		// don't override
-		// 		if _, ok := rc.Env[k]; !ok {
-		// 			rc.Env[k] = v
-		// 		}
-		// 	}
-		// }
 
 		return common.NewPipelineExecutor(
 			// rc.JobContainer.Remove(),

pkg/tart/config_darwin.go

@@ -1,9 +1,12 @@
 package tart
 
+import "io"
+
 type Config struct {
 	SSHUsername string
 	SSHPassword string
 	Softnet     bool
 	Headless    bool
 	AlwaysPull  bool
+	Writer      io.Writer
 }

pkg/tart/environment_darwin.go

@@ -4,14 +4,13 @@ import (
 	"context"
 	"fmt"
 	"io"
-	"log"
 	"os"
 	"path/filepath"
 	"strings"
 
-	"github.com/kballard/go-shellquote"
 	"github.com/actions-oss/act-cli/pkg/common"
 	"github.com/actions-oss/act-cli/pkg/container"
+	"github.com/kballard/go-shellquote"
 )
 
 type Environment struct {
@@ -24,20 +23,32 @@ type Environment struct {
 
 // "/Volumes/My Shared Files/act/"
 func (e *Environment) ToHostPath(path string) string {
-	actPath := filepath.Clean("/private/tmp/act/")
+	return e.translatePath(path, false)
-	altPath := filepath.Clean(path)
-	if strings.HasPrefix(altPath, actPath) {
-		return e.Miscpath + altPath[len(actPath):]
-	}
-	return altPath
 }
 
 func (e *Environment) ToContainerPath(path string) string {
 	path = e.HostEnvironment.ToContainerPath(path)
-	actPath := filepath.Clean(e.Miscpath)
+	return e.translatePath(path, true)
+}
+
+func (e *Environment) translatePath(path string, reverse bool) string {
+	mounts := map[string]string{
+		"/private/tmp/act":        e.Miscpath,
+		"/private/tmp/tool_cache": e.ToolCache,
+	}
 	altPath := filepath.Clean(path)
-	if strings.HasPrefix(altPath, actPath) {
+	for k, v := range mounts {
-		return "/private/tmp/act/" + altPath[len(actPath):]
+		if reverse {
+			v, k = k, v
+		}
+		actPath := filepath.Clean(k)
+		add := 0
+		if strings.HasPrefix(altPath, actPath+"/") {
+			add = 1
+		}
+		if altPath == actPath || add > 0 {
+			return filepath.Join(v, altPath[len(actPath)+add:])
+		}
 	}
 	return altPath
 }
@@ -71,8 +82,10 @@ func (e *Environment) start(ctx context.Context) error {
 
 	config := e.Config
 
+	config.Writer = e.StdOut
+
 	if config.AlwaysPull {
-		log.Printf("Pulling the latest version of %s...\n", actEnv.JobImage)
+		common.Logger(ctx).Infof("Pulling the latest version of %s...\n", actEnv.JobImage)
 		_, _, err := ExecWithEnv(ctx, nil,
 			"pull", actEnv.JobImage)
 		if err != nil {
@@ -80,26 +93,28 @@ func (e *Environment) start(ctx context.Context) error {
 		}
 	}
 
-	log.Println("Cloning and configuring a new VM...")
+	common.Logger(ctx).Info("Cloning and configuring a new VM...")
 	vm, err := CreateNewVM(ctx, *actEnv, 0, 0)
 	if err != nil {
 		_ = e.Stop(ctx)
 		return err
 	}
 	var customDirectoryMounts []string
-	_ = os.MkdirAll(e.Miscpath, 0666)
+	_ = os.MkdirAll(e.Miscpath, 0777)
+	_ = os.MkdirAll(e.ToolCache, 0777)
 	customDirectoryMounts = append(customDirectoryMounts, "act:"+e.Miscpath)
+	customDirectoryMounts = append(customDirectoryMounts, "tool_cache:"+e.ToolCache)
 	e.vm = vm
-	err = vm.Start(config, actEnv, customDirectoryMounts)
+	err = vm.Start(ctx, config, actEnv, customDirectoryMounts)
 	if err != nil {
 		_ = e.Stop(ctx)
 		return err
 	}
 
-	return e.execRaw(ctx, "ln -sf '/Volumes/My Shared Files/act' /private/tmp/act")
+	return e.execRaw(ctx, "ln -sf '/Volumes/My Shared Files/act' /private/tmp/act && ln -sf '/Volumes/My Shared Files/tool_cache' /private/tmp/tool_cache")
 }
 func (e *Environment) Stop(ctx context.Context) error {
-	log.Println("Stop VM?")
+	common.Logger(ctx).Debug("Preparing stopping VM")
 
 	actEnv := e.Env
 
@@ -110,12 +125,12 @@ func (e *Environment) Stop(ctx context.Context) error {
 		vm = ExistingVM(*actEnv)
 	}
 
-	if err := vm.Stop(); err != nil {
+	if err := vm.Stop(ctx); err != nil {
-		log.Printf("Failed to stop VM: %v", err)
+		common.Logger(ctx).Errorf("Failed to stop VM: %v", err)
 	}
 
-	if err := vm.Delete(); err != nil {
+	if err := vm.Delete(ctx); err != nil {
-		log.Printf("Failed to delete VM: %v", err)
+		common.Logger(ctx).Error("Failed to delete VM: %v", err)
 
 		return err
 	}
@@ -126,7 +141,7 @@ func (e *Environment) Stop(ctx context.Context) error {
 func (e *Environment) Remove() common.Executor {
 	return func(ctx context.Context) error {
 		_ = e.Stop(ctx)
-		log.Println("Remove VM?")
+		common.Logger(ctx).Debug("Stopped VM, removing...")
 		if e.CleanUp != nil {
 			e.CleanUp()
 		}
@@ -162,9 +177,6 @@ func (e *Environment) execRaw(ctx context.Context, script string) error {
 		vm = ExistingVM(*actEnv)
 	}
 
-	// Monitor "tart run" command's output so it's not silenced
-	go vm.MonitorTartRunOutput()
-
 	config := e.Config
 
 	ssh, err := vm.OpenSSH(ctx, config)
@@ -179,7 +191,7 @@ func (e *Environment) execRaw(ctx context.Context, script string) error {
 	}
 	defer session.Close()
 
-	os.Stdout.WriteString(script + "\n")
+	common.Logger(ctx).Debug(script)
 
 	session.Stdin = strings.NewReader(
 		script,

pkg/tart/vm_darwin.go

@@ -5,8 +5,6 @@ import (
 	"context"
 	"errors"
 	"fmt"
-	"io"
-	"log"
 	"net"
 	"os"
 	"os/exec"
@@ -14,8 +12,8 @@ import (
 	"strconv"
 	"strings"
 	"syscall"
-	"time"
 
+	"github.com/actions-oss/act-cli/pkg/common"
 	"github.com/avast/retry-go"
 	"golang.org/x/crypto/ssh"
 )
@@ -45,7 +43,7 @@ func CreateNewVM(
 	cpuOverride uint64,
 	memoryOverride uint64,
 ) (*VM, error) {
-	log.Print("CreateNewVM")
+	common.Logger(ctx).Debug("CreateNewVM")
 	vm := &VM{
 		id: actEnv.VirtualMachineID(),
 	}
@@ -85,7 +83,7 @@ func (vm *VM) cloneAndConfigure(
 	return nil
 }
 
-func (vm *VM) Start(config Config, _ *Env, customDirectoryMounts []string) error {
+func (vm *VM) Start(ctx context.Context, config Config, _ *Env, customDirectoryMounts []string) error {
 	os.Remove(vm.tartRunOutputPath())
 	var runArgs = []string{"run"}
 
@@ -103,22 +101,18 @@ func (vm *VM) Start(config Config, _ *Env, customDirectoryMounts []string) error
 
 	runArgs = append(runArgs, vm.id)
 
-	cmd := exec.Command(tartCommandName, runArgs...)
+	cmd := exec.CommandContext(ctx, tartCommandName, runArgs...)
 
-	outputFile, err := os.OpenFile(vm.tartRunOutputPath(), os.O_WRONLY|os.O_APPEND|os.O_CREATE, 0600)
+	common.Logger(ctx).Debug(strings.Join(runArgs, " "))
-	if err != nil {
-		return err
-	}
-	_, _ = outputFile.WriteString(strings.Join(runArgs, " ") + "\n")
 
-	cmd.Stdout = outputFile
+	cmd.Stdout = config.Writer
-	cmd.Stderr = outputFile
+	cmd.Stderr = config.Writer
 
 	cmd.SysProcAttr = &syscall.SysProcAttr{
 		Setsid: true,
 	}
 
-	err = cmd.Start()
+	err := cmd.Start()
 	if err != nil {
 		return err
 	}
@@ -126,33 +120,6 @@ func (vm *VM) Start(config Config, _ *Env, customDirectoryMounts []string) error
 	return nil
 }
 
-func (vm *VM) MonitorTartRunOutput() {
-	outputFile, err := os.Open(vm.tartRunOutputPath())
-	if err != nil {
-		fmt.Fprintf(os.Stderr, "Failed to open VM's output file, "+
-			"looks like the VM wasn't started in \"prepare\" step?\n")
-
-		return
-	}
-	defer func() {
-		_ = outputFile.Close()
-	}()
-
-	for {
-		n, err := io.Copy(os.Stdout, outputFile)
-		if err != nil {
-			fmt.Fprintf(os.Stderr, "Failed to display VM's output: %v\n", err)
-
-			break
-		}
-		if n == 0 {
-			time.Sleep(100 * time.Millisecond)
-
-			continue
-		}
-	}
-}
-
 func (vm *VM) OpenSSH(ctx context.Context, config Config) (*ssh.Client, error) {
 	ip, err := vm.IP(ctx)
 	if err != nil {
@@ -198,22 +165,22 @@ func (vm *VM) IP(ctx context.Context) (string, error) {
 	return strings.TrimSpace(stdout), nil
 }
 
-func (vm *VM) Stop() error {
+func (vm *VM) Stop(ctx context.Context) error {
-	log.Println("Stop VM REAL?")
+	common.Logger(ctx).Debug("Stop VM REAL?")
 	if vm.runcmd != nil {
-		log.Println("send sigint?")
+		common.Logger(ctx).Debug("send sigint")
 		_ = vm.runcmd.Process.Signal(os.Interrupt)
-		log.Println("wait?")
+		common.Logger(ctx).Debug("wait for cmd")
 		_ = vm.runcmd.Wait()
-		log.Println("wait done?")
+		common.Logger(ctx).Debug("cmd stopped")
 		return nil
 	}
-	_, _, err := Exec(context.Background(), "stop", vm.id)
+	_, _, err := Exec(ctx, "stop", vm.id)
 	return err
 }
 
-func (vm *VM) Delete() error {
+func (vm *VM) Delete(ctx context.Context) error {
-	_, _, err := Exec(context.Background(), "delete", vm.id)
+	_, _, err := Exec(ctx, "delete", vm.id)
 	if err != nil {
 		return fmt.Errorf("%w: failed to delete VM %s: %v", ErrVMFailed, vm.id, err)
 	}