From 50057c42e06b758ced413d665842e8dd9c3f3483 Mon Sep 17 00:00:00 2001 From: Pasha Sviderski Date: Thu, 23 Apr 2026 17:31:31 +1000 Subject: [PATCH] fix: machine logs timestamp parsing and streaming for systemd 30 && data[4] == '-' && data[7] == '-' && data[10] == 'T' { - timestampPart, messagePart, found := bytes.Cut(data, []byte(" ")) - var err error - if found { - timestamp, err = time.Parse(time.RFC3339Nano, string(timestampPart)) - if err != nil { - timestamp = time.Time{} - } + if timestampPart, messagePart, found := bytes.Cut(data, []byte(" ")); found { + if t, ok := parseUnixTimestamp(timestampPart); ok { + timestamp = t message = messagePart } } @@ -54,3 +50,20 @@ func entry(data []byte) api.LogEntry { Stream: api.LogStreamStdout, } } + +// parseUnixTimestamp parses a journalctl short-unix timestamp "SSSSSSSSSS.UUUUUU" with microsecond precision. +func parseUnixTimestamp(b []byte) (time.Time, bool) { + secPart, usecPart, found := bytes.Cut(b, []byte(".")) + if !found { + return time.Time{}, false + } + sec, err := strconv.ParseInt(string(secPart), 10, 64) + if err != nil { + return time.Time{}, false + } + usec, err := strconv.ParseInt(string(usecPart), 10, 64) + if err != nil { + return time.Time{}, false + } + return time.Unix(sec, usec*1000), true +} diff --git a/internal/journal/logs_test.go b/internal/journal/logs_test.go index 4274f55a..c8246f7c 100644 --- a/internal/journal/logs_test.go +++ b/internal/journal/logs_test.go @@ -11,6 +11,109 @@ import ( "github.com/stretchr/testify/require" ) +func TestParseUnixTimestamp(t *testing.T) { + tests := []struct { + name string + input string + want time.Time + ok bool + }{ + { + name: "valid with microseconds", + input: "1769188773.687500", + want: time.Unix(1769188773, 687500000), + ok: true, + }, + { + name: "zero microseconds", + input: "1769188773.000000", + want: time.Unix(1769188773, 0), + ok: true, + }, + { + name: "epoch", + input: "0.000000", + want: time.Unix(0, 0), + ok: true, + }, + { + name: "no fractional part", + input: "1769188773", + want: time.Time{}, + ok: false, + }, + { + name: "non-numeric seconds", + input: "abc.000000", + want: time.Time{}, + ok: false, + }, + { + name: "non-numeric microseconds", + input: "1769188773.abc", + want: time.Time{}, + ok: false, + }, + { + name: "empty", + input: "", + want: time.Time{}, + ok: false, + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + got, ok := parseUnixTimestamp([]byte(tt.input)) + assert.Equal(t, tt.ok, ok) + assert.True(t, tt.want.Equal(got), "want %v, got %v", tt.want, got) + }) + } +} + +func TestEntry(t *testing.T) { + tests := []struct { + name string + input string + timestamp time.Time + message string + }{ + { + name: "valid entry", + input: "1769188773.687500 uncloudd[332455]: INFO Starting daemon.", + timestamp: time.Unix(1769188773, 687500000), + message: "uncloudd[332455]: INFO Starting daemon.\n", + }, + { + name: "unparseable timestamp keeps full line as message", + input: "-- Boot 1234567890 --", + timestamp: time.Time{}, + message: "-- Boot 1234567890 --\n", + }, + { + name: "line without space keeps full line as message", + input: "nospacehere", + timestamp: time.Time{}, + message: "nospacehere\n", + }, + { + name: "empty line", + input: "", + timestamp: time.Time{}, + message: "\n", + }, + } + + for _, tt := range tests { + t.Run(tt.name, func(t *testing.T) { + got := entry([]byte(tt.input)) + assert.True(t, tt.timestamp.Equal(got.Timestamp), "timestamp: want %v, got %v", tt.timestamp, got.Timestamp) + assert.Equal(t, tt.message, string(got.Message)) + assert.Equal(t, api.LogStreamStdout, got.Stream) + }) + } +} + func TestLogs(t *testing.T) { commandContext = func(ctx context.Context, _ string, _ ...string) *exec.Cmd { return exec.CommandContext(ctx, "/usr/bin/tail", "testdata/logs") diff --git a/internal/journal/testdata/logs b/internal/journal/testdata/logs index 60eccc04..53c7d12a 100644 --- a/internal/journal/testdata/logs +++ b/internal/journal/testdata/logs @@ -1,6 +1,6 @@ -2026-01-23T17:19:33.686964+01:00 fedora kernel: apple-dcp 271c00000.dcp: DCP index:1 dptx target phy: 5 dptx die: 0 -2026-01-23T17:19:33.687155+01:00 fedora kernel: platform 271c00000.dcp:piodma: Adding to iommu group 9 -2026-01-23T17:19:33.687343+01:00 fedora kernel: apple-dcp 271c00000.dcp: RTKit: Initializing (protocol version 12) -2026-01-23T17:19:33.687500+01:00 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: 880255000 -> pa: be4f29000 -> iomem: ffff800082> -2026-01-23T17:19:33.687657+01:00 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: ffffec000, buffer: ffff8000817cc000 -2026-01-23T17:19:33.687826+01:00 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: ffffe8000, buffer: ffff8000817d4000 +1769188773.686964 fedora kernel: apple-dcp 271c00000.dcp: DCP index:1 dptx target phy: 5 dptx die: 0 +1769188773.687155 fedora kernel: platform 271c00000.dcp:piodma: Adding to iommu group 9 +1769188773.687343 fedora kernel: apple-dcp 271c00000.dcp: RTKit: Initializing (protocol version 12) +1769188773.687500 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: 880255000 -> pa: be4f29000 -> iomem: ffff800082> +1769188773.687657 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: ffffec000, buffer: ffff8000817cc000 +1769188773.687826 fedora kernel: apple-dcp 271c00000.dcp: shmem_setup: iova: ffffe8000, buffer: ffff8000817d4000