Fix bug where Action UI may occasionally not load logs (#6122)

In the combination of events where the user is viewing an action that is completed (and therefore no interval-based loading of logs is occurring), and `loadJob` is called while `loadJob` is already running (commonly from expanding two log sections back-to-back), the second request for loading would be discarded and never occur.

To fix this, the invocation of `loadJob` keeps track of the log cursors it is attempting to load, and an aborted invocation stores its attempted load.  If `loadJob` succeeds in loading and finds that an attempt was aborted while it was busy, it will reload the data.

Steps to reproduce:
- Open an Action UI that is already "Done".
- Click on two steps in rapid succession to expand their logs.
- (Race condition) As long as the second click is registered while the first log chunk is being loaded, its data won't load.

## Checklist

The [contributor guide](https://forgejo.org/docs/next/contributor/) contains information that will be helpful to first time contributors. There also are a few [conditions for merging Pull Requests in Forgejo repositories](https://codeberg.org/forgejo/governance/src/branch/main/PullRequestsAgreement.md). You are also welcome to join the [Forgejo development chatroom](https://matrix.to/#/#forgejo-development:matrix.org).

### Tests

- I added test coverage for Go changes...  (**not applicable**)
  - [ ] in their respective `*_test.go` for unit tests.
  - [ ] in the `tests/integration` directory if it involves interactions with a live Forgejo server.
- I added test coverage for JavaScript changes...
  - [x] in `web_src/js/*.test.js` if it can be unit tested.
  - [ ] in `tests/e2e/*.test.e2e.js` if it requires interactions with a live Forgejo server (see also the [developer guide for JavaScript testing](https://codeberg.org/forgejo/forgejo/src/branch/forgejo/tests/e2e/README.md#end-to-end-tests)).

### Documentation

- [ ] I created a pull request [to the documentation](https://codeberg.org/forgejo/docs) to explain to Forgejo users how to use this change.
- [x] I did not document these changes and I do not expect someone else to do it.

### Release notes

- [ ] I do not want this change to show in the release notes.
- [x] I want the title to show in the release notes with a link to this pull request.
- [ ] I want the content of the `release-notes/<pull request number>.md` to be be used for the release notes instead of the title.

Reviewed-on: https://codeberg.org/forgejo/forgejo/pulls/6122
Reviewed-by: Earl Warren <earl-warren@noreply.codeberg.org>
Reviewed-by: Otto <otto@codeberg.org>
Reviewed-by: Gusted <gusted@noreply.codeberg.org>
Co-authored-by: Mathieu Fenniak <mathieu@fenniak.net>
Co-committed-by: Mathieu Fenniak <mathieu@fenniak.net>

web_src/js/components/RepoActionView.test.js

@@ -103,3 +103,115 @@ test('processes ##[group] and ##[endgroup]', async () => {
   // Check if after the log list exists another log line
   expect(wrapper.get('.job-log-list + .job-log-line > .log-msg').text()).toEqual('A line outside the group');
 });
+
+test('load multiple steps on a finished action', async () => {
+  Object.defineProperty(document.documentElement, 'lang', {value: 'en'});
+  vi.spyOn(global, 'fetch').mockImplementation((url, opts) => {
+    if (url.endsWith('/artifacts')) {
+      return Promise.resolve({
+        ok: true,
+        json: vi.fn().mockResolvedValue(
+          {
+            artifacts: [],
+          },
+        ),
+      });
+    }
+
+    const postBody = JSON.parse(opts.body);
+    const stepsLog_value = [];
+    for (const cursor of postBody.logCursors) {
+      if (cursor.expanded) {
+        stepsLog_value.push(
+          {
+            step: cursor.step,
+            cursor: 0,
+            lines: [
+              {index: 1, message: `Step #${cursor.step + 1} Log #1`, timestamp: 0},
+              {index: 1, message: `Step #${cursor.step + 1} Log #2`, timestamp: 0},
+              {index: 1, message: `Step #${cursor.step + 1} Log #3`, timestamp: 0},
+            ],
+          },
+        );
+      }
+    }
+    const jobs_value = {
+      state: {
+        run: {
+          status: 'success',
+          commit: {
+            pusher: {},
+          },
+        },
+        currentJob: {
+          steps: [
+            {
+              summary: 'Test Step #1',
+              duration: '1s',
+              status: 'success',
+            },
+            {
+              summary: 'Test Step #2',
+              duration: '1s',
+              status: 'success',
+            },
+          ],
+        },
+      },
+      logs: {
+        stepsLog: opts.body?.includes('"cursor":null') ? stepsLog_value : [],
+      },
+    };
+
+    return Promise.resolve({
+      ok: true,
+      json: vi.fn().mockResolvedValue(
+        jobs_value,
+      ),
+    });
+  });
+
+  const wrapper = mount(RepoActionView, {
+    props: {
+      actionsURL: 'https://example.com/example-org/example-repo/actions',
+      runIndex: '1',
+      jobIndex: '2',
+      locale: {
+        approve: '',
+        cancel: '',
+        rerun: '',
+        artifactsTitle: '',
+        areYouSure: '',
+        confirmDeleteArtifact: '',
+        rerun_all: '',
+        showTimeStamps: '',
+        showLogSeconds: '',
+        showFullScreen: '',
+        downloadLogs: '',
+        status: {
+          unknown: '',
+          waiting: '',
+          running: '',
+          success: '',
+          failure: '',
+          cancelled: '',
+          skipped: '',
+          blocked: '',
+        },
+      },
+    },
+  });
+  await flushPromises();
+  // Click on both steps to start their log loading in fast succession...
+  await wrapper.get('.job-step-section:nth-of-type(1) .job-step-summary').trigger('click');
+  await wrapper.get('.job-step-section:nth-of-type(2) .job-step-summary').trigger('click');
+  await flushPromises();
+
+  // Verify both step's logs were loaded
+  expect(wrapper.get('.job-step-section:nth-of-type(1) .job-log-line:nth-of-type(1) .log-msg').text()).toEqual('Step #1 Log #1');
+  expect(wrapper.get('.job-step-section:nth-of-type(1) .job-log-line:nth-of-type(2) .log-msg').text()).toEqual('Step #1 Log #2');
+  expect(wrapper.get('.job-step-section:nth-of-type(1) .job-log-line:nth-of-type(3) .log-msg').text()).toEqual('Step #1 Log #3');
+  expect(wrapper.get('.job-step-section:nth-of-type(2) .job-log-line:nth-of-type(1) .log-msg').text()).toEqual('Step #2 Log #1');
+  expect(wrapper.get('.job-step-section:nth-of-type(2) .job-log-line:nth-of-type(2) .log-msg').text()).toEqual('Step #2 Log #2');
+  expect(wrapper.get('.job-step-section:nth-of-type(2) .job-log-line:nth-of-type(3) .log-msg').text()).toEqual('Step #2 Log #3');
+});

web_src/js/components/RepoActionView.vue

@@ -26,6 +26,7 @@ const sfc = {
     return {
       // internal state
       loading: false,
+      needLoadingWithLogCursors: null,
       intervalID: null,
       currentJobStepsStates: [],
       artifacts: [],
@@ -114,7 +115,9 @@ const sfc = {
     toggleStepLogs(idx) {
       this.currentJobStepsStates[idx].expanded = !this.currentJobStepsStates[idx].expanded;
       if (this.currentJobStepsStates[idx].expanded) {
-        this.loadJob(); // try to load the data immediately instead of waiting for next timer interval
+        // request data load immediately instead of waiting for next timer interval (which, if the job is done, will
+        // never happen because the interval will have been disabled)
+        this.loadJob();
       }
     },
     // cancel a run
@@ -229,13 +232,16 @@ const sfc = {
       await this.loadJob();
     },
 
-    async fetchJob() {
-      const logCursors = this.currentJobStepsStates.map((it, idx) => {
+    getLogCursors() {
+      return this.currentJobStepsStates.map((it, idx) => {
         // cursor is used to indicate the last position of the logs
         // it's only used by backend, frontend just reads it and passes it back, it and can be any type.
         // for example: make cursor=null means the first time to fetch logs, cursor=eof means no more logs, etc
         return {step: idx, cursor: it.cursor, expanded: it.expanded};
       });
+    },
+
+    async fetchJob(logCursors) {
       const resp = await POST(`${this.actionsURL}/runs/${this.runIndex}/jobs/${this.jobIndex}`, {
         data: {logCursors},
       });
@@ -243,19 +249,45 @@ const sfc = {
     },
 
     async loadJob() {
-      if (this.loading) return;
+      let myLoadingLogCursors = this.getLogCursors();
+      if (this.loading) {
+        // loadJob is already executing; but it's possible that our log cursor request has changed since it started.  If
+        // the interval load is active, that problem would solve itself, but if it isn't (say we're viewing a "done"
+        // job), then the change to the requested cursors may never be loaded.  To address this we set our newest
+        // requested log cursors into a state property and rely on loadJob to retry at the end of its execution if it
+        // notices these have changed.
+        this.needLoadingWithLogCursors = myLoadingLogCursors;
+        return;
+      }
+
       try {
         this.loading = true;
+        // Since no async operations occured since fetching myLoadingLogCursors, we can be sure that we have the most
+        // recent needed log cursors, so we can reset needLoadingWithLogCursors -- it could be stale if exceptions
+        // occurred in previous load attempts.
+        this.needLoadingWithLogCursors = null;
 
         let job, artifacts;
-        try {
-          [job, artifacts] = await Promise.all([
-            this.fetchJob(),
-            this.fetchArtifacts(), // refresh artifacts if upload-artifact step done
-          ]);
-        } catch (err) {
-          if (err instanceof TypeError) return; // avoid network error while unloading page
-          throw err;
+
+        while (true) {
+          try {
+            [job, artifacts] = await Promise.all([
+              this.fetchJob(myLoadingLogCursors),
+              this.fetchArtifacts(), // refresh artifacts if upload-artifact step done
+            ]);
+          } catch (err) {
+            if (err instanceof TypeError) return; // avoid network error while unloading page
+            throw err;
+          }
+
+          // We can be done as long as needLoadingWithLogCursors is null, or the same as what we just loaded.
+          if (this.needLoadingWithLogCursors === null || JSON.stringify(this.needLoadingWithLogCursors) === JSON.stringify(myLoadingLogCursors)) {
+            this.needLoadingWithLogCursors = null;
+            break;
+          }
+
+          // Otherwise we need to retry that.
+          myLoadingLogCursors = this.needLoadingWithLogCursors;
         }
 
         this.artifacts = artifacts['artifacts'] || [];