From 5fa236871fd802f404c6d1812d8e155ee2372409 Mon Sep 17 00:00:00 2001 From: Pasha Sviderski Date: Wed, 7 Oct 2026 11:35:17 +1000 Subject: [PATCH] fix(logs): resolve time ranges using client local time zone for logs commands --- cmd/uc/machine/logs.go | 10 ++- cmd/uc/machine/logs_test.go | 25 ++++++ cmd/uc/service/logs.go | 10 ++- cmd/uc/service/logs_test.go | 25 ++++++ internal/cli/logs/logs.go | 4 +- internal/cli/logs/time.go | 72 +++++++++++++++++ internal/cli/logs/time_test.go | 81 +++++++++++++++++++ internal/journal/journal.go | 17 +++- internal/journal/logs_test.go | 38 +++++++++ website/docs/9-cli-reference/uc_caddy_logs.md | 4 +- website/docs/9-cli-reference/uc_logs.md | 4 +- .../docs/9-cli-reference/uc_machine_logs.md | 4 +- .../docs/9-cli-reference/uc_service_logs.md | 4 +- 13 files changed, 282 insertions(+), 16 deletions(-) create mode 100644 cmd/uc/machine/logs_test.go create mode 100644 cmd/uc/service/logs_test.go create mode 100644 internal/cli/logs/time.go create mode 100644 internal/cli/logs/time_test.go diff --git a/cmd/uc/machine/logs.go b/cmd/uc/machine/logs.go index 33d8b9fe..4223be54 100644 --- a/cmd/uc/machine/logs.go +++ b/cmd/uc/machine/logs.go @@ -5,6 +5,7 @@ import ( "fmt" "slices" "strings" + "time" "github.com/psviderski/uncloud/internal/cli" "github.com/psviderski/uncloud/internal/cli/completion" @@ -64,6 +65,11 @@ If no services are specified, streams logs from the uncloud service.`, } func runLogs(ctx context.Context, uncli *cli.CLI, services []string, opts logs.Options) error { + since, until, err := logs.TimeRange(opts.Since, opts.Until, time.Now()) + if err != nil { + return err + } + if len(services) == 0 { services = []string{api.SystemServiceUncloud} } @@ -88,8 +94,8 @@ func runLogs(ctx context.Context, uncli *cli.CLI, services []string, opts logs.O logsOpts := api.ServiceLogsOptions{ Follow: opts.Follow, Tail: tail, - Since: opts.Since, - Until: opts.Until, + Since: since, + Until: until, Machines: cli.ExpandCommaSeparatedValues(opts.Machines), } diff --git a/cmd/uc/machine/logs_test.go b/cmd/uc/machine/logs_test.go new file mode 100644 index 00000000..7343540b --- /dev/null +++ b/cmd/uc/machine/logs_test.go @@ -0,0 +1,25 @@ +package machine + +import ( + "context" + "testing" + + "github.com/psviderski/uncloud/internal/cli/logs" + "github.com/stretchr/testify/require" +) + +func TestRunLogsInvalidTimeFilters(t *testing.T) { + t.Parallel() + + // Invalid filters must fail before connecting to the cluster. + for _, flag := range []string{"since", "until"} { + opts := logs.Options{} + if flag == "since" { + opts.Since = "invalid" + } else { + opts.Until = "invalid" + } + err := runLogs(context.Background(), nil, nil, opts) + require.ErrorContains(t, err, "invalid --"+flag+" value") + } +} diff --git a/cmd/uc/service/logs.go b/cmd/uc/service/logs.go index 0b1b2d6b..c196ddfd 100644 --- a/cmd/uc/service/logs.go +++ b/cmd/uc/service/logs.go @@ -5,6 +5,7 @@ import ( "errors" "fmt" "strings" + "time" mapset "github.com/deckarep/golang-set/v2" "github.com/psviderski/uncloud/internal/cli" @@ -78,6 +79,11 @@ If no services are specified, streams logs from all services defined in the Comp } func RunLogs(ctx context.Context, uncli *cli.CLI, args []string, opts logs.Options) error { + since, until, err := logs.TimeRange(opts.Since, opts.Until, time.Now()) + if err != nil { + return err + } + serviceArgs, err := logs.ParseServiceArgs(args) if err != nil { return err @@ -121,8 +127,8 @@ func RunLogs(ctx context.Context, uncli *cli.CLI, args []string, opts logs.Optio baseOpts := api.ServiceLogsOptions{ Follow: opts.Follow, Tail: tail, - Since: opts.Since, - Until: opts.Until, + Since: since, + Until: until, Machines: cli.ExpandCommaSeparatedValues(opts.Machines), } diff --git a/cmd/uc/service/logs_test.go b/cmd/uc/service/logs_test.go new file mode 100644 index 00000000..b04353d3 --- /dev/null +++ b/cmd/uc/service/logs_test.go @@ -0,0 +1,25 @@ +package service + +import ( + "context" + "testing" + + "github.com/psviderski/uncloud/internal/cli/logs" + "github.com/stretchr/testify/require" +) + +func TestRunLogsInvalidTimeFilters(t *testing.T) { + t.Parallel() + + // Invalid filters must fail before loading Compose files or connecting to the cluster. + for _, flag := range []string{"since", "until"} { + opts := logs.Options{} + if flag == "since" { + opts.Since = "invalid" + } else { + opts.Until = "invalid" + } + err := RunLogs(context.Background(), nil, nil, opts) + require.ErrorContains(t, err, "invalid --"+flag+" value") + } +} diff --git a/internal/cli/logs/logs.go b/internal/cli/logs/logs.go index fe5df5be..46bf1119 100644 --- a/internal/cli/logs/logs.go +++ b/internal/cli/logs/logs.go @@ -31,8 +31,8 @@ func Flags(options *Options) *pflag.FlagSet { "Examples:\n"+ " --since 2m30s Relative duration (2 minutes 30 seconds ago)\n"+ " --since 1h Relative duration (1 hour ago)\n"+ - " --since 2025-11-24 RFC 3339 date only (midnight using local timezone)\n"+ - " --since 2024-05-14T22:50:00 RFC 3339 date/time using local timezone\n"+ + " --since 2025-11-24 RFC 3339 date only (midnight using client local timezone)\n"+ + " --since 2024-05-14T22:50:00 RFC 3339 date/time using client local timezone\n"+ " --since 2024-01-31T10:30:00Z RFC 3339 date/time in UTC\n"+ " --since 1763953966 Unix timestamp (seconds since January 1, 1970)") set.StringVarP(&options.Tail, "tail", "n", "100", diff --git a/internal/cli/logs/time.go b/internal/cli/logs/time.go new file mode 100644 index 00000000..12ec73df --- /dev/null +++ b/internal/cli/logs/time.go @@ -0,0 +1,72 @@ +package logs + +import ( + "fmt" + "strconv" + "strings" + "time" +) + +// TimeRange resolves log filters that could be RFC 3339, timestamp, or relative duration to UTC timestamps. +// Dates without a timezone use now's location. Relative durations are computed from now. +func TimeRange(since, until string, now time.Time) (string, string, error) { + var err error + since, err = timestamp(since, now) + if err != nil { + return "", "", fmt.Errorf("invalid --since value: %w", err) + } + until, err = timestamp(until, now) + if err != nil { + return "", "", fmt.Errorf("invalid --until value: %w", err) + } + + return since, until, nil +} + +func timestamp(value string, now time.Time) (string, error) { + if value == "" { + return "", nil + } + // A bare zero is the Unix epoch, matching Docker's log filters. + if duration, err := time.ParseDuration(value); value != "0" && err == nil { + return now.Add(-duration).UTC().Format(time.RFC3339Nano), nil + } + + // Keep Docker's supported date layouts, but use the location's offset at the requested date. + for _, layout := range []string{ + time.RFC3339Nano, + "2006-01-02T15:04Z07:00", + "2006-01-02T15Z07:00", + "2006-01-02Z07:00", + "2006-01-02T15:04:05.999999999", + "2006-01-02T15:04", + "2006-01-02T15", + "2006-01-02", + } { + if t, err := time.ParseInLocation(layout, value, now.Location()); err == nil { + return t.UTC().Format(time.RFC3339Nano), nil + } + } + + seconds, fraction, hasFraction := strings.Cut(value, ".") + sec, err := strconv.ParseInt(seconds, 10, 64) + if err != nil { + return "", fmt.Errorf("failed to parse '%s' as a time or duration", value) + } + + var nsec int64 + if hasFraction { + if len(fraction) == 0 || len(fraction) > 9 || strings.ContainsAny(fraction, "+-") { + return "", fmt.Errorf("invalid Unix timestamp fraction in '%s'", value) + } + nsec, err = strconv.ParseInt(fraction+strings.Repeat("0", 9-len(fraction)), 10, 64) + if err != nil { + return "", fmt.Errorf("invalid Unix timestamp fraction in '%s': %w", value, err) + } + } + t := time.Unix(sec, nsec).UTC() + if t.Year() < 0 || t.Year() > 9999 { + return "", fmt.Errorf("Unix timestamp '%s' is outside the RFC 3339 date range", value) + } + return t.Format(time.RFC3339Nano), nil +} diff --git a/internal/cli/logs/time_test.go b/internal/cli/logs/time_test.go new file mode 100644 index 00000000..f3556478 --- /dev/null +++ b/internal/cli/logs/time_test.go @@ -0,0 +1,81 @@ +package logs + +import ( + "testing" + "time" + + timetypes "github.com/docker/docker/api/types/time" + "github.com/stretchr/testify/assert" + "github.com/stretchr/testify/require" +) + +func TestTimeRange(t *testing.T) { + t.Parallel() + + location, err := time.LoadLocation("Australia/Sydney") + require.NoError(t, err) + // January is daylight-saving time, but July timestamps must use the winter offset. + now := time.Date(2026, 1, 15, 12, 0, 0, 123456789, location) + tests := []struct { + input string + want string + }{ + {"", ""}, + {"2026-07-01", "2026-06-30T14:00:00Z"}, + {"2026-07-01T10", "2026-07-01T00:00:00Z"}, + {"2026-07-01T10:30", "2026-07-01T00:30:00Z"}, + {"2026-07-01T10:30:45.123456789", "2026-07-01T00:30:45.123456789Z"}, + {"2026-01-01T10:00:00", "2025-12-31T23:00:00Z"}, + {"2026-07-01T10:30:45Z", "2026-07-01T10:30:45Z"}, + {"2026-07-01T10:30:45+02:00", "2026-07-01T08:30:45Z"}, + {"2026-07-01T10:30:45-04:00", "2026-07-01T14:30:45Z"}, + {"2026-07-01T10+02:00", "2026-07-01T08:00:00Z"}, + {"2026-07-01T10:30+02:00", "2026-07-01T08:30:00Z"}, + {"2026-07-01+02:00", "2026-06-30T22:00:00Z"}, + {"1763953966", "2025-11-24T03:12:46Z"}, + {"1763953966.000000001", "2025-11-24T03:12:46.000000001Z"}, + {"0", "1970-01-01T00:00:00Z"}, + {"2m30s", "2026-01-15T00:57:30.123456789Z"}, + {"-1h", "2026-01-15T02:00:00.123456789Z"}, + } + for _, tt := range tests { + t.Run(tt.input, func(t *testing.T) { + since, until, err := TimeRange(tt.input, tt.input, now) + require.NoError(t, err) + assert.Equal(t, tt.want, since) + assert.Equal(t, tt.want, until) + + if since != "" { + // The server-side Docker SDK must preserve the cutoff even in another timezone. + actual, err := timetypes.GetTimestamp(since, now.In(time.UTC)) + require.NoError(t, err) + expected, err := time.Parse(time.RFC3339Nano, tt.want) + require.NoError(t, err) + sec, nsec, err := timetypes.ParseTimestamps(actual, 0) + require.NoError(t, err) + assert.True(t, expected.Equal(time.Unix(sec, nsec))) + } + }) + } + + since, until, err := TimeRange("3h", "1h30m", now) + require.NoError(t, err) + assert.Equal(t, "2026-01-14T22:00:00.123456789Z", since) + assert.Equal(t, "2026-01-14T23:30:00.123456789Z", until) +} + +func TestTimeRange_Invalid(t *testing.T) { + t.Parallel() + + for _, input := range []string{ + "invalid", "2026-02-30", "2026-01-01T25:00:00", "1763953966.xyz", + "1763953966.1234567890", "253402300800", + } { + t.Run(input, func(t *testing.T) { + _, _, err := TimeRange(input, "", time.Now()) + require.ErrorContains(t, err, "invalid --since value") + _, _, err = TimeRange("", input, time.Now()) + require.ErrorContains(t, err, "invalid --until value") + }) + } +} diff --git a/internal/journal/journal.go b/internal/journal/journal.go index da28c00e..6e367ed0 100644 --- a/internal/journal/journal.go +++ b/internal/journal/journal.go @@ -6,6 +6,7 @@ import ( "fmt" "io" "os/exec" + "time" "github.com/psviderski/uncloud/pkg/api" ) @@ -31,11 +32,11 @@ func logs(ctx context.Context, unit string, opts api.ServiceLogsOptions) (io.Rea if opts.Since != "" { args = append(args, "-S") - args = append(args, opts.Since) + args = append(args, journalTimestamp(opts.Since)) } if opts.Until != "" { args = append(args, "-U") - args = append(args, opts.Until) + args = append(args, journalTimestamp(opts.Until)) } cmd := commandContext(ctx, journalctl, args...) @@ -51,6 +52,18 @@ func logs(ctx context.Context, unit string, opts api.ServiceLogsOptions) (io.Rea return p, cmd.Wait, nil } +// journalTimestamp formats normalised client timestamps for journalctl versions that do not +// accept RFC 3339 timezone suffixes. Support for timestamps containing T and Z was added in +// systemd 255 (6 December 2023). Debian 12 ships systemd 252, so it still needs this conversion. +// Journald timestamps have microsecond precision. +func journalTimestamp(value string) string { + if t, err := time.Parse(time.RFC3339Nano, value); err == nil { + return t.UTC().Format("2006-01-02 15:04:05.999999") + " UTC" + } + // Preserve raw filters from older clients and SDK callers. + return value +} + // follow synchronously follows the io.Reader, writing each new journal entry to channel. // It stops when the reader is exhausted or the context is cancelled. func follow(ctx context.Context, reader io.Reader, outCh chan api.LogEntry) { diff --git a/internal/journal/logs_test.go b/internal/journal/logs_test.go index c8246f7c..3ef69aa0 100644 --- a/internal/journal/logs_test.go +++ b/internal/journal/logs_test.go @@ -115,6 +115,9 @@ func TestEntry(t *testing.T) { } func TestLogs(t *testing.T) { + originalCommandContext := commandContext + t.Cleanup(func() { commandContext = originalCommandContext }) + commandContext = func(ctx context.Context, _ string, _ ...string) *exec.Cmd { return exec.CommandContext(ctx, "/usr/bin/tail", "testdata/logs") } @@ -150,3 +153,38 @@ func TestLogs(t *testing.T) { // Still six because heartbeats are not written here and Tail is ignored as the command is overridden. assert.Equal(t, 6, i) } + +func TestLogs_TimeFilters(t *testing.T) { + originalCommandContext := commandContext + t.Cleanup(func() { commandContext = originalCommandContext }) + + var args []string + commandContext = func(ctx context.Context, command string, commandArgs ...string) *exec.Cmd { + assert.Equal(t, "journalctl", command) + args = commandArgs + return exec.CommandContext(ctx, "/usr/bin/tail", "testdata/logs") + } + + ch, err := Logs(context.Background(), "uncloud", api.ServiceLogsOptions{ + Since: "2026-07-01T10:30:45.123456789+10:00", + Until: "2026-07-01T01:30:45Z", + }) + require.NoError(t, err) + for range ch { + } + assert.Equal(t, []string{ + "-u", "uncloud", "--no-hostname", "-n", "0", "-o", "short-unix", + "-S", "2026-07-01 00:30:45.123456 UTC", + "-U", "2026-07-01 01:30:45 UTC", + }, args) + + // Older clients and SDK callers can still pass journalctl's native filters. + ch, err = Logs(context.Background(), "uncloud", api.ServiceLogsOptions{Since: "1h ago", Until: "today"}) + require.NoError(t, err) + for range ch { + } + assert.Equal(t, []string{ + "-u", "uncloud", "--no-hostname", "-n", "0", "-o", "short-unix", + "-S", "1h ago", "-U", "today", + }, args) +} diff --git a/website/docs/9-cli-reference/uc_caddy_logs.md b/website/docs/9-cli-reference/uc_caddy_logs.md index 6d259bb0..a7c3e1e8 100644 --- a/website/docs/9-cli-reference/uc_caddy_logs.md +++ b/website/docs/9-cli-reference/uc_caddy_logs.md @@ -23,8 +23,8 @@ uc caddy logs [flags] Examples: --since 2m30s Relative duration (2 minutes 30 seconds ago) --since 1h Relative duration (1 hour ago) - --since 2025-11-24 RFC 3339 date only (midnight using local timezone) - --since 2024-05-14T22:50:00 RFC 3339 date/time using local timezone + --since 2025-11-24 RFC 3339 date only (midnight using client local timezone) + --since 2024-05-14T22:50:00 RFC 3339 date/time using client local timezone --since 2024-01-31T10:30:00Z RFC 3339 date/time in UTC --since 1763953966 Unix timestamp (seconds since January 1, 1970) -n, --tail string Show the most recent logs and limit the number of lines shown per replica. Use 'all' to show all logs. (default "100") diff --git a/website/docs/9-cli-reference/uc_logs.md b/website/docs/9-cli-reference/uc_logs.md index ce79284d..09af3b3f 100644 --- a/website/docs/9-cli-reference/uc_logs.md +++ b/website/docs/9-cli-reference/uc_logs.md @@ -58,8 +58,8 @@ uc logs [SERVICE[/CONTAINER]...] [flags] Examples: --since 2m30s Relative duration (2 minutes 30 seconds ago) --since 1h Relative duration (1 hour ago) - --since 2025-11-24 RFC 3339 date only (midnight using local timezone) - --since 2024-05-14T22:50:00 RFC 3339 date/time using local timezone + --since 2025-11-24 RFC 3339 date only (midnight using client local timezone) + --since 2024-05-14T22:50:00 RFC 3339 date/time using client local timezone --since 2024-01-31T10:30:00Z RFC 3339 date/time in UTC --since 1763953966 Unix timestamp (seconds since January 1, 1970) -n, --tail string Show the most recent logs and limit the number of lines shown per replica. Use 'all' to show all logs. (default "100") diff --git a/website/docs/9-cli-reference/uc_machine_logs.md b/website/docs/9-cli-reference/uc_machine_logs.md index 15ae9001..ae414eb2 100644 --- a/website/docs/9-cli-reference/uc_machine_logs.md +++ b/website/docs/9-cli-reference/uc_machine_logs.md @@ -54,8 +54,8 @@ uc machine logs [SERVICE...] [flags] Examples: --since 2m30s Relative duration (2 minutes 30 seconds ago) --since 1h Relative duration (1 hour ago) - --since 2025-11-24 RFC 3339 date only (midnight using local timezone) - --since 2024-05-14T22:50:00 RFC 3339 date/time using local timezone + --since 2025-11-24 RFC 3339 date only (midnight using client local timezone) + --since 2024-05-14T22:50:00 RFC 3339 date/time using client local timezone --since 2024-01-31T10:30:00Z RFC 3339 date/time in UTC --since 1763953966 Unix timestamp (seconds since January 1, 1970) -n, --tail string Show the most recent logs and limit the number of lines shown per replica. Use 'all' to show all logs. (default "100") diff --git a/website/docs/9-cli-reference/uc_service_logs.md b/website/docs/9-cli-reference/uc_service_logs.md index 1b817f5f..57e53e00 100644 --- a/website/docs/9-cli-reference/uc_service_logs.md +++ b/website/docs/9-cli-reference/uc_service_logs.md @@ -58,8 +58,8 @@ uc service logs [SERVICE[/CONTAINER]...] [flags] Examples: --since 2m30s Relative duration (2 minutes 30 seconds ago) --since 1h Relative duration (1 hour ago) - --since 2025-11-24 RFC 3339 date only (midnight using local timezone) - --since 2024-05-14T22:50:00 RFC 3339 date/time using local timezone + --since 2025-11-24 RFC 3339 date only (midnight using client local timezone) + --since 2024-05-14T22:50:00 RFC 3339 date/time using client local timezone --since 2024-01-31T10:30:00Z RFC 3339 date/time in UTC --since 1763953966 Unix timestamp (seconds since January 1, 1970) -n, --tail string Show the most recent logs and limit the number of lines shown per replica. Use 'all' to show all logs. (default "100")