Merge pull request #2468 from metabase/in-app-logs

In-app logs

frontend/src/components/Logs.jsx

+import React, { Component, PropTypes } from "react";
+import ReactDOM from "react-dom";
+
+import LoadingAndErrorWrapper from "metabase/components/LoadingAndErrorWrapper.jsx";
+
+import reactAnsiStyle from "react-ansi-style";
+import "react-ansi-style/inject-css";
+
+import _ from "underscore";
+
+export default class Logs extends Component {
+    constructor(props, context) {
+        super(props, context);
+        this.state = {
+            logs: [],
+            scrollToBottom: true
+        };
+
+        this._onScroll = () => {
+            this.scrolling = true;
+            this._onScrollDebounced();
+        }
+        this._onScrollDebounced = _.debounce(() => {
+            let elem = ReactDOM.findDOMNode(this).parentNode;
+            let scrollToBottom = Math.abs(elem.scrollTop - (elem.scrollHeight - elem.offsetHeight)) < 10;
+            this.setState({ scrollToBottom }, () => {
+                this.scrolling = false;
+            });
+        }, 500);
+    }
+
+    componentWillMount() {
+        this.timer = setInterval(async () => {
+            let response = await fetch("/api/util/logs", { credentials: 'same-origin' });
+            let logs = await response.json()
+            this.setState({ logs: logs.reverse() })
+        }, 1000);
+    }
+
+    componentDidMount() {
+        let elem = ReactDOM.findDOMNode(this).parentNode;
+        elem.addEventListener("scroll", this._onScroll, false);
+    }
+
+    componentDidUpdate() {
+        let elem = ReactDOM.findDOMNode(this).parentNode;
+        if (!this.scrolling && this.state.scrollToBottom) {
+            if (elem.scrollTop !== elem.scrollHeight - elem.offsetHeight) {
+                elem.scrollTop = elem.scrollHeight - elem.offsetHeight;
+            }
+        }
+    }
+
+    componentWillUnmount() {
+        let elem = ReactDOM.findDOMNode(this).parentNode;
+        elem.removeEventListener("scroll", this._onScroll, false);
+        clearTimeout(this.timer);
+    }
+
+    render() {
+        let { logs } = this.state;
+        return (
+            <LoadingAndErrorWrapper loading={!logs || logs.length === 0}>
+                {() =>
+                    <div style={{ backgroundColor: "black", fontFamily: "monospace", fontSize: "14px", whiteSpace: "pre-line", padding: "0.5em" }}>
+                        {reactAnsiStyle(React, logs.join("\n"))}
+                    </div>
+                }
+            </LoadingAndErrorWrapper>
+        );
+    }
+}

frontend/src/components/ProfileLink.jsx

@@ -5,6 +5,7 @@ import _ from "underscore";
 
 import MetabaseSettings from "metabase/lib/settings";
 import Modal from "metabase/components/Modal.jsx";
+import Logs from "metabase/components/Logs.jsx";
 
 import UserAvatar from './UserAvatar.jsx';
 import Icon from './Icon.jsx';
