osbuildmonitor: include Timestamp for better tracability

This commit adds `Status.Timestamp` so that it's easier to correlate
what took how long when reconstructing the log (e.g. for bugreporting).

See also:
https://github.com/osbuild/images/compare/main...mvo5:osbuildmonitor-testdata?expand=1
for the full log.

pkg/osbuildmonitor/monitor.go

@@ -7,6 +7,7 @@ import (
 	"fmt"
 	"io"
 	"strings"
+	"time"
 )
 
 // Status is a high level aggregation of the low-level osbuild monitor
@@ -27,6 +28,9 @@ type Status struct {
 
 	// Progress contains the current progress.
 	Progress *Progress
+
+	// Timestamp contains the timestamp the message was recieved in
+	Timestamp time.Time
 }
 
 // Progress provides progress information from an osbuild build.
@@ -87,13 +91,15 @@ func (sr *StatusScanner) Status() (*Status, error) {
 	if pipelineContext == nil {
 		sr.pipelineContextMap[id] = &status.Context
 	}
+	ts := time.UnixMilli(int64(status.Timestamp * 1000))
 
 	st := &Status{
 		Trace: strings.TrimSpace(status.Message),
 		Progress: &Progress{
 			Done:  status.Progress.Done,
 			Total: status.Progress.Total,
 		},
+		Timestamp: ts,
 	}
 
 	// add subprogress
@@ -116,7 +122,8 @@ type statusJSON struct {
 	// Add "Result" here once
 	// https://github.com/osbuild/osbuild/pull/1831 is merged
 
-	Message string `json:"message"`
+	Message   string  `json:"message"`
+	Timestamp float64 `json:"timestamp"`
 }
 
 // contextJSON is the context for which a status is given. Once a context

pkg/osbuildmonitor/monitor_test.go

@@ -4,6 +4,7 @@ import (
 	"bytes"
 	"os"
 	"testing"
+	"time"
 
 	"github.com/stretchr/testify/assert"
 	"github.com/stretchr/testify/require"
@@ -15,6 +16,9 @@ const osbuildMonitorLines_curl = `{"message": "source/org.osbuild.curl (org.osb
 {"message": "source/org.osbuild.curl (org.osbuild.curl): Downloaded https://rpmrepo.osbuild.org/v2/mirror/public/f39/f39-x86_64-fedora-20231109/Packages/l/langpacks-fonts-en-4.0-9.fc39.noarch.rpm\n", "context": {"id": "7355d3857aa5c7b3a0c476c13d4b242a625fe190f2e7796df2335f3a34429db3"}, "progress": {"name": "pipelines/sources", "total": 4, "done": 0}, "timestamp": 1731589338.8256931}`
 
 func TestScannerSimple(t *testing.T) {
+	ts1 := 1731589338.8252223 * 1000
+	ts2 := 1731589338.8256931 * 1000
+
 	r := bytes.NewBufferString(osbuildMonitorLines_curl)
 	scanner := osbuildmonitor.NewStatusScanner(r)
 	// first line
@@ -26,6 +30,7 @@ func TestScannerSimple(t *testing.T) {
 			Done:  0,
 			Total: 4,
 		},
+		Timestamp: time.UnixMilli(int64(ts1)),
 	}, st)
 	// second line
 	st, err = scanner.Status()
@@ -36,6 +41,7 @@ func TestScannerSimple(t *testing.T) {
 			Done:  0,
 			Total: 4,
 		},
+		Timestamp: time.UnixMilli(int64(ts2)),
 	}, st)
 	// end
 	st, err = scanner.Status()
@@ -47,6 +53,8 @@ const osbuildMontiorLines_subprogress = `{"message": "Starting module org.osbui
 `
 
 func TestScannerSubprogress(t *testing.T) {
+	ts1 := 1731600115.14839 * 1000
+
 	r := bytes.NewBufferString(osbuildMontiorLines_subprogress)
 	scanner := osbuildmonitor.NewStatusScanner(r)
 	st, err := scanner.Status()
@@ -65,6 +73,7 @@ func TestScannerSubprogress(t *testing.T) {
 				},
 			},
 		},
+		Timestamp: time.UnixMilli(int64(ts1)),
 	}, st)
 }
 
@@ -80,5 +89,6 @@ func TestScannerSmoke(t *testing.T) {
 		if st == nil {
 			break
 		}
+		assert.NotEqual(t, time.Time{}, st.Timestamp)
 	}
 }