]> Cypherpunks.ru repositories - goredo.git/blob - run.go
No .rec required for recursive logs
[goredo.git] / run.go
1 /*
2 goredo -- djb's redo implementation on pure Go
3 Copyright (C) 2020-2021 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         "errors"
25         "flag"
26         "fmt"
27         "io"
28         "log"
29         "os"
30         "os/exec"
31         "path"
32         "path/filepath"
33         "strconv"
34         "strings"
35         "sync"
36         "syscall"
37         "time"
38
39         "go.cypherpunks.ru/recfile"
40         "go.cypherpunks.ru/tai64n/v2"
41         "golang.org/x/sys/unix"
42 )
43
44 const (
45         EnvDepFd        = "REDO_DEP_FD"
46         EnvDirPrefix    = "REDO_DIRPREFIX"
47         EnvDepCwd       = "REDO_DEP_CWD"
48         EnvBuildUUID    = "REDO_BUILD_UUID"
49         EnvStderrPrefix = "REDO_STDERR_PREFIX"
50         EnvTrace        = "REDO_TRACE"
51         EnvStderrKeep   = "REDO_LOGS"
52         EnvStderrSilent = "REDO_SILENT"
53         EnvNoSync       = "REDO_NO_SYNC"
54
55         RedoDir    = ".redo"
56         LockSuffix = ".lock"
57         DepSuffix  = ".rec"
58         TmpPrefix  = ".redo."
59         LogSuffix  = ".log"
60 )
61
62 var (
63         NoSync       bool = false
64         StderrKeep   bool = false
65         StderrSilent bool = false
66         StderrPrefix string
67         Jobs         sync.WaitGroup
68
69         flagTrace        *bool
70         flagTraceAll     *bool
71         flagStderrKeep   *bool
72         flagStderrSilent *bool
73
74         TracedAll bool
75 )
76
77 func init() {
78         cmdName := CmdName()
79         if !(cmdName == CmdNameRedo || cmdName == CmdNameRedoIfchange) {
80                 return
81         }
82         flagTrace = flag.Bool("x", false, "trace (sh -x) current targets")
83         flagTraceAll = flag.Bool("xx", false,
84                 fmt.Sprintf("trace (sh -x) all targets (%s=1)", EnvTrace))
85         flagStderrKeep = flag.Bool("k", false,
86                 fmt.Sprintf("keep job's stderr (%s=1)", EnvStderrKeep))
87         flagStderrSilent = flag.Bool("s", false,
88                 fmt.Sprintf("silent, do not print job's stderr (%s=1)", EnvStderrSilent))
89 }
90
91 type RunErr struct {
92         Tgt      string
93         DoFile   string
94         Started  *time.Time
95         Finished *time.Time
96         Err      error
97 }
98
99 func (e *RunErr) Name() string {
100         var name string
101         if e.DoFile == "" {
102                 name = e.Tgt
103         } else {
104                 name = fmt.Sprintf("%s (%s)", e.Tgt, e.DoFile)
105         }
106         if e.Finished == nil {
107                 return name
108         }
109         return fmt.Sprintf("%s (%.3fs)", name, e.Finished.Sub(*e.Started).Seconds())
110 }
111
112 func (e RunErr) Error() string {
113         return fmt.Sprintf("%s: %s", e.Name(), e.Err)
114 }
115
116 func mkdirs(pth string) error {
117         if _, err := os.Stat(pth); err == nil {
118                 return nil
119         }
120         return os.MkdirAll(pth, os.FileMode(0777))
121 }
122
123 func isModified(cwd, redoDir, tgt string) (bool, *Inode, error) {
124         fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
125         if err != nil {
126                 if os.IsNotExist(err) {
127                         return false, nil, nil
128                 }
129                 return false, nil, err
130         }
131         defer fdDep.Close()
132         r := recfile.NewReader(fdDep)
133         var ourInode *Inode
134         for {
135                 m, err := r.NextMap()
136                 if err != nil {
137                         if err == io.EOF {
138                                 break
139                         }
140                         return false, nil, err
141                 }
142                 if m["Target"] != tgt {
143                         continue
144                 }
145                 fd, err := os.Open(path.Join(cwd, tgt))
146                 if err != nil {
147                         if os.IsNotExist(err) {
148                                 return false, nil, nil
149                         }
150                         return false, nil, err
151                 }
152                 ourInode, err = inodeFromFile(fd)
153                 fd.Close()
154                 if err != nil {
155                         return false, nil, err
156                 }
157                 theirInode, err := inodeFromRec(m)
158                 if err != nil {
159                         return false, nil, err
160                 }
161                 if !ourInode.Equals(theirInode) {
162                         return true, ourInode, nil
163                 }
164                 break
165         }
166         return false, ourInode, nil
167 }
168
169 func syncDir(dir string) error {
170         fd, err := os.Open(dir)
171         if err != nil {
172                 return err
173         }
174         err = fd.Sync()
175         fd.Close()
176         return err
177 }
178
179 func runScript(tgtOrig string, errs chan error, traced bool) error {
180         cwd, tgt := cwdAndTgt(tgtOrig)
181         redoDir := path.Join(cwd, RedoDir)
182         if err := mkdirs(redoDir); err != nil {
183                 return TgtErr{tgtOrig, err}
184         }
185
186         // Acquire lock
187         fdLock, err := os.OpenFile(
188                 path.Join(redoDir, tgt+LockSuffix),
189                 os.O_WRONLY|os.O_TRUNC|os.O_CREATE,
190                 os.FileMode(0666),
191         )
192         if err != nil {
193                 return TgtErr{tgtOrig, err}
194         }
195         lockRelease := func() {
196                 trace(CLock, "LOCK_UN: %s", fdLock.Name())
197                 unix.Flock(int(fdLock.Fd()), unix.LOCK_UN)
198                 fdLock.Close()
199         }
200         trace(CLock, "LOCK_NB: %s", fdLock.Name())
201
202         // Waiting for job completion, already taken by someone else
203         if err = unix.Flock(int(fdLock.Fd()), unix.LOCK_EX|unix.LOCK_NB); err != nil {
204                 if uintptr(err.(syscall.Errno)) != uintptr(unix.EWOULDBLOCK) {
205                         fdLock.Close()
206                         return TgtErr{tgtOrig, err}
207                 }
208                 Jobs.Add(1)
209                 trace(CDebug, "waiting: %s", tgtOrig)
210                 if FdStatus != nil {
211                         FdStatus.Write([]byte{StatusWait})
212                 }
213                 go func() {
214                         defer Jobs.Done()
215                         trace(CLock, "LOCK_EX: %s", fdLock.Name())
216                         unix.Flock(int(fdLock.Fd()), unix.LOCK_EX)
217                         lockRelease()
218                         trace(CDebug, "waiting done: %s", tgtOrig)
219                         if FdStatus != nil {
220                                 FdStatus.Write([]byte{StatusWaited})
221                         }
222                         var depInfo *DepInfo
223                         fdDep, err := os.Open(path.Join(redoDir, tgt+DepSuffix))
224                         if err != nil {
225                                 if os.IsNotExist(err) {
226                                         err = errors.New("was not built: no .rec")
227                                 }
228                                 goto Finish
229                         }
230                         defer fdDep.Close()
231                         depInfo, err = depRead(fdDep)
232                         if err != nil {
233                                 goto Finish
234                         }
235                         if depInfo.build != BuildUUID {
236                                 err = errors.New("was not built: build differs")
237                         }
238                 Finish:
239                         if err != nil {
240                                 err = TgtErr{tgtOrig, err}
241                         }
242                         errs <- err
243                 }()
244                 return nil
245         }
246
247         // Check if target is not modified externally
248         modified, inodePrev, err := isModified(cwd, redoDir, tgt)
249         if err != nil {
250                 lockRelease()
251                 return TgtErr{tgtOrig, err}
252         }
253         if modified {
254                 trace(CWarn, "%s externally modified: not redoing", tgtOrig)
255                 lockRelease()
256                 go func() {
257                         errs <- nil
258                 }()
259                 return nil
260         }
261
262         // Start preparing .rec
263         fdDep, err := tempfile(redoDir, tgt+DepSuffix)
264         if err != nil {
265                 lockRelease()
266                 return TgtErr{tgtOrig, err}
267         }
268         fdDepPath := fdDep.Name()
269         cleanup := func() {
270                 lockRelease()
271                 fdDep.Close()
272                 os.Remove(fdDep.Name())
273         }
274         if _, err = recfile.NewWriter(fdDep).WriteFields(
275                 recfile.Field{Name: "Build", Value: BuildUUID},
276         ); err != nil {
277                 cleanup()
278                 return TgtErr{tgtOrig, err}
279         }
280
281         // Find .do
282         doFile, upLevels, err := findDo(fdDep, cwd, tgt)
283         if err != nil {
284                 cleanup()
285                 return TgtErr{tgtOrig, err}
286         }
287         if doFile == "" {
288                 cleanup()
289                 return TgtErr{tgtOrig, errors.New("no .do found")}
290         }
291
292         // Determine basename and DIRPREFIX
293         doFileRelPath := doFile
294         ents := strings.Split(cwd, "/")
295         ents = ents[len(ents)-upLevels:]
296         dirPrefix := path.Join(ents...)
297         cwdOrig := cwd
298         for i := 0; i < upLevels; i++ {
299                 cwd = path.Join(cwd, "..")
300                 doFileRelPath = path.Join("..", doFileRelPath)
301         }
302         cwd = path.Clean(cwd)
303         doFilePath := path.Join(cwd, doFile)
304         basename := tgt
305         runErr := RunErr{Tgt: tgtOrig}
306         if strings.HasPrefix(doFile, "default.") {
307                 basename = tgt[:len(tgt)-(len(doFile)-len("default.")-len(".do"))-1]
308                 runErr.DoFile = doFileRelPath
309         }
310
311         if err = writeDep(fdDep, cwdOrig, doFileRelPath); err != nil {
312                 cleanup()
313                 return TgtErr{tgtOrig, err}
314         }
315         fdDep.Close()
316         trace(CWait, "%s", runErr.Name())
317
318         // Prepare command line
319         var cmdName string
320         var args []string
321         if err = unix.Access(doFilePath, unix.X_OK); err == nil {
322                 cmdName = doFilePath
323                 args = make([]string, 0, 3)
324         } else {
325                 cmdName = "/bin/sh"
326                 if traced || TracedAll {
327                         args = append(args, "-ex")
328                 } else {
329                         args = append(args, "-e")
330                 }
331                 args = append(args, doFile)
332         }
333
334         // Temporary file for stdout
335         fdStdout, err := tempfile(cwdOrig, tgt)
336         if err != nil {
337                 cleanup()
338                 return TgtErr{tgtOrig, err}
339         }
340         stdoutPath := fdStdout.Name()
341         fdStdout.Close()
342         tmpPath := stdoutPath + ".3" // and for $3
343         tmpPathRel, err := filepath.Rel(cwd, tmpPath)
344         if err != nil {
345                 panic(err)
346         }
347         args = append(
348                 args,
349                 path.Join(dirPrefix, tgt),
350                 path.Join(dirPrefix, basename),
351                 tmpPathRel,
352         )
353
354         cmd := exec.Command(cmdName, args...)
355         cmd.Dir = cwd
356         // cmd.Stdin reads from /dev/null by default
357         cmd.Env = append(os.Environ(), fmt.Sprintf("%s=%d", EnvLevel, Level+1))
358         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDirPrefix, dirPrefix))
359         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvBuildUUID, BuildUUID))
360
361         childStderrPrefix := tempsuffix()
362         cmd.Env = append(cmd.Env, fmt.Sprintf(
363                 "%s=%s", EnvStderrPrefix, childStderrPrefix,
364         ))
365
366         fdNum := 0
367         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgts)
368         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsFd, 3+fdNum))
369         fdNum++
370         cmd.ExtraFiles = append(cmd.ExtraFiles, FdOODTgtsLock)
371         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvOODTgtsLockFd, 3+fdNum))
372         fdNum++
373
374         if FdStatus == nil {
375                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvStatusFd))
376         } else {
377                 cmd.ExtraFiles = append(cmd.ExtraFiles, FdStatus)
378                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvStatusFd, 3+fdNum))
379                 fdNum++
380         }
381
382         // Preparing stderr
383         var fdStderr *os.File
384         if StderrKeep {
385                 fdStderr, err = os.OpenFile(
386                         path.Join(redoDir, tgt+LogSuffix),
387                         os.O_WRONLY|os.O_CREATE,
388                         os.FileMode(0666),
389                 )
390                 if err != nil {
391                         cleanup()
392                         return TgtErr{tgtOrig, err}
393                 }
394                 fdStderr.Truncate(0)
395         }
396         shCtx := fmt.Sprintf(
397                 "sh: %s: %s %s cwd:%s dirprefix:%s",
398                 tgtOrig, cmdName, args, cwd, dirPrefix,
399         )
400         trace(CDebug, "%s", shCtx)
401
402         Jobs.Add(1)
403         go func() {
404                 jsToken := jsAcquire(shCtx)
405                 if JSR == nil {
406                         // infinite jobs
407                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=NO", EnvJobs))
408                 } else {
409                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSR)
410                         cmd.ExtraFiles = append(cmd.ExtraFiles, JSW)
411                         cmd.Env = append(cmd.Env, fmt.Sprintf(
412                                 "%s=%s %s%d,%d",
413                                 MakeFlagsName, MakeFlags, MakeJSArg, 3+fdNum+0, 3+fdNum+1,
414                         ))
415                         fdNum += 2
416                         cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvJSToken, jsToken))
417                 }
418
419                 if FdStatus != nil {
420                         FdStatus.Write([]byte{StatusRun})
421                 }
422
423                 var finished time.Time
424                 var exitErr *exec.ExitError
425                 started := time.Now()
426                 runErr.Started = &started
427                 fdStdout, err = os.OpenFile(stdoutPath, os.O_RDWR, os.FileMode(0666))
428                 if err != nil {
429                         runErr.Err = err
430                         errs <- runErr
431                         return
432                 }
433                 cmd.Stdout = fdStdout
434                 fdDep, err = os.OpenFile(fdDepPath, os.O_WRONLY|os.O_APPEND, os.FileMode(0666))
435                 if err != nil {
436                         runErr.Err = err
437                         errs <- runErr
438                         return
439                 }
440                 cmd.ExtraFiles = append(cmd.ExtraFiles, fdDep)
441                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%d", EnvDepFd, 3+fdNum))
442                 fdNum++
443                 cmd.Env = append(cmd.Env, fmt.Sprintf("%s=%s", EnvDepCwd, cwd))
444
445                 defer func() {
446                         jsRelease(shCtx, jsToken)
447                         fdDep.Close()
448                         fdStdout.Close()
449                         if fdStderr != nil {
450                                 fdStderr.Close()
451                                 logRecPath := path.Join(redoDir, tgt+LogSuffix+DepSuffix)
452                                 if fdStderr, err = os.OpenFile(
453                                         logRecPath,
454                                         os.O_WRONLY|os.O_CREATE,
455                                         os.FileMode(0666),
456                                 ); err == nil {
457                                         fdStderr.Truncate(0)
458                                         fields := []recfile.Field{
459                                                 {Name: "Build", Value: BuildUUID},
460                                                 {Name: "PID", Value: strconv.Itoa(cmd.Process.Pid)},
461                                                 {Name: "PPID", Value: strconv.Itoa(os.Getpid())},
462                                                 {Name: "Cwd", Value: cwd},
463                                         }
464                                         ts := new(tai64n.TAI64N)
465                                         ts.FromTime(started)
466                                         fields = append(fields,
467                                                 recfile.Field{Name: "Started", Value: tai64n.Encode(ts[:])},
468                                         )
469                                         ts.FromTime(finished)
470                                         fields = append(fields,
471                                                 recfile.Field{Name: "Finished", Value: tai64n.Encode(ts[:])})
472                                         fields = append(fields, recfile.Field{
473                                                 Name:  "Duration",
474                                                 Value: strconv.FormatInt(finished.Sub(started).Nanoseconds(), 10),
475                                         })
476                                         fields = append(fields, recfile.Field{Name: "Cmd", Value: cmdName})
477                                         for _, arg := range args {
478                                                 fields = append(fields, recfile.Field{Name: "Cmd", Value: arg})
479                                         }
480                                         for _, env := range cmd.Env {
481                                                 fields = append(fields, recfile.Field{Name: "Env", Value: env})
482                                         }
483                                         if exitErr != nil {
484                                                 fields = append(fields, recfile.Field{
485                                                         Name:  "ExitCode",
486                                                         Value: strconv.Itoa(exitErr.ProcessState.ExitCode()),
487                                                 })
488                                         }
489                                         w := bufio.NewWriter(fdStderr)
490
491                                         var depInfo *DepInfo
492                                         fdDep, err = os.Open(fdDep.Name())
493                                         if err != nil {
494                                                 goto Err
495                                         }
496                                         depInfo, err = depRead(fdDep)
497                                         fdDep.Close()
498                                         if err != nil {
499                                                 goto Err
500                                         }
501                                         for _, dep := range depInfo.ifchanges {
502                                                 fields = append(fields, recfile.Field{
503                                                         Name:  "Ifchange",
504                                                         Value: dep["Target"],
505                                                 })
506                                         }
507                                         _, err = recfile.NewWriter(w).WriteFields(fields...)
508                                         if err != nil {
509                                                 goto Err
510                                         }
511                                         err = w.Flush()
512                                 Err:
513                                         if err != nil {
514                                                 log.Println(err)
515                                                 os.Remove(logRecPath)
516                                         }
517                                         fdStderr.Close()
518                                 } else {
519                                         log.Println("can not open", logRecPath, ":", err)
520                                 }
521                         }
522                         lockRelease()
523                         os.Remove(fdDep.Name())
524                         os.Remove(fdStdout.Name())
525                         os.Remove(tmpPath)
526                         os.Remove(fdLock.Name())
527                         if FdStatus != nil {
528                                 FdStatus.Write([]byte{StatusDone})
529                         }
530                         Jobs.Done()
531                 }()
532                 stderr, err := cmd.StderrPipe()
533                 if err != nil {
534                         runErr.Err = err
535                         errs <- runErr
536                         return
537                 }
538                 started = time.Now()
539                 err = cmd.Start()
540                 if err != nil {
541                         runErr.Err = err
542                         errs <- runErr
543                         return
544                 }
545                 pid := fmt.Sprintf("[%d]", cmd.Process.Pid)
546                 trace(CDebug, "%s runs %s", tgtOrig, pid)
547
548                 stderrTerm := make(chan struct{}, 0)
549                 go func() {
550                         scanner := bufio.NewScanner(stderr)
551                         var line string
552                         ts := new(tai64n.TAI64N)
553                         for scanner.Scan() {
554                                 line = scanner.Text()
555                                 if strings.HasPrefix(line, childStderrPrefix) {
556                                         line = line[len(childStderrPrefix):]
557                                         os.Stderr.WriteString(StderrPrefix + line + "\n")
558                                         continue
559                                 }
560                                 if fdStderr != nil {
561                                         ts.FromTime(time.Now())
562                                         LogMutex.Lock()
563                                         fmt.Fprintln(fdStderr, tai64n.Encode(ts[:]), line)
564                                         LogMutex.Unlock()
565                                 }
566                                 if StderrSilent {
567                                         continue
568                                 }
569                                 if MyPid == 0 {
570                                         trace(CNone, "%s", line)
571                                 } else {
572                                         trace(CNone, "%s %s", pid, line)
573                                 }
574                         }
575                         close(stderrTerm)
576                 }()
577
578                 // Wait for job completion
579                 <-stderrTerm
580                 err = cmd.Wait()
581                 finished = time.Now()
582                 runErr.Finished = &finished
583                 if err != nil {
584                         exitErr = err.(*exec.ExitError)
585                         runErr.Err = err
586                         errs <- runErr
587                         return
588                 }
589
590                 // Was $1 touched?
591                 if inodePrev != nil {
592                         if fd, err := os.Open(path.Join(cwdOrig, tgt)); err == nil {
593                                 inode, err := inodeFromFile(fd)
594                                 fd.Close()
595                                 if err == nil && !inode.Equals(inodePrev) {
596                                         runErr.Err = errors.New("$1 was explicitly touched")
597                                         errs <- runErr
598                                         return
599                                 }
600                         }
601                 }
602
603                 // Does it produce both stdout and tmp?
604                 fiStdout, err := os.Stat(fdStdout.Name())
605                 if err != nil {
606                         runErr.Err = err
607                         errs <- runErr
608                         return
609                 }
610                 tmpExists := false
611                 _, err = os.Stat(tmpPath)
612                 if err == nil {
613                         if fiStdout.Size() > 0 {
614                                 runErr.Err = errors.New("created both tmp and stdout")
615                                 errs <- runErr
616                                 return
617                         }
618                         tmpExists = true
619                 } else if !os.IsNotExist(err) {
620                         runErr.Err = err
621                         errs <- runErr
622                         return
623                 }
624
625                 // Determine what file we must process at last
626                 var fd *os.File
627                 if tmpExists {
628                         fd, err = os.Open(tmpPath)
629                         if err != nil {
630                                 goto Finish
631                         }
632                         defer fd.Close()
633                 } else if fiStdout.Size() > 0 {
634                         fd = fdStdout
635                 }
636
637                 // Do we need to ifcreate it, of ifchange with renaming?
638                 if fd == nil {
639                         os.Remove(path.Join(cwdOrig, tgt))
640                         err = ifcreate(fdDep, tgt)
641                         if err != nil {
642                                 goto Finish
643                         }
644                 } else {
645                         if !NoSync {
646                                 err = fd.Sync()
647                                 if err != nil {
648                                         goto Finish
649                                 }
650                         }
651                         err = os.Rename(fd.Name(), path.Join(cwdOrig, tgt))
652                         if err != nil {
653                                 goto Finish
654                         }
655                         if !NoSync {
656                                 err = syncDir(cwdOrig)
657                                 if err != nil {
658                                         goto Finish
659                                 }
660                         }
661                         err = writeDep(fdDep, cwdOrig, tgt)
662                         if err != nil {
663                                 goto Finish
664                         }
665                 }
666
667                 // Commit .rec
668                 if !NoSync {
669                         err = fdDep.Sync()
670                         if err != nil {
671                                 goto Finish
672                         }
673                 }
674                 err = os.Rename(fdDep.Name(), path.Join(redoDir, tgt+DepSuffix))
675                 if err != nil {
676                         goto Finish
677                 }
678                 if !NoSync {
679                         err = syncDir(redoDir)
680                         if err != nil {
681                                 goto Finish
682                         }
683                 }
684         Finish:
685                 runErr.Err = err
686                 errs <- runErr
687         }()
688         return nil
689 }
690
691 func isOkRun(err error) bool {
692         if err == nil {
693                 return true
694         }
695         if err, ok := err.(RunErr); ok && err.Err == nil {
696                 trace(CRedo, "%s", err.Name())
697                 return true
698         }
699         trace(CErr, "%s", err)
700         return false
701 }