Correctly report step start times

cmd/entrypoint/main.go

@@ -33,6 +33,7 @@ var (
 	waitFiles       = flag.String("wait_file", "", "Comma-separated list of paths to wait for")
 	waitFileContent = flag.Bool("wait_file_content", false, "If specified, expect wait_file to have content")
 	postFile        = flag.String("post_file", "", "If specified, file to write upon completion")
+	terminationPath = flag.String("termination_path", "/tekton/termination", "If specified, file to write upon termination")
 
 	waitPollingInterval = time.Second
 )
@@ -45,6 +46,7 @@ func main() {
 		WaitFiles:       strings.Split(*waitFiles, ","),
 		WaitFileContent: *waitFileContent,
 		PostFile:        *postFile,
+		TerminationPath: *terminationPath,
 		Args:            flag.Args(),
 		Waiter:          &realWaiter{},
 		Runner:          &realRunner{},

cmd/git-init/main.go

@@ -37,7 +37,7 @@ func init() {
 	flag.BoolVar(&fetchSpec.SSLVerify, "sslVerify", true, "Enable/Disable SSL verification in the git config")
 	flag.BoolVar(&submodules, "submodules", true, "Initialize and fetch Git submodules")
 	flag.UintVar(&fetchSpec.Depth, "depth", 1, "Perform a shallow clone to this depth")
-	flag.StringVar(&terminationMessagePath, "terminationMessagePath", "/dev/termination-log", "Location of file containing termination message")
+	flag.StringVar(&terminationMessagePath, "terminationMessagePath", "/tekton/termination", "Location of file containing termination message")
 }
 
 func main() {
@@ -68,5 +68,7 @@ func main() {
 		},
 	}
 
-	termination.WriteMessage(logger, terminationMessagePath, output)
+	if err := termination.WriteMessage(terminationMessagePath, output); err != nil {
+		logger.Fatalf("Error writing message to %s : %s", terminationMessagePath, err)
+	}
 }

cmd/imagedigestexporter/main.go

