]> Cypherpunks.ru repositories - goredo.git/blobdiff - run.go
Redundant @documentencoding
[goredo.git] / run.go
diff --git a/run.go b/run.go
index f6a9042d192dd9316239c99660b3db42a0b61f6d..2e5dbf5f7ebd5fc8e9c4cfc6e8194333b0456fd9 100644 (file)
--- a/run.go
+++ b/run.go
@@ -1,6 +1,6 @@
 /*
 goredo -- djb's redo implementation on pure Go
-Copyright (C) 2020-2021 Sergey Matveev <stargrave@stargrave.org>
+Copyright (C) 2020-2023 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
@@ -21,55 +21,86 @@ package main
 
 import (
        "bufio"
+       "crypto/rand"
+       "encoding/hex"
        "errors"
        "flag"
        "fmt"
        "io"
+       "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    = ".rec"
+       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 {
+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      string
        DoFile   string
        Started  *time.Time
@@ -77,7 +108,7 @@ type RunErr struct {
        Err      error
 }
 
-func (e *RunErr) Name() string {
+func (e *RunError) Name() string {
        var name string
        if e.DoFile == "" {
                name = e.Tgt
@@ -87,64 +118,60 @@ func (e *RunErr) Name() string {
        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, *Inode, error) {
+func isModified(cwd, redoDir, tgt string) (bool, *Inode, string, error) {
        fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
        if err != nil {
                if os.IsNotExist(err) {
-                       return false, nil, nil
+                       return false, nil, "", nil
                }
-               return false, nil, err
+               return false, nil, "", err
        }
        defer fdDep.Close()
        r := recfile.NewReader(fdDep)
+       var modified bool
        var ourInode *Inode
+       var hshPrev string
        for {
                m, err := r.NextMap()
                if err != nil {
-                       if err == io.EOF {
+                       if errors.Is(err, io.EOF) {
                                break
                        }
-                       return false, nil, err
+                       return false, nil, "", err
                }
-               if m["Target"] != tgt {
+               if m["Type"] != DepTypeIfchange || m["Target"] != tgt {
                        continue
                }
-               fd, err := os.Open(path.Join(cwd, tgt))
+               ourInode, err = inodeFromFileByPath(path.Join(cwd, tgt))
                if err != nil {
                        if os.IsNotExist(err) {
-                               return false, nil, nil
+                               return false, nil, "", nil
                        }
-                       return false, nil, err
-               }
-               ourInode, err = inodeFromFile(fd)
-               fd.Close()
-               if err != nil {
-                       return false, nil, err
+                       return false, nil, "", err
                }
                theirInode, err := inodeFromRec(m)
                if err != nil {
-                       return false, nil, err
-               }
-               if !ourInode.Equals(theirInode) {
-                       return true, ourInode, nil
+                       return false, nil, "", err
                }
+               hshPrev = m["Hash"]
+               modified = !ourInode.Equals(theirInode)
                break
        }
-       return false, ourInode, nil
+       return modified, ourInode, hshPrev, nil
 }
 
 func syncDir(dir string) error {
@@ -161,9 +188,18 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
        cwd, tgt := cwdAndTgt(tgtOrig)
        redoDir := path.Join(cwd, RedoDir)
        if err := mkdirs(redoDir); err != nil {
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
 
+       shCtx := fmt.Sprintf("sh: %s: cwd:%s", tgtOrig, cwd)
+       jsToken := jsAcquire(shCtx)
+       jsNeedsRelease := true
+       defer func() {
+               if jsNeedsRelease {
+                       jsRelease(shCtx, jsToken)
+               }
+       }()
+
        // Acquire lock
        fdLock, err := os.OpenFile(
                path.Join(redoDir, tgt+LockSuffix),
@@ -171,40 +207,59 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                os.FileMode(0666),
        )
        if err != nil {
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, 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{tgtOrig, 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)", tgtOrig, flock.Pid)
                if FdStatus != nil {
-                       FdStatus.Write([]byte{StatusWait})
+                       if _, err = FdStatus.Write([]byte{StatusWait}); err != nil {
+                               log.Fatalln(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 {
+                               log.Println(err, fdLock.Name())
+                               time.Sleep(10 * time.Millisecond)
+                               goto LockAgain
+                       }
                        lockRelease()
-                       trace(CDebug, "waiting done: %s", tgtOrig)
+                       tracef(CDebug, "waiting done: %s", tgtOrig)
                        if FdStatus != nil {
-                               FdStatus.Write([]byte{StatusWaited})
+                               if _, err = FdStatus.Write([]byte{StatusWaited}); err != nil {
+                                       log.Fatalln(err)
+                               }
                        }
                        var depInfo *DepInfo
                        fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
                        if err != nil {
                                if os.IsNotExist(err) {
-                                       err = errors.New("was not built: no .dep")
+                                       err = errors.New("was not built: no .rec")
                                }
                                goto Finish
                        }
@@ -218,7 +273,8 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                        }
                Finish:
                        if err != nil {
-                               err = TgtErr{tgtOrig, err}
+                               err = TgtError{tgtOrig, err}
+                               fdLock.Close()
                        }
                        errs <- err
                }()
@@ -226,26 +282,30 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
        }
 
        // Check if target is not modified externally
-       modified, inodePrev, err := isModified(cwd, redoDir, tgt)
+       modified, inodePrev, hshPrev, err := isModified(cwd, redoDir, tgt)
        if err != nil {
                lockRelease()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
        if modified {
-               trace(CWarn, "%s externally modified: not redoing", tgtOrig)
                lockRelease()
+               if StopIfMod {
+                       return fmt.Errorf("%s externally modified", tgtOrig)
+               }
+               tracef(CWarn, "%s externally modified: not redoing", tgtOrig)
                go func() {
                        errs <- nil
                }()
                return nil
        }
 
-       // Start preparing .dep
+       // Start preparing .rec
        fdDep, err := tempfile(redoDir, tgt+DepSuffix)
        if err != nil {
                lockRelease()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
+       fdDepPath := fdDep.Name()
        cleanup := func() {
                lockRelease()
                fdDep.Close()
@@ -255,18 +315,18 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                recfile.Field{Name: "Build", Value: BuildUUID},
        ); err != nil {
                cleanup()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
 
        // Find .do
        doFile, upLevels, err := findDo(fdDep, cwd, tgt)
        if err != nil {
                cleanup()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
        if doFile == "" {
                cleanup()
-               return TgtErr{tgtOrig, errors.New("no .do found")}
+               return TgtError{tgtOrig, errors.New("no .do found")}
        }
 
        // Determine basename and DIRPREFIX
@@ -282,17 +342,18 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
        cwd = path.Clean(cwd)
        doFilePath := path.Join(cwd, doFile)
        basename := tgt
-       runErr := RunErr{Tgt: tgtOrig}
+       runErr := RunError{Tgt: tgtOrig}
        if strings.HasPrefix(doFile, "default.") {
                basename = tgt[:len(tgt)-(len(doFile)-len("default.")-len(".do"))-1]
                runErr.DoFile = doFileRelPath
        }
 
-       if err = writeDep(fdDep, cwdOrig, doFileRelPath); err != nil {
+       if err = depWrite(fdDep, cwdOrig, doFileRelPath, ""); err != nil {
                cleanup()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
-       trace(CWait, "%s", runErr.Name())
+       fdDep.Close()
+       tracef(CWait, "%s", runErr.Name())
 
        // Prepare command line
        var cmdName string
@@ -302,7 +363,7 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                args = make([]string, 0, 3)
        } else {
                cmdName = "/bin/sh"
-               if traced {
+               if traced || TracedAll {
                        args = append(args, "-ex")
                } else {
                        args = append(args, "-e")
@@ -314,9 +375,11 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
        fdStdout, err := tempfile(cwdOrig, tgt)
        if err != nil {
                cleanup()
-               return TgtErr{tgtOrig, err}
+               return TgtError{tgtOrig, err}
        }
-       tmpPath := fdStdout.Name() + ".3" // and for $3
+       stdoutPath := fdStdout.Name()
+       fdStdout.Close()
+       tmpPath := stdoutPath + ".3" // and for $3
        tmpPathRel, err := filepath.Rel(cwd, tmpPath)
        if err != nil {
                panic(err)
@@ -327,23 +390,33 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                path.Join(dirPrefix, basename),
                tmpPathRel,
        )
+       shCtx = fmt.Sprintf(
+               "sh: %s: %s %s cwd:%s dirprefix:%s",
+               tgtOrig, 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 {
@@ -354,77 +427,186 @@ 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,
+                       os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
                        os.FileMode(0666),
                )
                if err != nil {
                        cleanup()
-                       return TgtErr{tgtOrig, err}
+                       return TgtError{tgtOrig, err}
                }
-               fdStderr.Truncate(0)
        }
-       shCtx := fmt.Sprintf(
-               "sh: %s: %s %s cwd:%s dirprefix:%s",
-               tgtOrig, cmdName, args, cwd, dirPrefix,
-       )
-       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.Fatalln(err)
+                       }
+               }
+
+               defer jsRelease(shCtx, jsToken)
+
+               var finished time.Time
+               var exitErr *exec.ExitError
+               started := time.Now()
+               runErr.Started = &started
+               fdStdout, err = os.OpenFile(stdoutPath, 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(fdDepPath, 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
                }
+               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()
                        fdStdout.Close()
                        if fdStderr != nil {
                                fdStderr.Close()
+                               logRecPath := path.Join(redoDir, tgt+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},
+                                               {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)
+
+                                       var depInfo *DepInfo
+                                       fdDep, err := os.Open(fdDepPath)
+                                       if err != nil {
+                                               goto Err
+                                       }
+                                       depInfo, err = depRead(fdDep)
+                                       fdDep.Close()
+                                       if err != nil {
+                                               goto Err
+                                       }
+                                       for _, dep := range depInfo.ifchanges {
+                                               fields = append(fields, recfile.Field{
+                                                       Name:  "Ifchange",
+                                                       Value: dep["Target"],
+                                               })
+                                       }
+                                       _, err = recfile.NewWriter(w).WriteFields(fields...)
+                                       if err != nil {
+                                               goto Err
+                                       }
+                                       err = w.Flush()
+                               Err:
+                                       if err != nil {
+                                               log.Println(err)
+                                               os.Remove(logRecPath)
+                                       }
+                                       fdStderr.Close()
+                               } else {
+                                       log.Println("can not open", logRecPath, ":", err)
+                               }
                        }
+                       lockRelease()
                        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.Fatalln(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", tgtOrig, pid)
 
-               stderrTerm := make(chan struct{}, 0)
+               stderrTerm := make(chan struct{})
                go func() {
                        scanner := bufio.NewScanner(stderr)
                        var line string
@@ -437,18 +619,18 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                                        continue
                                }
                                if fdStderr != nil {
-                                       tai64n.FromTime(time.Now(), ts)
+                                       ts.FromTime(time.Now())
                                        LogMutex.Lock()
-                                       fmt.Fprintf(fdStderr, "%s %s\n", ts.Encode(), line)
+                                       fmt.Fprintln(fdStderr, tai64n.Encode(ts[:]), line)
                                        LogMutex.Unlock()
                                }
                                if StderrSilent {
                                        continue
                                }
                                if MyPid == 0 {
-                                       trace(CNone, "%s", line)
+                                       tracef(CNone, "%s", line)
                                } else {
-                                       trace(CNone, "%s %s", pid, line)
+                                       tracef(CNone, "%s %s", pid, line)
                                }
                        }
                        close(stderrTerm)
@@ -457,21 +639,41 @@ 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 inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
+                       if inodePrev == nil {
+                               runErr.Err = Err1WasTouched
+                               errs <- runErr
+                               return
+                       }
+                       if err != nil {
+                               runErr.Err = err
+                               errs <- runErr
+                               return
+                       }
+                       if !inode.Equals(inodePrev) {
+                               runErr.Err = Err1WasTouched
+                               errs <- runErr
+                               return
+                       }
+               }
+
                if inodePrev != nil {
-                       if fd, err := os.Open(path.Join(cwdOrig, tgt)); err == nil {
-                               inode, err := inodeFromFile(fd)
-                               fd.Close()
-                               if err == nil && !inode.Equals(inodePrev) {
-                                       runErr.Err = errors.New("$1 was explicitly touched")
+                       if inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
+                               if !inode.Equals(inodePrev) {
+                                       runErr.Err = Err1WasTouched
                                        errs <- runErr
                                        return
                                }
@@ -512,7 +714,7 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                        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)
@@ -520,6 +722,39 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                                goto Finish
                        }
                } else {
+                       var hsh string
+                       if hshPrev != "" {
+                               _, err = fd.Seek(0, io.SeekStart)
+                               if err != nil {
+                                       goto Finish
+                               }
+                               hsh, err = fileHash(fd)
+                               if err != nil {
+                                       goto Finish
+                               }
+                               if hsh == hshPrev {
+                                       tracef(CDebug, "%s has same hash, not renaming", tgtOrig)
+                                       err = os.Remove(fd.Name())
+                                       if err != nil {
+                                               goto Finish
+                                       }
+                                       err = os.Chtimes(path.Join(cwdOrig, tgt), finished, finished)
+                                       if err != nil {
+                                               goto Finish
+                                       }
+                                       if !NoSync {
+                                               err = syncDir(cwdOrig)
+                                               if err != nil {
+                                                       goto Finish
+                                               }
+                                       }
+                                       err = depWrite(fdDep, cwdOrig, tgt, hshPrev)
+                                       if err != nil {
+                                               goto Finish
+                                       }
+                                       goto RecCommit
+                               }
+                       }
                        if !NoSync {
                                err = fd.Sync()
                                if err != nil {
@@ -536,20 +771,22 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                                        goto Finish
                                }
                        }
-                       err = writeDep(fdDep, cwdOrig, tgt)
+                       err = depWrite(fdDep, cwdOrig, tgt, hsh)
                        if err != nil {
                                goto Finish
                        }
                }
 
-               // Commit .dep
+       RecCommit:
+               // Commit .rec
                if !NoSync {
                        err = fdDep.Sync()
                        if err != nil {
                                goto Finish
                        }
                }
-               err = os.Rename(fdDep.Name(), path.Join(redoDir, tgt+DepSuffix))
+               fdDepPath = path.Join(redoDir, tgt+DepSuffix)
+               err = os.Rename(fdDep.Name(), fdDepPath)
                if err != nil {
                        goto Finish
                }
@@ -559,6 +796,26 @@ func runScript(tgtOrig string, errs chan error, traced bool) error {
                                goto Finish
                        }
                }
+
+               // Post-commit .rec sanitizing
+               fdDep.Close()
+               if fdDepR, err := os.Open(fdDepPath); err == nil {
+                       depInfo, err := depRead(fdDepR)
+                       fdDepR.Close()
+                       if err != nil {
+                               goto Finish
+                       }
+                       ifchangeSeen := make(map[string]struct{}, len(depInfo.ifchanges))
+                       for _, dep := range depInfo.ifchanges {
+                               ifchangeSeen[dep["Target"]] = struct{}{}
+                       }
+                       for _, dep := range depInfo.ifcreates {
+                               if _, exists := ifchangeSeen[dep]; exists {
+                                       tracef(CWarn, "simultaneous ifcreate and ifchange records: %s", tgt)
+                               }
+                       }
+               }
+
        Finish:
                runErr.Err = err
                errs <- runErr
@@ -570,10 +827,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
 }