From 2ccbb8d58721e30afd2c6e2ad92326377a2656a3 Mon Sep 17 00:00:00 2001 From: David Dworken Date: Sat, 9 Sep 2023 12:28:01 -0700 Subject: [PATCH] Store timestamps in DB in Unix time, and display them in the Local time for consistent TZs in displays, and to ensure ordering is correct This fixes a bug where entries could be out of order if they were recorded on machines in different TZs (e.g. if one machine had the TZ set to UTC). Admittedly, this commit isn't a perfect fix since it doesn't change all the existing hishtory entries to be stored in UTC, but this just means that the ordering bug will continue to exist for historical entries, but be fixed for new entries. And for our purposes, that is good enough. :) # Please enter the commit message for your changes. Lines starting --- client/client_test.go | 86 ++++++++++--------- client/cmd/saveHistoryEntry.go | 8 +- .../TestSortByConsistentTimezone-query | 4 + .../TestSortByConsistentTimezone-tquery | 31 +++++++ client/lib/lib.go | 20 +++-- shared/testutils/testutils.go | 4 +- 6 files changed, 101 insertions(+), 52 deletions(-) create mode 100644 client/lib/goldens/TestSortByConsistentTimezone-query create mode 100644 client/lib/goldens/TestSortByConsistentTimezone-tquery diff --git a/client/client_test.go b/client/client_test.go index d495f4e..ea30926 100644 --- a/client/client_test.go +++ b/client/client_test.go @@ -429,13 +429,9 @@ func testBasicUserFlow(t *testing.T, tester shellTester, onlineStatus OnlineStat // Assert that hishtory is correctly using the dev config.sh homedir, err := os.UserHomeDir() - if err != nil { - t.Fatalf("failed to get homedir: %v", err) - } + require.NoError(t, err) dat, err := os.ReadFile(path.Join(homedir, data.GetHishtoryPath(), "config.sh")) - if err != nil { - t.Fatalf("failed to read config.sh: %v", err) - } + require.NoError(t, err, "failed to read config.sh") require.NotContains(t, string(dat), "# Background Run", "config.sh is the prod version when it shouldn't be") // Test the banner @@ -740,9 +736,7 @@ func testUpdate(t *testing.T, tester shellTester) { // Update out = tester.RunInteractiveShell(t, `hishtory update`) isExpected, err := regexp.MatchString(`Successfully updated hishtory from v0[.]Unknown to v0.\d+`, out) - if err != nil { - t.Fatalf("regex failure: %v", err) - } + require.NoError(t, err, "regex failure") if !isExpected { t.Fatalf("hishtory update returned unexpected out=%#v", out) } @@ -1019,13 +1013,9 @@ CGO_ENABLED=0 go build -o /tmp/client // Assert that config.sh isn't the dev version homedir, err := os.UserHomeDir() - if err != nil { - t.Fatalf("failed to get homedir: %v", err) - } + require.NoError(t, err) dat, err := os.ReadFile(path.Join(homedir, data.GetHishtoryPath(), "config.sh")) - if err != nil { - t.Fatalf("failed to read config.sh: %v", err) - } + require.NoError(t, err, "failed to read config.sh") require.NotContains(t, string(dat), "except it doesn't run the save process in the background", "config.sh is the testing version when it shouldn't be") // Test the status subcommand @@ -1065,9 +1055,7 @@ func testDisplayTable(t *testing.T, tester shellTester) { // Submit two fake entries tmz, err := time.LoadLocation("America/Los_Angeles") - if err != nil { - t.Fatalf("failed to load timezone: %v", err) - } + require.NoError(t, err) entry1 := testutils.MakeFakeHistoryEntry("table_cmd1") entry1.StartTime = time.Unix(1650096186, 0).In(tmz) entry1.EndTime = time.Unix(1650096190, 0).In(tmz) @@ -1131,9 +1119,7 @@ func testRequestAndReceiveDbDump(t *testing.T, tester shellTester) { config := hctx.GetConf(hctx.MakeContext()) deviceId1 := config.DeviceId resp, err := lib.ApiGet("/api/v1/get-dump-requests?user_id=" + data.UserId(secretKey) + "&device_id=" + deviceId1) - if err != nil { - t.Fatalf("failed to get pending dump requests: %v", err) - } + require.NoError(t, err, "failed to get pending dump requests") if string(resp) != "[]" { t.Fatalf("There are pending dump requests! user_id=%#v, resp=%#v", data.UserId(secretKey), string(resp)) } @@ -1158,18 +1144,14 @@ echo other`) // Wipe the DB to simulate entries getting deleted because they've already been read and expired _, err = lib.ApiGet("/api/v1/wipe-db-entries") - if err != nil { - t.Fatalf("failed to wipe the DB: %v", err) - } + require.NoError(t, err, "failed to wipe the remote DB") // Install a new one (with the same secret key but a diff device id) installHishtory(t, tester, secretKey) // Confirm there is now a pending dump requests that the first device should respond to resp, err = lib.ApiGet("/api/v1/get-dump-requests?user_id=" + data.UserId(secretKey) + "&device_id=" + deviceId1) - if err != nil { - t.Fatalf("failed to get pending dump requests: %v", err) - } + require.NoError(t, err, "failed to get pending dump requests") if string(resp) == "[]" { t.Fatalf("There are no pending dump requests! user_id=%#v, resp=%#v", data.UserId(secretKey), string(resp)) } @@ -1200,9 +1182,7 @@ echo other`) // Confirm there are no pending dump requests for the first device resp, err = lib.ApiGet("/api/v1/get-dump-requests?user_id=" + data.UserId(secretKey) + "&device_id=" + deviceId1) - if err != nil { - t.Fatalf("failed to get pending dump requests: %v", err) - } + require.NoError(t, err, "failed to get pending dump requests") if string(resp) != "[]" { t.Fatalf("There are pending dump requests! user_id=%#v, resp=%#v", data.UserId(secretKey), string(resp)) } @@ -2378,9 +2358,7 @@ func TestTimestampFormat(t *testing.T) { // Add some entries with fixed timestamps tmz, err := time.LoadLocation("America/Los_Angeles") - if err != nil { - t.Fatalf("failed to load timezone: %v", err) - } + require.NoError(t, err) entry1 := testutils.MakeFakeHistoryEntry("table_cmd1 aaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaaa") entry1.StartTime = time.Unix(1650096186, 0).In(tmz) entry1.EndTime = time.Unix(1650096190, 0).In(tmz) @@ -2403,6 +2381,40 @@ func TestTimestampFormat(t *testing.T) { testutils.CompareGoldens(t, out, "TestTimestampFormat-tquery") } +func TestSortByConsistentTimezone(t *testing.T) { + // Setup + tester := zshTester{} + defer testutils.BackupAndRestore(t)() + installHishtory(t, tester, "") + + // Add some entries with timestamps in different timezones + db := hctx.GetDb(hctx.MakeContext()) + timestamp := int64(1650096186) + la_time, err := time.LoadLocation("America/Los_Angeles") + require.NoError(t, err) + ny_time, err := time.LoadLocation("America/New_York") + require.NoError(t, err) + entry1 := testutils.MakeFakeHistoryEntry("first_entry") + entry1.StartTime = time.Unix(timestamp, 0).In(ny_time) + entry1.EndTime = time.Unix(timestamp+1, 0).In(ny_time) + testutils.Check(t, lib.ReliableDbCreate(db, entry1)) + entry2 := testutils.MakeFakeHistoryEntry("second_entry") + entry2.StartTime = time.Unix(timestamp+1000, 0).In(la_time) + entry2.EndTime = time.Unix(timestamp+1001, 0).In(la_time) + testutils.Check(t, lib.ReliableDbCreate(db, entry2)) + entry3 := testutils.MakeFakeHistoryEntry("third_entry") + entry3.StartTime = time.Unix(timestamp+2000, 0).In(ny_time) + entry3.EndTime = time.Unix(timestamp+2001, 0).In(ny_time) + testutils.Check(t, lib.ReliableDbCreate(db, entry3)) + + // And check that they're displayed in the correct order + out := hishtoryQuery(t, tester, "-pipefail") + testutils.CompareGoldens(t, out, "TestSortByConsistentTimezone-query") + out = captureTerminalOutput(t, tester, []string{"hishtory SPACE tquery SPACE -pipefail ENTER"}) + out = strings.TrimSpace(strings.Split(out, "hishtory tquery")[1]) + testutils.CompareGoldens(t, out, "TestSortByConsistentTimezone-tquery") +} + func TestZDotDir(t *testing.T) { // Setup tester := zshTester{} @@ -2493,14 +2505,10 @@ func TestSetConfigNoCorruption(t *testing.T) { c.HaveMissedUploads = (i % 2) == 0 // Write it err := hctx.SetConfig(c) - if err != nil { - panic(err) - } + require.NoError(t, err) // Check that we can read c2, err := hctx.GetConfig() - if err != nil { - panic(err) - } + require.NoError(t, err) if c2.UserSecret != c.UserSecret { panic("user secret mismatch") } diff --git a/client/cmd/saveHistoryEntry.go b/client/cmd/saveHistoryEntry.go index e5e913c..4840281 100644 --- a/client/cmd/saveHistoryEntry.go +++ b/client/cmd/saveHistoryEntry.go @@ -105,8 +105,8 @@ func presaveHistoryEntry(ctx context.Context) { } startTime, err := parseCrossPlatformInt(os.Args[4]) lib.CheckFatalError(err) - entry.StartTime = time.Unix(startTime, 0) - entry.EndTime = time.Unix(0, 0) + entry.StartTime = time.Unix(startTime, 0).UTC() + entry.EndTime = time.Unix(0, 0).UTC() // And persist it locally. db := hctx.GetDb(ctx) @@ -281,10 +281,10 @@ func buildHistoryEntry(ctx context.Context, args []string) (*data.HistoryEntry, if err != nil { return nil, fmt.Errorf("failed to parse start time %s as int: %w", args[5], err) } - entry.StartTime = time.Unix(seconds, 0) + entry.StartTime = time.Unix(seconds, 0).UTC() // end time - entry.EndTime = time.Now() + entry.EndTime = time.Now().UTC() // command if shell == "bash" { diff --git a/client/lib/goldens/TestSortByConsistentTimezone-query b/client/lib/goldens/TestSortByConsistentTimezone-query new file mode 100644 index 0000000..1f793d6 --- /dev/null +++ b/client/lib/goldens/TestSortByConsistentTimezone-query @@ -0,0 +1,4 @@ +Hostname CWD Timestamp Runtime Exit Code Command +localhost /tmp/ Apr 16 2022 01:36:26 PDT 1s 2 third_entry +localhost /tmp/ Apr 16 2022 01:19:46 PDT 1s 2 second_entry +localhost /tmp/ Apr 16 2022 01:03:06 PDT 1s 2 first_entry diff --git a/client/lib/goldens/TestSortByConsistentTimezone-tquery b/client/lib/goldens/TestSortByConsistentTimezone-tquery new file mode 100644 index 0000000..cf7438c --- /dev/null +++ b/client/lib/goldens/TestSortByConsistentTimezone-tquery @@ -0,0 +1,31 @@ +-pipefail + + + +Search Query: > -pipefail + +┌──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┐ +│ Hostname CWD Timestamp Runtime Exit Code Command │ +│──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────│ +│ localhost /tmp/ Apr 16 2022 01:36:26 PDT 1s 2 third_entry │ +│ localhost /tmp/ Apr 16 2022 01:19:46 PDT 1s 2 second_entry │ +│ localhost /tmp/ Apr 16 2022 01:03:06 PDT 1s 2 first_entry │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +│ │ +└──────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────────┘ +hiSHtory: Search your shell history • ctrl+h help \ No newline at end of file diff --git a/client/lib/lib.go b/client/lib/lib.go index eb7932d..cf9e611 100644 --- a/client/lib/lib.go +++ b/client/lib/lib.go @@ -117,7 +117,7 @@ func AddToDbIfNew(db *gorm.DB, entry data.HistoryEntry) { var results []data.HistoryEntry tx.Limit(1).Find(&results) if len(results) == 0 { - db.Create(entry) + db.Create(normalizeEntryTimezone(entry)) // TODO: check the error here and bubble it up } } @@ -146,13 +146,13 @@ func buildTableRow(ctx context.Context, columnNames []string, entry data.History case "CWD": row = append(row, entry.CurrentWorkingDirectory) case "Timestamp": - row = append(row, entry.StartTime.Format(hctx.GetConf(ctx).TimestampFormat)) + row = append(row, entry.StartTime.Local().Format(hctx.GetConf(ctx).TimestampFormat)) case "Runtime": if entry.EndTime == time.Unix(0, 0) { // An EndTime of zero means this is a pre-saved entry that never finished row = append(row, "N/A") } else { - row = append(row, entry.EndTime.Sub(entry.StartTime).Round(time.Millisecond).String()) + row = append(row, entry.EndTime.Local().Sub(entry.StartTime.Local()).Round(time.Millisecond).String()) } case "Exit Code": row = append(row, fmt.Sprintf("%d", entry.ExitCode)) @@ -301,8 +301,8 @@ func ImportHistory(ctx context.Context, shouldReadStdin, force bool) (int, error CurrentWorkingDirectory: "Unknown", HomeDirectory: homedir, ExitCode: 0, - StartTime: time.Now(), - EndTime: time.Now(), + StartTime: time.Now().UTC(), + EndTime: time.Now().UTC(), DeviceId: config.DeviceId, } err = ReliableDbCreate(db, entry) @@ -699,7 +699,14 @@ func IsOfflineError(err error) bool { strings.Contains(err.Error(), "net/http: TLS handshake timeout") } -func ReliableDbCreate(db *gorm.DB, entry interface{}) error { +func normalizeEntryTimezone(entry data.HistoryEntry) data.HistoryEntry { + entry.StartTime = entry.StartTime.UTC() + entry.EndTime = entry.EndTime.UTC() + return entry +} + +func ReliableDbCreate(db *gorm.DB, entry data.HistoryEntry) error { + entry = normalizeEntryTimezone(entry) var err error = nil i := 0 for i = 0; i < 10; i++ { @@ -892,7 +899,6 @@ func Search(ctx context.Context, db *gorm.DB, query string, limit int) ([]*data. if err != nil { return nil, err } - // TODO: This ordering isn't sufficient if some computers are in different timezones. Add better sorting here. if hctx.GetConf(ctx).BetaMode { tx = tx.Order("start_time DESC") } else { diff --git a/shared/testutils/testutils.go b/shared/testutils/testutils.go index 4ad1247..77ec18a 100644 --- a/shared/testutils/testutils.go +++ b/shared/testutils/testutils.go @@ -311,8 +311,8 @@ func MakeFakeHistoryEntry(command string) data.HistoryEntry { CurrentWorkingDirectory: "/tmp/", HomeDirectory: "/home/david/", ExitCode: 2, - StartTime: time.Unix(fakeHistoryTimestamp, 0), - EndTime: time.Unix(fakeHistoryTimestamp+3, 0), + StartTime: time.Unix(fakeHistoryTimestamp, 0).UTC(), + EndTime: time.Unix(fakeHistoryTimestamp+3, 0).UTC(), } }