X-Git-Url: http://www.git.cypherpunks.ru/?a=blobdiff_plain;f=run.go;h=8ea91d1eb9ca10d5789cd5cd9159c6c9aeb715f4;hb=HEAD;hp=40fad74af0f20f98dc517020faca88c86df57359;hpb=edb601644735972fac3efcdc27849b5b9b1f5fb7;p=goredo.git

diff --git a/run.go b/run.go
index 40fad74..8ea91d1 100644
--- a/run.go
+++ b/run.go
@@ -1,19 +1,17 @@
-/*
-goredo -- redo implementation on pure Go
-Copyright (C) 2020-2021 Sergey Matveev <stargrave@stargrave.org>
-
-This program is free software: you can redistribute it and/or modify
-it under the terms of the GNU General Public License as published by
-the Free Software Foundation, version 3 of the License.
-
-This program is distributed in the hope that it will be useful,
-but WITHOUT ANY WARRANTY; without even the implied warranty of
-MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
-GNU General Public License for more details.
-
-You should have received a copy of the GNU General Public License
-along with this program.  If not, see <http://www.gnu.org/licenses/>.
-*/
+// goredo -- djb's redo implementation on pure Go
+// Copyright (C) 2020-2024 Sergey Matveev <stargrave@stargrave.org>
+//
+// This program is free software: you can redistribute it and/or modify
+// it under the terms of the GNU General Public License as published by
+// the Free Software Foundation, version 3 of the License.
+//
+// This program is distributed in the hope that it will be useful,
+// but WITHOUT ANY WARRANTY; without even the implied warranty of
+// MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
+// GNU General Public License for more details.
+//
+// You should have received a copy of the GNU General Public License
+// along with this program.  If not, see <http://www.gnu.org/licenses/>.
 
 // Targets runner
 
@@ -21,128 +19,141 @@ package main
 
 import (
 	"bufio"
+	"crypto/rand"
+	"encoding/hex"
 	"errors"
 	"flag"
 	"fmt"
 	"io"
+	"io/fs"
+	"log"
 	"os"
 	"os/exec"
 	"path"
-	"path/filepath"
+	"strconv"
 	"strings"
 	"sync"
 	"syscall"
 	"time"
 
 	"go.cypherpunks.ru/recfile"
-	"go.cypherpunks.ru/tai64n"
+	"go.cypherpunks.ru/tai64n/v2"
 	"golang.org/x/sys/unix"
 )
 
 const (
 	EnvDepFd        = "REDO_DEP_FD"
 	EnvDirPrefix    = "REDO_DIRPREFIX"
+	EnvDepCwd       = "REDO_DEP_CWD"
 	EnvBuildUUID    = "REDO_BUILD_UUID"
 	EnvStderrPrefix = "REDO_STDERR_PREFIX"
 	EnvTrace        = "REDO_TRACE"
 	EnvStderrKeep   = "REDO_LOGS"
 	EnvStderrSilent = "REDO_SILENT"
 	EnvNoSync       = "REDO_NO_SYNC"
-
-	RedoDir    = ".redo"
-	LockSuffix = ".lock"
-	DepSuffix  = ".dep"
-	TmpPrefix  = ".redo."
-	LogSuffix  = ".log"
+	EnvStopIfMod    = "REDO_STOP_IF_MODIFIED"
+
+	RedoDir      = ".redo"
+	LockSuffix   = ".lock"
+	DepSuffix    = ".dep"
+	TmpPrefix    = ".redo."
+	LogSuffix    = ".log"
+	LogRecSuffix = ".log-rec"
 )
 
 var (
-	NoSync       bool = false
-	StderrKeep   bool = false
-	StderrSilent bool = false
+	NoSync       = false
+	StderrKeep   = false
+	StderrSilent = false
 	StderrPrefix string
+	StopIfMod    = false
 	Jobs         sync.WaitGroup
 
-	flagTrace        = flag.Bool("x", false, "trace (sh -x) current targets")
-	flagTraceAll     = flag.Bool("xx", false, fmt.Sprintf("trace (sh -x) all targets (%s=1)", EnvTrace))
-	flagStderrKeep   = flag.Bool("logs", false, fmt.Sprintf("keep job's stderr (%s=1)", EnvStderrKeep))
-	flagStderrSilent = flag.Bool("silent", false, fmt.Sprintf("do not print job's stderr (%s=1)", EnvStderrSilent))
+	flagTrace          *bool
+	flagTraceAll       *bool
+	flagStderrKeep     *bool
+	flagStderrSilent   *bool
+	flagForcedIfchange *bool
+
+	TracedAll bool
+
+	RunningProcs  = map[int]*os.Process{}
+	RunningProcsM sync.Mutex
+
+	Err1WasTouched = errors.New("$1 was explicitly touched")
 )
 
