Add frontend logging functions and log loading time for Dashboard and explore view #4226

graceguo-supercat · 2018-01-17T19:02:54Z

add frontend logging functions
add loading log for dash and explore view, also breakdown dash to multiple charts loading time.

This Logger module provides an event-based logging system. Log events are independent of log type (for example page_load_perf). We can define different log type, and attach some new events for other tracking purpose.

Dashboard loading log sample:
Request:
http://localhost:8080/superset/log/?impression_id=rybDJ7xdrf&dashboard_id=35

Post body:
{
source:client
type:page_load_perf
started_time:1516925660209
duration:4539
events:{"load_events":[{"label":"slice_44","is_cached":false,"row_count":37,"start_offset":3366,"duration":759},{"label":"slice_240","is_cached":false,"row_count":385,"start_offset":3357,"duration":961},{"label":"slice_53","is_cached":false,"row_count":14,"start_offset":3378,"duration":1143}],"render_events":[{"label":"slice_44","vis_type":"dist_bar","start_offset":4140,"duration":1},{"label":"slice_240","vis_type":"area","start_offset":4327,"duration":0},{"label":"slice_53","vis_type":"big_number","start_offset":4530,"duration":8}]}
}

source: for client action logging
type: I will use page_load_perf for all dashboard/ explore view page load performance tracking.
started_time: timestamp for page load start
duration: from page load till all charts are rendered (or error-out)
events is serialized json object, which has render_events list and load_events list like this:

events: {
    "load_events": [{
        "label": "slice_44",
        "is_cached": false,
        "row_count": 37,
        "start_offset": 3366,
        "duration": 759
    }, {
        "label": "slice_240",
        "is_cached": false,
        "row_count": 385,
        "start_offset": 3357,
        "duration": 961
    }, {
        "label": "slice_53",
        "is_cached": false,
        "row_count": 14,
        "start_offset": 3378,
        "duration": 1143
    }],
    "render_events": [{
        "label": "slice_44",
        "vis_type": "dist_bar",
        "start_offset": 4140,
        "duration": 1
    }, {
        "label": "slice_240",
        "vis_type": "area",
        "start_offset": 4327,
        "duration": 0
    }, {
        "label": "slice_53",
        "vis_type": "big_number",
        "start_offset": 4530,
        "duration": 8
    }]
}

@john-bodley @michellethomas @timifasubaa @williaster @fabianmenges

williaster · 2018-01-19T09:14:37Z

superset/assets/javascripts/chart/chartAction.js

+          startAt: logStart,
+          duration: Logger.getTimestamp() - logStart,
+        });
+        dispatch(chartUpdateSucceeded(queryResponse, key));


I think for redux/promise chaining you need to return the dispatch? which this function did before. I think it's not broken now but if you were to chain something else that might not work.

Yes. should return dispatch.

williaster · 2018-01-19T09:17:32Z

superset/assets/javascripts/logger.js