@@ -29,7 +29,7 @@ import (
 
 var (
 	images                 = flag.String("images", "", "List of images resources built by task in json format")
-	terminationMessagePath = flag.String("terminationMessagePath", "/dev/termination-log", "Location of file containing termination message")
+	terminationMessagePath = flag.String("terminationMessagePath", "/tekton/termination", "Location of file containing termination message")
 )
 
 /* The input of this go program will be a JSON string with all the output PipelineResources of type
@@ -78,5 +78,7 @@ func main() {
 
 	}
 
-	termination.WriteMessage(logger, *terminationMessagePath, output)
+	if err := termination.WriteMessage(*terminationMessagePath, output); err != nil {
+		logger.Fatalf("Unexpected error writing message %s to %s", *terminationMessagePath, err)
+	}
 }

pkg/entrypoint/entrypointer.go

@@ -18,6 +18,11 @@ package entrypoint
 
 import (
 	"fmt"
+	"time"
+
+	"github.com/tektoncd/pipeline/pkg/apis/pipeline/v1alpha1"
+	"github.com/tektoncd/pipeline/pkg/logging"
+	"github.com/tektoncd/pipeline/pkg/termination"
 )
 
 // Entrypointer holds fields for running commands with redirected
@@ -37,6 +42,9 @@ type Entrypointer struct {
 	// file is written.
 	PostFile string
 
+	// Termination path is the path of a file to write the starting time of this endpopint
+	TerminationPath string
+
 	// Waiter encapsulates waiting for files to exist.
 	Waiter Waiter
 	// Runner encapsulates running commands.
@@ -65,6 +73,11 @@ type PostWriter interface {
 // Go optionally waits for a file, runs the command, and writes a
 // post file.
 func (e Entrypointer) Go() error {
+	logger, _ := logging.NewLogger("", "entrypoint")
+	defer func() {
+		_ = logger.Sync()
+	}()
+	output := []v1alpha1.PipelineResourceResult{}
 	for _, f := range e.WaitFiles {
 		if err := e.Waiter.Wait(f, e.WaitFileContent); err != nil {
 			// An error happened while waiting, so we bail
@@ -77,12 +90,19 @@ func (e Entrypointer) Go() error {
 	if e.Entrypoint != "" {
 		e.Args = append([]string{e.Entrypoint}, e.Args...)
 	}
+	output = append(output, v1alpha1.PipelineResourceResult{
+		Key:   "StartedAt",
+		Value: time.Now().Format(time.RFC3339),
+	})
 
 	err := e.Runner.Run(e.Args...)
 
 	// Write the post file *no matter what*
 	e.WritePostFile(e.PostFile, err)
 
+	if wErr := termination.WriteMessage(e.TerminationPath, output); wErr != nil {
+		logger.Fatalf("Error while writing message: %s", wErr)
+	}
 	return err
 }
 

pkg/entrypoint/entrypointer_test.go

@@ -17,11 +17,15 @@ limitations under the License.
 package entrypoint
 
 import (
+	"encoding/json"
 	"errors"
+	"io/ioutil"
+	"os"
 	"reflect"
 	"testing"
 
 	"github.com/google/go-cmp/cmp"
+	"github.com/tektoncd/pipeline/pkg/apis/pipeline/v1alpha1"
 )
 
 func TestEntrypointerFailures(t *testing.T) {
@@ -63,16 +67,17 @@ func TestEntrypointerFailures(t *testing.T) {
 			}
 			fpw := &fakePostWriter{}
 			err := Entrypointer{
-				Entrypoint: "echo",
-				WaitFiles:  c.waitFiles,
-				PostFile:   c.postFile,
-				Args:       []string{"some", "args"},
-				Waiter:     fw,
-				Runner:     fr,
-				PostWriter: fpw,
+				Entrypoint:      "echo",
+				WaitFiles:       c.waitFiles,
+				PostFile:        c.postFile,
+				Args:            []string{"some", "args"},
+				Waiter:          fw,
+				Runner:          fr,
+				PostWriter:      fpw,
+				TerminationPath: "termination",
 			}.Go()
 			if err == nil {
-				t.Fatalf("Entrpointer didn't fail")
+				t.Fatalf("Entrypointer didn't fail")
 			}
 			if d := cmp.Diff(c.expectedError, err.Error()); d != "" {
 				t.Errorf("Entrypointer error diff -want, +got: %v", d)
@@ -125,13 +130,14 @@ func TestEntrypointer(t *testing.T) {
 		t.Run(c.desc, func(t *testing.T) {
 			fw, fr, fpw := &fakeWaiter{}, &fakeRunner{}, &fakePostWriter{}
 			err := Entrypointer{
-				Entrypoint: c.entrypoint,
-				WaitFiles:  c.waitFiles,
-				PostFile:   c.postFile,
-				Args:       c.args,
-				Waiter:     fw,
-				Runner:     fr,
-				PostWriter: fpw,
+				Entrypoint:      c.entrypoint,
+				WaitFiles:       c.waitFiles,
+				PostFile:        c.postFile,
+				Args:            c.args,
+				Waiter:          fw,
+				Runner:          fr,
+				PostWriter:      fpw,
+				TerminationPath: "termination",
 			}.Go()
 			if err != nil {
 				t.Fatalf("Entrypointer failed: %v", err)
@@ -173,6 +179,27 @@ func TestEntrypointer(t *testing.T) {
 			if c.postFile == "" && fpw.wrote != nil {
 				t.Errorf("Wrote post file when not required")
 			}
+			fileContents, err := ioutil.ReadFile("termination")
+			if err == nil {
+				var entries []v1alpha1.PipelineResourceResult
+				if err := json.Unmarshal([]byte(fileContents), &entries); err == nil {
+					var found = false
+					for _, result := range entries {
+						if result.Key == "StartedAt" {
+							found = true
+							break
+						}
+					}
+					if !found {
+						t.Error("Didn't find the startedAt entry")
+					}
+				}
+			} else if !os.IsNotExist(err) {
+				t.Error("Wanted termination file written, got nil")
+			}
+			if err := os.Remove("termination"); err != nil {
+				t.Errorf("Could not remove termination path: %s", err)
+			}
 		})
 	}
 }

pkg/pod/entrypoint.go

@@ -34,6 +34,7 @@ const (
 
 	downwardVolumeName     = "tekton-internal-downward"
 	downwardMountPoint     = "/tekton/downward"
+	terminationPath        = "/tekton/termination"
 	downwardMountReadyFile = "ready"
 	readyAnnotation        = "tekton.dev/ready"
 	readyAnnotationValue   = "READY"
@@ -106,12 +107,14 @@ func orderContainers(entrypointImage string, steps []corev1.Container) (corev1.C
 				"-wait_file_content", // Wait for file contents, not just an empty file.
 				// Start next step.
 				"-post_file", filepath.Join(mountPoint, fmt.Sprintf("%d", i)),
+				"-termination_path", terminationPath,
 			}
 		default:
 			// All other steps wait for previous file, write next file.
 			argsForEntrypoint = []string{
 				"-wait_file", filepath.Join(mountPoint, fmt.Sprintf("%d", i-1)),
 				"-post_file", filepath.Join(mountPoint, fmt.Sprintf("%d", i)),
+				"-termination_path", terminationPath,
 			}
 		}
 
@@ -129,6 +132,7 @@ func orderContainers(entrypointImage string, steps []corev1.Container) (corev1.C
 		steps[i].Command = []string{entrypointBinary}
 		steps[i].Args = argsForEntrypoint
 		steps[i].VolumeMounts = append(steps[i].VolumeMounts, toolsMount)
+		steps[i].TerminationMessagePath = terminationPath
 	}
 	// Mount the Downward volume into the first step container.
 	steps[0].VolumeMounts = append(steps[0].VolumeMounts, downwardMount)

pkg/pod/entrypoint_test.go

@@ -53,31 +53,37 @@ func TestOrderContainers(t *testing.T) {
 			"-wait_file", "/tekton/downward/ready",
 			"-wait_file_content",
 			"-post_file", "/tekton/tools/0",
+			"-termination_path", "/tekton/termination",
 			"-entrypoint", "cmd", "--",
 			"arg1", "arg2",
 		},
-		VolumeMounts: []corev1.VolumeMount{toolsMount, downwardMount},
+		VolumeMounts:           []corev1.VolumeMount{toolsMount, downwardMount},
+		TerminationMessagePath: "/tekton/termination",
 	}, {
 		Image:   "step-2",
 		Command: []string{entrypointBinary},
 		Args: []string{
 			"-wait_file", "/tekton/tools/0",
 			"-post_file", "/tekton/tools/1",
+			"-termination_path", "/tekton/termination",
 			"-entrypoint", "cmd1", "--",
 			"cmd2", "cmd3",
 			"arg1", "arg2",
 		},
-		VolumeMounts: []corev1.VolumeMount{volumeMount, toolsMount},
+		VolumeMounts:           []corev1.VolumeMount{volumeMount, toolsMount},
+		TerminationMessagePath: "/tekton/termination",
 	}, {
 		Image:   "step-3",
 		Command: []string{entrypointBinary},
 		Args: []string{
 			"-wait_file", "/tekton/tools/1",
 			"-post_file", "/tekton/tools/2",
+			"-termination_path", "/tekton/termination",
 			"-entrypoint", "cmd", "--",
 			"arg1", "arg2",
 		},
-		VolumeMounts: []corev1.VolumeMount{toolsMount},
+		VolumeMounts:           []corev1.VolumeMount{toolsMount},
+		TerminationMessagePath: "/tekton/termination",
 	}}
 	gotInit, got, err := orderContainers(images.EntrypointImage, steps)
 	if err != nil {