-type RunErr struct {
-	Tgt      string
+func init() {
+	cmdName := CmdName()
+	if !(cmdName == CmdNameRedo || cmdName == CmdNameRedoIfchange) {
+		return
+	}
+	flagTrace = flag.Bool("x", false, "trace (sh -x) current targets")
+	flagTraceAll = flag.Bool("xx", false,
+		fmt.Sprintf("trace (sh -x) all targets (%s=1)", EnvTrace))
+	flagStderrKeep = flag.Bool("k", false,
+		fmt.Sprintf("keep job's stderr (%s=1)", EnvStderrKeep))
+	flagStderrSilent = flag.Bool("s", false,
+		fmt.Sprintf("silent, do not print job's stderr (%s=1)", EnvStderrSilent))
+	flagForcedIfchange = flag.Bool("f", false, "forced redo-ifchange")
+}
+
+type RunError struct {
+	Tgt      *Tgt
 	DoFile   string
 	Started  *time.Time
 	Finished *time.Time
 	Err      error
 }
 
-func (e RunErr) Unwrap() error { return e.Err }
-
-func (e *RunErr) Name() string {
+func (e *RunError) Name() string {
 	var name string
 	if e.DoFile == "" {
-		name = e.Tgt
+		name = e.Tgt.rel
 	} else {
 		name = fmt.Sprintf("%s (%s)", e.Tgt, e.DoFile)
 	}
 	if e.Finished == nil {
 		return name
 	}
-	return fmt.Sprintf("%s (%fsec)", name, e.Finished.Sub(*e.Started).Seconds())
+	return fmt.Sprintf("%s (%.3fs)", name, e.Finished.Sub(*e.Started).Seconds())
 }
 
-func (e RunErr) Error() string {
+func (e RunError) Error() string {
 	return fmt.Sprintf("%s: %s", e.Name(), e.Err)
 }
 
 func mkdirs(pth string) error {
-	if _, err := os.Stat(pth); err == nil {
+	if FileExists(pth) {
 		return nil
 	}
 	return os.MkdirAll(pth, os.FileMode(0777))
 }
 
-func isModified(cwd, redoDir, tgt string) (bool, string, error) {
-	fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
-	if err != nil {
-		if os.IsNotExist(err) {
-			return false, "", nil
-		}
-		return false, "", err
+func isModified(dep *Dep, tgt *Tgt) (
+	modified bool, ourInode *Inode, hshPrev Hash, err error,
+) {
+	if dep == nil {
+		return
 	}
-	defer fdDep.Close()
-	r := recfile.NewReader(fdDep)
-	var ourTs string
-	for {
-		m, err := r.NextMap()
-		if err != nil {
-			if err == io.EOF {
-				break
-			}
-			return false, "", err
-		}
-		if m["Target"] != tgt {
+	for _, ifchange := range dep.ifchanges {
+		if ifchange.tgt.a != tgt.a {
 			continue
 		}
-		fd, err := os.Open(path.Join(cwd, tgt))
+		ourInode, err = inodeFromFileByPath(tgt.a)
 		if err != nil {
 			if os.IsNotExist(err) {
-				return false, "", nil
+				err = nil
+				return
 			}
-			return false, "", err
-		}
-		defer fd.Close()
-		ourTs, err = fileCtime(fd)
-		if err != nil {
-			return false, "", err
-		}
-		if ourTs != m["Ctime"] {
-			return true, ourTs, nil
+			err = ErrLine(err)
+			return
 		}
+		hshPrev = ifchange.Hash()
+		modified = !ourInode.Equals(ifchange.Inode())
 		break
 	}
-	return false, ourTs, nil
+	return
 }
 
 func syncDir(dir string) error {
@@ -155,190 +166,265 @@ func syncDir(dir string) error {
 	return err
 }
 
-func runScript(tgtOrig string, errs chan error, traced bool) error {
-	cwd, tgt := cwdAndTgt(tgtOrig)
-	redoDir := path.Join(cwd, RedoDir)
+func runScript(tgt *Tgt, errs chan error, forced, traced bool) error {
+	tgtH, tgtT := pathSplit(tgt.a)
+	redoDir := path.Join(tgtH, RedoDir)
 	if err := mkdirs(redoDir); err != nil {
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
 	}
 
+	shCtx := fmt.Sprintf("sh: %s: cwd:%s", tgt, tgtH)
+	jsToken := jsAcquire(shCtx)
+	jsNeedsRelease := true
+	defer func() {
+		if jsNeedsRelease {
+			jsRelease(shCtx, jsToken)
+		}
+	}()
+
 	// Acquire lock
 	fdLock, err := os.OpenFile(
-		path.Join(redoDir, tgt+LockSuffix),
+		path.Join(redoDir, tgtT+LockSuffix),
 		os.O_WRONLY|os.O_TRUNC|os.O_CREATE,
 		os.FileMode(0666),
 	)
 	if err != nil {
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
+	}
+	flock := unix.Flock_t{
+		Type:   unix.F_WRLCK,
+		Whence: io.SeekStart,
 	}
 	lockRelease := func() {
-		trace(CLock, "LOCK_UN: %s", fdLock.Name())
-		unix.Flock(int(fdLock.Fd()), unix.LOCK_UN)
+		tracef(CLock, "LOCK_UN: %s", fdLock.Name())
+		flock.Type = unix.F_UNLCK
+		if err := unix.FcntlFlock(fdLock.Fd(), unix.F_SETLK, &flock); err != nil {
+			log.Fatalln(err, fdLock.Name())
+		}
 		fdLock.Close()
 	}
-	trace(CLock, "LOCK_NB: %s", fdLock.Name())
+	tracef(CLock, "LOCK_NB: %s", fdLock.Name())
 
 	// Waiting for job completion, already taken by someone else
-	if err = unix.Flock(int(fdLock.Fd()), unix.LOCK_EX|unix.LOCK_NB); err != nil {
-		if uintptr(err.(syscall.Errno)) != uintptr(unix.EWOULDBLOCK) {
+	if err = unix.FcntlFlock(fdLock.Fd(), unix.F_SETLK, &flock); err != nil {
+		if uintptr(err.(syscall.Errno)) != uintptr(unix.EAGAIN) {
 			fdLock.Close()
-			return TgtErr{tgtOrig, err}
+			return TgtError{tgt, ErrLine(err)}
 		}
 		Jobs.Add(1)
-		trace(CDebug, "waiting: %s", tgtOrig)
+		if err = unix.FcntlFlock(fdLock.Fd(), unix.F_GETLK, &flock); err != nil {
+			log.Fatalln(err, fdLock.Name())
+		}
+		tracef(CDebug, "waiting: %s (pid=%d)", tgt, flock.Pid)
 		if FdStatus != nil {
-			FdStatus.Write([]byte{StatusWait})
+			if _, err = FdStatus.Write([]byte{StatusWait}); err != nil {
+				log.Fatal(err)
+			}
 		}
 		go func() {
 			defer Jobs.Done()
-			trace(CLock, "LOCK_EX: %s", fdLock.Name())
-			unix.Flock(int(fdLock.Fd()), unix.LOCK_EX)
+			tracef(CLock, "LOCK_EX: %s", fdLock.Name())
+		LockAgain:
+			if err := unix.FcntlFlock(fdLock.Fd(), unix.F_SETLKW, &flock); err != nil {
+				if errors.Is(err, unix.EDEADLK) {
+					time.Sleep(10 * time.Millisecond)
+					goto LockAgain
+				}
+				log.Fatalln(err, fdLock.Name())
+			}
 			lockRelease()
-			trace(CDebug, "waiting done: %s", tgtOrig)
+			tracef(CDebug, "waiting done: %s", tgt)
 			if FdStatus != nil {
-				FdStatus.Write([]byte{StatusWaited})
+				if _, err = FdStatus.Write([]byte{StatusWaited}); err != nil {
+					log.Fatal(err)
+				}
 			}
-			var depInfo *DepInfo
-			fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
-			if err != nil {
-				if os.IsNotExist(err) {
+			build, err := depBuildRead(tgt.dep)
+			if err == nil {
+				if build != BuildUUID {
+					err = errors.New("was not built: build differs")
+				}
+			} else {
+				if errors.Is(err, fs.ErrNotExist) {
 					err = errors.New("was not built: no .dep")
 				}
-				goto Finish
-			}
-			defer fdDep.Close()
-			depInfo, err = depRead(fdDep)
-			if err != nil {
-				goto Finish
-			}
-			if depInfo.build != BuildUUID {
-				err = errors.New("was not built: build differs")
 			}
-		Finish:
 			if err != nil {
-				err = TgtErr{tgtOrig, err}
+				err = TgtError{tgt, err}
 			}
 			errs <- err
 		}()
 		return nil
 	}
 
+	// It scans the whole .dep file while searching for the single target,
+	// but that one is always located at the very end
+	dep, err := depRead(tgt)
+	if err != nil {
+		if errors.Is(err, fs.ErrNotExist) {
+			err = nil
+		} else {
+			lockRelease()
+			return TgtError{tgt, ErrLine(err)}
+		}
+	}
+
+	// Check if it was already built in parallel
+	if !forced && dep != nil && dep.build == BuildUUID {
+		lockRelease()
+		errs <- nil
+		return nil
+	}
+
 	// Check if target is not modified externally
-	modified, tsPrev, err := isModified(cwd, redoDir, tgt)
+	modified, inodePrev, hshPrev, err := isModified(dep, tgt)
 	if err != nil {
 		lockRelease()
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
 	}
 	if modified {
-		trace(CWarn, "%s externally modified: not redoing", tgtOrig)
 		lockRelease()
+		if StopIfMod {
+			return fmt.Errorf("%s externally modified", tgt)
+		}
+		Jobs.Add(1)
+		tracef(CWarn, "%s externally modified: not redoing", tgt)
 		go func() {
 			errs <- nil
+			Jobs.Done()
 		}()
 		return nil
 	}
+	dep = nil
 
 	// Start preparing .dep
-	fdDep, err := tempfile(redoDir, tgt+DepSuffix)
+	fdDep, err := tempfile(redoDir, tgtT+DepSuffix)
 	if err != nil {
 		lockRelease()
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
 	}
+	fdDepOpened := true
+	fdDepExists := true
+	fdDepW := bufio.NewWriter(fdDep)
 	cleanup := func() {
 		lockRelease()
-		fdDep.Close()
-		os.Remove(fdDep.Name())
-	}
-	if _, err = recfile.NewWriter(fdDep).WriteFields(
-		recfile.Field{Name: "Build", Value: BuildUUID},
-	); err != nil {
-		cleanup()
-		return TgtErr{tgtOrig, err}
-	}
-
-	// Find .do
-	doFile, upLevels, err := findDo(fdDep, cwd, tgt)
-	if err != nil {
-		cleanup()
-		return TgtErr{tgtOrig, err}
+		if fdDepOpened {
+			fdDep.Close()
+		}
+		if fdDepExists {
+			os.Remove(fdDep.Name())
+		}
 	}
-	if doFile == "" {
+	if err = depBuildWrite(fdDepW, BuildUUID); err != nil {
 		cleanup()
-		return TgtErr{tgtOrig, errors.New("no .do found")}
+		return TgtError{tgt, ErrLine(err)}
 	}
 
+	var cwd string
+	var dirPrefix string
+	var doFile *Tgt
+	var doFileT string
+	basename := tgtT
+	runErr := RunError{Tgt: tgt}
 	// Determine basename and DIRPREFIX
-	ents := strings.Split(cwd, "/")
-	ents = ents[len(ents)-upLevels:]
-	dirPrefix := path.Join(ents...)
-	cwdOrig := cwd
-	for i := 0; i < upLevels; i++ {
-		cwd = path.Join(cwd, "..")
-	}
-	cwd = path.Clean(cwd)
-	doFilePath := path.Join(cwd, doFile)
-	basename := tgt
-	runErr := RunErr{Tgt: tgtOrig}
-	if strings.HasPrefix(doFile, "default.") {
-		basename = tgt[:len(tgt)-(len(doFile)-len("default.")-len(".do"))-1]
-		runErr.DoFile = doFile
+	{
+		doFileRelPath, upLevels, err := findDo(fdDepW, fdDep.Name(), tgtH, tgtT)
+		if err != nil {
+			cleanup()
+			return TgtError{tgt, ErrLine(err)}
+		}
+		if doFileRelPath == "" {
+			cleanup()
+			return TgtError{tgt, errors.New("no .do found")}
+		}
+		ents := strings.Split(tgtH, "/")
+		ents = ents[len(ents)-upLevels:]
+		dirPrefix = path.Join(ents...)
+		ups := make([]string, 0, upLevels+2)
+		ups = append(ups, tgtH)
+		for i := 0; i < upLevels; i++ {
+			ups = append(ups, "..")
+		}
+		ups = append(ups, doFileRelPath)
+		cwd = path.Clean(path.Join(ups[:len(ups)-1]...))
+		doFile = NewTgt(path.Join(ups...))
+		doFileT = path.Base(doFile.a)
+		if strings.HasPrefix(doFileT, "default.") {
+			basename = basename[:len(basename)-(len(doFileT)-len("default.")-len(".do"))-1]
+			runErr.DoFile = doFile.rel
+		}
 	}
 
-	if err = writeDep(fdDep, cwd, doFile); err != nil {
+	if err = depWrite(fdDepW, fdDep.Name(), tgtH, doFile, ""); err != nil {
 		cleanup()
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
 	}
-	trace(CWait, "%s", runErr.Name())
+	if err = fdDepW.Flush(); err != nil {
+		cleanup()
+		return TgtError{tgt, ErrLine(err)}
+	}
+	fdDep.Close()
+	fdDepOpened = false
+	tracef(CWait, "%s", runErr.Name())
 
 	// Prepare command line
 	var cmdName string
 	var args []string
-	if err = unix.Access(doFilePath, unix.X_OK); err == nil {
-		cmdName = doFilePath
+	if err = unix.Access(doFile.rel, unix.X_OK); err == nil {
+		cmdName = doFile.a
 		args = make([]string, 0, 3)
 	} else {
 		cmdName = "/bin/sh"
-		if traced {
+		if traced || TracedAll {
 			args = append(args, "-ex")
 		} else {
 			args = append(args, "-e")
 		}
-		args = append(args, doFile)
+		args = append(args, doFileT)
 	}
 
 	// Temporary file for stdout
-	fdStdout, err := tempfile(cwdOrig, tgt)
+	fdStdout, err := tempfile(tgtH, tgtT)
 	if err != nil {
 		cleanup()
-		return TgtErr{tgtOrig, err}
+		return TgtError{tgt, ErrLine(err)}
 	}
+	fdStdout.Close()
 	tmpPath := fdStdout.Name() + ".3" // and for $3
-	tmpPathRel, err := filepath.Rel(cwd, tmpPath)
-	if err != nil {
-		panic(err)
-	}
+	tmpPathRel := mustRel(cwd, tmpPath)
 	args = append(
 		args,
-		path.Join(dirPrefix, tgt),
+		path.Join(dirPrefix, tgtT),
 		path.Join(dirPrefix, basename),
 		tmpPathRel,
 	)
+	shCtx = fmt.Sprintf(
+		"sh: %s: %s %s cwd:%s dirprefix:%s",
+		tgt, cmdName, args, cwd, dirPrefix,
+	)
 
 	cmd := exec.Command(cmdName, args...)
 	cmd.Dir = cwd
-	cmd.Stdout = fdStdout
+	// cmd.Stdin reads from /dev/null by default
 	cmd.Env = append(os.Environ(), fmt.Sprintf("%s=%d", EnvLevel, Level+1))
 	cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDirPrefix, dirPrefix))
 	cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvBuildUUID, BuildUUID))
 
-	childStderrPrefix := tempsuffix()
+	childStderrPrefixRaw := make([]byte, 8)
+	if _, err = io.ReadFull(rand.Reader, childStderrPrefixRaw); err != nil {
+		panic(err)
+	}
+	childStderrPrefix := hex.EncodeToString(childStderrPrefixRaw)
 	cmd.Env = append(cmd.Env, fmt.Sprintf(
 		"%s=%s", EnvStderrPrefix, childStderrPrefix,
 	))
 
 	fdNum := 0
-	cmd.ExtraFiles = append(cmd.ExtraFiles, fdDep)
-	cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvDepFd, 3+fdNum))
+	cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgts)
+	cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsFd, 3+fdNum))
+	fdNum++
+	cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgtsLock)
+	cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsLockFd, 3+fdNum))
 	fdNum++
 
 	if FdStatus == nil {
@@ -349,74 +435,191 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
 		fdNum++
 	}
 
-	if JSR == nil {
-		// infinite jobs
-		cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvJSFd))
-	} else {
-		cmd.ExtraFiles = append(cmd.ExtraFiles, JSR)
-		cmd.ExtraFiles = append(cmd.ExtraFiles, JSW)
-		cmd.Env = append(cmd.Env, fmt.Sprintf(
-			"%s=%d,%d", EnvJSFd, 3+fdNum+0, 3+fdNum+1,
-		))
-		fdNum += 2
-	}
-
 	// Preparing stderr
-	stderr, err := cmd.StderrPipe()
-	if err != nil {
-		panic(err)
-	}
 	var fdStderr *os.File
 	if StderrKeep {
 		fdStderr, err = os.OpenFile(
-			path.Join(redoDir, tgt+LogSuffix),
-			os.O_WRONLY|os.O_CREATE,
+			path.Join(redoDir, tgtT+LogSuffix),
+			os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
 			os.FileMode(0666),
 		)
 		if err != nil {
 			cleanup()
-			return TgtErr{tgtOrig, err}
+			return TgtError{tgt, ErrLine(err)}
 		}
-		fdStderr.Truncate(0)
 	}
-	shCtx := fmt.Sprintf("sh: %s: %s %s [%s]", tgtOrig, cmdName, args, cwd)
-	trace(CDebug, "%s", shCtx)
+	tracef(CDebug, "%s", shCtx)
 
+	jsNeedsRelease = false
 	Jobs.Add(1)
 	go func() {
-		jsAcquire(shCtx)
+		if JSR == nil {
+			// infinite jobs
+			cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvJobs))
+		} else {
+			cmd.ExtraFiles = append(cmd.ExtraFiles, JSR)
+			cmd.ExtraFiles = append(cmd.ExtraFiles, JSW)
+			makeFlags := fmt.Sprintf(
+				"%s %s%d,%d", MakeFlags, MakeJSArg, 3+fdNum+0, 3+fdNum+1,
+			)
+			makeFlags = strings.Trim(makeFlags, " ")
+			cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", MakeFlagsName, makeFlags))
+			fdNum += 2
+			cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvJSToken, jsToken))
+		}
+
 		if FdStatus != nil {
-			FdStatus.Write([]byte{StatusRun})
+			if _, err = FdStatus.Write([]byte{StatusRun}); err != nil {
+				log.Fatal(err)
+			}
+		}
+
+		defer jsRelease(shCtx, jsToken)
+
+		var finished time.Time
+		var exitErr *exec.ExitError
+		started := time.Now()
+		runErr.Started = &started
+		fdStdout, err = os.OpenFile(fdStdout.Name(), os.O_RDWR, os.FileMode(0666))
+		if err != nil {
+			if fdStderr != nil {
+				fdStderr.Close()
+			}
+			runErr.Err = err
+			errs <- runErr
+			return
+		}
+		cmd.Stdout = fdStdout
+		fdDep, err = os.OpenFile(fdDep.Name(), os.O_WRONLY|os.O_APPEND, os.FileMode(0666))
+		if err != nil {
+			if fdStderr != nil {
+				fdStderr.Close()
+			}
+			fdStdout.Close()
+			runErr.Err = err
+			errs <- runErr
+			return
 		}
+		fdDepOpened = true
+		fdDepW.Reset(fdDep)
+		cmd.ExtraFiles = append(cmd.ExtraFiles, fdDep)
+		cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvDepFd, 3+fdNum))
+		fdNum++
+		cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDepCwd, cwd))
+
 		defer func() {
-			jsRelease(shCtx)
-			lockRelease()
-			fdDep.Close()
+			if fdDepOpened {
+				fdDep.Close()
+			}
 			fdStdout.Close()
 			if fdStderr != nil {
 				fdStderr.Close()
+				logRecPath := path.Join(redoDir, tgtT+LogRecSuffix)
+				if fdStderr, err = os.OpenFile(
+					logRecPath,
+					os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
+					os.FileMode(0666),
+				); err == nil {
+					fields := []recfile.Field{
+						{Name: "Build", Value: BuildUUID.String()},
+						{Name: "PPID", Value: strconv.Itoa(os.Getpid())},
+						{Name: "Cwd", Value: cwd},
+					}
+					if cmd.Process != nil {
+						fields = append(fields, recfile.Field{
+							Name: "PID", Value: strconv.Itoa(cmd.Process.Pid),
+						})
+					}
+					ts := new(tai64n.TAI64N)
+					ts.FromTime(started)
+					fields = append(fields,
+						recfile.Field{Name: "Started", Value: tai64n.Encode(ts[:])},
+					)
+					ts.FromTime(finished)
+					fields = append(fields,
+						recfile.Field{Name: "Finished", Value: tai64n.Encode(ts[:])})
+					fields = append(fields, recfile.Field{
+						Name:  "Duration",
+						Value: strconv.FormatInt(finished.Sub(started).Nanoseconds(), 10),
+					})
+					fields = append(fields, recfile.Field{Name: "Cmd", Value: cmdName})
+					for _, arg := range args {
+						fields = append(fields, recfile.Field{Name: "Arg", Value: arg})
+					}
+					for _, env := range cmd.Env {
+						fields = append(fields, recfile.Field{Name: "Env", Value: env})
+					}
+					if exitErr != nil {
+						fields = append(fields, recfile.Field{
+							Name:  "ExitCode",
+							Value: strconv.Itoa(exitErr.ProcessState.ExitCode()),
+						})
+					}
+
+					w := bufio.NewWriter(fdStderr)
+					if !fdDepExists {
+						var ifchanges []string
+						ifchanges, err = depReadOnlyIfchanges(tgt.dep)
+						if err != nil {
+							err = ErrLine(err)
+							goto Err
+						}
+						for _, ifchange := range ifchanges {
+							fields = append(fields, recfile.Field{
+								Name:  "Ifchange",
+								Value: ifchange,
+							})
+						}
+					}
+					_, err = recfile.NewWriter(w).WriteFields(fields...)
+					if err != nil {
+						err = ErrLine(err)
+						goto Err
+					}
+					err = ErrLine(w.Flush())
+				Err:
+					if err != nil {
+						log.Print(err)
+						os.Remove(logRecPath)
+					}
+					fdStderr.Close()
+				} else {
+					log.Println("can not open", logRecPath, ":", err)
+				}
+			}
+			lockRelease()
+			if fdDepExists {
+				os.Remove(fdDep.Name())
 			}
-			os.Remove(fdDep.Name())
 			os.Remove(fdStdout.Name())
 			os.Remove(tmpPath)
-			os.Remove(fdLock.Name())
 			if FdStatus != nil {
-				FdStatus.Write([]byte{StatusDone})
+				if _, err = FdStatus.Write([]byte{StatusDone}); err != nil {
+					log.Fatal(err)
+				}
 			}
 			Jobs.Done()
 		}()
