From c9dd3a73c6be9e8b49c345969a46a5e244223f61 Mon Sep 17 00:00:00 2001 From: Diogenesoftoronto <87236699+Diogenesoftoronto@users.noreply.github.com> Date: Thu, 25 Jan 2024 10:16:03 -0500 Subject: [PATCH] Add timestamps to Preservation tasks Adds timestamps to Preservations Tasks and gives additional details to the user in the enduro dashboard about when archivematica jobs started and finished. Closes #832 --- go.mod | 4 +- go.sum | 8 +- internal/am/job_tracker.go | 43 +++++++-- internal/am/job_tracker_test.go | 141 +++++++++++++++++++++++++++--- internal/am/poll_ingest_test.go | 27 +++--- internal/am/poll_transfer_test.go | 37 ++++---- 6 files changed, 209 insertions(+), 51 deletions(-) diff --git a/go.mod b/go.mod index 01292e606..0ca54652f 100644 --- a/go.mod +++ b/go.mod @@ -20,7 +20,7 @@ require ( github.com/go-sql-driver/mysql v1.7.1 github.com/golang-migrate/migrate/v4 v4.17.0 github.com/google/go-cmp v0.6.0 - github.com/google/uuid v1.5.0 + github.com/google/uuid v1.6.0 github.com/gorilla/websocket v1.5.1 github.com/hashicorp/go-cleanhttp v0.5.2 github.com/jmoiron/sqlx v1.3.5 @@ -39,7 +39,7 @@ require ( github.com/spf13/pflag v1.0.5 github.com/spf13/viper v1.18.2 github.com/stretchr/testify v1.8.4 - go.artefactual.dev/amclient v0.2.0 + go.artefactual.dev/amclient v0.3.0 go.artefactual.dev/tools v0.8.0 go.opentelemetry.io/otel v1.21.0 go.opentelemetry.io/otel/exporters/otlp/otlptrace/otlptracegrpc v1.21.0 diff --git a/go.sum b/go.sum index 263506854..b10b5c6e5 100644 --- a/go.sum +++ b/go.sum @@ -1100,8 +1100,8 @@ github.com/google/subcommands v1.0.1/go.mod h1:ZjhPrFU+Olkh9WazFPsl27BQ4UPiG37m3 github.com/google/uuid v1.0.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/google/uuid v1.1.2/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/google/uuid v1.3.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= -github.com/google/uuid v1.5.0 h1:1p67kYwdtXjb0gL0BPiP1Av9wiZPo5A8z2cWkTZ+eyU= -github.com/google/uuid v1.5.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= +github.com/google/uuid v1.6.0 h1:NIvaJDMOsjHA8n1jAhLSgzrAzy1Hgr+hNrb57e+94F0= +github.com/google/uuid v1.6.0/go.mod h1:TIyPZe4MgqvfeYDBFedMoGGpEw/LqOeaOT+nhxU+yHo= github.com/google/wire v0.5.0 h1:I7ELFeVBr3yfPIcc8+MWvrjk+3VjbcSzoXm3JVa+jD8= github.com/google/wire v0.5.0/go.mod h1:ngWDr9Qvq3yZA10YrxfyGELY/AFWGVpy9c1LTRi1EoU= github.com/googleapis/enterprise-certificate-proxy v0.0.0-20220520183353-fd19c99a87aa/go.mod h1:17drOmN3MwGY7t0e+Ei9b45FFGA3fBs3x36SsCg1hq8= @@ -1370,8 +1370,8 @@ github.com/zclconf/go-cty v1.14.1 h1:t9fyA35fwjjUMcmL5hLER+e/rEPqrbCK1/OSE4SI9KA github.com/zclconf/go-cty v1.14.1/go.mod h1:VvMs5i0vgZdhYawQNq5kePSpLAoz8u1xvZgrPIxfnZE= github.com/zeebo/assert v1.3.0/go.mod h1:Pq9JiuJQpG8JLJdtkwrJESF0Foym2/D9XMU5ciN/wJ0= github.com/zeebo/xxh3 v1.0.2/go.mod h1:5NWz9Sef7zIDm2JHfFlcQvNekmcEl9ekUZQQKCYaDcA= -go.artefactual.dev/amclient v0.2.0 h1:fO1lUsxaG23EGtbgPBfye5+ytnqg3H7BxAoAaQr0Mqc= -go.artefactual.dev/amclient v0.2.0/go.mod h1:jAJ98cSJ7QDSgMq/YUkmGpAJ4ssSzbIUN7XpynCa6uA= +go.artefactual.dev/amclient v0.3.0 h1:biXZobSWJCzwpJOYtlQzOkClOv2u5mB1TKA4023B7zw= +go.artefactual.dev/amclient v0.3.0/go.mod h1:jAJ98cSJ7QDSgMq/YUkmGpAJ4ssSzbIUN7XpynCa6uA= go.artefactual.dev/tools v0.8.0 h1:PYmurlVFIA5hA2p/lX4wq+sHkIhezN8kCpiBDT0NaFA= go.artefactual.dev/tools v0.8.0/go.mod h1:tBZMFxz4jkQK5MW+uDROYaAkTGQSG0lJgCVhqDbQ1Dg= go.opencensus.io v0.21.0/go.mod h1:mSImk1erAIZhrmZN+AvHh14ztQfjbGwt4TtuofqLduU= diff --git a/internal/am/job_tracker.go b/internal/am/job_tracker.go index 7f5f0867e..7090020c4 100644 --- a/internal/am/job_tracker.go +++ b/internal/am/job_tracker.go @@ -62,7 +62,9 @@ func (jt *JobTracker) SavePreservationTasks(ctx context.Context, unitID string) // list requests a job list for unitID from the Archivematica jobs endpoint. func (jt *JobTracker) list(ctx context.Context, unitID string) ([]amclient.Job, error) { - jobs, httpResp, err := jt.jobSvc.List(ctx, unitID, &amclient.JobsListRequest{}) + jobs, httpResp, err := jt.jobSvc.List(ctx, unitID, &amclient.JobsListRequest{ + Detailed: true, + }) if err != nil { return nil, convertAMClientError(httpResp, err) } @@ -83,10 +85,6 @@ func (jt *JobTracker) savePreservationTasks(ctx context.Context, jobs []amclient pt := ConvertJobToPreservationTask(job) pt.PreservationActionID = jt.presActionID - now := sql.NullTime{Time: jt.clock.Now(), Valid: true} - pt.StartedAt = now - pt.CompletedAt = now - err := jt.pkgSvc.CreatePreservationTask(ctx, &pt) if err != nil { return 0, err @@ -115,9 +113,38 @@ func filterSavedJobs(jobs []amclient.Job, saved map[string]struct{}) []amclient. // ConvertJobToPreservationTask converts an amclient.Job to a // package_.PreservationTask. func ConvertJobToPreservationTask(job amclient.Job) package_.PreservationTask { + st, co := jobTimeRange(job) return package_.PreservationTask{ - TaskID: job.ID, - Name: job.Name, - Status: jobStatusToPreservationTaskStatus[job.Status], + TaskID: job.ID, + Name: job.Name, + Status: jobStatusToPreservationTaskStatus[job.Status], + StartedAt: st, + CompletedAt: co, + } +} + +// jobTimeRange calculates the overall start and end times for a job. +func jobTimeRange(job amclient.Job) (sql.NullTime, sql.NullTime) { + if len(job.Tasks) == 0 { + return sql.NullTime{}, sql.NullTime{} + } + st := job.Tasks[0].StartedAt.Time + ct := job.Tasks[0].CompletedAt.Time + + for _, t := range job.Tasks[1:] { + // Update st to the earliest task start time. + if st.After(t.StartedAt.Time) { + st = t.StartedAt.Time + } + // Update ct to the latest task completion time. + if ct.Before(t.CompletedAt.Time) { + ct = t.CompletedAt.Time + } } + + // Emit NULLs if we see the zero value. + start := sql.NullTime{Time: st, Valid: !st.IsZero()} + end := sql.NullTime{Time: ct, Valid: !ct.IsZero()} + + return start, end } diff --git a/internal/am/job_tracker_test.go b/internal/am/job_tracker_test.go index 4a42a603e..2e655627c 100644 --- a/internal/am/job_tracker_test.go +++ b/internal/am/job_tracker_test.go @@ -2,10 +2,11 @@ package am_test import ( "context" - "database/sql" "net/http" "testing" + "time" + "entgo.io/ent/dialect/sql" "github.com/google/uuid" "github.com/jonboulle/clockwork" "go.artefactual.dev/amclient" @@ -16,6 +17,7 @@ import ( "gotest.tools/v3/assert" "github.com/artefactual-sdps/enduro/internal/am" + "github.com/artefactual-sdps/enduro/internal/package_" fake_package "github.com/artefactual-sdps/enduro/internal/package_/fake" ) @@ -26,12 +28,13 @@ func TestJobTracker(t *testing.T) { unitID := uuid.New().String() clock := clockwork.NewFakeClock() - nullTime := sql.NullTime{Time: clock.Now(), Valid: true} httpError := func(m *amclienttest.MockJobsServiceMockRecorder, statusCode int) { m.List( mockutil.Context(), unitID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( nil, &amclient.Response{Response: &http.Response{StatusCode: statusCode}}, @@ -48,8 +51,12 @@ func TestJobTracker(t *testing.T) { Status: amclient.JobStatusComplete, Tasks: []amclient.Task{ { - ID: "c134198c-9485-4f68-8d94-4da1e03b5e1b", - ExitCode: 0, + ID: "c134198c-9485-4f68-8d94-4da1e03b5e1b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), }, }, }, @@ -61,8 +68,12 @@ func TestJobTracker(t *testing.T) { Status: amclient.JobStatusComplete, Tasks: []amclient.Task{ { - ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", - ExitCode: 0, + ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 1, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Minute), }, }, }, @@ -85,7 +96,9 @@ func TestJobTracker(t *testing.T) { m.List( mockutil.Context(), unitID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( jobs, &amclient.Response{ @@ -98,8 +111,6 @@ func TestJobTracker(t *testing.T) { for _, job := range jobs { pt := am.ConvertJobToPreservationTask(job) pt.PreservationActionID = paID - pt.StartedAt = nullTime - pt.CompletedAt = nullTime m.CreatePreservationTask(mockutil.Context(), &pt).Return(nil) } }, @@ -113,7 +124,9 @@ func TestJobTracker(t *testing.T) { m.List( mockutil.Context(), unitID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( nil, &amclient.Response{ @@ -161,3 +174,109 @@ func TestJobTracker(t *testing.T) { }) } } + +func TestConvertJobToPreservationTask(t *testing.T) { + t.Parallel() + + type test struct { + name string + job amclient.Job + want package_.PreservationTask + } + + for _, tt := range []test{ + { + name: "Returns preservation task with computed time range", + job: amclient.Job{ + ID: "f60018ac-da79-4769-9509-c6c41d5efe7e", + LinkID: "70669a5b-01e4-4ea0-ac70-10292f87da05", + Microservice: "Verify SIP compliance", + Name: "Move to processing directory", + Status: amclient.JobStatusComplete, + Tasks: []amclient.Task{ + { + ID: "c134198c-9485-4f68-8d94-4da1e03b5e1b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2025, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), + }, + { + ID: "6e5edf16-ff93-47c0-a7d1-e623c110fa09", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2025, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2026, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), + }, + }, + }, + want: package_.PreservationTask{ + TaskID: "f60018ac-da79-4769-9509-c6c41d5efe7e", + Name: "Move to processing directory", + Status: package_.PreservationTaskStatus(package_.StatusDone), + StartedAt: sql.NullTime{ + Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC), + Valid: true, + }, + CompletedAt: sql.NullTime{ + Time: time.Date(2026, time.January, 18, 1, 27, 49, 0, time.UTC), + Valid: true, + }, + }, + }, + { + name: "Returns NULL completedAt if job is still processing", + job: amclient.Job{ + ID: "c2128d39-2ace-47c5-8cac-39ded8d9c9ef", + LinkID: "208d441b-6938-44f9-b54a-bd73f05bc764", + Microservice: "Verify SIP compliance", + Name: "Verify SIP compliance", + Status: amclient.JobStatusProcessing, + Tasks: []amclient.Task{ + { + ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Time{}}, + Duration: amclient.TaskDuration(time.Second / 2), + }, + { + ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2025, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2025, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Time{}}, + Duration: amclient.TaskDuration(time.Second / 2), + }, + }, + }, + want: package_.PreservationTask{ + TaskID: "c2128d39-2ace-47c5-8cac-39ded8d9c9ef", + Name: "Verify SIP compliance", + Status: package_.PreservationTaskStatus(package_.StatusInProgress), + StartedAt: sql.NullTime{ + Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC), + Valid: true, + }, + CompletedAt: sql.NullTime{}, + }, + }, + { + name: "Returns NULL timestamps in the job has no tasks", + job: amclient.Job{}, + want: package_.PreservationTask{}, + }, + } { + tt := tt + t.Run(tt.name, func(t *testing.T) { + t.Parallel() + + got := am.ConvertJobToPreservationTask(tt.job) + + assert.DeepEqual(t, got, tt.want) + }) + } +} diff --git a/internal/am/poll_ingest_test.go b/internal/am/poll_ingest_test.go index 79114aedd..504c44d87 100644 --- a/internal/am/poll_ingest_test.go +++ b/internal/am/poll_ingest_test.go @@ -1,7 +1,6 @@ package am_test import ( - "database/sql" "net/http" "testing" "time" @@ -25,7 +24,6 @@ import ( func TestPollIngestActivity(t *testing.T) { clock := clockwork.NewFakeClock() - nullTime := sql.NullTime{Time: clock.Now(), Valid: true} path := "/var/archivematica/fake/sip" presActionID := uint(2) sipID := uuid.New().String() @@ -50,8 +48,12 @@ func TestPollIngestActivity(t *testing.T) { LinkID: "70669a5b-01e4-4ea0-ac70-10292f87da05", Tasks: []amclient.Task{ { - ID: "9dc0b71a-cbb1-40f4-9fa4-647cc16c8ed5", - ExitCode: 0, + ID: "9dc0b71a-cbb1-40f4-9fa4-647cc16c8ed5", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), }, }, }, @@ -63,8 +65,10 @@ func TestPollIngestActivity(t *testing.T) { LinkID: "208d441b-6938-44f9-b54a-bd73f05bc764", Tasks: []amclient.Task{ { - ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", - ExitCode: 0, + ID: "6f5beca3-71ad-446c-8f19-3bc4dea16c9b", + ExitCode: 0, + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), }, }, }, @@ -127,7 +131,9 @@ func TestPollIngestActivity(t *testing.T) { m.List( mockutil.Context(), sipID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( jobs[:1], &amclient.Response{Response: &http200Resp}, @@ -138,7 +144,9 @@ func TestPollIngestActivity(t *testing.T) { m.List( mockutil.Context(), sipID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( jobs, &amclient.Response{Response: &http200Resp}, @@ -150,8 +158,7 @@ func TestPollIngestActivity(t *testing.T) { for i, job := range jobs { pt := am.ConvertJobToPreservationTask(job) pt.PreservationActionID = presActionID - pt.CompletedAt = nullTime - pt.StartedAt = nullTime + tasks[i] = &pt } diff --git a/internal/am/poll_transfer_test.go b/internal/am/poll_transfer_test.go index 45d8b909a..43602d0fd 100644 --- a/internal/am/poll_transfer_test.go +++ b/internal/am/poll_transfer_test.go @@ -1,7 +1,6 @@ package am_test import ( - "database/sql" "net/http" "testing" "time" @@ -29,16 +28,10 @@ var ( func TestPollTransferActivity(t *testing.T) { t.Parallel() - transferID := uuid.New().String() presActionID := uint(1) sipID := uuid.New().String() path := "/var/archivematica/fake/sip" - ttime, err := time.Parse(time.RFC3339, "2023-12-05T12:02:00Z") - if err != nil { - t.Fatal("Invalid test time") - } - nullTime := sql.NullTime{Time: ttime, Valid: true} jobs := []amclient.Job{ { @@ -49,8 +42,13 @@ func TestPollTransferActivity(t *testing.T) { LinkID: "541f5994-73b0-45bb-9cb5-367c06a21be7", Tasks: []amclient.Task{ { - ID: "11566538-66c5-4a20-aa70-77f7a9fa83d5", - ExitCode: 0, + ID: "11566538-66c5-4a20-aa70-77f7a9fa83d5", + ExitCode: 0, + Filename: "Images-94ade01c-49ce-49e0-9cc3-805575c676d0", + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + StartedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + CompletedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), }, }, }, @@ -62,8 +60,12 @@ func TestPollTransferActivity(t *testing.T) { LinkID: "045c43ae-d6cf-44f7-97d6-c8a602748565", Tasks: []amclient.Task{ { - ID: "53666170-0397-4962-8736-23295444b036", - ExitCode: 0, + ID: "53666170-0397-4962-8736-23295444b036", + ExitCode: 0, + FileID: "", + Filename: "Images-94ade01c-49ce-49e0-9cc3-805575c676d0", + CreatedAt: amclient.TaskDateTime{Time: time.Date(2024, time.January, 18, 1, 27, 49, 0, time.UTC)}, + Duration: amclient.TaskDuration(time.Second / 2), }, }, }, @@ -124,7 +126,9 @@ func TestPollTransferActivity(t *testing.T) { m.List( mockutil.Context(), transferID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( jobs, &amclient.Response{Response: &http200Resp}, @@ -136,7 +140,9 @@ func TestPollTransferActivity(t *testing.T) { m.List( mockutil.Context(), transferID, - &amclient.JobsListRequest{}, + &amclient.JobsListRequest{ + Detailed: true, + }, ).Return( jobs, &amclient.Response{Response: &http200Resp}, @@ -148,9 +154,8 @@ func TestPollTransferActivity(t *testing.T) { for _, job := range jobs { pt := am.ConvertJobToPreservationTask(job) pt.PreservationActionID = presActionID - pt.CompletedAt = nullTime - pt.StartedAt = nullTime m.CreatePreservationTask(mockutil.Context(), &pt).Return(nil) + } }, want: am.PollTransferActivityResult{ @@ -293,7 +298,7 @@ func TestPollTransferActivity(t *testing.T) { am.NewPollTransferActivity( logr.Discard(), &am.Config{PollInterval: time.Millisecond * 10}, - clockwork.NewFakeClockAt(ttime), + clockwork.NewFakeClock(), trfSvc, jobSvc, pkgSvc,