From 981acc654db00435bf73ad7ac9a24a2ce56ca883 Mon Sep 17 00:00:00 2001 From: Walter Leibbrandt <23798+walterl@users.noreply.github.com> Date: Mon, 12 Aug 2019 21:00:37 +0200 Subject: [PATCH] Transfer log events as JSON objects and allow filtering on front-end (#10522) * Return log events as JSON objects from API; render on front-end Site UUID added to log events. * Remove superfluous memoization of site UUID retrieval Settings are already cached. * Transfer timestamps in ISO-8601 format * Move `metabase.metabot.instance/local-process-uuid` to `metabase.public-settings` * Use `local-process-uuid` in stead of `site-uuid` `site-uuid` is not unique across processes, which is what we want to associate with log events. * Remove unused import * Allow log events to be filtered by process UUID on front-end * Move process selector out of loading wrapper Otherwise, if there are process UUIDs with no log events, the selector is removed with the log event list. * Figured out how to add docs to `defonce` * Fix ns declaration * Linter appeasement * Merge log events received from back-end with previously received ones This allows responses from multiple back-end instances to be spliced together. * Use MB components in stead of plain, styled HTML tags The select is only displayed if more than one process UUID was found. * Linter appeasement * Move `metabase.public-settings/local-process-uuid` to `metabase.config` * Fix sorting on multiple log event fields * Flatten `Select` children to allow nested arrays of children * Generate options directly under parent Select * Limit the number of log events that we render * Docstring and style updates * Update editor config with Clojure files max line length * Ensure that `NumericWrapper` is imported before use * Cleanup layout --- .editorconfig | 1 + .../metabase/admin/tasks/containers/Logs.jsx | 100 +++++++++++++++--- frontend/src/metabase/components/Select.jsx | 2 +- src/metabase/config.clj | 9 +- src/metabase/logger.clj | 28 ++--- src/metabase/metabot/instance.clj | 22 ++-- src/metabase/pulse/render/table.clj | 8 +- 7 files changed, 118 insertions(+), 52 deletions(-) diff --git a/.editorconfig b/.editorconfig index 83ff3366d4e..b2ab82eb6af 100644 --- a/.editorconfig +++ b/.editorconfig @@ -16,6 +16,7 @@ indent_style = tab [*.clj] indent_size = 2 +max_line_length = 120 [*.css] indent_size = 2 diff --git a/frontend/src/metabase/admin/tasks/containers/Logs.jsx b/frontend/src/metabase/admin/tasks/containers/Logs.jsx index 9277d99d3c4..247779c9ad3 100644 --- a/frontend/src/metabase/admin/tasks/containers/Logs.jsx +++ b/frontend/src/metabase/admin/tasks/containers/Logs.jsx @@ -9,7 +9,10 @@ import reactAnsiStyle from "react-ansi-style"; import "react-ansi-style/inject-css"; import _ from "underscore"; +import moment from "moment"; +import { t } from "ttag"; +import Select, { Option } from "metabase/components/Select"; import { addCSSRule } from "metabase/lib/dom"; import colors from "metabase/lib/colors"; @@ -27,6 +30,22 @@ const ANSI_COLORS = { for (const [name, color] of Object.entries(ANSI_COLORS)) { addCSSRule(`.react-ansi-style-${name}`, `color: ${color} !important`); } +const MAX_LOGS = 50000; + +function logEventKey(ev) { + return `${ev.timestamp}, ${ev.process_uuid}, ${ev.fqns}, ${ev.msg}`; +} + +function mergeLogs(...logArrays) { + 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(); +} export default class Logs extends Component { constructor() { @@ -34,6 +53,7 @@ export default class Logs extends Component { this.state = { logs: [], scrollToBottom: true, + selectedProcessUUID: "ALL", }; this._onScroll = () => { @@ -52,7 +72,7 @@ export default class Logs extends Component { async fetchLogs() { const logs = await UtilApi.logs(); - this.setState({ logs: logs.reverse() }); + this.setState({ logs: mergeLogs(this.state.logs, logs.reverse()) }); } componentWillMount() { @@ -80,23 +100,69 @@ export default class Logs extends Component { } render() { - const { logs } = this.state; - return ( - <LoadingAndErrorWrapper loading={!logs || logs.length === 0}> - {() => ( - <div - className="rounded bordered bg-light" - style={{ - fontFamily: '"Lucida Console", Monaco, monospace', - fontSize: "14px", - whiteSpace: "pre-line", - padding: "1em", - }} + const { logs, selectedProcessUUID } = 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.map(ev => { + const timestamp = moment(ev.timestamp).format(); + const uuid = ev.process_uuid || "---"; + return `[${uuid}] ${timestamp} ${ev.level} ${ev.fqns} ${ev.msg}`; + }); + + let processUUIDSelect = null; + if (processUUIDs.length > 1) { + processUUIDSelect = ( + <div className="pb1"> + <label>{t`Select Metabase process:`}</label> + <Select + defaultValue="ALL" + value={this.state.selectedProcessUUID} + onChange={e => + this.setState({ selectedProcessUUID: e.target.value }) + } + className="inline-block ml1" + width={400} > - {reactAnsiStyle(React, logs.join("\n"))} - </div> - )} - </LoadingAndErrorWrapper> + <Option value="ALL" key="ALL">{t`All Metabase processes`}</Option> + {processUUIDs.map(uuid => ( + <Option key={uuid} value={uuid}> + <code>{uuid}</code> + </Option> + ))} + </Select> + </div> + ); + } + + return ( + <div> + {processUUIDSelect} + + <LoadingAndErrorWrapper + loading={!filteredLogs || filteredLogs.length === 0} + > + {() => ( + <div + className="rounded bordered bg-light" + style={{ + fontFamily: '"Lucida Console", Monaco, monospace', + fontSize: "14px", + whiteSpace: "pre-line", + padding: "1em", + }} + > + {reactAnsiStyle(React, renderedLogs.join("\n"))} + </div> + )} + </LoadingAndErrorWrapper> + </div> ); } } diff --git a/frontend/src/metabase/components/Select.jsx b/frontend/src/metabase/components/Select.jsx index 8c25a4cea80..6cd29e5a1df 100644 --- a/frontend/src/metabase/components/Select.jsx +++ b/frontend/src/metabase/components/Select.jsx @@ -97,7 +97,7 @@ class BrowserSelect extends Component { multiple, } = this.props; - let children = this.props.children; + let children = _.flatten(this.props.children); let selectedNames = children .filter(child => this.isSelected(child.props.value)) diff --git a/src/metabase/config.clj b/src/metabase/config.clj index 79680006622..09f33eff7e9 100644 --- a/src/metabase/config.clj +++ b/src/metabase/config.clj @@ -5,7 +5,8 @@ [clojure.string :as str] [environ.core :as environ] [metabase.plugins.classloader :as classloader]) - (:import clojure.lang.Keyword)) + (:import clojure.lang.Keyword + java.util.UUID)) (def ^Boolean is-windows? "Are we running on a Windows machine?" @@ -101,6 +102,12 @@ Looks something like `Metabase v0.25.0.RC1`." (str "Metabase " (mb-version-info :tag))) +(defonce ^{:doc "This UUID is randomly-generated upon launch and used to identify this specific Metabase instance during + this specifc run. Restarting the server will change this UUID, and each server in a horizontal cluster + will have its own ID, making this different from the `site-uuid` Setting."} + local-process-uuid + (str (UUID/randomUUID))) + ;; This only affects dev: ;; diff --git a/src/metabase/logger.clj b/src/metabase/logger.clj index 70cb740d4f3..8accfc1d065 100644 --- a/src/metabase/logger.clj +++ b/src/metabase/logger.clj @@ -2,9 +2,8 @@ (:require [amalloy.ring-buffer :refer [ring-buffer]] [clj-time [coerce :as coerce] - [core :as t] [format :as time]] - [clojure.string :as str]) + [metabase.config :refer [local-process-uuid]]) (:import [org.apache.log4j Appender AppenderSkeleton Logger] org.apache.log4j.spi.LoggingEvent)) @@ -17,26 +16,19 @@ [] (reverse (seq @messages*))) -(defonce ^:private formatter (time/formatter "MMM dd HH:mm:ss" (t/default-time-zone))) - -(defn- event->log-string [^LoggingEvent event] - ;; for messages that include an Exception, include the string representation of it (i.e., its stacktrace) - ;; separated by newlines - (str/join - "\n" - (cons - (let [ts (time/unparse formatter (coerce/from-long (.getTimeStamp event))) - level (.getLevel event) - fqns (.getLoggerName event) - msg (.getMessage event)] - (format "%s \033[1m%s %s\033[0m :: %s" ts level fqns msg)) - (seq (.getThrowableStrRep event))))) - +(defn- event->log-data [^LoggingEvent event] + {:timestamp (time/unparse (time/formatter :date-time) + (coerce/from-long (.getTimeStamp event))) + :level (.getLevel event) + :fqns (.getLoggerName event) + :msg (.getMessage event) + :exception (.getThrowableStrRep event) + :process_uuid local-process-uuid}) (defn- metabase-appender ^Appender [] (proxy [AppenderSkeleton] [] (append [event] - (swap! messages* conj (event->log-string event)) + (swap! messages* conj (event->log-data event)) nil) (close [] nil) diff --git a/src/metabase/metabot/instance.clj b/src/metabase/metabot/instance.clj index 0b802a4e9de..57bf42fa836 100644 --- a/src/metabase/metabot/instance.clj +++ b/src/metabase/metabot/instance.clj @@ -14,26 +14,22 @@ How do we uniquiely identify each instance? - `local-process-uuid` is randomly-generated upon launch and used to identify this specific Metabase instance during - this specifc run. Restarting the server will change this UUID, and each server in a hortizontal cluster will have - its own ID, making this different from the `site-uuid` Setting. The local process UUID is used to differentiate - different horizontally clustered MB instances so we can determine which of them will handle MetaBot duties. - - TODO - if we ever want to use this elsewhere, we need to move it to `metabase.config` or somewhere else central like - that." + `metabase.public-settings/local-process-uuid` is randomly-generated upon launch and used to identify this specific + Metabase instance during this specifc run. Restarting the server will change this UUID, and each server in a + hortizontal cluster will have its own ID, making this different from the `site-uuid` Setting. The local process UUID + is used to differentiate different horizontally clustered MB instances so we can determine which of them will handle + MetaBot duties." (:require [clojure.tools.logging :as log] [honeysql.core :as hsql] + [metabase + [config :refer [local-process-uuid]] + [util :as u]] [metabase.models.setting :as setting :refer [defsetting]] - [metabase.util :as u] [metabase.util [date :as du] [i18n :refer [trs]]] [toucan.db :as db]) - (:import java.sql.Timestamp - java.util.UUID)) - -(defonce ^:private local-process-uuid - (str (UUID/randomUUID))) + (:import java.sql.Timestamp)) (defsetting ^:private metabot-instance-uuid "UUID of the active MetaBot instance (the Metabase process currently handling MetaBot duties.)" diff --git a/src/metabase/pulse/render/table.clj b/src/metabase/pulse/render/table.clj index 99ab03aa109..aa33bf6c036 100644 --- a/src/metabase/pulse/render/table.clj +++ b/src/metabase/pulse/render/table.clj @@ -4,8 +4,12 @@ [metabase.pulse.render [color :as color] [style :as style]]) - (:import jdk.nashorn.api.scripting.JSObject - metabase.pulse.render.common.NumericWrapper)) + (:import jdk.nashorn.api.scripting.JSObject)) + +;; Our 'helpful' NS declaration linter will complain that common is unused. But we need to require it so +;; NumericWrapper exists in the first place. +(require 'metabase.pulse.render.common) +(import 'metabase.pulse.render.common.NumericWrapper) (defn- bar-th-style [] (merge (style/font-style) {:font-size :14.22px -- GitLab