Skip to content

Commit

Permalink
Merge pull request apache#5 from airbnb/gg-CherryPickLogger
Browse files Browse the repository at this point in the history
add frontend logging utility function (apache#4226)
  • Loading branch information
Grace Guo authored Jan 31, 2018
2 parents 07cc89f + 5ba6d3e commit 310edae
Show file tree
Hide file tree
Showing 13 changed files with 215 additions and 6 deletions.
9 changes: 9 additions & 0 deletions superset/assets/javascripts/chart/Chart.jsx
Original file line number Diff line number Diff line change
Expand Up @@ -6,6 +6,7 @@ import Mustache from 'mustache';
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';
Expand Down Expand Up @@ -144,13 +145,21 @@ 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) {
qr.data = sandboxedEval(fd.js_data)(qr.data);
}
// [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);
}
Expand Down
29 changes: 28 additions & 1 deletion superset/assets/javascripts/chart/chartAction.js
Original file line number Diff line number Diff line change
@@ -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');

Expand Down Expand Up @@ -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 };
Expand Down Expand Up @@ -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') {
Expand Down
5 changes: 5 additions & 0 deletions superset/assets/javascripts/chart/chartReducer.js
Original file line number Diff line number Diff line change
Expand Up @@ -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',
Expand Down
22 changes: 21 additions & 1 deletion superset/assets/javascripts/dashboard/components/Dashboard.jsx
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand All @@ -21,6 +23,7 @@ const propTypes = {
userId: PropTypes.string,
isStarred: PropTypes.bool,
editMode: PropTypes.bool,
impressionId: PropTypes.string,
};

const defaultProps = {
Expand All @@ -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 };
Expand Down Expand Up @@ -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);
Expand Down
Original file line number Diff line number Diff line change
Expand Up @@ -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,
Expand All @@ -17,6 +17,7 @@ function mapStateToProps({ charts, dashboard }) {
userId: dashboard.userId,
isStarred: !!dashboard.isStarred,
editMode: dashboard.editMode,
impressionId,
};
}

Expand Down
2 changes: 2 additions & 0 deletions superset/assets/javascripts/dashboard/reducers.js
Original file line number Diff line number Diff line change
@@ -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';
Expand Down Expand Up @@ -200,4 +201,5 @@ export const dashboard = function (state = {}, action) {
export default combineReducers({
charts,
dashboard,
impressionId: () => (shortid.generate()),
});
Original file line number Diff line number Diff line change
Expand Up @@ -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(),
Expand All @@ -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);
Expand Down Expand Up @@ -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];
Expand All @@ -220,6 +238,7 @@ function mapStateToProps({ explore, charts }) {
forcedHeight: explore.forced_height,
chart,
timeout: explore.common.conf.SUPERSET_WEBSERVER_TIMEOUT,
impressionId,
};
}

Expand Down
2 changes: 2 additions & 0 deletions superset/assets/javascripts/explore/index.jsx
Original file line number Diff line number Diff line change
Expand Up @@ -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';
Expand Down Expand Up @@ -64,6 +65,7 @@ const initState = {
saveModalAlert: null,
},
explore: bootstrappedState,
impressionId: shortid.generate(),
};
const store = createStore(rootReducer, initState,
compose(applyMiddleware(thunk), initEnhancer(false)),
Expand Down
2 changes: 2 additions & 0 deletions superset/assets/javascripts/explore/reducers/index.js
Original file line number Diff line number Diff line change
@@ -1,4 +1,5 @@
import { combineReducers } from 'redux';
import shortid from 'shortid';

import charts from '../../chart/chartReducer';
import saveModal from './saveModalReducer';
Expand All @@ -8,4 +9,5 @@ export default combineReducers({
charts,
saveModal,
explore,
impressionId: () => (shortid.generate()),
});
114 changes: 114 additions & 0 deletions superset/assets/javascripts/logger.js
Original file line number Diff line number Diff line change
@@ -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 = {};
}
}
}
1 change: 1 addition & 0 deletions superset/assets/spec/helpers/browser.js
Original file line number Diff line number Diff line change
Expand Up @@ -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);
Loading

0 comments on commit 310edae

Please sign in to comment.