Merge branch '21204-stable-log-sort' into main. Closes #21204

Arvados-DCO-1.1-Signed-off-by: Stephen Smith <stephen@curii.com>

diff --git a/cypress/integration/process.spec.js b/cypress/integration/process.spec.js
index 438acbf14dca2608ddf23b9dc3822d4aedbf3dd2..38d9794b18573a0379a3bbba93f53f0b661abe83 100644 (file)
--- a/cypress/integration/process.spec.js
+++ b/cypress/integration/process.spec.js
@@ -556,6 +556,53 @@ describe("Process tests", function () {
             });
         });
 
+        it("preserves original ordering of lines within the same log type", function () {
+            const crName = "test_container_request";
+            createContainerRequest(activeUser, crName, "arvados/jobs", ["echo", "hello world"], false, "Committed").then(function (containerRequest) {
+                cy.appendLog(adminUser.token, containerRequest.uuid, "stdout.txt", [
+                    // Should come first
+                    "2023-07-18T20:14:46.000000000Z A out 1",
+                    // Comes fourth in a contiguous block
+                    "2023-07-18T20:14:48.128642814Z A out 2",
+                    "2023-07-18T20:14:48.128642814Z X out 3",
+                    "2023-07-18T20:14:48.128642814Z A out 4",
+                ]).as("stdout");
+
+                cy.appendLog(adminUser.token, containerRequest.uuid, "stderr.txt", [
+                    // Comes second
+                    "2023-07-18T20:14:47.000000000Z Z err 1",
+                    // Comes third in a contiguous block
+                    "2023-07-18T20:14:48.128642814Z B err 2",
+                    "2023-07-18T20:14:48.128642814Z C err 3",
+                    "2023-07-18T20:14:48.128642814Z Y err 4",
+                    "2023-07-18T20:14:48.128642814Z Z err 5",
+                    "2023-07-18T20:14:48.128642814Z A err 6",
+                ]).as("stderr");
+
+                cy.loginAs(activeUser);
+                cy.goToPath(`/processes/${containerRequest.uuid}`);
+                cy.get("[data-cy=process-details]").should("contain", crName);
+                cy.get("[data-cy=process-logs]").should("contain", "No logs yet");
+
+                cy.getAll("@stdout", "@stderr").then(() => {
+                    // Switch to All logs
+                    cy.get("[data-cy=process-logs-filter]").click();
+                    cy.get("body").contains("li", "All logs").click();
+                    // Verify sorted logs
+                    cy.get("[data-cy=process-logs] pre").eq(0).should("contain", "2023-07-18T20:14:46.000000000Z A out 1");
+                    cy.get("[data-cy=process-logs] pre").eq(1).should("contain", "2023-07-18T20:14:47.000000000Z Z err 1");
+                    cy.get("[data-cy=process-logs] pre").eq(2).should("contain", "2023-07-18T20:14:48.128642814Z B err 2");
+                    cy.get("[data-cy=process-logs] pre").eq(3).should("contain", "2023-07-18T20:14:48.128642814Z C err 3");
+                    cy.get("[data-cy=process-logs] pre").eq(4).should("contain", "2023-07-18T20:14:48.128642814Z Y err 4");
+                    cy.get("[data-cy=process-logs] pre").eq(5).should("contain", "2023-07-18T20:14:48.128642814Z Z err 5");
+                    cy.get("[data-cy=process-logs] pre").eq(6).should("contain", "2023-07-18T20:14:48.128642814Z A err 6");
+                    cy.get("[data-cy=process-logs] pre").eq(7).should("contain", "2023-07-18T20:14:48.128642814Z A out 2");
+                    cy.get("[data-cy=process-logs] pre").eq(8).should("contain", "2023-07-18T20:14:48.128642814Z X out 3");
+                    cy.get("[data-cy=process-logs] pre").eq(9).should("contain", "2023-07-18T20:14:48.128642814Z A out 4");
+                });
+            });
+        });
+
         it("correctly generates sniplines", function () {
             const SNIPLINE = `================ ✀ ================ ✀ ========= Some log(s) were skipped ========= ✀ ================ ✀ ================`;
             const crName = "test_container_request";

diff --git a/src/store/process-logs-panel/process-logs-panel-actions.ts b/src/store/process-logs-panel/process-logs-panel-actions.ts
index 4e52431eebadc9a05b240ee530cd29e3390569e4..88b56a2c324379c2b9be44c859da7ad9e05eb28e 100644 (file)
--- a/src/store/process-logs-panel/process-logs-panel-actions.ts
+++ b/src/store/process-logs-panel/process-logs-panel-actions.ts
@@ -33,6 +33,12 @@ type FileWithProgress = {
     lastByte: number;
 }
 
+type SortableLine = {
+    logType: LogEventType,
+    timestamp: string;
+    contents: string;
+}
+
 export type ProcessLogsPanelAction = UnionOf<typeof processLogsPanelActions>;
 
 export const setProcessLogsPanelFilter = (filter: string) =>
@@ -257,18 +263,61 @@ const mergeMultilineLoglines = (logFragments: LogFragment[]) => (
  * @returns string[] of merged and sorted log lines
  */
 const mergeSortLogFragments = (logFragments: LogFragment[]): string[] => {
-    const sortableLines = fragmentsToLines(logFragments
-        .filter((fragment) => (!NON_SORTED_LOG_TYPES.includes(fragment.logType))));
+    const sortableFragments = logFragments
+        .filter((fragment) => (!NON_SORTED_LOG_TYPES.includes(fragment.logType)));
 
     const nonSortableLines = fragmentsToLines(logFragments
         .filter((fragment) => (NON_SORTED_LOG_TYPES.includes(fragment.logType)))
         .sort((a, b) => (a.logType.localeCompare(b.logType))));
 
-    return [...nonSortableLines, ...sortableLines.sort(sortLogLines)]
+    return [...nonSortableLines, ...sortLogFragments(sortableFragments)];
 };
 
-const sortLogLines = (a: string, b: string) => {
-    return a.localeCompare(b);
+/**
+ * Performs merge and sort of input log fragment lines
+ * @param logFragments set of sortable log fragments to be merged and sorted
+ * @returns A string array containing all lines, sorted by timestamp and
+ *          preserving line ordering and type grouping when timestamps match
+ */
+const sortLogFragments = (logFragments: LogFragment[]): string[] => {
+    const linesWithType: SortableLine[] = logFragments
+        // Map each logFragment into an array of SortableLine
+        .map((fragment: LogFragment): SortableLine[] => (
+            fragment.contents.map((singleLine: string) => {
+                const timestampMatch = singleLine.match(LOG_TIMESTAMP_PATTERN);
+                const timestamp = timestampMatch && timestampMatch[0] ? timestampMatch[0] : "";
+                return {
+                    logType: fragment.logType,
+                    timestamp: timestamp,
+                    contents: singleLine,
+                };
+            })
+        // Merge each array of SortableLine into single array
+        )).reduce((acc: SortableLine[], lines: SortableLine[]) => (
+            [...acc, ...lines]
+        ), [] as SortableLine[]);
+
+    return linesWithType
+        .sort(sortableLineSortFunc)
+        .map(lineWithType => lineWithType.contents);
+};
+
+/**
+ * Sort func to sort lines
+ *   Preserves original ordering of lines from the same source
+ *   Stably orders lines of differing type but same timestamp
+ *     (produces a block of same-timestamped lines of one type before a block
+ *     of same timestamped lines of another type for readability)
+ *   Sorts all other lines by contents (ie by timestamp)
+ */
+const sortableLineSortFunc = (a: SortableLine, b: SortableLine) => {
+    if (a.logType === b.logType) {
+        return 0;
+    } else if (a.timestamp === b.timestamp) {
+        return a.logType.localeCompare(b.logType);
+    } else {
+        return a.contents.localeCompare(b.contents);
+    }
 };
 
 const fragmentsToLines = (fragments: LogFragment[]): string[] => (