From 993bdd2b25a3525d7b4819f800a96729124b96cc Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Wed, 6 Sep 2023 08:34:04 -0400 Subject: [PATCH 01/33] don't repeat log attributes during publishing --- internal/publish/publish.go | 24 ++++++++++-------------- 1 file changed, 10 insertions(+), 14 deletions(-) diff --git a/internal/publish/publish.go b/internal/publish/publish.go index af29fcf0d..ab21c95b9 100644 --- a/internal/publish/publish.go +++ b/internal/publish/publish.go @@ -120,7 +120,7 @@ type DeploymentNotFoundDetails struct { ContentID types.ContentID } -func withLog[T any](op events.Operation, msg string, log logging.Logger, fn func() (T, error)) (value T, err error) { +func withLog[T any](op events.Operation, msg string, label string, log logging.Logger, fn func() (T, error)) (value T, err error) { log = log.With(logging.LogKeyOp, op) log.Start(msg) value, err = fn() @@ -130,14 +130,13 @@ func withLog[T any](op events.Operation, msg string, log logging.Logger, fn func err = types.ErrToAgentError(op, err) return } - log.Success("Done " + msg) + log.Success("Done", label, value) return value, nil } func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, account *accounts.Account, client clients.APIClient, log logging.Logger) error { - log = log.With( - "server", account.URL, - logging.LogKeyOp, events.PublishCreateBundleOp) + log.Info("Starting deployment to server", "server", account.URL) + log = log.With(logging.LogKeyOp, events.PublishCreateBundleOp) log.Start("Creating bundle") bundleFile, err := os.CreateTemp("", "bundle-*.tar.gz") if err != nil { @@ -159,9 +158,8 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco var contentID types.ContentID if cmd.State.Target.ContentId != "" && !cmd.New { contentID = cmd.State.Target.ContentId - log = log.With("content_id", contentID) - _, err := withLog(events.PublishCreateDeploymentOp, "Updating deployment", log, func() (any, error) { - return nil, client.UpdateDeployment(contentID, cmd.State.Connect.Content) + _, err := withLog(events.PublishCreateDeploymentOp, "Updating deployment", "content_id", log, func() (any, error) { + return contentID, client.UpdateDeployment(contentID, cmd.State.Connect.Content) }) if err != nil { httpErr, ok := err.(*clients.HTTPError) @@ -174,22 +172,21 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco return err } } else { - contentID, err = withLog(events.PublishCreateDeploymentOp, "Creating deployment", log, func() (types.ContentID, error) { + contentID, err = withLog(events.PublishCreateDeploymentOp, "Creating deployment", "content_id", log, func() (types.ContentID, error) { return client.CreateDeployment(cmd.State.Connect.Content) }) if err != nil { return err } - log = log.With("content_id", contentID) + log.Info("content_id", contentID) } - bundleID, err := withLog(events.PublishUploadBundleOp, "Uploading deployment bundle", log, func() (types.BundleID, error) { + bundleID, err := withLog(events.PublishUploadBundleOp, "Uploading deployment bundle", "bundle_id", log, func() (types.BundleID, error) { return client.UploadBundle(contentID, bundleFile) }) if err != nil { return err } - log = log.With("bundle_id", bundleID) cmd.State.Target = state.TargetID{ ServerType: account.ServerType, @@ -202,13 +199,12 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco DeployedAt: types.NewOptional(time.Now()), } - taskID, err := withLog(events.PublishDeployBundleOp, "Initiating bundle deployment", log, func() (types.TaskID, error) { + taskID, err := withLog(events.PublishDeployBundleOp, "Initiating bundle deployment", "task_id", log, func() (types.TaskID, error) { return client.DeployBundle(contentID, bundleID) }) if err != nil { return err } - log = log.With("task_id", taskID) taskLogger := log.With("source", "serverLog") err = client.WaitForTask(taskID, taskLogger) From 387dc435ef569dfe9e8072d35effe438ba992d6d Mon Sep 17 00:00:00 2001 From: tdstein Date: Thu, 7 Sep 2023 12:15:33 -0400 Subject: [PATCH 02/33] Fixes ignore matching on directories --- internal/bundles/gitignore/gitignore.go | 3 ++- internal/bundles/gitignore/gitignore_test.go | 13 +++++++++++++ test/sample-content/fastapi-simple/.gitignore | 1 + 3 files changed, 16 insertions(+), 1 deletion(-) create mode 100644 test/sample-content/fastapi-simple/.gitignore diff --git a/internal/bundles/gitignore/gitignore.go b/internal/bundles/gitignore/gitignore.go index f76b3c7f4..3aaa9f9df 100644 --- a/internal/bundles/gitignore/gitignore.go +++ b/internal/bundles/gitignore/gitignore.go @@ -319,7 +319,8 @@ func (ign *GitIgnoreList) match(path string, info os.FileInfo) *Match { // Match returns whether any of the globs in the ignore list match the // specified path. Uses the same matching rules as .gitignore files. func (ign *GitIgnoreList) Match(path string) *Match { - return ign.match(path, nil) + stat, _ := ign.fs.Stat(path) + return ign.match(path, stat) } // Walk walks the file tree with the specified root and calls fn on each file diff --git a/internal/bundles/gitignore/gitignore_test.go b/internal/bundles/gitignore/gitignore_test.go index d0b247d15..5311edd96 100644 --- a/internal/bundles/gitignore/gitignore_test.go +++ b/internal/bundles/gitignore/gitignore_test.go @@ -75,4 +75,17 @@ func (s *GitIgnoreSuite) TestMatch() { s.Equal("*.bak", m.Pattern) s.Equal("", m.FilePath) s.Equal(0, m.Line) + + ignoredir := s.cwd.Join("ignoredir") + err = ignoredir.MkdirAll(0700) + s.NoError(err) + err = ign.AppendGlobs([]string{"ignoredir/"}, MatchSourceUser) + s.NoError(err) + + m = ign.Match(ignoredir.Path()) + s.NotNil(m) + s.Equal(MatchSourceUser, m.Source) + s.Equal("ignoredir/", m.Pattern) + s.Equal("", m.FilePath) + s.Equal(0, m.Line) } diff --git a/test/sample-content/fastapi-simple/.gitignore b/test/sample-content/fastapi-simple/.gitignore new file mode 100644 index 000000000..1d17dae13 --- /dev/null +++ b/test/sample-content/fastapi-simple/.gitignore @@ -0,0 +1 @@ +.venv From 6be8d6ed9b59028934f3e70540ae9d657e9d43c1 Mon Sep 17 00:00:00 2001 From: tdstein Date: Thu, 7 Sep 2023 12:56:22 -0400 Subject: [PATCH 03/33] Modifies IgnoreList interface --- internal/bundles/gitignore/gitignore.go | 11 ++++++++--- internal/bundles/gitignore/gitignore_test.go | 12 ++++++++---- internal/bundles/gitignore/interface.go | 8 +++++--- internal/services/api/files/files.go | 6 +++++- internal/services/api/files/services.go | 6 +++++- 5 files changed, 31 insertions(+), 12 deletions(-) diff --git a/internal/bundles/gitignore/gitignore.go b/internal/bundles/gitignore/gitignore.go index 3aaa9f9df..db7fc4d05 100644 --- a/internal/bundles/gitignore/gitignore.go +++ b/internal/bundles/gitignore/gitignore.go @@ -318,9 +318,14 @@ func (ign *GitIgnoreList) match(path string, info os.FileInfo) *Match { // Match returns whether any of the globs in the ignore list match the // specified path. Uses the same matching rules as .gitignore files. -func (ign *GitIgnoreList) Match(path string) *Match { - stat, _ := ign.fs.Stat(path) - return ign.match(path, stat) +func (ign *GitIgnoreList) Match(path string) (*Match, error) { + stat, err := ign.fs.Stat(path) + if err != nil { + if !os.IsNotExist(err) { + return nil, err + } + } + return ign.match(path, stat), nil } // Walk walks the file tree with the specified root and calls fn on each file diff --git a/internal/bundles/gitignore/gitignore_test.go b/internal/bundles/gitignore/gitignore_test.go index 5311edd96..9e8a212d8 100644 --- a/internal/bundles/gitignore/gitignore_test.go +++ b/internal/bundles/gitignore/gitignore_test.go @@ -57,11 +57,13 @@ func (s *GitIgnoreSuite) TestMatch() { s.NoError(err) // Match returns nil if no match - m := ign.Match("app.py") + m, err := ign.Match("app.py") + s.Nil(err) s.Nil(m) // File matches include file info - m = ign.Match(".Rhistory") + m, err = ign.Match(".Rhistory") + s.Nil(err) s.NotNil(m) s.Equal(MatchSourceFile, m.Source) s.Equal(".Rhistory", m.Pattern) @@ -69,7 +71,8 @@ func (s *GitIgnoreSuite) TestMatch() { s.Equal(1, m.Line) // Non-file matches don't include file info - m = ign.Match("app.py.bak") + m, err = ign.Match("app.py.bak") + s.Nil(err) s.NotNil(m) s.Equal(MatchSourceUser, m.Source) s.Equal("*.bak", m.Pattern) @@ -82,7 +85,8 @@ func (s *GitIgnoreSuite) TestMatch() { err = ign.AppendGlobs([]string{"ignoredir/"}, MatchSourceUser) s.NoError(err) - m = ign.Match(ignoredir.Path()) + m, err = ign.Match(ignoredir.Path()) + s.Nil(err) s.NotNil(m) s.Equal(MatchSourceUser, m.Source) s.Equal("ignoredir/", m.Pattern) diff --git a/internal/bundles/gitignore/interface.go b/internal/bundles/gitignore/interface.go index 0ab74568d..0a9721be8 100644 --- a/internal/bundles/gitignore/interface.go +++ b/internal/bundles/gitignore/interface.go @@ -12,7 +12,7 @@ type IgnoreList interface { Append(path util.Path) error AppendGlobs(patterns []string, source MatchSource) error AppendGit() error - Match(path string) *Match + Match(path string) (*Match, error) Walk(root util.Path, fn util.WalkFunc) error } @@ -38,9 +38,9 @@ func (m *MockGitIgnoreList) AppendGit() error { return args.Error(0) } -func (m *MockGitIgnoreList) Match(path string) bool { +func (m *MockGitIgnoreList) Match(path string) (*Match, error) { args := m.Called(path) - return args.Bool(0) + return args.Get(0).(*Match), args.Error(1) } func (m *MockGitIgnoreList) Walk(root util.Path, fn util.WalkFunc) error { @@ -48,6 +48,8 @@ func (m *MockGitIgnoreList) Walk(root util.Path, fn util.WalkFunc) error { return args.Error(0) } +var _ IgnoreList = &MockGitIgnoreList{} + // Maintain a reference to the original gitignore so it // and its license remain in our vendor directory. type _ gitignore.IgnoreList diff --git a/internal/services/api/files/files.go b/internal/services/api/files/files.go index eee18ad19..4770d2bc9 100644 --- a/internal/services/api/files/files.go +++ b/internal/services/api/files/files.go @@ -86,7 +86,11 @@ func (f *File) insert(root util.Path, path util.Path, ignore gitignore.IgnoreLis } // otherwise, create it - exclusion := ignore.Match(path.Path()) + exclusion, err := ignore.Match(path.Path()) + if err != nil { + return nil, err + } + child, err := CreateFile(root, path, exclusion) if err != nil { return nil, err diff --git a/internal/services/api/files/services.go b/internal/services/api/files/services.go index 71a698900..59ef7b3b1 100644 --- a/internal/services/api/files/services.go +++ b/internal/services/api/files/services.go @@ -38,7 +38,11 @@ type filesService struct { func (s filesService) GetFile(p util.Path) (*File, error) { p = p.Clean() - m := s.ignore.Match(p.String()) + m, err := s.ignore.Match(p.String()) + if err != nil { + return nil, err + } + file, err := CreateFile(s.root, p, m) if err != nil { return nil, err From 5be263e7e7e8a14f75f6b602e7bf252c22ac90a8 Mon Sep 17 00:00:00 2001 From: tdstein Date: Thu, 7 Sep 2023 13:03:34 -0400 Subject: [PATCH 04/33] Changes error assertions to NoError --- internal/bundles/gitignore/gitignore_test.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/internal/bundles/gitignore/gitignore_test.go b/internal/bundles/gitignore/gitignore_test.go index 9e8a212d8..9463a0f3a 100644 --- a/internal/bundles/gitignore/gitignore_test.go +++ b/internal/bundles/gitignore/gitignore_test.go @@ -58,12 +58,12 @@ func (s *GitIgnoreSuite) TestMatch() { // Match returns nil if no match m, err := ign.Match("app.py") - s.Nil(err) + s.NoError(err) s.Nil(m) // File matches include file info m, err = ign.Match(".Rhistory") - s.Nil(err) + s.NoError(err) s.NotNil(m) s.Equal(MatchSourceFile, m.Source) s.Equal(".Rhistory", m.Pattern) @@ -72,7 +72,7 @@ func (s *GitIgnoreSuite) TestMatch() { // Non-file matches don't include file info m, err = ign.Match("app.py.bak") - s.Nil(err) + s.NoError(err) s.NotNil(m) s.Equal(MatchSourceUser, m.Source) s.Equal("*.bak", m.Pattern) @@ -86,7 +86,7 @@ func (s *GitIgnoreSuite) TestMatch() { s.NoError(err) m, err = ign.Match(ignoredir.Path()) - s.Nil(err) + s.NoError(err) s.NotNil(m) s.Equal(MatchSourceUser, m.Source) s.Equal("ignoredir/", m.Pattern) From 9cbe75bdb1686e9180dee422b9014e4b3d2ed29d Mon Sep 17 00:00:00 2001 From: tdstein Date: Fri, 8 Sep 2023 10:49:40 -0400 Subject: [PATCH 05/33] Removes non-regular files from file count --- web/src/components/panels/FilesToPublish.vue | 10 ++++++++-- 1 file changed, 8 insertions(+), 2 deletions(-) diff --git a/web/src/components/panels/FilesToPublish.vue b/web/src/components/panels/FilesToPublish.vue index 8c5082fe6..0e3e90d7b 100644 --- a/web/src/components/panels/FilesToPublish.vue +++ b/web/src/components/panels/FilesToPublish.vue @@ -34,7 +34,7 @@ const deploymentStore = useDeploymentStore(); const files = ref([]); const expanded = ref([]); -type FileInfo = Pick; +type FileInfo = Pick; const fileMap = ref(new Map()); @@ -56,9 +56,14 @@ const selectedFileTotalSize = computed(() : string => { }); const fileSummary = computed(() => { - const count = deploymentStore.files.length; const path = deploymentStore.deployment?.sourcePath; + // Calculate the number of files that are "files" (i.e., regular files, not directories, symlinks, etc.) + const count = deploymentStore.files + .map(file => fileMap.value.get(file)) + .filter(info => info?.isFile) + .length; + if (count) { return `${count} files selected from ${path} (total = ${selectedFileTotalSize.value})`; } else if (path) { @@ -83,6 +88,7 @@ function populateFileMap(file: DeploymentFile) { size: file.size, isEntrypoint: file.isEntrypoint, exclusion: file.exclusion, + isFile: file.isFile }; fileMap.value.set(file.id, info); file.files.forEach(populateFileMap); From 52b5e3f01bd688cf52fa96fd645c3400e9c11196 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Mon, 11 Sep 2023 13:37:12 -0400 Subject: [PATCH 06/33] resolve duplicate event_op attributes --- internal/publish/publish.go | 8 ++++---- 1 file changed, 4 insertions(+), 4 deletions(-) diff --git a/internal/publish/publish.go b/internal/publish/publish.go index ab21c95b9..1ed1f6332 100644 --- a/internal/publish/publish.go +++ b/internal/publish/publish.go @@ -136,8 +136,6 @@ func withLog[T any](op events.Operation, msg string, label string, log logging.L func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, account *accounts.Account, client clients.APIClient, log logging.Logger) error { log.Info("Starting deployment to server", "server", account.URL) - log = log.With(logging.LogKeyOp, events.PublishCreateBundleOp) - log.Start("Creating bundle") bundleFile, err := os.CreateTemp("", "bundle-*.tar.gz") if err != nil { return types.ErrToAgentError(events.PublishCreateBundleOp, err) @@ -145,7 +143,10 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco defer os.Remove(bundleFile.Name()) defer bundleFile.Close() - _, err = bundler.CreateBundle(bundleFile) + _, err = withLog(events.PublishCreateBundleOp, "Creating bundle", "filename", log, func() (any, error) { + _, err := bundler.CreateBundle(bundleFile) + return bundleFile.Name(), err + }) if err != nil { return types.ErrToAgentError(events.PublishCreateBundleOp, err) } @@ -153,7 +154,6 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco if err != nil { return types.ErrToAgentError(events.PublishCreateBundleOp, err) } - log.Success("Done creating bundle") var contentID types.ContentID if cmd.State.Target.ContentId != "" && !cmd.New { From c980001efb3a04beacb7bed80a5346614bdb9f39 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Mon, 11 Sep 2023 13:37:28 -0400 Subject: [PATCH 07/33] add progress events for package actions --- internal/api_client/clients/client_connect.go | 73 ++++++++++++++++++- 1 file changed, 69 insertions(+), 4 deletions(-) diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index b447c2ef6..8fceb5f30 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -241,19 +241,73 @@ func (c *ConnectClient) getTask(taskID types.TaskID, previous *taskDTO) (*taskDT return &task, nil } +var buildAPIPattern = regexp.MustCompile("Building (Shiny application|Plumber API).*") +var buildAppPattern = regexp.MustCompile("Building (.* application|.* API|Jupyter notebook).*") +var launchPattern = regexp.MustCompile("Launching .* (application|API|notebook)") +var staticPattern = regexp.MustCompile("(Building|Launching) static content") + func eventOpFromLogLine(currentOp events.Operation, line string) events.Operation { - if match, _ := regexp.MatchString("Building (Shiny application|Plumber API).*", line); match { + if match := buildAPIPattern.MatchString(line); match { return events.PublishRestoreREnvOp - } else if match, _ := regexp.MatchString("Building (.* application|.* API|Jupyter notebook).*", line); match { + } else if match := buildAppPattern.MatchString(line); match { return events.PublishRestorePythonEnvOp - } else if match, _ := regexp.MatchString("Launching .* (application|API|notebook)", line); match { + } else if match := launchPattern.MatchString(line); match { return events.PublishRunContentOp - } else if match, _ := regexp.MatchString("(Building|Launching) static content", line); match { + } else if match := staticPattern.MatchString(line); match { return events.PublishRunContentOp } return currentOp } +type runtime string + +const ( + rRuntime runtime = "r" + pythonRuntime runtime = "python" +) + +type packageStatus string + +const ( + downloadAndInstallPackage packageStatus = "download+install" + downloadPackage packageStatus = "download" + installPackage packageStatus = "install" +) + +var rPackagePattern = regexp.MustCompile(`Installing ([[:word:]\.]+) (\(\S+\)) ...`) +var pythonDownloadingPackagePattern = regexp.MustCompile(`Downloading (\S+)-(\S+)-`) +var pythonCollectingPackagePattern = regexp.MustCompile(`Collecting (\S+)==(\S+)`) +var pythonInstallingPackagePattern = regexp.MustCompile(`Found existing installation: (\S+) (\S+)`) + +type packageEvent struct { + runtime runtime + status packageStatus + name string + version string +} + +func makePackageEvent(match []string, rt runtime, status packageStatus) *packageEvent { + return &packageEvent{ + runtime: rt, + status: status, + name: match[1], + version: match[2], + } +} + +func packageEventFromLogLine(line string) *packageEvent { + if match := rPackagePattern.FindStringSubmatch(line); match != nil { + return makePackageEvent(match, rRuntime, downloadAndInstallPackage) + } else if match := pythonDownloadingPackagePattern.FindStringSubmatch(line); match != nil { + return makePackageEvent(match, pythonRuntime, downloadPackage) + } else if match := pythonCollectingPackagePattern.FindStringSubmatch(line); match != nil { + return makePackageEvent(match, pythonRuntime, downloadPackage) + } else if match := pythonInstallingPackagePattern.FindStringSubmatch(line); match != nil { + return makePackageEvent(match, pythonRuntime, installPackage) + } + return nil +} + func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) error { var previous *taskDTO var op events.Operation @@ -264,6 +318,7 @@ func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) err return err } for _, line := range task.Output { + // Detect state transitions from certain matching log lines. nextOp := eventOpFromLogLine(op, line) if nextOp != op { if op != "" { @@ -273,6 +328,16 @@ func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) err log = log.With(logging.LogKeyOp, op) } log.Info(line) + + // Log a progress event for certain matching log lines. + event := packageEventFromLogLine(line) + if event != nil { + log.Status("Package restore", + "runtime", event.runtime, + "status", event.status, + "name", event.name, + "version", event.version) + } } if task.Finished { if task.Error != "" { From bd2cb2115fc709544e6f0910536e35f136276501 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Tue, 12 Sep 2023 12:10:36 -0400 Subject: [PATCH 08/33] tests --- internal/api_client/clients/client_connect.go | 79 ++++--- .../api_client/clients/client_connect_test.go | 216 ++++++++++++++++++ internal/api_client/clients/http_client.go | 2 +- internal/bundles/bundle.go | 2 +- internal/logging/logger.go | 36 +-- internal/logging/logger_test.go | 45 ++-- internal/logging/loggingtest/mock_logger.go | 41 +--- internal/logging/mock_base_logger.go | 63 +++++ .../logging/{loggingtest => }/mock_handler.go | 2 +- internal/logging/multi_handler_test.go | 42 ++-- internal/publish/publish.go | 8 +- internal/services/middleware/log_request.go | 4 +- internal/services/proxy/http_proxy.go | 2 +- 13 files changed, 411 insertions(+), 131 deletions(-) create mode 100644 internal/api_client/clients/client_connect_test.go create mode 100644 internal/logging/mock_base_logger.go rename internal/logging/{loggingtest => }/mock_handler.go (97%) diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index 8fceb5f30..c6754d416 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -241,15 +241,15 @@ func (c *ConnectClient) getTask(taskID types.TaskID, previous *taskDTO) (*taskDT return &task, nil } -var buildAPIPattern = regexp.MustCompile("Building (Shiny application|Plumber API).*") -var buildAppPattern = regexp.MustCompile("Building (.* application|.* API|Jupyter notebook).*") +var buildRPattern = regexp.MustCompile("Building (Shiny application|Plumber API|R Markdown document).*") +var buildPythonPattern = regexp.MustCompile("Building (.* application|.* API|Jupyter notebook).*") var launchPattern = regexp.MustCompile("Launching .* (application|API|notebook)") var staticPattern = regexp.MustCompile("(Building|Launching) static content") func eventOpFromLogLine(currentOp events.Operation, line string) events.Operation { - if match := buildAPIPattern.MatchString(line); match { + if match := buildRPattern.MatchString(line); match { return events.PublishRestoreREnvOp - } else if match := buildAppPattern.MatchString(line); match { + } else if match := buildPythonPattern.MatchString(line); match { return events.PublishRestorePythonEnvOp } else if match := launchPattern.MatchString(line); match { return events.PublishRunContentOp @@ -277,7 +277,7 @@ const ( var rPackagePattern = regexp.MustCompile(`Installing ([[:word:]\.]+) (\(\S+\)) ...`) var pythonDownloadingPackagePattern = regexp.MustCompile(`Downloading (\S+)-(\S+)-`) var pythonCollectingPackagePattern = regexp.MustCompile(`Collecting (\S+)==(\S+)`) -var pythonInstallingPackagePattern = regexp.MustCompile(`Found existing installation: (\S+) (\S+)`) +var pythonInstallingPackagePattern = regexp.MustCompile(`Found existing installation: (\S+) ()\S+`) type packageEvent struct { runtime runtime @@ -308,6 +308,43 @@ func packageEventFromLogLine(line string) *packageEvent { return nil } +func (c *ConnectClient) handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (types.Operation, error) { + var nextOp types.Operation + + for _, line := range task.Output { + // Detect state transitions from certain matching log lines. + nextOp = eventOpFromLogLine(op, line) + if nextOp != op { + if op != "" { + log.Success("Done") + } + op = nextOp + log = log.WithArgs(logging.LogKeyOp, op) + } + log.Info(line) + + // Log a progress event for certain matching log lines. + event := packageEventFromLogLine(line) + if event != nil { + log.Status("Package restore", + "runtime", event.runtime, + "status", event.status, + "name", event.name, + "version", event.version) + } + } + if task.Finished { + if task.Error != "" { + // TODO: make these errors more specific, maybe by + // using the Connect error codes from the logs. + err := errors.New(task.Error) + return nextOp, types.NewAgentError(events.DeploymentFailedCode, err, nil) + } + log.Success("Done") + } + return nextOp, nil +} + func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) error { var previous *taskDTO var op events.Operation @@ -317,37 +354,9 @@ func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) err if err != nil { return err } - for _, line := range task.Output { - // Detect state transitions from certain matching log lines. - nextOp := eventOpFromLogLine(op, line) - if nextOp != op { - if op != "" { - log.Success("Done") - } - op = nextOp - log = log.With(logging.LogKeyOp, op) - } - log.Info(line) - - // Log a progress event for certain matching log lines. - event := packageEventFromLogLine(line) - if event != nil { - log.Status("Package restore", - "runtime", event.runtime, - "status", event.status, - "name", event.name, - "version", event.version) - } - } + op, err = c.handleTaskUpdate(task, op, log) if task.Finished { - if task.Error != "" { - // TODO: make these errors more specific, maybe by - // using the Connect error codes from the logs. - err := errors.New(task.Error) - return types.NewAgentError(events.DeploymentFailedCode, err, nil) - } - log.Success("Done") - return nil + return err } previous = task time.Sleep(500 * time.Millisecond) diff --git a/internal/api_client/clients/client_connect_test.go b/internal/api_client/clients/client_connect_test.go new file mode 100644 index 000000000..d25bceda8 --- /dev/null +++ b/internal/api_client/clients/client_connect_test.go @@ -0,0 +1,216 @@ +package clients + +// Copyright (C) 2023 by Posit Software, PBC. + +import ( + "io/fs" + "testing" + "time" + + "github.com/rstudio/connect-client/internal/accounts" + "github.com/rstudio/connect-client/internal/events" + "github.com/rstudio/connect-client/internal/logging" + "github.com/rstudio/connect-client/internal/logging/loggingtest" + "github.com/rstudio/connect-client/internal/types" + "github.com/rstudio/connect-client/internal/util/utiltest" + "github.com/stretchr/testify/mock" + "github.com/stretchr/testify/suite" +) + +type ConnectClientSuite struct { + utiltest.Suite +} + +func TestConnectClientSuite(t *testing.T) { + suite.Run(t, new(ConnectClientSuite)) +} + +func (s *ConnectClientSuite) TestNewConnectClient() { + account := &accounts.Account{} + timeout := 10 * time.Second + log := logging.New() + + client, err := NewConnectClient(account, timeout, log) + s.NoError(err) + s.Equal(account, client.account) + s.Equal(log, client.log) + s.NotNil(client.client) +} + +func (s *ConnectClientSuite) TestNewConnectClientErr() { + account := &accounts.Account{ + Certificate: "/nonexistent", + } + timeout := 10 * time.Second + log := logging.New() + + client, err := NewConnectClient(account, timeout, log) + s.ErrorIs(err, fs.ErrNotExist) + s.Nil(client) +} + +type taskTest struct { + task taskDTO // The task response from the server + nextOp types.Operation // Expected next state + err error // Expected error +} + +func (s *ConnectClientSuite) TestWaitForTask() { + account := &accounts.Account{} + timeout := 10 * time.Second + log := loggingtest.NewMockLogger() + + str := mock.AnythingOfType("string") + anything := mock.Anything + log.On("Success", "Done") + log.On("Info", str) + log.On("Info", str, str, anything) + + expectedPackages := [][]string{ + {string(installPackage), "wheel", ""}, + {string(installPackage), "setuptools", ""}, + {string(installPackage), "pip", ""}, + {string(downloadPackage), "anyio", "3.6.2"}, + {string(downloadPackage), "argon2-cffi", "21.3.0"}, + } + for _, pkg := range expectedPackages { + log.On("Status", + "Package restore", + "runtime", pythonRuntime, + "status", packageStatus(pkg[0]), + "name", pkg[1], + "version", pkg[2]) + } + log.On("WithArgs", str, anything).Return(log) + + client, err := NewConnectClient(account, timeout, log) + s.NoError(err) + taskID := types.TaskID("W3YpnrwUOQJxL5DS") + + tests := []taskTest{ + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "Building Jupyter notebook...", + "Bundle created with Python version 3.11.3 is compatible with environment Local with Python version 3.11.3 from /opt/python/3.11.3/bin/python3.11", + "Bundle requested Python version 3.11.3; using /opt/python/3.11.3/bin/python3.11 which has version 3.11.3", + "2023/09/12 12:11:28.545506553 [rsc-session] Content GUID: 04f24082-2396-484b-9839-f810891dce95", + "2023/09/12 12:11:28.545544671 [rsc-session] Content ID: 24257", + "2023/09/12 12:11:28.545552006 [rsc-session] Bundle ID: 41367", + "2023/09/12 12:11:28.545557386 [rsc-session] Job Key: W3YpnrwUOQJxL5DS ", + "2023/09/12 12:11:28.687716230 Linux distribution: Ubuntu 22.04.2 LTS (jammy)", + "2023/09/12 12:11:28.689253595 Running as user: uid=1031(rstudio-connect) gid=999(rstudio-connect) groups=999(rstudio-connect)", + "2023/09/12 12:11:28.689266827 Connect version: 2023.08.0-dev+835", + "2023/09/12 12:11:28.689299912 LANG: C.UTF-8", + "2023/09/12 12:11:28.689301087 Working directory: /opt/rstudio-connect/mnt/app ", + }, + Last: 11, + }, + nextOp: events.PublishRestorePythonEnvOp, + }, + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "2023/09/12 12:11:28.689309426 Building environment using Python 3.11.3 (main, Jun 4 2023, 22:34:28) [GCC 11.3.0] at /opt/python/3.11.3/bin/python3.11", + "2023/09/12 12:11:28.704289342 Skipped packages: appnope==0.1.3", + "2023/09/12 12:11:28.704310687 Creating environment: AbrY5VfQZ5r97HDk5puHtA", + "2023/09/12 12:11:46.700864736 Requirement already satisfied: pip in ./python/env/lib/python3.11/site-packages (22.3.1)", + "2023/09/12 12:11:46.985722400 Collecting pip", + "2023/09/12 12:11:47.051703423 Using cached pip-23.2.1-py3-none-any.whl (2.1 MB)", + "2023/09/12 12:11:47.069280700 Requirement already satisfied: setuptools in ./python/env/lib/python3.11/site-packages (65.5.0)", + "2023/09/12 12:11:47.410791493 Collecting setuptools", + "2023/09/12 12:11:47.425842304 Using cached setuptools-68.2.1-py3-none-any.whl (807 kB)", + "2023/09/12 12:11:47.433729649 Requirement already satisfied: wheel in /opt/python/3.11.3/lib/python3.11/site-packages (0.41.1)", + "2023/09/12 12:11:47.487214762 Collecting wheel", + "2023/09/12 12:11:47.496886789 Using cached wheel-0.41.2-py3-none-any.whl (64 kB)", + "2023/09/12 12:11:47.648418967 Installing collected packages: wheel, setuptools, pip", + "2023/09/12 12:11:47.648650446 Attempting uninstall: wheel", + "2023/09/12 12:11:47.652986893 Found existing installation: wheel 0.41.1", + "2023/09/12 12:11:47.653521318 Not uninstalling wheel at /opt/python/3.11.3/lib/python3.11/site-packages, outside environment /opt/rstudio-connect/mnt/app/python/env", + "2023/09/12 12:11:47.653782046 Can't uninstall 'wheel'. No files were found to uninstall.", + "2023/09/12 12:11:48.144296856 Attempting uninstall: setuptools", + "2023/09/12 12:11:48.149444749 Found existing installation: setuptools 65.5.0", + "2023/09/12 12:11:48.550304512 Uninstalling setuptools-65.5.0:", + "2023/09/12 12:11:48.944303947 Successfully uninstalled setuptools-65.5.0", + "2023/09/12 12:11:53.789270259 Attempting uninstall: pip", + "2023/09/12 12:11:53.793350144 Found existing installation: pip 22.3.1", + "2023/09/12 12:11:54.663642768 Uninstalling pip-22.3.1:", + "2023/09/12 12:11:54.774633341 Successfully uninstalled pip-22.3.1", + "2023/09/12 12:12:06.254491799 Successfully installed pip-23.2.1 setuptools-68.2.1 wheel-0.41.2 ", + }, + Last: 37, + }, + nextOp: events.PublishRestorePythonEnvOp, + }, + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "2023/09/12 12:12:07.965738756 Collecting anyio==3.6.2 (from -r python/requirements.txt (line 1))", + "2023/09/12 12:12:07.975267843 Using cached anyio-3.6.2-py3-none-any.whl (80 kB)", + "2023/09/12 12:12:08.083943365 Collecting argon2-cffi==21.3.0 (from -r python/requirements.txt (line 2))", + "2023/09/12 12:12:08.100883289 Using cached argon2_cffi-21.3.0-py3-none-any.whl (14 kB)", + }, + Last: 41, + }, + nextOp: events.PublishRestorePythonEnvOp, + }, + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "2023/09/12 12:12:19.773456111 Installing collected packages: anyio, wcwidth, textwrap3, pure-eval, ptyprocess, pickleshare, mistune, ipython-genutils, fastjsonschema, executing, backcall, widgetsnbextension, websocket-client, webcolors, urllib3, uri-template, traitlets, tqdm, tornado, tinycss2, testpath, tenacity, soupsieve, sniffio, six, Send2Trash, rfc3986-validator, pyzmq, PyYAML, python-json-logger, pyrsistent, pyparsing, Pygments, pycparser, psutil, prompt-toolkit, prometheus-client, platformdirs, pexpect, parso, pandocfilters, packaging, nest-asyncio, MarkupSafe, jupyterlab-widgets, jupyterlab-pygments, jsonpointer, idna, fqdn, entrypoints, defusedxml, decorator, debugpy, click, charset-normalizer, certifi, attrs, ansiwrap, terminado, rfc3339-validator, requests, QtPy, python-dateutil, matplotlib-inline, jupyter_core, jsonschema, Jinja2, jedi, comm, cffi, bleach, beautifulsoup4, asttokens, anyio, stack-data, nbformat, jupyter_server_terminals, jupyter_client, arrow, argon2-cffi-bindings, nbclient, isoduration, ipython, argon2-cffi, papermill, nbconvert, ipykernel, qtconsole, jupyter-events, jupyter-console, ipywidgets, jupyter_server, notebook_shim, nbclassic, notebook, jupyter", + "2023/09/12 12:13:38.459203951 Successfully installed Jinja2-3.1.2 MarkupSafe-2.1.2 PyYAML-6.0 Pygments-2.15.1 QtPy-2.3.1 Send2Trash-1.8.2 ansiwrap-0.8.4 anyio-3.6.2 argon2-cffi-21.3.0 argon2-cffi-bindings-21.2.0 arrow-1.2.3 asttokens-2.2.1 attrs-23.1.0 backcall-0.2.0 beautifulsoup4-4.12.2 bleach-6.0.0 certifi-2023.7.22 cffi-1.15.1 charset-normalizer-3.2.0 click-8.1.7 comm-0.1.3 debugpy-1.6.7 decorator-5.1.1 defusedxml-0.7.1 entrypoints-0.4 executing-1.2.0 fastjsonschema-2.16.3 fqdn-1.5.1 idna-3.4 ipykernel-6.23.0 ipython-8.13.2 ipython-genutils-0.2.0 ipywidgets-8.0.6 isoduration-20.11.0 jedi-0.18.2 jsonpointer-2.3 jsonschema-4.17.3 jupyter-1.0.0 jupyter-console-6.6.3 jupyter-events-0.6.3 jupyter_client-8.2.0 jupyter_core-5.3.0 jupyter_server-2.5.0 jupyter_server_terminals-0.4.4 jupyterlab-pygments-0.2.2 jupyterlab-widgets-3.0.7 matplotlib-inline-0.1.6 mistune-2.0.5 nbclassic-1.0.0 nbclient-0.7.4 nbconvert-7.4.0 nbformat-5.8.0 nest-asyncio-1.5.6 notebook-6.5.4 notebook_shim-0.2.3 packaging-23.1 pandocfilters-1.5.0 papermill-2.4.0 parso-0.8.3 pexpect-4.8.0 pickleshare-0.7.5 platformdirs-3.5.1 prometheus-client-0.16.0 prompt-toolkit-3.0.38 psutil-5.9.5 ptyprocess-0.7.0 pure-eval-0.2.2 pycparser-2.21 pyparsing-3.0.9 pyrsistent-0.19.3 python-dateutil-2.8.2 python-json-logger-2.0.7 pyzmq-25.0.2 qtconsole-5.4.3 requests-2.31.0 rfc3339-validator-0.1.4 rfc3986-validator-0.1.1 six-1.16.0 sniffio-1.3.0 soupsieve-2.4.1 stack-data-0.6.2 tenacity-8.2.3 terminado-0.17.1 testpath-0.6.0 textwrap3-0.9.2 tinycss2-1.2.1 tornado-6.3.1 tqdm-4.66.1 traitlets-5.9.0 uri-template-1.2.0 urllib3-2.0.4 wcwidth-0.2.6 webcolors-1.13 webencodings-0.5.1 websocket-client-1.5.1 widgetsnbextension-4.0.7", + "2023/09/12 12:13:40.684793490 Packages in the environment: ansiwrap==0.8.4, anyio==3.6.2, argon2-cffi==21.3.0, argon2-cffi-bindings==21.2.0, arrow==1.2.3, asttokens==2.2.1, attrs==23.1.0, backcall==0.2.0, beautifulsoup4==4.12.2, bleach==6.0.0, certifi==2023.7.22, cffi==1.15.1, charset-normalizer==3.2.0, click==8.1.7, comm==0.1.3, debugpy==1.6.7, decorator==5.1.1, defusedxml==0.7.1, entrypoints==0.4, executing==1.2.0, fastjsonschema==2.16.3, fqdn==1.5.1, idna==3.4, ipykernel==6.23.0, ipython==8.13.2, ipython-genutils==0.2.0, ipywidgets==8.0.6, isoduration==20.11.0, jedi==0.18.2, Jinja2==3.1.2, jsonpointer==2.3, jsonschema==4.17.3, jupyter==1.0.0, jupyter-console==6.6.3, jupyter-events==0.6.3, jupyter_client==8.2.0, jupyter_core==5.3.0, jupyter_server==2.5.0, jupyter_server_terminals==0.4.4, jupyterlab-pygments==0.2.2, jupyterlab-widgets==3.0.7, MarkupSafe==2.1.2, matplotlib-inline==0.1.6, mistune==2.0.5, nbclassic==1.0.0, nbclient==0.7.4, nbconvert==7.4.0, nbformat==5.8.0, nest-asyncio==1.5.6, notebook==6.5.4, notebook_shim==0.2.3, packaging==23.1, pandocfilters==1.5.0, papermill==2.4.0, parso==0.8.3, pexpect==4.8.0, pickleshare==0.7.5, platformdirs==3.5.1, prometheus-client==0.16.0, prompt-toolkit==3.0.38, psutil==5.9.5, ptyprocess==0.7.0, pure-eval==0.2.2, pycparser==2.21, Pygments==2.15.1, pyparsing==3.0.9, pyrsistent==0.19.3, python-dateutil==2.8.2, python-json-logger==2.0.7, PyYAML==6.0, pyzmq==25.0.2, qtconsole==5.4.3, QtPy==2.3.1, requests==2.31.0, rfc3339-validator==0.1.4, rfc3986-validator==0.1.1, Send2Trash==1.8.2, six==1.16.0, sniffio==1.3.0, soupsieve==2.4.1, stack-data==0.6.2, tenacity==8.2.3, terminado==0.17.1, testpath==0.6.0, textwrap3==0.9.2, tinycss2==1.2.1, tornado==6.3.1, tqdm==4.66.1, traitlets==5.9.0, uri-template==1.2.0, urllib3==2.0.4, wcwidth==0.2.6, webcolors==1.13, webencodings==0.5.1, websocket-client==1.5.1, widgetsnbextension==4.0.7,", + "2023/09/12 12:13:40.684844104 Creating kernel spec: python3", + "2023/09/12 12:13:42.493712394 0.00s - Debugger warning: It seems that frozen modules are being used, which may", + "2023/09/12 12:13:42.493725446 0.00s - make the debugger miss breakpoints. Please pass -Xfrozen_modules=off", + "2023/09/12 12:13:42.493763373 0.00s - to python to disable frozen modules.", + "2023/09/12 12:13:42.493764977 0.00s - Note: Debugging will proceed. Set PYDEVD_DISABLE_FILE_VALIDATION=1 to disable this validation.", + "2023/09/12 12:13:42.787686354 Installed kernelspec python3 in /opt/rstudio-connect/mnt/app/python/env/share/jupyter/kernels/python3", + "2023/09/12 12:13:42.994165519 Creating lockfile: python/requirements.txt.lock", + "Completed Python build against Python version: '3.11.3' ", + }, + Last: 52, + }, + nextOp: events.PublishRestorePythonEnvOp, + }, + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "Launching Jupyter notebook...", + "Using environment Local", + "2023/09/12 12:13:44.541508100 [rsc-session] Content GUID: 04f24082-2396-484b-9839-f810891dce95", + "2023/09/12 12:13:44.541629598 [rsc-session] Content ID: 24257", + "2023/09/12 12:13:44.541635566 [rsc-session] Bundle ID: 41367", + "2023/09/12 12:13:44.541639071 [rsc-session] Variant ID: 5921", + "2023/09/12 12:13:44.541642353 [rsc-session] Job Key: l6FJXo5Ip5C4jyDf", + "2023/09/12 12:13:44.701717371 Running on host: dogfood02", + "2023/09/12 12:13:44.713132676 Linux distribution: Ubuntu 22.04.2 LTS (jammy)", + "2023/09/12 12:13:44.714771923 Running as user: uid=1031(rstudio-connect) gid=999(rstudio-connect) groups=999(rstudio-connect)", + "2023/09/12 12:13:44.714781982 Connect version: 2023.08.0-dev+835", + "2023/09/12 12:13:44.714807857 LANG: C.UTF-8", + "2023/09/12 12:13:44.714811167 Working directory: /opt/rstudio-connect/mnt/app", + "2023/09/12 12:13:44.714819234 Bootstrapping environment using Python 3.11.3 (main, Jun 4 2023, 22:34:28) [GCC 11.3.0] at /opt/python/3.11.3/bin/python3.11", + "2023/09/12 12:13:44.716751212 Running content with the Python virtual environment /opt/rstudio-connect/mnt/app/python/env (/opt/rstudio-connect/mnt/python-environments/pip/3.11.3/AbrY5VfQZ5r97HDk5puHtA) },", + }, + Last: 67, + }, + nextOp: events.PublishRunContentOp, + }, + } + op := events.AgentOp + for _, test := range tests { + op, err = client.handleTaskUpdate(&test.task, op, log) + if test.err != nil { + s.ErrorIs(err, test.err) + } else { + s.NoError(err) + } + s.Equal(test.nextOp, op) + } + log.AssertExpectations(s.T()) +} diff --git a/internal/api_client/clients/http_client.go b/internal/api_client/clients/http_client.go index 1c7f562ec..1d346c3da 100644 --- a/internal/api_client/clients/http_client.go +++ b/internal/api_client/clients/http_client.go @@ -183,7 +183,7 @@ func loadCACertificates(path string, log logging.Logger) (*x509.CertPool, error) log.Info("Loading CA certificate", "path", path) certificate, err := os.ReadFile(path) if err != nil { - return nil, fmt.Errorf("Error reading certificate file: %s", err) + return nil, fmt.Errorf("Error reading certificate file: %w", err) } certPool := x509.NewCertPool() ok := certPool.AppendCertsFromPEM(certificate) diff --git a/internal/bundles/bundle.go b/internal/bundles/bundle.go index d10e7e38f..d60de5450 100644 --- a/internal/bundles/bundle.go +++ b/internal/bundles/bundle.go @@ -227,7 +227,7 @@ func (b *bundle) walkFunc(path util.Path, info fs.FileInfo, err error) error { if err != nil { return err } - pathLogger := b.log.With( + pathLogger := b.log.WithArgs( "path", path, "size", info.Size(), ) diff --git a/internal/logging/logger.go b/internal/logging/logger.go index ceee531ea..3142612ed 100644 --- a/internal/logging/logger.go +++ b/internal/logging/logger.go @@ -28,37 +28,47 @@ const ( LogKeyErrCode = "error_code" ) -type Logger struct { +type Logger interface { BaseLogger + Start(msg string, args ...any) + Success(msg string, args ...any) + Status(msg string, args ...any) + Progress(msg string, done float32, total float32, args ...any) + Failure(err error) + WithArgs(args ...any) Logger } -func New() Logger { - return Logger{ +type loggerImpl struct { + BaseLogger +} + +func New() loggerImpl { + return loggerImpl{ slog.Default(), } } -func FromStdLogger(log *slog.Logger) Logger { - return Logger{log} +func FromStdLogger(log *slog.Logger) loggerImpl { + return loggerImpl{log} } -func (l Logger) Start(msg string, args ...any) { +func (l loggerImpl) Start(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, StartPhase}, args...)...) } -func (l Logger) Success(msg string, args ...any) { +func (l loggerImpl) Success(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, SuccessPhase}, args...)...) } -func (l Logger) Status(msg string, args ...any) { +func (l loggerImpl) Status(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, ProgressPhase}, args...)...) } -func (l Logger) Progress(msg string, done float32, total float32, args ...any) { +func (l loggerImpl) Progress(msg string, done float32, total float32, args ...any) { l.Info(msg, append([]any{LogKeyPhase, ProgressPhase, "done", done, "total", total}, args...)...) } -func (l Logger) Failure(err error) { +func (l loggerImpl) Failure(err error) { if agentError, ok := err.(types.EventableError); ok { args := []any{ LogKeyOp, agentError.GetOperation(), @@ -73,11 +83,11 @@ func (l Logger) Failure(err error) { // We shouldn't get here, because callers who use Failure // (the Publish routine) will wrap all errors in AgentErrors. // But just in case, log it anyway. - l.Debug("Received a non-eventable error in Logger.Failure; see the following error entry") + l.Debug("Received a non-eventable error in LoggerImpl.Failure; see the following error entry") l.Error(err.Error(), LogKeyPhase, FailurePhase) } } -func (l Logger) With(args ...any) Logger { - return Logger{l.BaseLogger.With(args...)} +func (l loggerImpl) WithArgs(args ...any) Logger { + return loggerImpl{l.BaseLogger.With(args...)} } diff --git a/internal/logging/logger_test.go b/internal/logging/logger_test.go index 3d3ebb9e2..48a02c6f1 100644 --- a/internal/logging/logger_test.go +++ b/internal/logging/logger_test.go @@ -7,7 +7,6 @@ import ( "log/slog" "testing" - "github.com/rstudio/connect-client/internal/logging/loggingtest" "github.com/rstudio/connect-client/internal/types" "github.com/rstudio/connect-client/internal/util/utiltest" "github.com/stretchr/testify/mock" @@ -35,34 +34,34 @@ func (s *LoggingSuite) TestFromStdLogger() { } func (s *LoggingSuite) TestStart() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, StartPhase, "arg", "value") - log := Logger{baseLogger} + log := loggerImpl{baseLogger} log.Start("message", "arg", "value") - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestSuccess() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, SuccessPhase, "arg", "value") - log := Logger{baseLogger} + log := loggerImpl{baseLogger} log.Success("message", "arg", "value") - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestStatus() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, ProgressPhase, "arg", "value") - log := Logger{baseLogger} + log := loggerImpl{baseLogger} log.Status("message", "arg", "value") - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestProgress() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() baseLogger.On( "Info", "message", LogKeyPhase, ProgressPhase, @@ -70,24 +69,24 @@ func (s *LoggingSuite) TestProgress() { "total", float32(100), "arg", "value") - log := Logger{baseLogger} + log := loggerImpl{baseLogger} log.Progress("message", 20, 100, "arg", "value") - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestFailureGoError() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() baseLogger.On("Error", "test error", LogKeyPhase, FailurePhase) baseLogger.On("Debug", mock.AnythingOfType("string")) - log := Logger{baseLogger} + log := loggerImpl{baseLogger} err := errors.New("test error") log.Failure(err) - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestFailureAgentError() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() op := types.Operation("testOp") baseLogger.On( @@ -97,7 +96,7 @@ func (s *LoggingSuite) TestFailureAgentError() { LogKeyErrCode, types.UnknownErrorCode, "Metadata", "some metadata") - log := Logger{baseLogger} + log := loggerImpl{baseLogger} baseErr := errors.New("test error") errData := struct { Metadata string @@ -105,14 +104,14 @@ func (s *LoggingSuite) TestFailureAgentError() { err := types.NewAgentError(types.UnknownErrorCode, baseErr, &errData) err.SetOperation(op) log.Failure(err) - s.Assert() + baseLogger.AssertExpectations(s.T()) } func (s *LoggingSuite) TestWith() { - baseLogger := loggingtest.NewMockLogger() + baseLogger := NewMockBaseLogger() expectedLogger := slog.Default() baseLogger.On("With", "arg", "value", "arg2", "value2").Return(expectedLogger) - log := Logger{baseLogger} - actualLogger := log.With("arg", "value", "arg2", "value2") - s.Equal(Logger{expectedLogger}, actualLogger) + log := loggerImpl{baseLogger} + actualLogger := log.WithArgs("arg", "value", "arg2", "value2") + s.Equal(loggerImpl{expectedLogger}, actualLogger) } diff --git a/internal/logging/loggingtest/mock_logger.go b/internal/logging/loggingtest/mock_logger.go index 01fd82d73..85828400e 100644 --- a/internal/logging/loggingtest/mock_logger.go +++ b/internal/logging/loggingtest/mock_logger.go @@ -3,61 +3,42 @@ package loggingtest // Copyright (C) 2023 by Posit Software, PBC. import ( - "context" - "log/slog" - - "github.com/stretchr/testify/mock" + "github.com/rstudio/connect-client/internal/logging" ) type MockLogger struct { - mock.Mock + logging.MockBaseLogger } func NewMockLogger() *MockLogger { return &MockLogger{} } -func (m *MockLogger) Error(msg string, args ...any) { - mockArgs := append([]any{msg}, args...) - m.Called(mockArgs...) -} - -func (m *MockLogger) Warn(msg string, args ...any) { +func (m *MockLogger) Start(msg string, args ...any) { mockArgs := append([]any{msg}, args...) m.Called(mockArgs...) } -func (m *MockLogger) Info(msg string, args ...any) { +func (m *MockLogger) Success(msg string, args ...any) { mockArgs := append([]any{msg}, args...) m.Called(mockArgs...) } -func (m *MockLogger) Debug(msg string, args ...any) { +func (m *MockLogger) Status(msg string, args ...any) { mockArgs := append([]any{msg}, args...) m.Called(mockArgs...) } -func (m *MockLogger) Log(ctx context.Context, level slog.Level, msg string, args ...any) { - mockArgs := append([]any{ctx, level, msg}, args...) +func (m *MockLogger) Progress(msg string, done float32, total float32, args ...any) { + mockArgs := append([]any{msg, done, total}, args...) m.Called(mockArgs...) } -func (m *MockLogger) Handler() slog.Handler { - mockArgs := m.Called() - return mockArgs.Get(0).(slog.Handler) +func (m *MockLogger) Failure(err error) { + m.Called(err) } -func (m *MockLogger) Enabled(ctx context.Context, level slog.Level) bool { - args := m.Called(ctx, level) - return args.Bool(0) -} - -func (m *MockLogger) With(args ...any) *slog.Logger { +func (m *MockLogger) WithArgs(args ...any) logging.Logger { mockArgs := m.Called(args...) - return mockArgs.Get(0).(*slog.Logger) -} - -func (m *MockLogger) WithGroup(name string) *slog.Logger { - mockArgs := m.Called(name) - return mockArgs.Get(0).(*slog.Logger) + return mockArgs.Get(0).(logging.Logger) } diff --git a/internal/logging/mock_base_logger.go b/internal/logging/mock_base_logger.go new file mode 100644 index 000000000..569601d5c --- /dev/null +++ b/internal/logging/mock_base_logger.go @@ -0,0 +1,63 @@ +package logging + +// Copyright (C) 2023 by Posit Software, PBC. + +import ( + "context" + "log/slog" + + "github.com/stretchr/testify/mock" +) + +type MockBaseLogger struct { + mock.Mock +} + +func NewMockBaseLogger() *MockBaseLogger { + return &MockBaseLogger{} +} + +func (m *MockBaseLogger) Error(msg string, args ...any) { + mockArgs := append([]any{msg}, args...) + m.Called(mockArgs...) +} + +func (m *MockBaseLogger) Warn(msg string, args ...any) { + mockArgs := append([]any{msg}, args...) + m.Called(mockArgs...) +} + +func (m *MockBaseLogger) Info(msg string, args ...any) { + mockArgs := append([]any{msg}, args...) + m.Called(mockArgs...) +} + +func (m *MockBaseLogger) Debug(msg string, args ...any) { + mockArgs := append([]any{msg}, args...) + m.Called(mockArgs...) +} + +func (m *MockBaseLogger) Log(ctx context.Context, level slog.Level, msg string, args ...any) { + mockArgs := append([]any{ctx, level, msg}, args...) + m.Called(mockArgs...) +} + +func (m *MockBaseLogger) Handler() slog.Handler { + mockArgs := m.Called() + return mockArgs.Get(0).(slog.Handler) +} + +func (m *MockBaseLogger) Enabled(ctx context.Context, level slog.Level) bool { + args := m.Called(ctx, level) + return args.Bool(0) +} + +func (m *MockBaseLogger) With(args ...any) *slog.Logger { + mockArgs := m.Called(args...) + return mockArgs.Get(0).(*slog.Logger) +} + +func (m *MockBaseLogger) WithGroup(name string) *slog.Logger { + mockArgs := m.Called(name) + return mockArgs.Get(0).(*slog.Logger) +} diff --git a/internal/logging/loggingtest/mock_handler.go b/internal/logging/mock_handler.go similarity index 97% rename from internal/logging/loggingtest/mock_handler.go rename to internal/logging/mock_handler.go index d65d26082..bc16ca9cf 100644 --- a/internal/logging/loggingtest/mock_handler.go +++ b/internal/logging/mock_handler.go @@ -1,4 +1,4 @@ -package loggingtest +package logging // Copyright (C) 2023 by Posit Software, PBC. diff --git a/internal/logging/multi_handler_test.go b/internal/logging/multi_handler_test.go index d28c8f8e3..0941c681a 100644 --- a/internal/logging/multi_handler_test.go +++ b/internal/logging/multi_handler_test.go @@ -9,7 +9,6 @@ import ( "os" "testing" - "github.com/rstudio/connect-client/internal/logging/loggingtest" "github.com/rstudio/connect-client/internal/util/utiltest" "github.com/stretchr/testify/mock" "github.com/stretchr/testify/suite" @@ -24,8 +23,8 @@ func TestMultiHanlderSuite(t *testing.T) { } func (s *MultiHandlerSuite) TestNewMultiHandler() { - h1 := loggingtest.NewMockHandler() - h2 := loggingtest.NewMockHandler() + h1 := NewMockHandler() + h2 := NewMockHandler() multiHandler := NewMultiHandler(h1, h2) s.Equal([]slog.Handler{h1, h2}, multiHandler.handlers) @@ -44,8 +43,8 @@ func (s *MultiHandlerSuite) TestEnabled() { } func (s *MultiHandlerSuite) TestHandle() { - h1 := loggingtest.NewMockHandler() - h2 := loggingtest.NewMockHandler() + h1 := NewMockHandler() + h2 := NewMockHandler() h1.On("Enabled", mock.Anything, slog.LevelInfo).Return(true) h2.On("Enabled", mock.Anything, slog.LevelInfo).Return(false) @@ -57,11 +56,12 @@ func (s *MultiHandlerSuite) TestHandle() { Message: "message", } multiHandler.Handle(context.Background(), record) - s.Assert() + h1.AssertExpectations(s.T()) + h2.AssertExpectations(s.T()) } func (s *MultiHandlerSuite) TestHandleError() { - baseHandler := loggingtest.NewMockHandler() + baseHandler := NewMockHandler() testError := errors.New("test error from Handle") baseHandler.On("Enabled", mock.Anything, slog.LevelInfo).Return(true) baseHandler.On("Handle", mock.Anything, mock.Anything).Return(testError) @@ -73,14 +73,14 @@ func (s *MultiHandlerSuite) TestHandleError() { } err := multiHandler.Handle(context.Background(), record) s.ErrorIs(err, testError) - s.Assert() + baseHandler.AssertExpectations(s.T()) } func (s *MultiHandlerSuite) TestWithAttrs() { - h1 := loggingtest.NewMockHandler() - h2 := loggingtest.NewMockHandler() - h1WithAttrs := loggingtest.NewMockHandler() - h2WithAttrs := loggingtest.NewMockHandler() + h1 := NewMockHandler() + h2 := NewMockHandler() + h1WithAttrs := NewMockHandler() + h2WithAttrs := NewMockHandler() attr := slog.Attr{ Key: "att", @@ -93,27 +93,29 @@ func (s *MultiHandlerSuite) TestWithAttrs() { multiHandler := NewMultiHandler(h1, h2) returnedHandler := multiHandler.WithAttrs(attrs) s.Equal(NewMultiHandler(h1WithAttrs, h2WithAttrs), returnedHandler) - s.Assert() + h1.AssertExpectations(s.T()) + h2.AssertExpectations(s.T()) } func (s *MultiHandlerSuite) TestWithGroup() { - h1 := loggingtest.NewMockHandler() - h2 := loggingtest.NewMockHandler() - h1WithGroup := loggingtest.NewMockHandler() - h2WithGroup := loggingtest.NewMockHandler() + h1 := NewMockHandler() + h2 := NewMockHandler() + h1WithGroup := NewMockHandler() + h2WithGroup := NewMockHandler() h1.On("WithGroup", "group").Return(h1WithGroup) h2.On("WithGroup", "group").Return(h2WithGroup) multiHandler := NewMultiHandler(h1, h2) returnedHandler := multiHandler.WithGroup("group") s.Equal(NewMultiHandler(h1WithGroup, h2WithGroup), returnedHandler) - s.Assert() + h1.AssertExpectations(s.T()) + h2.AssertExpectations(s.T()) } func (s *MultiHandlerSuite) TestWithGroupEmptyName() { - baseHandler := loggingtest.NewMockHandler() + baseHandler := NewMockHandler() multiHandler := NewMultiHandler(baseHandler) returnedHandler := multiHandler.WithGroup("") s.Equal(multiHandler, returnedHandler) - s.Assert() + baseHandler.AssertExpectations(s.T()) } diff --git a/internal/publish/publish.go b/internal/publish/publish.go index 1ed1f6332..736c179d3 100644 --- a/internal/publish/publish.go +++ b/internal/publish/publish.go @@ -67,7 +67,7 @@ func logAppInfo(accountURL string, contentID types.ContentID, log logging.Logger DashboardURL: fmt.Sprintf("%s/connect/#/apps/%s", accountURL, contentID), DirectURL: fmt.Sprintf("%s/content/%s", accountURL, contentID), } - log.With( + log.WithArgs( "dashboardURL", appInfo.DashboardURL, "directURL", appInfo.DirectURL, "serverURL", accountURL, @@ -121,7 +121,7 @@ type DeploymentNotFoundDetails struct { } func withLog[T any](op events.Operation, msg string, label string, log logging.Logger, fn func() (T, error)) (value T, err error) { - log = log.With(logging.LogKeyOp, op) + log = log.WithArgs(logging.LogKeyOp, op) log.Start(msg) value, err = fn() if err != nil { @@ -206,11 +206,11 @@ func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, acco return err } - taskLogger := log.With("source", "serverLog") + taskLogger := log.WithArgs("source", "serverLog") err = client.WaitForTask(taskID, taskLogger) if err != nil { return err } - log = log.With(logging.LogKeyOp, events.AgentOp) + log = log.WithArgs(logging.LogKeyOp, events.AgentOp) return logAppInfo(account.URL, contentID, log) } diff --git a/internal/services/middleware/log_request.go b/internal/services/middleware/log_request.go index b90a20b91..2e0172ce0 100644 --- a/internal/services/middleware/log_request.go +++ b/internal/services/middleware/log_request.go @@ -51,7 +51,7 @@ func LogRequest(msg string, log logging.Logger, next http.HandlerFunc) http.Hand next(writer, req) elapsedMs := time.Since(startTime).Milliseconds() - fieldLogger := log.With( + fieldLogger := log.WithArgs( "method", req.Method, "url", req.URL.String(), "elapsed_ms", elapsedMs, @@ -62,7 +62,7 @@ func LogRequest(msg string, log logging.Logger, next http.HandlerFunc) http.Hand ) correlationId := writer.Header().Get("X-Correlation-Id") if correlationId != "" { - fieldLogger = fieldLogger.With("X-Correlation-Id", correlationId) + fieldLogger = fieldLogger.WithArgs("X-Correlation-Id", correlationId) } fieldLogger.Info(msg) } diff --git a/internal/services/proxy/http_proxy.go b/internal/services/proxy/http_proxy.go index 76d7aee56..942cc3407 100644 --- a/internal/services/proxy/http_proxy.go +++ b/internal/services/proxy/http_proxy.go @@ -139,7 +139,7 @@ func (p *proxy) logHeader(msg string, header http.Header) { value = fmt.Sprintf("%v", values) } } - log = log.With(headerName(name), value) + log = log.WithArgs(headerName(name), value) } log.Debug(msg) } From f0f3706d698ea7b1838033de52a6d330f4ef2f9d Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Tue, 12 Sep 2023 16:06:47 -0400 Subject: [PATCH 09/33] more tests --- internal/api_client/clients/client_connect.go | 35 +++-- .../api_client/clients/client_connect_test.go | 141 +++++++++++++++--- 2 files changed, 142 insertions(+), 34 deletions(-) diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index c6754d416..29d3b4156 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -9,6 +9,7 @@ import ( "io" "net/http" "regexp" + "strings" "time" "github.com/rstudio/connect-client/internal/accounts" @@ -247,23 +248,30 @@ var launchPattern = regexp.MustCompile("Launching .* (application|API|notebook)" var staticPattern = regexp.MustCompile("(Building|Launching) static content") func eventOpFromLogLine(currentOp events.Operation, line string) events.Operation { - if match := buildRPattern.MatchString(line); match { + match := buildRPattern.MatchString(line) + if match || strings.Contains(line, "Bundle created with R version") { return events.PublishRestoreREnvOp - } else if match := buildPythonPattern.MatchString(line); match { + } + match = buildPythonPattern.MatchString(line) + if match || strings.Contains(line, "Bundle requested Python version") { return events.PublishRestorePythonEnvOp - } else if match := launchPattern.MatchString(line); match { + } + match = launchPattern.MatchString(line) + if match { return events.PublishRunContentOp - } else if match := staticPattern.MatchString(line); match { + } + match = staticPattern.MatchString(line) + if match { return events.PublishRunContentOp } return currentOp } -type runtime string +type packageRuntime string const ( - rRuntime runtime = "r" - pythonRuntime runtime = "python" + rRuntime packageRuntime = "r" + pythonRuntime packageRuntime = "python" ) type packageStatus string @@ -274,19 +282,18 @@ const ( installPackage packageStatus = "install" ) -var rPackagePattern = regexp.MustCompile(`Installing ([[:word:]\.]+) (\(\S+\)) ...`) -var pythonDownloadingPackagePattern = regexp.MustCompile(`Downloading (\S+)-(\S+)-`) +var rPackagePattern = regexp.MustCompile(`Installing ([[:word:]\.]+) \((\S+)\) ...`) var pythonCollectingPackagePattern = regexp.MustCompile(`Collecting (\S+)==(\S+)`) var pythonInstallingPackagePattern = regexp.MustCompile(`Found existing installation: (\S+) ()\S+`) type packageEvent struct { - runtime runtime + runtime packageRuntime status packageStatus name string version string } -func makePackageEvent(match []string, rt runtime, status packageStatus) *packageEvent { +func makePackageEvent(match []string, rt packageRuntime, status packageStatus) *packageEvent { return &packageEvent{ runtime: rt, status: status, @@ -298,8 +305,6 @@ func makePackageEvent(match []string, rt runtime, status packageStatus) *package func packageEventFromLogLine(line string) *packageEvent { if match := rPackagePattern.FindStringSubmatch(line); match != nil { return makePackageEvent(match, rRuntime, downloadAndInstallPackage) - } else if match := pythonDownloadingPackagePattern.FindStringSubmatch(line); match != nil { - return makePackageEvent(match, pythonRuntime, downloadPackage) } else if match := pythonCollectingPackagePattern.FindStringSubmatch(line); match != nil { return makePackageEvent(match, pythonRuntime, downloadPackage) } else if match := pythonInstallingPackagePattern.FindStringSubmatch(line); match != nil { @@ -308,7 +313,7 @@ func packageEventFromLogLine(line string) *packageEvent { return nil } -func (c *ConnectClient) handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (types.Operation, error) { +func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (types.Operation, error) { var nextOp types.Operation for _, line := range task.Output { @@ -354,7 +359,7 @@ func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) err if err != nil { return err } - op, err = c.handleTaskUpdate(task, op, log) + op, err = handleTaskUpdate(task, op, log) if task.Finished { return err } diff --git a/internal/api_client/clients/client_connect_test.go b/internal/api_client/clients/client_connect_test.go index d25bceda8..ebf143548 100644 --- a/internal/api_client/clients/client_connect_test.go +++ b/internal/api_client/clients/client_connect_test.go @@ -3,6 +3,7 @@ package clients // Copyright (C) 2023 by Posit Software, PBC. import ( + "errors" "io/fs" "testing" "time" @@ -56,8 +57,6 @@ type taskTest struct { } func (s *ConnectClientSuite) TestWaitForTask() { - account := &accounts.Account{} - timeout := 10 * time.Second log := loggingtest.NewMockLogger() str := mock.AnythingOfType("string") @@ -66,25 +65,29 @@ func (s *ConnectClientSuite) TestWaitForTask() { log.On("Info", str) log.On("Info", str, str, anything) - expectedPackages := [][]string{ - {string(installPackage), "wheel", ""}, - {string(installPackage), "setuptools", ""}, - {string(installPackage), "pip", ""}, - {string(downloadPackage), "anyio", "3.6.2"}, - {string(downloadPackage), "argon2-cffi", "21.3.0"}, + expectedPackages := []struct { + rt packageRuntime + status packageStatus + name string + version string + }{ + {pythonRuntime, installPackage, "wheel", ""}, + {pythonRuntime, installPackage, "setuptools", ""}, + {pythonRuntime, installPackage, "pip", ""}, + {pythonRuntime, downloadPackage, "anyio", "3.6.2"}, + {pythonRuntime, downloadPackage, "argon2-cffi", "21.3.0"}, + {rRuntime, downloadAndInstallPackage, "R6", "2.5.1"}, + {rRuntime, downloadAndInstallPackage, "Rcpp", "1.0.10"}, } for _, pkg := range expectedPackages { log.On("Status", "Package restore", - "runtime", pythonRuntime, - "status", packageStatus(pkg[0]), - "name", pkg[1], - "version", pkg[2]) + "runtime", pkg.rt, + "status", pkg.status, + "name", pkg.name, + "version", pkg.version) } log.On("WithArgs", str, anything).Return(log) - - client, err := NewConnectClient(account, timeout, log) - s.NoError(err) taskID := types.TaskID("W3YpnrwUOQJxL5DS") tests := []taskTest{ @@ -153,7 +156,7 @@ func (s *ConnectClientSuite) TestWaitForTask() { "2023/09/12 12:12:08.083943365 Collecting argon2-cffi==21.3.0 (from -r python/requirements.txt (line 2))", "2023/09/12 12:12:08.100883289 Using cached argon2_cffi-21.3.0-py3-none-any.whl (14 kB)", }, - Last: 41, + Last: 43, }, nextOp: events.PublishRestorePythonEnvOp, }, @@ -173,11 +176,13 @@ func (s *ConnectClientSuite) TestWaitForTask() { "2023/09/12 12:13:42.994165519 Creating lockfile: python/requirements.txt.lock", "Completed Python build against Python version: '3.11.3' ", }, - Last: 52, + Last: 54, }, nextOp: events.PublishRestorePythonEnvOp, }, { + // This doesn't really make sense to come next, + // in fact it is from a different log, but here it is anyway. task: taskDTO{ Id: taskID, Output: []string{ @@ -197,14 +202,77 @@ func (s *ConnectClientSuite) TestWaitForTask() { "2023/09/12 12:13:44.714819234 Bootstrapping environment using Python 3.11.3 (main, Jun 4 2023, 22:34:28) [GCC 11.3.0] at /opt/python/3.11.3/bin/python3.11", "2023/09/12 12:13:44.716751212 Running content with the Python virtual environment /opt/rstudio-connect/mnt/app/python/env (/opt/rstudio-connect/mnt/python-environments/pip/3.11.3/AbrY5VfQZ5r97HDk5puHtA) },", }, - Last: 67, + Finished: true, + Last: 69, }, nextOp: events.PublishRunContentOp, }, + + { + task: taskDTO{ + Id: taskID, + Output: []string{ + "Bundle created with R version 4.3.0, Python version 3.11.3, and Quarto version 0.9.105 is compatible with environment Local with R version 4.3.1 from /opt/R/4.3.1/bin/R, Python version 3.11.3 from /opt/python/3.11.3/bin/python3.11, and Quarto version 1.3.450 from /opt/quarto/1.3.450/bin/quarto", + "Bundle requested R version 4.3.0; using /opt/R/4.3.1/bin/R which has version 4.3.1", + "Performing manifest.json to packrat transformation.", + "Rewriting .Rprofile to disable renv activation.", + "2023/09/12 17:02:42.966434822 [rsc-session] Content GUID: 067f9077-b831-4cff-bcd2-ee0797f27cb8", + "2023/09/12 17:02:42.966484486 [rsc-session] Content ID: 24275", + "2023/09/12 17:02:42.966491187 [rsc-session] Bundle ID: 41387", + "2023/09/12 17:02:42.966495586 [rsc-session] Job Key: MjLGWJMm4mkQCxRo", + "2023/09/12 17:02:44.214759306 Running on host: dogfood01", + "2023/09/12 17:02:44.240099958 Linux distribution: Ubuntu 22.04.2 LTS (jammy)", + "2023/09/12 17:02:44.243027005 Running as user: uid=1031(rstudio-connect) gid=999(rstudio-connect) groups=999(rstudio-connect)", + "2023/09/12 17:02:44.243096083 Connect version: 2023.08.0-dev+835", + "2023/09/12 17:02:44.243134910 LANG: C.UTF-8", + "2023/09/12 17:02:44.243454938 Working directory: /opt/rstudio-connect/mnt/app", + "2023/09/12 17:02:44.243650732 Using R 4.3.1", + "2023/09/12 17:02:44.243656003 R.home(): /opt/R/4.3.1/lib/R", + "2023/09/12 17:02:44.244676467 Using user agent string: 'RStudio R (4.3.1 x86_64-pc-linux-gnu x86_64 linux-gnu)'", + "2023/09/12 17:02:44.245211912 # Validating R library read / write permissions --------------------------------", + "2023/09/12 17:02:44.249695973 Using R library for packrat bootstrap: /opt/rstudio-connect/mnt/R/4.3.1", + "2023/09/12 17:02:44.250108685 # Validating managed packrat installation --------------------------------------", + "2023/09/12 17:02:44.250391017 Vendored packrat archive: /opt/rstudio-connect/ext/R/packrat_0.9.1-1_ac6bc33bce3869513cbe1ce14a697dfa807d9c41.tar.gz", + "2023/09/12 17:02:44.262948547 Vendored packrat SHA: ac6bc33bce3869513cbe1ce14a697dfa807d9c41", + "2023/09/12 17:02:44.276923165 Managed packrat SHA: ac6bc33bce3869513cbe1ce14a697dfa807d9c41", + "2023/09/12 17:02:44.278612673 Managed packrat version: 0.9.1.1", + "2023/09/12 17:02:44.279320329 Managed packrat is up-to-date.", + "2023/09/12 17:02:44.279664142 # Validating packrat cache read / write permissions ----------------------------", + "2023/09/12 17:02:44.643930307 Using packrat cache directory: /opt/rstudio-connect/mnt/packrat/4.3.1", + "2023/09/12 17:02:44.644104262 # Setting packrat options and preparing lockfile -------------------------------", + "2023/09/12 17:02:44.807459260 Audited package hashes with local packrat installation.", + "2023/09/12 17:02:44.809608665 # Resolving R package repositories ---------------------------------------------", + "2023/09/12 17:02:44.827081713 Received repositories from Connect's configuration:", + `2023/09/12 17:02:44.827696151 - CRAN = "https://packagemanager.posit.co/cran/__linux__/jammy/latest"`, + `2023/09/12 17:02:44.827703834 - RSPM = "https://packagemanager.posit.co/cran/__linux__/jammy/latest"`, + "2023/09/12 17:02:45.034481466 Received repositories from published content:", + `2023/09/12 17:02:45.036517369 - CRAN = "https://cran.rstudio.com"`, + "2023/09/12 17:02:45.041604661 Combining repositories from configuration and content.", + "2023/09/12 17:02:45.041811490 Packages will be installed using the following repositories:", + `2023/09/12 17:02:45.042593774 - CRAN = "https://packagemanager.posit.co/cran/__linux__/jammy/latest"`, + `2023/09/12 17:02:45.042601638 - RSPM = "https://packagemanager.posit.co/cran/__linux__/jammy/latest"`, + `2023/09/12 17:02:45.042624054 - CRAN.1 = "https://cran.rstudio.com"`, + "2023/09/12 17:02:45.061047966 # Installing required R packages with `packrat::restore()` ---------------------", + "2023/09/12 17:02:45.096309315 Warning in packrat::restore(overwrite.dirty = TRUE, prompt = FALSE, restart = FALSE) :", + "2023/09/12 17:02:45.096320185 The most recent snapshot was generated using R version 4.3.0", + "2023/09/12 17:02:45.141302848 Installing R6 (2.5.1) ...", + "2023/09/12 17:02:45.177720769 Using cached R6.", + "2023/09/12 17:02:45.179592403 OK (symlinked cache)", + "2023/09/12 17:02:45.179785920 Installing Rcpp (1.0.10) ...", + "2023/09/12 17:02:45.224715974 Using cached Rcpp.", + "2023/09/12 17:02:45.227149420 OK (symlinked cache)", + "Completed packrat build against R version: '4.3.1'", + }, + Last: 119, + }, + nextOp: events.PublishRestoreREnvOp, + }, } op := events.AgentOp + var err error + for _, test := range tests { - op, err = client.handleTaskUpdate(&test.task, op, log) + op, err = handleTaskUpdate(&test.task, op, log) if test.err != nil { s.ErrorIs(err, test.err) } else { @@ -214,3 +282,38 @@ func (s *ConnectClientSuite) TestWaitForTask() { } log.AssertExpectations(s.T()) } + +func (s *ConnectClientSuite) TestWaitForTaskErr() { + log := loggingtest.NewMockLogger() + + str := mock.AnythingOfType("string") + anything := mock.Anything + log.On("Success", "Done") + log.On("Info", str) + log.On("Info", str, str, anything) + log.On("WithArgs", str, anything).Return(log) + + task := taskDTO{ + Id: types.TaskID("W3YpnrwUOQJxL5DS"), + Output: []string{ + "Building Jupyter notebook...", + "Bundle created with Python version 3.11.3 is compatible with environment Local with Python version 3.11.3 from /opt/python/3.11.3/bin/python3.11", + "Bundle requested Python version 3.11.3; using /opt/python/3.11.3/bin/python3.11 which has version 3.11.3", + "2023/09/12 13:34:48.308740036 Execution halted", + "Build error: exit status 1", + }, + Finished: true, + Error: "exit status 1", + Last: 5, + } + + op := events.AgentOp + op, err := handleTaskUpdate(&task, op, log) + s.Equal(&types.AgentError{ + Code: events.DeploymentFailedCode, + Err: errors.New("exit status 1"), + Data: types.ErrorData{}, + }, err) + s.Equal(events.PublishRestorePythonEnvOp, op) + log.AssertExpectations(s.T()) +} From c7bc4c605ce87c7cb00fbdbb337da0426b18de90 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Tue, 12 Sep 2023 16:08:36 -0400 Subject: [PATCH 10/33] add start event --- internal/api_client/clients/client_connect.go | 1 + 1 file changed, 1 insertion(+) diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index 29d3b4156..bdd1ebdf6 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -325,6 +325,7 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty } op = nextOp log = log.WithArgs(logging.LogKeyOp, op) + log.Start("Starting") } log.Info(line) From a9490861f6cb9767fef302a4e6095cafd1dd6273 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Tue, 12 Sep 2023 16:49:42 -0400 Subject: [PATCH 11/33] update test for new log message --- internal/api_client/clients/client_connect_test.go | 2 ++ 1 file changed, 2 insertions(+) diff --git a/internal/api_client/clients/client_connect_test.go b/internal/api_client/clients/client_connect_test.go index ebf143548..fe6188d04 100644 --- a/internal/api_client/clients/client_connect_test.go +++ b/internal/api_client/clients/client_connect_test.go @@ -61,6 +61,7 @@ func (s *ConnectClientSuite) TestWaitForTask() { str := mock.AnythingOfType("string") anything := mock.Anything + log.On("Start", "Starting") log.On("Success", "Done") log.On("Info", str) log.On("Info", str, str, anything) @@ -288,6 +289,7 @@ func (s *ConnectClientSuite) TestWaitForTaskErr() { str := mock.AnythingOfType("string") anything := mock.Anything + log.On("Start", "Starting") log.On("Success", "Done") log.On("Info", str) log.On("Info", str, str, anything) From 5e8591bc1b4baba0261d6ad515ea73335052b765 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 11:40:08 -0400 Subject: [PATCH 12/33] add overall start/success event --- .vscode/launch.json | 4 +-- internal/api_client/clients/client_connect.go | 25 +++++++++++-------- internal/events/events.go | 1 + internal/publish/publish.go | 10 +++++--- 4 files changed, 25 insertions(+), 15 deletions(-) diff --git a/.vscode/launch.json b/.vscode/launch.json index d1af61246..3d162f605 100644 --- a/.vscode/launch.json +++ b/.vscode/launch.json @@ -13,7 +13,7 @@ "args": [ "publish-ui", "-n", - "devpwpg", + "dogfood", "${workspaceFolder}/notebook1" ], }, @@ -26,7 +26,7 @@ "args": [ "publish", "-n", - "badauth2", + "dogfood", "${workspaceFolder}/notebook1", "--debug", ], diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index bdd1ebdf6..54a70666d 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -321,13 +321,17 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty nextOp = eventOpFromLogLine(op, line) if nextOp != op { if op != "" { - log.Success("Done") + log.Success("Done", logging.LogKeyOp, op) + } + + if nextOp == "" { + fmt.Println("nextOp is empty") } op = nextOp - log = log.WithArgs(logging.LogKeyOp, op) - log.Start("Starting") + log.Start(line, logging.LogKeyOp, op) + } else { + log.Info(line, logging.LogKeyOp, op) } - log.Info(line) // Log a progress event for certain matching log lines. event := packageEventFromLogLine(line) @@ -336,7 +340,8 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty "runtime", event.runtime, "status", event.status, "name", event.name, - "version", event.version) + "version", event.version, + logging.LogKeyOp, op) } } if task.Finished { @@ -344,16 +349,16 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty // TODO: make these errors more specific, maybe by // using the Connect error codes from the logs. err := errors.New(task.Error) - return nextOp, types.NewAgentError(events.DeploymentFailedCode, err, nil) + return op, types.NewAgentError(events.DeploymentFailedCode, err, nil) } - log.Success("Done") + log.Success("Done", logging.LogKeyOp, op) } - return nextOp, nil + return op, nil } func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) error { var previous *taskDTO - var op events.Operation + var op events.Operation = events.PublishOp for { task, err := c.getTask(taskID, previous) @@ -361,7 +366,7 @@ func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) err return err } op, err = handleTaskUpdate(task, op, log) - if task.Finished { + if err != nil || task.Finished { return err } previous = task diff --git a/internal/events/events.go b/internal/events/events.go index 7ea0540f9..dab1bcecd 100644 --- a/internal/events/events.go +++ b/internal/events/events.go @@ -34,6 +34,7 @@ const ( PublishRestoreREnvOp Operation = "publish/restoreREnv" PublishRunContentOp Operation = "publish/runContent" PublishSetVanityUrlOp Operation = "publish/setVanityURL" + PublishOp Operation = "publish" ) func EventTypeOf(op Operation, phase Phase, errCode ErrorCode) EventType { diff --git a/internal/publish/publish.go b/internal/publish/publish.go index 736c179d3..afa2e1908 100644 --- a/internal/publish/publish.go +++ b/internal/publish/publish.go @@ -67,12 +67,13 @@ func logAppInfo(accountURL string, contentID types.ContentID, log logging.Logger DashboardURL: fmt.Sprintf("%s/connect/#/apps/%s", accountURL, contentID), DirectURL: fmt.Sprintf("%s/content/%s", accountURL, contentID), } - log.WithArgs( + log.Success("Deployment successful", + logging.LogKeyOp, events.PublishOp, "dashboardURL", appInfo.DashboardURL, "directURL", appInfo.DirectURL, "serverURL", accountURL, "contentID", contentID, - ).Info("Deployment successful") + ) jsonInfo, err := json.Marshal(appInfo) if err != nil { return err @@ -135,7 +136,10 @@ func withLog[T any](op events.Operation, msg string, label string, log logging.L } func publishWithClient(cmd *cli_types.PublishArgs, bundler bundles.Bundler, account *accounts.Account, client clients.APIClient, log logging.Logger) error { - log.Info("Starting deployment to server", "server", account.URL) + log.Start("Starting deployment to server", + logging.LogKeyOp, events.PublishOp, + "server", account.URL, + ) bundleFile, err := os.CreateTemp("", "bundle-*.tar.gz") if err != nil { return types.ErrToAgentError(events.PublishCreateBundleOp, err) From ebdb4e037b7ae30c874ced6a5922d32b7b2f023d Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 14:51:04 -0400 Subject: [PATCH 13/33] fix state and error handling --- internal/api_client/clients/client_connect.go | 11 +++----- .../api_client/clients/client_connect_test.go | 26 ++++++++++++------- 2 files changed, 20 insertions(+), 17 deletions(-) diff --git a/internal/api_client/clients/client_connect.go b/internal/api_client/clients/client_connect.go index 54a70666d..031a8b621 100644 --- a/internal/api_client/clients/client_connect.go +++ b/internal/api_client/clients/client_connect.go @@ -323,10 +323,6 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty if op != "" { log.Success("Done", logging.LogKeyOp, op) } - - if nextOp == "" { - fmt.Println("nextOp is empty") - } op = nextOp log.Start(line, logging.LogKeyOp, op) } else { @@ -348,8 +344,9 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty if task.Error != "" { // TODO: make these errors more specific, maybe by // using the Connect error codes from the logs. - err := errors.New(task.Error) - return op, types.NewAgentError(events.DeploymentFailedCode, err, nil) + err := types.NewAgentError(events.DeploymentFailedCode, errors.New(task.Error), nil) + err.SetOperation(op) + return op, err } log.Success("Done", logging.LogKeyOp, op) } @@ -358,7 +355,7 @@ func handleTaskUpdate(task *taskDTO, op types.Operation, log logging.Logger) (ty func (c *ConnectClient) WaitForTask(taskID types.TaskID, log logging.Logger) error { var previous *taskDTO - var op events.Operation = events.PublishOp + var op events.Operation for { task, err := c.getTask(taskID, previous) diff --git a/internal/api_client/clients/client_connect_test.go b/internal/api_client/clients/client_connect_test.go index fe6188d04..9f2d074d6 100644 --- a/internal/api_client/clients/client_connect_test.go +++ b/internal/api_client/clients/client_connect_test.go @@ -61,9 +61,12 @@ func (s *ConnectClientSuite) TestWaitForTask() { str := mock.AnythingOfType("string") anything := mock.Anything - log.On("Start", "Starting") - log.On("Success", "Done") - log.On("Info", str) + log.On("Start", "Building Jupyter notebook...", logging.LogKeyOp, events.PublishRestorePythonEnvOp) + log.On("Start", "Launching Jupyter notebook...", logging.LogKeyOp, events.PublishRunContentOp) + log.On("Start", "Bundle created with R version 4.3.0, Python version 3.11.3, and Quarto version 0.9.105 is compatible with environment Local with R version 4.3.1 from /opt/R/4.3.1/bin/R, Python version 3.11.3 from /opt/python/3.11.3/bin/python3.11, and Quarto version 1.3.450 from /opt/quarto/1.3.450/bin/quarto", logging.LogKeyOp, events.PublishRestoreREnvOp) + log.On("Success", "Done", logging.LogKeyOp, events.PublishRestorePythonEnvOp) + log.On("Success", "Done", logging.LogKeyOp, events.PublishRunContentOp) + log.On("Success", "Done", logging.LogKeyOp, events.AgentOp) log.On("Info", str, str, anything) expectedPackages := []struct { @@ -81,14 +84,18 @@ func (s *ConnectClientSuite) TestWaitForTask() { {rRuntime, downloadAndInstallPackage, "Rcpp", "1.0.10"}, } for _, pkg := range expectedPackages { + op := events.PublishRestorePythonEnvOp + if pkg.rt == rRuntime { + op = events.PublishRestoreREnvOp + } log.On("Status", "Package restore", "runtime", pkg.rt, "status", pkg.status, "name", pkg.name, - "version", pkg.version) + "version", pkg.version, + logging.LogKeyOp, op) } - log.On("WithArgs", str, anything).Return(log) taskID := types.TaskID("W3YpnrwUOQJxL5DS") tests := []taskTest{ @@ -289,11 +296,9 @@ func (s *ConnectClientSuite) TestWaitForTaskErr() { str := mock.AnythingOfType("string") anything := mock.Anything - log.On("Start", "Starting") - log.On("Success", "Done") - log.On("Info", str) + + log.On("Start", "Building Jupyter notebook...", logging.LogKeyOp, events.PublishRestorePythonEnvOp) log.On("Info", str, str, anything) - log.On("WithArgs", str, anything).Return(log) task := taskDTO{ Id: types.TaskID("W3YpnrwUOQJxL5DS"), @@ -309,12 +314,13 @@ func (s *ConnectClientSuite) TestWaitForTaskErr() { Last: 5, } - op := events.AgentOp + op := events.Operation("") op, err := handleTaskUpdate(&task, op, log) s.Equal(&types.AgentError{ Code: events.DeploymentFailedCode, Err: errors.New("exit status 1"), Data: types.ErrorData{}, + Op: events.PublishRestorePythonEnvOp, }, err) s.Equal(events.PublishRestorePythonEnvOp, op) log.AssertExpectations(s.T()) From 6f7ebe8f509d029d7adce2f7d87466db5e6415c3 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 14:51:13 -0400 Subject: [PATCH 14/33] logger naming --- internal/logging/logger.go | 24 ++++++++++++------------ internal/logging/logger_test.go | 20 ++++++++++---------- 2 files changed, 22 insertions(+), 22 deletions(-) diff --git a/internal/logging/logger.go b/internal/logging/logger.go index 3142612ed..c45286c2b 100644 --- a/internal/logging/logger.go +++ b/internal/logging/logger.go @@ -38,37 +38,37 @@ type Logger interface { WithArgs(args ...any) Logger } -type loggerImpl struct { +type logger struct { BaseLogger } -func New() loggerImpl { - return loggerImpl{ +func New() Logger { + return logger{ slog.Default(), } } -func FromStdLogger(log *slog.Logger) loggerImpl { - return loggerImpl{log} +func FromStdLogger(log *slog.Logger) Logger { + return logger{log} } -func (l loggerImpl) Start(msg string, args ...any) { +func (l logger) Start(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, StartPhase}, args...)...) } -func (l loggerImpl) Success(msg string, args ...any) { +func (l logger) Success(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, SuccessPhase}, args...)...) } -func (l loggerImpl) Status(msg string, args ...any) { +func (l logger) Status(msg string, args ...any) { l.Info(msg, append([]any{LogKeyPhase, ProgressPhase}, args...)...) } -func (l loggerImpl) Progress(msg string, done float32, total float32, args ...any) { +func (l logger) Progress(msg string, done float32, total float32, args ...any) { l.Info(msg, append([]any{LogKeyPhase, ProgressPhase, "done", done, "total", total}, args...)...) } -func (l loggerImpl) Failure(err error) { +func (l logger) Failure(err error) { if agentError, ok := err.(types.EventableError); ok { args := []any{ LogKeyOp, agentError.GetOperation(), @@ -88,6 +88,6 @@ func (l loggerImpl) Failure(err error) { } } -func (l loggerImpl) WithArgs(args ...any) Logger { - return loggerImpl{l.BaseLogger.With(args...)} +func (l logger) WithArgs(args ...any) Logger { + return logger{l.BaseLogger.With(args...)} } diff --git a/internal/logging/logger_test.go b/internal/logging/logger_test.go index 48a02c6f1..de43c5ce5 100644 --- a/internal/logging/logger_test.go +++ b/internal/logging/logger_test.go @@ -22,13 +22,13 @@ func TestLoggingSuite(t *testing.T) { } func (s *LoggingSuite) TestDefaultLogger() { - log := New() + log := New().(logger) s.NotNil(log.BaseLogger) } func (s *LoggingSuite) TestFromStdLogger() { stdLogger := slog.Default() - log := FromStdLogger(stdLogger) + log := FromStdLogger(stdLogger).(logger) s.NotNil(log.BaseLogger) s.Equal(stdLogger, log.BaseLogger) } @@ -37,7 +37,7 @@ func (s *LoggingSuite) TestStart() { baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, StartPhase, "arg", "value") - log := loggerImpl{baseLogger} + log := logger{baseLogger} log.Start("message", "arg", "value") baseLogger.AssertExpectations(s.T()) } @@ -46,7 +46,7 @@ func (s *LoggingSuite) TestSuccess() { baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, SuccessPhase, "arg", "value") - log := loggerImpl{baseLogger} + log := logger{baseLogger} log.Success("message", "arg", "value") baseLogger.AssertExpectations(s.T()) } @@ -55,7 +55,7 @@ func (s *LoggingSuite) TestStatus() { baseLogger := NewMockBaseLogger() baseLogger.On("Info", "message", LogKeyPhase, ProgressPhase, "arg", "value") - log := loggerImpl{baseLogger} + log := logger{baseLogger} log.Status("message", "arg", "value") baseLogger.AssertExpectations(s.T()) } @@ -69,7 +69,7 @@ func (s *LoggingSuite) TestProgress() { "total", float32(100), "arg", "value") - log := loggerImpl{baseLogger} + log := logger{baseLogger} log.Progress("message", 20, 100, "arg", "value") baseLogger.AssertExpectations(s.T()) } @@ -79,7 +79,7 @@ func (s *LoggingSuite) TestFailureGoError() { baseLogger.On("Error", "test error", LogKeyPhase, FailurePhase) baseLogger.On("Debug", mock.AnythingOfType("string")) - log := loggerImpl{baseLogger} + log := logger{baseLogger} err := errors.New("test error") log.Failure(err) baseLogger.AssertExpectations(s.T()) @@ -96,7 +96,7 @@ func (s *LoggingSuite) TestFailureAgentError() { LogKeyErrCode, types.UnknownErrorCode, "Metadata", "some metadata") - log := loggerImpl{baseLogger} + log := logger{baseLogger} baseErr := errors.New("test error") errData := struct { Metadata string @@ -111,7 +111,7 @@ func (s *LoggingSuite) TestWith() { baseLogger := NewMockBaseLogger() expectedLogger := slog.Default() baseLogger.On("With", "arg", "value", "arg2", "value2").Return(expectedLogger) - log := loggerImpl{baseLogger} + log := logger{baseLogger} actualLogger := log.WithArgs("arg", "value", "arg2", "value2") - s.Equal(loggerImpl{expectedLogger}, actualLogger) + s.Equal(logger{expectedLogger}, actualLogger) } From 5dcfb4fe08f90df15f0f7bba7c2df79a99cdae8d Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 08:20:20 -0400 Subject: [PATCH 15/33] make publish API async --- internal/services/api/publish.go | 29 +++++++++++++++++++++++------ internal/services/local_token.go | 21 ++------------------- internal/state/deployment.go | 11 +++++++++++ internal/util/random.go | 25 +++++++++++++++++++++++++ 4 files changed, 61 insertions(+), 25 deletions(-) diff --git a/internal/services/api/publish.go b/internal/services/api/publish.go index 126cbce3a..6b3041b59 100644 --- a/internal/services/api/publish.go +++ b/internal/services/api/publish.go @@ -3,24 +3,41 @@ package api // Copyright (C) 2023 by Posit Software, PBC. import ( + "encoding/json" "net/http" "github.com/rstudio/connect-client/internal/accounts" "github.com/rstudio/connect-client/internal/cli_types" "github.com/rstudio/connect-client/internal/logging" "github.com/rstudio/connect-client/internal/publish" + "github.com/rstudio/connect-client/internal/state" ) +type PublishReponse struct { + LocalID state.LocalDeploymentID `json:"local_id"` // Unique ID of this publishing operation. Only valid for this run of the agent. +} + func PostPublishHandlerFunc(publishArgs *cli_types.PublishArgs, lister accounts.AccountList, log logging.Logger) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { - switch req.Method { - case http.MethodPost: + localID, err := state.NewLocalID() + if err != nil { + InternalError(w, req, log, err) + return + } + publishArgs.State.LocalID = localID + response := PublishReponse{ + LocalID: localID, + } + w.Header().Set("content-type", "application/json") + w.WriteHeader(http.StatusAccepted) + json.NewEncoder(w).Encode(response) + + go func() { + log = log.WithArgs("local_id", localID) err := publish.PublishManifestFiles(publishArgs, lister, log) if err != nil { - InternalError(w, req, log, err) + log.Error("Deployment failed", "error", err.Error()) } - default: - return - } + }() } } diff --git a/internal/services/local_token.go b/internal/services/local_token.go index 3e00f1185..90ae6a0ea 100644 --- a/internal/services/local_token.go +++ b/internal/services/local_token.go @@ -3,32 +3,15 @@ package services // Copyright (C) 2023 by Posit Software, PBC. import ( - "encoding/base64" - "strings" - "github.com/rstudio/connect-client/internal/util" ) type LocalToken string func NewLocalToken() (LocalToken, error) { - key, err := util.RandomBytes(32) - if err != nil { - return LocalToken(""), err - } - tokenString, err := toBase64(key) + str, err := util.RandomString(32) if err != nil { return LocalToken(""), err } - return LocalToken(tokenString), nil -} - -func toBase64(data []byte) (string, error) { - var writer strings.Builder - encoder := base64.NewEncoder(base64.RawURLEncoding, &writer) - _, err := encoder.Write(data) - if err != nil { - return "", err - } - return writer.String(), nil + return LocalToken(str), nil } diff --git a/internal/state/deployment.go b/internal/state/deployment.go index 3eea9c204..db18d6cf2 100644 --- a/internal/state/deployment.go +++ b/internal/state/deployment.go @@ -23,7 +23,18 @@ type TargetID struct { DeployedAt types.NullTime `json:"deployed_at" kong:"-"` // Date/time bundle was deployed } +type LocalDeploymentID string + +func NewLocalID() (LocalDeploymentID, error) { + str, err := util.RandomString(16) + if err != nil { + return LocalDeploymentID(""), err + } + return LocalDeploymentID(str), nil +} + type Deployment struct { + LocalID LocalDeploymentID `json:"local_id" kong:"-"` // Unique ID of this publishing operation. Only valid for this run of the agent. SourceDir util.Path `json:"source_path" kong:"-"` // Absolute path to source directory being published Target TargetID `json:"target" kong:"embed"` // Identity of previous deployment Manifest bundles.Manifest `json:"manifest" kong:"embed"` // manifest.json content for this deployment diff --git a/internal/util/random.go b/internal/util/random.go index 1b0021401..70c447b96 100644 --- a/internal/util/random.go +++ b/internal/util/random.go @@ -4,6 +4,8 @@ package util import ( "crypto/rand" + "encoding/base64" + "strings" ) func RandomBytes(n int) ([]byte, error) { @@ -11,3 +13,26 @@ func RandomBytes(n int) ([]byte, error) { _, err := rand.Read(buf) return buf, err } + +func RandomString(n int) (string, error) { + // Base64 encoding of bytes->string expands length by 1/3 + key, err := RandomBytes((n * 3) / 4) + if err != nil { + return "", err + } + tokenString, err := toBase64(key) + if err != nil { + return "", err + } + return tokenString, nil +} + +func toBase64(data []byte) (string, error) { + var writer strings.Builder + encoder := base64.NewEncoder(base64.RawURLEncoding, &writer) + _, err := encoder.Write(data) + if err != nil { + return "", err + } + return writer.String(), nil +} From d1f1bbce9ddf0ab911d03ac772f97fc57cd76950 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 10:13:34 -0400 Subject: [PATCH 16/33] LocalToken test --- internal/services/local_token_test.go | 26 ++++++++++++++++++++++++++ 1 file changed, 26 insertions(+) create mode 100644 internal/services/local_token_test.go diff --git a/internal/services/local_token_test.go b/internal/services/local_token_test.go new file mode 100644 index 000000000..557592570 --- /dev/null +++ b/internal/services/local_token_test.go @@ -0,0 +1,26 @@ +package services + +// Copyright (C) 2023 by Posit Software, PBC. + +import ( + "testing" + + "github.com/rstudio/connect-client/internal/util/utiltest" + "github.com/stretchr/testify/suite" +) + +type LocalTokenSuite struct { + utiltest.Suite +} + +func TestLocalTokenSuite(t *testing.T) { + suite.Run(t, new(LocalTokenSuite)) +} + +func (s *LocalTokenSuite) TestNewLocalToken() { + token1, err := NewLocalToken() + s.NoError(err) + token2, err := NewLocalToken() + s.NoError(err) + s.NotEqual(token1, token2) +} From 8479de1baf912a5e42b0f0eca04d958b77458c56 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 10:15:51 -0400 Subject: [PATCH 17/33] RandomString test --- internal/util/random_test.go | 30 +++++++++++++++++++++++++++--- 1 file changed, 27 insertions(+), 3 deletions(-) diff --git a/internal/util/random_test.go b/internal/util/random_test.go index 330fc33d1..6ae6d8737 100644 --- a/internal/util/random_test.go +++ b/internal/util/random_test.go @@ -18,7 +18,31 @@ func TestRandomSuite(t *testing.T) { } func (s *RandomSuite) TestRandomBytes() { - r, err := RandomBytes(32) - s.Nil(err) - s.Len(r, 32) + r1, err := RandomBytes(32) + s.NoError(err) + s.Len(r1, 32) + + r2, err := RandomBytes(32) + s.NoError(err) + s.Len(r2, 32) + s.NotEqual(r1, r2) + + r3, err := RandomBytes(12) + s.NoError(err) + s.Len(r3, 12) +} + +func (s *RandomSuite) TestRandomString() { + r1, err := RandomString(32) + s.NoError(err) + s.Len(r1, 32) + + r2, err := RandomString(32) + s.NoError(err) + s.Len(r2, 32) + s.NotEqual(r1, r2) + + r3, err := RandomString(12) + s.NoError(err) + s.Len(r3, 12) } From 0cd6b687ec55faf26941d138b2e3ffd80c27c978 Mon Sep 17 00:00:00 2001 From: Michael Marchetti Date: Thu, 14 Sep 2023 10:46:52 -0400 Subject: [PATCH 18/33] publish API test --- internal/services/api/publish.go | 4 +- internal/services/api/publish_test.go | 57 +++++++++++++++++++++++++++ 2 files changed, 60 insertions(+), 1 deletion(-) create mode 100644 internal/services/api/publish_test.go diff --git a/internal/services/api/publish.go b/internal/services/api/publish.go index 6b3041b59..9a79ac210 100644 --- a/internal/services/api/publish.go +++ b/internal/services/api/publish.go @@ -17,6 +17,8 @@ type PublishReponse struct { LocalID state.LocalDeploymentID `json:"local_id"` // Unique ID of this publishing operation. Only valid for this run of the agent. } +var publishFn = publish.PublishManifestFiles + func PostPublishHandlerFunc(publishArgs *cli_types.PublishArgs, lister accounts.AccountList, log logging.Logger) http.HandlerFunc { return func(w http.ResponseWriter, req *http.Request) { localID, err := state.NewLocalID() @@ -34,7 +36,7 @@ func PostPublishHandlerFunc(publishArgs *cli_types.PublishArgs, lister accounts. go func() { log = log.WithArgs("local_id", localID) - err := publish.PublishManifestFiles(publishArgs, lister, log) + err := publishFn(publishArgs, lister, log) if err != nil { log.Error("Deployment failed", "error", err.Error()) } diff --git a/internal/services/api/publish_test.go b/internal/services/api/publish_test.go new file mode 100644 index 000000000..193cffd05 --- /dev/null +++ b/internal/services/api/publish_test.go @@ -0,0 +1,57 @@ +package api + +// Copyright (C) 2023 by Posit Software, PBC. + +import ( + "encoding/json" + "net/http" + "net/http/httptest" + "testing" + + "github.com/rstudio/connect-client/internal/accounts" + "github.com/rstudio/connect-client/internal/cli_types" + "github.com/rstudio/connect-client/internal/logging" + "github.com/rstudio/connect-client/internal/state" + "github.com/rstudio/connect-client/internal/util/utiltest" + "github.com/stretchr/testify/suite" +) + +type PublishHandlerFuncSuite struct { + utiltest.Suite +} + +func TestPublishHandlerFuncSuite(t *testing.T) { + suite.Run(t, new(PublishHandlerFuncSuite)) +} + +func (s *PublishHandlerFuncSuite) TestPublishHandlerFunc() { + publishArgs := &cli_types.PublishArgs{ + State: state.NewDeployment(), + } + oldID := publishArgs.State.LocalID + log := logging.New() + + rec := httptest.NewRecorder() + req, err := http.NewRequest("POST", "/api/publish", nil) + s.NoError(err) + + publishFn = func(args *cli_types.PublishArgs, lister accounts.AccountList, log logging.Logger) error { + s.NotNil(args) + s.NotEqual(state.LocalDeploymentID(""), args.State.LocalID) + return nil + } + handler := PostPublishHandlerFunc(publishArgs, nil, log) + handler(rec, req) + + s.Equal(http.StatusAccepted, rec.Result().StatusCode) + s.Equal("application/json", rec.Header().Get("content-type")) + + res := &PublishReponse{} + dec := json.NewDecoder(rec.Body) + dec.DisallowUnknownFields() + s.NoError(dec.Decode(res)) + + s.NotEqual(state.LocalDeploymentID(""), publishArgs.State.LocalID) + s.NotEqual(oldID, publishArgs.State.LocalID) + s.Equal(publishArgs.State.LocalID, res.LocalID) +} From 2499e5eb165312da7e5c97e9bd5c461be2efd89d Mon Sep 17 00:00:00 2001 From: Bill Sager Date: Mon, 18 Sep 2023 14:07:18 -0700 Subject: [PATCH 19/33] initial refactoring towards POC 9-15 base --- web/public/images/publisher-advanced.svg | 27 +++++++ web/public/images/publisher-destination.svg | 11 +++ web/public/images/publisher-folder.svg | 10 +++ web/public/images/publisher-positlogo.svg | 13 ++++ web/public/images/publisher-python.svg | 15 ++++ web/public/images/publisher-settings.svg | 29 ++++++++ web/src/App.vue | 67 ++++++++--------- web/src/api/types/deployments.ts | 2 + web/src/components/AppMenu.vue | 73 +++++++++++++++++++ web/src/components/LayoutPanel.vue | 47 ------------ .../AdvancedSettings.vue | 4 +- .../CommonSettings.vue | 4 +- .../configurePublish/ConfigurePublish.vue | 51 +++++++++++++ .../configurePublish/DeploymentMode.vue | 46 ++++++++++++ .../DestinationTarget.vue | 4 +- .../FilesToPublish.vue | 4 +- .../configurePublish/LayoutPanel.vue | 60 +++++++++++++++ .../PublishingHeader.vue} | 28 +++++-- .../PythonProject.vue | 4 +- .../publishProcess/PublishContent.vue | 28 +++++++ web/src/utils/modelWrapper.ts | 23 ++++++ 21 files changed, 449 insertions(+), 101 deletions(-) create mode 100644 web/public/images/publisher-advanced.svg create mode 100644 web/public/images/publisher-destination.svg create mode 100644 web/public/images/publisher-folder.svg create mode 100644 web/public/images/publisher-positlogo.svg create mode 100644 web/public/images/publisher-python.svg create mode 100644 web/public/images/publisher-settings.svg create mode 100644 web/src/components/AppMenu.vue delete mode 100644 web/src/components/LayoutPanel.vue rename web/src/components/{panels => configurePublish}/AdvancedSettings.vue (70%) rename web/src/components/{panels => configurePublish}/CommonSettings.vue (67%) create mode 100644 web/src/components/configurePublish/ConfigurePublish.vue create mode 100644 web/src/components/configurePublish/DeploymentMode.vue rename web/src/components/{panels => configurePublish}/DestinationTarget.vue (83%) rename web/src/components/{panels => configurePublish}/FilesToPublish.vue (95%) create mode 100644 web/src/components/configurePublish/LayoutPanel.vue rename web/src/components/{PublishProcess.vue => configurePublish/PublishingHeader.vue} (56%) rename web/src/components/{panels => configurePublish}/PythonProject.vue (71%) create mode 100644 web/src/components/publishProcess/PublishContent.vue create mode 100644 web/src/utils/modelWrapper.ts diff --git a/web/public/images/publisher-advanced.svg b/web/public/images/publisher-advanced.svg new file mode 100644 index 000000000..4d2233060 --- /dev/null +++ b/web/public/images/publisher-advanced.svg @@ -0,0 +1,27 @@ + + + + + + + diff --git a/web/public/images/publisher-destination.svg b/web/public/images/publisher-destination.svg new file mode 100644 index 000000000..44c8ee787 --- /dev/null +++ b/web/public/images/publisher-destination.svg @@ -0,0 +1,11 @@ + + + + + + + diff --git a/web/public/images/publisher-folder.svg b/web/public/images/publisher-folder.svg new file mode 100644 index 000000000..0214b862c --- /dev/null +++ b/web/public/images/publisher-folder.svg @@ -0,0 +1,10 @@ + + + + + + diff --git a/web/public/images/publisher-positlogo.svg b/web/public/images/publisher-positlogo.svg new file mode 100644 index 000000000..19c18d07c --- /dev/null +++ b/web/public/images/publisher-positlogo.svg @@ -0,0 +1,13 @@ + + + + + + + + + + diff --git a/web/public/images/publisher-python.svg b/web/public/images/publisher-python.svg new file mode 100644 index 000000000..e9a393c9c --- /dev/null +++ b/web/public/images/publisher-python.svg @@ -0,0 +1,15 @@ + + + + + + + + diff --git a/web/public/images/publisher-settings.svg b/web/public/images/publisher-settings.svg new file mode 100644 index 000000000..7fc0b8fde --- /dev/null +++ b/web/public/images/publisher-settings.svg @@ -0,0 +1,29 @@ + + + + + + + diff --git a/web/src/App.vue b/web/src/App.vue index cd4754320..ffbb1a40b 100644 --- a/web/src/App.vue +++ b/web/src/App.vue @@ -9,61 +9,56 @@ elevated class="bg-primary text-white" > - - + + + + Posit Publisher - -
- What would you like to be published and how? -
- - - - - - - - - - - - -
+ +
diff --git a/web/src/components/LayoutPanel.vue b/web/src/components/LayoutPanel.vue deleted file mode 100644 index b91c24025..000000000 --- a/web/src/components/LayoutPanel.vue +++ /dev/null @@ -1,47 +0,0 @@ - - - - - - diff --git a/web/src/components/panels/AdvancedSettings.vue b/web/src/components/configurePublish/AdvancedSettings.vue similarity index 70% rename from web/src/components/panels/AdvancedSettings.vue rename to web/src/components/configurePublish/AdvancedSettings.vue index 02adf2774..cca067db7 100644 --- a/web/src/components/panels/AdvancedSettings.vue +++ b/web/src/components/configurePublish/AdvancedSettings.vue @@ -3,7 +3,7 @@ diff --git a/web/src/components/panels/CommonSettings.vue b/web/src/components/configurePublish/CommonSettings.vue similarity index 67% rename from web/src/components/panels/CommonSettings.vue rename to web/src/components/configurePublish/CommonSettings.vue index ea99cdb2e..f7210dcc5 100644 --- a/web/src/components/panels/CommonSettings.vue +++ b/web/src/components/configurePublish/CommonSettings.vue @@ -3,13 +3,13 @@ diff --git a/web/src/components/configurePublish/ConfigurePublish.vue b/web/src/components/configurePublish/ConfigurePublish.vue new file mode 100644 index 000000000..eb1fd1a39 --- /dev/null +++ b/web/src/components/configurePublish/ConfigurePublish.vue @@ -0,0 +1,51 @@ + + + diff --git a/web/src/components/configurePublish/DeploymentMode.vue b/web/src/components/configurePublish/DeploymentMode.vue new file mode 100644 index 000000000..8774ec643 --- /dev/null +++ b/web/src/components/configurePublish/DeploymentMode.vue @@ -0,0 +1,46 @@ + + + + + diff --git a/web/src/components/panels/DestinationTarget.vue b/web/src/components/configurePublish/DestinationTarget.vue similarity index 83% rename from web/src/components/panels/DestinationTarget.vue rename to web/src/components/configurePublish/DestinationTarget.vue index 322de1ae5..e6385d438 100644 --- a/web/src/components/panels/DestinationTarget.vue +++ b/web/src/components/configurePublish/DestinationTarget.vue @@ -4,7 +4,7 @@ TODO: select from previous deployments or add to existing or new targets @@ -13,7 +13,7 @@ diff --git a/web/src/components/PublishProcess.vue b/web/src/components/configurePublish/PublishingHeader.vue similarity index 56% rename from web/src/components/PublishProcess.vue rename to web/src/components/configurePublish/PublishingHeader.vue index 40a231384..c8144fc52 100644 --- a/web/src/components/PublishProcess.vue +++ b/web/src/components/configurePublish/PublishingHeader.vue @@ -1,12 +1,25 @@