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