]> Cypherpunks.ru repositories - goredo.git/blobdiff - run.go
Download link for 2.6.2 release
[goredo.git] / run.go
diff --git a/run.go b/run.go
index 589889e3db6edbf62f51f626e5f9ed04394323fd..8ea91d1eb9ca10d5789cd5cd9159c6c9aeb715f4 100644 (file)
--- a/run.go
+++ b/run.go
@@ -1,19 +1,17 @@
-/*
-goredo -- redo implementation on pure Go
-Copyright (C) 2020 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,22 +657,28 @@ 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 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")
+               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
-                               fd.Close()
                                return
                        }
                }
@@ -472,7 +686,7 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                // 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
                }
@@ -485,70 +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 {
-                       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
@@ -560,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
 }