From commits-return-2282-archive-asf-public=cust-asf.ponee.io@superset.incubator.apache.org Sat Feb 16 07:10:18 2019 Return-Path: X-Original-To: archive-asf-public@cust-asf.ponee.io Delivered-To: archive-asf-public@cust-asf.ponee.io Received: from mail.apache.org (hermes.apache.org [140.211.11.3]) by mx-eu-01.ponee.io (Postfix) with SMTP id 9FFB5180608 for ; Sat, 16 Feb 2019 08:10:16 +0100 (CET) Received: (qmail 69902 invoked by uid 500); 16 Feb 2019 07:10:15 -0000 Mailing-List: contact commits-help@superset.incubator.apache.org; run by ezmlm Precedence: bulk List-Help: List-Unsubscribe: List-Post: List-Id: Reply-To: dev@superset.incubator.apache.org Delivered-To: mailing list commits@superset.incubator.apache.org Received: (qmail 69893 invoked by uid 99); 16 Feb 2019 07:10:15 -0000 Received: from ec2-52-202-80-70.compute-1.amazonaws.com (HELO gitbox.apache.org) (52.202.80.70) by apache.org (qpsmtpd/0.29) with ESMTP; Sat, 16 Feb 2019 07:10:15 +0000 Received: by gitbox.apache.org (ASF Mail Server at gitbox.apache.org, from userid 33) id C26A683A9B; Sat, 16 Feb 2019 07:10:14 +0000 (UTC) Date: Sat, 16 Feb 2019 07:10:14 +0000 To: "commits@superset.apache.org" Subject: [incubator-superset] branch master updated: Improve Superset logger (#6879) MIME-Version: 1.0 Content-Type: text/plain; charset=utf-8 Content-Transfer-Encoding: 8bit Message-ID: <155030101433.15585.11711978425575933126@gitbox.apache.org> From: graceguo@apache.org X-Git-Host: gitbox.apache.org X-Git-Repo: incubator-superset X-Git-Refname: refs/heads/master X-Git-Reftype: branch X-Git-Oldrev: bd9a2c15e79f2f337bf3bdfd67603eee8d0e16a9 X-Git-Newrev: 47f42ed351964230c77611b215466eea115e6456 X-Git-Rev: 47f42ed351964230c77611b215466eea115e6456 X-Git-NotificationType: ref_changed_plus_diff X-Git-Multimail-Version: 1.5.dev Auto-Submitted: auto-generated This is an automated email from the ASF dual-hosted git repository. graceguo pushed a commit to branch master in repository https://gitbox.apache.org/repos/asf/incubator-superset.git The following commit(s) were added to refs/heads/master by this push: new 47f42ed Improve Superset logger (#6879) 47f42ed is described below commit 47f42ed351964230c77611b215466eea115e6456 Author: Grace Guo AuthorDate: Fri Feb 15 23:10:05 2019 -0800 Improve Superset logger (#6879) * enable beacon * add middleware * add unit tests --- .../spec/javascripts/chart/chartActions_spec.js | 44 +++-- .../dashboard/components/Dashboard_spec.jsx | 1 + .../components/gridComponents/Chart_spec.jsx | 1 + .../components/gridComponents/Markdown_spec.jsx | 1 + .../components/gridComponents/Tabs_spec.jsx | 1 + superset/assets/spec/javascripts/logger_spec.js | 179 -------------------- .../spec/javascripts/middleware/logger_spec.js | 111 +++++++++++++ superset/assets/src/chart/Chart.jsx | 7 +- superset/assets/src/chart/ChartContainer.jsx | 6 +- superset/assets/src/chart/ChartRenderer.jsx | 57 ++++--- superset/assets/src/chart/chartAction.js | 13 +- superset/assets/src/components/OmniContainer.jsx | 2 +- superset/assets/src/dashboard/App.jsx | 3 +- .../assets/src/dashboard/actions/dashboardState.js | 17 -- .../assets/src/dashboard/components/Dashboard.jsx | 76 +-------- .../assets/src/dashboard/components/Header.jsx | 29 +++- .../dashboard/components/SliceHeaderControls.jsx | 27 --- .../dashboard/components/gridComponents/Chart.jsx | 36 +++- .../components/gridComponents/Markdown.jsx | 14 ++ .../dashboard/components/gridComponents/Tabs.jsx | 7 + superset/assets/src/dashboard/containers/Chart.jsx | 2 + .../assets/src/dashboard/containers/Dashboard.jsx | 2 + .../dashboard/containers/DashboardComponent.jsx | 4 + .../src/dashboard/containers/DashboardHeader.jsx | 3 + superset/assets/src/explore/App.jsx | 3 +- .../explore/components/ExploreViewContainer.jsx | 32 ++-- superset/assets/src/logger.js | 183 --------------------- superset/assets/src/logger/LogUtils.js | 63 +++++++ .../ChartContainer.jsx => logger/actions/index.js} | 22 +-- superset/assets/src/middleware/loggerMiddleware.js | 117 +++++++++++++ .../DebouncedMessageQueue.js} | 34 +++- superset/config.py | 2 +- 32 files changed, 527 insertions(+), 572 deletions(-) diff --git a/superset/assets/spec/javascripts/chart/chartActions_spec.js b/superset/assets/spec/javascripts/chart/chartActions_spec.js index d30a41d..09f618c 100644 --- a/superset/assets/spec/javascripts/chart/chartActions_spec.js +++ b/superset/assets/spec/javascripts/chart/chartActions_spec.js @@ -19,7 +19,7 @@ import fetchMock from 'fetch-mock'; import sinon from 'sinon'; -import { Logger } from '../../../src/logger'; +import { LOG_EVENT } from '../../../src/logger/actions'; import * as exploreUtils from '../../../src/explore/exploreUtils'; import * as actions from '../../../src/chart/chartAction'; @@ -27,7 +27,6 @@ describe('chart actions', () => { const MOCK_URL = '/mockURL'; let dispatch; let urlStub; - let loggerStub; const setupDefaultFetchMock = () => { fetchMock.post(MOCK_URL, { json: {} }, { overwriteRoutes: true }); @@ -44,12 +43,10 @@ describe('chart actions', () => { urlStub = sinon .stub(exploreUtils, 'getExploreUrlAndPayload') .callsFake(() => ({ url: MOCK_URL, payload: {} })); - loggerStub = sinon.stub(Logger, 'append'); }); afterEach(() => { urlStub.restore(); - loggerStub.restore(); fetchMock.resetHistory(); }); @@ -58,7 +55,7 @@ describe('chart actions', () => { return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, success - expect(dispatch.callCount).toBe(4); + expect(dispatch.callCount).toBe(5); expect(fetchMock.calls(MOCK_URL)).toHaveLength(1); expect(dispatch.args[0][0].type).toBe(actions.CHART_UPDATE_STARTED); @@ -70,7 +67,7 @@ describe('chart actions', () => { const actionThunk = actions.runQuery({}); return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, success - expect(dispatch.callCount).toBe(4); + expect(dispatch.callCount).toBe(5); expect(fetchMock.calls(MOCK_URL)).toHaveLength(1); expect(dispatch.args[1][0].type).toBe(actions.TRIGGER_QUERY); @@ -82,7 +79,7 @@ describe('chart actions', () => { const actionThunk = actions.runQuery({}); return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, success - expect(dispatch.callCount).toBe(4); + expect(dispatch.callCount).toBe(5); expect(fetchMock.calls(MOCK_URL)).toHaveLength(1); expect(dispatch.args[2][0].type).toBe(actions.UPDATE_QUERY_FORM_DATA); @@ -90,14 +87,29 @@ describe('chart actions', () => { }); }); + it('should dispatch logEvent async action', () => { + const actionThunk = actions.runQuery({}); + return actionThunk(dispatch).then(() => { + // chart update, trigger query, update form data, success + expect(dispatch.callCount).toBe(5); + expect(fetchMock.calls(MOCK_URL)).toHaveLength(1); + expect(typeof dispatch.args[3][0]).toBe('function'); + + dispatch.args[3][0](dispatch); + expect(dispatch.callCount).toBe(6); + expect(dispatch.args[5][0].type).toBe(LOG_EVENT); + + return Promise.resolve(); + }); + }); + it('should dispatch CHART_UPDATE_SUCCEEDED action upon success', () => { const actionThunk = actions.runQuery({}); return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, success - expect(dispatch.callCount).toBe(4); + expect(dispatch.callCount).toBe(5); expect(fetchMock.calls(MOCK_URL)).toHaveLength(1); - expect(dispatch.args[3][0].type).toBe(actions.CHART_UPDATE_SUCCEEDED); - expect(loggerStub.callCount).toBe(1); + expect(dispatch.args[4][0].type).toBe(actions.CHART_UPDATE_SUCCEEDED); return Promise.resolve(); }); @@ -112,10 +124,8 @@ describe('chart actions', () => { return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, fail - expect(dispatch.callCount).toBe(4); - expect(dispatch.args[3][0].type).toBe(actions.CHART_UPDATE_TIMEOUT); - expect(loggerStub.callCount).toBe(1); - expect(loggerStub.args[0][1].error_details).toBe('timeout'); + expect(dispatch.callCount).toBe(5); + expect(dispatch.args[4][0].type).toBe(actions.CHART_UPDATE_TIMEOUT); setupDefaultFetchMock(); return Promise.resolve(); @@ -130,13 +140,11 @@ describe('chart actions', () => { return actionThunk(dispatch).then(() => { // chart update, trigger query, update form data, fail - expect(dispatch.callCount).toBe(4); - const updateFailedAction = dispatch.args[3][0]; + expect(dispatch.callCount).toBe(5); + const updateFailedAction = dispatch.args[4][0]; expect(updateFailedAction.type).toBe(actions.CHART_UPDATE_FAILED); expect(updateFailedAction.queryResponse.error).toBe('misc error'); - expect(loggerStub.callCount).toBe(1); - expect(loggerStub.args[0][1].error_details).toBe('misc error'); setupDefaultFetchMock(); return Promise.resolve(); diff --git a/superset/assets/spec/javascripts/dashboard/components/Dashboard_spec.jsx b/superset/assets/spec/javascripts/dashboard/components/Dashboard_spec.jsx index f61264d..523b835 100644 --- a/superset/assets/spec/javascripts/dashboard/components/Dashboard_spec.jsx +++ b/superset/assets/spec/javascripts/dashboard/components/Dashboard_spec.jsx @@ -40,6 +40,7 @@ describe('Dashboard', () => { addSliceToDashboard() {}, removeSliceFromDashboard() {}, runQuery() {}, + logEvent() {}, }, initMessages: [], dashboardState, diff --git a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Chart_spec.jsx b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Chart_spec.jsx index 23d634c..5e75edf 100644 --- a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Chart_spec.jsx +++ b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Chart_spec.jsx @@ -54,6 +54,7 @@ describe('Chart', () => { refreshChart() {}, toggleExpandSlice() {}, addFilter() {}, + logEvent() {}, editMode: false, isExpanded: false, supersetCanExplore: false, diff --git a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Markdown_spec.jsx b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Markdown_spec.jsx index 7339983..f320492 100644 --- a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Markdown_spec.jsx +++ b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Markdown_spec.jsx @@ -51,6 +51,7 @@ describe('Markdown', () => { handleComponentDrop() {}, updateComponents() {}, deleteComponent() {}, + logEvent() {}, }; function setup(overrideProps) { diff --git a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Tabs_spec.jsx b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Tabs_spec.jsx index 86f3a9f..59b067c 100644 --- a/superset/assets/spec/javascripts/dashboard/components/gridComponents/Tabs_spec.jsx +++ b/superset/assets/spec/javascripts/dashboard/components/gridComponents/Tabs_spec.jsx @@ -52,6 +52,7 @@ describe('Tabs', () => { onChangeTab() {}, deleteComponent() {}, updateComponents() {}, + logEvent() {}, }; function setup(overrideProps) { diff --git a/superset/assets/spec/javascripts/logger_spec.js b/superset/assets/spec/javascripts/logger_spec.js deleted file mode 100644 index 4486aff..0000000 --- a/superset/assets/spec/javascripts/logger_spec.js +++ /dev/null @@ -1,179 +0,0 @@ -/** - * Licensed to the Apache Software Foundation (ASF) under one - * or more contributor license agreements. See the NOTICE file - * distributed with this work for additional information - * regarding copyright ownership. The ASF licenses this file - * to you under the Apache License, Version 2.0 (the - * "License"); you may not use this file except in compliance - * with the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, - * software distributed under the License is distributed on an - * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY - * KIND, either express or implied. See the License for the - * specific language governing permissions and limitations - * under the License. - */ -import fetchMock from 'fetch-mock'; - -import { Logger, ActionLog } from '../../src/logger'; - -describe('ActionLog', () => { - it('should be a constructor', () => { - const newLogger = new ActionLog({}); - expect(newLogger instanceof ActionLog).toBe(true); - }); - - it( - 'should set the eventNames, impressionId, source, sourceId, and sendNow init parameters', - () => { - const eventNames = []; - const impressionId = 'impressionId'; - const source = 'source'; - const sourceId = 'sourceId'; - const sendNow = true; - - const log = new ActionLog({ eventNames, impressionId, source, sourceId, sendNow }); - expect(log.eventNames).toBe(eventNames); - expect(log.impressionId).toBe(impressionId); - expect(log.source).toBe(source); - expect(log.sourceId).toBe(sourceId); - expect(log.sendNow).toBe(sendNow); - }, - ); - - it('should set attributes with the setAttribute method', () => { - const log = new ActionLog({}); - expect(log.test).toBeUndefined(); - log.setAttribute('test', 'testValue'); - expect(log.test).toBe('testValue'); - }); - - it('should track added events', () => { - const log = new ActionLog({}); - const eventName = 'myEventName'; - const eventBody = { test: 'event' }; - expect(log.events[eventName]).toBeUndefined(); - - log.addEvent(eventName, eventBody); - expect(log.events[eventName]).toHaveLength(1); - expect(log.events[eventName][0]).toMatchObject(eventBody); - Logger.end(log); - }); -}); - -describe('Logger', () => { - const logEndpoint = 'glob:*/superset/log/*'; - fetchMock.post(logEndpoint, 'success'); - afterEach(fetchMock.resetHistory); - - it('should add events when .append(eventName, eventBody) is called', () => { - const eventName = 'testEvent'; - const eventBody = { test: 'event' }; - const log = new ActionLog({ eventNames: [eventName] }); - Logger.start(log); - Logger.append(eventName, eventBody); - expect(log.events[eventName]).toHaveLength(1); - expect(log.events[eventName][0]).toMatchObject(eventBody); - Logger.end(log); - }); - - describe('.send()', () => { - const eventNames = ['test']; - - function setup(overrides = {}) { - const log = new ActionLog({ eventNames, ...overrides }); - return log; - } - - it('should POST an event to /superset/log/ when called', (done) => { - const log = setup(); - Logger.start(log); - Logger.append(eventNames[0], { test: 'event' }); - expect(log.events[eventNames[0]]).toHaveLength(1); - Logger.end(log); - - setTimeout(() => { - expect(fetchMock.calls(logEndpoint)).toHaveLength(1); - done(); - }, 0); - }); - - it("should flush the log's events", () => { - const log = setup(); - Logger.start(log); - Logger.append(eventNames[0], { test: 'event' }); - const event = log.events[eventNames[0]][0]; - expect(event).toMatchObject({ test: 'event' }); - Logger.end(log); - expect(log.events).toEqual({}); - }); - - it( - 'should include ts, start_offset, event_name, impression_id, source, and source_id in every event', - (done) => { - const config = { - eventNames: ['event1', 'event2'], - impressionId: 'impress_me', - source: 'superset', - sourceId: 'lolz', - }; - const log = setup(config); - - Logger.start(log); - Logger.append('event1', { key: 'value' }); - Logger.append('event2', { foo: 'bar' }); - Logger.end(log); - - setTimeout(() => { - const calls = fetchMock.calls(logEndpoint); - expect(calls).toHaveLength(1); - const options = calls[0][1]; - const events = JSON.parse(options.body.get('events')); - - expect(events).toHaveLength(2); - - expect(events[0]).toMatchObject({ - key: 'value', - event_name: 'event1', - impression_id: config.impressionId, - source: config.source, - source_id: config.sourceId, - }); - - expect(events[1]).toMatchObject({ - foo: 'bar', - event_name: 'event2', - impression_id: config.impressionId, - source: config.source, - source_id: config.sourceId, - }); - - expect(typeof events[0].ts).toBe('number'); - expect(typeof events[1].ts).toBe('number'); - expect(typeof events[0].start_offset).toBe('number'); - expect(typeof events[1].start_offset).toBe('number'); - - done(); - }, 0); - }, - ); - - it( - 'should send() a log immediately if .append() is called with sendNow=true', - (done) => { - const log = setup(); - Logger.start(log); - Logger.append(eventNames[0], { test: 'event' }, true); - - setTimeout(() => { - expect(fetchMock.calls(logEndpoint)).toHaveLength(1); - Logger.end(log); // flush logs - done(); - }, 0); - }, - ); - }); -}); diff --git a/superset/assets/spec/javascripts/middleware/logger_spec.js b/superset/assets/spec/javascripts/middleware/logger_spec.js new file mode 100644 index 0000000..c5f5a4a --- /dev/null +++ b/superset/assets/spec/javascripts/middleware/logger_spec.js @@ -0,0 +1,111 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +import sinon from 'sinon'; +import { SupersetClient } from '@superset-ui/connection'; +import logger from '../../../src/middleware/loggerMiddleware'; +import { LOG_EVENT } from '../../../src/logger/actions'; +import { LOG_ACTIONS_LOAD_CHART } from '../../../src/logger/LogUtils'; + +describe('logger middleware', () => { + const next = sinon.spy(); + const mockStore = { + getState: () => ({ + dashboardInfo: { + id: 1, + }, + impressionId: 'impression_id', + }), + }; + const action = { + type: LOG_EVENT, + payload: { + eventName: LOG_ACTIONS_LOAD_CHART, + eventData: { + key: 'value', + start_offset: 100, + }, + }, + }; + + let postStub; + beforeEach(() => { + postStub = sinon.stub(SupersetClient, 'post'); + }); + afterEach(() => { + next.reset(); + postStub.restore(); + }); + + it('should listen to LOG_EVENT action type', () => { + const action1 = { + type: 'ACTION_TYPE', + payload: { + some: 'data', + }, + }; + logger(mockStore)(next)(action1); + expect(next.callCount).toBe(1); + }); + + it('should POST an event to /superset/log/ when called', () => { + const clock = sinon.useFakeTimers(); + logger(mockStore)(next)(action); + expect(next.callCount).toBe(0); + + clock.tick(2000); + expect(SupersetClient.post.callCount).toBe(1); + expect(SupersetClient.post.getCall(0).args[0].endpoint).toMatch('/superset/log/'); + }); + + it( + 'should include ts, start_offset, event_name, impression_id, source, and source_id in every event', + () => { + const clock = sinon.useFakeTimers(); + logger(mockStore)(next)(action); + clock.tick(2000); + + expect(SupersetClient.post.callCount).toBe(1); + const events = SupersetClient.post.getCall(0).args[0].postPayload.events; + const mockEventdata = action.payload.eventData; + const mockEventname = action.payload.eventName; + expect(events[0]).toMatchObject({ + key: mockEventdata.key, + event_name: mockEventname, + impression_id: mockStore.getState().impressionId, + source: 'dashboard', + source_id: mockStore.getState().dashboardInfo.id, + event_type: 'timing', + }); + + expect(typeof events[0].ts).toBe('number'); + expect(typeof events[0].start_offset).toBe('number'); + }, + ); + + it('should debounce a few log requests to one', () => { + const clock = sinon.useFakeTimers(); + logger(mockStore)(next)(action); + logger(mockStore)(next)(action); + logger(mockStore)(next)(action); + clock.tick(2000); + + expect(SupersetClient.post.callCount).toBe(1); + expect(SupersetClient.post.getCall(0).args[0].postPayload.events).toHaveLength(3); + }); +}); diff --git a/superset/assets/src/chart/Chart.jsx b/superset/assets/src/chart/Chart.jsx index aa72c95..3ef2c8b 100644 --- a/superset/assets/src/chart/Chart.jsx +++ b/superset/assets/src/chart/Chart.jsx @@ -18,7 +18,7 @@ */ import PropTypes from 'prop-types'; import React from 'react'; -import { Logger, LOG_ACTIONS_RENDER_CHART_CONTAINER } from '../logger'; +import { Logger, LOG_ACTIONS_RENDER_CHART_CONTAINER } from '../logger/LogUtils'; import Loading from '../components/Loading'; import RefreshChartOverlay from '../components/RefreshChartOverlay'; import StackTraceMessage from '../components/StackTraceMessage'; @@ -73,16 +73,17 @@ class Chart extends React.PureComponent { } } - handleRenderFailure(error, info) { + handleRenderContainerFailure(error, info) { const { actions, chartId } = this.props; console.warn(error); // eslint-disable-line actions.chartRenderingFailed(error.toString(), chartId, info ? info.componentStack : null); - Logger.append(LOG_ACTIONS_RENDER_CHART_CONTAINER, { + actions.logEvent(LOG_ACTIONS_RENDER_CHART_CONTAINER, { slice_id: chartId, has_err: true, error_details: error.toString(), start_offset: this.renderStartTime, + ts: new Date().getTime(), duration: Logger.getTimestamp() - this.renderStartTime, }); } diff --git a/superset/assets/src/chart/ChartContainer.jsx b/superset/assets/src/chart/ChartContainer.jsx index f677c5b..03a4f1a 100644 --- a/superset/assets/src/chart/ChartContainer.jsx +++ b/superset/assets/src/chart/ChartContainer.jsx @@ -20,11 +20,15 @@ import { connect } from 'react-redux'; import { bindActionCreators } from 'redux'; import * as actions from './chartAction'; +import { logEvent } from '../logger/actions'; import Chart from './Chart'; function mapDispatchToProps(dispatch) { return { - actions: bindActionCreators(actions, dispatch), + actions: bindActionCreators({ + ...actions, + logEvent, + }, dispatch), }; } diff --git a/superset/assets/src/chart/ChartRenderer.jsx b/superset/assets/src/chart/ChartRenderer.jsx index bae2682..dcc3f5e 100644 --- a/superset/assets/src/chart/ChartRenderer.jsx +++ b/superset/assets/src/chart/ChartRenderer.jsx @@ -22,7 +22,7 @@ import PropTypes from 'prop-types'; import React from 'react'; import { ChartProps, SuperChart } from '@superset-ui/chart'; import { Tooltip } from 'react-bootstrap'; -import { Logger, LOG_ACTIONS_RENDER_CHART } from '../logger'; +import { Logger, LOG_ACTIONS_RENDER_CHART } from '../logger/LogUtils'; const propTypes = { annotationData: PropTypes.object, @@ -61,6 +61,7 @@ class ChartRenderer extends React.Component { this.state = {}; this.createChartProps = ChartProps.createSelector(); + this.hasQueryResponseChnage = false; this.setTooltip = this.setTooltip.bind(this); this.handleAddFilter = this.handleAddFilter.bind(this); @@ -69,18 +70,23 @@ class ChartRenderer extends React.Component { } shouldComponentUpdate(nextProps) { - if ( + const resultsReady = nextProps.queryResponse && ['success', 'rendered'].indexOf(nextProps.chartStatus) > -1 && !nextProps.queryResponse.error && - !nextProps.refreshOverlayVisible && - (nextProps.annotationData !== this.props.annotationData || - nextProps.queryResponse !== this.props.queryResponse || + !nextProps.refreshOverlayVisible; + + if (resultsReady) { + this.hasQueryResponseChnage = + nextProps.queryResponse !== this.props.queryResponse; + + if (this.hasQueryResponseChnage || + nextProps.annotationData !== this.props.annotationData || nextProps.height !== this.props.height || nextProps.width !== this.props.width || - nextProps.triggerRender) - ) { - return true; + nextProps.triggerRender) { + return true; + } } return false; } @@ -126,12 +132,17 @@ class ChartRenderer extends React.Component { actions.chartRenderingSucceeded(chartId); } - Logger.append(LOG_ACTIONS_RENDER_CHART, { - slice_id: chartId, - viz_type: vizType, - start_offset: this.renderStartTime, - duration: Logger.getTimestamp() - this.renderStartTime, - }); + // only log chart render time which is triggered by query results change + // currently we don't log chart re-render time, like window resize etc + if (this.hasQueryResponseChnage) { + actions.logEvent(LOG_ACTIONS_RENDER_CHART, { + slice_id: chartId, + viz_type: vizType, + start_offset: this.renderStartTime, + ts: new Date().getTime(), + duration: Logger.getTimestamp() - this.renderStartTime, + }); + } } handleRenderFailure(error, info) { @@ -139,13 +150,17 @@ class ChartRenderer extends React.Component { console.warn(error); // eslint-disable-line actions.chartRenderingFailed(error.toString(), chartId, info ? info.componentStack : null); - Logger.append(LOG_ACTIONS_RENDER_CHART, { - slice_id: chartId, - has_err: true, - error_details: error.toString(), - start_offset: this.renderStartTime, - duration: Logger.getTimestamp() - this.renderStartTime, - }); + // only trigger render log when query is changed + if (this.hasQueryResponseChnage) { + actions.logEvent(LOG_ACTIONS_RENDER_CHART, { + slice_id: chartId, + has_err: true, + error_details: error.toString(), + start_offset: this.renderStartTime, + ts: new Date().getTime(), + duration: Logger.getTimestamp() - this.renderStartTime, + }); + } } renderTooltip() { diff --git a/superset/assets/src/chart/chartAction.js b/superset/assets/src/chart/chartAction.js index bcdc4e1..2154759 100644 --- a/superset/assets/src/chart/chartAction.js +++ b/superset/assets/src/chart/chartAction.js @@ -24,7 +24,8 @@ import { SupersetClient } from '@superset-ui/connection'; import { getExploreUrlAndPayload, getAnnotationJsonUrl } from '../explore/exploreUtils'; import { requiresQuery, ANNOTATION_SOURCE_TYPES } from '../modules/AnnotationTypes'; import { addDangerToast } from '../messageToasts/actions'; -import { Logger, LOG_ACTIONS_LOAD_CHART } from '../logger'; +import { logEvent } from '../logger/actions'; +import { Logger, LOG_ACTIONS_LOAD_CHART } from '../logger/LogUtils'; import getClientErrorObject from '../utils/getClientErrorObject'; import { allowCrossDomain } from '../utils/hostNamesConfig'; @@ -194,29 +195,31 @@ export function runQuery(formData, force = false, timeout = 60, key) { } const queryPromise = SupersetClient.post(querySettings) .then(({ json }) => { - Logger.append(LOG_ACTIONS_LOAD_CHART, { + dispatch(logEvent(LOG_ACTIONS_LOAD_CHART, { slice_id: key, is_cached: json.is_cached, force_refresh: force, row_count: json.rowcount, datasource: formData.datasource, start_offset: logStart, + ts: new Date().getTime(), duration: Logger.getTimestamp() - logStart, has_extra_filters: formData.extra_filters && formData.extra_filters.length > 0, viz_type: formData.viz_type, - }); + })); return dispatch(chartUpdateSucceeded(json, key)); }) .catch((response) => { const appendErrorLog = (errorDetails) => { - Logger.append(LOG_ACTIONS_LOAD_CHART, { + dispatch(logEvent(LOG_ACTIONS_LOAD_CHART, { slice_id: key, has_err: true, error_details: errorDetails, datasource: formData.datasource, start_offset: logStart, + ts: new Date().getTime(), duration: Logger.getTimestamp() - logStart, - }); + })); }; if (response.statusText === 'timeout') { diff --git a/superset/assets/src/components/OmniContainer.jsx b/superset/assets/src/components/OmniContainer.jsx index 6b1cac3..792d8ba 100644 --- a/superset/assets/src/components/OmniContainer.jsx +++ b/superset/assets/src/components/OmniContainer.jsx @@ -27,7 +27,7 @@ import { Logger, ActionLog, LOG_ACTIONS_OMNIBAR_TRIGGERED, -} from '../logger'; +} from '../logger/LogUtils'; const propTypes = { impressionId: PropTypes.string.isRequired, diff --git a/superset/assets/src/dashboard/App.jsx b/superset/assets/src/dashboard/App.jsx index 28d0473..49c5453 100644 --- a/superset/assets/src/dashboard/App.jsx +++ b/superset/assets/src/dashboard/App.jsx @@ -24,6 +24,7 @@ import { hot } from 'react-hot-loader'; import { initFeatureFlags } from 'src/featureFlags'; import { initEnhancer } from '../reduxUtils'; +import logger from '../middleware/loggerMiddleware'; import setupApp from '../setup/setupApp'; import setupPlugins from '../setup/setupPlugins'; import DashboardContainer from './containers/Dashboard'; @@ -42,7 +43,7 @@ const store = createStore( rootReducer, initState, compose( - applyMiddleware(thunk), + applyMiddleware(thunk, logger), initEnhancer(false), ), ); diff --git a/superset/assets/src/dashboard/actions/dashboardState.js b/superset/assets/src/dashboard/actions/dashboardState.js index 8945ca7..bdade32 100644 --- a/superset/assets/src/dashboard/actions/dashboardState.js +++ b/superset/assets/src/dashboard/actions/dashboardState.js @@ -26,11 +26,6 @@ import { chart as initChart } from '../../chart/chartReducer'; import { fetchDatasourceMetadata } from '../../dashboard/actions/datasources'; import { applyDefaultFormData } from '../../explore/store'; import getClientErrorObject from '../../utils/getClientErrorObject'; -import { - Logger, - LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, - LOG_ACTIONS_REFRESH_DASHBOARD, -} from '../../logger'; import { SAVE_TYPE_OVERWRITE } from '../util/constants'; import { addSuccessToast, @@ -45,13 +40,6 @@ export function setUnsavedChanges(hasUnsavedChanges) { export const CHANGE_FILTER = 'CHANGE_FILTER'; export function changeFilter(chart, col, vals, merge = true, refresh = true) { - Logger.append(LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, { - id: chart.id, - column: col, - value_count: Array.isArray(vals) ? vals.length : (vals && 1) || 0, - merge, - refresh, - }); return { type: CHANGE_FILTER, chart, col, vals, merge, refresh }; } @@ -174,11 +162,6 @@ export function saveDashboardRequest(data, id, saveType) { export function fetchCharts(chartList = [], force = false, interval = 0) { return (dispatch, getState) => { - Logger.append(LOG_ACTIONS_REFRESH_DASHBOARD, { - force, - interval, - chartCount: chartList.length, - }); const timeout = getState().dashboardInfo.common.conf .SUPERSET_WEBSERVER_TIMEOUT; if (!interval) { diff --git a/superset/assets/src/dashboard/components/Dashboard.jsx b/superset/assets/src/dashboard/components/Dashboard.jsx index c4e83ed..d884e9a 100644 --- a/superset/assets/src/dashboard/components/Dashboard.jsx +++ b/superset/assets/src/dashboard/components/Dashboard.jsx @@ -31,15 +31,8 @@ import { } from '../util/propShapes'; import { areObjectsEqual } from '../../reduxUtils'; import getFormDataWithExtraFilters from '../util/charts/getFormDataWithExtraFilters'; -import { - Logger, - ActionLog, - DASHBOARD_EVENT_NAMES, - LOG_ACTIONS_MOUNT_DASHBOARD, - LOG_ACTIONS_LOAD_DASHBOARD_PANE, - LOG_ACTIONS_FIRST_DASHBOARD_LOAD, -} from '../../logger'; -import OmniContianer from '../../components/OmniContainer'; +import { LOG_ACTIONS_MOUNT_DASHBOARD } from '../../logger/LogUtils'; +import OmniContainer from '../../components/OmniContainer'; import '../stylesheets/index.less'; @@ -48,6 +41,7 @@ const propTypes = { addSliceToDashboard: PropTypes.func.isRequired, removeSliceFromDashboard: PropTypes.func.isRequired, runQuery: PropTypes.func.isRequired, + logEvent: PropTypes.func.isRequired, }).isRequired, dashboardInfo: dashboardInfoPropShape.isRequired, dashboardState: dashboardStatePropShape.isRequired, @@ -84,71 +78,11 @@ class Dashboard extends React.PureComponent { return message; // Gecko + Webkit, Safari, Chrome etc. } - constructor(props) { - super(props); - this.isFirstLoad = true; - this.actionLog = new ActionLog({ - impressionId: props.impressionId, - source: 'dashboard', - sourceId: props.dashboardInfo.id, - eventNames: DASHBOARD_EVENT_NAMES, - }); - Logger.start(this.actionLog); - this.initTs = new Date().getTime(); - } - componentDidMount() { - Logger.append(LOG_ACTIONS_MOUNT_DASHBOARD); + this.props.actions.logEvent(LOG_ACTIONS_MOUNT_DASHBOARD); } componentWillReceiveProps(nextProps) { - if (!nextProps.dashboardState.editMode) { - // log pane loads - const loadedPaneIds = []; - let minQueryStartTime = Infinity; - const allVisiblePanesDidLoad = Object.entries(nextProps.loadStats).every( - ([paneId, stats]) => { - const { - didLoad, - minQueryStartTime: paneMinQueryStart, - ...restStats - } = stats; - if ( - didLoad && - this.props.loadStats[paneId] && - !this.props.loadStats[paneId].didLoad - ) { - Logger.append(LOG_ACTIONS_LOAD_DASHBOARD_PANE, { - ...restStats, - duration: new Date().getTime() - paneMinQueryStart, - version: 'v2', - }); - - if (!this.isFirstLoad) { - Logger.send(this.actionLog); - } - } - if (this.isFirstLoad && didLoad && stats.slice_ids.length > 0) { - loadedPaneIds.push(paneId); - minQueryStartTime = Math.min(minQueryStartTime, paneMinQueryStart); - } - - // return true if it is loaded, or it's index is not 0 - return didLoad || stats.index !== 0; - }, - ); - - if (allVisiblePanesDidLoad && this.isFirstLoad) { - Logger.append(LOG_ACTIONS_FIRST_DASHBOARD_LOAD, { - pane_ids: loadedPaneIds, - duration: new Date().getTime() - minQueryStartTime, - version: 'v2', - }); - Logger.send(this.actionLog); - this.isFirstLoad = false; - } - } - const currentChartIds = getChartIdsFromLayout(this.props.layout); const nextChartIds = getChartIdsFromLayout(nextProps.layout); @@ -240,7 +174,7 @@ class Dashboard extends React.PureComponent { return ( - + ); diff --git a/superset/assets/src/dashboard/components/Header.jsx b/superset/assets/src/dashboard/components/Header.jsx index d0714f3..bba1a72 100644 --- a/superset/assets/src/dashboard/components/Header.jsx +++ b/superset/assets/src/dashboard/components/Header.jsx @@ -35,6 +35,12 @@ import { } from '../util/constants'; import { safeStringify } from '../../utils/safeStringify'; +import { + LOG_ACTIONS_PERIODIC_RENDER_DASHBOARD, + LOG_ACTIONS_FORCE_REFRESH_DASHBOARD, + LOG_ACTIONS_TOGGLE_EDIT_DASHBOARD, +} from '../../logger/LogUtils'; + const propTypes = { addSuccessToast: PropTypes.func.isRequired, addDangerToast: PropTypes.func.isRequired, @@ -60,6 +66,7 @@ const propTypes = { showBuilderPane: PropTypes.bool.isRequired, toggleBuilderPane: PropTypes.func.isRequired, updateCss: PropTypes.func.isRequired, + logEvent: PropTypes.func.isRequired, hasUnsavedChanges: PropTypes.bool.isRequired, maxUndoHistoryExceeded: PropTypes.bool.isRequired, @@ -89,6 +96,7 @@ class Header extends React.PureComponent { this.handleCtrlY = this.handleCtrlY.bind(this); this.toggleEditMode = this.toggleEditMode.bind(this); this.forceRefresh = this.forceRefresh.bind(this); + this.startPeriodicRender = this.startPeriodicRender.bind(this); this.overwriteDashboard = this.overwriteDashboard.bind(this); } @@ -115,11 +123,25 @@ class Header extends React.PureComponent { forceRefresh() { if (!this.props.isLoading) { - return this.props.fetchCharts(Object.values(this.props.charts), true); + const chartList = Object.values(this.props.charts); + this.props.logEvent(LOG_ACTIONS_FORCE_REFRESH_DASHBOARD, { + force: true, + interval: 0, + chartCount: chartList.length, + }); + return this.props.fetchCharts(chartList, true); } return false; } + startPeriodicRender(interval) { + this.props.logEvent(LOG_ACTIONS_PERIODIC_RENDER_DASHBOARD, { + force: true, + interval, + }); + return this.props.startPeriodicRender(interval); + } + handleChangeText(nextText) { const { updateDashboardTitle, onChange } = this.props; if (nextText && this.props.dashboardTitle !== nextText) { @@ -150,6 +172,9 @@ class Header extends React.PureComponent { toggleEditMode() { this.props.setEditMode(!this.props.editMode); + this.props.logEvent(LOG_ACTIONS_TOGGLE_EDIT_DASHBOARD, { + editMode: !this.props.editMode, + }); } overwriteDashboard() { @@ -320,7 +345,7 @@ class Header extends React.PureComponent { onSave={onSave} onChange={onChange} forceRefreshAllCharts={this.forceRefresh} - startPeriodicRender={this.props.startPeriodicRender} + startPeriodicRender={this.startPeriodicRender} updateCss={updateCss} editMode={editMode} hasUnsavedChanges={hasUnsavedChanges} diff --git a/superset/assets/src/dashboard/components/SliceHeaderControls.jsx b/superset/assets/src/dashboard/components/SliceHeaderControls.jsx index b86b012..c228702 100644 --- a/superset/assets/src/dashboard/components/SliceHeaderControls.jsx +++ b/superset/assets/src/dashboard/components/SliceHeaderControls.jsx @@ -22,13 +22,6 @@ import moment from 'moment'; import { Dropdown, MenuItem } from 'react-bootstrap'; import { t } from '@superset-ui/translation'; -import { - Logger, - LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, - LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, - LOG_ACTIONS_REFRESH_CHART, -} from '../../logger'; - const propTypes = { slice: PropTypes.object.isRequired, isCached: PropTypes.bool, @@ -83,35 +76,15 @@ class SliceHeaderControls extends React.PureComponent { exportCSV() { this.props.exportCSV(this.props.slice.slice_id); - Logger.append( - LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, - { - slice_id: this.props.slice.slice_id, - is_cached: this.props.isCached, - }, - true, - ); } exploreChart() { this.props.exploreChart(this.props.slice.slice_id); - Logger.append( - LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, - { - slice_id: this.props.slice.slice_id, - is_cached: this.props.isCached, - }, - true, - ); } refreshChart() { if (this.props.updatedDttm) { this.props.forceRefresh(this.props.slice.slice_id); - Logger.append(LOG_ACTIONS_REFRESH_CHART, { - slice_id: this.props.slice.slice_id, - is_cached: this.props.isCached, - }); } } diff --git a/superset/assets/src/dashboard/components/gridComponents/Chart.jsx b/superset/assets/src/dashboard/components/gridComponents/Chart.jsx index 7d1f167..1765525 100644 --- a/superset/assets/src/dashboard/components/gridComponents/Chart.jsx +++ b/superset/assets/src/dashboard/components/gridComponents/Chart.jsx @@ -24,6 +24,12 @@ import SliceHeader from '../SliceHeader'; import ChartContainer from '../../../chart/ChartContainer'; import MissingChart from '../MissingChart'; import { slicePropShape, chartPropShape } from '../../util/propShapes'; +import { + LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, + LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, + LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, + LOG_ACTIONS_FORCE_REFRESH_CHART, +} from '../../../logger/LogUtils'; const propTypes = { id: PropTypes.number.isRequired, @@ -40,14 +46,20 @@ const propTypes = { timeout: PropTypes.number.isRequired, filters: PropTypes.object.isRequired, refreshChart: PropTypes.func.isRequired, + logEvent: PropTypes.func.isRequired, toggleExpandSlice: PropTypes.func.isRequired, addFilter: PropTypes.func.isRequired, editMode: PropTypes.bool.isRequired, isExpanded: PropTypes.bool.isRequired, + isCached: PropTypes.bool, supersetCanExplore: PropTypes.bool.isRequired, sliceCanEdit: PropTypes.bool.isRequired, }; +const defaultProps = { + isCached: false, +}; + // we use state + shouldComponentUpdate() logic to prevent perf-wrecking // resizing across all slices on a dashboard on every update const RESIZE_TIMEOUT = 350; @@ -133,19 +145,38 @@ class Chart extends React.Component { this.setState(() => ({ width, height })); } - addFilter(...args) { - this.props.addFilter(this.props.chart, ...args); + addFilter(...[col, vals, merge, refresh]) { + this.props.logEvent(LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, { + id: this.props.chart.id, + column: col, + value_count: Array.isArray(vals) ? vals.length : (vals && 1) || 0, + merge, + refresh, + }); + this.props.addFilter(this.props.chart, col, vals, merge, refresh); } exploreChart() { + this.props.logEvent(LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, { + slice_id: this.props.slice.slice_id, + is_cached: this.props.isCached, + }); exportChart(this.props.formData); } exportCSV() { + this.props.logEvent(LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, { + slice_id: this.props.slice.slice_id, + is_cached: this.props.isCached, + }); exportChart(this.props.formData, 'csv'); } forceRefresh() { + this.props.logEvent(LOG_ACTIONS_FORCE_REFRESH_CHART, { + slice_id: this.props.slice.slice_id, + is_cached: this.props.isCached, + }); return this.props.refreshChart(this.props.chart, true, this.props.timeout); } @@ -246,5 +277,6 @@ class Chart extends React.Component { } Chart.propTypes = propTypes; +Chart.defaultProps = defaultProps; export default Chart; diff --git a/superset/assets/src/dashboard/components/gridComponents/Markdown.jsx b/superset/assets/src/dashboard/components/gridComponents/Markdown.jsx index 0ec16de..a5614f1 100644 --- a/superset/assets/src/dashboard/components/gridComponents/Markdown.jsx +++ b/superset/assets/src/dashboard/components/gridComponents/Markdown.jsx @@ -36,6 +36,7 @@ import { GRID_MIN_ROW_UNITS, GRID_BASE_UNIT, } from '../../util/constants'; +import { Logger, LOG_ACTIONS_RENDER_CHART } from '../../../logger/LogUtils'; const propTypes = { id: PropTypes.string.isRequired, @@ -46,6 +47,9 @@ const propTypes = { depth: PropTypes.number.isRequired, editMode: PropTypes.bool.isRequired, + // from redux + logEvent: PropTypes.func.isRequired, + // grid related availableColumnCount: PropTypes.number.isRequired, columnWidth: PropTypes.number.isRequired, @@ -78,6 +82,7 @@ class Markdown extends React.PureComponent { editor: null, editorMode: 'preview', }; + this.renderStartTime = Logger.getTimestamp(); this.handleChangeFocus = this.handleChangeFocus.bind(this); this.handleChangeEditorMode = this.handleChangeEditorMode.bind(this); @@ -86,6 +91,15 @@ class Markdown extends React.PureComponent { this.setEditor = this.setEditor.bind(this); } + componentDidMount() { + this.props.logEvent(LOG_ACTIONS_RENDER_CHART, { + viz_type: 'markdown', + start_offset: this.renderStartTime, + ts: new Date().getTime(), + duration: Logger.getTimestamp() - this.renderStartTime, + }); + } + componentWillReceiveProps(nextProps) { const nextSource = nextProps.component.meta.code; if (this.state.markdownSource !== nextSource) { diff --git a/superset/assets/src/dashboard/components/gridComponents/Tabs.jsx b/superset/assets/src/dashboard/components/gridComponents/Tabs.jsx index 38e89b9..e899a4a 100644 --- a/superset/assets/src/dashboard/components/gridComponents/Tabs.jsx +++ b/superset/assets/src/dashboard/components/gridComponents/Tabs.jsx @@ -29,6 +29,7 @@ import { componentShape } from '../../util/propShapes'; import { NEW_TAB_ID, DASHBOARD_ROOT_ID } from '../../util/constants'; import { RENDER_TAB, RENDER_TAB_CONTENT } from './Tab'; import { TAB_TYPE } from '../../util/componentTypes'; +import { LOG_ACTIONS_SELECT_DASHBOARD_TAB } from '../../../logger/LogUtils'; const NEW_TAB_INDEX = -1; const MAX_TAB_COUNT = 7; @@ -43,6 +44,7 @@ const propTypes = { renderTabContent: PropTypes.bool, // whether to render tabs + content or just tabs editMode: PropTypes.bool.isRequired, renderHoverMenu: PropTypes.bool, + logEvent: PropTypes.func.isRequired, // grid related availableColumnCount: PropTypes.number, @@ -106,6 +108,11 @@ class Tabs extends React.PureComponent { }, }); } else if (tabIndex !== this.state.tabIndex) { + this.props.logEvent(LOG_ACTIONS_SELECT_DASHBOARD_TAB, { + id: component.id, + index: tabIndex, + }); + this.setState(() => ({ tabIndex })); this.props.onChangeTab({ tabIndex, tabId: component.children[tabIndex] }); } diff --git a/superset/assets/src/dashboard/containers/Chart.jsx b/superset/assets/src/dashboard/containers/Chart.jsx index 7d689ec..ddec2ff 100644 --- a/superset/assets/src/dashboard/containers/Chart.jsx +++ b/superset/assets/src/dashboard/containers/Chart.jsx @@ -24,6 +24,7 @@ import { toggleExpandSlice, } from '../actions/dashboardState'; import { refreshChart } from '../../chart/chartAction'; +import { logEvent } from '../../logger/actions'; import getFormDataWithExtraFilters from '../util/charts/getFormDataWithExtraFilters'; import { updateComponents } from '../actions/dashboardLayout'; import Chart from '../components/gridComponents/Chart'; @@ -73,6 +74,7 @@ function mapDispatchToProps(dispatch) { toggleExpandSlice, addFilter, refreshChart, + logEvent, }, dispatch, ); diff --git a/superset/assets/src/dashboard/containers/Dashboard.jsx b/superset/assets/src/dashboard/containers/Dashboard.jsx index 7a26f2e..865ec40 100644 --- a/superset/assets/src/dashboard/containers/Dashboard.jsx +++ b/superset/assets/src/dashboard/containers/Dashboard.jsx @@ -26,6 +26,7 @@ import { removeSliceFromDashboard, } from '../actions/dashboardState'; import { runQuery } from '../../chart/chartAction'; +import { logEvent } from '../../logger/actions'; import getLoadStatsPerTopLevelComponent from '../util/logging/getLoadStatsPerTopLevelComponent'; function mapStateToProps(state) { @@ -64,6 +65,7 @@ function mapDispatchToProps(dispatch) { addSliceToDashboard, removeSliceFromDashboard, runQuery, + logEvent, }, dispatch, ), diff --git a/superset/assets/src/dashboard/containers/DashboardComponent.jsx b/superset/assets/src/dashboard/containers/DashboardComponent.jsx index a64bf55..180fcd3 100644 --- a/superset/assets/src/dashboard/containers/DashboardComponent.jsx +++ b/superset/assets/src/dashboard/containers/DashboardComponent.jsx @@ -33,6 +33,8 @@ import { handleComponentDrop, } from '../actions/dashboardLayout'; +import { logEvent } from '../../logger/actions'; + const propTypes = { component: componentShape.isRequired, parentComponent: componentShape.isRequired, @@ -40,6 +42,7 @@ const propTypes = { deleteComponent: PropTypes.func.isRequired, updateComponents: PropTypes.func.isRequired, handleComponentDrop: PropTypes.func.isRequired, + logEvent: PropTypes.func.isRequired, }; function mapStateToProps( @@ -80,6 +83,7 @@ function mapDispatchToProps(dispatch) { deleteComponent, updateComponents, handleComponentDrop, + logEvent, }, dispatch, ); diff --git a/superset/assets/src/dashboard/containers/DashboardHeader.jsx b/superset/assets/src/dashboard/containers/DashboardHeader.jsx index fe96bf2..4eaca36 100644 --- a/superset/assets/src/dashboard/containers/DashboardHeader.jsx +++ b/superset/assets/src/dashboard/containers/DashboardHeader.jsx @@ -48,6 +48,8 @@ import { addWarningToast, } from '../../messageToasts/actions'; +import { logEvent } from '../../logger/actions'; + import { DASHBOARD_HEADER_ID } from '../util/constants'; function mapStateToProps({ @@ -98,6 +100,7 @@ function mapDispatchToProps(dispatch) { onSave: saveDashboardRequest, setMaxUndoHistoryExceeded, maxUndoHistoryToast, + logEvent, }, dispatch, ); diff --git a/superset/assets/src/explore/App.jsx b/superset/assets/src/explore/App.jsx index 3087614..c0fdcf5 100644 --- a/superset/assets/src/explore/App.jsx +++ b/superset/assets/src/explore/App.jsx @@ -24,6 +24,7 @@ import thunk from 'redux-thunk'; import { initFeatureFlags } from 'src/featureFlags'; import { initEnhancer } from '../reduxUtils'; +import logger from '../middleware/loggerMiddleware'; import ToastPresenter from '../messageToasts/containers/ToastPresenter'; import ExploreViewContainer from './components/ExploreViewContainer'; import getInitialState from './reducers/getInitialState'; @@ -46,7 +47,7 @@ const store = createStore( rootReducer, initState, compose( - applyMiddleware(thunk), + applyMiddleware(thunk, logger), initEnhancer(false), ), ); diff --git a/superset/assets/src/explore/components/ExploreViewContainer.jsx b/superset/assets/src/explore/components/ExploreViewContainer.jsx index 28355bc..9ef7e9e 100644 --- a/superset/assets/src/explore/components/ExploreViewContainer.jsx +++ b/superset/assets/src/explore/components/ExploreViewContainer.jsx @@ -34,7 +34,11 @@ import * as exploreActions from '../actions/exploreActions'; import * as saveModalActions from '../actions/saveModalActions'; import * as chartActions from '../../chart/chartAction'; import { fetchDatasourceMetadata } from '../../dashboard/actions/datasources'; -import { Logger, ActionLog, EXPLORE_EVENT_NAMES, LOG_ACTIONS_MOUNT_EXPLORER } from '../../logger'; +import * as logActions from '../../logger/actions/'; +import { + LOG_ACTIONS_MOUNT_EXPLORER, + LOG_ACTIONS_CHANGE_EXPLORE_CONTROLS, +} from '../../logger/LogUtils'; import Hotkeys from '../../components/Hotkeys'; // Prolly need to move this to a global context @@ -72,13 +76,6 @@ const propTypes = { class ExploreViewContainer extends React.Component { constructor(props) { super(props); - this.loadingLog = new ActionLog({ - impressionId: props.impressionId, - source: 'slice', - sourceId: props.slice ? props.slice.slice_id : 0, - eventNames: EXPLORE_EVENT_NAMES, - }); - Logger.start(this.loadingLog); this.state = { height: this.getHeight(), @@ -102,19 +99,10 @@ class ExploreViewContainer extends React.Component { window.addEventListener('popstate', this.handlePopstate); document.addEventListener('keydown', this.handleKeydown); this.addHistory({ isReplace: true }); - Logger.append(LOG_ACTIONS_MOUNT_EXPLORER); + this.props.actions.logEvent(LOG_ACTIONS_MOUNT_EXPLORER); } componentWillReceiveProps(nextProps) { - const wasRendered = - ['rendered', 'failed', 'stopped'].indexOf(this.props.chart.chartStatus) > -1; - const isRendered = ['rendered', 'failed', 'stopped'].indexOf(nextProps.chart.chartStatus) > -1; - if (nextProps.chart.id !== this.props.chart.id) { - this.loadingLog.sourceId = nextProps.chart.id; - } - if (!wasRendered && isRendered) { - Logger.send(this.loadingLog); - } if (nextProps.controls.viz_type.value !== this.props.controls.viz_type.value) { this.props.actions.resetControls(); this.props.actions.triggerQuery(true, this.props.chart.id); @@ -136,6 +124,7 @@ class ExploreViewContainer extends React.Component { this.props.actions.renderTriggered(new Date().getTime(), this.props.chart.id); } if (this.hasQueryControlChanged(changedControlKeys, nextProps.controls)) { + this.props.actions.logEvent(LOG_ACTIONS_CHANGE_EXPLORE_CONTROLS); this.setState({ chartIsStale: true, refreshOverlayVisible: true }); } } @@ -399,7 +388,12 @@ function mapStateToProps(state) { } function mapDispatchToProps(dispatch) { - const actions = Object.assign({}, exploreActions, saveModalActions, chartActions); + const actions = Object.assign({}, + exploreActions, + saveModalActions, + chartActions, + logActions, + ); return { actions: bindActionCreators(actions, dispatch), }; diff --git a/superset/assets/src/logger.js b/superset/assets/src/logger.js deleted file mode 100644 index 5bea387..0000000 --- a/superset/assets/src/logger.js +++ /dev/null @@ -1,183 +0,0 @@ -/** - * Licensed to the Apache Software Foundation (ASF) under one - * or more contributor license agreements. See the NOTICE file - * distributed with this work for additional information - * regarding copyright ownership. The ASF licenses this file - * to you under the Apache License, Version 2.0 (the - * "License"); you may not use this file except in compliance - * with the License. You may obtain a copy of the License at - * - * http://www.apache.org/licenses/LICENSE-2.0 - * - * Unless required by applicable law or agreed to in writing, - * software distributed under the License is distributed on an - * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY - * KIND, either express or implied. See the License for the - * specific language governing permissions and limitations - * under the License. - */ -/* eslint no-console: 0 */ -import { SupersetClient } from '@superset-ui/connection'; - -// This creates an association between an eventName and the ActionLog instance so that -// Logger.append calls do not have to know about the appropriate ActionLog instance -const addEventHandlers = {}; - -export const Logger = { - start(log) { - // create a handler to handle adding each event type - log.eventNames.forEach((eventName) => { - if (!addEventHandlers[eventName]) { - addEventHandlers[eventName] = log.addEvent.bind(log); - } else { - // eslint-disable-next-line no-console - console.warn(`Duplicate event handler for event '${eventName}'`); - } - }); - }, - - append(eventName, eventBody, sendNow) { - if (addEventHandlers[eventName]) { - addEventHandlers[eventName](eventName, eventBody, sendNow); - } else { - // eslint-disable-next-line no-console - console.warn(`No event handler for event '${eventName}'`); - } - }, - - end(log) { - this.send(log); - - // remove handlers - log.eventNames.forEach((eventName) => { - if (addEventHandlers[eventName]) { - delete addEventHandlers[eventName]; - } - }); - }, - - send(log) { - const { impressionId, source, sourceId, events } = log; - let endpoint = '/superset/log/?explode=events'; - - // backend logs treat these request params as first-class citizens - if (source === 'dashboard') { - endpoint += `&dashboard_id=${sourceId}`; - } else if (source === 'slice') { - endpoint += `&slice_id=${sourceId}`; - } - - const eventData = []; - for (const eventName in events) { - events[eventName].forEach((event) => { - eventData.push({ - source, - source_id: sourceId, - event_name: eventName, - impression_id: impressionId, - ...event, - }); - }); - } - - SupersetClient.post({ - endpoint, - postPayload: { events: eventData }, - parseMethod: null, - }); - - // flush events for this logger - log.events = {}; // eslint-disable-line no-param-reassign - }, - - // note that this returns ms since page load, NOT ms since epoc - getTimestamp() { - return Math.round(window.performance.now()); - }, -}; - -export class ActionLog { - constructor({ impressionId, source, sourceId, sendNow, eventNames }) { - this.impressionId = impressionId; - this.source = source; - this.sourceId = sourceId; - this.eventNames = eventNames || []; - this.sendNow = sendNow || false; - this.events = {}; - - this.addEvent = this.addEvent.bind(this); - } - - setAttribute(name, value) { - this[name] = value; - } - - addEvent(eventName, eventBody, sendNow) { - if (sendNow) { - Logger.send({ - ...this, - // overwrite events so that Logger.send doesn't clear this.events - events: { - [eventName]: [ - { - ts: new Date().getTime(), - start_offset: Logger.getTimestamp(), - ...eventBody, - }, - ], - }, - }); - } else { - this.events[eventName] = this.events[eventName] || []; - - this.events[eventName].push({ - ts: new Date().getTime(), - start_offset: Logger.getTimestamp(), - ...eventBody, - }); - - if (this.sendNow) { - Logger.send(this); - } - } - } -} - -// Log event types ------------------------------------------------------------ -export const LOG_ACTIONS_MOUNT_DASHBOARD = 'mount_dashboard'; -export const LOG_ACTIONS_MOUNT_EXPLORER = 'mount_explorer'; - -export const LOG_ACTIONS_FIRST_DASHBOARD_LOAD = 'first_dashboard_load'; -export const LOG_ACTIONS_LOAD_DASHBOARD_PANE = 'load_dashboard_pane'; -export const LOG_ACTIONS_LOAD_CHART = 'load_chart_data'; -export const LOG_ACTIONS_RENDER_CHART_CONTAINER = 'render_chart_container'; -export const LOG_ACTIONS_RENDER_CHART = 'render_chart'; -export const LOG_ACTIONS_REFRESH_CHART = 'force_refresh_chart'; - -export const LOG_ACTIONS_REFRESH_DASHBOARD = 'force_refresh_dashboard'; -export const LOG_ACTIONS_EXPLORE_DASHBOARD_CHART = 'explore_dashboard_chart'; -export const LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART = 'export_csv_dashboard_chart'; -export const LOG_ACTIONS_CHANGE_DASHBOARD_FILTER = 'change_dashboard_filter'; -export const LOG_ACTIONS_OMNIBAR_TRIGGERED = 'omnibar_dashboard_triggered'; - -export const DASHBOARD_EVENT_NAMES = [ - LOG_ACTIONS_MOUNT_DASHBOARD, - LOG_ACTIONS_FIRST_DASHBOARD_LOAD, - LOG_ACTIONS_LOAD_DASHBOARD_PANE, - LOG_ACTIONS_LOAD_CHART, - LOG_ACTIONS_RENDER_CHART, - LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, - LOG_ACTIONS_REFRESH_CHART, - LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, - LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, - LOG_ACTIONS_REFRESH_DASHBOARD, - LOG_ACTIONS_OMNIBAR_TRIGGERED, -]; - -export const EXPLORE_EVENT_NAMES = [ - LOG_ACTIONS_MOUNT_EXPLORER, - LOG_ACTIONS_LOAD_CHART, - LOG_ACTIONS_RENDER_CHART, - LOG_ACTIONS_REFRESH_CHART, - LOG_ACTIONS_RENDER_CHART_CONTAINER, -]; diff --git a/superset/assets/src/logger/LogUtils.js b/superset/assets/src/logger/LogUtils.js new file mode 100644 index 0000000..ce9aeac --- /dev/null +++ b/superset/assets/src/logger/LogUtils.js @@ -0,0 +1,63 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +// Log event names ------------------------------------------------------------ +export const LOG_ACTIONS_LOAD_CHART = 'load_chart'; +export const LOG_ACTIONS_RENDER_CHART = 'render_chart'; + +export const LOG_ACTIONS_MOUNT_DASHBOARD = 'mount_dashboard'; +export const LOG_ACTIONS_MOUNT_EXPLORER = 'mount_explorer'; + +export const LOG_ACTIONS_SELECT_DASHBOARD_TAB = 'select_dashboard_tab'; +export const LOG_ACTIONS_RENDER_CHART_CONTAINER = 'render_chart_container'; +export const LOG_ACTIONS_FORCE_REFRESH_CHART = 'force_refresh_chart'; +export const LOG_ACTIONS_CHANGE_EXPLORE_CONTROLS = 'change_explore_controls'; +export const LOG_ACTIONS_TOGGLE_EDIT_DASHBOARD = 'toggle_edit_dashboard'; +export const LOG_ACTIONS_FORCE_REFRESH_DASHBOARD = 'force_refresh_dashboard'; +export const LOG_ACTIONS_PERIODIC_RENDER_DASHBOARD = 'periodic_render_dashboard'; +export const LOG_ACTIONS_EXPLORE_DASHBOARD_CHART = 'explore_dashboard_chart'; +export const LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART = 'export_csv_dashboard_chart'; +export const LOG_ACTIONS_CHANGE_DASHBOARD_FILTER = 'change_dashboard_filter'; +export const LOG_ACTIONS_OMNIBAR_TRIGGERED = 'omnibar_triggered'; + +// Log event types -------------------------------------------------------------- +export const LOG_EVENT_TYPE_TIMING = new Set([ + LOG_ACTIONS_LOAD_CHART, + LOG_ACTIONS_RENDER_CHART, +]); +export const LOG_EVENT_TYPE_USER = new Set([ + LOG_ACTIONS_MOUNT_DASHBOARD, + LOG_ACTIONS_SELECT_DASHBOARD_TAB, + LOG_ACTIONS_EXPLORE_DASHBOARD_CHART, + LOG_ACTIONS_FORCE_REFRESH_CHART, + LOG_ACTIONS_EXPORT_CSV_DASHBOARD_CHART, + LOG_ACTIONS_CHANGE_DASHBOARD_FILTER, + LOG_ACTIONS_CHANGE_EXPLORE_CONTROLS, + LOG_ACTIONS_TOGGLE_EDIT_DASHBOARD, + LOG_ACTIONS_FORCE_REFRESH_DASHBOARD, + LOG_ACTIONS_OMNIBAR_TRIGGERED, + LOG_ACTIONS_MOUNT_EXPLORER, + LOG_ACTIONS_RENDER_CHART_CONTAINER, +]); + +export const Logger = { + // note that this returns ms since page load, NOT ms since epoc + getTimestamp() { + return Math.round(window.performance.now()); + }, +}; diff --git a/superset/assets/src/chart/ChartContainer.jsx b/superset/assets/src/logger/actions/index.js similarity index 71% copy from superset/assets/src/chart/ChartContainer.jsx copy to superset/assets/src/logger/actions/index.js index f677c5b..68c24c4 100644 --- a/superset/assets/src/chart/ChartContainer.jsx +++ b/superset/assets/src/logger/actions/index.js @@ -16,16 +16,16 @@ * specific language governing permissions and limitations * under the License. */ -import { connect } from 'react-redux'; -import { bindActionCreators } from 'redux'; +export const LOG_EVENT = 'LOG_EVENT'; -import * as actions from './chartAction'; -import Chart from './Chart'; - -function mapDispatchToProps(dispatch) { - return { - actions: bindActionCreators(actions, dispatch), - }; +export function logEvent(eventName, eventData) { + return dispatch => ( + dispatch({ + type: LOG_EVENT, + payload: { + eventName, + eventData, + }, + }) + ); } - -export default connect(null, mapDispatchToProps)(Chart); diff --git a/superset/assets/src/middleware/loggerMiddleware.js b/superset/assets/src/middleware/loggerMiddleware.js new file mode 100644 index 0000000..4c5a5f2 --- /dev/null +++ b/superset/assets/src/middleware/loggerMiddleware.js @@ -0,0 +1,117 @@ +/** + * Licensed to the Apache Software Foundation (ASF) under one + * or more contributor license agreements. See the NOTICE file + * distributed with this work for additional information + * regarding copyright ownership. The ASF licenses this file + * to you under the Apache License, Version 2.0 (the + * "License"); you may not use this file except in compliance + * with the License. You may obtain a copy of the License at + * + * http://www.apache.org/licenses/LICENSE-2.0 + * + * Unless required by applicable law or agreed to in writing, + * software distributed under the License is distributed on an + * "AS IS" BASIS, WITHOUT WARRANTIES OR CONDITIONS OF ANY + * KIND, either express or implied. See the License for the + * specific language governing permissions and limitations + * under the License. + */ +/* eslint-disable camelcase */ +/* eslint prefer-const: 2 */ +import shortid from 'shortid'; +import { SupersetClient } from '@superset-ui/connection'; + +import { safeStringify } from '../utils/safeStringify'; +import { LOG_EVENT } from '../logger/actions'; +import { LOG_EVENT_TYPE_TIMING } from '../logger/LogUtils'; +import DebouncedMessageQueue from '../utils/DebouncedMessageQueue'; + +const LOG_ENDPOINT = '/superset/log/?explode=events'; +const sendBeacon = (events) => { + if (events.length <= 0) { + return; + } + + let endpoint = LOG_ENDPOINT; + const { source, source_id } = events[0]; + // backend logs treat these request params as first-class citizens + if (source === 'dashboard') { + endpoint += `&dashboard_id=${source_id}`; + } else if (source === 'slice') { + endpoint += `&slice_id=${source_id}`; + } + + if (navigator.sendBeacon) { + const formData = new FormData(); + formData.append('events', safeStringify(events)); + navigator.sendBeacon(endpoint, formData); + } else { + SupersetClient.post({ + endpoint, + postPayload: { events }, + parseMethod: null, + }); + } +}; + +// beacon API has data size limit = 2^16. +// assume avg each log entry has 2^6 characters +const MAX_EVENTS_PER_REQUEST = 1024; +const logMessageQueue = new DebouncedMessageQueue({ + callback: sendBeacon, + sizeThreshold: MAX_EVENTS_PER_REQUEST, + delayThreshold: 1000, +}); +let lastEventId = 0; +const loggerMiddleware = store => next => (action) => { + if (action.type !== LOG_EVENT) { + return next(action); + } + + const { dashboardInfo, explore, impressionId } = store.getState(); + let logMetadata = { + impression_id: impressionId, + version: 'v2', + }; + if (dashboardInfo) { + logMetadata = { + source: 'dashboard', + source_id: dashboardInfo.id, + ...logMetadata, + }; + } else if (explore) { + logMetadata = { + source: 'slice', + source_id: explore.slice ? explore.slice.slice_id : 0, + ...logMetadata, + }; + } + + const { eventName } = action.payload; + let { eventData = {} } = action.payload; + eventData = { + ...logMetadata, + ts: new Date().getTime(), + event_name: eventName, + ...eventData, + }; + if (LOG_EVENT_TYPE_TIMING.has(eventName)) { + eventData = { + ...eventData, + event_type: 'timing', + trigger_event: lastEventId, + }; + } else { + lastEventId = shortid.generate(); + eventData = { + ...eventData, + event_type: 'user', + event_id: lastEventId, + }; + } + + logMessageQueue.append(eventData); + return eventData; +}; + +export default loggerMiddleware; diff --git a/superset/assets/src/chart/ChartContainer.jsx b/superset/assets/src/utils/DebouncedMessageQueue.js similarity index 51% copy from superset/assets/src/chart/ChartContainer.jsx copy to superset/assets/src/utils/DebouncedMessageQueue.js index f677c5b..70a46ff 100644 --- a/superset/assets/src/chart/ChartContainer.jsx +++ b/superset/assets/src/utils/DebouncedMessageQueue.js @@ -16,16 +16,32 @@ * specific language governing permissions and limitations * under the License. */ -import { connect } from 'react-redux'; -import { bindActionCreators } from 'redux'; +import { debounce } from 'lodash'; -import * as actions from './chartAction'; -import Chart from './Chart'; +class DebouncedMessageQueue { + constructor({ callback = () => {}, sizeThreshold = 1000, delayThreshold = 1000 }) { + this.queue = []; + this.sizeThreshold = sizeThreshold; + this.delayThrehold = delayThreshold; -function mapDispatchToProps(dispatch) { - return { - actions: bindActionCreators(actions, dispatch), - }; + this.trigger = debounce(this.trigger.bind(this), this.delayThrehold); + this.callback = callback; + } + append(eventData) { + this.queue.push(eventData); + this.trigger(); + } + trigger() { + if (this.queue.length > 0) { + const events = this.queue.splice(0, this.sizeThreshold); + this.callback.call(null, events); + + // If there are remaining items, call it again. + if (this.queue.length > 0) { + this.trigger(); + } + } + } } -export default connect(null, mapDispatchToProps)(Chart); +export default DebouncedMessageQueue; diff --git a/superset/config.py b/superset/config.py index d038816..8011128 100644 --- a/superset/config.py +++ b/superset/config.py @@ -96,7 +96,7 @@ QUERY_SEARCH_LIMIT = 1000 WTF_CSRF_ENABLED = True # Add endpoints that need to be exempt from CSRF protection -WTF_CSRF_EXEMPT_LIST = [] +WTF_CSRF_EXEMPT_LIST = ['superset.views.core.log'] # Whether to run the web server in debug mode or not DEBUG = os.environ.get('FLASK_ENV') == 'development'