run.go

   1 /*
   2 goredo -- djb's redo implementation on pure Go
   3 Copyright (C) 2020-2023 Sergey Matveev <stargrave@stargrave.org>
   4
   5 This program is free software: you can redistribute it and/or modify
   6 it under the terms of the GNU General Public License as published by
   7 the Free Software Foundation, version 3 of the License.
   8
   9 This program is distributed in the hope that it will be useful,
  10 but WITHOUT ANY WARRANTY; without even the implied warranty of
  11 MERCHANTABILITY or FITNESS FOR A PARTICULAR PURPOSE.  See the
  12 GNU General Public License for more details.
  13
  14 You should have received a copy of the GNU General Public License
  15 along with this program.  If not, see <http://www.gnu.org/licenses/>.
  16 */
  17
  18 // Targets runner
  19
  20 package main
  21
  22 import (
  23         "bufio"
  24         "crypto/rand"
  25         "encoding/hex"
  26         "errors"
  27         "flag"
  28         "fmt"
  29         "io"
  30         "log"
  31         "os"
  32         "os/exec"
  33         "path"
  34         "strconv"
  35         "strings"
  36         "sync"
  37         "syscall"
  38         "time"
  39
  40         "go.cypherpunks.ru/recfile"
  41         "go.cypherpunks.ru/tai64n/v2"
  42         "golang.org/x/sys/unix"
  43 )
  44
  45 const (
  46         EnvDepFd        = "REDO_DEP_FD"
  47         EnvDirPrefix    = "REDO_DIRPREFIX"
  48         EnvDepCwd       = "REDO_DEP_CWD"
  49         EnvBuildUUID    = "REDO_BUILD_UUID"
  50         EnvStderrPrefix = "REDO_STDERR_PREFIX"
  51         EnvTrace        = "REDO_TRACE"
  52         EnvStderrKeep   = "REDO_LOGS"
  53         EnvStderrSilent = "REDO_SILENT"
  54         EnvNoSync       = "REDO_NO_SYNC"
  55         EnvStopIfMod    = "REDO_STOP_IF_MODIFIED"
  56
  57         RedoDir      = ".redo"
  58         LockSuffix   = ".lock"
  59         DepSuffix    = ".rec"
  60         TmpPrefix    = ".redo."
  61         LogSuffix    = ".log"
  62         LogRecSuffix = ".log-rec"
  63 )
  64
  65 var (
  66         NoSync       = false
  67         StderrKeep   = false
  68         StderrSilent = false
  69         StderrPrefix string
  70         StopIfMod    = false
  71         Jobs         sync.WaitGroup
  72
  73         flagTrace          *bool
  74         flagTraceAll       *bool
  75         flagStderrKeep     *bool
  76         flagStderrSilent   *bool
  77         flagForcedIfchange *bool
  78
  79         TracedAll bool
  80
  81         RunningProcs  = map[int]*os.Process{}
  82         RunningProcsM sync.Mutex
  83
  84         Err1WasTouched = errors.New("$1 was explicitly touched")
  85 )
  86
  87 func init() {
  88         cmdName := CmdName()
  89         if !(cmdName == CmdNameRedo || cmdName == CmdNameRedoIfchange) {
  90                 return
  91         }
  92         flagTrace = flag.Bool("x", false, "trace (sh -x) current targets")
  93         flagTraceAll = flag.Bool("xx", false,
  94                 fmt.Sprintf("trace (sh -x) all targets (%s=1)", EnvTrace))
  95         flagStderrKeep = flag.Bool("k", false,
  96                 fmt.Sprintf("keep job's stderr (%s=1)", EnvStderrKeep))
  97         flagStderrSilent = flag.Bool("s", false,
  98                 fmt.Sprintf("silent, do not print job's stderr (%s=1)", EnvStderrSilent))
  99         flagForcedIfchange = flag.Bool("f", false, "forced redo-ifchange")
 100 }
 101
 102 type RunError struct {
 103         Tgt      string
 104         DoFile   string
 105         Started  *time.Time
 106         Finished *time.Time
 107         Err      error
 108 }
 109
 110 func (e *RunError) Name() string {
 111         var name string
 112         if e.DoFile == "" {
 113                 name = e.Tgt
 114         } else {
 115                 name = fmt.Sprintf("%s (%s)", e.Tgt, e.DoFile)
 116         }
 117         if e.Finished == nil {
 118                 return name
 119         }
 120         return fmt.Sprintf("%s (%.3fs)", name, e.Finished.Sub(*e.Started).Seconds())
 121 }
 122
 123 func (e RunError) Error() string {
 124         return fmt.Sprintf("%s: %s", e.Name(), e.Err)
 125 }
 126
 127 func mkdirs(pth string) error {
 128         if FileExists(pth) {
 129                 return nil
 130         }
 131         return os.MkdirAll(pth, os.FileMode(0777))
 132 }
 133
 134 func isModified(cwd, redoDir, tgt string) (bool, *Inode, string, error) {
 135         fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
 136         if err != nil {
 137                 if os.IsNotExist(err) {
 138                         return false, nil, "", nil
 139                 }
 140                 return false, nil, "", ErrLine(err)
 141         }
 142         defer fdDep.Close()
 143         r := recfile.NewReader(fdDep)
 144         var modified bool
 145         var ourInode *Inode
 146         var hshPrev string
 147         for {
 148                 m, err := r.NextMap()
 149                 if err != nil {
 150                         if errors.Is(err, io.EOF) {
 151                                 break
 152                         }
 153                         return false, nil, "", ErrLine(err)
 154                 }
 155                 if m["Type"] != DepTypeIfchange || m["Target"] != tgt {
 156                         continue
 157                 }
 158                 ourInode, err = inodeFromFileByPath(path.Join(cwd, tgt))
 159                 if err != nil {
 160                         if os.IsNotExist(err) {
 161                                 return false, nil, "", nil
 162                         }
 163                         return false, nil, "", ErrLine(err)
 164                 }
 165                 theirInode, err := inodeFromRec(m)
 166                 if err != nil {
 167                         return false, nil, "", ErrLine(err)
 168                 }
 169                 hshPrev = m["Hash"]
 170                 modified = !ourInode.Equals(theirInode)
 171                 break
 172         }
 173         return modified, ourInode, hshPrev, nil
 174 }
 175
 176 func syncDir(dir string) error {
 177         fd, err := os.Open(dir)
 178         if err != nil {
 179                 return err
 180         }
 181         err = fd.Sync()
 182         fd.Close()
 183         return err
 184 }
 185
 186 func runScript(tgtOrig string, errs chan error, forced, traced bool) error {
 187         cwd, tgt := cwdAndTgt(tgtOrig)
 188         redoDir := path.Join(cwd, RedoDir)
 189         if err := mkdirs(redoDir); err != nil {
 190                 return TgtError{tgtOrig, ErrLine(err)}
 191         }
 192
 193         shCtx := fmt.Sprintf("sh: %s: cwd:%s", tgtOrig, cwd)
 194         jsToken := jsAcquire(shCtx)
 195         jsNeedsRelease := true
 196         defer func() {
 197                 if jsNeedsRelease {
 198                         jsRelease(shCtx, jsToken)
 199                 }
 200         }()
 201
 202         // Acquire lock
 203         fdLock, err := os.OpenFile(
 204                 path.Join(redoDir, tgt+LockSuffix),
 205                 os.O_WRONLY|os.O_TRUNC|os.O_CREATE,
 206                 os.FileMode(0666),
 207         )
 208         if err != nil {
 209                 return TgtError{tgtOrig, ErrLine(err)}
 210         }
 211         flock := unix.Flock_t{
 212                 Type:   unix.F_WRLCK,
 213                 Whence: io.SeekStart,
 214         }
 215         lockRelease := func() {
 216                 tracef(CLock, "LOCK_UN: %s", fdLock.Name())
 217                 flock.Type = unix.F_UNLCK
 218                 if err := unix.FcntlFlock(fdLock.Fd(), unix.F_SETLK, &flock); err != nil {
 219                         log.Fatalln(err, fdLock.Name())
 220                 }
 221                 fdLock.Close()
 222         }
 223         tracef(CLock, "LOCK_NB: %s", fdLock.Name())
 224
 225         // Waiting for job completion, already taken by someone else
 226         if err = unix.FcntlFlock(fdLock.Fd(), unix.F_SETLK, &flock); err != nil {
 227                 if uintptr(err.(syscall.Errno)) != uintptr(unix.EAGAIN) {
 228                         fdLock.Close()
 229                         return TgtError{tgtOrig, ErrLine(err)}
 230                 }
 231                 Jobs.Add(1)
 232                 if err = unix.FcntlFlock(fdLock.Fd(), unix.F_GETLK, &flock); err != nil {
 233                         log.Fatalln(err, fdLock.Name())
 234                 }
 235                 tracef(CDebug, "waiting: %s (pid=%d)", tgtOrig, flock.Pid)
 236                 if FdStatus != nil {
 237                         if _, err = FdStatus.Write([]byte{StatusWait}); err != nil {
 238                                 log.Fatal(err)
 239                         }
 240                 }
 241                 go func() {
 242                         defer Jobs.Done()
 243                         tracef(CLock, "LOCK_EX: %s", fdLock.Name())
 244                 LockAgain:
 245                         if err := unix.FcntlFlock(fdLock.Fd(), unix.F_SETLKW, &flock); err != nil {
 246                                 if errors.Is(err, unix.EDEADLK) {
 247                                         time.Sleep(10 * time.Millisecond)
 248                                         goto LockAgain
 249                                 }
 250                                 log.Fatalln(err, fdLock.Name())
 251                         }
 252                         lockRelease()
 253                         tracef(CDebug, "waiting done: %s", tgtOrig)
 254                         if FdStatus != nil {
 255                                 if _, err = FdStatus.Write([]byte{StatusWaited}); err != nil {
 256                                         log.Fatal(err)
 257                                 }
 258                         }
 259                         build, err := depReadBuild(path.Join(redoDir, tgt+DepSuffix))
 260                         if err != nil {
 261                                 if errors.Is(err, fs.ErrNotExist) {
 262                                         err = errors.New("was not built: no .rec")
 263                                 }
 264                                 goto Finish
 265                         }
 266                         if build != BuildUUID {
 267                                 err = errors.New("was not built: build differs")
 268                         }
 269                 Finish:
 270                         if err != nil {
 271                                 err = TgtError{tgtOrig, err}
 272                                 fdLock.Close()
 273                         }
 274                         errs <- err
 275                 }()
 276                 return nil
 277         }
 278
 279         // Check if it was already built in parallel
 280         if !forced {
 281                 if build, err := depReadBuild(path.Join(redoDir, tgt+DepSuffix)); err == nil && build == BuildUUID {
 282                         lockRelease()
 283                         errs <- nil
 284                         return nil
 285                 }
 286         }
 287
 288         // Check if target is not modified externally
 289         modified, inodePrev, hshPrev, err := isModified(cwd, redoDir, tgt)
 290         if err != nil {
 291                 lockRelease()
 292                 return TgtError{tgtOrig, err}
 293         }
 294         if modified {
 295                 lockRelease()
 296                 if StopIfMod {
 297                         return fmt.Errorf("%s externally modified", tgtOrig)
 298                 }
 299                 tracef(CWarn, "%s externally modified: not redoing", tgtOrig)
 300                 go func() {
 301                         errs <- nil
 302                 }()
 303                 return nil
 304         }
 305
 306         // Start preparing .rec
 307         fdDep, err := tempfile(redoDir, tgt+DepSuffix)
 308         if err != nil {
 309                 lockRelease()
 310                 return TgtError{tgtOrig, ErrLine(err)}
 311         }
 312         fdDepPath := fdDep.Name()
 313         cleanup := func() {
 314                 lockRelease()
 315                 fdDep.Close()
 316                 os.Remove(fdDep.Name())
 317         }
 318         if _, err = recfile.NewWriter(fdDep).WriteFields(
 319                 recfile.Field{Name: "Build", Value: BuildUUID},
 320         ); err != nil {
 321                 cleanup()
 322                 return TgtError{tgtOrig, ErrLine(err)}
 323         }
 324
 325         // Find .do
 326         doFile, upLevels, err := findDo(fdDep, cwd, tgt)
 327         if err != nil {
 328                 cleanup()
 329                 return TgtError{tgtOrig, ErrLine(err)}
 330         }
 331         if doFile == "" {
 332                 cleanup()
 333                 return TgtError{tgtOrig, errors.New("no .do found")}
 334         }
 335
 336         // Determine basename and DIRPREFIX
 337         doFileRelPath := doFile
 338         ents := strings.Split(cwd, "/")
 339         ents = ents[len(ents)-upLevels:]
 340         dirPrefix := path.Join(ents...)
 341         cwdOrig := cwd
 342         for i := 0; i < upLevels; i++ {
 343                 cwd = path.Join(cwd, "..")
 344                 doFileRelPath = path.Join("..", doFileRelPath)
 345         }
 346         cwd = path.Clean(cwd)
 347         doFilePath := path.Join(cwd, doFile)
 348         basename := tgt
 349         runErr := RunError{Tgt: tgtOrig}
 350         if strings.HasPrefix(doFile, "default.") {
 351                 basename = tgt[:len(tgt)-(len(doFile)-len("default.")-len(".do"))-1]
 352                 runErr.DoFile = doFileRelPath
 353         }
 354
 355         if err = depWrite(fdDep, cwdOrig, doFileRelPath, ""); err != nil {
 356                 cleanup()
 357                 return TgtError{tgtOrig, ErrLine(err)}
 358         }
 359         fdDep.Close()
 360         tracef(CWait, "%s", runErr.Name())
 361
 362         // Prepare command line
 363         var cmdName string
 364         var args []string
 365         if err = unix.Access(doFilePath, unix.X_OK); err == nil {
 366                 cmdName = doFilePath
 367                 args = make([]string, 0, 3)
 368         } else {
 369                 cmdName = "/bin/sh"
 370                 if traced || TracedAll {
 371                         args = append(args, "-ex")
 372                 } else {
 373                         args = append(args, "-e")
 374                 }
 375                 args = append(args, doFile)
 376         }
 377
 378         // Temporary file for stdout
 379         fdStdout, err := tempfile(cwdOrig, tgt)
 380         if err != nil {
 381                 cleanup()
 382                 return TgtError{tgtOrig, ErrLine(err)}
 383         }
 384         stdoutPath := fdStdout.Name()
 385         fdStdout.Close()
 386         tmpPath := stdoutPath + ".3" // and for $3
 387         tmpPathRel := mustRel(cwd, tmpPath)
 388         args = append(
 389                 args,
 390                 path.Join(dirPrefix, tgt),
 391                 path.Join(dirPrefix, basename),
 392                 tmpPathRel,
 393         )
 394         shCtx = fmt.Sprintf(
 395                 "sh: %s: %s %s cwd:%s dirprefix:%s",
 396                 tgtOrig, cmdName, args, cwd, dirPrefix,
 397         )
 398
 399         cmd := exec.Command(cmdName, args...)
 400         cmd.Dir = cwd
 401         // cmd.Stdin reads from /dev/null by default
 402         cmd.Env = append(os.Environ(), fmt.Sprintf("%s=%d", EnvLevel, Level+1))
 403         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDirPrefix, dirPrefix))
 404         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvBuildUUID, BuildUUID))
 405
 406         childStderrPrefixRaw := make([]byte, 8)
 407         if _, err = io.ReadFull(rand.Reader, childStderrPrefixRaw); err != nil {
 408                 panic(err)
 409         }
 410         childStderrPrefix := hex.EncodeToString(childStderrPrefixRaw)
 411         cmd.Env = append(cmd.Env, fmt.Sprintf(
 412                 "%s=%s", EnvStderrPrefix, childStderrPrefix,
 413         ))
 414
 415         fdNum := 0
 416         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgts)
 417         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsFd, 3+fdNum))
 418         fdNum++
 419         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgtsLock)
 420         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsLockFd, 3+fdNum))
 421         fdNum++
 422
 423         if FdStatus == nil {
 424                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvStatusFd))
 425         } else {
 426                 cmd.ExtraFiles = append(cmd.ExtraFiles, FdStatus)
 427                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvStatusFd, 3+fdNum))
 428                 fdNum++
 429         }
 430
 431         // Preparing stderr
 432         var fdStderr *os.File
 433         if StderrKeep {
 434                 fdStderr, err = os.OpenFile(
 435                         path.Join(redoDir, tgt+LogSuffix),
 436                         os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
 437                         os.FileMode(0666),
 438                 )
 439                 if err != nil {
 440                         cleanup()
 441                         return TgtError{tgtOrig, ErrLine(err)}
 442                 }
 443         }
 444         tracef(CDebug, "%s", shCtx)
 445
 446         jsNeedsRelease = false
 447         Jobs.Add(1)
 448         go func() {
 449                 if JSR == nil {
 450                         // infinite jobs
 451                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvJobs))
 452                 } else {
 453                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSR)
 454                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSW)
 455                         makeFlags := fmt.Sprintf(
 456                                 "%s %s%d,%d", MakeFlags, MakeJSArg, 3+fdNum+0, 3+fdNum+1,
 457                         )
 458                         makeFlags = strings.Trim(makeFlags, " ")
 459                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", MakeFlagsName, makeFlags))
 460                         fdNum += 2
 461                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvJSToken, jsToken))
 462                 }
 463
 464                 if FdStatus != nil {
 465                         if _, err = FdStatus.Write([]byte{StatusRun}); err != nil {
 466                                 log.Fatal(err)
 467                         }
 468                 }
 469
 470                 defer jsRelease(shCtx, jsToken)
 471
 472                 var finished time.Time
 473                 var exitErr *exec.ExitError
 474                 started := time.Now()
 475                 runErr.Started = &started
 476                 fdStdout, err = os.OpenFile(stdoutPath, os.O_RDWR, os.FileMode(0666))
 477                 if err != nil {
 478                         if fdStderr != nil {
 479                                 fdStderr.Close()
 480                         }
 481                         runErr.Err = err
 482                         errs <- runErr
 483                         return
 484                 }
 485                 cmd.Stdout = fdStdout
 486                 fdDep, err = os.OpenFile(fdDepPath, os.O_WRONLY|os.O_APPEND, os.FileMode(0666))
 487                 if err != nil {
 488                         if fdStderr != nil {
 489                                 fdStderr.Close()
 490                         }
 491                         fdStdout.Close()
 492                         runErr.Err = err
 493                         errs <- runErr
 494                         return
 495                 }
 496                 cmd.ExtraFiles = append(cmd.ExtraFiles, fdDep)
 497                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvDepFd, 3+fdNum))
 498                 fdNum++
 499                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDepCwd, cwd))
 500
 501                 defer func() {
 502                         fdDep.Close()
 503                         fdStdout.Close()
 504                         if fdStderr != nil {
 505                                 fdStderr.Close()
 506                                 logRecPath := path.Join(redoDir, tgt+LogRecSuffix)
 507                                 if fdStderr, err = os.OpenFile(
 508                                         logRecPath,
 509                                         os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
 510                                         os.FileMode(0666),
 511                                 ); err == nil {
 512                                         fields := []recfile.Field{
 513                                                 {Name: "Build", Value: BuildUUID},
 514                                                 {Name: "PPID", Value: strconv.Itoa(os.Getpid())},
 515                                                 {Name: "Cwd", Value: cwd},
 516                                         }
 517                                         if cmd.Process != nil {
 518                                                 fields = append(fields, recfile.Field{
 519                                                         Name: "PID", Value: strconv.Itoa(cmd.Process.Pid),
 520                                                 })
 521                                         }
 522                                         ts := new(tai64n.TAI64N)
 523                                         ts.FromTime(started)
 524                                         fields = append(fields,
 525                                                 recfile.Field{Name: "Started", Value: tai64n.Encode(ts[:])},
 526                                         )
 527                                         ts.FromTime(finished)
 528                                         fields = append(fields,
 529                                                 recfile.Field{Name: "Finished", Value: tai64n.Encode(ts[:])})
 530                                         fields = append(fields, recfile.Field{
 531                                                 Name:  "Duration",
 532                                                 Value: strconv.FormatInt(finished.Sub(started).Nanoseconds(), 10),
 533                                         })
 534                                         fields = append(fields, recfile.Field{Name: "Cmd", Value: cmdName})
 535                                         for _, arg := range args {
 536                                                 fields = append(fields, recfile.Field{Name: "Arg", Value: arg})
 537                                         }
 538                                         for _, env := range cmd.Env {
 539                                                 fields = append(fields, recfile.Field{Name: "Env", Value: env})
 540                                         }
 541                                         if exitErr != nil {
 542                                                 fields = append(fields, recfile.Field{
 543                                                         Name:  "ExitCode",
 544                                                         Value: strconv.Itoa(exitErr.ProcessState.ExitCode()),
 545                                                 })
 546                                         }
 547                                         w := bufio.NewWriter(fdStderr)
 548
 549                                         var depInfo *DepInfo
 550                                         fdDep, err := os.Open(fdDepPath)
 551                                         if err != nil {
 552                                                 err = ErrLine(err)
 553                                                 goto Err
 554                                         }
 555                                         depInfo, err = depRead(fdDep)
 556                                         fdDep.Close()
 557                                         if err != nil {
 558                                                 err = ErrLine(err)
 559                                                 goto Err
 560                                         }
 561                                         for _, dep := range depInfo.ifchanges {
 562                                                 fields = append(fields, recfile.Field{
 563                                                         Name:  "Ifchange",
 564                                                         Value: dep["Target"],
 565                                                 })
 566                                         }
 567                                         _, err = recfile.NewWriter(w).WriteFields(fields...)
 568                                         if err != nil {
 569                                                 err = ErrLine(err)
 570                                                 goto Err
 571                                         }
 572                                         err = ErrLine(w.Flush())
 573                                 Err:
 574                                         if err != nil {
 575                                                 log.Print(err)
 576                                                 os.Remove(logRecPath)
 577                                         }
 578                                         fdStderr.Close()
 579                                 } else {
 580                                         log.Println("can not open", logRecPath, ":", err)
 581                                 }
 582                         }
 583                         lockRelease()
 584                         os.Remove(fdDep.Name())
 585                         os.Remove(fdStdout.Name())
 586                         os.Remove(tmpPath)
 587                         if FdStatus != nil {
 588                                 if _, err = FdStatus.Write([]byte{StatusDone}); err != nil {
 589                                         log.Fatal(err)
 590                                 }
 591                         }
 592                         Jobs.Done()
 593                 }()
 594                 stderr, err := cmd.StderrPipe()
 595                 if err != nil {
 596                         runErr.Err = err
 597                         errs <- runErr
 598                         return
 599                 }
 600                 started = time.Now()
 601                 err = cmd.Start()
 602                 if err != nil {
 603                         runErr.Err = err
 604                         errs <- runErr
 605                         return
 606                 }
 607                 RunningProcsM.Lock()
 608                 RunningProcs[cmd.Process.Pid] = cmd.Process
 609                 RunningProcsM.Unlock()
 610                 pid := fmt.Sprintf("[%d]", cmd.Process.Pid)
 611                 tracef(CDebug, "%s runs %s", tgtOrig, pid)
 612
 613                 stderrTerm := make(chan struct{})
 614                 go func() {
 615                         scanner := bufio.NewScanner(stderr)
 616                         var line string
 617                         ts := new(tai64n.TAI64N)
 618                         for scanner.Scan() {
 619                                 line = scanner.Text()
 620                                 if strings.HasPrefix(line, childStderrPrefix) {
 621                                         line = line[len(childStderrPrefix):]
 622                                         os.Stderr.WriteString(StderrPrefix + line + "\n")
 623                                         continue
 624                                 }
 625                                 if fdStderr != nil {
 626                                         ts.FromTime(time.Now())
 627                                         LogMutex.Lock()
 628                                         fmt.Fprintln(fdStderr, tai64n.Encode(ts[:]), line)
 629                                         LogMutex.Unlock()
 630                                 }
 631                                 if StderrSilent {
 632                                         continue
 633                                 }
 634                                 if MyPid == 0 {
 635                                         tracef(CNone, "%s", line)
 636                                 } else {
 637                                         tracef(CNone, "%s %s", pid, line)
 638                                 }
 639                         }
 640                         close(stderrTerm)
 641                 }()
 642
 643                 // Wait for job completion
 644                 <-stderrTerm
 645                 err = cmd.Wait()
 646                 RunningProcsM.Lock()
 647                 delete(RunningProcs, cmd.Process.Pid)
 648                 RunningProcsM.Unlock()
 649                 finished = time.Now()
 650                 runErr.Finished = &finished
 651                 if err != nil {
 652                         exitErr = err.(*exec.ExitError)
 653                         runErr.Err = err
 654                         errs <- runErr
 655                         return
 656                 }
 657
 658                 // Was $1 touched?
 659                 if inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
 660                         if inodePrev == nil {
 661                                 runErr.Err = Err1WasTouched
 662                                 errs <- runErr
 663                                 return
 664                         }
 665                         if err != nil {
 666                                 runErr.Err = err
 667                                 errs <- runErr
 668                                 return
 669                         }
 670                         if !inode.Equals(inodePrev) {
 671                                 runErr.Err = Err1WasTouched
 672                                 errs <- runErr
 673                                 return
 674                         }
 675                 }
 676
 677                 if inodePrev != nil {
 678                         if inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
 679                                 if !inode.Equals(inodePrev) {
 680                                         runErr.Err = Err1WasTouched
 681                                         errs <- runErr
 682                                         return
 683                                 }
 684                         }
 685                 }
 686
 687                 // Does it produce both stdout and tmp?
 688                 fiStdout, err := os.Stat(fdStdout.Name())
 689                 if err != nil {
 690                         runErr.Err = ErrLine(err)
 691                         errs <- runErr
 692                         return
 693                 }
 694                 tmpExists := false
 695                 _, err = os.Stat(tmpPath)
 696                 if err == nil {
 697                         if fiStdout.Size() > 0 {
 698                                 runErr.Err = errors.New("created both tmp and stdout")
 699                                 errs <- runErr
 700                                 return
 701                         }
 702                         tmpExists = true
 703                 } else if !errors.Is(err, fs.ErrNotExist) {
 704                         runErr.Err = ErrLine(err)
 705                         errs <- runErr
 706                         return
 707                 }
 708
 709                 // Determine what file we must process at last
 710                 var fd *os.File
 711                 if tmpExists {
 712                         fd, err = os.Open(tmpPath)
 713                         if err != nil {
 714                                 err = ErrLine(err)
 715                                 goto Finish
 716                         }
 717                         defer fd.Close()
 718                 } else if fiStdout.Size() > 0 {
 719                         fd = fdStdout
 720                 }
 721
 722                 // Do we need to ifcreate it, or ifchange with renaming?
 723                 if fd == nil {
 724                         os.Remove(path.Join(cwdOrig, tgt))
 725                         err = ifcreate(fdDep, tgt)
 726                         if err != nil {
 727                                 err = ErrLine(err)
 728                                 goto Finish
 729                         }
 730                 } else {
 731                         var hsh string
 732                         if hshPrev != "" {
 733                                 _, err = fd.Seek(0, io.SeekStart)
 734                                 if err != nil {
 735                                         err = ErrLine(err)
 736                                         goto Finish
 737                                 }
 738                                 hsh, err = fileHash(fd)
 739                                 if err != nil {
 740                                         err = ErrLine(err)
 741                                         goto Finish
 742                                 }
 743                                 if hsh == hshPrev {
 744                                         tracef(CDebug, "%s has same hash, not renaming", tgtOrig)
 745                                         err = ErrLine(os.Remove(fd.Name()))
 746                                         if err != nil {
 747                                                 goto Finish
 748                                         }
 749                                         err = ErrLine(os.Chtimes(path.Join(cwdOrig, tgt), finished, finished))
 750                                         if err != nil {
 751                                                 goto Finish
 752                                         }
 753                                         if !NoSync {
 754                                                 err = ErrLine(syncDir(cwdOrig))
 755                                                 if err != nil {
 756                                                         goto Finish
 757                                                 }
 758                                         }
 759                                         err = ErrLine(depWrite(fdDep, cwdOrig, tgt, hshPrev))
 760                                         if err != nil {
 761                                                 goto Finish
 762                                         }
 763                                         goto RecCommit
 764                                 }
 765                         }
 766                         if !NoSync {
 767                                 err = ErrLine(fd.Sync())
 768                                 if err != nil {
 769                                         goto Finish
 770                                 }
 771                         }
 772                         err = ErrLine(os.Rename(fd.Name(), path.Join(cwdOrig, tgt)))
 773                         if err != nil {
 774                                 goto Finish
 775                         }
 776                         if !NoSync {
 777                                 err = ErrLine(syncDir(cwdOrig))
 778                                 if err != nil {
 779                                         goto Finish
 780                                 }
 781                         }
 782                         err = ErrLine(depWrite(fdDep, cwdOrig, tgt, hsh))
 783                         if err != nil {
 784                                 goto Finish
 785                         }
 786                 }
 787
 788         RecCommit:
 789                 // Commit .rec
 790                 if !NoSync {
 791                         err = ErrLine(fdDep.Sync())
 792                         if err != nil {
 793                                 goto Finish
 794                         }
 795                 }
 796                 fdDepPath = path.Join(redoDir, tgt+DepSuffix)
 797                 err = ErrLine(os.Rename(fdDep.Name(), fdDepPath))
 798                 if err != nil {
 799                         goto Finish
 800                 }
 801                 if !NoSync {
 802                         err = ErrLine(syncDir(redoDir))
 803                         if err != nil {
 804                                 goto Finish
 805                         }
 806                 }
 807
 808                 // Post-commit .rec sanitizing
 809                 fdDep.Close()
 810                 if fdDepR, err := os.Open(fdDepPath); err == nil {
 811                         depInfo, err := depRead(fdDepR)
 812                         fdDepR.Close()
 813                         if err != nil {
 814                                 err = ErrLine(err)
 815                                 goto Finish
 816                         }
 817                         ifchangeSeen := make(map[string]struct{}, len(depInfo.ifchanges))
 818                         for _, dep := range depInfo.ifchanges {
 819                                 ifchangeSeen[dep["Target"]] = struct{}{}
 820                         }
 821                         for _, dep := range depInfo.ifcreates {
 822                                 if _, exists := ifchangeSeen[dep]; exists {
 823                                         tracef(CWarn, "simultaneous ifcreate and ifchange records: %s", tgt)
 824                                 }
 825                         }
 826                 }
 827
 828         Finish:
 829                 runErr.Err = err
 830                 errs <- runErr
 831         }()
 832         return nil
 833 }
 834
 835 func isOkRun(err error) bool {
 836         if err == nil {
 837                 return true
 838         }
 839         var runErr RunError
 840         if errors.As(err, &runErr) && runErr.Err == nil {
 841                 tracef(CRedo, "%s", runErr.Name())
 842                 return true
 843         }
 844         tracef(CErr, "%s", err)
 845         return false
 846 }