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 724c3f4 add frontend logging utility function (#4226)
724c3f4 is described below
commit 724c3f48a4395b4979b08f0c7f305067c3bf0ca6
Author: Grace Guo <[email protected]>
AuthorDate: Tue Jan 30 10:27:13 2018 -0800
add frontend logging utility function (#4226)
add loading log for dash and exploreview
breakdown whole page load action to multiple charts loading events and
render events
---
superset/assets/javascripts/chart/Chart.jsx | 9 ++
superset/assets/javascripts/chart/chartAction.js | 29 +++++-
superset/assets/javascripts/chart/chartReducer.js | 5 +
.../javascripts/dashboard/components/Dashboard.jsx | 22 +++-
.../dashboard/components/DashboardContainer.jsx | 3 +-
superset/assets/javascripts/dashboard/reducers.js | 2 +
.../explore/components/ExploreViewContainer.jsx | 23 ++++-
superset/assets/javascripts/explore/index.jsx | 2 +
.../assets/javascripts/explore/reducers/index.js | 2 +
superset/assets/javascripts/logger.js | 114 +++++++++++++++++++++
superset/assets/spec/helpers/browser.js | 1 +
superset/models/core.py | 2 +-
superset/views/core.py | 7 ++
13 files changed, 215 insertions(+), 6 deletions(-)
diff --git a/superset/assets/javascripts/chart/Chart.jsx
b/superset/assets/javascripts/chart/Chart.jsx
index e1502a3..d370c79 100644
--- a/superset/assets/javascripts/chart/Chart.jsx
+++ b/superset/assets/javascripts/chart/Chart.jsx
@@ -7,6 +7,7 @@ import { Tooltip } from 'react-bootstrap';
import { d3format } from '../modules/utils';
import ChartBody from './ChartBody';
import Loading from '../components/Loading';
+import { Logger, LOG_ACTIONS_RENDER_EVENT } from '../logger';
import StackTraceMessage from '../components/StackTraceMessage';
import visMap from '../../visualizations/main';
import sandboxedEval from '../modules/sandbox';
@@ -171,6 +172,7 @@ class Chart extends React.PureComponent {
const viz = visMap[this.props.vizType];
const fd = this.props.formData;
const qr = this.props.queryResponse;
+ const renderStart = Logger.getTimestamp();
try {
// Executing user-defined data mutator function
if (fd.js_data) {
@@ -178,6 +180,13 @@ class Chart extends React.PureComponent {
}
// [re]rendering the visualization
viz(this, qr, this.props.setControlValue);
+ Logger.append(LOG_ACTIONS_RENDER_EVENT, {
+ label: this.props.chartKey,
+ vis_type: this.props.vizType,
+ start_offset: renderStart,
+ duration: Logger.getTimestamp() - renderStart,
+ });
+ this.props.actions.chartRenderingSucceeded(this.props.chartKey);
} catch (e) {
this.props.actions.chartRenderingFailed(e, this.props.chartKey);
}
diff --git a/superset/assets/javascripts/chart/chartAction.js
b/superset/assets/javascripts/chart/chartAction.js
index 393400d..3682949 100644
--- a/superset/assets/javascripts/chart/chartAction.js
+++ b/superset/assets/javascripts/chart/chartAction.js
@@ -1,5 +1,6 @@
import { getExploreUrl, getAnnotationJsonUrl } from '../explore/exploreUtils';
import { requiresQuery, ANNOTATION_SOURCE_TYPES } from
'../modules/AnnotationTypes';
+import { Logger, LOG_ACTIONS_LOAD_EVENT } from '../logger';
const $ = window.$ = require('jquery');
@@ -36,6 +37,11 @@ export function chartRenderingFailed(error, key) {
return { type: CHART_RENDERING_FAILED, error, key };
}
+export const CHART_RENDERING_SUCCEEDED = 'CHART_RENDERING_SUCCEEDED';
+export function chartRenderingSucceeded(key) {
+ return { type: CHART_RENDERING_SUCCEEDED, key };
+}
+
export const REMOVE_CHART = 'REMOVE_CHART';
export function removeChart(key) {
return { type: REMOVE_CHART, key };
@@ -107,16 +113,37 @@ export const RUN_QUERY = 'RUN_QUERY';
export function runQuery(formData, force = false, timeout = 60, key) {
return (dispatch) => {
const url = getExploreUrl(formData, 'json', force);
+ let logStart;
const queryRequest = $.ajax({
url,
dataType: 'json',
timeout: timeout * 1000,
+ beforeSend: () => {
+ logStart = Logger.getTimestamp();
+ },
});
const queryPromise =
Promise.resolve(dispatch(chartUpdateStarted(queryRequest, key)))
.then(() => queryRequest)
- .then(queryResponse => dispatch(chartUpdateSucceeded(queryResponse,
key)))
+ .then((queryResponse) => {
+ Logger.append(LOG_ACTIONS_LOAD_EVENT, {
+ label: key,
+ is_cached: queryResponse.is_cached,
+ row_count: queryResponse.rowcount,
+ datasource: formData.datasource,
+ start_offset: logStart,
+ duration: Logger.getTimestamp() - logStart,
+ });
+ return dispatch(chartUpdateSucceeded(queryResponse, key));
+ })
.catch((err) => {
+ Logger.append(LOG_ACTIONS_LOAD_EVENT, {
+ label: key,
+ has_err: true,
+ datasource: formData.datasource,
+ start_offset: logStart,
+ duration: Logger.getTimestamp() - logStart,
+ });
if (err.statusText === 'timeout') {
dispatch(chartUpdateTimeout(err.statusText, timeout, key));
} else if (err.statusText !== 'abort') {
diff --git a/superset/assets/javascripts/chart/chartReducer.js
b/superset/assets/javascripts/chart/chartReducer.js
index 3cc9e5e..e1dfe05 100644
--- a/superset/assets/javascripts/chart/chartReducer.js
+++ b/superset/assets/javascripts/chart/chartReducer.js
@@ -55,6 +55,11 @@ export default function chartReducer(charts = {}, action) {
chartAlert: t('Updating chart was stopped'),
};
},
+ [actions.CHART_RENDERING_SUCCEEDED](state) {
+ return { ...state,
+ chartStatus: 'rendered',
+ };
+ },
[actions.CHART_RENDERING_FAILED](state) {
return { ...state,
chartStatus: 'failed',
diff --git a/superset/assets/javascripts/dashboard/components/Dashboard.jsx
b/superset/assets/javascripts/dashboard/components/Dashboard.jsx
index cc85cad..c99c293 100644
--- a/superset/assets/javascripts/dashboard/components/Dashboard.jsx
+++ b/superset/assets/javascripts/dashboard/components/Dashboard.jsx
@@ -5,6 +5,8 @@ import AlertsWrapper from '../../components/AlertsWrapper';
import GridLayout from './GridLayout';
import Header from './Header';
import { areObjectsEqual } from '../../reduxUtils';
+import { Logger, ActionLog, LOG_ACTIONS_PAGE_LOAD,
+ LOG_ACTIONS_LOAD_EVENT, LOG_ACTIONS_RENDER_EVENT } from '../../logger';
import { t } from '../../locales';
import '../../../stylesheets/dashboard.css';
@@ -21,6 +23,7 @@ const propTypes = {
userId: PropTypes.string,
isStarred: PropTypes.bool,
editMode: PropTypes.bool,
+ impressionId: PropTypes.string,
};
const defaultProps = {
@@ -41,6 +44,14 @@ class Dashboard extends React.PureComponent {
super(props);
this.refreshTimer = null;
this.firstLoad = true;
+ this.loadingLog = new ActionLog({
+ impressionId: props.impressionId,
+ actionType: LOG_ACTIONS_PAGE_LOAD,
+ source: 'dashboard',
+ sourceId: props.dashboard.id,
+ eventNames: [LOG_ACTIONS_LOAD_EVENT, LOG_ACTIONS_RENDER_EVENT],
+ });
+ Logger.start(this.loadingLog);
// alert for unsaved changes
this.state = { unsavedChanges: false };
@@ -68,10 +79,19 @@ class Dashboard extends React.PureComponent {
}
componentDidMount() {
- this.firstLoad = false;
window.addEventListener('resize', this.rerenderCharts);
}
+ componentWillReceiveProps(nextProps) {
+ if (this.firstLoad &&
+ Object.values(nextProps.slices)
+ .every(slice => (['rendered', 'failed',
'stopped'].indexOf(slice.chartStatus) > -1))
+ ) {
+ Logger.end(this.loadingLog);
+ this.firstLoad = false;
+ }
+ }
+
componentDidUpdate(prevProps) {
if (!areObjectsEqual(prevProps.filters, this.props.filters) &&
this.props.refresh) {
const currentFilterKeys = Object.keys(this.props.filters);
diff --git
a/superset/assets/javascripts/dashboard/components/DashboardContainer.jsx
b/superset/assets/javascripts/dashboard/components/DashboardContainer.jsx
index 092caf6..a18a5d2 100644
--- a/superset/assets/javascripts/dashboard/components/DashboardContainer.jsx
+++ b/superset/assets/javascripts/dashboard/components/DashboardContainer.jsx
@@ -5,7 +5,7 @@ import * as dashboardActions from '../actions';
import * as chartActions from '../../chart/chartAction';
import Dashboard from './Dashboard';
-function mapStateToProps({ charts, dashboard }) {
+function mapStateToProps({ charts, dashboard, impressionId }) {
return {
initMessages: dashboard.common.flash_messages,
timeout: dashboard.common.conf.SUPERSET_WEBSERVER_TIMEOUT,
@@ -17,6 +17,7 @@ function mapStateToProps({ charts, dashboard }) {
userId: dashboard.userId,
isStarred: !!dashboard.isStarred,
editMode: dashboard.editMode,
+ impressionId,
};
}
diff --git a/superset/assets/javascripts/dashboard/reducers.js
b/superset/assets/javascripts/dashboard/reducers.js
index 0ee7964..1e37aca 100644
--- a/superset/assets/javascripts/dashboard/reducers.js
+++ b/superset/assets/javascripts/dashboard/reducers.js
@@ -1,5 +1,6 @@
import { combineReducers } from 'redux';
import d3 from 'd3';
+import shortid from 'shortid';
import charts, { chart } from '../chart/chartReducer';
import * as actions from './actions';
@@ -200,4 +201,5 @@ export const dashboard = function (state = {}, action) {
export default combineReducers({
charts,
dashboard,
+ impressionId: () => (shortid.generate()),
});
diff --git
a/superset/assets/javascripts/explore/components/ExploreViewContainer.jsx
b/superset/assets/javascripts/explore/components/ExploreViewContainer.jsx
index 835cc1a..bf9afd4 100644
--- a/superset/assets/javascripts/explore/components/ExploreViewContainer.jsx
+++ b/superset/assets/javascripts/explore/components/ExploreViewContainer.jsx
@@ -15,23 +15,36 @@ import { chartPropType } from '../../chart/chartReducer';
import * as exploreActions from '../actions/exploreActions';
import * as saveModalActions from '../actions/saveModalActions';
import * as chartActions from '../../chart/chartAction';
+import { Logger, ActionLog, LOG_ACTIONS_PAGE_LOAD,
+ LOG_ACTIONS_LOAD_EVENT, LOG_ACTIONS_RENDER_EVENT } from '../../logger';
const propTypes = {
actions: PropTypes.object.isRequired,
datasource_type: PropTypes.string.isRequired,
isDatasourceMetaLoading: PropTypes.bool.isRequired,
- chartStatus: PropTypes.string,
chart: PropTypes.shape(chartPropType).isRequired,
+ slice: PropTypes.object,
controls: PropTypes.object.isRequired,
forcedHeight: PropTypes.string,
form_data: PropTypes.object.isRequired,
standalone: PropTypes.bool.isRequired,
timeout: PropTypes.number,
+ impressionId: PropTypes.string,
};
class ExploreViewContainer extends React.Component {
constructor(props) {
super(props);
+ this.firstLoad = true;
+ this.loadingLog = new ActionLog({
+ impressionId: props.impressionId,
+ actionType: LOG_ACTIONS_PAGE_LOAD,
+ source: 'slice',
+ sourceId: props.slice ? props.slice.slice_id : 0,
+ eventNames: [LOG_ACTIONS_LOAD_EVENT, LOG_ACTIONS_RENDER_EVENT],
+ });
+ Logger.start(this.loadingLog);
+
this.state = {
height: this.getHeight(),
width: this.getWidth(),
@@ -44,6 +57,11 @@ class ExploreViewContainer extends React.Component {
}
componentWillReceiveProps(np) {
+ if (this.firstLoad &&
+ ['rendered', 'failed', 'stopped'].indexOf(np.chart.chartStatus) > -1) {
+ Logger.end(this.loadingLog);
+ this.firstLoad = false;
+ }
if (np.controls.viz_type.value !== this.props.controls.viz_type.value) {
this.props.actions.resetControls();
this.props.actions.triggerQuery(true, this.props.chart.chartKey);
@@ -197,7 +215,7 @@ class ExploreViewContainer extends React.Component {
ExploreViewContainer.propTypes = propTypes;
-function mapStateToProps({ explore, charts }) {
+function mapStateToProps({ explore, charts, impressionId }) {
const form_data = getFormDataFromControls(explore.controls);
const chartKey = Object.keys(charts)[0];
const chart = charts[chartKey];
@@ -220,6 +238,7 @@ function mapStateToProps({ explore, charts }) {
forcedHeight: explore.forced_height,
chart,
timeout: explore.common.conf.SUPERSET_WEBSERVER_TIMEOUT,
+ impressionId,
};
}
diff --git a/superset/assets/javascripts/explore/index.jsx
b/superset/assets/javascripts/explore/index.jsx
index d66ad52..35eb68d 100644
--- a/superset/assets/javascripts/explore/index.jsx
+++ b/superset/assets/javascripts/explore/index.jsx
@@ -5,6 +5,7 @@ import { createStore, applyMiddleware, compose } from 'redux';
import { Provider } from 'react-redux';
import thunk from 'redux-thunk';
+import shortid from 'shortid';
import { now } from '../modules/dates';
import { initEnhancer } from '../reduxUtils';
import { getChartKey } from './exploreUtils';
@@ -64,6 +65,7 @@ const initState = {
saveModalAlert: null,
},
explore: bootstrappedState,
+ impressionId: shortid.generate(),
};
const store = createStore(rootReducer, initState,
compose(applyMiddleware(thunk), initEnhancer(false)),
diff --git a/superset/assets/javascripts/explore/reducers/index.js
b/superset/assets/javascripts/explore/reducers/index.js
index 22f7e8f..13d0ed1 100644
--- a/superset/assets/javascripts/explore/reducers/index.js
+++ b/superset/assets/javascripts/explore/reducers/index.js
@@ -1,4 +1,5 @@
import { combineReducers } from 'redux';
+import shortid from 'shortid';
import charts from '../../chart/chartReducer';
import saveModal from './saveModalReducer';
@@ -8,4 +9,5 @@ export default combineReducers({
charts,
saveModal,
explore,
+ impressionId: () => (shortid.generate()),
});
diff --git a/superset/assets/javascripts/logger.js
b/superset/assets/javascripts/logger.js
new file mode 100644
index 0000000..c7823fc
--- /dev/null
+++ b/superset/assets/javascripts/logger.js
@@ -0,0 +1,114 @@
+import $ from 'jquery';
+
+export const LOG_ACTIONS_PAGE_LOAD = 'page_load_perf';
+export const LOG_ACTIONS_LOAD_EVENT = 'load_events';
+export const LOG_ACTIONS_RENDER_EVENT = 'render_events';
+
+const handlers = {};
+
+export const Logger = {
+ start(log) {
+ log.setAttribute('startAt', new Date().getTime() - this.getTimestamp());
+ log.eventNames.forEach((eventName) => {
+ if (!handlers[eventName]) {
+ handlers[eventName] = [];
+ }
+ handlers[eventName].push(log.addEvent.bind(log));
+ });
+ },
+
+ append(eventName, eventBody) {
+ return handlers[eventName].length &&
+ handlers[eventName].forEach(handler => (handler(eventName, eventBody)));
+ },
+
+ end(log) {
+ log.setAttribute('duration', new Date().getTime() - log.startAt);
+ this.send(log);
+
+ log.eventNames.forEach((eventName) => {
+ if (handlers[eventName].length) {
+ const index = handlers[eventName]
+ .findIndex(handler => (handler === log.addEvent));
+ handlers[eventName].splice(index, 1);
+ }
+ });
+ },
+
+ send(log) {
+ const { impressionId, actionType, source, sourceId, events, startAt,
duration } = log;
+ const requestPrams = [];
+ requestPrams.push(['impression_id', impressionId]);
+ switch (source) {
+ case 'dashboard':
+ requestPrams.push(['dashboard_id', sourceId]);
+ break;
+ case 'slice':
+ requestPrams.push(['slice_id', sourceId]);
+ break;
+ default:
+ break;
+ }
+ let url = '/superset/log/';
+ if (requestPrams.length) {
+ url += '?' + requestPrams.map(([k, v]) => (k + '=' + v)).join('&');
+ }
+ const eventData = {};
+ for (const eventName in events) {
+ eventData[eventName] = [];
+ events[eventName].forEach((event) => {
+ eventData[eventName].push(event);
+ });
+ }
+
+ $.ajax({
+ url,
+ method: 'POST',
+ dataType: 'json',
+ data: {
+ source: 'client',
+ type: actionType,
+ started_time: startAt,
+ duration,
+ events: JSON.stringify(eventData),
+ },
+ });
+ },
+
+ getTimestamp() {
+ return Math.round(window.performance.now());
+ },
+};
+
+export class ActionLog {
+ constructor({ impressionId, actionType, source, sourceId, eventNames,
sendNow }) {
+ this.impressionId = impressionId;
+ this.source = source;
+ this.sourceId = sourceId;
+ this.actionType = actionType;
+ this.eventNames = eventNames;
+ this.sendNow = sendNow || false;
+ this.startAt = 0;
+ this.duration = 0;
+ this.events = {};
+
+ this.addEvent = this.addEvent.bind(this);
+ }
+
+ setAttribute(name, value) {
+ this[name] = value;
+ }
+
+ addEvent(eventName, eventBody) {
+ if (!this.events[eventName]) {
+ this.events[eventName] = [];
+ }
+ this.events[eventName].push(eventBody);
+
+ if (this.sendNow) {
+ this.setAttribute('duration', new Date().getTime() - this.startAt);
+ Logger.send(this);
+ this.events = {};
+ }
+ }
+}
diff --git a/superset/assets/spec/helpers/browser.js
b/superset/assets/spec/helpers/browser.js
index 638a63d..d465d86 100644
--- a/superset/assets/spec/helpers/browser.js
+++ b/superset/assets/spec/helpers/browser.js
@@ -38,4 +38,5 @@ global.sinon.useFakeXMLHttpRequest();
global.window.XMLHttpRequest = global.XMLHttpRequest;
global.window.location = { href: 'about:blank' };
+global.window.performance = { now: () => (new Date().getTime()) };
global.$ = require('jquery')(global.window);
diff --git a/superset/models/core.py b/superset/models/core.py
index 1b71d42..142482b 100644
--- a/superset/models/core.py
+++ b/superset/models/core.py
@@ -860,7 +860,7 @@ class Log(Model):
if g.user:
user_id = g.user.get_id()
d = request.args.to_dict()
- post_data = request.form or {}
+ post_data = request.form.to_dict() or {}
d.update(post_data)
d.update(kwargs)
slice_id = d.get('slice_id')
diff --git a/superset/views/core.py b/superset/views/core.py
index db905f3..0f0adea 100755
--- a/superset/views/core.py
+++ b/superset/views/core.py
@@ -1974,6 +1974,13 @@ class Superset(BaseSupersetView):
bootstrap_data=json.dumps(bootstrap_data),
)
+ @api
+ @has_access_api
+ @log_this
+ @expose('/log/', methods=['POST'])
+ def log(self):
+ return Response(status=200)
+
@has_access
@expose('/sync_druid/', methods=['POST'])
@log_this
--
To stop receiving notification emails like this one, please contact
[email protected].