@@ -16,7 +17,10 @@ export default class ProfileLink extends Component {
     constructor(props, context) {
         super(props, context);
 
-        this.state = { dropdownOpen: false, aboutModalOpen: false };
+        this.state = {
+            dropdownOpen: false,
+            modalOpen: null
+        };
 
         _.bindAll(this, "toggleDropdown", "closeDropdown", "openModal", "closeModal");
     }
@@ -34,17 +38,17 @@ export default class ProfileLink extends Component {
         this.setState({ dropdownOpen: false });
     }
 
-    openModal() {
-        this.setState({ dropdownOpen: false, aboutModalOpen: true });
+    openModal(modalName) {
+        this.setState({ dropdownOpen: false, modalOpen: modalName });
     }
 
     closeModal() {
-        this.setState({ aboutModalOpen: false });
+        this.setState({ modalOpen: null });
     }
 
     render() {
         const { user, context } = this.props;
-        const { aboutModalOpen, dropdownOpen } = this.state;
+        const { modalOpen, dropdownOpen } = this.state;
         const { tag, date } = MetabaseSettings.get('version');
 
         let dropDownClasses = cx({
@@ -97,8 +101,16 @@ export default class ProfileLink extends Component {
                                     </a>
                                 </li>
 
+                                { user.is_superuser &&
+                                    <li>
+                                        <a data-metabase-event={"Navbar;Profile Dropdown;Debugging "+tag} onClick={this.openModal.bind(this, "logs")} className="Dropdown-item block text-white no-decoration">
+                                            Logs
+                                        </a>
+                                    </li>
+                                }
+
                                 <li>
-                                    <a data-metabase-event={"Navbar;Profile Dropdown;About "+tag} onClick={this.openModal} className="Dropdown-item block text-white no-decoration">
+                                    <a data-metabase-event={"Navbar;Profile Dropdown;About "+tag} onClick={this.openModal.bind(this, "about")} className="Dropdown-item block text-white no-decoration">
                                         About Metabase
                                     </a>
                                 </li>
@@ -110,7 +122,7 @@ export default class ProfileLink extends Component {
                         </div>
                     : null }
 
-                    { aboutModalOpen ?
+                    { modalOpen === "about" ?
                         <Modal className="Modal Modal--small">
                             <div className="px4 pt4 pb2 text-centered relative">
                                 <span className="absolute top right p4 text-normal text-grey-3 cursor-pointer" onClick={this.closeModal}>
@@ -130,6 +142,10 @@ export default class ProfileLink extends Component {
                                 <span>and is built with care in San Francisco, CA</span>
                             </div>
                         </Modal>
+                    : modalOpen === "logs" ?
+                        <Modal className="Modal Modal--wide" onClose={this.closeModal}>
+                            <Logs onClose={this.closeModal} />
+                        </Modal>
                     : null }
                 </div>
             </OnClickOut>

frontend/src/css/components/modal.css

@@ -29,6 +29,10 @@
   width: 480px;
 }
 
+.Modal.Modal--wide {
+  width: 85%;
+}
+
 .Modal-backdrop {
     position: fixed;
     top: 0;

project.clj

@@ -20,6 +20,9 @@
                  [org.clojure/math.numeric-tower "0.0.4"]             ; math functions like `ceil`
                  [org.clojure/tools.logging "0.3.1"]                  ; logging framework
                  [org.clojure/tools.namespace "0.2.10"]
+                 [amalloy/ring-buffer "1.2"
+                  :exclusions [org.clojure/clojure
+                               org.clojure/clojurescript]]            ; fixed length queue implementation, used in log buffering
                  [amalloy/ring-gzip-middleware "0.1.3"]               ; Ring middleware to GZIP responses if client can handle it
                  [aleph "0.4.1-beta4"]                                ; Async HTTP library; WebSockets
                  [cheshire "5.5.0"]                                   ; fast JSON encoding (used by Ring JSON middleware)
@@ -109,7 +112,8 @@
                               "-Xms1024m"                             ; give JVM a decent heap size to start with
                               "-Xmx2048m"                             ; hard limit of 2GB so we stop hitting the 4GB container limit on CircleCI
                               "-XX:+CMSClassUnloadingEnabled"         ; let Clojure's dynamically generated temporary classes be GC'ed from PermGen
-                              "-XX:+UseConcMarkSweepGC"]}             ; Concurrent Mark Sweep GC needs to be used for Class Unloading (above)
+                              "-XX:+UseConcMarkSweepGC"]              ; Concurrent Mark Sweep GC needs to be used for Class Unloading (above)
+                   :aot [metabase.logger]}                            ; Log appender class needs to be compiled for log4j to use it
              :reflection-warnings {:global-vars {*warn-on-reflection* true}} ; run `lein check-reflection-warnings` to check for reflection warnings
              :expectations {:injections [(require 'metabase.test-setup)]
                             :resource-paths ["test_resources"]

resources/log4j.properties

-log4j.rootLogger=WARN, console
+log4j.rootLogger=WARN, console, metabase
 
 # log to the console
 log4j.appender.console=org.apache.log4j.ConsoleAppender
@@ -14,6 +14,8 @@ log4j.appender.file.MaxBackupIndex=2
 log4j.appender.file.layout=org.apache.log4j.PatternLayout
 log4j.appender.file.layout.ConversionPattern=%d [%t] %-5p%c - %m%n
 
+log4j.appender.metabase=metabase.logger.Appender
+
 # customizations to logging by package
 log4j.logger.metabase=INFO
 log4j.logger.metabase.driver=DEBUG

src/metabase/api/util.clj

 (ns metabase.api.util
-  (:require [compojure.core :refer [defroutes POST]]
-            [metabase.api.common :refer :all]))
+  (:require [compojure.core :refer [defroutes GET POST]]
+            [metabase.api.common :refer :all]
+            [metabase.logger :as logger]))
 
 
 (defendpoint POST "/password_check"
@@ -10,5 +11,10 @@
   ;; checking happens in the
   {:valid true})
 
+(defendpoint GET "/logs"
+  "Logs."
+  []
+  (check-superuser)
+  (logger/get-messages))
 
 (define-routes)

src/metabase/core.clj

@@ -16,6 +16,7 @@
                       [db :as db]
                       [driver :as driver]
                       [events :as events]
+                      [logger :as logger]
                       [metabot :as metabot]
                       [middleware :as mb-middleware]
                       [routes :as routes]

src/metabase/logger.clj

+(ns metabase.logger
+  (:require [clj-time.core :as t]
+            [clj-time.coerce :as coerce]
+            [clj-time.format :as time]
+            [amalloy.ring-buffer :refer [ring-buffer]])
+  (:gen-class
+    :extends org.apache.log4j.AppenderSkeleton
+    :name metabase.logger.Appender)
+  (:import (org.apache.log4j.spi LoggingEvent)))
+
+(def ^:private ^:const max-log-entries 2500)
+
+(def ^:private messages (atom (ring-buffer max-log-entries)))
+
+(defn get-messages
+  "Get the list of currently buffered log entries"
+  []
+  (reverse (seq @messages)))
+
+
+(def ^:private formatter (time/formatter "MMM dd HH:mm:ss" (t/default-time-zone)))
+
+(defn -append
+  "docstring"
+  [_ ^LoggingEvent event]
+  (let [ts    (time/unparse formatter (coerce/from-long (.getTimeStamp event)))
+        level (.getLevel event)
+        fqns  (.getLoggerName event)
+        msg   (.getMessage event)]
+    (swap! messages conj (format "%s \033[1m%s %s\033[0m :: %s" ts level fqns msg))
+    nil))
+
+(defn -close
+  "docstring"
+  [_]
+  nil)
+
+(defn -requiresLayout
+  "docstring"
+  [_]
+  false)