-		started := time.Now()
-		runErr.Started = &started
-		err := cmd.Start()
+		stderr, err := cmd.StderrPipe()
+		if err != nil {
+			runErr.Err = err
+			errs <- runErr
+			return
+		}
+		started = time.Now()
+		err = cmd.Start()
 		if err != nil {
 			runErr.Err = err
 			errs <- runErr
 			return
 		}
+		RunningProcsM.Lock()
+		RunningProcs[cmd.Process.Pid] = cmd.Process
+		RunningProcsM.Unlock()
 		pid := fmt.Sprintf("[%d]", cmd.Process.Pid)
-		trace(CDebug, "%s runs %s", tgtOrig, pid)
+		tracef(CDebug, "%s runs %s", tgt, pid)
 
-		stderrTerm := make(chan struct{}, 0)
+		stderrTerm := make(chan struct{})
 		go func() {
 			scanner := bufio.NewScanner(stderr)
 			var line string
@@ -425,22 +628,27 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
 				line = scanner.Text()
 				if strings.HasPrefix(line, childStderrPrefix) {
 					line = line[len(childStderrPrefix):]
-					os.Stderr.WriteString(StderrPrefix + line + "\n")
+					if StderrPrefix == "" {
+						withPrependedTgt(line)
+					} else {
+						stderrWrite(StderrPrefix + line + "\n")
+					}
 					continue
 				}
 				if fdStderr != nil {
-					tai64n.FromTime(time.Now(), ts)
-					LogMutex.Lock()
-					fmt.Fprintf(fdStderr, "%s %s\n", ts.Encode(), line)
-					LogMutex.Unlock()
+					ts.FromTime(time.Now())
+					fmt.Fprintln(fdStderr, tai64n.Encode(ts[:]), line)
 				}
 				if StderrSilent {
 					continue
 				}
-				if MyPid == 0 {
-					trace(CNone, "%s", line)
+				if MyPID != 0 {
+					line = pid + " " + line
+				}
+				if StderrPrefix == "" {
+					withPrependedTgt("[" + tgt.rel + "]" + line)
 				} else {
-					trace(CNone, "%s %s", pid, line)
+					stderrWrite(StderrPrefix + "[" + tgt.rel + "]" + line + "\n")
 				}
 			}
 			close(stderrTerm)
@@ -449,32 +657,36 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
 		// Wait for job completion
 		<-stderrTerm
 		err = cmd.Wait()
-		finished := time.Now()
+		RunningProcsM.Lock()
+		delete(RunningProcs, cmd.Process.Pid)
+		RunningProcsM.Unlock()
+		finished = time.Now()
 		runErr.Finished = &finished
 		if err != nil {
+			exitErr = err.(*exec.ExitError)
 			runErr.Err = err
 			errs <- runErr
 			return
 		}
 
 		// Was $1 touched?
-		if tsPrev != "" {
-			if fd, err := os.Open(path.Join(cwdOrig, tgt)); err == nil {
-				ts, err := fileCtime(fd)
-				fd.Close()
-				if err == nil && ts != tsPrev {
-					runErr.Err = errors.New("$1 was explicitly touched")
-					errs <- runErr
-					fd.Close()
-					return
-				}
+		if inode, err := inodeFromFileByPath(tgt.a); err == nil {
+			if inodePrev == nil {
+				runErr.Err = Err1WasTouched
+				errs <- runErr
+				return
+			}
+			if !inode.Equals(inodePrev) {
+				runErr.Err = Err1WasTouched
+				errs <- runErr
+				return
 			}
 		}
 
 		// Does it produce both stdout and tmp?
 		fiStdout, err := os.Stat(fdStdout.Name())
 		if err != nil {
-			runErr.Err = err
+			runErr.Err = ErrLine(err)
 			errs <- runErr
 			return
 		}
@@ -487,71 +699,149 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
 				return
 			}
 			tmpExists = true
-		} else if !os.IsNotExist(err) {
-			runErr.Err = err
+		} else if !errors.Is(err, fs.ErrNotExist) {
+			runErr.Err = ErrLine(err)
 			errs <- runErr
 			return
 		}
 
 		// Determine what file we must process at last
 		var fd *os.File
+		var chmod fs.FileMode
 		if tmpExists {
 			fd, err = os.Open(tmpPath)
 			if err != nil {
+				err = ErrLine(err)
 				goto Finish
 			}
 			defer fd.Close()
+			if fi, rerr := fd.Stat(); rerr == nil {
+				chmod = fi.Mode()
+			} else {
+				err = ErrLine(rerr)
+				goto Finish
+			}
 		} else if fiStdout.Size() > 0 {
 			fd = fdStdout
 		}
 
-		// Do we need to ifcreate it, of ifchange with renaming?
+		// Do we need to ifcreate it, or ifchange with renaming?
 		if fd == nil {
-			os.Remove(path.Join(cwdOrig, tgt))
-			err = ifcreate(fdDep, tgt)
+			os.Remove(tgt.a)
+			err = ifcreate(fdDepW, fdDep.Name(), tgtT)
 			if err != nil {
+				err = ErrLine(err)
 				goto Finish
 			}
 		} else {
+			var hsh Hash
+			if hshPrev != "" {
+				_, err = fd.Seek(0, io.SeekStart)
+				if err != nil {
+					err = ErrLine(err)
+					goto Finish
+				}
+				hsh, err = fileHash(fd)
+				if err != nil {
+					err = ErrLine(err)
+					goto Finish
+				}
+				if hsh == hshPrev {
+					tracef(CDebug, "%s has same hash, not renaming", tgt)
+					err = ErrLine(os.Remove(fd.Name()))
+					if err != nil {
+						goto Finish
+					}
+					if chmod != 0 {
+						err = ErrLine(os.Chmod(tgt.a, chmod))
+						if err != nil {
+							goto Finish
+						}
+					}
+					err = ErrLine(os.Chtimes(tgt.a, finished, finished))
+					if err != nil {
+						goto Finish
+					}
+					if !NoSync {
+						err = ErrLine(syncDir(tgtH))
+						if err != nil {
+							goto Finish
+						}
+					}
+					err = ErrLine(depWrite(fdDepW, fdDep.Name(), tgtH, tgt, hsh))
+					if err != nil {
+						goto Finish
+					}
+					goto RecCommit
+				}
+			}
 			if !NoSync {
-				err = fd.Sync()
+				err = ErrLine(fd.Sync())
 				if err != nil {
 					goto Finish
 				}
 			}
-			err = os.Rename(fd.Name(), path.Join(cwdOrig, tgt))
+			err = ErrLine(os.Rename(fd.Name(), tgt.a))
 			if err != nil {
 				goto Finish
 			}
 			if !NoSync {
-				err = syncDir(cwdOrig)
+				err = ErrLine(syncDir(tgtH))
 				if err != nil {
 					goto Finish
 				}
 			}
-			err = writeDep(fdDep, cwdOrig, tgt)
+			err = ErrLine(depWrite(fdDepW, fdDep.Name(), tgtH, tgt, hsh))
 			if err != nil {
 				goto Finish
 			}
 		}
 
+	RecCommit:
 		// Commit .dep
+		err = ErrLine(fdDepW.Flush())
+		if err != nil {
+			goto Finish
+		}
 		if !NoSync {
-			err = fdDep.Sync()
+			err = ErrLine(fdDep.Sync())
 			if err != nil {
 				goto Finish
 			}
 		}
-		err = os.Rename(fdDep.Name(), path.Join(redoDir, tgt+DepSuffix))
+		err = ErrLine(os.Rename(fdDep.Name(), tgt.dep))
 		if err != nil {
 			goto Finish
 		}
+		fdDepExists = false
 		if !NoSync {
-			err = syncDir(redoDir)
+			err = ErrLine(syncDir(redoDir))
 			if err != nil {
 				goto Finish
 			}
 		}
+		fdDep.Close()
+		fdDepOpened = false
+
+		// Post-commit .dep sanitizing
+		dep, err = depRead(tgt)
+		if err == nil {
+			ifchangeSeen := make(map[string]struct{}, len(dep.ifchanges))
+			for _, ifchange := range dep.ifchanges {
+				ifchangeSeen[ifchange.tgt.a] = struct{}{}
+			}
+			for _, ifcreate := range dep.ifcreates {
+				if _, exists := ifchangeSeen[ifcreate.a]; exists {
+					tracef(CWarn, "simultaneous ifcreate and ifchange records: %s", tgt)
+				}
+			}
+		} else if errors.Is(err, fs.ErrNotExist) {
+			err = nil
+		} else {
+			err = ErrLine(err)
+			goto Finish
+		}
+
 	Finish:
 		runErr.Err = err
 		errs <- runErr
@@ -563,10 +853,11 @@ func isOkRun(err error) bool {
 	if err == nil {
 		return true
 	}
-	if err, ok := err.(RunErr); ok && err.Err == nil {
-		trace(CRedo, "%s", err.Name())
+	var runErr RunError
+	if errors.As(err, &runErr) && runErr.Err == nil {
+		tracef(CRedo, "%s", runErr.Name())
 		return true
 	}
-	trace(CErr, "%s", err)
+	tracef(CErr, "%s", err)
 	return false
 }