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