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                         var depInfo *DepInfo
 260                         fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
 261                         if err != nil {
 262                                 if os.IsNotExist(err) {
 263                                         err = errors.New("was not built: no .rec")
 264                                 }
 265                                 goto Finish
 266                         }
 267                         defer fdDep.Close()
 268                         depInfo, err = depRead(fdDep)
 269                         if err != nil {
 270                                 goto Finish
 271                         }
 272                         if depInfo.build != BuildUUID {
 273                                 err = errors.New("was not built: build differs")
 274                         }
 275                 Finish:
 276                         if err != nil {
 277                                 err = TgtError{tgtOrig, err}
 278                                 fdLock.Close()
 279                         }
 280                         errs <- err
 281                 }()
 282                 return nil
 283         }
 284
 285         // Check if it was already built in parallel
 286         if !forced {
 287                 if fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix)); err == nil {
 288                         depInfo, err := depRead(fdDep)
 289                         fdDep.Close()
 290                         if err == nil && depInfo.build == BuildUUID {
 291                                 lockRelease()
 292                                 errs <- nil
 293                                 return nil
 294                         }
 295                 }
 296         }
 297
 298         // Check if target is not modified externally
 299         modified, inodePrev, hshPrev, err := isModified(cwd, redoDir, tgt)
 300         if err != nil {
 301                 lockRelease()
 302                 return TgtError{tgtOrig, err}
 303         }
 304         if modified {
 305                 lockRelease()
 306                 if StopIfMod {
 307                         return fmt.Errorf("%s externally modified", tgtOrig)
 308                 }
 309                 tracef(CWarn, "%s externally modified: not redoing", tgtOrig)
 310                 go func() {
 311                         errs <- nil
 312                 }()
 313                 return nil
 314         }
 315
 316         // Start preparing .rec
 317         fdDep, err := tempfile(redoDir, tgt+DepSuffix)
 318         if err != nil {
 319                 lockRelease()
 320                 return TgtError{tgtOrig, ErrLine(err)}
 321         }
 322         fdDepPath := fdDep.Name()
 323         cleanup := func() {
 324                 lockRelease()
 325                 fdDep.Close()
 326                 os.Remove(fdDep.Name())
 327         }
 328         if _, err = recfile.NewWriter(fdDep).WriteFields(
 329                 recfile.Field{Name: "Build", Value: BuildUUID},
 330         ); err != nil {
 331                 cleanup()
 332                 return TgtError{tgtOrig, ErrLine(err)}
 333         }
 334
 335         // Find .do
 336         doFile, upLevels, err := findDo(fdDep, cwd, tgt)
 337         if err != nil {
 338                 cleanup()
 339                 return TgtError{tgtOrig, ErrLine(err)}
 340         }
 341         if doFile == "" {
 342                 cleanup()
 343                 return TgtError{tgtOrig, errors.New("no .do found")}
 344         }
 345
 346         // Determine basename and DIRPREFIX
 347         doFileRelPath := doFile
 348         ents := strings.Split(cwd, "/")
 349         ents = ents[len(ents)-upLevels:]
 350         dirPrefix := path.Join(ents...)
 351         cwdOrig := cwd
 352         for i := 0; i < upLevels; i++ {
 353                 cwd = path.Join(cwd, "..")
 354                 doFileRelPath = path.Join("..", doFileRelPath)
 355         }
 356         cwd = path.Clean(cwd)
 357         doFilePath := path.Join(cwd, doFile)
 358         basename := tgt
 359         runErr := RunError{Tgt: tgtOrig}
 360         if strings.HasPrefix(doFile, "default.") {
 361                 basename = tgt[:len(tgt)-(len(doFile)-len("default.")-len(".do"))-1]
 362                 runErr.DoFile = doFileRelPath
 363         }
 364
 365         if err = depWrite(fdDep, cwdOrig, doFileRelPath, ""); err != nil {
 366                 cleanup()
 367                 return TgtError{tgtOrig, ErrLine(err)}
 368         }
 369         fdDep.Close()
 370         tracef(CWait, "%s", runErr.Name())
 371
 372         // Prepare command line
 373         var cmdName string
 374         var args []string
 375         if err = unix.Access(doFilePath, unix.X_OK); err == nil {
 376                 cmdName = doFilePath
 377                 args = make([]string, 0, 3)
 378         } else {
 379                 cmdName = "/bin/sh"
 380                 if traced || TracedAll {
 381                         args = append(args, "-ex")
 382                 } else {
 383                         args = append(args, "-e")
 384                 }
 385                 args = append(args, doFile)
 386         }
 387
 388         // Temporary file for stdout
 389         fdStdout, err := tempfile(cwdOrig, tgt)
 390         if err != nil {
 391                 cleanup()
 392                 return TgtError{tgtOrig, ErrLine(err)}
 393         }
 394         stdoutPath := fdStdout.Name()
 395         fdStdout.Close()
 396         tmpPath := stdoutPath + ".3" // and for $3
 397         tmpPathRel := mustRel(cwd, tmpPath)
 398         args = append(
 399                 args,
 400                 path.Join(dirPrefix, tgt),
 401                 path.Join(dirPrefix, basename),
 402                 tmpPathRel,
 403         )
 404         shCtx = fmt.Sprintf(
 405                 "sh: %s: %s %s cwd:%s dirprefix:%s",
 406                 tgtOrig, cmdName, args, cwd, dirPrefix,
 407         )
 408
 409         cmd := exec.Command(cmdName, args...)
 410         cmd.Dir = cwd
 411         // cmd.Stdin reads from /dev/null by default
 412         cmd.Env = append(os.Environ(), fmt.Sprintf("%s=%d", EnvLevel, Level+1))
 413         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDirPrefix, dirPrefix))
 414         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvBuildUUID, BuildUUID))
 415
 416         childStderrPrefixRaw := make([]byte, 8)
 417         if _, err = io.ReadFull(rand.Reader, childStderrPrefixRaw); err != nil {
 418                 panic(err)
 419         }
 420         childStderrPrefix := hex.EncodeToString(childStderrPrefixRaw)
 421         cmd.Env = append(cmd.Env, fmt.Sprintf(
 422                 "%s=%s", EnvStderrPrefix, childStderrPrefix,
 423         ))
 424
 425         fdNum := 0
 426         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgts)
 427         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsFd, 3+fdNum))
 428         fdNum++
 429         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgtsLock)
 430         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsLockFd, 3+fdNum))
 431         fdNum++
 432
 433         if FdStatus == nil {
 434                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvStatusFd))
 435         } else {
 436                 cmd.ExtraFiles = append(cmd.ExtraFiles, FdStatus)
 437                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvStatusFd, 3+fdNum))
 438                 fdNum++
 439         }
 440
 441         // Preparing stderr
 442         var fdStderr *os.File
 443         if StderrKeep {
 444                 fdStderr, err = os.OpenFile(
 445                         path.Join(redoDir, tgt+LogSuffix),
 446                         os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
 447                         os.FileMode(0666),
 448                 )
 449                 if err != nil {
 450                         cleanup()
 451                         return TgtError{tgtOrig, ErrLine(err)}
 452                 }
 453         }
 454         tracef(CDebug, "%s", shCtx)
 455
 456         jsNeedsRelease = false
 457         Jobs.Add(1)
 458         go func() {
 459                 if JSR == nil {
 460                         // infinite jobs
 461                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvJobs))
 462                 } else {
 463                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSR)
 464                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSW)
 465                         makeFlags := fmt.Sprintf(
 466                                 "%s %s%d,%d", MakeFlags, MakeJSArg, 3+fdNum+0, 3+fdNum+1,
 467                         )
 468                         makeFlags = strings.Trim(makeFlags, " ")
 469                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", MakeFlagsName, makeFlags))
 470                         fdNum += 2
 471                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvJSToken, jsToken))
 472                 }
 473
 474                 if FdStatus != nil {
 475                         if _, err = FdStatus.Write([]byte{StatusRun}); err != nil {
 476                                 log.Fatal(err)
 477                         }
 478                 }
 479
 480                 defer jsRelease(shCtx, jsToken)
 481
 482                 var finished time.Time
 483                 var exitErr *exec.ExitError
 484                 started := time.Now()
 485                 runErr.Started = &started
 486                 fdStdout, err = os.OpenFile(stdoutPath, os.O_RDWR, os.FileMode(0666))
 487                 if err != nil {
 488                         if fdStderr != nil {
 489                                 fdStderr.Close()
 490                         }
 491                         runErr.Err = err
 492                         errs <- runErr
 493                         return
 494                 }
 495                 cmd.Stdout = fdStdout
 496                 fdDep, err = os.OpenFile(fdDepPath, os.O_WRONLY|os.O_APPEND, os.FileMode(0666))
 497                 if err != nil {
 498                         if fdStderr != nil {
 499                                 fdStderr.Close()
 500                         }
 501                         fdStdout.Close()
 502                         runErr.Err = err
 503                         errs <- runErr
 504                         return
 505                 }
 506                 cmd.ExtraFiles = append(cmd.ExtraFiles, fdDep)
 507                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvDepFd, 3+fdNum))
 508                 fdNum++
 509                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDepCwd, cwd))
 510
 511                 defer func() {
 512                         fdDep.Close()
 513                         fdStdout.Close()
 514                         if fdStderr != nil {
 515                                 fdStderr.Close()
 516                                 logRecPath := path.Join(redoDir, tgt+LogRecSuffix)
 517                                 if fdStderr, err = os.OpenFile(
 518                                         logRecPath,
 519                                         os.O_WRONLY|os.O_CREATE|os.O_TRUNC,
 520                                         os.FileMode(0666),
 521                                 ); err == nil {
 522                                         fields := []recfile.Field{
 523                                                 {Name: "Build", Value: BuildUUID},
 524                                                 {Name: "PPID", Value: strconv.Itoa(os.Getpid())},
 525                                                 {Name: "Cwd", Value: cwd},
 526                                         }
 527                                         if cmd.Process != nil {
 528                                                 fields = append(fields, recfile.Field{
 529                                                         Name: "PID", Value: strconv.Itoa(cmd.Process.Pid),
 530                                                 })
 531                                         }
 532                                         ts := new(tai64n.TAI64N)
 533                                         ts.FromTime(started)
 534                                         fields = append(fields,
 535                                                 recfile.Field{Name: "Started", Value: tai64n.Encode(ts[:])},
 536                                         )
 537                                         ts.FromTime(finished)
 538                                         fields = append(fields,
 539                                                 recfile.Field{Name: "Finished", Value: tai64n.Encode(ts[:])})
 540                                         fields = append(fields, recfile.Field{
 541                                                 Name:  "Duration",
 542                                                 Value: strconv.FormatInt(finished.Sub(started).Nanoseconds(), 10),
 543                                         })
 544                                         fields = append(fields, recfile.Field{Name: "Cmd", Value: cmdName})
 545                                         for _, arg := range args {
 546                                                 fields = append(fields, recfile.Field{Name: "Arg", Value: arg})
 547                                         }
 548                                         for _, env := range cmd.Env {
 549                                                 fields = append(fields, recfile.Field{Name: "Env", Value: env})
 550                                         }
 551                                         if exitErr != nil {
 552                                                 fields = append(fields, recfile.Field{
 553                                                         Name:  "ExitCode",
 554                                                         Value: strconv.Itoa(exitErr.ProcessState.ExitCode()),
 555                                                 })
 556                                         }
 557                                         w := bufio.NewWriter(fdStderr)
 558
 559                                         var depInfo *DepInfo
 560                                         fdDep, err := os.Open(fdDepPath)
 561                                         if err != nil {
 562                                                 err = ErrLine(err)
 563                                                 goto Err
 564                                         }
 565                                         depInfo, err = depRead(fdDep)
 566                                         fdDep.Close()
 567                                         if err != nil {
 568                                                 err = ErrLine(err)
 569                                                 goto Err
 570                                         }
 571                                         for _, dep := range depInfo.ifchanges {
 572                                                 fields = append(fields, recfile.Field{
 573                                                         Name:  "Ifchange",
 574                                                         Value: dep["Target"],
 575                                                 })
 576                                         }
 577                                         _, err = recfile.NewWriter(w).WriteFields(fields...)
 578                                         if err != nil {
 579                                                 err = ErrLine(err)
 580                                                 goto Err
 581                                         }
 582                                         err = ErrLine(w.Flush())
 583                                 Err:
 584                                         if err != nil {
 585                                                 log.Print(err)
 586                                                 os.Remove(logRecPath)
 587                                         }
 588                                         fdStderr.Close()
 589                                 } else {
 590                                         log.Println("can not open", logRecPath, ":", err)
 591                                 }
 592                         }
 593                         lockRelease()
 594                         os.Remove(fdDep.Name())
 595                         os.Remove(fdStdout.Name())
 596                         os.Remove(tmpPath)
 597                         if FdStatus != nil {
 598                                 if _, err = FdStatus.Write([]byte{StatusDone}); err != nil {
 599                                         log.Fatal(err)
 600                                 }
 601                         }
 602                         Jobs.Done()
 603                 }()
 604                 stderr, err := cmd.StderrPipe()
 605                 if err != nil {
 606                         runErr.Err = err
 607                         errs <- runErr
 608                         return
 609                 }
 610                 started = time.Now()
 611                 err = cmd.Start()
 612                 if err != nil {
 613                         runErr.Err = err
 614                         errs <- runErr
 615                         return
 616                 }
 617                 RunningProcsM.Lock()
 618                 RunningProcs[cmd.Process.Pid] = cmd.Process
 619                 RunningProcsM.Unlock()
 620                 pid := fmt.Sprintf("[%d]", cmd.Process.Pid)
 621                 tracef(CDebug, "%s runs %s", tgtOrig, pid)
 622
 623                 stderrTerm := make(chan struct{})
 624                 go func() {
 625                         scanner := bufio.NewScanner(stderr)
 626                         var line string
 627                         ts := new(tai64n.TAI64N)
 628                         for scanner.Scan() {
 629                                 line = scanner.Text()
 630                                 if strings.HasPrefix(line, childStderrPrefix) {
 631                                         line = line[len(childStderrPrefix):]
 632                                         os.Stderr.WriteString(StderrPrefix + line + "\n")
 633                                         continue
 634                                 }
 635                                 if fdStderr != nil {
 636                                         ts.FromTime(time.Now())
 637                                         LogMutex.Lock()
 638                                         fmt.Fprintln(fdStderr, tai64n.Encode(ts[:]), line)
 639                                         LogMutex.Unlock()
 640                                 }
 641                                 if StderrSilent {
 642                                         continue
 643                                 }
 644                                 if MyPid == 0 {
 645                                         tracef(CNone, "%s", line)
 646                                 } else {
 647                                         tracef(CNone, "%s %s", pid, line)
 648                                 }
 649                         }
 650                         close(stderrTerm)
 651                 }()
 652
 653                 // Wait for job completion
 654                 <-stderrTerm
 655                 err = cmd.Wait()
 656                 RunningProcsM.Lock()
 657                 delete(RunningProcs, cmd.Process.Pid)
 658                 RunningProcsM.Unlock()
 659                 finished = time.Now()
 660                 runErr.Finished = &finished
 661                 if err != nil {
 662                         exitErr = err.(*exec.ExitError)
 663                         runErr.Err = err
 664                         errs <- runErr
 665                         return
 666                 }
 667
 668                 // Was $1 touched?
 669                 if inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
 670                         if inodePrev == nil {
 671                                 runErr.Err = Err1WasTouched
 672                                 errs <- runErr
 673                                 return
 674                         }
 675                         if err != nil {
 676                                 runErr.Err = err
 677                                 errs <- runErr
 678                                 return
 679                         }
 680                         if !inode.Equals(inodePrev) {
 681                                 runErr.Err = Err1WasTouched
 682                                 errs <- runErr
 683                                 return
 684                         }
 685                 }
 686
 687                 if inodePrev != nil {
 688                         if inode, err := inodeFromFileByPath(path.Join(cwdOrig, tgt)); err == nil {
 689                                 if !inode.Equals(inodePrev) {
 690                                         runErr.Err = Err1WasTouched
 691                                         errs <- runErr
 692                                         return
 693                                 }
 694                         }
 695                 }
 696
 697                 // Does it produce both stdout and tmp?
 698                 fiStdout, err := os.Stat(fdStdout.Name())
 699                 if err != nil {
 700                         runErr.Err = ErrLine(err)
 701                         errs <- runErr
 702                         return
 703                 }
 704                 tmpExists := false
 705                 _, err = os.Stat(tmpPath)
 706                 if err == nil {
 707                         if fiStdout.Size() > 0 {
 708                                 runErr.Err = errors.New("created both tmp and stdout")
 709                                 errs <- runErr
 710                                 return
 711                         }
 712                         tmpExists = true
 713                 } else if !os.IsNotExist(err) {
 714                         runErr.Err = ErrLine(err)
 715                         errs <- runErr
 716                         return
 717                 }
 718
 719                 // Determine what file we must process at last
 720                 var fd *os.File
 721                 if tmpExists {
 722                         fd, err = os.Open(tmpPath)
 723                         if err != nil {
 724                                 err = ErrLine(err)
 725                                 goto Finish
 726                         }
 727                         defer fd.Close()
 728                 } else if fiStdout.Size() > 0 {
 729                         fd = fdStdout
 730                 }
 731
 732                 // Do we need to ifcreate it, or ifchange with renaming?
 733                 if fd == nil {
 734                         os.Remove(path.Join(cwdOrig, tgt))
 735                         err = ifcreate(fdDep, tgt)
 736                         if err != nil {
 737                                 err = ErrLine(err)
 738                                 goto Finish
 739                         }
 740                 } else {
 741                         var hsh string
 742                         if hshPrev != "" {
 743                                 _, err = fd.Seek(0, io.SeekStart)
 744                                 if err != nil {
 745                                         err = ErrLine(err)
 746                                         goto Finish
 747                                 }
 748                                 hsh, err = fileHash(fd)
 749                                 if err != nil {
 750                                         err = ErrLine(err)
 751                                         goto Finish
 752                                 }
 753                                 if hsh == hshPrev {
 754                                         tracef(CDebug, "%s has same hash, not renaming", tgtOrig)
 755                                         err = ErrLine(os.Remove(fd.Name()))
 756                                         if err != nil {
 757                                                 goto Finish
 758                                         }
 759                                         err = ErrLine(os.Chtimes(path.Join(cwdOrig, tgt), finished, finished))
 760                                         if err != nil {
 761                                                 goto Finish
 762                                         }
 763                                         if !NoSync {
 764                                                 err = ErrLine(syncDir(cwdOrig))
 765                                                 if err != nil {
 766                                                         goto Finish
 767                                                 }
 768                                         }
 769                                         err = ErrLine(depWrite(fdDep, cwdOrig, tgt, hshPrev))
 770                                         if err != nil {
 771                                                 goto Finish
 772                                         }
 773                                         goto RecCommit
 774                                 }
 775                         }
 776                         if !NoSync {
 777                                 err = ErrLine(fd.Sync())
 778                                 if err != nil {
 779                                         goto Finish
 780                                 }
 781                         }
 782                         err = ErrLine(os.Rename(fd.Name(), path.Join(cwdOrig, tgt)))
 783                         if err != nil {
 784                                 goto Finish
 785                         }
 786                         if !NoSync {
 787                                 err = ErrLine(syncDir(cwdOrig))
 788                                 if err != nil {
 789                                         goto Finish
 790                                 }
 791                         }
 792                         err = ErrLine(depWrite(fdDep, cwdOrig, tgt, hsh))
 793                         if err != nil {
 794                                 goto Finish
 795                         }
 796                 }
 797
 798         RecCommit:
 799                 // Commit .rec
 800                 if !NoSync {
 801                         err = ErrLine(fdDep.Sync())
 802                         if err != nil {
 803                                 goto Finish
 804                         }
 805                 }
 806                 fdDepPath = path.Join(redoDir, tgt+DepSuffix)
 807                 err = ErrLine(os.Rename(fdDep.Name(), fdDepPath))
 808                 if err != nil {
 809                         goto Finish
 810                 }
 811                 if !NoSync {
 812                         err = ErrLine(syncDir(redoDir))
 813                         if err != nil {
 814                                 goto Finish
 815                         }
 816                 }
 817
 818                 // Post-commit .rec sanitizing
 819                 fdDep.Close()
 820                 if fdDepR, err := os.Open(fdDepPath); err == nil {
 821                         depInfo, err := depRead(fdDepR)
 822                         fdDepR.Close()
 823                         if err != nil {
 824                                 err = ErrLine(err)
 825                                 goto Finish
 826                         }
 827                         ifchangeSeen := make(map[string]struct{}, len(depInfo.ifchanges))
 828                         for _, dep := range depInfo.ifchanges {
 829                                 ifchangeSeen[dep["Target"]] = struct{}{}
 830                         }
 831                         for _, dep := range depInfo.ifcreates {
 832                                 if _, exists := ifchangeSeen[dep]; exists {
 833                                         tracef(CWarn, "simultaneous ifcreate and ifchange records: %s", tgt)
 834                                 }
 835                         }
 836                 }
 837
 838         Finish:
 839                 runErr.Err = err
 840                 errs <- runErr
 841         }()
 842         return nil
 843 }
 844
 845 func isOkRun(err error) bool {
 846         if err == nil {
 847                 return true
 848         }
 849         var runErr RunError
 850         if errors.As(err, &runErr) && runErr.Err == nil {
 851                 tracef(CRedo, "%s", runErr.Name())
 852                 return true
 853         }
 854         tracef(CErr, "%s", err)
 855         return false
 856 }