diff --git a/frontend/src/metabase-types/api/admin.ts b/frontend/src/metabase-types/api/admin.ts
index 251b4fc35720bc1a23e33289e7e7b0f53f07b858..42e674fe776a093826b52e681ba43b0cf29a110e 100644
--- a/frontend/src/metabase-types/api/admin.ts
+++ b/frontend/src/metabase-types/api/admin.ts
@@ -16,7 +16,7 @@ export type ApiKey = {
};
export interface Log {
- timestamp: number;
+ timestamp: string;
process_uuid: string;
fqns: string;
msg: string;
diff --git a/frontend/src/metabase/admin/tasks/components/Logs/Logs.styled.tsx b/frontend/src/metabase/admin/tasks/components/Logs/Logs.styled.tsx
index 38472ce1b3793a5282bb6f8af72886b31dbe33dd..e0a4ae14b3f255aea69dfef5b5e7af581c85d152 100644
--- a/frontend/src/metabase/admin/tasks/components/Logs/Logs.styled.tsx
+++ b/frontend/src/metabase/admin/tasks/components/Logs/Logs.styled.tsx
@@ -21,6 +21,8 @@ const LOG_COLORS = {
export const LogsContainer = styled(LoadingAndErrorWrapper)`
height: 100%;
padding-left: 1rem;
+ display: flex;
+ flex-direction: column;
`;
export const LogsContent = styled.div`
diff --git a/frontend/src/metabase/admin/tasks/components/Logs/Logs.tsx b/frontend/src/metabase/admin/tasks/components/Logs/Logs.tsx
index eb2a5a18a65f0a4667e8b72f3dcc7347c49387f0..a9c009bcc4cb815509782c6ca9fac25a2a048e90 100644
--- a/frontend/src/metabase/admin/tasks/components/Logs/Logs.tsx
+++ b/frontend/src/metabase/admin/tasks/components/Logs/Logs.tsx
@@ -1,165 +1,68 @@
-import moment from "moment-timezone"; // eslint-disable-line no-restricted-imports -- deprecated usage
-import { Component } from "react";
+import { useState, useMemo } from "react";
import * as React from "react";
import reactAnsiStyle from "react-ansi-style";
import { t } from "ttag";
import _ from "underscore";
import Select, { Option } from "metabase/core/components/Select";
-import { UtilApi } from "metabase/services";
-import type { Log } from "metabase-types/api";
import { LogsContainer, LogsContent } from "./Logs.styled";
-
-const MAX_LOGS = 50000;
-
-function logEventKey(ev: Log) {
- return `${ev.timestamp}, ${ev.process_uuid}, ${ev.fqns}, ${ev.msg}`;
+import { usePollingLogsQuery, useTailLogs } from "./hooks";
+import { filterLogs, formatLog, getAllProcessUUIDs } from "./utils";
+
+interface LogsProps {
+ // NOTE: fetching logs could come back from any machine if there's multiple machines backing a MB isntance
+ // make this frequent enough that you will most likely get every log from every machine in some reasonable
+ // amount of time
+ pollingDurationMs?: number;
}
-function mergeLogs(...logArrays: Log[] | Log[][]) {
- return _.chain(logArrays)
- .flatten(true)
- .sortBy(ev => ev.msg)
- .sortBy(ev => ev.process_uuid)
- .sortBy(ev => ev.timestamp)
- .uniq(true, logEventKey)
- .last(MAX_LOGS)
- .value();
-}
-
-type LogsProps = Record<string, never>;
-
-interface LogsState {
- loaded: boolean;
- error: string | null;
- logs: Log[];
- selectedProcessUUID: string;
-}
-
-export class Logs extends Component<LogsProps, LogsState> {
- constructor(props: LogsProps) {
- super(props);
- this.state = {
- loaded: false,
- error: null,
- logs: [],
- selectedProcessUUID: "ALL",
- };
- }
-
- timer: NodeJS.Timeout | null = null;
- scrollRef: React.RefObject<HTMLDivElement> = React.createRef();
- unmounted = false;
- shouldTail = true;
-
- componentDidMount() {
- this.fetchLogs();
- this.timer = setInterval(this.fetchLogs, 1000);
- }
-
- componentWillUnmount() {
- this.unmounted = true;
- if (this.timer) {
- clearInterval(this.timer);
- }
- }
-
- fetchLogs = async () => {
- try {
- const logs = await UtilApi.logs();
- if (!this.unmounted) {
- this.setState({
- loaded: true,
- logs: mergeLogs(this.state.logs, logs.reverse()),
- });
- this.maybeTail();
- }
- } catch (err: any) {
- console.error(err);
- const msg = err?.data?.message ?? err.messsage ?? t`An error occurred.`;
- !this.unmounted && this.setState({ error: msg });
- }
- };
-
- _onScroll = () => {
- const elem = this.scrollRef.current;
- if (elem) {
- this.shouldTail = elem.scrollTop >= elem.scrollHeight - elem.offsetHeight;
- }
- };
-
- maybeTail = () => {
- const elem = this.scrollRef.current;
- if (this.shouldTail && elem) {
- elem.scrollTop = elem.scrollHeight;
- }
- };
-
- render() {
- const { logs, selectedProcessUUID, error, loaded } = this.state;
- const filteredLogs = logs.filter(
- ev =>
- !selectedProcessUUID ||
- selectedProcessUUID === "ALL" ||
- ev.process_uuid === selectedProcessUUID,
- );
- const processUUIDs = _.uniq(
- logs.map(ev => ev.process_uuid).filter(Boolean),
- ).sort();
- const renderedLogs = filteredLogs.flatMap(ev => {
- const timestamp = moment(ev.timestamp).format();
- const uuid = ev.process_uuid || "---";
- return [
- `[${uuid}] ${timestamp} ${ev.level} ${ev.fqns} ${ev.msg}`,
- ...(ev.exception || []),
- ];
- });
-
- const noResults = !filteredLogs || filteredLogs.length === 0;
- const resultText = noResults
+export const Logs = ({ pollingDurationMs = 1000 }: LogsProps) => {
+ const [selectedProcessUUID, setSelectedProcessUUID] = useState("ALL");
+ const { loaded, error, logs } = usePollingLogsQuery(pollingDurationMs);
+ const processUUIDs = useMemo(() => getAllProcessUUIDs(logs), [logs]);
+ const filteredLogs = useMemo(
+ () => filterLogs(logs, selectedProcessUUID),
+ [logs, selectedProcessUUID],
+ );
+ const { scrollRef, onScroll, refollow } = useTailLogs(filteredLogs);
+
+ const displayLogs = useMemo(() => {
+ const noResults = filteredLogs.length === 0;
+ const logText = noResults
? t`There's nothing here, yet.`
- : renderedLogs.join("\n");
-
- return (
- <LogsContainer loading={!loaded} error={error}>
- {() => (
- <>
- {processUUIDs.length > 1 && (
- <div className="pb1">
- <label>{t`Select Metabase process:`}</label>
- <Select
- defaultValue="ALL"
- value={this.state.selectedProcessUUID}
- onChange={(e: { target: { value: string } }) =>
- this.setState({ selectedProcessUUID: e.target.value })
- }
- className="inline-block ml1"
- width={400}
- >
- <Option
- value="ALL"
- key="ALL"
- >{t`All Metabase processes`}</Option>
- {processUUIDs.map(uuid => (
- <Option key={uuid} value={uuid}>
- <code>{uuid}</code>
- </Option>
- ))}
- </Select>
- </div>
- )}
-
- <LogsContent
- id="logs-content"
- ref={this.scrollRef}
- onScroll={this._onScroll}
- >
- {reactAnsiStyle(React, resultText)}
- </LogsContent>
- </>
- )}
- </LogsContainer>
- );
- }
-}
+ : filteredLogs.map(formatLog).join("\n");
+ return reactAnsiStyle(React, logText);
+ }, [filteredLogs]);
+
+ return (
+ <LogsContainer loading={!loaded} error={error}>
+ {processUUIDs.length > 1 && (
+ <div className="pb1">
+ <label>{t`Select Metabase process:`}</label>
+ <Select
+ defaultValue="ALL"
+ value={selectedProcessUUID}
+ onChange={(e: { target: { value: string } }) => {
+ refollow();
+ setSelectedProcessUUID(e.target.value);
+ }}
+ className="inline-block ml1"
+ width={400}
+ >
+ <Option value="ALL" key="ALL">{t`All Metabase processes`}</Option>
+ {processUUIDs.map(uuid => (
+ <Option key={uuid} value={uuid}>
+ <code>{uuid}</code>
+ </Option>
+ ))}
+ </Select>
+ </div>
+ )}
+
+ <LogsContent id="logs-content" ref={scrollRef} onScroll={onScroll}>
+ {displayLogs}
+ </LogsContent>
+ </LogsContainer>
+ );
+};
diff --git a/frontend/src/metabase/admin/tasks/components/Logs/Logs.unit.spec.tsx b/frontend/src/metabase/admin/tasks/components/Logs/Logs.unit.spec.tsx
index b805b23e3873998d8832a17b82f6e2825b76f2d6..5dc45a5026ca146941a8d0165936f8ea992656da 100644
--- a/frontend/src/metabase/admin/tasks/components/Logs/Logs.unit.spec.tsx
+++ b/frontend/src/metabase/admin/tasks/components/Logs/Logs.unit.spec.tsx
@@ -1,15 +1,37 @@
-import { render, screen, waitFor } from "@testing-library/react";
+import { act, render, screen, waitFor } from "@testing-library/react";
import fetchMock from "fetch-mock";
import { UtilApi } from "metabase/services";
import { Logs } from "./Logs";
+import { maybeMergeLogs } from "./utils";
+
+const log = {
+ timestamp: "2024-01-10T21:21:58.597Z",
+ level: "DEBUG",
+ fqns: "metabase.server.middleware.log",
+ msg: "\u001B[32mGET /api/collection/root 200 17.6 ms (2 DB calls) App DB connections: 0/7 Jetty threads: 7/50 (1 idle, 0 queued) (42 total active threads) Queries in flight: 0 (0 queued)\u001B[0m",
+ exception: null,
+ process_uuid: "e7774ef2-42ab-43de-89f7-d6de9fdc624f",
+};
+
+let utilSpy: any;
describe("Logs", () => {
describe("log fetching", () => {
+ beforeEach(() => {
+ utilSpy = jest.spyOn(UtilApi, "logs");
+ jest.useFakeTimers({ advanceTimers: true });
+ });
+
+ afterEach(() => {
+ utilSpy.mockClear();
+ fetchMock.restore();
+ jest.useRealTimers();
+ });
+
it("should call UtilApi.logs every 1 second", async () => {
fetchMock.get("path:/api/util/logs", []);
- const utilSpy = jest.spyOn(UtilApi, "logs");
render(<Logs />);
await waitFor(() => [
expect(screen.getByTestId("loading-spinner")).toBeInTheDocument(),
@@ -17,6 +39,33 @@ describe("Logs", () => {
]);
});
+ it("should skip calls to UtilsApi.logs if last request is still in-flight", async () => {
+ fetchMock.get("path:/api/util/logs", []);
+ let resolve: any;
+ utilSpy.mockReturnValueOnce(new Promise(res => (resolve = res)));
+ render(<Logs />);
+ await waitFor(() => [
+ expect(screen.getByTestId("loading-spinner")).toBeInTheDocument(),
+ expect(utilSpy).toHaveBeenCalledTimes(1),
+ ]);
+ act(() => {
+ jest.advanceTimersByTime(1100); // wait longer than polling period
+ });
+ expect(utilSpy).toHaveBeenCalledTimes(1); // should not have been called
+ act(() => {
+ resolve([log]);
+ });
+ await waitFor(() => {
+ expect(
+ screen.getByText(new RegExp(log.process_uuid)),
+ ).toBeInTheDocument();
+ });
+ act(() => {
+ jest.advanceTimersByTime(1100);
+ });
+ expect(utilSpy).toHaveBeenCalledTimes(2); // should have issued new request
+ });
+
it("should display no results if there are no logs", async () => {
fetchMock.get("path:/api/util/logs", []);
render(<Logs />);
@@ -28,14 +77,6 @@ describe("Logs", () => {
});
it("should display results if server responds with logs", async () => {
- const log = {
- timestamp: "2024-01-10T21:21:58.597Z",
- level: "DEBUG",
- fqns: "metabase.server.middleware.log",
- msg: "\u001B[32mGET /api/collection/root 200 17.6 ms (2 DB calls) App DB connections: 0/7 Jetty threads: 7/50 (1 idle, 0 queued) (42 total active threads) Queries in flight: 0 (0 queued)\u001B[0m",
- exception: null,
- process_uuid: "e7774ef2-42ab-43de-89f7-d6de9fdc624f",
- };
fetchMock.get("path:/api/util/logs", [log]);
render(<Logs />);
await waitFor(() => {
@@ -57,4 +98,16 @@ describe("Logs", () => {
});
});
});
+
+ describe("log processing", () => {
+ it("should skip updates if fetched logs match match previously requested logs", async () => {
+ const originalLogs = [log];
+ const shouldNotBeMerged = maybeMergeLogs(originalLogs, [log]);
+ expect(shouldNotBeMerged).toBe(originalLogs);
+ const shoudlBeMerged = maybeMergeLogs(originalLogs, [
+ { ...log, msg: "different" },
+ ]);
+ expect(shoudlBeMerged).not.toBe(originalLogs);
+ });
+ });
});
diff --git a/frontend/src/metabase/admin/tasks/components/Logs/hooks.ts b/frontend/src/metabase/admin/tasks/components/Logs/hooks.ts
new file mode 100644
index 0000000000000000000000000000000000000000..f811a35cd2b572e9c4af86fb1e8481ca1e94aeba
--- /dev/null
+++ b/frontend/src/metabase/admin/tasks/components/Logs/hooks.ts
@@ -0,0 +1,100 @@
+import { useInterval } from "@mantine/hooks";
+import { useState, useEffect, useRef, useCallback } from "react";
+import { useMount } from "react-use";
+import { t } from "ttag";
+import _ from "underscore";
+
+import { UtilApi } from "metabase/services";
+import type { Log } from "metabase-types/api";
+
+import { maybeMergeLogs } from "./utils";
+
+export function usePollingLogsQuery(pollingDurationMs: number) {
+ const [loaded, setLoaded] = useState(false);
+ const [error, setError] = useState<any>(null);
+ const [logs, setLogs] = useState<Log[]>([]);
+
+ const isMountedRef = useRef(false);
+ const isFetchingRef = useRef(false);
+
+ const fetchLogs = async () => {
+ if (isFetchingRef.current) {
+ console.warn("skipping logs request as a request is currently in flight");
+ return;
+ }
+
+ try {
+ isFetchingRef.current = true;
+ const newLogs: Log[] = await UtilApi.logs();
+ if (isMountedRef.current) {
+ setLoaded(true);
+ setError(null);
+ setLogs(logs => maybeMergeLogs(logs, newLogs));
+ isFetchingRef.current = false;
+ }
+ } catch (err: any) {
+ console.error(err);
+ const msg = err?.data?.message ?? err.messsage ?? t`An error occurred.`;
+ if (isMountedRef.current) {
+ setError(msg);
+ isFetchingRef.current = false;
+ }
+ }
+ };
+
+ const pollingInterval = useInterval(fetchLogs, pollingDurationMs);
+
+ // keep track of mounted state to avoid settings state after unmount
+ // clear timeout that is polling for logs
+ useMount(() => {
+ isMountedRef.current = true;
+ fetchLogs();
+ pollingInterval.start();
+ return () => {
+ isMountedRef.current = false;
+ pollingInterval.stop();
+ };
+ });
+
+ return { loaded, error, logs };
+}
+
+export function useTailLogs(logs: Log[]) {
+ const scrollRef = useRef<any>();
+ const shouldAutoFollow = useRef(true);
+
+ function autoFollow() {
+ const elem = scrollRef.current;
+ if (elem && shouldAutoFollow.current) {
+ elem.scrollTop = elem.scrollHeight;
+ }
+ }
+
+ // auto-follow logs on update
+ useEffect(() => {
+ if (logs.length) {
+ autoFollow();
+ }
+ }, [logs]);
+
+ // recalculate if we should be auto-following based on if the
+ // user is currently scrolled to the bottom of the container
+ const onScroll = useCallback(() => {
+ const elem = scrollRef.current;
+ if (elem) {
+ const isAtBottom =
+ elem.scrollTop >= elem.scrollHeight - elem.offsetHeight;
+ shouldAutoFollow.current = isAtBottom;
+ }
+ }, []);
+
+ const refollow = () => {
+ shouldAutoFollow.current = true;
+ };
+
+ return {
+ scrollRef,
+ onScroll,
+ refollow,
+ };
+}
diff --git a/frontend/src/metabase/admin/tasks/components/Logs/utils.ts b/frontend/src/metabase/admin/tasks/components/Logs/utils.ts
new file mode 100644
index 0000000000000000000000000000000000000000..9923570acc48a8bcf08ad53b91267c9ed7a00d50
--- /dev/null
+++ b/frontend/src/metabase/admin/tasks/components/Logs/utils.ts
@@ -0,0 +1,69 @@
+import dayjs from "dayjs";
+import orderBy from "lodash.orderby";
+import _ from "underscore";
+
+import type { Log } from "metabase-types/api";
+
+const MAX_LOGS = 50000;
+
+function logEventKey(ev: Log) {
+ return `${ev.timestamp}, ${ev.process_uuid}, ${ev.fqns}, ${ev.msg}`;
+}
+
+export function mergeLogs(logArrays: Log[][]) {
+ let prevLogKey = "";
+ return orderBy(
+ logArrays.flat(),
+ ["timestamp", "process_uuid", "msg"],
+ ["asc", "asc", "asc"],
+ )
+ .filter(log => {
+ const key = logEventKey(log);
+ const keep = prevLogKey !== key;
+ if (keep) {
+ prevLogKey = key;
+ }
+ return keep;
+ })
+ .slice(-1 * MAX_LOGS);
+}
+
+export function maybeMergeLogs(logs: Log[], newLogs: Log[]) {
+ const newestLog = _.first(newLogs);
+ const hasFetchedNewLogs = newestLog && !hasLog(logs, newestLog);
+ if (hasFetchedNewLogs) {
+ return mergeLogs([logs, newLogs.reverse()]);
+ }
+ return logs;
+}
+
+export function hasLog(logs: Log[], targetLog: Log): boolean {
+ // search from back as newer logs are last
+ return _.findLastIndex(logs, targetLog) > -1;
+}
+
+export function filterLogs(logs: Log[], processUUID: string) {
+ return logs.filter(
+ ev =>
+ !processUUID || processUUID === "ALL" || ev.process_uuid === processUUID,
+ );
+}
+
+export function getAllProcessUUIDs(logs: Log[]) {
+ const uuids = new Set<string>();
+ logs.forEach(log => uuids.add(log.process_uuid));
+ return [...uuids].filter(Boolean).sort();
+}
+
+// date formatting is expensive for megabytes of logs
+const formatTs = (ts: string) => dayjs(ts).format();
+const memoedFormatTs = _.memoize(formatTs);
+
+export function formatLog(log: Log) {
+ const timestamp = memoedFormatTs(log.timestamp);
+ const uuid = log.process_uuid || "---";
+ return [
+ `[${uuid}] ${timestamp} ${log.level} ${log.fqns} ${log.msg}`,
+ ...(log.exception || []),
+ ];
+}
diff --git a/package.json b/package.json
index 9e592952818b4c7f271512dfbb75f92248157461..1422e0fe1aeed91db0a1d80c12162335ad25b5fe 100644
--- a/package.json
+++ b/package.json
@@ -67,6 +67,7 @@
"leaflet-draw": "^0.4.9",
"leaflet.heat": "^0.2.0",
"lodash.debounce": "^4.0.8",
+ "lodash.orderby": "^4.6.0",
"moment-timezone": "^0.5.38",
"mustache": "^2.3.2",
"normalizr": "^3.0.2",
@@ -183,6 +184,7 @@
"@types/leaflet.heat": "^0.2.1",
"@types/lodash.clonedeep": "^4.5.9",
"@types/lodash.debounce": "^4.0.9",
+ "@types/lodash.orderby": "^4.6.9",
"@types/mustache": "^4.1.2",
"@types/postcss-import": "^12.0.1",
"@types/postcss-url": "^8.0.2",
diff --git a/yarn.lock b/yarn.lock
index 6bd06c20ddff4e99843d36823f9d5b0e64c64efd..7f1565ab9204d02987792b93e3cdc63cedd2be78 100644
--- a/yarn.lock
+++ b/yarn.lock
@@ -4792,6 +4792,13 @@
dependencies:
"@types/lodash" "*"
+"@types/lodash.orderby@^4.6.9":
+ version "4.6.9"
+ resolved "https://registry.yarnpkg.com/@types/lodash.orderby/-/lodash.orderby-4.6.9.tgz#3b1968ad257016690b1b9479ba4079208a97ee5f"
+ integrity sha512-T9o2wkIJOmxXwVTPTmwJ59W6eTi2FseiLR369fxszG649Po/xe9vqFNhf/MtnvT5jrbDiyWKxPFPZbpSVK0SVQ==
+ dependencies:
+ "@types/lodash" "*"
+
"@types/lodash@*":
version "4.14.202"
resolved "https://registry.yarnpkg.com/@types/lodash/-/lodash-4.14.202.tgz#f09dbd2fb082d507178b2f2a5c7e74bd72ff98f8"
@@ -14832,6 +14839,11 @@ lodash.once@^4.1.1:
resolved "https://registry.yarnpkg.com/lodash.once/-/lodash.once-4.1.1.tgz#0dd3971213c7c56df880977d504c88fb471a97ac"
integrity sha512-Sb487aTOCr9drQVL8pIxOzVhafOjZN9UU54hiN8PU3uAiSV7lx1yYNpbNmex2PK6dSJoNTSJUUswT651yww3Mg==
+lodash.orderby@^4.6.0:
+ version "4.6.0"
+ resolved "https://registry.yarnpkg.com/lodash.orderby/-/lodash.orderby-4.6.0.tgz#e697f04ce5d78522f54d9338b32b81a3393e4eb3"
+ integrity sha512-T0rZxKmghOOf5YPnn8EY5iLYeWCpZq8G41FfqoVHH5QDTAFaghJRmAdLiadEDq+ztgM2q5PjA+Z1fOwGrLgmtg==
+
lodash.sortby@^4.7.0:
version "4.7.0"
resolved "https://registry.yarnpkg.com/lodash.sortby/-/lodash.sortby-4.7.0.tgz#edd14c824e2cc9c1e0b0a1b42bb5210516a42438"