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