+
+  send(log) {
+    const { action, containerId, events, startAt, duration } = log;
+    const url = `/superset/${action}/?${action === LOG_ACTIONS_LOAD_DASHBOARD ? 'dashboard_id' : 'slice_id'}=${containerId}`;


this breaks if there are more than two types of load actions yeah? could we make it check each explicitly?

i changed the way tracking type of load actions. i added source and sourceId attributes in ActionLog instance.

williaster · 2018-01-19T09:24:18Z

superset/assets/javascripts/explore/components/ExploreViewContainer.jsx

+  componentWillMount() {
+    this.actionLog = new ActionLog({
+      action: LOG_ACTIONS_LOAD_EXPLORE,
+      containerId: this.props.slice.slice_id,


do you think this should just be id? it's not exactly a container. cc @john-bodley

also what if an explore view doesn't have a slice id/isn't saved?

in existed logs table, for explore view without existed slice_id, the log entry will have slice_id=0

williaster · 2018-01-19T09:26:36Z

superset/assets/javascripts/logger.js

+    const url = `/superset/${action}/?${action === LOG_ACTIONS_LOAD_DASHBOARD ? 'dashboard_id' : 'slice_id'}=${containerId}`;
+    const eventData = {};
+    events.forEach((event) => {
+      const { label, ...eventBody } = event;


it seems like label is functioning more like an event name or event key, and all other object keys implicitly get mapped to meta data. could we make the format of the logs more explicit and generic by having only event (or eventName, to replace label) and meta keys, where meta is an object of anything?

cc @john-bodley for naming/formatting.

williaster · 2018-01-19T09:29:51Z

superset/assets/javascripts/logger.js

+
+export const LOG_ACTIONS_LOAD_DASHBOARD = 'load_dashboard';
+export const LOG_ACTIONS_LOAD_EXPLORE = 'load_explore';
+export const LOAD_EVENT = 'load';


it seem strange to add LOG_ACTIONS_ as a prefix for actions but nothing for event names. what do you think of also adding LOG_EVENTS_ as a prefix for this?

timifasubaa · 2018-01-29T23:13:42Z

PING

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events

mistercrunch · 2018-01-30T05:27:00Z

LGTM

graceguo-supercat · 2018-01-30T18:27:05Z

🎆

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events (cherry picked from commit 724c3f4)

mistercrunch · 2018-01-31T06:37:27Z

I think this broke the <CachedLabel/> and rowcount label. Fix here #4316

add frontend logging utility function (apache#4226)

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events

graceguo-supercat requested a review from mistercrunch January 17, 2018 19:02

graceguo-supercat changed the title ~~add frontend logging functions~~ add frontend logging functions and log loading time for Dashboard and explore view Jan 17, 2018

williaster reviewed Jan 19, 2018

View reviewed changes

graceguo-supercat force-pushed the gg-LoadingTimeLogging branch from 4aec8a9 to aa7ad14 Compare January 21, 2018 08:05

graceguo-supercat changed the title ~~add frontend logging functions and log loading time for Dashboard and explore view~~ [WiP]add frontend logging functions and log loading time for Dashboard and explore view Jan 24, 2018

graceguo-supercat force-pushed the gg-LoadingTimeLogging branch 4 times, most recently from 15c24bb to 2cfe667 Compare January 26, 2018 00:53

graceguo-supercat changed the title ~~[WiP]add frontend logging functions and log loading time for Dashboard and explore view~~ Add frontend logging functions and log loading time for Dashboard and explore view Jan 26, 2018

add frontend logging utility function

d24d596

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events

graceguo-supercat force-pushed the gg-LoadingTimeLogging branch from 2cfe667 to d24d596 Compare January 30, 2018 01:30

graceguo-supercat merged commit 724c3f4 into apache:master Jan 30, 2018

graceguo-supercat deleted the gg-LoadingTimeLogging branch January 30, 2018 21:20

graceguo-supercat pushed a commit to airbnb/superset-fork that referenced this pull request Jan 31, 2018

Merge pull request #5 from airbnb/gg-CherryPickLogger

310edae

add frontend logging utility function (apache#4226)

graceguo-supercat mentioned this pull request Feb 1, 2018

[Bug] Resize should trigger chart re-render #4322

Merged

michellethomas pushed a commit to michellethomas/panoramix that referenced this pull request May 24, 2018

add frontend logging utility function (apache#4226)

60c1e5f

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events

wenchma pushed a commit to wenchma/incubator-superset that referenced this pull request Nov 16, 2018

add frontend logging utility function (apache#4226)

91584ff

add loading log for dash and exploreview breakdown whole page load action to multiple charts loading events and render events

mistercrunch added 🏷️ bot A label used by `supersetbot` to keep track of which PR where auto-tagged with release labels 🚢 0.23.0 labels Feb 27, 2024

Provide feedback

Saved searches

Use saved searches to filter your results more quickly

Add frontend logging functions and log loading time for Dashboard and explore view #4226

Add frontend logging functions and log loading time for Dashboard and explore view #4226

graceguo-supercat commented Jan 17, 2018 •

edited

williaster Jan 19, 2018

graceguo-supercat Jan 21, 2018

williaster Jan 19, 2018

graceguo-supercat Jan 21, 2018

williaster Jan 19, 2018

graceguo-supercat Jan 21, 2018 •

edited

williaster Jan 19, 2018

williaster Jan 19, 2018

graceguo-supercat Jan 21, 2018

timifasubaa commented Jan 29, 2018

mistercrunch commented Jan 30, 2018

graceguo-supercat commented Jan 30, 2018

mistercrunch commented Jan 31, 2018 •

edited

Add frontend logging functions and log loading time for Dashboard and explore view #4226

Add frontend logging functions and log loading time for Dashboard and explore view #4226

Conversation

graceguo-supercat commented Jan 17, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

graceguo-supercat Jan 21, 2018 • edited

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

Choose a reason for hiding this comment

timifasubaa commented Jan 29, 2018

mistercrunch commented Jan 30, 2018

graceguo-supercat commented Jan 30, 2018

mistercrunch commented Jan 31, 2018 • edited

graceguo-supercat commented Jan 17, 2018 •

edited

graceguo-supercat Jan 21, 2018 •

edited

mistercrunch commented Jan 31, 2018 •

edited